- PR -

httpd [notice] SIGHUP received. Attempting to restart

1
投稿者投稿内容
Jumpin'' Jack Flash
大ベテラン
会議室デビュー日: 2006/01/24
投稿数: 198
投稿日時: 2007-04-02 18:05
1ヶ月ほど前までは、とても安定したWebサーバーだったのですが、
最近、Webサイトが見えなくなる現象が多発し、困っています。

環境：CentOS 4、Apache httpd 2.0.52-22

error_log*の最終行に必ず
----
[Sun Apr 01 04:03:12 2007] [notice] SIGHUP received. Attempting to restart
----
と記録されます。

「SIGHUP received. Attempting to restart」でググってみました。
日本語のページ 約 265 件ヒットしました。
ログローテートに失敗して、お亡くなりになるようです。
けっこう多くの方が悩まされているようで、対応方法も様々でした。
ただ、対応策を立てるにあたって皆さん、
----
[Sun Apr 01 04:03:12 2007] [notice] SIGHUP received. Attempting to restart
----
これの後続のメッセージにヒントを得ているようですが、
私の場合、後続のメッセージがありません。よって、原因が特定できません。

何か、手がかりを得るために調査することはないでしょうか？

よろしくお願いいたします。
angel
ぬし
会議室デビュー日: 2005/03/17
投稿数: 711
投稿日時: 2007-04-02 18:27
こんにちは。
ログの日付は実際のものでしょうか?
もしそうであれば、CentOSに標準で入っている logrotate を使用したログローテートが契機になっていると考えて良いでしょう。( /etc/crontab の“run-parts /etc/cron.daily”の行で時期が指定され、/etc/cron.daily/logrotate で実施内容が記述されています )

であれば、まずは logrotate の設定を確認するのが第一。
恐らく、logrotate の設定ファイル ( /etc/logrotate.d/???? ) の postrotateセクションに、HUPシグナルを送るような処理が書いてあるのでしょう。
ただ、その処理によっては Apacheの restart が上手くいかなかったりすることは十分にあります。( そもそも USR1シグナル を使用する graceful restart の方が良いと思いますし )

なお、Apache でロードしているモジュールによっては、HUP であれ USR1 であれ、restart が上手くいかないケースも経験したことがあります。感覚的には PHP等のスクリプトエンジンや、SSL関連なのですが、コレといった根拠はありません。

場合によっては、別の方式を考える必要もあるかもしれませんね。
logrotate を使うのであれば、stop+start にするとか、logrotate を使わずに rotatelogs を使ってローテートを実現するとか…。

[ メッセージ編集済み 編集者: angel 編集日時 2007-04-02 18:29 ]
あんとれ
ぬし
会議室デビュー日: 2004/01/14
投稿数: 556
投稿日時: 2007-04-03 13:56
正常に起動しているときに、ps するとどんな結果が返ってきますか？

# ps -ef | grep httpd
root 22303 1 0 13:43 ? 00:00:00 /usr/sbin/httpd -k start <== ★
nobody 22311 22303 0 13:44 ? 00:00:00 /usr/sbin/httpd -k start
nobody 22312 22303 0 13:44 ? 00:00:00 /usr/sbin/httpd -k start
nobody 22313 22303 0 13:44 ? 00:00:00 /usr/sbin/httpd -k start
nobody 22314 22303 0 13:44 ? 00:00:00 /usr/sbin/httpd -k start
nobody 22315 22303 0 13:44 ? 00:00:00 /usr/sbin/httpd -k start

Apache を停止し、★に表示されたコマンドで Apache を起動し、

# kill -HUP 22303

とかってやるとどうなりますか？

あとは、/etc/logrotate.d 内のスクリプトを確認してみるとか。
Jumpin'' Jack Flash
大ベテラン
会議室デビュー日: 2006/01/24
投稿数: 198
投稿日時: 2007-04-03 15:08
logrotateは、週に1回行われるようです。
----
error_log.1:[Sun Apr 01 04:03:12 2007] [notice] SIGHUP received. Attempting to restart
error_log.2:[Sun Mar 25 04:02:10 2007] [notice] SIGHUP received. Attempting to restart
error_log.3:[Sun Mar 18 04:02:11 2007] [notice] SIGHUP received. Attempting to restart
error_log.4:[Sun Mar 11 04:02:11 2007] [notice] SIGHUP received. Attempting to restart
----
これは、実際の日付です。

しかし、今日もWebサイトが見えなくなりました。
仮説が崩れました。

error_log.1〜4 全てこのメッセージで終わり、後続のメッセージはありません。
後続のメッセージがないということは、正常にログローテートを完了したという
ことでしょう。
上記メッセージは「SIGHUPを受信して、再起動を試みている」と通知[notice]し
ているだけで、[error]は出ていません。

