[kamailio/kamailio] KEMI Fatal Python error: failed releasing import lock after fork (Issue #3125)
### Description using kamailio 5.6.0 python: 3.8.10 OS : ubuntu 20.0.4
When trying to use kemi with the default configuration I get on startup.
` Fatal Python error: failed releasing import lock after fork `
#### Reproduction Using The configuration described here : https://kamailio.org/docs/tutorials/devel/kamailio-kemi-framework/kemi/#basi...
#### Debugging Data ``` 0(1) INFO: <core> [core/kemi.c:106]: sr_kemi_core_info(): ===== kamailio.child_init(1) kamailio | 0(1) DEBUG: <core> [core/sr_module.c:923]: init_child(): initializing PROC_POSTCHILDINIT with rank -126 kamailio | 0(1) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 0 rank -126: app_python3 [stand-alone receiver @ 10.10.0.4:5060] kamailio | Fatal Python error: failed releasing import lock after fork kamailio | Python runtime state: initialized kamailio | kamailio | Current thread 0x00007f3faa857180 (most recent call first): kamailio | <no Python frame> kamailio | 7(14) DEBUG: <core> [core/pt.c:308]: fork_process(): seeding PRNG with 1232772928 kamailio | 7(14) DEBUG: <core> [core/rand/cryptorand.c:36]: cryptorand_seed(): seeding cryptorand generator with 1232772928 kamailio | 7(14) DEBUG: <core> [core/rand/fortuna/random.c:175]: sr_add_entropy(): additional 4 bytes entropy added to cryptographic PRNG kamailio | 7(14) DEBUG: <core> [core/pt.c:313]: fork_process(): test random numbers 987270226 561754816 1532392054 1162699744 kamailio | 7(14) DEBUG: <core> [core/sr_module.c:923]: init_child(): initializing PROC_RPC with rank -2 kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: corex [ctl handler] kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: usrloc [ctl handler] kamailio | 7(14) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for sruid is [ulcx-62931156-e-] (0 / 16) kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: registrar [ctl handler] kamailio | 7(14) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for sruid is [uloc-62931156-e-] (0 / 16) kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: jsonrpcs [ctl handler] kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: kex [ctl handler] kamailio | 7(14) DEBUG: kex [kex_mod.c:155]: child_init(): rank is (-2) kamailio | 7(14) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for sruid is [srid-62931156-e-] (0 / 16) kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: tm [ctl handler] kamailio | 7(14) DEBUG: tm [callid.c:136]: child_init_callid(): callid: '2ef035de7699493f-14@10.10.0.4' kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: tmx [ctl handler] kamailio | 7(14) DEBUG: tmx [tmx_mod.c:262]: child_init(): rank is (-2) kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: sl [ctl handler] kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: ctl [ctl handler] kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: debugger [ctl handler] kamailio | 7(14) DEBUG: debugger [debugger_mod.c:224]: child_init(): rank is (-2) kamailio | 7(14) DEBUG: <core> [core/sr_module.c:875]: init_mod_child(): idx 7 rank -2: app_python3 [ctl handler] kamailio | 7(14) DEBUG: app_python3 [apy_kemi.c:234]: sr_apy_kemi_exec_func_ex(): execution of method: .info kamailio | 7(14) DEBUG: app_python3 [apy_kemi.c:266]: sr_apy_kemi_exec_func_ex(): param[1] for: info is str: ===== kamailio.child_init(-2) kamailio | kamailio | 7(14) INFO: <core> [core/kemi.c:106]: sr_kemi_core_info(): ===== kamailio.child_init(-2) kamailio | 7(14) DEBUG: ctl [ctl.c:329]: mod_child(): ctl: mod_child(0), fork_process=0, csl=0x56186255e180 kamailio | 7(14) DEBUG: ctl [ctl.c:336]: mod_child(): ctl: 0 io_listen_loop(1, 0x56186255e180) kamailio | 7(14) INFO: ctl [io_listener.c:213]: io_listen_loop(): io_listen_loop: using epoll_lt io watch method (config) kamailio | 7(14) DEBUG: ctl [io_listener.c:245]: io_listen_loop(): io_listen_loop: adding socket 8, type 2, transport 3 (/var/run/kamailio//kamailio_ctl) kamailio | 7(14) DEBUG: ctl [../../core/io_wait.h:374]: io_watch_add(): processing io_watch_add(0x7f3fa8aa2380, 8, 2, 0x56186255e180) - fd_no=0 kamailio exited with code 139
```
This does not happen when using loadmodule "app_python.so" -- instead of app_python3.so
and ``` modparam("app_python", "load", "/opt/kamailio/etc/kamailio.py") cfgengine "python"
``` As apposed to the python3 equivalents. I am curious about what may be different.
Thank you.
This appears to be fixed after removing
``` 202 #if PY_VERSION_HEX >= 0x03070000 203 PyOS_AfterFork_Parent() ; 204 #endif ``` no clue what I am doing, I hope this info is useful.
iirc, the above snipped was added to fix another issue:
- https://github.com/kamailio/kamailio/issues/2885
Maybe it needs to be executed only in some cases, if so, then a modparam can be added to allow controlling it.
Not sure if @aalba6675 is still around to comment on it.
Hmmm...taking a look at this issue now
I found the root cause: we call `PyOS_AfterFork_Child()` unconditionally; it should only be called in a real child process. @miconda: can I confirm that `rank > 0` is the correct test for a child process?
Tested AlmaLinux 8.6 with Python 3.9: kamailio can now startup with the sample KEMI Python routing script .
@aalba6675: thanks for taking care of it! Rank>0 means that it is a SIP worker process (one that handles incoming sip traffic), but kamailio config parts can be executed with SIP messages by other processes, for example the main timer process does the retransmission and may execute a `failure_route` block.
I would not worry about no-fork mode, that is not fully functional anyhow (e.g., not tcp support) and not sure if anyone still tests with that mode.
If the function has to be executed in children processes, then the ranks PROC_MAIN, PROC_INIT and PROC_POSTCHILDINIT have to be skipped -- some details about ranks in the code at:
* https://github.com/kamailio/kamailio/blob/c37ccdc6e3bad0af4644941a872f510c51...
Fixed on master and 5.6.
Closed #3125 as completed.
-
aalba6675 -
Daniel-Constantin Mierla
-
Nigel Daniels