uWSGIで大きいログが壊れないようにする設定

uWSGIがファイルやパイプにログを書くときは、各ワーカープロセスが直接ファイルやパイプに書く場合と、一旦masterプロセスにログを送ってmasterプロセスからログを書く場合があります。

masterプロセスにログを送る設定は --log-master ですが、このオプションを暗黙的に有効にするオプションがあります。 UWSGI_OPT_LOG_MASTERUWSGI_OPT_REQ_LOG_MASTER というフラグが指定された場合に log_master が設定されるようになっていて、uwsgi-2.0ブランチではこれらのオプション(エイリアスを含む)にそのフラグが指定されています。

touch-logrotate
touch-logreopen
log-syslog
log-socket
req-logger
logger-req
logger
threaded-logger
log-encoder
log-req-encoder
log-drain
log-filter
log-route
log-req-route
log-alarm
alarm-log
not-log-alarm
not-alarm-log
log-master
log-maxsize

他にもネットワーク経由で外にログを飛ばすようなプラグインがlog_masterを有効にすることもあるので、なにかプラグインを使っている場合は確認してください。

log_masterを有効にしていない場合は、ログの出力先がファイルなら1回のwriteで書かれるサイズは実質的に無制限にアトミックに書かれ、他のスレッドやプロセスからのwrite()と混ざらないと思います。参考に、Linuxの man wirte(2)には次のように書かれていて、Linux 3.14からは問題ないようです。あまりに大きい場合は途中でシグナルが来た時にどうなるかわかりませんが、バッファに乗る範囲のログなら気にしなくてもいいんじゃないかな。

       According to POSIX.1-2008/SUSv4 Section XSI 2.9.7 ("Thread
       Interactions with Regular File Operations"):

           All of the following functions shall be atomic with respect
           to each other in the effects specified in POSIX.1-2008 when
           they operate on regular files or symbolic links: ...

       Among the APIs subsequently listed are write() and writev(2).
       And among the effects that should be atomic across threads (and
       processes) are updates of the file offset.  However, before Linux
       3.14, this was not the case: if two processes that share an open
       file description (see open(2)) perform a write() (or writev(2))
       at the same time, then the I/O operations were not atomic with
       respect to updating the file offset, with the result that the
       blocks of data output by the two processes might (incorrectly)
       overlap.  This problem was fixed in Linux 3.14.

write(2) - Linux manual page

パイプの場合は一度に書き込めるサイズはPIPE_BUFで、POSIXで512バイト、Linuxでは4096バイトになります。これを超える場合は一度でwriteできない可能性があり、1行のログをループで複数回write()する可能性があるので、他のプロセスが書いたログが1行の間に割り込む可能性があります。ログを標準出力等からパイプに書きたい場合は、 --log-master を指定した方が壊れにくくなります。

   PIPE_BUF
       POSIX.1 says that writes of less than PIPE_BUF bytes must be
       atomic: the output data is written to the pipe as a contiguous
       sequence.  Writes of more than PIPE_BUF bytes may be nonatomic:
       the kernel may interleave the data with data written by other
       processes.  POSIX.1 requires PIPE_BUF to be at least 512 bytes.
       (On Linux, PIPE_BUF is 4096 bytes.)

pipe(7) - Linux manual page

つぎは log_master が有効な場合です。この場合、 --log-master-stream を指定していなければUnixドメインソケットでパケット型の通信をします。Linuxの場合は SOCK_SEQPACKET が使われます。

// core/logging.c の create_logpipe()
#if defined(SOCK_SEQPACKET) && defined(__linux__)
        if (socketpair(AF_UNIX, SOCK_SEQPACKET, 0, uwsgi.shared->worker_log_pipe)) {
#else
        if (socketpair(AF_UNIX, SOCK_DGRAM, 0, uwsgi.shared->worker_log_pipe)) {
#endif

システムコールとして送受信できるサイズはソケットバッファに制限され net.core.wmem_default, net.core.rmem_default がデフォルトですが、実際には uWSGI の log_master_bufsize のデフォルト値 8192 バイトがログ1行を壊れずに書けるデフォルトの上限になります。uWSGIがこのサイズの送受信バッファを持っていて、このサイズを超える部分は分割ではなく破棄されるためです。

なるべくログを壊したくない場合は、 --log-master-bufsize オプションにもっと大きい値を指定できまず。ソケットバッファが log-master-bufsize より小さい場合はsetsockoptでソケットバッファも大きくするので、net.core.wmem_default, net.core.rmem_default よりも大きい値を指定できます。 --log-master-bufsize のドキュメントには64bit整数と書かれていますが、 setsockopt を呼び出す時にint型を利用しているので、実質的な最大値は 231-1 になります。

ログ転送ミドルウェアがログを読み込む時にも1レコードの最大サイズを指定することが多いと思うので、それと合わせて、普段の数倍のデカいスタックトレースが生成されてもログを取りこぼさない程度の大きさを指定するといいでしょう。

このブログに乗せているコードは引用を除き CC0 1.0 で提供します。