{"thread":{"id":"26849","subject":"Unable to clone via git protocol / early EOF / index-pack failed","startedAt":"2011-03-24T10:27:03Z","lastAt":"2011-03-26T18:50:41Z","messageCount":6,"participants":["Harald Welte","Holger Freyther","Matthieu Moy"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"164220","messageId":"20110324102703.GH4534@prithivi.gnumonks.org","threadId":"26849","inReplyTo":null,"subject":"Unable to clone via git protocol / early EOF / index-pack failed","fromName":"Harald Welte","fromEmail":"laforge@gnumonks.org","sentAt":"2011-03-24T10:27:03Z","receivedAt":"2011-03-24T10:27:03Z","isPatch":false,"sender":{"key":"laforge@gnumonks.org","avatar":null},"body":"Hi all,\n\nsince a couple of days ago, I'm encountering a very strange problem regarding\none of my git-daemon installations.  It started when I updated the kernel on\nthe git server to Debians \"2.6.32-5-openvz-amd64\".\n\nHowever, all openvz limits have been set to 'unlimited', and there is plenty\nof memory available, the system is idle otherwise.  The repositories are _very_\nsmall, so I do not think resource limitations are an issue.  Also, thre is no\n-ENOMEM or any similar error message from the kernel to git-daemon that would\nmake OpenVZ resource constraints become a suspect.\n\nThis is the output I get on the client side:\n---\nvishnu:/tmp# GIT_TRACE=1 git clone git://git.osmocom.org/cyberflex-shell.git\ntrace: built-in: git 'clone' 'git://git.osmocom.org/cyberflex-shell.git'\nInitialized empty Git repository in /tmp/cyberflex-shell/.git/\ntrace: run_command: 'index-pack' '--stdin' '-v' '--fix-thin' '--keep=fetch-pack 19371 on vishnu.netfilter.org'\ntrace: exec: 'git-index-pack' '--stdin' '-v' '--fix-thin' '--keep=fetch-pack 19371 on vishnu.netfilter.org'\nremote: trace: exec: 'git-pack-objects' '--stdout' '--progress' '--delta-base-offset'\nremote: trace: built-in: git 'pack-objects' '--stdout' '--progress' '--delta-base-offset'\nremote: Counting objects: 1310, done.\nremote: Compressing objects: 100% (341/341), done.\nremote: Total 1310 (delta 968), reused 1299 (delta 963)\nfatal: The remote end hung up unexpectedly\nfatal: early EOF\nfatal: index-pack failed\n---\n\nThe output on the server side looks normal:\n---\ntrace: run_command: '/root/git/git-daemon' '--serve' '--verbose' '--base-path=/srv/gitosis/repositories' '/srv/gitosis/repositories'\n[27202] Connection from 82.99.25.66:5329\n[27202] Extended attributes (22 bytes) exist <host=git.osmocom.org>\n[27202] Request upload-pack for '/openggsn.git'\ntrace: run_command: 'upload-pack' '--strict' '--timeout=0' '.'\n[27202] trace: exec: 'git' 'upload-pack' '--strict' '--timeout=0' '.'\n[27202] trace: exec: 'git-upload-pack' '--strict' '--timeout=0' '.'\n[27202] trace: run_command: 'pack-objects' '--stdout' '--progress' '--delta-base-offset'\n[24307] [27202] Disconnected\n---\n\nWhen I retry the 'git clone' on the client many times, in about 1 of every 10\nto 20 cases it will succeed, but will fail with the same EOF the other 90-95%.\n\nI have tried git version 1.5.6.5, current git.git master, and 1.7.2.5 - they\nall show the same problem, though I had the feeling that git.git master has\na higher probability of success.\n\nThe probability of successful cloning also seems to be influenced by the amount\nof latency between the server and the client.  If I run it on the same machine\nit always works, if I run it on the same ethernet segment, it almost always works,\nand via internet it almost always fails.\n\nLooking at a strace of git-daemon, I get a segment close to the process\ntermination, where a child process is first doing close(1), then fstat(1),\nwhich returns -EBADF.  I'm not sure if this is the cause of the problem,\nbut it looks strange anyway:\n---\n[pid 24306] write(1, \"X\\261_v\\312\\256\\265\\240\\220\\227\\350\\4\\201WA@Y\\341y7\"..., 20) = 20\n[pid 24306] close(1)                    = 0\n[pid 24306] brk(0x2411000)              = 0x2411000\n[pid 24306] write(2, \"Total 102 (delta 58), reused 0 (delta 0)\\n\"..., 41) = 41\n[pid 24306] fstat(1, 0x7fff9070e0a0)    = -1 EBADF (Bad file descriptor)\n[pid 24306] exit_group(0)               = ?\nProcess 24306 detached\n[pid 24302] <... write resumed> )       = 7832\n[pid 24302] --- SIGCHLD (Child exited) @ 0 (0) ---\n[pid 24302] write(1, \"0G\\n\\34182w\\227['\\307\\243\\232^cn'H\\30\\243\\25Y\\2032yU\\24\\213\\3653+\\205`\\0309\\331kFo\\4\\330\\310wE\\4\\274kk\\244c\\32\\331HJ\\32\\300\\213r.\\272Q\\24FF\\345\\255\\355*\\260\\241d\\265\\20\\225\\352F\\0102\\231Y\\4\\262:\\314Pw\\241\\4b\\16\\10\\31\\205\\\\\\31ma\\336#\\216\\31\\251\\35\\366\\350,\\234\\v\\272\\374x\\336\\347\\34\\344\\353\\30\\201\\344z\\302\\214\\n\\202\\31#\\374\\332\\331\\31\\340/\\256+\\300\\342\\n\\374\\306w\\201\\263\\26v\\261\\211$@\\250;\\370P\\335R.]`\\252\\23c\\235\\273\\306\\216@_sd\\2325\\3450\\6|L\\5\\274\\265^D[:hV\\t\\315\\300(z\\233\\0106\\10\\270QTL\\253\\2\\376L\\275^\\247\\323{\\327\\350\\235\\17{\\215\\17\\262q\\246\\2546\\356\\342\\2+\\271\\344\\216Ya&p\\311\\300\\227\\201\\240\\17R\\207X+z#\\225\\256\\214\\275\\\\0*\\252Kz\\361\\206=r#\"..., 360) = 360\n[pid 24302] read(6, \"jects:  49% (49/99)   \\rCompressing objects:  50% (50/99)   \\rCompressing objects:  51% (51/99)   \\rCompressing objects:  52% (52/9\"..., 128) = 128\n[pid 24302] write(1, \"0085\\2\"..., 5)    = 5\n---\n\nI have tried 'git fsck' and 'git gc' on the server repositories, this caused\nno change whatsoever in the behaviour.\n\nI have taken pcap files on the server and client.  They both agree, so I don't\nexpect any firewall, NAT or other IP device to interfere with the communication.\n\nIt is clearly git-daemon who terminates the TCP connection with a [RST,ACK]\npacket towards the client.\n\nDo you have any idea how to further debug the problem?  I've been searching\nthe web for quite soem time, and while I can find a number of reports\ndescribing similar issues, even with small repositories, and as early as 2009,\nthere is no response or solution to any of those postings.\n\nIf you want to experience the problem on the client side, try cloning any\nof the repositories listed on http://cgit.osmocom.org/\n\nRegards,\n\tHarald\n-- \n- Harald Welte <laforge@gnumonks.org>           http://laforge.gnumonks.org/\n============================================================================\n\"Privacy in residential applications is a desirable marketing option.\"\n                                                  (ETSI EN 300 175-7 Ch. A6)\n"},{"id":"164223","messageId":"20110324103049.GI4534@prithivi.gnumonks.org","threadId":"26849","inReplyTo":"20110324102703.GH4534@prithivi.gnumonks.org","subject":"Re: Unable to clone via git protocol / early EOF / index-pack failed","fromName":"Harald Welte","fromEmail":"laforge@gnumonks.org","sentAt":"2011-03-24T10:30:49Z","receivedAt":"2011-03-24T10:30:49Z","isPatch":false,"sender":{"key":"laforge@gnumonks.org","avatar":null},"body":"Hi again,\n\n> since a couple of days ago, I'm encountering a very strange problem regarding\n> one of my git-daemon installations. \n\nWhat I forgot to mention:  The same repositories work fine using the\n'ssh' transport, we can clone, fetch, update, push without any problems\nat all.  So I am quite sure the problem is not related to the repository\ndata/metadata, but specifically related to git-daemon.\n\nThanks again,\n\tHarald\n-- \n- Harald Welte <laforge@gnumonks.org>           http://laforge.gnumonks.org/\n============================================================================\n\"Privacy in residential applications is a desirable marketing option.\"\n                                                  (ETSI EN 300 175-7 Ch. A6)\n"},{"id":"164368","messageId":"loom.20110326T180713-801@post.gmane.org","threadId":"26849","inReplyTo":"20110324102703.GH4534@prithivi.gnumonks.org","subject":"Re: Unable to clone via git protocol / early EOF / index-pack failed","fromName":"Holger Freyther","fromEmail":"zecke@selfish.org","sentAt":"2011-03-26T17:12:51Z","receivedAt":"2011-03-26T17:12:51Z","isPatch":false,"sender":{"key":"zecke@selfish.org","avatar":null},"body":"Harald Welte <laforge <at> gnumonks.org> writes:\n\n> \n> Hi all,\n\nHi,\n\nI was tracing this on the same server with these flags[1] and in the success\nand failure case the commands send to and from the server are the same.\nMy current guess is that something is not getting flushed and the tcp socket\nis closed too early.\n\nIt is a bit difficult to track all the processes that get started and what they\nshould do and to figure out at which point the fd for the tcp socket is really\nclosed.\n\nanyone has an idea of what we could do?\n\ncheers\n   holger\n\n[1] GIT_TRACE_PACKET=1 GIT_TRACE=2 GIT_DEBUG_SEND_PACK=2\n"},{"id":"164369","messageId":"loom.20110326T183100-349@post.gmane.org","threadId":"26849","inReplyTo":"loom.20110326T180713-801@post.gmane.org","subject":"Re: Unable to clone via git protocol / early EOF / index-pack failed","fromName":"Holger Freyther","fromEmail":"zecke@selfish.org","sentAt":"2011-03-26T17:34:31Z","receivedAt":"2011-03-26T17:34:31Z","isPatch":false,"sender":{"key":"zecke@selfish.org","avatar":null},"body":"Holger Freyther <zecke <at> selfish.org> writes:\n\n\n> It is a bit difficult to track all the processes that get started and what they\n> should do and to figure out at which point the fd for the tcp socket is really\n> closed.\n\nIf I do the below hack it is working fine. Adding a fflush(NULL).. or a\nclose(fileno(stdout)).. fsync... sched_yield() is not fixing it though.\n\ndiff --git a/upload-pack.c b/upload-pack.c\nindex 72aa661..4cd12c9 100644\n--- a/upload-pack.c\n+++ b/upload-pack.c\n@@ -695,6 +695,8 @@ static void upload_pack(void)\n                get_common_commits();\n                create_pack_file();\n        }\n+\n+       sleep(1);\n }\n \n int main(int argc, char **argv)\n"},{"id":"164371","messageId":"vpq8vw1epc1.fsf@bauges.imag.fr","threadId":"26849","inReplyTo":"loom.20110326T183100-349@post.gmane.org","subject":"Re: Unable to clone via git protocol / early EOF / index-pack failed","fromName":"Matthieu Moy","fromEmail":"matthieu.moy@grenoble-inp.fr","sentAt":"2011-03-26T17:58:22Z","receivedAt":"2011-03-26T17:58:22Z","isPatch":false,"sender":{"key":"matthieu.moy@grenoble-inp.fr","avatar":"https://gravatar.com/avatar/72c8a2705971a25dfaff23cece15130d405685845d911aedd5667ace277f3fc5?d=mp&s=160"},"body":"Holger Freyther <zecke@selfish.org> writes:\n\n> Holger Freyther <zecke <at> selfish.org> writes:\n>\n>\n>> It is a bit difficult to track all the processes that get started and what they\n>> should do and to figure out at which point the fd for the tcp socket is really\n>> closed.\n>\n> If I do the below hack it is working fine. Adding a fflush(NULL).. or a\n> close(fileno(stdout)).. fsync... sched_yield() is not fixing it though.\n>\n> diff --git a/upload-pack.c b/upload-pack.c\n> index 72aa661..4cd12c9 100644\n> --- a/upload-pack.c\n> +++ b/upload-pack.c\n> @@ -695,6 +695,8 @@ static void upload_pack(void)\n>                 get_common_commits();\n>                 create_pack_file();\n>         }\n> +\n> +       sleep(1);\n>  }\n>  \n>  int main(int argc, char **argv)\n\nThat reminds me an issue I had with git over SSH. The problem was indeed\nnot Git-related:\n\n  http://readlist.com/lists/securityfocus.com/secureshell/0/3071.html\n\nIn short, when sending 196481 bytes or more, _and_ if the server did not\nconsume the data fast enough, then the connection was closed after\n65536=2^16 bytes.\n\nThat was on RHEL, and upgrading the kernel solved the issue. Scary...\n\n-- \nMatthieu Moy\nhttp://www-verimag.imag.fr/~moy/\n"},{"id":"164379","messageId":"4D8E3581.6020003@selfish.org","threadId":"26849","inReplyTo":"vpq8vw1epc1.fsf@bauges.imag.fr","subject":"Re: Unable to clone via git protocol / early EOF / index-pack failed","fromName":"Holger Freyther","fromEmail":"zecke@selfish.org","sentAt":"2011-03-26T18:50:41Z","receivedAt":"2011-03-26T18:50:41Z","isPatch":false,"sender":{"key":"zecke@selfish.org","avatar":null},"body":"On 03/26/2011 06:58 PM, Matthieu Moy wrote:\n\n> \n> That reminds me an issue I had with git over SSH. The problem was indeed\n> not Git-related:\n> \n>   http://readlist.com/lists/securityfocus.com/secureshell/0/3071.html\n> \n> In short, when sending 196481 bytes or more, _and_ if the server did not\n> consume the data fast enough, then the connection was closed after\n> 65536=2^16 bytes.\n> \n> That was on RHEL, and upgrading the kernel solved the issue. Scary...\n> \n\nYes, scary. I assume that fflush(stdout) has no real meaning for sockets\neither? So the next best thing would be to use ioctl and SIOCOUTQ on the\nsocket? Any other ideas?\n"}]}