Armadilloフォーラム

lighttpdのシステムログについて

nakamura3776

2014年10月3日 16時00分

Armadillo-420、Linux(atmark-dist v1.28.1 (AtmarkTechno/Armadillo-420)
Linux 2.6.26-at15 [armv5tejl arch])でソフト開発を行っております。

中村です。

漠然とした質問で申し訳ございません。

 システムログを確認したところ、lighttpd から以下のメッセージを出力しております。

 メッセージの内容からWeb画面を操作しないで 360秒経過したものと認識しておりますが、メッセージを出力する
 タイミングが不定期です。(画面を開いてから 6分,12分・・・・1時間以上となります。)

 メッセージの出力条件をお教え願います。

======== messeges の内容 =============================================
Sep 21 07:25:32 lighttpd[1384]: (../../src/server.c.1149) NOTE: a request for /cgi-bin/baseside.cgi?parm1=get_seg timed out after writing 243 bytes. We waited 360 seconds. If this a problem increase server.max-write-idle
=========================================================================

以上 よろしくお願いします。

コメント

中村です。

質問者さんも"中村さん"ですね。

>  メッセージの出力条件をお教え願います。
>
> ======== messeges の内容 =============================================
> Sep 21 07:25:32 lighttpd[1384]: (../../src/server.c.1149) NOTE: a request for /cgi-bin/baseside.cgi?parm1=get_seg timed out after writing 243 bytes. We waited 360 seconds. If this a problem increase server.max-write-idle
> =========================================================================

起動したcgiが終了せず、STDOUTにも何も出力しない時間が
server.max-write-idle以上になったときに、このメッセージが
syslogに記録されます。

server.max-write-idleのデフォルトは360ですが、
/etc/lighttpd.confに設定を書くことで変更できます。
360秒だと実験に時間がかかって大変なので、
server.max-write-idle = 10
として、以下に書く実験をやってみました。

実験用のcgiは、次のような簡単なシェルスクリプトです。
ファイル名は何でもいいですが、/home/www-data/a.cgi
とでもしておきましょう。

#!/bin/sh
 
cat <<__END
Content-Type: text/html
 
<HTML>
<BODY>
hoge<br>
__END
 
sleep 5
echo hogehoge
 
cat <<__END
</BODY>
</HTML>
__END

このスクリプト(cgi)を実行したときには、
"timed out after writing XXX bytes....."
は出ませんが、5秒のsleepを12秒にすると出ます。

sleepのところを次のようにした場合には出ません。

sleep 8
echo hogehoge
sleep 8

もうちょっと極端な例として、次ような場合は
1000秒たっても出ません。

for i in `seq 1 1000`; do
  echo "hoge $i "
  sleep 1
done

しかし、次の場合は、100秒(ループ100回)の後の
sleep 12 のところで出ます。

for i in `seq 1 100`; do
  echo "hoge $i "
  sleep 1
done
sleep 12
echo hogehoge

--
なかむら

> 中村です。
>
> 質問者さんも"中村さん"ですね。
>
> >  メッセージの出力条件をお教え願います。
> >
> > ======== messeges の内容 =============================================
> > Sep 21 07:25:32 lighttpd[1384]: (../../src/server.c.1149) NOTE: a request for /cgi-bin/baseside.cgi?parm1=get_seg timed out after writing 243 bytes. We waited 360 seconds. If this a problem increase server.max-write-idle
> > =========================================================================
>
> 起動したcgiが終了せず、STDOUTにも何も出力しない時間が
> server.max-write-idle以上になったときに、このメッセージが
> syslogに記録されます。
>
> server.max-write-idleのデフォルトは360ですが、
> /etc/lighttpd.confに設定を書くことで変更できます。
> 360秒だと実験に時間がかかって大変なので、
> server.max-write-idle = 10
> として、以下に書く実験をやってみました。
>
> 実験用のcgiは、次のような簡単なシェルスクリプトです。
> ファイル名は何でもいいですが、/home/www-data/a.cgi
> とでもしておきましょう。
>

> #!/bin/sh
> 
> cat <<__END
> Content-Type: text/html
> 
> <HTML>
> <BODY>
> hoge<br>
> __END
> 
> sleep 5
> echo hogehoge
> 
> cat <<__END
> </BODY>
> </HTML>
> __END
> 

>
> このスクリプト(cgi)を実行したときには、
> "timed out after writing XXX bytes....."
> は出ませんが、5秒のsleepを12秒にすると出ます。
>
> sleepのところを次のようにした場合には出ません。
>

> sleep 8
> echo hogehoge
> sleep 8
> 

>
> もうちょっと極端な例として、次ような場合は
> 1000秒たっても出ません。
>

> for i in `seq 1 1000`; do
>   echo "hoge $i "
>   sleep 1
> done
> 

