Fix removing simple queue in child processes

[dstlmrk]

Hello, I think this pull request could fix #309.

There is problem with calling multiprocessing.current_process() which returns the instance of _MainProcess(). But because this code is executed before a new thread there are same values/objects. In child process is the same object as in parent process. You can check it with id(self._owner_process).

Source code of multiprocessing: https://github.com/python/cpython/blob/master/Lib/multiprocessing/process.py#L41

Another way how to fix it is to move self._owner_process = multiprocessing.current_process() after creating a new thread. There would be different objects in every process. But I think there is better to work wih PID numbers than objects.

[Delgan]

Wow! Thanks a lot for taking the time to investigate and fix this issue!

Kudos for finding the solution. To be honest I'm still scratching my head trying to figure out what's going on. 😲

In child process is the same object as in parent process.

Why that?
Why does calling multiprocessing.current_process() in the child returns the same process as in the parent?
Why does it fail if _owner_process is a Process() object but not if it's an int? Is uwsgi somehow mutating the main process?
Why does it freeze at stop() anyway?

It will take me probably some time to properly grasp all of that, but I will publish your correction as soon as possible. Thank you very much!

[dstlmrk]

I will try to describe it :) And I want to apologize because last part "Another way how to fix it..." of my previous comment is not correct.

1), 2) Why does calling multiprocessing.current_process() in the child returns the same process as in the parent? and 3b) Why does it fail if _owner_process is a Process() object but not if it's an int?

Why multiprocessing returns the same object? Because of this and this. This object/instance is created once in master process and everytime when you call multiprocessing.current_process() you get the same instance (it doesn't create new instance everytime when you call it). That's property of multiprocessing. It returns the same object but it behaves differently in every process. You can call property pid (ident) and it will return pid of current process. That's the reason why self._owner_process doesn't return pid of parent process. Actually self._owner_process = multiprocessing.current_process() everytime.

I can show you my custom output from code (everywhere is the same object but it behaves differently):

...
[os.getpid()=19870] I'm MASTER!!!
[os.getpid()=19870] In Handler.__init__() id(self._owner_process)=139955875152368
[os.getpid()=19870] In Handler.__init__() self._owner_process.pid=19870
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x55630ead8a50 pid: 19870 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 19870)
spawned uWSGI worker 1 (pid: 19873, cores: 1)
spawned uWSGI http 1 (pid: 19874)
^CSIGINT/SIGQUIT received...killing workers...
gateway "uWSGI http 1" has been buried (pid: 19874)
[os.getpid()=19873] Exit process
[os.getpid()=19873] In Handler.stop() id(self._owner_process)=139955875152368 ?= id(multiprocessing.current_process())=139955875152368
[os.getpid()=19873] In Handler.stop() self._owner_process.pid=19873 ?= multiprocessing.current_process().pid=19873
Thu Sep 17 12:51:19 2020 - worker 1 (pid: 19873) is taking too much time to die...NO MERCY !!!
...

3a) Is uwsgi somehow mutating the main process?

The uwsgi doesn't mutate the main process.

4) Why does it freeze at stop() anyway?

This condition means children should return and don't continue in code. But every child thinks he is master so every child kills logging thread (simple queue) and I don't know exactly why but it causes timeout in children/worker proccesses.

[Delgan]

Thanks for the explanations!

One thing is still confusing me.

This object/instance is created once in master process and everytime when you call multiprocessing.current_process() you get the same instance (it doesn't create new instance everytime when you call it).
[...]
Actually self._owner_process = multiprocessing.current_process() everytime.

That's not what I'm observing while using standard multiprocessing without involving uwsgi:

import multiprocessing

main = multiprocessing.current_process()

def hello_world():
    child = multiprocessing.current_process()
    print("main == child:", main == child)

if __name__ == "__main__":
    p = multiprocessing.Process(target=hello_world)
    p.start()
    p.join()

This prints "main == child: False".

Using uwsgi I get the opposite result:

import multiprocessing
from flask import Flask

application = Flask(__name__)
main = multiprocessing.current_process()

@application.route('/')
def hello_world():
    child  = multiprocessing.current_process()
    return "main == child: {}".format(main == child)

That's this behavior difference that I can't understand. 😕

[dstlmrk]

Hmm.. I checked multiprocessing code and I see reason probably there. This library does some overhead before starting process. I see it calls _bootstrap method, replaces _current_process with self (the child process) and deletes the original current_process. I think that's the reason why child process in multiprocessing has new instance every start of Process.

I'm not sure but uwsgi doesn't use multiprocessing library probably and can't execute this overhead itself. In our applications based on uwsgi we can't use loguru without this change.

[Delgan]

Yeah, uwsgi probably implements its own bootstrapping procedure. 😕

Anyway, thanks again. I wanted to be sure it was somehow related to uwsgi and that loguru was working properly out of that context.

I will merge this PR and probably publish a new version during the week-end. 👍

[dstlmrk]

I am glad I could help you :)

[Delgan]

Again, thanks a lot for your help! It should be fine in v0.5.3. 👍