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

[h.kondo]

近藤です。

情報のご提供ありがとうございます。

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

ご指摘の通りです。

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

>動作の遅延とは

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

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


「プロセス内で 呼び出している 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 の処理は、バッファーに空きがあれば待たずに戻る
>と思います。

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

シリアル通信を使用して、外部機器とデータ送受信を行っています。
データ受信後、通常は数ms～数十msで返信しているのですが、たまに500ms以上返信が遅れる
場合があり、それにより通信異常となってしまうことが課題点です。

前回コメントしたようにログ出力数を減らすことにより頻度はかなり減ったため、
そこがボトルネックと考えて調べています。

>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

>してみると分ります。

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

貴重な情報およびご指摘ありがとうございます。