13.1 sched_yield livelock in libomp.so

From: CyberLeo Kitsana <cyberleo_at_cyberleo.net>
Date: Sun, 02 Oct 2022 17:22:13 UTC
Greetings!

I'm trying to figure out if I did something wrong, or if this is a 
genuine bug I've found.

When I upgraded from 12.3 to 13.1 and rebuilt all packages, I noticed 
some php-fpm pools started consuming 100% CPU at random. The processes 
responsible are always child processes of the master php-fpm process, 
and share the same process title, so I think they're fresh forks newly 
created to handle a request on a given pool, but don't get far in their 
startup process before spinning.

----8<----
5452 root   SsJ  php-fpm: master process (/usr/local/etc/php-fpm.conf) 
(php-fp
49045 root   RJ   - php-fpm: master process 
(/usr/local/etc/php-fpm.conf) (php-
51796 root   RJ   - php-fpm: master process 
(/usr/local/etc/php-fpm.conf) (php-
53088 www    SJ   - php-fpm: pool simple.cyberleo.net (php-fpm)
53331 www    IJ   - php-fpm: pool simple.cyberleo.net (php-fpm)
----8<----

A truss of the process spams hundreds of these per second constantly:

----8<----
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
sched_yield()					 = 0 (0x0)
----8<----

As a temporary workaround, I set up cron to run 'service php-fpm 
restart' once an hour, and then I discovered that even the config test 
that the startup script runs (php-fpm -t) can hang in the same way.

Running lldb on the forked process results in the following backtrace, 
seemingly implicating libomp.so, although I have no idea how that is 
being pulled in.

----8<----
(lldb) process attach --pid 49045
This version of LLDB has no plugin for the language "assembler". 
Inspection of frame variables will be limited.
Process 49045 stopped
* thread #1, name = 'php-fpm', stop reason = signal SIGSTOP
     frame #0: 0x0000000800aa524a libc.so.7`__sys_sched_yield at 
sched_yield.S:4
Executable module set to "/local/sbin/php-fpm".
Architecture set to: x86_64-unknown-freebsd13.1.
(lldb) bt
* thread #1, name = 'php-fpm', stop reason = signal SIGSTOP
   * frame #0: 0x0000000800aa524a libc.so.7`__sys_sched_yield at 
sched_yield.S:4
     frame #1: 0x00000008030e0351 
libomp.so`::__kmp_wait_4_ptr(spinner=0x000000080313d6dc, checker=1, 
pred=(libomp.so`__kmp_bakery_check(void*, unsigned int) at 
kmp_lock.cpp:611), obj=0x000000080313d6c0)(void *, kmp_uint32), void *) 
at kmp_dispatch.cpp:2688:5
     frame #2: 0x00000008030f8bb8 
libomp.so`::__kmp_acquire_ticket_lock(kmp_ticket_lock_t *, kmp_int32) 
[inlined] __kmp_acquire_ticket_lock_timed_template(lck=<unavailable>) at 
kmp_lock.cpp:633:3
     frame #3: 0x00000008030f8b99 
libomp.so`::__kmp_acquire_ticket_lock(lck=<unavailable>, 
gtid=<unavailable>) at kmp_lock.cpp:638:16
     frame #4: 0x00000008030fe924 
libomp.so`::__kmp_get_global_thread_id_reg() [inlined] 
__kmp_acquire_bootstrap_lock(lck=<unavailable>) at kmp_lock.h:524:10
     frame #5: 0x00000008030fe913 
libomp.so`::__kmp_get_global_thread_id_reg() at kmp_runtime.cpp:249:5
     frame #6: 0x00000008030c2d2e libomp.so`::kmpc_malloc(size_t) 
[inlined] __kmp_entry_thread() at kmp.h:3304:14
     frame #7: 0x00000008030c2d29 libomp.so`::kmpc_malloc(size=119093) 
at kmp_alloc.cpp:1098:14
     frame #8: 0x0000000803136677 
libomp.so`::__kmp_is_address_mapped(addr=0x0000000802cdd158) at 
z_Linux_util.cpp:2003:34
     frame #9: 0x0000000803107f25 
libomp.so`__kmp_register_library_startup() at kmp_runtime.cpp:6563:15
     frame #10: 0x00000008030fe984 
libomp.so`__kmp_do_serial_initialize() at kmp_runtime.cpp:6753:3
     frame #11: 0x0000000803108244 libomp.so`::__kmp_serial_initialize() 
at kmp_runtime.cpp:7026:3
     frame #12: 0x00000008007a4743 
libthr.so.3`thr_fork_impl(a=<unavailable>) at thr_fork.c:269:5
     frame #13: 0x00000008007a4418 libthr.so.3`__thr_fork at 
