onedev/server

#735 send-pack: unexpected disconnect while reading sideband packet

Closed

Activities

James opened 2 years ago

Running OneDev 7.2.4 as a service on windows with git git version 2.36.1.windows.1. No fancy setup, running openjdk, all defaults. Create new project, add new remote to existing PHP based project which is 202MB total (not including .git folder). When I push using git push onedev master I get the normal packing stuff but then:

$ git push onedev master
Enumerating objects: 42531, done.
Counting objects: 100% (42531/42531), done.
Delta compression using up to 8 threads
Compressing objects: 100% (16143/16143), done.
Writing objects: 100% (42531/42531), 102.23 MiB | 204.06 MiB/s, done.
Total 42531 (delta 27944), reused 40102 (delta 26144), pack-reused 0
error: RPC failed; curl 56 Recv failure: Connection was reset
send-pack: unexpected disconnect while reading sideband packet
fatal: the remote end hung up unexpectedly
Everything up-to-date

I've tried the typical changing buffer size (500MB), verbose trace etc and still the same issue. This is the last part of the push with trace on (and through HTTP Toolkit):

...
09:17:46.390617 run-command.c:654       trace: run_command: git pack-objects --all-progress-implied --revs --stdout --thin --delta-base-offset --progress
09:17:46.410654 exec-cmd.c:237          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
09:17:46.412553 git.c:459               trace: built-in: git pack-objects --all-progress-implied --revs --stdout --thin --delta-base-offset --progress
Enumerating objects: 42531, done.
Counting objects: 100% (42531/42531), done.
Delta compression using up to 8 threads
Compressing objects: 100% (16143/16143), done.
09:17:47.556727 pkt-line.c:80           packet:          git< PACK ...
Writing objects: 100% (42531/42531), 102.15 MiB | 200.78 MiB/s, done.
Total 42531 (delta 27941), reused 40105 (delta 26144), pack-reused 0
09:17:48.083641 pkt-line.c:80           packet:          git> 0000
09:17:48.083641 http.c:689              == Info: Connection 1 seems to be dead
09:17:48.083641 http.c:689              == Info: Closing connection 1
09:17:48.084643 http.c:689              == Info: NTLM-proxy picked AND auth done set, clear picked
09:17:48.084643 http.c:689              == Info: Hostname 127.0.0.1 was found in DNS cache
09:17:48.084643 http.c:689              == Info:   Trying 127.0.0.1:8000...
09:17:48.084643 http.c:689              == Info: Connected to 127.0.0.1 (127.0.0.1) port 8000 (#2)
09:17:48.084643 http.c:689              == Info: Server auth using Basic with user 'james'
09:17:48.085643 http.c:636              => Send header, 0000000374 bytes (0x00000176)
09:17:48.085643 http.c:648              => Send header: POST http://[server]:6610/APP-Web/git-receive-pack HTTP/1.1
09:17:48.085643 http.c:648              => Send header: Host: [server]:6610
09:17:48.085643 http.c:648              => Send header: Authorization: Basic <redacted>
09:17:48.085643 http.c:648              => Send header: User-Agent: git/2.36.1.windows.1
09:17:48.085643 http.c:648              => Send header: Accept-Encoding: deflate, gzip, br, zstd
09:17:48.085643 http.c:648              => Send header: Proxy-Connection: Keep-Alive
09:17:48.085643 http.c:648              => Send header: Content-Type: application/x-git-receive-pack-request
09:17:48.085643 http.c:648              => Send header: Accept: application/x-git-receive-pack-result
09:17:48.085643 http.c:648              => Send header: Content-Length: 107116419
09:17:48.085643 http.c:648              => Send header:
09:17:48.994525 http.c:689              == Info: Recv failure: Connection was reset
09:17:48.994525 http.c:689              == Info: Closing connection 2
error: RPC failed; curl 56 Recv failure: Connection was reset
send-pack: unexpected disconnect while reading sideband packet
fatal: the remote end hung up unexpectedly
Everything up-to-date
09:17:49.155983 exec-cmd.c:237          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
09:17:49.158948 git.c:459               trace: built-in: git config --bool core.sparseCheckout

Interestingly i'm moving from Bonobo server as I have been geting the same issue with it. However, Onedev server log actually contains info:

2022-05-18 23:17:47,438 ERROR [qtp598316733-34] io.onedev.server.git.GitFilter Error serving git request
java.util.concurrent.ExecutionException: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: org.eclipse.jetty.io.EofException
	at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor$WorkFuture.get(DefaultWorkExecutor.java:217)
	at io.onedev.server.git.GitFilter.processPacks(GitFilter.java:238)
	at io.onedev.server.git.GitFilter.doFilter(GitFilter.java:326)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:450)
	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at io.onedev.server.util.jetty.DisableTraceFilter.doFilter(DisableTraceFilter.java:28)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:763)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:386)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.RuntimeException: org.eclipse.jetty.io.EofException
	at io.onedev.commons.bootstrap.Bootstrap.unchecked(Bootstrap.java:363)
	at io.onedev.commons.utils.ExceptionUtils.unchecked(ExceptionUtils.java:35)
	at io.onedev.commons.utils.command.ProcessStreamPumper.waitFor(ProcessStreamPumper.java:59)
	at io.onedev.commons.utils.command.Commandline.execute(Commandline.java:330)
	at io.onedev.commons.utils.command.Commandline.execute(Commandline.java:183)
	at io.onedev.server.git.command.ReceivePackCommand.call(ReceivePackCommand.java:59)
	at io.onedev.server.git.GitFilter$4.run(GitFilter.java:233)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor$5.call(DefaultWorkExecutor.java:252)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor$5.call(DefaultWorkExecutor.java:248)
	at io.onedev.server.security.SecurityUtils$3.call(SecurityUtils.java:378)
	at io.onedev.server.util.concurrent.DefaultWorkExecutor$4.call(DefaultWorkExecutor.java:121)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at io.onedev.server.security.SecurityUtils$1.run(SecurityUtils.java:352)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	... 1 common frames omitted
Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: org.eclipse.jetty.io.EofException
	at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
	at io.onedev.commons.utils.command.ProcessStreamPumper.waitFor(ProcessStreamPumper.java:54)
	... 13 common frames omitted
