Я обнаружил в системном журнале нескольких серверов, что некоторые сообщения, связанные с CRON, написаны не вовремя, например, следующее:
Aug 21 06:26:01 hty-controller CRON[30159]: (root) CMD ( python /.../clean_image_child.py)
Aug 21 06:26:01 hty-controller CRON[30156]: (CRON) info (...)
Aug 21 06:26:03 hty-controller CRON[29302]: (CRON) info (...)
Aug 19 04:01:01 hty-controller CRON[30176]: (root) CMD ( python /.../clean_image_child.py)
Aug 21 06:27:01 hty-controller CRON[30178]: (root) CMD ( python /var/lib/.../recycle_bin.py)
Aug 21 06:27:01 hty-controller CRON[30179]: (root) CMD ( python /.../clean_image_child.py)
Aug 21 06:27:01 hty-controller CRON[30177]: (CRON) info (...)
Обнаружено, что сообщения с «неправильным временем» относятся к предыдущей дате и времени, и в содержании системного журнала в то время, на которое делается ссылка, фактически отсутствуют именно эти строки сообщений (согласно расписанию CRON). То есть сообщения при записи в системный журнал кажутся задержанными надолго.
В приведенном выше примере скрипт clean_image_child.py выполняется каждую минуту. Ожидаемая одна строка сообщения CRON о его выполнении не появилась в системном журнале в минуту «19 августа, 04:01», а была отложена до (после) «21 августа 06:26». Тщательная проверка всех серверов показывает, что наблюдение можно подтвердить для всех таких случаев, когда у нас все еще есть «фрагмент системного журнала с отсутствующими сообщениями CRON» (некоторые из них слишком старые и были заменены). И мы не обнаружили таких случаев (задержек сообщений в syslog) ни для каких приложений / служб, кроме CRON.
Мы провели эксперимент, чтобы выяснить это. Мы предоставили CRON еще один сценарий для выполнения каждую минуту, который добавляет одну строку сообщения с меткой времени в другой (собственный) файл журнала. В этом самоуправляемом файле журнала мы получаем одно сообщение сценария каждую минуту без единой ошибки. Но в системном журнале в некоторые моменты отсутствовали сообщения CRON о его запуске, которые появлялись через несколько часов или дней. Таким образом, задерживается только сообщение (а не график выполнения).
На серверах работает ubuntu 14.04.1 LTS с (самокомпилированным) ядром 3.18 (3.18.0-031800-generic X86_64). Версия CRON - 3.0pl1-124ubuntu2. Версия rsyslogd - 7.4.4-1ubuntu2.
Хотя похоже, что это поведение не повлияет на другие службы в системе, мне все еще любопытно - почему это могло произойти? Это ошибка или пропуск конфигурации в CRON, или в rsyslogd, или несовпадение версии ядра и этих приложений?
На самом деле это дубликат комментария @Stone. Просто дайте понять всем, что на это есть ответ.
Короче говоря, в используемой мной версии rsyslog есть ошибка, которая задерживает полученное сообщение системного журнала на произвольный период времени. Отчет об ошибке здесь. И обновление rsyslog решило проблему. Это не вина CRON.