thr_fork.c:314:10
     frame #14: 0x00000000006d2651 php-fpm`match + 56945
     frame #15: 0x00000000006dc528 php-fpm`_pcre2_xclass_8 + 1752
     frame #16: 0x00000000006e4cb8 php-fpm`preg_replace_common + 2200
     frame #17: 0x00000000006d69cf php-fpm`set_start_bits + 3391
     frame #18: 0x00000000006d1f48 php-fpm`match + 55144
     frame #19: 0x00000000006d8f87 php-fpm`php_pcre2_substitute + 1367
     frame #20: 0x00000000004304a0 php-fpm`_start(ap=<unavailable>, 
cleanup=<unavailable>) at crt1_c.c:75:7
----8<----

And the config test (php-fpm -t) process looks like this:

----8<----
(lldb) process attach --pid 18483
This version of LLDB has no plugin for the language "assembler". 
Inspection of frame variables will be limited.
Process 18483 stopped
* thread #1, name = 'php-fpm', stop reason = signal SIGSTOP
     frame #0: 0x0000000800aa524a libc.so.7`__sys_sched_yield at 
sched_yield.S:4
Executable module set to "/local/sbin/php-fpm".
Architecture set to: x86_64-unknown-freebsd13.1.
(lldb) bt
* thread #1, name = 'php-fpm', stop reason = signal SIGSTOP
   * frame #0: 0x0000000800aa524a libc.so.7`__sys_sched_yield at 
sched_yield.S:4
     frame #1: 0x00000008030e0351 
libomp.so`::__kmp_wait_4_ptr(spinner=0x000000080313d6dc, checker=1, 
pred=(libomp.so`__kmp_bakery_check(void*, unsigned int) at 
kmp_lock.cpp:611), obj=0x000000080313d6c0)(void *, kmp_uint32), void *) 
at kmp_dispatch.cpp:2688:5
     frame #2: 0x00000008030f8bb8 
libomp.so`::__kmp_acquire_ticket_lock(kmp_ticket_lock_t *, kmp_int32) 
[inlined] __kmp_acquire_ticket_lock_timed_template(lck=<unavailable>) at 
kmp_lock.cpp:633:3
     frame #3: 0x00000008030f8b99 
libomp.so`::__kmp_acquire_ticket_lock(lck=<unavailable>, 
gtid=<unavailable>) at kmp_lock.cpp:638:16
     frame #4: 0x00000008030fe924 
libomp.so`::__kmp_get_global_thread_id_reg() [inlined] 
__kmp_acquire_bootstrap_lock(lck=<unavailable>) at kmp_lock.h:524:10
     frame #5: 0x00000008030fe913 
libomp.so`::__kmp_get_global_thread_id_reg() at kmp_runtime.cpp:249:5
     frame #6: 0x00000008030c2d2e libomp.so`::kmpc_malloc(size_t) 
[inlined] __kmp_entry_thread() at kmp.h:3304:14
     frame #7: 0x00000008030c2d29 libomp.so`::kmpc_malloc(size=121888) 
at kmp_alloc.cpp:1098:14
     frame #8: 0x0000000803136677 
libomp.so`::__kmp_is_address_mapped(addr=0x0000000803146158) at 
z_Linux_util.cpp:2003:34
     frame #9: 0x0000000803107f25 
libomp.so`__kmp_register_library_startup() at kmp_runtime.cpp:6563:15
     frame #10: 0x00000008030fe984 
libomp.so`__kmp_do_serial_initialize() at kmp_runtime.cpp:6753:3
     frame #11: 0x00000008030fe938 
libomp.so`::__kmp_get_global_thread_id_reg() at kmp_runtime.cpp:251:7
     frame #12: 0x00000008030e9ee2 
libomp.so`::__kmp_api_omp_init_lock(user_lock=0x0000000803679490) at 
kmp_ftn_entry.h:1083:14
     frame #13: 0x00000008035a7616 
libMagickCore-6.so.7`MagickCoreGenesis + 54
     frame #14: 0x000000080334e906 imagick.so`zm_startup_imagick + 182
     frame #15: 0x0000000000643ab8 php-fpm`scan + 22232
     frame #16: 0x0000000000643e9c php-fpm`scan + 23228
     frame #17: 0x0000000000650986 php-fpm`scan + 75174
     frame #18: 0x0000000000643d76 php-fpm`scan + 22934
     frame #19: 0x00000000005d7b13 php-fpm`php_module_startup + 2067
     frame #20: 0x00000000006da2d3 php-fpm`php_pcre2_substitute + 6307
     frame #21: 0x00000000006d8eb0 php-fpm`php_pcre2_substitute + 1152
     frame #22: 0x00000000004304a0 php-fpm`_start(ap=<unavailable>, 
cleanup=<unavailable>) at crt1_c.c:75:7
----8<----

Thoughts?

-- 
Fuzzy love,
-CyberLeo


Technical Administrator

CyberLeo.Net Webhosting
http://www.CyberLeo.Net

Element9 Communications
http://www.Element9.net


Furry Peace! - http://www.fur.com/peace/