Caused by: java.lang.RuntimeException: org.eclipse.jetty.io.EofException
	at io.onedev.commons.utils.command.ProcessStreamPumper$1.run(ProcessStreamPumper.java:80)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	... 3 common frames omitted
Caused by: org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279)
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277)
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381)
	at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:820)
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223)
	at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550)
	at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:910)
	at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:987)
	at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor$GzipBufferCB.process(GzipHttpOutputInterceptor.java:416)
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223)
	at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor.gzip(GzipHttpOutputInterceptor.java:139)
	at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor.commit(GzipHttpOutputInterceptor.java:240)
	at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor.write(GzipHttpOutputInterceptor.java:109)
	at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285)
	at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:269)
	at org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:749)
	at io.onedev.server.util.OutputStreamWrapper.flush(OutputStreamWrapper.java:31)
	at io.onedev.commons.utils.command.ProcessStreamPumper$1.run(ProcessStreamPumper.java:76)
	... 5 common frames omitted
Caused by: java.io.IOException: Connection reset by peer
	at java.base/sun.nio.ch.SocketDispatcher.writev0(Native Method)
	at java.base/sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:58)
	at java.base/sun.nio.ch.IOUtil.write(IOUt...

Robin Shen commented 2 years ago

This seems odd. I just test the same setup on Windows 10 and everything works fine. Do you have some sort of virus scanning software. If yes, turn off it and try again.

Robin Shen commented 2 years ago

Also make sure to disable proxy if there is any.

James commented 2 years ago

Thanks for taking a look. I just disabled Nortons (sic), and no proxy. Still the same issue:

$ git push onedev master
Enumerating objects: 42531, done.
Counting objects: 100% (42531/42531), done.
Delta compression using up to 8 threads
Compressing objects: 100% (16143/16143), done.
Writing objects: 100% (42531/42531), 101.90 MiB | 204.60 MiB/s, done.
Total 42531 (delta 27946), reused 40100 (delta 26144), pack-reused 0
error: RPC failed; curl 56 Recv failure: Connection was reset
send-pack: unexpected disconnect while reading sideband packet
fatal: the remote end hung up unexpectedly
Everything up-to-date

Its mostly php etc script, with 1 binary at 44MB.

Any other ideas?

Robin Shen commented 2 years ago

I even tested on a fresh started Windows VM and still it works. From the error message, it seems that the connection between git and onedev is forcibly stopped. My experience with anti-virus software is that even if they are disabled, they still work in the backend doing something.

You may push via SSH with encrypted traffic to see if the problem still exist.

Robin Shen commented 2 years ago

Want to mention that big file is not a problem at all, I tested with single 200M file or a 3G repository without any issues.

James commented 2 years ago

I wonder could there be some encoding in the files that might cause something to break? I know git is configure to check out windows line endings?!

So i have tested onedev with a simple react project:

Docker on a fresh windows 2019 server install in VirtualBox,
and then again under Hyper-V (turns out I can't use Docker in Windows guest or host with VurtualBox :( and Linux images)
Ran on windows 11 from server.bat console

And all good, no issues (actually had to allow Git to work across filesystems due to the docker volume mount under windows).

Then after failing to install Docker on a VMWare windows 2019 VM (incompatibilities) i ran from command line (and installed as service), and this is where i'm having issues. The VM is on a suite of hosted servers with Gigabit connectivity.

I just tested creating the same project name on the HyperV Docker setup and successfully pushed the same project to it. It sat for a while after the Total 42531 (delta 27... line (ok, maybe 20 seconds but felt like hours) but completed successfully.

Ahhh, i just tried SSH and it works. I had to create a key pair and added it through the ui. So it looks like its ssh for us rather than http.

I wonder why http doesn't work? I wonder if it will work with SSL?

Robin Shen commented 2 years ago

SSL probably works also. I ever worked on a project and connection is dropped sometimes for unknown reason at customer site, and after encrypting traffic with SSL everything works fine. Finally it turned out that plain traffic matches a particular pattern in customer security software and the connection was dropped.

Robin Shen commented 2 years ago

Also have you tested pushing some other repo to OneDev running as Windows service on that machine?

James commented 2 years ago

Yes, I have pushed successfully using SSH to the vm running it as a service for several projects. And its picked up and processed the commit history which is nice.

I'll try https and see if it works, but I agree it probably will. But i think its not a big deal having the devs add their key to their account and use SSH. It could even be the firewall of the server side network that is causing drops too.

Thanks for your help :)

cheers

Robin Shen changed state to 'Closed' 2 years ago

Previous Value	Current Value
Open	Closed

Robin Shen commented 2 years ago

OK. Closing this issue now. Feel free to reopen if you believe it is a OneDev bug.

James commented 2 years ago

Thanks again :)

Type	Bug
Priority	Normal
Assignee	Robin Shen
Affected Versions	Not Found

Issue Votes (0)

Watchers (4)

Reference

onedev/server#735