Python time.sleep — никогда не просыпаться

Я думаю, что это будет одна из тех простых проблем, когда вы это видите, но это сбило меня с толку.

[СТОП НАЖМИТЕ: я был прав. Решение было найдено. См. ответы.]

Я использую Python unittest framework для тестирования многопоточного приложения. Красиво и прямолинейно - у меня есть около 5 рабочих потоков, отслеживающих общую очередь, и один поток-производитель, создающий для них рабочие элементы. Поток-производитель запускается тестовым примером.

В этом тесте в очередь ставится только одна задача. Обработка, которую он выполняет в тесте, является просто заглушкой для реальной обработки, поэтому рабочий поток делает 5-секундный сон, чтобы имитировать прошедшее время до того, как задача действительно будет выполнена, и поток будет готов получить другую задачу. .

К фрагменту кода относится:

 logging.info("Sleep starting")
 time.sleep(5)
 logging.info("Waking up")

Теперь самое странное. Я вижу сообщение журнала «Начало сна», но не вижу сообщение о пробуждении. Программа зависает и не реагирует на прерывание клавиатуры (CTRL+C). Загрузка процессора очень низкая.

Я вижу ту же проблему в Windows и Ubuntu (Python 2.6.2).

Я подумал, возникает ли исключение и скрывается ли оно, поэтому я добавляю «печать 1/0» между первой и второй строкой - я вижу, что возникает ошибка «Деление на ноль». Я перемещаю его после сна, и я никогда не вижу сообщения.

Я подумал: «Хорошо, может быть, другой поток пытается одновременно зарегистрировать что-то очень-очень большое, и он все еще буферизуется. Что он делает?»

Что ж, к этому времени тест вернулся к модульному тесту, где он приостанавливается, ожидая начала работы потока, прежде чем проверять состояние системы.

 logging.info("Test sleep starting")
 time.sleep(0.25)
 logging.info("Test waking up")

Вау, это выглядит знакомо. Замерзает точно так же! Первое сообщение журнала появляется, второе нет.

Недавно я значительно переписал модуль, поэтому я не могу утверждать, что «ничего не трогал», но я не вижу ничего плохого в своих изменениях.

Подозрительные области:

• Я включаю использование Threading.Lock (потому что я не знаю, как рассуждать о безопасности GIL, поэтому я придерживаюсь того, что знаю. Я не вижу ничего «тупикового» в моем коде.

• Я новичок в Python unittest framework. Есть ли что-то, что он делает с перенаправлением ведения журнала или подобным, что может имитировать эти симптомы?

• Нет, я не подменял нестандартный модуль времени!

Что помешает потоку проснуться? Что еще я пропустил?