{"thread":{"id":"48233","subject":"reg. fatal: The remote end hung up unexpectedly on NFS","startedAt":"2018-04-06T18:26:16Z","lastAt":"2018-04-08T19:31:50Z","messageCount":4,"participants":["Satya Prakash GS","Ævar Arnfjörð Bjarmason","Jeff King"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"343978","messageId":"CAJZK4X4-AZ6uEoVbAtQ9ErdJ2guKj9puXcpdX_3igBNPdQNp5A@mail.gmail.com","threadId":"48233","inReplyTo":null,"subject":"reg. fatal: The remote end hung up unexpectedly on NFS","fromName":"Satya Prakash GS","fromEmail":"g.satyaprakash@gmail.com","sentAt":"2018-04-06T18:25:51Z","receivedAt":"2018-04-06T18:26:16Z","isPatch":false,"sender":{"key":"g.satyaprakash@gmail.com","avatar":null},"body":"Hi,\n\nWe have a distributed filesystem with NFS access. On the NFS mount, I\nwas doing a git-clone and if NFS server crashed and came back up while\nthe clone is going on, clone fails with the below message:\n\ngit clone https://satgs@github.com/fs/private-qa.git\n\nremote: Counting objects: 139419, done.\nremote: Compressing objects: 100% (504/504), done.\nReceiving objects: 7% (9760/139419), 5.32 MiB | 5.27 MiB/s\nerror: RPC failed; result=18, HTTP code = 200 MiB | 96.00 KiB/s\nfatal: The remote end hung up unexpectedly\nfatal: early EOF\nfatal: index-pack failed\n\nOn NFS server crash, it usually takes a minute or two for our\nfilesystem to failover to new NFS server. Initially I suspected it had\nsomething to do with the filesystem, like attributes of the file\nwritten by git weren't matching what it was expecting but the same\ntest fails on open source NFS server. While clone is going on, if I\nstopped the open source NFS server for 2 minutes and restarted it, git\nclone fails.\n\nAnother interesting thing is, if the restart happens within a few\nseconds, git clone succeeds.\n\nSideband_demux fails while trying to read from the pipe. Read size\ndoesn't match what is expected. If there are 2 parts to git clone\nwhich is fetching data and writing to local filesystem, is this error\nhappening while trying to fetch ? Since it succeeds if the restart is\ndone immediately, has this got something to do with the protocol\ntimeouts.\n\nPlease advise on how to debug this further.\n\nThanks,\nSatya.\n"},{"id":"343979","messageId":"87woxkyxz6.fsf@evledraar.gmail.com","threadId":"48233","inReplyTo":"CAJZK4X4-AZ6uEoVbAtQ9ErdJ2guKj9puXcpdX_3igBNPdQNp5A@mail.gmail.com","subject":"Re: reg. fatal: The remote end hung up unexpectedly on NFS","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2018-04-06T18:46:21Z","receivedAt":"2018-04-06T18:46:29Z","isPatch":false,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Fri, Apr 06 2018, Satya Prakash wrote:\n\n> Hi,\n>\n> We have a distributed filesystem with NFS access. On the NFS mount, I\n> was doing a git-clone and if NFS server crashed and came back up while\n> the clone is going on, clone fails with the below message:\n>\n> git clone https://satgs@github.com/fs/private-qa.git\n>\n> remote: Counting objects: 139419, done.\n> remote: Compressing objects: 100% (504/504), done.\n> Receiving objects: 7% (9760/139419), 5.32 MiB | 5.27 MiB/s\n> error: RPC failed; result=18, HTTP code = 200 MiB | 96.00 KiB/s\n> fatal: The remote end hung up unexpectedly\n> fatal: early EOF\n> fatal: index-pack failed\n>[...]\n> Please advise on how to debug this further.\n\nI don't know what this could be, but have you tried turning on the\nvarious GIT_TRACE env variables document in \"man git\"? Some of those\nmight hold a clue to what's going on here.\n\nHave you tried to do other git-independent tests to see if in general\nthe NFS failover isn't resulting in data being written as applications\nexpect? E.g. doing a recursive wget of some data with known SHA1-sums,\nor doing a stess test of some sort on a filesystem that uses checksums\n(such as btrfs), which could be loop-mounted to a file stored on NFS.\n"},{"id":"343997","messageId":"20180406194845.GB11450@sigill.intra.peff.net","threadId":"48233","inReplyTo":"CAJZK4X4-AZ6uEoVbAtQ9ErdJ2guKj9puXcpdX_3igBNPdQNp5A@mail.gmail.com","subject":"Re: reg. fatal: The remote end hung up unexpectedly on NFS","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2018-04-06T19:48:45Z","receivedAt":"2018-04-06T19:48:52Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Apr 06, 2018 at 11:55:51PM +0530, Satya Prakash GS wrote:\n\n> We have a distributed filesystem with NFS access. On the NFS mount, I\n> was doing a git-clone and if NFS server crashed and came back up while\n> the clone is going on, clone fails with the below message:\n> \n> git clone https://satgs@github.com/fs/private-qa.git\n> \n> remote: Counting objects: 139419, done.\n> remote: Compressing objects: 100% (504/504), done.\n> Receiving objects: 7% (9760/139419), 5.32 MiB | 5.27 MiB/s\n> error: RPC failed; result=18, HTTP code = 200 MiB | 96.00 KiB/s\n> fatal: The remote end hung up unexpectedly\n> fatal: early EOF\n> fatal: index-pack failed\n\nCurl's result=18 is CURLE_PARTIAL_FILE. Usually that means the other\nside hung up partway through. But given the NFS symptoms you describe, I\nwonder if fwrite() to the file simply returned an error, and curl gave\nup.\n\n> On NFS server crash, it usually takes a minute or two for our\n> filesystem to failover to new NFS server. Initially I suspected it had\n> something to do with the filesystem, like attributes of the file\n> written by git weren't matching what it was expecting but the same\n> test fails on open source NFS server. While clone is going on, if I\n> stopped the open source NFS server for 2 minutes and restarted it, git\n> clone fails.\n> \n> Another interesting thing is, if the restart happens within a few\n> seconds, git clone succeeds.\n> \n> Sideband_demux fails while trying to read from the pipe. Read size\n> doesn't match what is expected. If there are 2 parts to git clone\n> which is fetching data and writing to local filesystem, is this error\n> happening while trying to fetch ? Since it succeeds if the restart is\n> done immediately, has this got something to do with the protocol\n> timeouts.\n> \n> Please advise on how to debug this further.\n\nIf you're on Linux, strace could show you the write error. Unfortunately\nit's a little tricky because the http bits happen in a sub-process. But\ntry:\n\n cat >/in/your/$PATH/git-remote-strace <<\\EOF\n #!/bin/sh\n protocol=$(echo \"$2\" | cut -d: -f1)\n exec strace -f -o /tmp/foo.out git-remote-$protocol \"$@\"\n EOF\n chmod +x /in/your/$PATH/git-remote-strace\n\n git clone strace::https://github.com/whatever\n\nMy guess is you may find a failed `write()` in there.\n\n-Peff\n"},{"id":"344114","messageId":"CAJZK4X4Y5RqKww3thWBb5hCbSDWuxqDBRbY5EeOAB66ugaHVLg@mail.gmail.com","threadId":"48233","inReplyTo":"20180406194845.GB11450@sigill.intra.peff.net","subject":"Re: reg. fatal: The remote end hung up unexpectedly on NFS","fromName":"Satya Prakash GS","fromEmail":"g.satyaprakash@gmail.com","sentAt":"2018-04-08T19:31:19Z","receivedAt":"2018-04-08T19:31:50Z","isPatch":false,"sender":{"key":"g.satyaprakash@gmail.com","avatar":null},"body":"Avarab,\n\nI enabled GIT_TRACE, packet, etc. I could not make much sense of the\noutput. I downloaded git source and started looking at the code.\nYeah, kernel compilation with failovers worked on our filesystem. We\ntried xfs test suite with failovers, it worked. Since it's failing\nwith open source NFS, I am wondering if this even has anything to do\nwith filesystem.\n\nJeff,\n\nThank you for the clear instructions on strace.\n\nLooks like 5 and 6 are two ends of a pipe.\n\nread(5, \"\\27\\3\\3\\5r\", 5) = 5\nread(5, \"S\\10n\\230i\\257\\27\\2\\333&\\335jou~\\3036}S\\273\\212\\250\\33\\310\\216b\\253\\3505\\332\\266X\"...,\n1394) = 1394\nwrite(6, \"\\2530\\253x\\27\\247iz\\246\\321*\\v\\33\\306.\\221I\\36\\4\\304D\\\\\\360\\361\\306I\\213\\304\\245m\\247\\30\"...,\n1370) = 1370\n<... read resumed>\n\"\\2530\\253x\\27\\247iz\\246\\321*\\v\\33\\306.\\221I\\36\\4\\304D\\\\\\360\\361\\306I\\213\\304\\245m\\247\\30\"...,\n5071) = 1370\nrt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, \nread(0, \n<... rt_sigaction resumed> NULL, 8) = 0\npoll([{fd=5, events=POLLIN}], 1, 1000) = 1 ([{fd=5, revents=POLLIN}])\nrt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, 8) = 0\nrt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, NULL, 8) = 0\npoll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1\n([{fd=5, revents=POLLIN|POLLRDNORM}])\nread(5, \"\\27\\3\\3\\5r\", 5) = 5\nread(5, \"S\\10n\\230i\\257\\27\\3]T\\0{\\232\\253\\377$\\265\\277\\211o.\\314T\\315\\257\\335j\\322\\367\\31o\\262\"...,\n1394) = 1394\n\n>>>>>>>>>>>>> Write preceding the last read has succeeded\nwrite(6, \"\\237%\\204W$\\236\\177\\305@\\210+\\236\\227.\\316\\226\\250\\t\\256:\\27?};\\270^A\\317\\204\\222\\35]\"...,\n1370) = 1370\n>>>>>>>>\n\n<... read resumed>\n\"\\237%\\204W$\\236\\177\\305@\\210+\\236\\227.\\316\\226\\250\\t\\256:\\27?};\\270^A\\317\\204\\222\\35]\"...,\n3701) = 1370\nrt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, \nread(0, \n<... rt_sigaction resumed> NULL, 8) = 0\npoll([{fd=5, events=POLLIN}], 1, 1000) = 1 ([{fd=5, revents=POLLIN}])\nrt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, 8) = 0\nrt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, NULL, 8) = 0\npoll([{fd=5, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1\n([{fd=5, revents=POLLIN|POLLRDNORM}])\nread(5, \"\\27\\3\\3\\5r\", 5) = 5\n\n>>>>> Problematic reads\nread(5, \"S\\10n\\230i\\257\\27\\4\\220\\243\\375\\3772\\213?\\267\\356V\\246r\\226`\\223\\253^\\310\\314\\207\\222\\22%\\376\"...,\n1394) = 363\nread(5, \"\", 1031) = 0\n>>>>>>>>>>>>>>>\n\nwrite(5, \"\\25\\3\\3\\0\\32\\265(Nk5\\330Y\\4!\\374S\\204\\377\\304\\0166j\\rV\\305;e3\\347&w\",\n31) = 31\nclose(5)\n\nrt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, NULL, 8) = 0\nrt_sigaction(SIGPIPE, {0x441ed0, [PIPE], SA_RESTORER|SA_RESTART,\n0x7f038e8bb890}, NULL, 8) = 0\nwrite(2, \"error: RPC failed; result=18, HT\"..., 46) = 46\nbrk(0x1597000) = 0x1597000\nclose(6 \n<... read resumed> \"\", 2331) = 0\n<... close resumed> ) = 0\nread(7, \"0000\", 4096) = 4\nwrite(2, \"fatal: The remote end hung up un\"..., 43 \nread(7, \n<... write resumed> ) = 43\nclose(4 \n<... read resumed> \"\", 4096) = 0\n<... close resumed> )\n\nLast read from pipe (fd 5) was a partial read. Write has succeeded on\nthe pipe but read failed, that's strange. In this case, it doesn't\neven look like the write was interleaved.\n\nThanks,\nSatya.\n\nOn Sat, Apr 7, 2018 at 1:18 AM, Jeff King wrote:\n> On Fri, Apr 06, 2018 at 11:55:51PM +0530, Satya Prakash GS wrote:\n>\n>> We have a distributed filesystem with NFS access. On the NFS mount, I\n>> was doing a git-clone and if NFS server crashed and came back up while\n>> the clone is going on, clone fails with the below message:\n>>\n>> git clone https://satgs@github.com/fs/private-qa.git\n>>\n>> remote: Counting objects: 139419, done.\n>> remote: Compressing objects: 100% (504/504), done.\n>> Receiving objects: 7% (9760/139419), 5.32 MiB | 5.27 MiB/s\n>> error: RPC failed; result=18, HTTP code = 200 MiB | 96.00 KiB/s\n>> fatal: The remote end hung up unexpectedly\n>> fatal: early EOF\n>> fatal: index-pack failed\n>\n> Curl's result=18 is CURLE_PARTIAL_FILE. Usually that means the other\n> side hung up partway through. But given the NFS symptoms you describe, I\n> wonder if fwrite() to the file simply returned an error, and curl gave\n> up.\n>\n>> On NFS server crash, it usually takes a minute or two for our\n>> filesystem to failover to new NFS server. Initially I suspected it had\n>> something to do with the filesystem, like attributes of the file\n>> written by git weren't matching what it was expecting but the same\n>> test fails on open source NFS server. While clone is going on, if I\n>> stopped the open source NFS server for 2 minutes and restarted it, git\n>> clone fails.\n>>\n>> Another interesting thing is, if the restart happens within a few\n>> seconds, git clone succeeds.\n>>\n>> Sideband_demux fails while trying to read from the pipe. Read size\n>> doesn't match what is expected. If there are 2 parts to git clone\n>> which is fetching data and writing to local filesystem, is this error\n>> happening while trying to fetch ? Since it succeeds if the restart is\n>> done immediately, has this got something to do with the protocol\n>> timeouts.\n>>\n>> Please advise on how to debug this further.\n>\n> If you're on Linux, strace could show you the write error. Unfortunately\n> it's a little tricky because the http bits happen in a sub-process. But\n> try:\n>\n> cat >/in/your/$PATH/git-remote-strace <<\\EOF\n> #!/bin/sh\n> protocol=$(echo \"$2\" | cut -d: -f1)\n> exec strace -f -o /tmp/foo.out git-remote-$protocol \"$@\"\n> EOF\n> chmod +x /in/your/$PATH/git-remote-strace\n>\n> git clone strace::https://github.com/whatever\n>\n> My guess is you may find a failed `write()` in there.\n>\n> -Peff\n"}]}