>
> しかし、次の場合は、100秒(ループ100回)の後の
> sleep 12 のところで出ます。
>

> for i in `seq 1 100`; do
>   echo "hoge $i "
>   sleep 1
> done
> sleep 12
> echo hogehoge
> 

>
> --
> なかむら
>
>
>
なかむら様
 中村です。

 ありがとうございます。

 "何も出力しない時間がserver.max-write-idle以上になったときに、このメッセージがsyslogに記録されます。"
 は理解できるのですが、同じ画面で出力するタイミングが一定しない事が不可解した。

 cgiのプログラムを調査いたします。

 

中村です。

>  は理解できるのですが、同じ画面で出力するタイミングが一定しない事が不可解した。

そのcgiが何をしているのかわらないので、再現しやすい方法で
タイミングが一定しない理由を説明したつもりですが、
わかりにくかったでしょうか?

先日の例では、sleepで出力を停止する処理を"~"の中に書きましたが、
次のように"~"の外でsleepしても同じように"timed out after writing XXX bytes"の
メッセージが出ます。

#!/bin/sh
 
cat <<__END
Content-Type: text/html
 
<HTML>
<BODY>
hoge hoge hoge<br>
</BODY>
</HTML>
__END
 
sleep 12           <===== ここです。

こんな例を書くと、もっとわからなくなったりして・・・

--
なかむら

中村です。

質問内容とは関係のない投稿ですが、ここにぶらさげさせてもらいます。

先日も別スレッドで発生しましたが、また本文が表示されない現象が発生してます。
フォーラム画面(web)で「作成者:y.nakamura 作成日:2014/10/06 - 10:38」はあるのですが、
中身が表示されません。

メール配信はちゃんと中身はありました。

--
なかむら

> 中村です。
>
> 質問内容とは関係のない投稿ですが、ここにぶらさげさせてもらいます。
>
> 先日も別スレッドで発生しましたが、また本文が表示されない現象が発生してます。
> フォーラム画面(web)で「作成者:y.nakamura 作成日:2014/10/06 - 10:38」はあるのですが、
> 中身が表示されません。
>
> メール配信はちゃんと中身はありました。
>
> --
> なかむら
>
なかむら様
 中村です。

 回答、ありがとうございます。

 例では、CGIロジックを変更しておりますが、当方では、CGIロジックは変更しないで運用しております。
 同じ面を表示して何もしない状態で、メッセージの出力タイミングが6分後~1時間以上経過する場合が有ったので・・・
 ロジックを見た限り時間が一定しない理由が理解できませんでした。
 このメッセージが出力しても、システムがダウンするとは思われないので問題視はしていません。

中村です。

>  例では、CGIロジックを変更しておりますが、当方では、CGIロジックは変更しないで運用しております。

そのCGIが何をするものなのかは想像すらできませんが、
CGIがSTDOUTへ出力するデータが、何等かの理由で
変化している(STDOUTへ出力する間隔が長くなることがある)
のではないでしょうか?

--
なかむら

> 中村です。
>
> >  例では、CGIロジックを変更しておりますが、当方では、CGIロジックは変更しないで運用しております。
>
> そのCGIが何をするものなのかは想像すらできませんが、
> CGIがSTDOUTへ出力するデータが、何等かの理由で
> 変化している(STDOUTへ出力する間隔が長くなることがある)
> のではないでしょうか?
>
> --
> なかむら
>

なかむら様
 中村です。

 回答ありがとうございます。

 CGIは、ファイル(テキストファイル)の内容を単純に表示するのみです。
  ファイルの内容を全て表示していることは確認しています。
 更新は、更新ボタンをクリックする事で手動で行います。

 lighttpdは、max-write-idle のタイムアウトをどのように計っているのでしょうか?
  ①タイマーを使用している。
  ②定期的に時刻を取得して計っている。
  ③トランザクション発生時に時刻を取得して計っている。

 lighttpdの仕様について参考になるサイトをご存知でしたら、お教え願えれば幸いです。
 
 

中村です。

>  CGIは、ファイル(テキストファイル)の内容を単純に表示するのみです。
>   ファイルの内容を全て表示していることは確認しています。

ならば、そのCGIはテキストファイルの内容を出力し終わった時点で
終了していると思います。
psコマンドで確認してください。
もし終了せずにそのCGI(プロセス)が残っているのならば、
何等かの問題があるのではないでしょうか?

>  lighttpdは、max-write-idle のタイムアウトをどのように計っているのでしょうか?
>   ①タイマーを使用している。
>   ②定期的に時刻を取得して計っている。
>   ③トランザクション発生時に時刻を取得して計っている。

たしか、タイマで1秒ごとにserver.cの中のチェック関数がコールされて、
その中で時計をみて経過時間のチェックをしていたと思います。

>  lighttpdの仕様について参考になるサイトをご存知でしたら、お教え願えれば幸いです。

