{"thread":{"id":"28056","subject":"t5800-*.sh: Intermittent test failures","startedAt":"2011-08-09T18:30:12Z","lastAt":"2011-11-03T01:30:28Z","messageCount":12,"participants":["Ramsay Jones","Sverre Rabbelier","Junio C Hamano","Jeff King","Alex Riesen"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"173217","messageId":"4E417CB4.50007@ramsay1.demon.co.uk","threadId":"28056","inReplyTo":null,"subject":"t5800-*.sh: Intermittent test failures","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsay1.demon.co.uk","sentAt":"2011-08-09T18:30:12Z","receivedAt":"2011-08-09T18:30:12Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"\nI've noticed some intermittent test failures in t5800-*.sh on Linux\nrecently. The failures (test #7 onwards) are due to a git-push to a\nremote, via the git-remote-test helper, hanging in git-fast-import.\n\ngit-bisect fingers the following commit:\n\n    a515ebe9f1ac9bc248c12a291dc008570de505ca is the first bad commit\n    commit a515ebe9f1ac9bc248c12a291dc008570de505ca\n    Author: Sverre Rabbelier <srabbelier@gmail.com>\n    Date:   Sat Jul 16 15:03:40 2011 +0200\n\n        transport-helper: implement marks location as capability\n\n        Now that the gitdir location is exported as an environment variable\n        this can be implemented elegantly without requiring any explicit\n        flushes nor an ad-hoc exchange of values.\n\n        Signed-off-by: Sverre Rabbelier <srabbelier@gmail.com>\n        Acked-by: Jeff King <peff@peff.net>\n        Signed-off-by: Junio C Hamano <gitster@pobox.com>\n\n    :100644 100644 1ed7a5651ef5a2320c56856b5a1fe784e178ab23 e9c832bfd3da7db771cc2113\n    027d3e590dc51d59 M      git-remote-testgit.py\n    :100644 100644 0cfc9ae9059ce121b567406d7941b71cd54b961c 74c3122df1835c45a6b62120\n    5fb18b4fc89af366 M      transport-helper.c\n\nwhich didn't seem too likely at first, but it does reduce the size of the\nfast-import stream (by moving the import/export marks filenames to the\ncommand line). This could change the timings enough to cause the problem.\n\nI set various environment variables (eg GIT_TRANSLOOP_DEBUG, GIT_DEBUG_TESTGIT etc)\nin order to get some additional clues, in addition to looking at the stackframe\nof all of the processes in the hung pipeline, which looks like:\n\n    git(push)->git-remote-test->git(fast-import)->git-fast-import\n\nThe git-fast-import is hung in the read() syscall waiting for data which will\nnever arrive. This is because the git(fast-export) process, started by the above\ngit(push), executes (producing it's data on stdout) and completes successfully\nand exits *before* the above git-fast-import process starts.\n\nI haven't looked to see how the git(fast-export)/git-fast-import processes are\nplumbed together, but there seems to be a synchronization problem somewhere ...\n\nUnfortunately, I don't have time at the moment to finish debugging this, so I\nwas hoping someone who knows the code better than me could fix it up ...\nThanks! :-P\n\n[I've included the stackframes (from the above pipeline) below in case it helps]\n\nATB,\nRamsay Jones\n\n\n[git-fast-import]\n(gdb) bt\n#0  0xffffe410 in __kernel_vsyscall ()\n#1  0xb7dd6033 in read () from /lib/tls/i686/cmov/libc.so.6\n#2  0xb7d774f8 in _IO_file_read () from /lib/tls/i686/cmov/libc.so.6\n#3  0xb7d788c0 in _IO_file_underflow () from /lib/tls/i686/cmov/libc.so.6\n#4  0xb7d78fbb in _IO_default_uflow () from /lib/tls/i686/cmov/libc.so.6\n#5  0xb7d7a31d in __uflow () from /lib/tls/i686/cmov/libc.so.6\n#6  0xb7d742a0 in getc () from /lib/tls/i686/cmov/libc.so.6\n#7  0x0807e203 in strbuf_getwholeline (sb=0x80e348c, fp=0xb7e53420, term=10)\n    at strbuf.c:361\n#8  0x0807e262 in strbuf_getline (sb=0x80e348c, fp=0xb7e53420, term=10)\n    at strbuf.c:376\n#9  0x0804f681 in read_next_command () at fast-import.c:1853\n#10 0x0805368b in main (argc=4, argv=0xbf8eac74) at fast-import.c:3295\n(gdb)\n\n[git(fast-import)]\n(gdb) bt\n#0  0xffffe410 in __kernel_vsyscall ()\n#1  0xb7dcf0b3 in __waitpid_nocancel () from /lib/tls/i686/cmov/libpthread.so.0\n#2  0x08129706 in wait_or_whine (pid=6200, argv0=0x81e4070 \"git-fast-import\", \n    silent_exec_failure=1) at run-command.c:105\n#3  0x0812a08f in finish_command (cmd=0xbfe42874) at run-command.c:415\n#4  0x0812a0be in run_command (cmd=0xbfe42874) at run-command.c:423\n#5  0x0812a1bf in run_command_v_opt (argv=0xbfe429dc, opt=8)\n    at run-command.c:443\n#6  0x0804c12d in execv_dashed_external (argv=0xbfe429dc) at git.c:489\n#7  0x0804c192 in run_argv (argcp=0xbfe42950, argv=0xbfe42954) at git.c:507\n#8  0x0804c321 in main (argc=4, argv=0xbfe429dc) at git.c:577\n(gdb)\n\n[git-remote-test]\n(gdb) bt\n#0  0xffffe410 in __kernel_vsyscall ()\n#1  0xb7f230b3 in __waitpid_nocancel () from /lib/tls/i686/cmov/libpthread.so.0\n#2  0x080f8fc0 in posix_waitpid (self=0x0, args=0xb7d615ec)\n    at ../Modules/posixmodule.c:5636\n... [snipped as uninteresting!]\n(gdb) \n\n[git(push)]\n(gdb) bt\n#0  0xffffe410 in __kernel_vsyscall ()\n#1  0xb7dde033 in read () from /lib/tls/i686/cmov/libc.so.6\n#2  0xb7d7f4f8 in _IO_file_read () from /lib/tls/i686/cmov/libc.so.6\n#3  0xb7d808c0 in _IO_file_underflow () from /lib/tls/i686/cmov/libc.so.6\n#4  0xb7d80fbb in _IO_default_uflow () from /lib/tls/i686/cmov/libc.so.6\n#5  0xb7d8231d in __uflow () from /lib/tls/i686/cmov/libc.so.6\n#6  0xb7d7c2a0 in getc () from /lib/tls/i686/cmov/libc.so.6\n#7  0x08138d6b in strbuf_getwholeline (sb=0xbfb662c8, fp=0x81e4760, term=10)\n    at strbuf.c:361\n#8  0x08138dca in strbuf_getline (sb=0xbfb662c8, fp=0x81e4760, term=10)\n    at strbuf.c:376\n#9  0x0813ffe3 in recvline_fh (helper=0x81e4760, buffer=0xbfb662c8)\n    at transport-helper.c:51\n#10 0x081400be in recvline (helper=0x81e44a0, buffer=0xbfb662c8)\n    at transport-helper.c:64\n#11 0x08141a6e in push_update_refs_status (data=0x81e44a0, \n    remote_refs=0x81e48e8) at transport-helper.c:652\n#12 0x08141e80 in push_refs_with_export (transport=0x81e4450, \n    remote_refs=0x81e48e8, flags=0) at transport-helper.c:759\n#13 0x08141f74 in push_refs (transport=0x81e4450, remote_refs=0x81e48e8, \n    flags=0) at transport-helper.c:783\n#14 0x0813f846 in transport_push (transport=0x81e4450, refspec_nr=1, \n    refspec=0x81e43e8, flags=0, nonfastforward=0xbfb6642c) at transport.c:1044\n#15 0x080a3bda in push_with_options (transport=0x81e4450, flags=0)\n    at builtin/push.c:131\n#16 0x080a3ea7 in do_push (repo=0x0, flags=0) at builtin/push.c:209\n#17 0x080a4377 in cmd_push (argc=0, argv=0xbfb668c8, prefix=0x0)\n    at builtin/push.c:265\n#18 0x0804bf3f in run_builtin (p=0x81977b4, argc=1, argv=0xbfb668c8)\n    at git.c:302\n#19 0x0804c0a5 in handle_internal_command (argc=1, argv=0xbfb668c8)\n    at git.c:460\n#20 0x0804c185 in run_argv (argcp=0xbfb66840, argv=0xbfb66844) at git.c:504\n#21 0x0804c321 in main (argc=1, argv=0xbfb668c8) at git.c:577\n(gdb)\n"},{"id":"173316","messageId":"CAGdFq_jv_T-x7VGqm_j-fDfeW6TsBG95=1TWn91Yk9B3TGZdsQ@mail.gmail.com","threadId":"28056","inReplyTo":"4E417CB4.50007@ramsay1.demon.co.uk","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Sverre Rabbelier","fromEmail":"srabbelier@gmail.com","sentAt":"2011-08-11T21:39:21Z","receivedAt":"2011-08-11T21:39:21Z","isPatch":false,"sender":{"key":"srabbelier@gmail.com","avatar":"https://avatars.githubusercontent.com/u/3098?v=4"},"body":"Heya,\n\nOn Tue, Aug 9, 2011 at 20:30, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n> The git-fast-import is hung in the read() syscall waiting for data which will\n> never arrive. This is because the git(fast-export) process, started by the above\n> git(push), executes (producing it's data on stdout) and completes successfully\n> and exits *before* the above git-fast-import process starts.\n>\n> I haven't looked to see how the git(fast-export)/git-fast-import processes are\n> plumbed together, but there seems to be a synchronization problem somewhere ...\n\nThis seems odd, before the fast-export process is even started it's\nstdout are wired to the stdin of the helper (and thus the fast-import\nprocess). What indication do you have that fast-import hasn't started\nand that fast-export has finished?\n\nAlso, you say git remote-test everywhere, but it should be git\nremote-testgit, typo?\n\n-- \nCheers,\n\nSverre Rabbelier\n"},{"id":"173468","messageId":"4E46E3C4.7020608@ramsay1.demon.co.uk","threadId":"28056","inReplyTo":"CAGdFq_jv_T-x7VGqm_j-fDfeW6TsBG95=1TWn91Yk9B3TGZdsQ@mail.gmail.com","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsay1.demon.co.uk","sentAt":"2011-08-13T20:51:16Z","receivedAt":"2011-08-13T20:51:16Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"Sverre Rabbelier wrote:\n>> I haven't looked to see how the git(fast-export)/git-fast-import processes are\n>> plumbed together, but there seems to be a synchronization problem somewhere ...\n> \n> This seems odd, before the fast-export process is even started it's\n> stdout are wired to the stdin of the helper (and thus the fast-import\n> process). What indication do you have that fast-import hasn't started\n> and that fast-export has finished?\n\nI indulged in a spot of \"printf debugging\". ;-)  see more below.\n\n> Also, you say git remote-test everywhere, but it should be git\n> remote-testgit, typo?\n\nYep. [It was actually caused by a cut/paste/edit of pstree output (pstree\ntruncates long fields); not that you could guess that! ;-P ]\n\nSo ...\n\nI added some additional debug code to transport-helper.c (see below) in\naddition to creating debug output files from the git-fast-import/export\ncommands. (I won't show the code for this debug output; it wouldn't be\nhard to imagine! :-)\n\nIn addition to the uninteresting \"printf debugging\" info, I used\ngettimeofday() to show the start and end times for the git(fast-export)\nprocess and the start time for git-fast-import. The last hunk below,\nfor instance, shows the code to output the git(fast-export) end time ...\n\n--- >8 ----\ndiff --git a/transport-helper.c b/transport-helper.c\nindex 74c3122..7c9d881 100644\n--- a/transport-helper.c\n+++ b/transport-helper.c\n@@ -132,6 +132,8 @@ static struct child_process *get_helper(struct transport *transport)\n \tsnprintf(git_dir_buf, sizeof(git_dir_buf), \"%s=%s\", GIT_DIR_ENVIRONMENT, get_git_dir());\n \thelper->env = helper_env;\n \n+\tif (debug)\n+\t\tfprintf(stderr, \"Debug: start remote helper: <%s>\\n\", helper->argv[0]);\n \tcode = start_command(helper);\n \tif (code < 0 && errno == ENOENT)\n \t\tdie(\"Unable to find remote helper for '%s'\", data->name);\n@@ -376,6 +378,8 @@ static int get_importer(struct transport *transport, struct child_process *fasti\n \tfastimport->argv[1] = \"--quiet\";\n \n \tfastimport->git_cmd = 1;\n+\tif (debug)\n+\t\tfprintf(stderr, \"Debug: get_importer, start fast-import\\n\");\n \treturn start_command(fastimport);\n }\n \n@@ -403,6 +407,8 @@ static int get_exporter(struct transport *transport,\n \t\tfastexport->argv[argc++] = revlist_args->items[i].string;\n \n \tfastexport->git_cmd = 1;\n+\tif (debug)\n+\t\tfprintf(stderr, \"Debug: get_exporter, start fast-export\\n\");\n \treturn start_command(fastexport);\n }\n \n@@ -756,6 +762,11 @@ static int push_refs_with_export(struct transport *transport,\n \n \tif (finish_command(&exporter))\n \t\tdie(\"Error while running fast-export\");\n+\tif (debug) {\n+\t\tstruct timeval tv;\n+\t\tgettimeofday(&tv, NULL);\n+\t\tfprintf(stderr, \"fast-export finished @ %lds %ldus\\n\", tv.tv_sec, tv.tv_usec);\n+\t}\n \tpush_update_refs_status(data, remote_refs);\n \treturn 0;\n }\n--- >8 ----\n\nThe debug output from \"./t5800-remote-helpers.sh -v\" ends like this:\n\n... [snipped]\nDebug: Capabilities complete.\nDebug: Remote helper: Waiting...\nGot command 'list' with args ''\n? refs/heads/new\n? refs/heads/master\n@refs/heads/master HEAD\nDebug: Remote helper: <- ? refs/heads/new\nDebug: Remote helper: Waiting...\nDebug: Remote helper: <- ? refs/heads/master\nDebug: Remote helper: Waiting...\nDebug: Remote helper: <- @refs/heads/master HEAD\nDebug: Remote helper: Waiting...\nDebug: Remote helper: <- \nDebug: Read ref listing.\nDebug: Remote helper: -> export\nDebug: get_exporter, start fast-export\nfast-export finished @ 1313178956s 366398us\nDebug: Remote helper: Waiting...\nGot command 'export' with args ''\n\nThe fast-export debug file looks like:\n\n--- >8 ----\nfast-export: pid = 11096 (ppid 11090)\nstarted @ 1313178956s 364790us\narg: <fast-export>\narg: <--use-done-feature>\narg: <--export-marks=.git/info/fast-import/a08486a77c5cf1b4aa17fa9e64673e352ebe1a96/testgit.marks>\narg: <--import-marks=.git/info/fast-import/a08486a77c5cf1b4aa17fa9e64673e352ebe1a96/testgit.marks>\narg: <^refs/testgit/origin/master>\narg: <refs/heads/master>\n----end args----: <>\nhandle object: <ab28ce7f215103f3f4bf70fd439541590dccc91b>\nhandle commit: <refs/heads/master>\nmain: <done!>\n--- >8 ----\n\nThe fast-import debug file looks like:\n\n--- >8 ----\nfast-import: pid = 11104 (ppid = 11103)\nstarted @ 1313178956s 382392us\nmain: <start-up>\nmain: <start-up #1>\nmain: <before loop>\n--- >8 ----\n\nNote that git(fast-export) executes in 1608 micro-seconds and finishes\n15994 micro-seconds before git-fast-import starts.\n\nATB,\nRamsay Jones\n"},{"id":"174823","messageId":"7vpqjgyvn1.fsf@alter.siamese.dyndns.org","threadId":"28056","inReplyTo":"CAGdFq_jv_T-x7VGqm_j-fDfeW6TsBG95=1TWn91Yk9B3TGZdsQ@mail.gmail.com","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2011-09-04T19:06:58Z","receivedAt":"2011-09-04T19:06:58Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Sverre Rabbelier <srabbelier@gmail.com> writes:\n\n> Heya,\n>\n> On Tue, Aug 9, 2011 at 20:30, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n>> The git-fast-import is hung in the read() syscall waiting for data which will\n>> never arrive. This is because the git(fast-export) process, started by the above\n>> git(push), executes (producing it's data on stdout) and completes successfully\n>> and exits *before* the above git-fast-import process starts.\n>>\n>> I haven't looked to see how the git(fast-export)/git-fast-import processes are\n>> plumbed together, but there seems to be a synchronization problem somewhere ...\n>\n> This seems odd, before the fast-export process is even started it's\n> stdout are wired to the stdin of the helper (and thus the fast-import\n> process). What indication do you have that fast-import hasn't started\n> and that fast-export has finished?\n>\n> Also, you say git remote-test everywhere, but it should be git\n> remote-testgit, typo?\n\nFWIW, I have been seeing this every once in a while.\n"},{"id":"175128","messageId":"4E68FE73.4000005@ramsay1.demon.co.uk","threadId":"28056","inReplyTo":"7vpqjgyvn1.fsf@alter.siamese.dyndns.org","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsay1.demon.co.uk","sentAt":"2011-09-08T17:42:11Z","receivedAt":"2011-09-08T17:42:11Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"Junio C Hamano wrote:\n> Sverre Rabbelier <srabbelier@gmail.com> writes:\n>> On Tue, Aug 9, 2011 at 20:30, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n>>> The git-fast-import is hung in the read() syscall waiting for data which will\n>>> never arrive. This is because the git(fast-export) process, started by the above\n>>> git(push), executes (producing it's data on stdout) and completes successfully\n>>> and exits *before* the above git-fast-import process starts.\n>>>\n>>> I haven't looked to see how the git(fast-export)/git-fast-import processes are\n>>> plumbed together, but there seems to be a synchronization problem somewhere ...\n>> This seems odd, before the fast-export process is even started it's\n>> stdout are wired to the stdin of the helper (and thus the fast-import\n>> process). What indication do you have that fast-import hasn't started\n>> and that fast-export has finished?\n>>\n>> Also, you say git remote-test everywhere, but it should be git\n>> remote-testgit, typo?\n> \n> FWIW, I have been seeing this every once in a while.\n\nGood to know I'm not alone ;-P\n\nUnfortunately, I haven't had the time to debug this further than I've\nalready reported ...\n\nAs I said, it's obviously a process plumbing/synchronization problem; the reading\nend of the fast-export output pipe must be open for read by someone (probably by\nit's parent), otherwise it would receive SIGPIPE (also, the output is small enough\nnot to fill the pipe) rather than exiting with success.\n\nWhen I run the tests with \"make test >test-out\", I see a failure rate of about\n1 in 10. If I then set the debug environment variables (GIT_TRANSPORT_HELPER_DEBUG,\nGIT_TRANSLOOP_DEBUG and GIT_DEBUG_TESTGIT) and run the test script directly (-v),\nthen the failure rate goes up to about 1 in 3.\n\nWell, ... I added debug code to git-fast-{im,ex}port which writes the debug info\nto a file (can't write to stdout/stderr obviously), so that may well be affecting\nthe timing enough to increase the chance of a failure. Having said that, If I'm\nlistening to music (rhythmbox) at the same time, then the failure rate seems to\nincrease ...\n\nATB,\nRamsay Jones\n"},{"id":"175130","messageId":"20110908182055.GA16500@sigill.intra.peff.net","threadId":"28056","inReplyTo":"4E68FE73.4000005@ramsay1.demon.co.uk","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2011-09-08T18:20:55Z","receivedAt":"2011-09-08T18:20:55Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Sep 08, 2011 at 06:42:11PM +0100, Ramsay Jones wrote:\n\n> When I run the tests with \"make test >test-out\", I see a failure rate of about\n> 1 in 10. If I then set the debug environment variables (GIT_TRANSPORT_HELPER_DEBUG,\n> GIT_TRANSLOOP_DEBUG and GIT_DEBUG_TESTGIT) and run the test script directly (-v),\n> then the failure rate goes up to about 1 in 3.\n\nHmm. I can't reproduce a failure here, but I do get some weirdness. My\nrecipe is:\n\n-- >8 --\ncat >foo.sh <<\\EOF\n#!/bin/sh\n\nexec >$1.out 2>&1\n\nn=0\nwhile test $n -lt 100; do\n\tn=$(($n+1))\n\tGIT_TRANSPORT_HELPER_DEBUG=1 \\\n\tGIT_TRANSLOOP_DEBUG=1 \\\n\tGIT_DEBUG_TESTGIT=1 \\\n\t./t5800-remote-helpers.sh --root=/run/shm/git-tests-$1 -v || {\n\t\techo FAIL $n\n\t\texit 1\n\t}\n\techo OK $n\ndone\nEOF\n\n# try to keep an 8-core machine busy\nfor i in `seq 1 16`; do\n  sh foo.sh $i &\ndone\n-- 8< --\n\nI never see a test failure, but a few of the 16 end up hanging. The\nprocess tree for the hanged tests look like:\n\n  t5800-remote-helper\n    git push\n      git-remote-testgit\n        git fast-import\n          git-fast-import\n\nAll of them are blocked on wait(), except for the final fast-import,\nwhich is blocked trying to read() from stdin.\n\n-Peff\n"},{"id":"175302","messageId":"4E6D089C.4090006@ramsay1.demon.co.uk","threadId":"28056","inReplyTo":"20110908182055.GA16500@sigill.intra.peff.net","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Ramsay Jones","fromEmail":"ramsay@ramsay1.demon.co.uk","sentAt":"2011-09-11T19:14:36Z","receivedAt":"2011-09-11T19:14:36Z","isPatch":false,"sender":{"key":"ramsay@ramsayjones.plus.com","avatar":"https://avatars.githubusercontent.com/u/33702710?v=4"},"body":"Jeff King wrote:\n> On Thu, Sep 08, 2011 at 06:42:11PM +0100, Ramsay Jones wrote:\n> \n>> When I run the tests with \"make test >test-out\", I see a failure rate of about\n>> 1 in 10. If I then set the debug environment variables (GIT_TRANSPORT_HELPER_DEBUG,\n>> GIT_TRANSLOOP_DEBUG and GIT_DEBUG_TESTGIT) and run the test script directly (-v),\n>> then the failure rate goes up to about 1 in 3.\n> \n> Hmm. I can't reproduce a failure here, but I do get some weirdness. My\n> recipe is:\n\nAh, sorry, ... I didn't make myself clear then, because ...\n\n> -- >8 --\n> cat >foo.sh <<\\EOF\n> #!/bin/sh\n> \n> exec >$1.out 2>&1\n> \n> n=0\n> while test $n -lt 100; do\n> \tn=$(($n+1))\n> \tGIT_TRANSPORT_HELPER_DEBUG=1 \\\n> \tGIT_TRANSLOOP_DEBUG=1 \\\n> \tGIT_DEBUG_TESTGIT=1 \\\n> \t./t5800-remote-helpers.sh --root=/run/shm/git-tests-$1 -v || {\n> \t\techo FAIL $n\n> \t\texit 1\n> \t}\n> \techo OK $n\n> done\n> EOF\n> \n> # try to keep an 8-core machine busy\n> for i in `seq 1 16`; do\n>   sh foo.sh $i &\n> done\n> -- 8< --\n> \n> I never see a test failure, but a few of the 16 end up hanging. The\n> process tree for the hanged tests look like:\n> \n>   t5800-remote-helper\n>     git push\n>       git-remote-testgit\n>         git fast-import\n>           git-fast-import\n> \n> All of them are blocked on wait(), except for the final fast-import,\n> which is blocked trying to read() from stdin.\n\n... these hangs *are* the failures of which I speak!  Yes, the script\ndoesn't get to declare a failure, but AFAIAC a hanging test (and it\nisn't the same test # each time) is a failing test. :-D\n\nATB,\nRamsay Jones\n"},{"id":"178653","messageId":"CALxABCbnZp-y0Fqzoa=Ab92P+hsT7hs3nXZsnA=ph3yGfkXhdA@mail.gmail.com","threadId":"28056","inReplyTo":"4E6D089C.4090006@ramsay1.demon.co.uk","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2011-11-01T21:57:21Z","receivedAt":"2011-11-01T21:57:21Z","isPatch":false,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"On Sun, Sep 11, 2011 at 21:14, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n> ... these hangs *are* the failures of which I speak!  Yes, the script\n> doesn't get to declare a failure, but AFAIAC a hanging test (and it\n> isn't the same test # each time) is a failing test. :-D\n\nWas there any outcome of this discussion? I'm asking because I\ncan reproduce this very reliably on a little server here.\n"},{"id":"178654","messageId":"7vfwi7lc54.fsf@alter.siamese.dyndns.org","threadId":"28056","inReplyTo":"CALxABCbnZp-y0Fqzoa=Ab92P+hsT7hs3nXZsnA=ph3yGfkXhdA@mail.gmail.com","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2011-11-01T22:18:47Z","receivedAt":"2011-11-01T22:18:47Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Alex Riesen <raa.lkml@gmail.com> writes:\n\n> On Sun, Sep 11, 2011 at 21:14, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n>> ... these hangs *are* the failures of which I speak!  Yes, the script\n>> doesn't get to declare a failure, but AFAIAC a hanging test (and it\n>> isn't the same test # each time) is a failing test. :-D\n>\n> Was there any outcome of this discussion? I'm asking because I\n> can reproduce this very reliably on a little server here.\n\nI do remember this discussion and recall seeing _no_ outcome.\n\nI did see the hang myself once or twice but did not and do not have a\nreliable reproduction. I have been waiting for somebody to raise the issue\nagain ;-).\n"},{"id":"178662","messageId":"CALxABCbKSi-aHezjyn5wJ0-BPW1PvvaC2i9VeV7yXOf4yCdx4Q@mail.gmail.com","threadId":"28056","inReplyTo":"7vfwi7lc54.fsf@alter.siamese.dyndns.org","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2011-11-01T23:02:29Z","receivedAt":"2011-11-01T23:02:29Z","isPatch":false,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"On Tue, Nov 1, 2011 at 23:18, Junio C Hamano <gitster@pobox.com> wrote:\n> Alex Riesen <raa.lkml@gmail.com> writes:\n>\n>> On Sun, Sep 11, 2011 at 21:14, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n>>> ... these hangs *are* the failures of which I speak!  Yes, the script\n>>> doesn't get to declare a failure, but AFAIAC a hanging test (and it\n>>> isn't the same test # each time) is a failing test. :-D\n>>\n>> Was there any outcome of this discussion? I'm asking because I\n>> can reproduce this very reliably on a little server here.\n>\n> I do remember this discussion and recall seeing _no_ outcome.\n>\n> I did see the hang myself once or twice but did not and do not have a\n> reliable reproduction. I have been waiting for somebody to raise the issue\n> again ;-).\n>\n\nI think I managed to bisect it (between 1.7.6 and 1.7.7):\n\n$ git bisect start v1.7.7 v1.7.6\n...\n$ git bisect good\na515ebe9f1ac9bc248c12a291dc008570de505ca is the first bad commit\ncommit a515ebe9f1ac9bc248c12a291dc008570de505ca\nAuthor: Sverre Rabbelier <srabbelier@gmail.com>\nDate:   Sat Jul 16 15:03:40 2011 +0200\n\n    transport-helper: implement marks location as capability\n\n    Now that the gitdir location is exported as an environment variable\n    this can be implemented elegantly without requiring any explicit\n    flushes nor an ad-hoc exchange of values.\n\n    Signed-off-by: Sverre Rabbelier <srabbelier@gmail.com>\n    Acked-by: Jeff King <peff@peff.net>\n    Signed-off-by: Junio C Hamano <gitster@pobox.com>\n\n:100644 100644 1ed7a5651ef5a2320c56856b5a1fe784e178ab23\ne9c832bfd3da7db771cc2113027d3e590dc51d59 M\tgit-remote-testgit.py\n:100644 100644 0cfc9ae9059ce121b567406d7941b71cd54b961c\n74c3122df1835c45a6b621205fb18b4fc89af366 M\ttransport-helper.c\n\nSadly, I'm going to be able to repeat the test in about 20 hours.\n"},{"id":"178736","messageId":"CAGdFq_h+Hpv9perLTU2rbdT6oZ3kZy22t5nghJQeEjNGvunL+A@mail.gmail.com","threadId":"28056","inReplyTo":"CALxABCbKSi-aHezjyn5wJ0-BPW1PvvaC2i9VeV7yXOf4yCdx4Q@mail.gmail.com","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Sverre Rabbelier","fromEmail":"srabbelier@gmail.com","sentAt":"2011-11-02T23:35:12Z","receivedAt":"2011-11-02T23:35:12Z","isPatch":false,"sender":{"key":"srabbelier@gmail.com","avatar":"https://avatars.githubusercontent.com/u/3098?v=4"},"body":"Heya,\n\nOn Wed, Nov 2, 2011 at 00:02, Alex Riesen <raa.lkml@gmail.com> wrote:\n> On Tue, Nov 1, 2011 at 23:18, Junio C Hamano <gitster@pobox.com> wrote:\n>> Alex Riesen <raa.lkml@gmail.com> writes:\n>>\n>>> On Sun, Sep 11, 2011 at 21:14, Ramsay Jones <ramsay@ramsay1.demon.co.uk> wrote:\n>>>> ... these hangs *are* the failures of which I speak!  Yes, the script\n>>>> doesn't get to declare a failure, but AFAIAC a hanging test (and it\n>>>> isn't the same test # each time) is a failing test. :-D\n>>>\n>>> Was there any outcome of this discussion? I'm asking because I\n>>> can reproduce this very reliably on a little server here.\n>>\n>> I do remember this discussion and recall seeing _no_ outcome.\n>>\n>> I did see the hang myself once or twice but did not and do not have a\n>> reliable reproduction. I have been waiting for somebody to raise the issue\n>> again ;-).\n>>\n>\n> I think I managed to bisect it (between 1.7.6 and 1.7.7):\n>\n> $ git bisect start v1.7.7 v1.7.6\n> ...\n> $ git bisect good\n> a515ebe9f1ac9bc248c12a291dc008570de505ca is the first bad commit\n> commit a515ebe9f1ac9bc248c12a291dc008570de505ca\n> Author: Sverre Rabbelier <srabbelier@gmail.com>\n> Date:   Sat Jul 16 15:03:40 2011 +0200\n>\n>    transport-helper: implement marks location as capability\n>\n>    Now that the gitdir location is exported as an environment variable\n>    this can be implemented elegantly without requiring any explicit\n>    flushes nor an ad-hoc exchange of values.\n>\n>    Signed-off-by: Sverre Rabbelier <srabbelier@gmail.com>\n>    Acked-by: Jeff King <peff@peff.net>\n>    Signed-off-by: Junio C Hamano <gitster@pobox.com>\n>\n> :100644 100644 1ed7a5651ef5a2320c56856b5a1fe784e178ab23\n> e9c832bfd3da7db771cc2113027d3e590dc51d59 M      git-remote-testgit.py\n> :100644 100644 0cfc9ae9059ce121b567406d7941b71cd54b961c\n> 74c3122df1835c45a6b621205fb18b4fc89af366 M      transport-helper.c\n>\n> Sadly, I'm going to be able to repeat the test in about 20 hours.\n\nÆvar, this seems like something we could look at during the mini\nGitTogether in Amsterdam this Saturday, no?\n\n-- \nCheers,\n\nSverre Rabbelier\n"},{"id":"178743","messageId":"7vobwugfgr.fsf@alter.siamese.dyndns.org","threadId":"28056","inReplyTo":"CAGdFq_h+Hpv9perLTU2rbdT6oZ3kZy22t5nghJQeEjNGvunL+A@mail.gmail.com","subject":"Re: t5800-*.sh: Intermittent test failures","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2011-11-03T01:30:28Z","receivedAt":"2011-11-03T01:30:28Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Sverre Rabbelier <srabbelier@gmail.com> writes:\n\n> Ævar, this seems like something we could look at during the mini\n> GitTogether in Amsterdam this Saturday, no?\n\nHave fun.\n\nI think I happened to hit this while testing today's 'pu' that hasn't been\npushed out. The process chain looks like this:\n\npid  command                     stuck at\n4767 sh t5800-remote-helpers.sh  wait4(-1)\n 4793 git push                   read(6)\n  4809 git-remote-testgit        wait4(4906)\n   4906 git fast-import          wait4(4912)\n    4912 git-fast-import         read(0)\n\nlr-x------ 1 junio junio 64 Nov  2 18:21 /proc/4793/fd/6 -> pipe:[133037701]\nl-wx------ 1 junio junio 64 Nov  2 18:21 /proc/4793/fd/7 -> pipe:[133037700]\nlr-x------ 1 junio junio 64 Nov  2 18:21 /proc/4793/fd/8 -> pipe:[133037701]\nlr-x------ 1 junio junio 64 Nov  2 18:05 /proc/4809/fd/0 -> pipe:[133037700]\nl-wx------ 1 junio junio 64 Nov  2 18:05 /proc/4809/fd/1 -> pipe:[133037701]\nlr-x------ 1 junio junio 64 Nov  2 18:05 /proc/4906/fd/0 -> pipe:[133037700]\nl-wx------ 1 junio junio 64 Nov  2 18:05 /proc/4906/fd/1 -> pipe:[133037701]\nlr-x------ 1 junio junio 64 Nov  2 18:03 /proc/4912/fd/0 -> pipe:[133037700]\nl-wx------ 1 junio junio 64 Nov  2 18:03 /proc/4912/fd/1 -> pipe:[133037701]\n\nSo \"git push (4793)\" is stuck reading from pipe:[133037701], expecting the\ninnermost \"git-fast-import (4912)\" to write to it via its standard output,\nbut the latter is waiting to read from pipe:[133037700], hoping the former\nto write to it via its fd#7.\n\nDoes this deadlock ring a bell to anybody who's involved in these\ncodepaths?\n"}]}