Re: Cygwin outputting message to stderr on dofork EAGAIN failure even when Python exception is caught and handled

[Andrey Repin <anrdaemon@yandex.ru>]

Greetings, Nicholas Williams!

> We have a Python (installed and run through Cygwin) process running on
> Windows Server 2022 that was very, very occasionally failing when subprocess.check_output was called:

> 0 [main] python3 28481 dofork: child -1 - forked process 16856 died
> unexpectedly, retry 0, exit code 0xC0000142, errno 11
> …
>     subprocess.check_output(["cygpath", "-w", directory.name], encoding="utf-8").strip()
> File "/usr/lib/python3.9/subprocess.py", line 424, in check_output <>
>      <>return run(*popenargs, stdout=PIPE, timeout=timeout, check=True, <>
> File "/usr/lib/python3.9/subprocess.py", line 505, in run <>
>      <>with Popen(*popenargs, **kwargs) as process: <>
> File "/usr/lib/python3.9/subprocess.py", line 951, in __init__ <>
>      <>self._execute_child(args, executable, preexec_fn, close_fds, <>
> File "/usr/lib/python3.9/subprocess.py", line 1754, in _execute_child
>     self.pid = _posixsubprocess.fork_exec(
> BlockingIOError: [Errno 11] Resource temporarily unavailable

> Setting aside for a minute the various reasons this might be happening
> occasionally, which we cannot solve for at this moment, the error number
> (EAGAIN) indicates that you should “try again.” So that’s exactly what we
> did. We added a try/catch to the Python code to catch the BlockingIOError
> and, if and only if the error number is EAGAIN, we try up to two more times.
> This fixed the problem and caused the application to stop quitting. We
> output a warning to our log so that we don’t forget about the problem, but
> the warning only ever appears once, so retrying a single time seems to help.

> However … even though Python handles the dofork error, turns it into a
> Python exception, and our code catches the Python exception and handles it
> properly, Cygwin (not Python … Cygwin) still outputs a message to stderr
> right before our warning message. This Cygwin error message shows up as an error in our log tracking:

> 0 [main] python3 15042 dofork: child -1 - forked process 6780 died
> unexpectedly, retry 0, exit code 0xC0000142, errno 11
> 06/16 13:57:53. 87520: WARNING: Retrying command in 2 seconds due to EAGAIN: [the command we’re running]

> I’m sure there could be any number of things I might be missing, but IMO,
> if the process calling dofork properly handles the error raised by dofork,
> Cygwin should not be outputting an error message to stderr.

> Thoughts?

My inexperienced and uneducated thought would be that forking code is fragile
and some parts of it prone to misbehavior. When an unforeseen error is
detected, it's better to report it sooner, than to get bitten by it later.

Regarding your specific issue, if you create a STC[1] (a minimally enough
version of your code that, say, fork a process thousands of times, which
reliable reproduce the issue) somebody else could run to test the cause, that
would be wonderful.

(If, however, you could find and fix the cause, that would be even more wonderful!)

[1] https://www.cygwin.com/acronyms/#STC


-- 
With best regards,
Andrey Repin
Monday, June 17, 2024 10:52:05

Sorry for my terrible english...