[Armadillo:09013] Re: syslogdの挙動について

Yasushi SHOJI email@hidden
2013年 7月 10日 (水) 20:44:30 JST


こんにちは、

At Tue, 9 Jul 2013 18:40:19 +0900,
h.kondo wrote:
>
> 一般的な情報を調べたところ、「プロセスからのログ出力が多すぎると、カーネル内のバッファが
> 一杯になり、syslogdがバッファから読み出して空きができるまでプロセスが待たされる」とのことで、
> 大量にログ出力をしないほうがよいと考えています。

プロセスと syslogd は、unix domain で通信します。その通信はカーネルが処
理しますが、「カーネルが unix domain の処理につかうバッファが一杯になり、
syslog(3)を呼んでいるプロセスが待たされる」という事でしょうか?

上記の様な状況はありそうですね。syslogd がログを書き出すときの I/Oがボ
トルネックになり recv(3)できない状況にもかかわらず、多くsyslog(3) され
た場合などが考えられます。

> しかしながら、必要最低限のログ出力にしても、少なからず動作が遅延しているように見え、問題となっています。

動作の遅延とは

  - 「あるプロセスがsyslog(3)を呼び出してから、syslogd がファイルに書き
    出すまでの時間が、希望しているよりも遅い」という認識で良いですか?それとも、

  - 上記の説明にあるようにバッファーが空くまで待ちたくないという意味で
    は、「プロセス内で 呼び出している syslog(3)から抜けてくるまでに時間」
    という意味でしょうか?

また、もし可能であれば

  - 「どれくらいのオーダーの遅延を気にしているか」という点と、
  - 「なぜ、遅延を気にされているか」を教えて頂けますか?

というのも、syslogd はログの書き出し遅延を気にするような場合には、向い
ていないと思います。syslog(3)を呼び出すと、以下のような流れで syslogd
がファイルにログを書き出します。

 - プロセスが syslog(3)をコール
 - カーネルへのタスクスイッチ
 - syslogd が、ログを recv(3)
 - syslogd が、ログを書き出すファイルを open(2)
 - syslogd が、ログを printf(3)
 - syslogd が、ログを close(2)するタイミングで、最後のデータがファイル
   に書き出される

syslog(3)から戻ってくるのは、syslog(3)内でデーターを送り出した後になる
と思いますので、syslogd の処理は、バッファーに空きがあれば待たずに戻る
と思います。

しかし、もし遅延を気にする場合は、自前でログに書き出した方が良いと思い
ます。

> 一般的には、syslogdがfsync()することにより性能が低下するとのことで、fsync()をしないようにすればよいのではないか
> と考えましたが、syslogdのソースを見ると、もともとfsync()をしていないようです。(正しいでしょうか)

a440の syslogd である busybox の sysklogd のソースを見てみました。
user/busybox/sysklogd/syslogd.c::message()まわりを見ても *sync()は入っ
てなさそうに見えます。

> 対策として、カーネル内のバッファサイズを大きくして試してみたいと考えていますが、そのような事は可能でしょうか。

「動作の遅延対策として、カーネル内の unix domain で使っているバッファサ
イズを大きくしたい」いう話であってますか?

 - /proc/sys/net/core/rmem_max
 - /proc/sys/net/core/wmem_max

で、カーネルが通信に使うメモリサイズの上限を決めれたはずです。


> 可能な場合、ご教示をお願いします。
> また、デフォルトのバッファサイズはいくつなのでしょうか。

cat /proc/sys/net/core/rmem_max

してみると分ります。


遅延などを追うときは、ボトルネックをしっかり調べてからの方が良いかもし
れません。
--
          yashi




armadillo メーリングリストの案内