{"thread":{"id":"56477","subject":"[PATCH] t5562: use alarm() to interrupt timed child-wait","startedAt":"2021-09-09T22:57:59Z","lastAt":"2021-09-09T23:11:38Z","messageCount":2,"participants":["Jeff King","Eric Sunshine"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"435341","messageId":"YTqRdU1Tgn/HVhdA@coredump.intra.peff.net","threadId":"56477","inReplyTo":null,"subject":"[PATCH] t5562: use alarm() to interrupt timed child-wait","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2021-09-09T22:57:57Z","receivedAt":"2021-09-09T22:57:59Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"The t5562 script occasionally takes 60 extra seconds to complete due to\na race condition in the invoke-with-content-length.pl helper.\n\nThe way it's supposed to work is this:\n\n - we set up a SIGCLD handler\n\n - we kick off http-backend and write to it with a set content-length,\n but _don't_ close the pipe\n\n - we sleep for 60 seconds, assuming that SIGCLD from http-backend\n finishing will interrupt us\n\n - after the sleep finishes (whetherby 60 seconds or because it was\n interrupted by the signal), we check a flag to see if our SIGCLD\n handler was called. If not, then we complain.\n\nThis usually completes immediately, because the signal interrupts our\nsleep. But very occasionally the child process dies _before_ we hit the\nsleep, so we don't realize it. The test still completes successfully\n(because our $exited flag is set), but it takes an extra 60 seconds.\n\nThere's no way to check the flag and sleep atomically. So the best we\ncan do with this approach is to sleep in smaller chunks (say, 1 second)\nand check the flag incrementally. Then we waste a maximum of 1 second if\nwe lose the race. This was proposed in:\n\n https://lore.kernel.org/git/20190218205028.32486-1-max@max630.net/\n\nand it does work. But we can do better.\n\nInstead of blocking on sleep and waiting for the child signal to\ninterrupt us, we can block on the child exiting and set an alarm signal\nto trigger the timeout.\n\nThis lets us exit the script immediately when the child behaves (with no\nrace possible), and wait a maximum of 60 seconds when it doesn't.\n\nNote one small subtlety: perl is very willing to restart the waitpid()\ncall after the alarm is delivered, even if we've thrown an exception via\ndie. \"perldoc -f alarm\" claims you can get around this with an eval/die\ncombo (and even has some example code), but it doesn't seem to work for\nme with waitpid(); instead, we continue waiting until the child exits.\n\nSo instead, we'll instruct the child process to exit in the alarm\nhandler itself. In the original code this was done by calling\nclose($out). That would continue to work, since our child is always\nhttp-backend, which should exit when its stdin closes. But we can be\neven more robust against a hung or confused child by sending a KILL\nsignal, which should terminate it immediately.\n\nReported-by: SZEDER Gábor \nSigned-off-by: Jeff King \n---\nThis was discussed recently in:\n\n https://lore.kernel.org/git/YRretXfEfiVujSeO@coredump.intra.peff.net/\n\nI had planned to resurrect Max's patch (linked above), but came up with\nthis better solution.\n\n t/t5562/invoke-with-content-length.pl | 16 ++++++++--------\n 1 file changed, 8 insertions(+), 8 deletions(-)\n\ndiff --git a/t/t5562/invoke-with-content-length.pl b/t/t5562/invoke-with-content-length.pl\nindex 0943474af2..718dd9b49d 100644\n--- a/t/t5562/invoke-with-content-length.pl\n+++ b/t/t5562/invoke-with-content-length.pl\n@@ -13,11 +13,6 @@\n defined read($body_fh, $body_data, $body_size) or die \"Cannot read $body_filename: $!\";\n close($body_fh);\n \n-my $exited = 0;\n-$SIG{\"CHLD\"} = sub {\n- $exited = 1;\n-};\n-\n # write data\n my $pid = open(my $out, \"|-\", @command);\n {\n@@ -29,8 +24,13 @@\n }\n print $out $body_data or die \"Cannot write data: $!\";\n \n-sleep 60; # is interrupted by SIGCHLD\n-if (!$exited) {\n- close($out);\n+$SIG{ALRM} = sub {\n+ kill 'KILL', $pid;\n die \"Command did not exit after reading whole body\";\n+};\n+alarm 60;\n+\n+my $ret = waitpid($pid, 0);\n+if ($ret != $pid) {\n+ die \"confusing return from waitpid: $ret\";\n }\n-- \n2.33.0.731.g46856368d1\n"},{"id":"435344","messageId":"CAPig+cRXerwoqthmOAvOKZs=EVb1VB2ig=uBn247xUuWocqDmQ@mail.gmail.com","threadId":"56477","inReplyTo":"YTqRdU1Tgn/HVhdA@coredump.intra.peff.net","subject":"Re: [PATCH] t5562: use alarm() to interrupt timed child-wait","fromName":"Eric Sunshine","fromEmail":"sunshine@sunshineco.com","sentAt":"2021-09-09T23:11:25Z","receivedAt":"2021-09-09T23:11:38Z","isPatch":true,"sender":{"key":"sunshine@sunshineco.com","avatar":"https://avatars.githubusercontent.com/u/163641?v=4"},"body":"On Thu, Sep 9, 2021 at 6:58 PM Jeff King wrote:\n> [...]\n> - after the sleep finishes (whetherby 60 seconds or because it was\n> interrupted by the signal), we check a flag to see if our SIGCLD\n> handler was called. If not, then we complain.\n\ns/whetherby/whether by/\n"}]}