bpo-33613, test_semaphore_tracker_sigint: fix race condition#7850

pablogsal

Fail test_semaphore_tracker_sigint if no warnings are expected and
one is received.

Fix race condition when the child receives SIGINT
before it can register signal handlers for it.

The race condition occurs when the parent calls
_semaphore_tracker.ensure_running() (which in turn spawns the
semaphore_tracker using _posixsubprocess.fork_exec), the child
registers the signal handlers and the parent tries to kill the child.
What seems to happen is that in some slow systems, the parent sends the
signal to kill the child before the child protects against the signal.

There is no reliable and portable solution for the parent to wait until
the child has register the signal handlers to send the signal to kill
the child so a sleep is introduced between the spawning of the child
and the parent sending the signal to give time to the child to register
the handlers.

https://bugs.python.org/issue33613

Fail `test_semaphore_tracker_sigint` if no warnings are expected and one is received. Fix race condition when the child receives SIGINT before it can register signal handlers for it. The race condition occurs when the parent calls `_semaphore_tracker.ensure_running()` (which in turn spawns the semaphore_tracker using `_posixsubprocess.fork_exec`), the child registers the signal handlers and the parent tries to kill the child. What seem to happen is that in some slow systems, the parent sends the signal to kill the child before the child protects against the signal. There is no reliable and portable solution for the parent to wait until the child has register the signal handlers to send the signal to kill the child so a `sleep` is introduced between the spawning of the child and the parent sending the signal to give time to the child to register the handlers.

taleinat

Regarding the unrelated change of the warning check, FWIW I find the existing code (without the change in this PR) clearer.

pablogsal

@taleinat I am happy to undo that change. The problem is that the test was silently failing when SIGINT was being delivered as the test does not check that no warnings are raised. Notice that the presence of a warning means that the process died and therefore SIGINT did kill the process, which is precisely what the test checks that does not happen.

I think in order to check that the test works as intended without the need to run the suite with -Wall, we need to modify the test.

…me process

… the same process

…runs in the same process

pablogsal

@pitrou Could you take a look at this?

Here is a summary of all the changes to make reviewing this easier:

Updated the tracker to answer to a PING command to we know when is alive.
The test function check_semaphore_tracker_death restarts the tracker every time to avoid interference between test runs and allow parallel testing.
The test function check_semaphore_tracker_death now checks for warnings as these are indicative of the tracker being dead and restarted (this was one of the main errors and the reason tests were passing without the -W error option).
Fixed the race condition in the tests: the parent was killing the child before the child could protect itself against the signals. I was able to reproduce the problem on one of the slowest buildbots (gcc112.fsffrance.org and gcc110.fsffrance.org) and I can confirm that this PR fixes the problem.

pitrou

From a high-level POV:

Fixed the race condition in the tests: the parent was killing the child before the child could protect itself against the signals. I was able to reproduce the problem on one of the slowest buildbots (gcc112.fsffrance.org and gcc110.fsffrance.org) and I can confirm that this PR fixes the problem.

Is that important? If we have very slow buildbots, we could skip the test on them. Testing this piece of functionality on all buildbots is not critical.

pitrou

Assuming we validate this approach, there are still problems with the implementation.

bedevere-bot

When you're done making the requested changes, leave the comment: I have made the requested changes; please review again.

…esting runs in the same process

pablogsal

Is that important? If we have very slow buildbots, we could skip the test on them. Testing this piece of functionality on all buildbots is not critical.

That was one of the original problems in the issue. It does not happen only on the slowest buildbots, but these are a reliable place to test for the race condition to happen. In my humble opinion, the existence of the race makes the tests more unreliable and we should fix that, but I you think there is a better approach or a different compromise, I am more than happy to go for that.

vstinner

@pitrou wrote: "I'm a bit uneasy with this. What if spawnv_passfds takes a very long time for some reason? The user will try to stop it using ^C... and nothing will happen."

You are true that SIGINT is blocked while spawnv_passfds() is running, but spawnv_passfds() should be quick in the parent: to oversimplify, it just calls fork() which should be very quick (it's not a O(n) operating thanks to copy-on-write). I prefer to see this race condition fixed. IMHO the short time window where CTRL+c is blocked is small enough to be acceptable.

Note: signals are not lost or ignored, it's just that signals are only handled once spawnv_passfds() completes (once the signals are unblocked).

I suggest to backport the change to 2.7, 3.6 and 3.7 branches to make our buildbots more reliable.

vstinner

@pitrou: @pablogsal updated his PR, and it now LGTM. Would you mind to have a second look?

Note: this PR has a long history since @pablogsal chose to rewrite his PR with a different approach ("ping" then pthread_sigmask) rather than creating a new PR.

IMHO pthread_sigmask is smpler and more reliable than the "ping" idea. There is no need to establish (and then close, reliably) a new communication channel with pthread_sigmask.

pitrou

Fair enough. I think this is good to go.

bedevere-bot

@pitrou: Please replace # with GH- in the commit message next time. Thanks!

miss-islington

Thanks @pablogsal for the PR, and @pitrou for merging it 🌮🎉.. I'm working now to backport this PR to: 3.6.
🐍🍒⛏🤖 I'm not a witch! I'm not a witch!

miss-islington

Thanks @pablogsal for the PR, and @pitrou for merging it 🌮🎉.. I'm working now to backport this PR to: 2.7.
🐍🍒⛏🤖

miss-islington

Thanks @pablogsal for the PR, and @pitrou for merging it 🌮🎉.. I'm working now to backport this PR to: 3.7.
🐍🍒⛏🤖 I'm not a witch! I'm not a witch!

miss-islington

Sorry, @pablogsal and @pitrou, I could not cleanly backport this to 2.7 due to a conflict.
Please backport using cherry_picker on command line.
cherry_picker ec74d187f50a8a48f94eb37023300583fbd644cc 2.7

bedevere-bot

GH-9055 is a backport of this pull request to the 3.7 branch.

…H-7850) Fail `test_semaphore_tracker_sigint` if no warnings are expected and one is received. Fix race condition when the child receives SIGINT before it can register signal handlers for it. The race condition occurs when the parent calls `_semaphore_tracker.ensure_running()` (which in turn spawns the semaphore_tracker using `_posixsubprocess.fork_exec`), the child registers the signal handlers and the parent tries to kill the child. What seem to happen is that in some slow systems, the parent sends the signal to kill the child before the child protects against the signal. (cherry picked from commit ec74d18) Co-authored-by: Pablo Galindo <Pablogsal@gmail.com>

