Re: Slow VM, svn client drops connection with FIN packet
stuartm.cod...@gmail.com writes: > I have another failure, with some debug info, and some updates. > > We're switching to a different system for this particular repository, so I > may or may not be able to continue debug efforts. :-( > > Since there's no debug info available for the svn 1.8 client, I haven't > been running that. > > I went a full week without a failure, which I suspect is due to the > enormous amount of debugging that neon-debug-mask=255 produces, so this > week I dialed it back to 127 and got a failure on the first try. > > Here's the latest failure. First up, the debug info: > Got 8192 bytes. > XML: Parsing 8192 bytes. > XML: char-data (235) returns 0 > XML: xmlParseChunk returned 0 > Reading 8192 bytes of response body. > Got 6600 bytes. > XML: Parsing 6600 bytes. > XML: char-data (235) returns 0 > XML: xmlParseChunk returned 0 > Reading 8192 bytes of response body. > Aborted request (-3): Could not read response body That message comes from ne_request.c and the -3 is NE_SOCK_CLOSED defined in ne_socket.h: #define NE_SOCK_CLOSED (-3) /* Connection was reset (e.g. server crashed) */ > sess: Closing connection. > sess: Connection closed. > Request ends, status 200 class 2xx, error line: > Could not read response body: connection was closed by server > Running destroy hooks. > Request ends. > svn: E175002: REPORT of '/svn/repos//!svn/me': Could not read > response body: connection was closed by server (http://) > sess: Destroying session. > sess: Destroying session. What does the server error log show? -- Philip Martin | Subversion Committer WANdisco // *Non-Stop Data*
Re: Slow VM, svn client drops connection with FIN packet
Philip Martin writes: > That message comes from ne_request.c and the -3 is NE_SOCK_CLOSED > defined in ne_socket.h: > > #define NE_SOCK_CLOSED (-3) > /* Connection was reset (e.g. server crashed) */ /* Socket was closed */ #define NE_SOCK_CLOSED (-3) The comment associated with the constant is "Socket was closed" not "Connection was reset". -- Philip Martin | Subversion Committer WANdisco // *Non-Stop Data*
Re: Slow VM, svn client drops connection with FIN packet
I don't have access to the server log, but you can see from the wireshark capture that the *client* closed the connection (look for the RST packet), not the server. The error of "socket closed" is consistent with that. I suspect that there's an issue handling the "http-timeout" timer; it gets triggered during a TCP zero window situation, and then not canceled properly, and then it fires, closing the socket. That would also fit the data of the bug being in 1.6 (reported by someone else, but I linked to it in my original post), 1.7 and 1.8; it's a bug in svn's handling of the underlying HTTP interaction layer, and not in that layer or the server or somewhere else. I could be wrong. When I look at the evidence so far, that's what I see. ...Stu On Tue, Jan 14, 2014 at 6:33 AM, Philip Martin wrote: > stuartm.cod...@gmail.com writes: > > > I have another failure, with some debug info, and some updates. > > > > We're switching to a different system for this particular repository, so > I > > may or may not be able to continue debug efforts. :-( > > > > Since there's no debug info available for the svn 1.8 client, I haven't > > been running that. > > > > I went a full week without a failure, which I suspect is due to the > > enormous amount of debugging that neon-debug-mask=255 produces, so this > > week I dialed it back to 127 and got a failure on the first try. > > > > Here's the latest failure. First up, the debug info: > > Got 8192 bytes. > > XML: Parsing 8192 bytes. > > XML: char-data (235) returns 0 > > XML: xmlParseChunk returned 0 > > Reading 8192 bytes of response body. > > Got 6600 bytes. > > XML: Parsing 6600 bytes. > > XML: char-data (235) returns 0 > > XML: xmlParseChunk returned 0 > > Reading 8192 bytes of response body. > > Aborted request (-3): Could not read response body > > That message comes from ne_request.c and the -3 is NE_SOCK_CLOSED > defined in ne_socket.h: > > #define NE_SOCK_CLOSED (-3) > /* Connection was reset (e.g. server crashed) */ > > > sess: Closing connection. > > sess: Connection closed. > > Request ends, status 200 class 2xx, error line: > > Could not read response body: connection was closed by server > > Running destroy hooks. > > Request ends. > > svn: E175002: REPORT of '/svn/repos//!svn/me': Could not read > > response body: connection was closed by server (http://) > > sess: Destroying session. > > sess: Destroying session. > > What does the server error log show? > > -- > Philip Martin | Subversion Committer > WANdisco // *Non-Stop Data* >
Re: Slow VM, svn client drops connection with FIN packet
Here's this morning's failure. For testing, I've set http-timeout=67. I am trying to see if the zero window is a coincidence or not. The debug output: Reading 8192 bytes of response body. Got 8192 bytes. XML: Parsing 8192 bytes. XML: char-data (235) returns 0 XML: xmlParseChunk returned 0 Reading 8192 bytes of response body. Got 6180 bytes. XML: Parsing 6180 bytes. XML: char-data (235) returns 0 XML: xmlParseChunk returned 0 Reading 8192 bytes of response body. Aborted request (-3): Could not read response body sess: Closing connection. sess: Connection closed. Request ends, status 200 class 2xx, error line: Could not read response body: connection was closed by server Running destroy hooks. Request ends. svn: E175002: REPORT of '/svn/repos/deckard-65x/!svn/me': Could not read response body: connection was closed by server (http://foundry51.qnx.com) sess: Destroying session. sess: Destroying session. The network capture: 391174498.61043900010.222.3.8810.14.11.50HTTP1434 Continuation or non-HTTP traffic 391175498.61049500010.14.11.5010.222.3.88TCP5437480 > http [ACK] Seq=1945767 Ack=480574851 Win=1280 Len=0 391176498.84217900010.222.3.8810.14.11.50HTTP1334 [TCP Window Full] Continuation or non-HTTP traffic 391177499.04226400010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391178499.29797200010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391179499.29806500010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391180499.79676200010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391181499.79681100010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391182500.77834900010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391183500.77840500010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391184502.72819100010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391185502.7282610.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391186506.61403100010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391187506.61409300010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391188514.37163800010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391189514.37169400010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 391190529.87221100010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 391191*REF*10.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 39119230.98860100010.222.3.8810.14.11.50TCP60[TCP Keep-Alive] http > 37480 [ACK] Seq=480576130 Ack=1945767 Win=908288 Len=0 39119330.98864500010.14.11.5010.222.3.88TCP54[TCP ZeroWindow] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=0 Len=0 39119471.28265500010.14.11.5010.222.3.88TCP54[TCP Window Update] 37480 > http [ACK] Seq=1945767 Ack=480576131 Win=1171456 Len=0 39119571.29659800010.222.3.8810.14.11.50HTTP1434 Continuation or non-HTTP traffic which results in: 39259871.90686300010.222.3.8810.14.11.50HTTP1434 Continuation or non-HTTP traffic 39259971.90692500010.14.11.5010.222.3.88TCP5437480 > http [ACK] Seq=1945767 Ack=482310892 Win=987904 Len=0 39260072.04327600010.14.11.5010.222.3.88TCP54[TCP Window Update] 37480 > http [ACK] Seq=1945767 Ack=482310892 Win=1188096 Len=0 39260172.37532500010.14.11.5010.222.3.88TCP5437480 > http [FIN, ACK] Seq=1945767 Ack=482310892 Win=1188096 Len=0 39260272.3886910.222.3.8810.14.11.50TCP60http > 37480 [ACK] Seq=482310892 Ack=1945768 Win=908288 Len=0 There are two interesting things: The long gap after the *REF* packet is unusual, it's the first time I've seen that. The FIN packet is 72 seconds later, not 67 like I set the timeout. OTOH, it's close, and, given the long gap no packets occur at FIN - 67 seconds. I'm going to keep trying random timeou
Re: Slow VM, svn client drops connection with FIN packet
Stuart MacDonald writes: > svn: E175002: REPORT of '/svn/repos/deckard-65x/!svn/me': Could not read > response body: connection was closed by server (http://foundry51.qnx.com) I can provoke this on my local LAN by setting the Apache timeout on the server to a low value such as 5 seconds. Then I run a checkout that generates a large REPORT response and I use gdb to interrupt the client at subversion/libsvn_ra_neon/fetch.c:1709 so that the client is in the middle of reading the repsonse. I wait for the server timeout to expire and then resume the client and I get the error: svn: E175002: REPORT of '/obj/repo/!svn/me': Could not read response body: connection was closed by server (http://peri.local:) One fix is to increase the server timeout to handle your slow client. -- Philip Martin | Subversion Committer WANdisco // *Non-Stop Data*
Re: Can't move temporary on update.
Does your virus scanner (local or on the server if G: is a network drive) do something specific with that file? It appears that the tempfile that was just created, disappeared before it could be moved into the pristine store. Bert Sent from Windows Mail From: Stefan Sent: Monday, January 13, 2014 10:32 PM To: users@subversion.apache.org Sry, forgot the obvious most important info: Client is running 1.8.5 Server is running Visual SVN 2.5.15 - based on SVN 1.7.13 - server is set-up to use neon. I traced the issue down to obvious problems with a certain directory in the repository. Ignoring/Skipping that directory and the check-out as well as the update operation work fine. Looking into the .svn/tmp-directory I do see a single existing file: trz2A87.tmp but obviously there's no trace of the mentioned svn-E78ED003 file. Regards, Stefan > Hi, > > we recently started getting this error when trying to update or > check-out a repository. > Weird thing is that the issue only occurs when we try to > check-out/update the thing externally (meaning via VPN). > > Error: > svn: E720002: Can't move 'G:\Egosoft\X4\Source\.svn\tmp\svn-E78ED003' > to > 'G:\Egosoft\X4\Source\.svn\pristine\00\0077903324a83da0419971daeb632ff51529d320.svn-base': > > The system cannot find the file specified. > svn: E720183: Additional errors: > svn: E720183: Can't create directory > 'G:\Egosoft\X4\Source\.svn\pristine\00': Cannot create a file when > that file already exists. > > The issue is 100% reproducible on two completely different machines. > > Is there any way I could trace down the root-cause of the problem? > > Regards, > Stefan > > --- > This email is free from viruses and malware because avast! Antivirus > protection is active. > http://www.avast.com > > --- This email is free from viruses and malware because avast! Antivirus protection is active. http://www.avast.com
