Может ли обработчик SMTP ведения журнала Python заморозить мою ветку на 2 минуты?

Question

Согласно моему лог-файлу, произошла довольно запутанная последовательность событий, и я собираюсь обвинить Python logger, что является смелым заявлением. Я подумал, что должен получить второе мнение о том, может ли то, что я говорю, быть правдой.

Я пытаюсь объяснить, почему в моем файле журнала есть несколько больших пробелов (около двух минут за раз) во время стрессовых периодов для моего приложения, когда оно пропускает сроки.

Я использую модуль журналирования Python на удаленном сервере и у меня есть настройка с файлом конфигурации, чтобы все журналы серьезности ОШИБКИ или выше отправлялись мне по электронной почте. Как правило, за один раз будет отправляться только одна ошибка, но в периоды длительных проблем я могу получить дюжину в минуту - раздражает, но ничего, что не должно подчеркивать SMTP.

Я считаю, что после короткого всплеска таких сообщений система регистрации Python (или, возможно, система SMTP, на которой она находится) сталкивается с ошибками или перегрузкой. Затем вызов журнала Python блокируется в течение двух минут, в результате чего мой поток пропускает сроки. (Я был достаточно умен, чтобы перемещать журналы до критического пути приложения - поэтому мне все равно, если регистрация займет у меня несколько секунд, но две минуты это слишком долго.)

Это выглядит как довольно неловкая архитектура (как для системы журналирования, которая может зависнуть, так и для системы SMTP (Ubuntu, sendmail), которая не может обрабатывать десятки писем в минуту **), так что это удивляет меня, но это точно соответствует симптомам.

Кто-нибудь имел опыт работы с этим? Кто-нибудь может описать, как остановить его от блокировки?

** РЕДАКТИРОВАТЬ # 2: Я действительно посчитал. 170 писем за два часа. Забудьте предыдущее редактирование. Я посчитал неправильно. Уже поздно ...

Answer 1

Стресс-тестирование показало:

Моя конфигурация журналов отправляла важные сообщения SMTPHandler и отлаживала сообщения в локальный файл журнала.

Для тестирования я создал умеренно большое количество потоков (например, 50), которые ожидали триггера, а затем одновременно пытались записать критическое сообщение или сообщение отладки, в зависимости от теста.

Тест № 1: Все потоки отправляют критические сообщения: выяснилось, что на отправку первого критического сообщения ушло около 0,9 секунды. Второе критическое сообщение заняло около 1,9 секунды. Третий еще дольше, быстро складывается. Похоже, что сообщения, отправляемые на электронную почту, блокируют ожидание завершения отправки.

Тест № 2: Все потоки отправляют сообщения отладки: они запускаются довольно быстро, от сотен до тысяч микросекунд.

Тест № 3: смесь обоих. Из результатов стало ясно, что отладочные сообщения также блокировались в ожидании отправки сообщений с критическими сообщениями.

Так, не то, чтобы 2 минуты означали тайм-аут. Именно эти две минуты представляли большое количество заблокированных потоков, ожидающих в очереди.

Почему столько критических сообщений отправлялось одновременно? Это ирония. Внутри метода, который включал сетевой вызов, был вызов logging.debug (). У меня был какой-то код, отслеживающий скорость метода (чтобы увидеть, не слишком ли длинный сетевой вызов). Если это так, он (конечно) зарегистрировал критическую ошибку, которая отправила электронное письмо. Затем следующий поток заблокировался при вызове logging.debug (), что означает, что он пропустил крайний срок, вызвав еще одно электронное письмо и запустив другой поток для медленной работы.

2-минутная задержка в одном потоке не была сетевым таймаутом. Это был один поток, ожидающий другого потока, который был заблокирован на 1 минуту 57 - потому что он ожидал другого потока, заблокированного на 1 минуту 55 и т. Д. И т. Д. И т. Д.

Это не очень красивое поведение от SMTPHandler.

Answer 2

Двухминутная пауза звучит как тайм-аут - в основном, вероятно, в сетевом стеке.

Попробуйте добавить:

*                -       nofile          64000

в файл /etc/security/limits.conf на всех задействованных машинах, а затем перезагрузите все машины, чтобы убедиться, что он применяется ко всем работающим службам.