Windowsの再起動とその原因をイベントログから探る

今回は、イベントログからWindows Updateによる再起動時間を計測するために必要な情報を集めることにして、イベントログシリーズの最後としたい。

シャットダウンと再起動に関しては、前回解説したように（「WindowsイベントログをPowerShellを用いて扱う」）、PowerShellのGet-WinEventで、カーネルからのメッセージを見ればよかった。しかし、これだけだと再起動の理由が不明だ。また、現在のWindows 10でもいきなり落ちてしまうことは年に数回ある。こうしたシャットダウンの原因を探さないと、Windows Updateによる再起動を区別できない。

正式な機能アップデートのログが取れなかったので、Windows Insider Previewのインストールにかかる時間を測定した。プレビュー版のアップデートに約25分、その後、再起動が要求されて、3回の再起動を経て、Windowsが立ち上がるまでに31分、起動後の処理がされ、インストールが正常終了と判定されるまでに41分かかっている

そもそも、Windows Updateで再起動が要求されても、現在のWindows 10ではすぐに再起動が始まることはまれで、アクティブ時間を避ける、ユーザーに確認を取るといったことが行なわれたのちに開始される。このため、Windows Updateのタイミングとシャットダウンのタイミングが数日空いてしまうことも珍しくない。

User32のイベントログでシャットダウンの理由を調べる

まず、シャットダウンの理由だが、これは、User32がイベントログを残してくれる。Windows Serverを扱った人なら、手動によるシャットダウンに際して、Windowsが理由を尋ねるダイアログを出すことをご存じだろう。Windows 10にも同様の仕組みがあるが、いちいち確認はせず、User32が勝手に理由を推測してイベントログに記録する。

ただし調べてみると、User32のイベントログには、「シャットダウン開始」だけでなく「シャットダウンに失敗」というログもあることがわかった。とりあえず、以下のイベントを取り出せばよい。

ProviderName=User32
EventID=1074　　#シャットダウンの理由と開始
EventID=1073　　#シャットダウン失敗

具体的には、以下のコマンドでイベントを取り出せる。

Get-WinEvent -Path $mylog -FilterXPath "Event/System[ (EventID=1073 or EventID=1074) and Provider[@Name='User32']]"

なお、前回と同じく$mypathには、evtxイベントログファイルのパスを入れてある。

クラッシュの種類を判別する

ところがWindowsは、不具合によりいきなり落ちることもある。これは事前には、検出することはできないが、EventLogが再起動後に「予期せぬシャットダウン」というイベントログを残してくれる。これを見ることで、直前のシャットダウン（と再起動）がクラッシュによるものであることがわかる。そのためには、以下のイベントを取り出す。

ProviderName=EventLog
EventID=6008

このイベントを取り出すには、以下のコマンドを使う。

Get-WinEvent -Path $mylog -FilterXPath "Event/System[ EventID=6008 and Provider[@Name='EventLog']]"

Windows Updateのログから再起動しそうなアップデートを探す

WindowsUpdateは、アップデートのダウンロードやインストール開始などのイベントログを記録している。しかし、すべてのアップデートとMicrosoftストアからのソフトウェア更新が記録されるため、膨大な量になる。必要なイベントとしては、

ProviderName=Microsoft-Windows-WindowsUpdateClient
EventID=19：インストール成功
EventID=20：インストール失敗
EventID=43：インストール開始
EventID=44：ダウンロード開始
EventID=216：コミット成功(20H1以降）
EventID=218：コミット開始(同)

がある。アップデートの名称は、Propertiesの最初の要素（Properties.value[0]）に入っている。とりあえず、イベントの取り出しは、

Get-WinEvent -Path $mylog -FilterXPath "Event/System[ (EventID=19 or EventID=43 or EventID=44) and Provider[@Name='Microsoft-Windows-WindowsUpdateClient']]"

とした。再起動に関係ありそうなアップデートには、「機能」アップデート、「累積」的なアップデート、Insider Preview、言語パックなどがある。

このうち、日本語版のWindowsでも、「累積的」として「Cumulative」が、「言語」として「Language」がアップデートパッケージ名に含まれることがある。また、英語版のWindowsでもログを集めることを考えると、「機能」は「Feature」の表記がありえる。これらをパッケージ名に含むイベントログを見付けるとき、XPathでフィルターを記述するのはちと面倒だ。そこでhere-Objectを使って、

Get-WinEvent -Path $mylog -FilterXPath "Event/System[ (EventID=19 or EventID=43 or EventID=44) and Provider[@Name='Microsoft-Windows-WindowsUpdateClient']]" -ErrorAction SilentlyContinue Where-Object { $_.Properties.value[0] -match "機能InsiderFeature累積CumulativeLanguage" }

と記述することにした。

イベントログの出力を処理しやすい形式で出力

簡易には、これまで示したGet-WinEventコマンドの出力をSelect-Objectなどで必要なプロパティのみを取り出して出力するのでもいいのだが、中身が配列になっているPorpertiesの扱いがちょっと面倒だ。このため、Foreach-Objectを使って、

ForEach-Object {"{0}`t{1}`t{2}`t{3}" -F ($_.TimeCreated.ToString($myTfmt)),($_.RecordID),($myres[$_.id]),(対象により指定が違う部分) } `

といった形式で、タブ区切りの文字列出力を作ることにした。タブ区切りとしたのは、ExcelのCSVがフィールドの切れ目を誤解することがあるからだ。

ForEach-Objectは、パイプラインの前から来るオブジェクトの配列の各要素に対して{　}内のスクリプトを適用するものだ。Select-Objectでは、やってくるオブジェクトのプロパティしか指定できないので、Propertiesプロパティの中に入っている配列オブジェクトの一部を取り出すことができない。

しかし、ForEach-Objectの{　}内には、任意のスクリプトを記述できるため、プロパティの中のオブジェクトの一部を取り出すこともできる。また「"{0}`t{1}`t{2}`t{3}" -F ... 」という部分は、先頭のフォーマット指定文字列に対して、-F以降の計算式を当てはめて文字列として出力するもの。C言語でいうprintfと似たような機能で、{}で囲まれた部分が書式指定文字にあたる。「`t」はタブ文字を表すため、この部分では、後ろの計算式の結果をタブ区切りの文字列として出力できる。

ただし、イベントにより、最後の計算式は違いが出る。メッセージに埋め込む文字列は、イベントごとに違うからだ。このあたりをまとめたのが、以下の表である。

2020-01-01 19:23:42