ググるといろいろとみるかると思いますよ。
ただ「max-write-idleのタイムアウトをどのように計っているのか?」を
解説しているようなところはたぶん存在しないと思います。
server.cのソースを見ましょう。
問題のエラーメッセージを出している
server.c.1149
のあたりです。

--
なかむら

> 中村です。
>
> >  CGIは、ファイル(テキストファイル)の内容を単純に表示するのみです。
> >   ファイルの内容を全て表示していることは確認しています。
>
> ならば、そのCGIはテキストファイルの内容を出力し終わった時点で
> 終了していると思います。
> psコマンドで確認してください。
> もし終了せずにそのCGI(プロセス)が残っているのならば、
> 何等かの問題があるのではないでしょうか?
>
> >  lighttpdは、max-write-idle のタイムアウトをどのように計っているのでしょうか?
> >   ①タイマーを使用している。
> >   ②定期的に時刻を取得して計っている。
> >   ③トランザクション発生時に時刻を取得して計っている。
>
> たしか、タイマで1秒ごとにserver.cの中のチェック関数がコールされて、
> その中で時計をみて経過時間のチェックをしていたと思います。
>
> >  lighttpdの仕様について参考になるサイトをご存知でしたら、お教え願えれば幸いです。
>
> ググるといろいろとみるかると思いますよ。
> ただ「max-write-idleのタイムアウトをどのように計っているのか?」を
> 解説しているようなところはたぶん存在しないと思います。
> server.cのソースを見ましょう。
> 問題のエラーメッセージを出している
> server.c.1149
> のあたりです。
>
> --
> なかむら
>

なかむら様
 中村です。

回答、ありがとうございます。

 psで見る限りプロセスは残っていません。
 
 > たしか、タイマで1秒ごとにserver.cの中のチェック関数がコールされて
 #ifdef USE_ALARM でコンパイル対象から外れているので、外部からタイミングを得ているものと考えていました。

> ググるといろいろとみるかると思いますよ。
> ただ「max-write-idleのタイムアウトをどのように計っているのか?」を
> 解説しているようなところはたぶん存在しないと思います。

 ligthtpdで検索して、質問できそうなサイトを捜してみます。

 このトピックを一度閉じようと思います。
 (Armadilloの機能から外れてきたので。)
 解決した際に報告いたします。

 

> 中村です。
>
> >  CGIは、ファイル(テキストファイル)の内容を単純に表示するのみです。
> >   ファイルの内容を全て表示していることは確認しています。
>
> ならば、そのCGIはテキストファイルの内容を出力し終わった時点で
> 終了していると思います。
> psコマンドで確認してください。
> もし終了せずにそのCGI(プロセス)が残っているのならば、
> 何等かの問題があるのではないでしょうか?
>
> >  lighttpdは、max-write-idle のタイムアウトをどのように計っているのでしょうか?
> >   ①タイマーを使用している。
> >   ②定期的に時刻を取得して計っている。
> >   ③トランザクション発生時に時刻を取得して計っている。
>
> たしか、タイマで1秒ごとにserver.cの中のチェック関数がコールされて、
> その中で時計をみて経過時間のチェックをしていたと思います。
>
> >  lighttpdの仕様について参考になるサイトをご存知でしたら、お教え願えれば幸いです。
>
> ググるといろいろとみるかると思いますよ。
> ただ「max-write-idleのタイムアウトをどのように計っているのか?」を
> 解説しているようなところはたぶん存在しないと思います。
> server.cのソースを見ましょう。
> 問題のエラーメッセージを出している
> server.c.1149
> のあたりです。
>
> --
> なかむら
>

なかむら様
 中村です。

回答、ありがとうございます。

 psで見る限りプロセスは残っていません。
 
 > たしか、タイマで1秒ごとにserver.cの中のチェック関数がコールされて
 #ifdef USE_ALARM でコンパイル対象から外れているので、外部からタイミングを得ているものと考えていました。

> ググるといろいろとみるかると思いますよ。
> ただ「max-write-idleのタイムアウトをどのように計っているのか?」を
> 解説しているようなところはたぶん存在しないと思います。

 ligthtpdで検索して、質問できそうなサイトを捜してみます。

 このトピックを一度閉じようと思います。
 (Armadilloの機能から外れてきたので。)
 解決した際に報告いたします。

 

大澤です。
> フォーラム画面(web)で「作成者:y.nakamura 作成日:2014/10/06 - 10:38」はあるのですが、
> 中身が表示されません。
ご不便おかけして申し訳ございません。
復旧いたしました。

中村です。

> ご不便おかけして申し訳ございません。
> 復旧いたしました。

対応、ありがとうございます。
でも・・・今度は大澤さんの
「作成日:2014/10/06 - 13:35」の本文が表示されてないです。
(↑の引用はメール配信されたものをコピペしました)

--
なかむら