Нечетная задержка вывода Ruby под nohup?

Я вижу некоторое запутанное поведение со скриптом Ruby при работе под nohup. В основном я делаю это:

require 'logger'

logger_file = open('/mnt/dbsdata/output.log', File::WRONLY | File::APPEND | File::CREAT)
LOGGER = Logger.new(logger_file)
LOGGER.level = Logger::INFO

  def run_command(cmd,display=true)
    if display
      LOGGER.info "Executing: #{cmd}"
    end
    output = `#{cmd} 2>&1` ; results=$?.success?
    if ! results
        LOGGER.error "FAILED to execute #{cmd}"
        LOGGER.error output
        return false
    end
    return true
  end

begin
  run_command("some_longrunning_command", true)
  run_command("some_other_longrunning_command",true)
  # etc...
end

Что здесь странно, так это то, что как при использовании Logger, как указано выше, так и при обычном puts в STDOUT (nohup.out) синхронизация вывода сильно отличается. Я думаю, что мог бы просто просмотреть файл журнала и увидеть сообщения регистрации в реальном времени (сообщение журнала, выполнить команду, повторить), однако то, что происходит, представляет собой массовую очистку сообщений для регистрации многих устаревших сообщений одновременно, спустя много времени после того, как их команда была уже выполнено и завершено.

При выполнении скрипта из оболочки:

`nohup ruby myscript.rb &`

Это ведет себя так, как ожидалось, если не работает под nohup.

Кто-нибудь сталкивался с этим и знает хороший обходной путь?


ruby linux nohup
person Madmartigan    schedule 18.10.2013    source источник

Ответы (2)


arrow_upward
2
arrow_downward

Я не могу сказать наверняка, но похоже на проблему с IO sync. Ввод/вывод обычно буферизуется для скорости. ОЗУ работает намного быстрее, чем диски, поэтому операции чтения и записи временно сохраняются до тех пор, пока данные не будут запрошены кодом или пока диск не сможет их получить. В классе ввода-вывода Ruby есть метод sync=, который позволяет указать Ruby немедленно очищать буфер при записи.

Это должно работать:

logger_file = open('/mnt/dbsdata/output.log', File::WRONLY | File::APPEND | File::CREAT)
logger_file.sync = true
LOGGER = Logger.new(logger_file)
LOGGER.level = Logger::INFO

Для простоты вы можете создать правильный режим для своего вывода, используя:

    logger_file = File.open('/mnt/dbsdata/output.log', 'a')
person the Tin Man    schedule 18.10.2013
comment
Отлично, это победитель. Большое спасибо. - person Madmartigan; 19.10.2013
comment
Просто предостережение: не запускайте синхронизацию без крайней необходимости, например, когда вы записываете в журнал или используете Logger. Для обычного ввода-вывода позвольте Ruby буферизовать его. Ваш процессор и скорость кода будут вам благодарны. - person the Tin Man; 19.10.2013
comment
Спасибо за совет. Ведение журнала не является слишком частым и подробным, поэтому в этом случае я не вижу слишком большого снижения производительности. Как уже говорилось, эта проблема возникает только тогда, когда скрипт находится под nohup — и не только с регистратором, но и с обычным стандартным выводом. Если вам известны какие-либо ресурсы, которые могли бы объяснить это, я был бы признателен за ссылку. В противном случае я также могу рассмотреть демонизацию. Спасибо еще раз. - person Madmartigan; 19.10.2013
comment
Я не сторонник демонизации, потому что ее сложно отлаживать, настраивать и т. д. nohup — это своего рода демонизация для бедняков, но ее НАМНОГО легче отлаживать. Вы можете спросить об этом на superuser.com, это родственный сайт для системных администраторов, которые знают гораздо больше о том, что может вызвать эту проблему. Удачи! - person the Tin Man; 19.10.2013
comment
Вместо использования STDOUT.sync = true вы можете вызвать STDOUT.flush в тех точках, где хотите сбросить вывод. Это дает вам лучший контроль над тем, когда сбрасывать буфер и какой именно буфер. Однако вы все еще во власти ОС, по крайней мере, для МРТ. - person vgoff; 19.10.2013
comment
OP не использует STDOUT, поэтому использование sync или flush на этом канале не поможет. sync должен появиться в дескрипторе файла, который открыт и затем передается в Logger. - person the Tin Man; 19.10.2013

arrow_upward
0
arrow_downward

Похоже на буферизацию. Попробуйте войти в stderr и посмотрите, поможет ли это.

person Some Guy    schedule 18.10.2013