Windows で hudson サービスが再起動できない場合の対処法

Windows Server 2003 R2 Standard Edition SP2 の環境に新たに Hudson 環境を構築しているのですが。hudson サービスの再起動がどうもうまくいかないので原因調査してみました。

Hudson のバージョン 1.353 と 1.384 で試しています。

現象

• Hudson の各ページ（/restart とか /safeRestart とか）から再起動すると、一回目は再起動できるけれど、二回目以降は「Hudsonが再起動するまでしばらくお待ちください....」で止まってしまう。
• 一度この状態になってしまうと、hudson サービスを MMC（services.msc）から再起動しても現象は解決せず、java.exe のプロセスを強制終了させる必要がある
• 二回目の再起動時に、hudson.out.log には

java.net.BindException: Address already in use: JVM_Bind
	at java.net.PlainSocketImpl.socketBind(Native Method)
	at java.net.PlainSocketImpl.bind(Unknown Source)
	at java.net.ServerSocket.bind(Unknown Source)
	at java.net.ServerSocket.<init>(Unknown Source)
	at java.net.ServerSocket.<init>(Unknown Source)
	at winstone.HttpListener.getServerSocket(HttpListener.java:102)
	at winstone.HttpListener.run(HttpListener.java:116)
	at java.lang.Thread.run(Unknown Source)

みたいなログが残っている。

もう少し細かい現象

Process Explorer で観察してみると、再起動をかけた際に起動された hudson.exe が落ちて、java.exe のプロセスがサービスに紐づかない形で残ってしまう。このタイミングで DW20.EXE（Microsoft Application Error Reporting）が起動しているので、Java じゃなくて hudson.exe 側の問題みたい。

イベントビューアを見ると、

イベントの種類:	エラー
イベント ソース:	.NET Runtime 2.0 Error Reporting
イベント カテゴリ:	なし
イベント ID:	5000
説明:
EventType clr20r3, P1 hudson.exe, P2 1.0.0.0, P3 4a6756e1, P4 mscorlib, P5 2.0.0.0,
P6 4be90358, P7 344a, P8 21c, P9 system.io.ioexception, P10 NIL.

とかなんとか情報が残っている。

clr20r3 mscorlib を元に色々調べてみるけど、「何もしてないはずなのに気がついたら治ってた」とか「ハードウェアのドライバを入れた途端に出るようになった」みたいな情報があったので、Microsoft Update でパッチを片っ端からあててみたけど効果なし。

hudson.exe について

hudson.exe は Windows Service Wrapper（winsw.exe）という、通常プログラムをサービス化するプログラムのようで。（これも id:kkawa さんが owner なのかな？すごいなぁ・・・。）

この .exe でできることは限られてるので、

• Windows Service Wrapper: Wiki: ConfigurationSyntax ? Project Kenai

あたりを参考に、試しに logmode を変えてみると・・・ちゃんと再起動できた！どうもログファイルまわりに問題があるらしい。

詳細な動作

Process Monitor やらで追った感じだと、こんな流れになっているみたい。

元々起動している Hudson（図中の java.exe:102）は再起動のリクエストがあると「hudson.exe restart」みたいなコマンドを投げる。（hudson.exe:103 が起動する。）そのときさらに hudson.exe:104 が起動されてサービスが開始されてログファイルに対してローテーションをかけようとする（？）んだけど、ファイルは hudson.exe:101 が握ちゃってるもんだから、SHARING VIOLATION が発生してプロセス終了（hudson サービスも停止）と。再起動がうまくいく環境（Windows XP）では先に hudson.exe:101 側が CloseFile してるから問題なく動作しているみたい。

この後残った java.exe:105 はサービスとの結びつきが消えているものの hudson.lifecycle=hudson.lifecycle.WindowsServiceLifecycle として起動されているので、この状態で画面から再起動を行うと、hudson サービスが再起動して別の java.exe プロセスが起動する。

でもサービスに結びついていない java.exe:105 がポートを使っている状態のままなので、hudson サービスとして起動されたほうは何もできないし、java.exe:105 の停止はいつまで経っても行われないから、「再起動中」の表示で止まってしまうと。

とりあえずの回避策

hudson.xml の最後に

  <logmode>rotate</logmode>

の指定があるので、これを

  <logmode>roll</logmode>

に変更すれば OK。他に reset と append も試したけど、問題なく動作するのは roll だけみたい。

雑感

前 Windows 7 環境で構築したときは気にならなかったんだけど、OS 頻繁に再起動していたからなのか、環境に依存してるのか。Xeon 環境ってレースコンディション問題とか起きやすい気がするけど、そっち系？

• Restarting Hudson - Windows Installation - Server Fault

で再起動できないって報告があるけど、これも Windows Server 2003 だから OS の問題なのかもしれない。

追記

これで解決だと思ったのに Hudson PXE netboot plugin 入れて再起動しようとしたら、hudson.exe が落ちる現象が再発・・・。どうしたもんだか。

（さらに追記）
その後 hudson.exe が落ちる現象は再現せず。
でも Windows XP の別環境でも Hudson PXE netboot plugin は動作しなかったので、PXE 用の環境は別に用意しようかと。