miss-islington

Sorry, @pablogsal and @pitrou, I could not cleanly backport this to 3.6 due to a conflict.
Please backport using cherry_picker on command line.
cherry_picker ec74d187f50a8a48f94eb37023300583fbd644cc 3.6

pitrou

Please don't backport this. This isn't fixing a user-visible bug.

vstinner

Please don't backport this. This isn't fixing a user-visible bug.

It hurts on the buildbots, and so it makes our life harder (Pablo and me who watch the random failures on buildbots).

pitrou

Right, but we shouldn't modify library code to heal the buildbots (and risk introducing regressions).

vstinner

If you don't want to backport the code, I suggest to remove or skip the test in 3.6 and 3.7 branches. I don't want to have known race condition in our test suite.

pitrou

I'm ok with skipping the tests on the buildbots, as long as it's not skipped unconditionally.

pablogsal requested a review from vstinner June 21, 2018 21:40

the-knights-who-say-ni added the CLA signed label Jun 21, 2018

bedevere-bot added the awaiting merge label Jun 21, 2018

pablogsal force-pushed the bpo33613 branch from 008c17c to 5f1df08 Compare June 21, 2018 22:34

pablogsal force-pushed the bpo33613 branch 3 times, most recently from 4b8f76f to 9408236 Compare June 24, 2018 18:35

Implement PONG command in the semaphore tracker

4f9babb

pablogsal force-pushed the bpo33613 branch from 9408236 to 4f9babb Compare June 24, 2018 20:01

pablogsal commented Jun 24, 2018

View reviewed changes

Ensure the tracker is killed to allow multiple testing runs in the sa… …

26d81a3

…me process

pablogsal force-pushed the bpo33613 branch from 1215a11 to 26d81a3 Compare June 24, 2018 20:35

taleinat reviewed Jun 30, 2018

View reviewed changes

pablogsal force-pushed the bpo33613 branch from d075473 to b315e8e Compare July 6, 2018 23:58

fixup! Ensure the tracker is killed to allow multiple testing runs in… …

a7d5c59

… the same process

pablogsal force-pushed the bpo33613 branch from b315e8e to a7d5c59 Compare July 7, 2018 20:17

fixup! fixup! Ensure the tracker is killed to allow multiple testing … …

a735d49

…runs in the same process

pitrou requested changes Jul 24, 2018

View reviewed changes

bedevere-bot added awaiting changes and removed awaiting merge labels Jul 24, 2018

fixup! fixup! fixup! Ensure the tracker is killed to allow multiple t… …

9460da4

…esting runs in the same process

pablogsal force-pushed the bpo33613 branch 2 times, most recently from e16e027 to 9460da4 Compare July 24, 2018 12:29

Remove extraneous NEWS file

c0a088c

pitrou approved these changes Sep 4, 2018

View reviewed changes

pitrou merged commit ec74d18 into python:master Sep 4, 2018

bedevere-bot removed the awaiting merge label Sep 4, 2018

vstinner added needs backport to 3.6 labels Sep 4, 2018

miss-islington assigned pitrou Sep 4, 2018

bedevere-bot removed the needs backport to 3.7 label Sep 4, 2018

pitrou removed needs backport to 2.7 labels Sep 4, 2018

serhiy-storchaka reviewed Oct 6, 2018

View reviewed changes

pablogsal deleted the bpo33613 branch May 19, 2021 18:57

Conversation

pablogsal commented Jun 21, 2018 • edited by bedevere-bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

taleinat commented Jun 24, 2018

Uh oh!

pablogsal commented Jun 24, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

pablogsal commented Jul 24, 2018

Uh oh!

pitrou commented Jul 24, 2018

Uh oh!

pitrou left a comment

Choose a reason for hiding this comment

Uh oh!

bedevere-bot commented Jul 24, 2018

Uh oh!

pablogsal commented Jul 24, 2018

Uh oh!

vstinner commented Sep 3, 2018

Uh oh!

vstinner commented Sep 3, 2018

Uh oh!

pitrou commented Sep 4, 2018

Uh oh!

bedevere-bot commented Sep 4, 2018

Uh oh!

miss-islington commented Sep 4, 2018

Uh oh!

miss-islington commented Sep 4, 2018

Uh oh!

miss-islington commented Sep 4, 2018

Uh oh!

miss-islington commented Sep 4, 2018

Uh oh!

bedevere-bot commented Sep 4, 2018

Uh oh!

miss-islington commented Sep 4, 2018

Uh oh!

pitrou commented Sep 4, 2018

Uh oh!

vstinner commented Sep 4, 2018

Uh oh!

pitrou commented Sep 4, 2018

Uh oh!

vstinner commented Sep 4, 2018

Uh oh!

pitrou commented Sep 4, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

9 participants

pablogsal commented Jun 21, 2018 •

edited by bedevere-bot

Loading

pablogsal commented Jun 24, 2018 •

edited

Loading