Перемещение журнала Rails позволяет сохранить старый журнал открытым и заполнить его

Question

Я помогаю поддерживать сайт Rails.Он работает на JRuby 1.5.5, Rails 2.3.10, на машине Solaris Sparc.У меня есть проблема, связанная с ведением журнала.

Чтобы наши файлы журналов не становились слишком большими и не заполняли диск, мы используем смещение журналов, встроенное в класс Logger.В config / environment / production.rb у нас есть:

config.logger = Logger.new(config.log_path, 10, 100.megabyte)

, который должен вращать файлы журнала, когда они достигают 100 мегабайт, и хранить только 10 файлов.

Проблема двоякая:Rails не вращает журналы должным образом, и он сохраняет открытый файл журнала для записи в него - но то, что он пишет, это просто повторяющееся содержимое нескольких запросов.Поэтому, если я сделаю ls -l log, я увижу что-то вроде этого:

-rw-r--r-- 83040892 Oct  4 15:07 production.log
-rw-r--r-- 3303158664 Oct  4 15:07 production.log.0
-rw-r--r-- 104857616 Oct  2 23:13 production.log.1
-rw-r--r-- 104857618 Oct  1 17:12 production.log.2

Обратите внимание, что последний циклический журнал все еще открыт и все еще записывается (запуск pfiles подтверждает, что сервер Rails все еще имееттри файловых дескриптора к журналу).Также обратите внимание, что он достиг 3 гигабайт за два дня, где обычно мы используем 100 МБ в день.Это потому, что он полон повторных запросов.Я не могу легко вставить это здесь, но журнал полон того же 1000-строчного фрагмента запросов с 18:50 3 октября (который, я считаю, является точкой, в которой журналы вращаются), напечатанной снова и снова.Исходя из прошлого опыта, файл журнала будет продолжать заполняться этим повторяющимся содержимым, пока диск не заполнится.

Является ли смещение журнала / запись в Rails просто поврежденной?(В нашем использовании лог-файла нет ничего странного: мы не ведем прямую регистрацию, все это происходит из инфраструктуры Rails.) Очевидный следующий шаг - попробовать что-то вроде logrotate, но если Rails отказывается закрывать старые файлы журнала ипишет им навсегда, я подозреваю, что это не решит мою проблему (потому что журнал никогда не будет закрыт, и, следовательно, дисковое пространство никогда не восстановится).

Answer 1

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

Причина наиболее вероятна в том, что один или несколько ваших экземпляров или потоков Rails все еще используют дескриптор старого файла .

Решение состоит в том, чтобы убедиться, что все экземпляры Rails полностью перезапускаются после вращения журналов, поэтому все они используют новый дескриптор / имя файла.

Используйте logrotate вместо config.logger для поворота ваших журналов!

Я бы предложил использовать вращение журналов UNIX для вращения журналов, а не config.logger. ИМХО, это лучшее решение, более надежное, у вас больше контроля над ротацией журналов, и вы можете предоставить некоторые команды после ротации для перезапуска ваших процессов Rails. (либо через опцию logrotate postrotate или endscript)

См .:

http://www.opencsw.org/packages/logrotate/ (пакет logrotate для Solaris)

http://www.thegeekstuff.com/2010/07/logrotate-examples/ (учебник logrotate с примерами)

http://linux.die.net/man/8/logrotate

Можно ли использовать единорога? - Unicorn имеет встроенную поддержку для повторного открытия всех файлов журнала в вашем приложении с помощью сигнала USR1 - это позволяет logrotate вращать файлы атомарно ... - Единорог отслеживает и перезапускает своих работников! Вы можете убить рабочих после ротации журнала, и Unicorn перезапустит их, убедившись, что они используют новый файл журнала.

См .: https://github.com/blog/517-unicorn (много преимуществ для единорога над монгрелом)

Если вы используете Mongrel и не можете переключиться на Unicorn:

используйте logrotate и перезапустите ваш Mongrels с помощью опции postrotate.

надеюсь, это поможет ..

Answer 2

Я всегда использовал механизм ротации логов платформы при работе с файлами логов Rails.Следуя советам http://www.nullislove.com/2007/09/10/rotating-rails-log-files/, а также потому, что я запускаю Passenger с http://overstimulate.com/articles/logrotate-rails-passenger.

Первый метод использует метод logrotate copytruncate для создания нового файла журнала, поэтому процессы обрабатываютсяу которого все еще есть дескриптор, он всегда будет записывать в текущий файл журнала.

Другие вещи, которые нужно проверить на сервере:

• Убедитесь, что ни один из гемов или плагинов не имеетдескриптор Logger в контексте ruby.
• Поскольку вы используете JRuby, убедитесь, что где-то нет застрявшего / сбегающего потока, который пытается выполнить запрос, но застревает в журнале.
• Как и в случае с Passenger, рассмотрите возможность перезапуска процессов сервера Rails время от времени.Я знаю, что это действительно хак, но это может сработать.

Answer 3

Нейл,

Я не знаю, работает ли это для вашей конкретной ситуации, но у меня была похожая проблема, и я думаю, что я только что решил ее.В моем случае у меня было два симптома.Первой была та же проблема, что и у вас - мой ротация журналов была чокнутой ... в частности, файл production.log.1 оставался открытым, и продолжалась запись в журнал, пока производственный журнал также регистрировался.Вторым симптомом было то, что владельцы файлов журналов и членство в группах продолжали меняться на root.Мое приложение Rails разворачивается через Capistrano, используя пользователя 'deployer', поэтому я получаю все возможные аккуратные ошибки всякий раз, когда приложение пытается записать файл журнала, который больше не принадлежит развертывателю.

Мне стыдно сказать, сколько времени мне потребовалось, чтобы понять причину обеих проблем.Где-то по пути я обновил cron crontab приложения от имени root .Должно быть, это было, когда я возился в командной строке ... если бы я просто остался с моим рецептом развертывания через Capistrano, я бы не сделал этого случайно.В любом случае, я наконец заглянул в / var / spool / cron / crontabs и нашел две копии моего файла crontab: одну для развертывания и одну для root.Итак, процессы, запущенные cron для моего приложения, дублировались - один был запущен в среде развертывания, а второй - под root.Это был тот второй, который все испортил.Как только я удалил crontab рута, все стало лучше.

Некоторые предостережения: в моей настройке не было никаких задач, не связанных с приложением, в crontab root, то есть это был точный дубликат crontab развертывателя ... поэтому удаление его не имело для меня побочных эффектов.Кроме того, мой сервер работает под управлением Ubuntu ... путь к вашим crontabs может быть другим.

Надеюсь, это поможет.

• David

Answer 4

Я думаю, что вы забыли 's' в мегабайтах или вместо этого используйте что-то вроде этого

config.logger = Logger.new(config.log_path, 10, 102400)

также проверьте эту ссылку, это очень полезно

http://railsillustrated.com/logger-tricks.html