今回のWebサイトが見えなくなる障害とlogrotateは関係ないようです。
logrotateが行われていない今日もWebサイトが見えなくなったからです。
私の早合点でした。

こうなると、何が原因かサッパリわからなくなりました。

昨日httpdを再起動し、正常にWebサイトが見えることを確認した後から
今日Webサイトが見えなくなるまでの間に、怪しいerror_logはありません。
/var/log/messagesの怪しいログをピックアップしてみました。
----
Apr 2 17:28:28 platini named[1207]: client ::ffff:192.168.1.3#42190: query (cache) denied
Apr 2 17:29:02 platini named[1207]: client ::ffff:192.168.1.3#42191: query (cache) denied
Apr 2 17:32:27 platini named[1207]: client ::ffff:192.168.1.3#42193: query (cache) denied
Apr 2 17:32:45 platini named[1207]: client ::ffff:192.168.1.3#42194: query (cache) denied

Apr 3 09:54:33 platini unix_chkpwd[27765]: check pass; user unknown
Apr 3 09:54:33 platini unix_chkpwd[27765]: password check failed for user (webmaster)
Apr 3 09:54:33 platini smtp(pam_unix)[3234]: authentication failure; logname= uid=0 euid=0 tty= ruser= rhost= user=webmaster
Apr 3 09:54:33 platini saslauthd[3234]: pam_ldap: error trying to bind as user "uid=webmaster,ou=People,dc=****,dc=jp" (Invalid credentials)
Apr 3 09:54:35 platini saslauthd[3234]: do_auth : auth failure: [user=webmaster] [service=smtp] [realm=****.jp] [mech=pam] [reason=PAM auth error]

Apr 3 10:24:41 platini named[1207]: notify question section contains no SOA
----
なんだか、いろいろ改善点がありそうです。


■psの結果

# ps -ef | grep httpd （Webサイトが見えていないとき）
----
root 21600 1 0 Apr02 ? 00:00:00 /usr/sbin/httpd
root 21603 21600 0 Apr02 ? 00:00:00 /usr/sbin/httpd
8080 21604 21600 0 Apr02 ? 00:00:01 /usr/sbin/httpd
root 21605 21600 0 Apr02 ? 00:00:00 /usr/sbin/httpd
root 21606 21600 0 Apr02 ? 00:00:00 /usr/sbin/httpd
root 21607 21600 0 Apr02 ? 00:00:00 /usr/sbin/httpd
root 21608 21600 0 Apr02 ? 00:00:00 /usr/sbin/httpd
root 21609 21600 0 Apr02 ? 00:00:00 /usr/sbin/httpd
8080 21610 21600 0 Apr02 ? 00:00:02 /usr/sbin/httpd
root 29129 29016 0 14:21 pts/0 00:00:00 grep httpd
----

# /etc/init.d/httpd restart
----
Stopping httpd: [ OK ]
Starting httpd: [ OK ]
----

# ps -ef | grep httpd （正常に起動しているとき）
----
root 29175 1 5 14:29 ? 00:00:00 /usr/sbin/httpd
8080 29178 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
8080 29179 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29180 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29181 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29182 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29183 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29184 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29185 29175 0 14:29 ? 00:00:00 /usr/sbin/httpd
root 29188 29016 0 14:29 pts/0 00:00:00 grep httpd
----
F/A
ぬし
会議室デビュー日: 2006/03/18
投稿数: 312
お住まい・勤務地: Tokyo
投稿日時: 2007-04-03 22:18
えっと、症状からは
「logrotateに関係無しに突然Webがみれなくなるようだ」って事でいいんですか？

そういう事だと、”Webサイトが見えなくなる現象”ってのが
具体的にどういうものかをご説明頂かないと難しいですね。

具体的にってのは、
例えばtelnetでポートにアクセスしたら応答があるのかどうかなど…

あと、そのWebサイトはバックエンドで何か動いているのですか？
それとも、どちらかというと静的htmlファイルの詰め合わせですか？

＜追加・補足＞
プロセスは動作していますし、エラーも出ていないということであれば
Apache以外のOSやネットワークに問題がある可能性が高いと思います。



[ メッセージ編集済み 編集者: F/A 編集日時 2007-04-03 22:33 ]
Jumpin'' Jack Flash
大ベテラン
会議室デビュー日: 2006/01/24
投稿数: 198
投稿日時: 2007-04-05 19:24
すいません、Apacheのバージョンを上げ、様子を見た後、
状況を整理したうえで、改めて質問させていただきます。

ありがとうございました。
1

スキルアップ／キャリアアップ（JOB@IT）