nohup 下奇怪的 Ruby 输出滞后？答案

【问题标题】：Odd Ruby output lag under nohup?nohup 下奇怪的 Ruby 输出滞后？
【发布时间】：2013-10-18 17:30:34
【问题描述】：

在nohup 下运行时，我发现 Ruby 脚本存在一些令人困惑的行为。基本上我是这样做的：

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) 时，输出时序都相差甚远。我想我可以只跟踪日志文件并查看实时记录消息（记录消息、执行命令、重复），但是正在发生的事情是大量刷新消息以一次记录许多过时的消息，在他们的命令很久之后已经执行并完成。

当像这样从 shell 执行脚本时：

`nohup ruby myscript.rb &`

当不在 nohup 下运行时，它的行为与预期一样。

有人遇到过这种情况并知道一个好的解决方法吗？

【问题讨论】：

标签： ruby linux nohup

【解决方案1】：

我不能肯定地说，但这听起来像是一个 IO sync 问题。 I/O 通常被缓冲以提高速度。 RAM 比磁盘快很多，因此读取和写入是临时存储的，直到代码请求数据或磁盘能够接收数据。 Ruby 的 IO 类具有 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')

【讨论】：

太棒了，那是赢家。非常感谢。
请注意：除非绝对必要，否则不要强制同步，例如在写入日志或使用 Logger 时。对于普通的 I/O，让 Ruby 缓冲它。您的 CPU 和代码速度将感谢您。
感谢您的提示。日志记录既不太频繁也不太冗长，因此在这种情况下我没有看到太多的性能影响。如前所述，此问题仅在脚本处于 nohup 下时发生 - 不仅在记录器中，在正常标准输出中也是如此。如果您知道任何可以解释这一点的资源，我会很感激一个链接。否则，我也可以考虑守护进程。再次感谢。
我不喜欢守护进程，因为它很难调试、设置等。nohup 有点像穷人的守护进程，但调试起来要容易得多。您可能会在superuser.com 上询问这个问题，这是系统管理员的兄弟网站，他们会更了解可能导致此问题的原因。祝你好运！
您可以在要刷新输出的位置调用STDOUT.flush，而不是使用 STDOUT.sync = true。这使您可以更好地控制何时刷新缓冲区以及哪个特定缓冲区。不过，您仍然受制于操作系统，至少对于 MRI 而言。

【解决方案2】：

听起来像缓冲。尝试登录到 stderr 看看是否有帮助。

【讨论】：