phpdaemon icon indicating copy to clipboard operation
phpdaemon copied to clipboard

Часть процессов phpDaemon впадает в бесконечный цикл вызовов epoll_wait и увеличивают использование cpu

Open lightbliss opened this issue 4 years ago • 6 comments

Добрый день! Используем phpDaemon для обработки API-запросов. Столкнулись с такой проблемой, что несколько (примерно равно количеству ядер на сервере) процессов phpd через некоторое время (если полностью перезапустить мастер-процесс, то через 10 минут) начинают очень активно делать системные вызовы "epoll_wait" такого вида: [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 766) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 766) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 766) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 762) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 762) = 1

Стрейс статистика по процессу показывает такое: % time | seconds | usecs/call | calls | errors | syscall 98.98 | 0.661405 | 5 | 121343 | | epoll_wait

lsof процесса выглядит так: COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME ... php 7118 root 2u a_inode 0,10 0 6487 [eventfd] php 7118 root 3r CHR 1,9 0t0 1033 /dev/urandom php 7118 root 4u a_inode 0,10 0 6487 [eventfd] php 7118 root 5u a_inode 0,10 0 6487 [eventpoll] php 7118 root 6u a_inode 0,10 0 6487 [eventfd] php 7118 root 7u a_inode 0,10 0 6487 [eventpoll] php 7118 root 8w REG 253,0 79811 136834586 /var/log/phpdaemon.log php 7118 root 9u a_inode 0,10 0 6487 [eventfd] ...

Эти процессы сразу начинают использовать cpu на 100% и cpu на сервере начинает упираться в полку (50% system, 40% nice). При этом кажется, что процессы просто греют воздух и реальной работы не делают. Когда же приходят настоящие запросы, то они успешно выполняются и 5xx ошибок мы не наблюдаем.

Версия phpDaemon: commit e8d51786e847fe4bf6639cbd152b0c19d6cdb360 Версия php 7.0.33 Версия php-расширения event 2.4.1 libevent2 headers version => 2.0.21-stable

Конфиг phpDaemon: min-workers 64; max-workers 128; min-spare-workers 32; max-spare-workers 64; start-workers 64; max-idle 120; max-requests 16384;

phpDaemon запускается через systemd

На виртуалке - 8 ядер, система - CentOS Linux 7. Также, по наблюдениям, если уменьшить первые 4 опции в конфиге phpDeamon в 2 раза (min-workers, max-workers, min-spare-workers, max-spare-workers), то 100% использования cpu прекращается, но по htop и strace видно, что больные процессы все еще появляются в системе. На более мощном сервере (20 ядер), при таких же настройках phpDaemon, процессы с бесконечным вызовом epoll_wait не появляются.

Можно ли как-то такое поведение с воркерами починить, чтобы не было бесконечных вызовов epoll_wait?

lightbliss avatar Jul 27 '21 09:07 lightbliss

Добрый день!

Такая проблема возникает когда изнутри event loop наружу выбрасывается исключение. Нужно отследить этот момент и добавить try/catch в нужное место.

вт, 27 июл. 2021 г. в 12:40, Makarenko Sergey @.***>:

Добрый день! Используем phpDaemon для обработки API-запросов. Столкнулись с такой проблемой, что несколько (примерно равно количеству ядер на сервере) процессов phpd через некоторое время (если полностью перезапустить мастер-процесс, то через 10 минут) начинают очень активно делать системные вызовы "epoll_wait" такого вида: [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 766) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 766) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 766) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 764) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 763) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 762) = 1 [pid 7118] epoll_wait(7, {EPOLLIN, {u32=2, u64=2}}, 32, 762) = 1

Стрейс статистика по процессу показывает такое: % time | seconds | usecs/call | calls | errors | syscall 98.98 | 0.661405 | 5 | 121343 | | epoll_wait

