Windowsサービスで発生するエラーのメモ

目次
https://tera1707.com/entry/2022/02/06/144447#WindowsService

やりたいこと

以前、C++のサービスの作り方を調べて、サンプルを作った。

サービスの処理の中で、Windowsのルール、お作法に従えていないときなどには、Windowsのイベントビューアにいろいろエラーログが残る様子。

上記のサンプルで勉強する中で、見たエラーログを、下記にメモする。

もくじ

  • イベント7009
  • イベント7000
  • イベント7034
  • イベント7031
  • イベント7011
  • イベント7046

■イベント7009 「SvcName サービスの接続を待機中にタイムアウト (30000 ミリ秒) になりました。」

サービスのexeが起動してから、StartServiceCtrlDispatcher()を呼ぶまでに、デフォルトで30秒以上かかったときに、このログが出る。

StartServiceCtrlDispatcher()を読んだ後に30秒Sleepしてみても、7009は発生しなかった。 (StartServiceCtrlDispatcherで登録したハンドラの中の先頭でSleepさせてみて実験)

image.png

※このエラー発生時、エラー発生時点でサービスのexe(プロセス)は終了していた。

※デフォルトの30秒というのは、下記レジストリで変えられる。

  • キー
    • HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control
    • ServicesPipeTimeout

参考:https://www.yrl.com/fwp_support/faq/a1hrbt0000000n9x.html

※試しにServicesPipeTimeoutを5秒(5000)にしたときの7009エラーは下記の通り。
 レジストリの値を変えた後は、再起動必要。

image.png

インサイドWindows 第6版のP348 4.2 サービス の中に、

StartServiceCtrlDispatcher関数は、SCMと名前付きパイプを使ってやり取りするための接続を確立した後、名前付きパイプを通じてSCMからコマンドが届くのを待ちます

とある。この関数が「接続を確立する」のが、指定秒数より遅れると、7009になるものだと思われる。

★追記

上で試した

  • main関数が開始してからStartServiceCtrlDispatcher()を呼ぶ前に、30秒以上かかってしまった場合

に加えて、

  • main関数が開始してからStartServiceCtrlDispatcher()を呼ぶ前に、returnしてしまった場合

にも、このイベントが発生する様子。

イベントのDiscriptionから、「待たされたときに発生する」イメージを持ってしまうが、 「StartServiceCtrlDispatcher()にたどり着かなかった」ときにも発生する。地味に注意。

■イベント7000 「SvcName サービスを、次のエラーが原因で開始できませんでした: そのサービスは指定時間内に開始要求または制御要求に応答しませんでした。」

今回試した限りでは、上のエラーイベント7009と同時に、ペアで発生していた。

■イベント7034 「SvcName サービスは予期せぬ原因により終了しました。このサービスの強制終了は 1 回目です。」

サービスが予期せぬエラーで終わったときに出る。

今回試したときは、サービスのプロセスをtaskkillコマンドで意図して強制終了したときに出た。
(メッセージに「強制終了は・・・」とある。もしかしたら、taskkillでなくて本当に予期せぬエラーの場合は、違うコードなのかも?未検証。)

■イベント7031 「SvcName サービスは予期せぬ原因により終了しました。このサービスの終了は 1 回目です。次の修正操作が 60000 ミリ秒以内に実行されます: サービスの再開。」

下図のように、サービスの設定で、エラー時にサービスを再起動するように設定していると、 サービスが予期せぬエラーが終わったときにこのイベントが出た。 (再起動するように設定してないと、7034になるっぽい)

「最初のエラー」だけに再起動の設定をして、「次のエラー」以降を「何もしない」にしていても、「エラーカウントのリセット」が0日後になっていると、1回エラーが起きても回数が即リセットされるようで、何度taskkillしても7031で「1回目」になり、毎回再起動された。

「エラーカウントのリセット」を「1日後に行う」にすると、カウントがされるようになり、2回目にtaskkillしたときに下図ようになり、以降再起動はされなかった。

■イベント7011 「SvcName サービスからのトランザクション応答を待機中にタイムアウト (5000 ミリ秒) になりました。」

サービスがサービスコトロールを受け付けてから一定時間(デフォルト30秒)以内に処理を返さない場合(具体的にはサービスコトロールを処理する関数を抜けない場合)に発生。

デフォルトの30秒は、イベント7009のタイムアウト値の設定のレジストリの値ServicesPipeTimeoutの値になる。(ので、今回実験したときに5000になってたので5秒でエラーイベント発生した。)

発生時、コマンドプロンプトでSCを送っていた側には下図のようなエラーが出た。

また実験的に、下記のようなSCを受ける関数を作って、200番のSCを送って試した際、

  • Sleepしてる最中にエラーイベントが出て、sc controlコマンドは上図のようなエラーになる。
  • が、35秒経過後、サービス側はSleepを抜けて、何事もなかったかのように続きが実行される。状態もRUNNNINGのまま。

という動きになった。

DWORD WINAPI SvcCtrlHandler(DWORD dwControl, DWORD dwEventType, LPVOID lpEventData, LPVOID lpContext)
{
    switch (dwControl)
    {
    case 200:
        Sleep(35000);
        break;
 ・・・以下省略

インサイドWindowsには、「SCの処理は30秒以内に終わらせないとエラーになる」と書いているのに、サービスのexeは何のエラーも出さないじゃないか、と思っていたら、  exeが例外出すとかではなく、「エラーのイベントがイベントログに記録される」ということだった。

■イベント7046

7011が10回連続で発生すると、7046になることがあるらしい。
が、今自分の実験用サービスで、7011を10回起こしても7046は起きなかった。実験用に、無理やりSleepさせてたり、タイムアウトを5秒にしていることで起きなくなっているのかもしれない。 要検証。