{"thread":{"id":"52373","subject":"[PATCH] t9300-fast-import: don't hang if background fast-import exits too early","startedAt":"2019-11-30T10:46:53Z","lastAt":"2019-12-06T19:03:44Z","messageCount":7,"participants":["SZEDER Gábor","Junio C Hamano"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"387331","messageId":"20191130104644.17350-1-szeder.dev@gmail.com","threadId":"52373","inReplyTo":null,"subject":"[PATCH] t9300-fast-import: don't hang if background fast-import exits too early","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-11-30T10:46:44Z","receivedAt":"2019-11-30T10:46:53Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"The five tests checking 'git fast-import's checkpoint handling in\n't9300-fast-import.sh', all with the prefix \"V:\" in their test\ndescription, can hang indefinitely if 'git fast-import' unexpectedly\ndies early in any of these tests.\n\nThese five tests run 'git fast-import' in the background, while\nfeeding instructions to its standard input through a fifo from a\nbackground subshell, and reading and verifying its standard output\nthrough another fifo in the test script's main shell process.  This\n\"reading and verifying\" is basically a 'while read ...' shell loop\niterating until 'git fast-import' outputs the expected line, ignoring\nany other output.  This doesn't work very well when 'git fast-import'\ndies before printing that particular line, because the 'read' builtin\ndoesn't get EOF after the death of 'git fast-import', as their input\nand output are not connected directly but through a fifo.\nConsequently, that 'read' hangs waiting for the next line from the\nalready dead 'git fast-import', leaving the test script and in turn\nthe whole test suite hanging.\n\nAvoid this hang by checking whether the background 'git fast-import'\nprocess exited unexpectedly early, and interrupt the 'while read' loop\nif it did.  We have to jump through some hoops to achive that, though:\n\n  - Start the background 'git fast-import' in another background\n    subshell, which then waits until that 'git fast-import' process\n    exits.  If it does exit, then report its exit code, and write a\n    message to the fifo used for 'git fast-import's standard output,\n    thus un-block the 'read' builtin in the main shell process.\n\n  - Modify that 'while read' loop to break the loop upon seeing that\n    message, and fail the test in the usual way.\n\n  - Once the test is finished kill that background subshell as well,\n    and do so before killing the background 'git fast-import'.\n    Otherwise the background 'git fast-import' and subshell would die\n    racily, and if 'git fast-import' were to die sooner, then we might\n    get some undesired and potentially confusing messages in the\n    test's output.\n\nSigned-off-by: SZEDER Gábor <szeder.dev@gmail.com>\n---\n t/t9300-fast-import.sh | 23 +++++++++++++++++------\n 1 file changed, 17 insertions(+), 6 deletions(-)\n\ndiff --git a/t/t9300-fast-import.sh b/t/t9300-fast-import.sh\nindex e707fb861e..dcfaa9cc36 100755\n--- a/t/t9300-fast-import.sh\n+++ b/t/t9300-fast-import.sh\n@@ -3148,63 +3148,74 @@ test_expect_success 'U: validate root delete result' '\n # The commands in input_file should not produce any output on the file\n # descriptor set with --cat-blob-fd (or stdout if unspecified).\n #\n # To make sure you're observing the side effects of checkpoint *before*\n # fast-import terminates (and thus writes out its state), check that the\n # fast-import process is still running using background_import_still_running\n # *after* evaluating the test conditions.\n background_import_then_checkpoint () {\n \toptions=$1\n \tinput_file=$2\n \n \tmkfifo V.input\n \texec 8<>V.input\n \trm V.input\n \n \tmkfifo V.output\n \texec 9<>V.output\n \trm V.output\n \n-\tgit fast-import $options <&8 >&9 &\n-\techo $! >V.pid\n+\t(\n+\t\tgit fast-import $options <&8 >&9 &\n+\t\techo $! >V.fi.pid\n+\t\twait $!\n+\t\techo >&2 \"background fast-import terminated too early with exit code $?\"\n+\t\t# Un-block the read loop in the main shell process.\n+\t\techo >&9 UNEXPECTED\n+\t) &\n+\techo $! >V.sh.pid\n \t# We don't mind if fast-import has already died by the time the test\n \t# ends.\n-\ttest_when_finished \"\n+\ttest_when_finished '\n \t\texec 8>&-; exec 9>&-;\n-\t\tkill $(cat V.pid) && wait $(cat V.pid)\n-\t\ttrue\"\n+\t\tkill $(cat V.sh.pid) && wait $(cat V.sh.pid)\n+\t\tkill $(cat V.fi.pid) && wait $(cat V.sh.pid)\n+\t\ttrue'\n \n \t# Start in the background to ensure we adhere strictly to (blocking)\n \t# pipes writing sequence. We want to assume that the write below could\n \t# block, e.g. if fast-import blocks writing its own output to &9\n \t# because there is no reader on &9 yet.\n \t(\n \t\tcat \"$input_file\"\n \t\techo \"checkpoint\"\n \t\techo \"progress checkpoint\"\n \t) >&8 &\n \n \terror=1 ;# assume the worst\n \twhile read output <&9\n \tdo\n \t\tif test \"$output\" = \"progress checkpoint\"\n \t\tthen\n \t\t\terror=0\n \t\t\tbreak\n+\t\telif test \"$output\" = \"UNEXPECTED\"\n+\t\tthen\n+\t\t\tbreak\n \t\tfi\n \t\t# otherwise ignore cruft\n \t\techo >&2 \"cruft: $output\"\n \tdone\n \n \tif test $error -eq 1\n \tthen\n \t\tfalse\n \tfi\n }\n \n background_import_still_running () {\n-\tif ! kill -0 \"$(cat V.pid)\"\n+\tif ! kill -0 \"$(cat V.fi.pid)\"\n \tthen\n \t\techo >&2 \"background fast-import terminated too early\"\n \t\tfalse\n \tfi\n }\n-- \n2.24.0.643.gac013444ca\n\n"},{"id":"387350","messageId":"xmqqsgm512vl.fsf@gitster-ct.c.googlers.com","threadId":"52373","inReplyTo":"20191130104644.17350-1-szeder.dev@gmail.com","subject":"Re: [PATCH] t9300-fast-import: don't hang if background fast-import exits too early","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-11-30T21:16:30Z","receivedAt":"2019-11-30T21:17:45Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"SZEDER Gábor <szeder.dev@gmail.com> writes:\n\n> +\t(\n> +\t\tgit fast-import $options <&8 >&9 &\n> +\t\techo $! >V.fi.pid\n> +\t\twait $!\n> +\t\techo >&2 \"background fast-import terminated too early with exit code $?\"\n> +\t\t# Un-block the read loop in the main shell process.\n> +\t\techo >&9 UNEXPECTED\n> +\t) &\n> +\techo $! >V.sh.pid\n>  \t# We don't mind if fast-import has already died by the time the test\n>  \t# ends.\n> -\ttest_when_finished \"\n> +\ttest_when_finished '\n>  \t\texec 8>&-; exec 9>&-;\n> -\t\tkill $(cat V.pid) && wait $(cat V.pid)\n> -\t\ttrue\"\n> +\t\tkill $(cat V.sh.pid) && wait $(cat V.sh.pid)\n> +\t\tkill $(cat V.fi.pid) && wait $(cat V.sh.pid)\n> +\t\ttrue'\n\nThe original interpolates the PID of the fast-import when\n\"when-finished\" program is registered, so it is OK if somebody else\nremoved V.pid file; the new one interpolates when \"when-finished\"\nprogram is run, reading from V.??.pid, so somebody needs to make\nsure these pid files will stay around.  I do not think it is an\nissue as I suspect we've left it to the global clean-up procedure\nthat removes the trash directory to remove the pid file.\n\nBy the way, does the second \"kill && wait\" wait for the right\nprocess?\n\n>  background_import_still_running () {\n> -\tif ! kill -0 \"$(cat V.pid)\"\n> +\tif ! kill -0 \"$(cat V.fi.pid)\"\n>  \tthen\n>  \t\techo >&2 \"background fast-import terminated too early\"\n>  \t\tfalse\n>  \tfi\n>  }\n"},{"id":"387370","messageId":"20191201093148.GH23183@szeder.dev","threadId":"52373","inReplyTo":"xmqqsgm512vl.fsf@gitster-ct.c.googlers.com","subject":"Re: [PATCH] t9300-fast-import: don't hang if background fast-import exits too early","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-12-01T09:31:48Z","receivedAt":"2019-12-01T09:33:15Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"On Sat, Nov 30, 2019 at 01:16:30PM -0800, Junio C Hamano wrote:\n> SZEDER Gábor <szeder.dev@gmail.com> writes:\n> \n> > +\t(\n> > +\t\tgit fast-import $options <&8 >&9 &\n> > +\t\techo $! >V.fi.pid\n> > +\t\twait $!\n> > +\t\techo >&2 \"background fast-import terminated too early with exit code $?\"\n> > +\t\t# Un-block the read loop in the main shell process.\n> > +\t\techo >&9 UNEXPECTED\n> > +\t) &\n> > +\techo $! >V.sh.pid\n> >  \t# We don't mind if fast-import has already died by the time the test\n> >  \t# ends.\n> > -\ttest_when_finished \"\n> > +\ttest_when_finished '\n> >  \t\texec 8>&-; exec 9>&-;\n> > -\t\tkill $(cat V.pid) && wait $(cat V.pid)\n> > -\t\ttrue\"\n> > +\t\tkill $(cat V.sh.pid) && wait $(cat V.sh.pid)\n> > +\t\tkill $(cat V.fi.pid) && wait $(cat V.sh.pid)\n> > +\t\ttrue'\n> \n> The original interpolates the PID of the fast-import when\n> \"when-finished\" program is registered, so it is OK if somebody else\n> removed V.pid file; the new one interpolates when \"when-finished\"\n> program is run, reading from V.??.pid, so somebody needs to make\n> sure these pid files will stay around.  I do not think it is an\n> issue as I suspect we've left it to the global clean-up procedure\n> that removes the trash directory to remove the pid file.\n\nIn the original the same shell process starts 'git fast-import',\nwrites its pidfile, and registers the test_when_finished commands, so\nwe can be sure that the pid file is already present when the shell\nruns the $(cat V.pid) command substitutions.\n\nWith this patch that's not the case anymore, because the background\nsubshell starts 'git fast-import' and writes the pidfile, but the main\nshell process registers the test_when_finished commands.  IOW these\ntwo shell processes are racing, and it's possible that the\ntest_when_finished command is executed before the background subshell\ncan write the pidfile.  So double quotes around the block of\ntest_when_finished commands are not good.\n\n> By the way, does the second \"kill && wait\" wait for the right\n> process?\n\nOuch, it clearly doesn't.  Copy-paste error I suppose.\nThanks for spotting it.\n\n> \n> >  background_import_still_running () {\n> > -\tif ! kill -0 \"$(cat V.pid)\"\n> > +\tif ! kill -0 \"$(cat V.fi.pid)\"\n> >  \tthen\n> >  \t\techo >&2 \"background fast-import terminated too early\"\n> >  \t\tfalse\n> >  \tfi\n> >  }\n"},{"id":"387375","messageId":"xmqq36e412er.fsf@gitster-ct.c.googlers.com","threadId":"52373","inReplyTo":"20191201093148.GH23183@szeder.dev","subject":"Re: [PATCH] t9300-fast-import: don't hang if background fast-import exits too early","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-12-01T15:38:52Z","receivedAt":"2019-12-01T15:39:16Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"SZEDER Gábor <szeder.dev@gmail.com> writes:\n\n>> > -\ttest_when_finished \"\n>> > +\ttest_when_finished '\n>> >  \t\texec 8>&-; exec 9>&-;\n>> > -\t\tkill $(cat V.pid) && wait $(cat V.pid)\n>> > -\t\ttrue\"\n>> > +\t\tkill $(cat V.sh.pid) && wait $(cat V.sh.pid)\n>> > +\t\tkill $(cat V.fi.pid) && wait $(cat V.sh.pid)\n>> > +\t\ttrue'\n>> \n>> The original interpolates the PID of the fast-import when\n>> \"when-finished\" program is registered, so it is OK if somebody else\n>> removed V.pid file; the new one interpolates when \"when-finished\"\n>> program is run, reading from V.??.pid, so somebody needs to make\n>> sure these pid files will stay around.  I do not think it is an\n>> issue as I suspect we've left it to the global clean-up procedure\n>> that removes the trash directory to remove the pid file.\n>\n> In the original the same shell process starts 'git fast-import',\n> writes its pidfile, and registers the test_when_finished commands, so\n> we can be sure that the pid file is already present when the shell\n> runs the $(cat V.pid) command substitutions.\n\nYes.  It also means that V.pid file was not very useful in the\nwhen-finished handler in the original.  We could have just used a\nshell variable.\n\n> With this patch that's not the case anymore, because the background\n> subshell starts 'git fast-import' and writes the pidfile, but the main\n> shell process registers the test_when_finished commands.  IOW these\n> two shell processes are racing, and it's possible that the\n> test_when_finished command is executed before the background subshell\n> can write the pidfile.  So double quotes around the block of\n> test_when_finished commands are not good.\n\nOh, I was not questioning that.  I wanted to make sure, and I was\ndoing so aloud, that these files are\n\n (1) created way before, and \n (2) left on the filesystem\n\nwhen-finished handler actually runs, because the original did not\nneed any guarantee for (2), but now the sq version does.\n"},{"id":"387638","messageId":"20191206190331.29443-1-szeder.dev@gmail.com","threadId":"52373","inReplyTo":"20191130104644.17350-1-szeder.dev@gmail.com","subject":"[PATCH v2 0/2] t9300-fast-import: don't hang if background fast-import exits too early","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-12-06T19:03:29Z","receivedAt":"2019-12-06T19:03:43Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"The five tests checking 'git fast-import's checkpoint handling in\n't9300-fast-import.sh', all with the prefix \"V:\" in their test\ndescription, can hang indefinitely if 'git fast-import' unexpectedly\ndies early in any of these tests.\n\nChanges since v1:\n\n  - The first patch is new, and refactors those tests to store the PID\n    of the background 'git fast-import' process in a shell variable\n    instead of in a pidfile.\n\n  - The second patch is conceptually the same as the only patch v1,\n    but it has been updated to store the PID of the background\n    subshell in a variable as well.\n\nSZEDER Gábor (2):\n  t9300-fast-import: store the PID in a variable instead of pidfile\n  t9300-fast-import: don't hang if background fast-import exits too\n    early\n\n t/t9300-fast-import.sh | 20 ++++++++++++++++----\n 1 file changed, 16 insertions(+), 4 deletions(-)\n\n-- \n2.24.0.801.g241c134b8d\n\n"},{"id":"387639","messageId":"20191206190331.29443-2-szeder.dev@gmail.com","threadId":"52373","inReplyTo":"20191206190331.29443-1-szeder.dev@gmail.com","subject":"[PATCH v2 1/2] t9300-fast-import: store the PID in a variable instead of pidfile","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-12-06T19:03:30Z","receivedAt":"2019-12-06T19:03:43Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"The five tests running 'git fast-import' in the background in\n't9300-fast-import.sh' store the PID of that background process in a\npidfile, to be used to check whether that background process survived\neach test and then to kill it in test_when_finished commands.  To\nachieve this all these five tests run three $(cat <pidfile>) command\nsubstitutions each.\n\nStore the PID of the background 'git fast-import' in a variable to\navoid those extra processes.\n\nSigned-off-by: SZEDER Gábor <szeder.dev@gmail.com>\n---\n t/t9300-fast-import.sh | 6 +++---\n 1 file changed, 3 insertions(+), 3 deletions(-)\n\ndiff --git a/t/t9300-fast-import.sh b/t/t9300-fast-import.sh\nindex e707fb861e..6820ebbb63 100755\n--- a/t/t9300-fast-import.sh\n+++ b/t/t9300-fast-import.sh\n@@ -3165,12 +3165,12 @@ background_import_then_checkpoint () {\n \trm V.output\n \n \tgit fast-import $options <&8 >&9 &\n-\techo $! >V.pid\n+\tfi_pid=$!\n \t# We don't mind if fast-import has already died by the time the test\n \t# ends.\n \ttest_when_finished \"\n \t\texec 8>&-; exec 9>&-;\n-\t\tkill $(cat V.pid) && wait $(cat V.pid)\n+\t\tkill $fi_pid && wait $fi_pid\n \t\ttrue\"\n \n \t# Start in the background to ensure we adhere strictly to (blocking)\n@@ -3202,7 +3202,7 @@ background_import_then_checkpoint () {\n }\n \n background_import_still_running () {\n-\tif ! kill -0 \"$(cat V.pid)\"\n+\tif ! kill -0 \"$fi_pid\"\n \tthen\n \t\techo >&2 \"background fast-import terminated too early\"\n \t\tfalse\n-- \n2.24.0.801.g241c134b8d\n\n"},{"id":"387640","messageId":"20191206190331.29443-3-szeder.dev@gmail.com","threadId":"52373","inReplyTo":"20191206190331.29443-1-szeder.dev@gmail.com","subject":"[PATCH v2 2/2] t9300-fast-import: don't hang if background fast-import exits too early","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-12-06T19:03:31Z","receivedAt":"2019-12-06T19:03:44Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"The five tests checking 'git fast-import's checkpoint handling in\n't9300-fast-import.sh', all with the prefix \"V:\" in their test\ndescription, can hang indefinitely if 'git fast-import' unexpectedly\ndies early in any of these tests.\n\nThese five tests run 'git fast-import' in the background, while\nfeeding instructions to its standard input through a fifo (fd 8) from\na background subshell, and reading and verifying its standard output\nthrough another fifo (fd 9) in the test script's main shell process.\nThis \"reading and verifying\" is basically a 'while read ...' shell\nloop iterating until 'git fast-import' outputs the expected line,\nignoring any other output.  This doesn't work very well when 'git\nfast-import' dies before printing that particular line, because the\n'read' builtin doesn't get EOF after the death of 'git fast-import',\nas their input and output are not connected directly but through a\nfifo.  Consequently, that 'read' hangs waiting for the next line from\nthe already dead 'git fast-import', leaving the test script and in\nturn the whole test suite hanging.\n\nAvoid this hang by checking whether the background 'git fast-import'\nprocess exited unexpectedly early, and interrupt the 'while read' loop\nif it did.  We have to jump through some hoops to achive that, though:\n\n  - Start the background 'git fast-import' in another background\n    subshell, which then:\n\n      - prints the PID of that 'git fast-import' process to the fifo,\n\tto be read by the main shell process, so it will know which\n\tprocess to kill when the test is finished.\n\n      - waits until that 'git fast-import' process exits.  If it does\n\texit, then report its exit code, and write a message to the\n\tfifo used for 'git fast-import's standard output, thus\n\tun-block the 'read' builtin in the main shell process.\n\n  - Modify that 'while read' loop to break the loop upon seeing that\n    message, and fail the test in the usual way.\n\n  - Once the test is finished kill that background subshell as well,\n    and do so before killing the background 'git fast-import'.\n    Otherwise the background 'git fast-import' and subshell processes\n    would die racily, and if 'git fast-import' were to die sooner,\n    then we might get some undesired and potentially confusing\n    messages in the test's output.\n\nSigned-off-by: SZEDER Gábor <szeder.dev@gmail.com>\n---\n t/t9300-fast-import.sh | 16 ++++++++++++++--\n 1 file changed, 14 insertions(+), 2 deletions(-)\n\ndiff --git a/t/t9300-fast-import.sh b/t/t9300-fast-import.sh\nindex 6820ebbb63..8f6f80f021 100755\n--- a/t/t9300-fast-import.sh\n+++ b/t/t9300-fast-import.sh\n@@ -3164,12 +3164,21 @@ background_import_then_checkpoint () {\n \texec 9<>V.output\n \trm V.output\n \n-\tgit fast-import $options <&8 >&9 &\n-\tfi_pid=$!\n+\t(\n+\t\tgit fast-import $options <&8 >&9 &\n+\t\techo $! >&9\n+\t\twait $!\n+\t\techo >&2 \"background fast-import terminated too early with exit code $?\"\n+\t\t# Un-block the read loop in the main shell process.\n+\t\techo >&9 UNEXPECTED\n+\t) &\n+\tsh_pid=$!\n+\tread fi_pid <&9\n \t# We don't mind if fast-import has already died by the time the test\n \t# ends.\n \ttest_when_finished \"\n \t\texec 8>&-; exec 9>&-;\n+\t\tkill $sh_pid && wait $sh_pid\n \t\tkill $fi_pid && wait $fi_pid\n \t\ttrue\"\n \n@@ -3190,6 +3199,9 @@ background_import_then_checkpoint () {\n \t\tthen\n \t\t\terror=0\n \t\t\tbreak\n+\t\telif test \"$output\" = \"UNEXPECTED\"\n+\t\tthen\n+\t\t\tbreak\n \t\tfi\n \t\t# otherwise ignore cruft\n \t\techo >&2 \"cruft: $output\"\n-- \n2.24.0.801.g241c134b8d\n\n"}]}