[issue12954] Multiprocessing logging under Windows
New submission from paul j3 <ajipanca@gmail.com>: The Windows programming guidelines for the multiprocessing module documentation should include a warning that any logging initialization should be protected by the 'if __name__' block. Otherwise you will get duplicate logging entries for the child processes. This is because the multiprocessing.forking.prepare() function explicitly calls log_to_stderr(), and may implicitly do so again when it imports the parent module, resulting in duplicate logging handlers. ---------- assignee: docs@python components: Documentation messages: 143815 nosy: docs@python, paul.j3 priority: normal severity: normal status: open title: Multiprocessing logging under Windows _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
Mark Lawrence added the comment: @paul j3 can you prepare a patch for this? ---------- nosy: +BreamoreBoy type: -> behavior versions: +Python 2.7, Python 3.4, Python 3.5 _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
paul j3 added the comment: It will take a while to reconstruct the circumstances behind this issue. I think I was working through some online class examples, working in the Eclipse pydev environment. Currently I'm mostly working in linux, and not doing much with multiprocessing. Looks like most, if not all, the examples are already protected with the 'if __name__' clause. ---------- _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
paul j3 added the comment: The documentation currently warns https://docs.python.org/2/library/multiprocessing.html#windows
Safe importing of main module
Make sure that the main module can be safely imported by a new Python interpreter without causing unintended side effects (such a starting a new process).
The logging duplication that I mentioned here is one of those side effects. So there's probably no need for further warnings. ---------- _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
Ari Koivula added the comment: I encountered this problem on Python 3.2.5 on Windows and don't think a vague warning about initializing modules is a proper solution. A better solution would be to simply not add multiple handlers, even if log_to_stderr is called more than once. ---------- nosy: +Ari.Koivula _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
paul j3 added the comment: I added a print line to a 'windows' example from the documentation: from multiprocessing import Process print 'importing multiprocessing' def foo(): print 'hello' p = Process(target=foo) p.start() Run with Python 2.7.0 on linux I get importing multiprocessing hello Run with same, but on Windows I get importing multiprocessing importing multiprocessing hello importing multiprocessing hello (recursively) Now if I put the last part into an if: if __name__ == '__main__': p = Process(target=foo) p.start() the Windows version no longer recurses, but I still get the double print message. In linux the child process is created with `os.fork`, which makes a copy of the parent. The script is only loaded and run once. In windows, the child is created by issuing a new call to Python with the script. The script is loaded and run by the child as well as the parent, hence the double print. So any action that you don't want run when the child is created should be in the 'if __name__' block. I can picture modifying the log_to_stderr function so that it checks the logger's 'handlers' list for one that already writes to stderr. It should be easy to add to your own code. But isn't it easier just to segregate all the 'main' actions from the 'child' ones? ---------- _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
Ari Koivula added the comment: Guarding the initialization is indeed correct and works, but log_to_stderr adding the handler multiple times is still annoying. Especially as you probably do want it to be called for child processes (at least on windows) and it might be called during initialization in multiprocessing.forking.prepare (but not on windows). There is no need to go through the handlers. Just avoid adding the handler again if it has already been added. There actually already is a variable (multiprocessing.util._log_to_stderr) that tracks this, but it isn't used. ---------- _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
Ari Koivula added the comment: Actually, multiprocessing.forking.prepare does call log_to_stderr on windows. While debugging the double handler issue I somehow came to the conclusion that it didn't, but it seems to work just fine now. I must have been doing something weird like creating the processes before setting the log level to cause that. This issue can probably be closed. ---------- _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
paul j3 added the comment: I had noticed the `global _log_to_stderr` in `util.log_to_stderr()`, but hadn't taken time to track down where it is used. Not only is it passed from the 'util' module to the 'forking' one, but it is also passed via a piped pickle from parent to child process. There's a lot more to simulating 'os.fork' in Windows than I would have guessed. ---------- _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
Davin Potts added the comment: Closing per the feedback of the OP and secondary contributor to the issue. Kudos to the reporters for such nice follow-up. ---------- nosy: +davin resolution: -> not a bug stage: -> resolved status: open -> closed _______________________________________ Python tracker <report@bugs.python.org> <http://bugs.python.org/issue12954> _______________________________________
participants (4)
-
Ari Koivula -
Davin Potts
-
Mark Lawrence
-
paul j3