lsof процесса выглядит так: COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME ... php 7118 root 2u a_inode 0,10 0 6487 [eventfd] php 7118 root 3r CHR 1,9 0t0 1033 /dev/urandom php 7118 root 4u a_inode 0,10 0 6487 [eventfd] php 7118 root 5u a_inode 0,10 0 6487 [eventpoll] php 7118 root 6u a_inode 0,10 0 6487 [eventfd] php 7118 root 7u a_inode 0,10 0 6487 [eventpoll] php 7118 root 8w REG 253,0 79811 136834586 /var/log/phpdaemon.log php 7118 root 9u a_inode 0,10 0 6487 [eventfd] ...

Эти процессы сразу начинают использовать cpu на 100% и cpu на сервере начинает упираться в полку (50% system, 40% nice). При этом кажется, что процессы просто греют воздух и реальной работы не делают. Когда же приходят настоящие запросы, то они успешно выполняются и 5xx ошибок мы не наблюдаем.

Версия phpDaemon: commit e8d5178 https://github.com/kakserpom/phpdaemon/commit/e8d51786e847fe4bf6639cbd152b0c19d6cdb360 Версия php 7.0.33 Версия php-расширения event 2.4.1 libevent2 headers version => 2.0.21-stable

Конфиг phpDaemon: min-workers 64; max-workers 128; min-spare-workers 32; max-spare-workers 64; start-workers 64; max-idle 120; max-requests 16384;

phpDaemon запускается через systemd

На виртуалке - 8 ядер, система - CentOS Linux 7. Также, по наблюдениям, если уменьшить первые 4 опции в конфиге phpDeamon в 2 раза (min-workers, max-workers, min-spare-workers, max-spare-workers), то 100% использования cpu прекращается, но по htop и strace видно, что больные процессы все еще появляются в системе. На более мощном сервере (20 ядер), при таких же настройках phpDaemon, процессы с бесконечным вызовом epoll_wait не появляются.

Можно ли как-то такое поведение с воркерами починить, чтобы не было бесконечных вызовов epoll_wait?

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/kakserpom/phpdaemon/issues/300, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABKZ5UFW2OGR74S62GPGBTTZZ5HNANCNFSM5BB3LQRQ .

kakserpom avatar Jul 27 '21 10:07 kakserpom

Добрый день! Могу попросить вас более подробно рассказать про это исключение?

Я заглянул поглубже в код, но, пока, не нашел место, откуда такое исключение может выбрасываться. Обернул самые верхние функции в try/catch, но тоже пока ничего не словил.

И, по идее, если выбрасывается необработанное исключение, то запрос должен завершаться неудачей с 5xx ошибкой, а в логах должно появляться что-то вроде "Fatal error: Uncaught Exception", но мы таких записей не наблюдаем. Или я ошибаюсь и оно так не работает?

lightbliss avatar Jul 29 '21 06:07 lightbliss

Еще забыл добавить такое уточнение, что если перезапустить все процессы phpd полностью, то воркеры заболевают одновременно и ровно через 10 минут (засекали по часам). Это не зависит от мощности сервера и нагрузки на сервер, всегда 10 минут.

lightbliss avatar Jul 29 '21 07:07 lightbliss

В итоге, удалось выяснить, что проблема исчезает, если использовать eio-enabled = false

eio

eio support => enabled
Debug support => disabled
Version => 2.0.4

Кажется, что зависает где-то на вызове PHPDaemon\FS\FileSystem::waitAllEvents() при завершении работы воркера

nkolosov avatar Aug 03 '21 05:08 nkolosov

Очень интересно! Было бы классно подебажить, у вас есть телеграм для связи?

вт, 3 авг. 2021 г. в 08:44, Nikita Kolosov @.***>:

В итоге, удалось выяснить, что проблема исчезает, если использовать eio-enabled = false

eio

eio support => enabled

Debug support => disabled

Version => 2.0.4

Кажется, что зависает где-то на вызове PHPDaemon\FS\FileSystem::waitAllEvents() при завершении работы воркера

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/kakserpom/phpdaemon/issues/300#issuecomment-891547959, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABKZ5WHUYPDAYGFPP4NFZLT2564FANCNFSM5BB3LQRQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&utm_campaign=notification-email .

kakserpom avatar Aug 03 '21 08:08 kakserpom

Да, конечно, буду рад https://t.me/nkolosov

nkolosov avatar Aug 03 '21 08:08 nkolosov