[WinRM] トラブルシュートはエラーとイベントビューアから確認を開始するべし
皆さんごきげんよう。ういこです。今日は「WinRM でトラブル発生したときは、表示されたエラーと、イベントビューアをじっくり見よう！ 」をお送りします。
WinRM というのは、"リモートコンピュータを管理を可能にする" 機構だと Web でご覧になった方もいらっしゃるかと思います。SOAP ベースとか何とか色々難しいことが良く書いてありますが、あの弊社の誇る素敵エバンジェリストの安納さんのブログにもございますように、要は HTTP (含む HTTPS) で WMI が使えちゃうぞーというステキテクノロジです。はて、WMI はリモート コンピュータを対象にしても使えるし、何をいまさらジロー？と思うそこのあなた！いえいえ、何がいいって、DCOM 使わなくていいんです。DCOM。
以前の記事にもちらっと触れたことがありますが、WMI は DCOM を基盤として動作しますので、動作前提として DCOM がきちんと構成されている必要があります。DCOM はさらに RPC を基盤として動作します。よって、WMI でリモート コンピュータを管理したいというときは、以下の三つが動作する必要があるのです。
・RPC
・DCOM
・WMI
当然、そこにはリモートコンピュータへのアクセス権の他、RPC、DCOM が使うポートが外部から使える状態になっていなくてはいけません。
会社のイントラネットで使うならまだしも、例えばインターネット越しに操作してほしい！という端末で、RPC / DCOM などのポート解放は…怖いです。そうしたことに対する一つの答えとして、WinRM があります。WinRM は HTTP / HTTPS で WMI の動作が出来てしまうので、セキュリティ上の懸念が随分楽になります。
さて、そんないいことずくめに思える WinRM ですが、やっぱりなんか問題が起きた時は結構面倒です。
WMI もそうですが、使うに易しいからと言って、トラブルシュートや仕組みも易しいわけではないということを常に考える必要があります。ここを誤解すると、保守などのフェーズでとんでもないことになります。
…と、脅かしまくりですが、WinRM、どうも問題発生時の状況を把握するのが WMI と比べるとずっと楽になっているようです。
とにかく、失敗時にコンソールに出るメッセージも詳細だし、イベントログに出る情報が判りやすいこと。
WMI の場合、スクリプトで使われることが多いですが、スクリプトの実行エラーとか言われちゃうと何がエラーなのかさっぱりですし、プログラムで実行したとしても、HRESULT 判りづらいし、イベントログも、DCOM のエラーだ、RPC のエラーだ何だと色々見なくてはいけない情報があちこちとっちらかってましたが、WinRM の場合、ちゃんと集約されています。しかも情報が詳細。非常に判りやすいです。
じゃあどんだけわかりやすいのよと思いますよね。早速試してみましょう。
さて、Hyper-V を構成し、リモート デスクトップを有効にした程度にしてある環境（Windows Server 2008 R2）が都合よく手元にあったので、コイツをターゲットにして実行してみます。クライアントは Windows 7、クライアントには winrm quickconfig してますが、サーバはもちろん何にもしておりません。
さあどんなコマンド叩いたろかとしばし考えましたが、かめがわさんの素晴らしく判りやすいこの Technet コンテンツから頂いてきたコマンドをたたいてエラーを出してみました。(内容も判り易く、とてもいい記事です。是非ご覧ください！)
ちなみに実行元は Windows 7 日本語版、実行先は Windows Server 2008 R2 日本語版、それぞれ同じドメインに入っています。
PowerShell でのリモート管理
https://technet.microsoft.com/ja-jp/windows/ee460851.aspx
PS C:\Windows\system32> Invoke-Command -ComputerName jpdsfim -ScriptBlock {Get-Service}
[jpdsfim] リモート サーバーへの接続が失敗し、次のエラー メッセージが返されました。WinRM クライアントは、指定された時間内に処理を完了できません。コンピューター名が有効で、ネットワークを介して到達可能で、Windows リモート管理サービスのファイアウォールの例外が有効化されていることを確認してください。詳細については、about_Remote_Troubleshooting のヘルプ トピックを参照してください。
+ CategoryInfo : OpenError: (:) []、PSRemotingTransportException
+ FullyQualifiedErrorId : PSSessionStateBroken
このメッセージによると、
1. (パラメータに指定した) コンピューター名が有効であること
2. (パラメータに指定したコンピュータに対して) ネットワークを介して到達可能であること
3. (パラメータに指定したコンピュータ上で) Windows リモート管理サービスのファイアウォールの例外が有効化されていること
の三つの条件がそろってるか確認してほしいということですね。
今回、"上記のパラメータに指定したコンピュータ" は、jpdsfim という名前でございます。
じゃあ、手っ取り早く指定した名前で Ping でもやってみましょうか。
PS C:\Windows\system32> ping jpdsfim
jpdsfim.uikoutest.microsoft.com [2001:4898:7008:1014:69d0:d1a0:925b:e057]に ping を送信しています 32 バイトのデータ:
2001:4898:7008:1014:69d0:d1a0:925b:e057 からの応答: 時間 =1ms
2001:4898:7008:1014:69d0:d1a0:925b:e057 からの応答: 時間 <1ms
2001:4898:7008:1014:69d0:d1a0:925b:e057 からの応答: 時間 <1ms
2001:4898:7008:1014:69d0:d1a0:925b:e057 からの応答: 時間 <1ms2001:4898:7008:1014:69d0:d1a0:925b:e057 の ping 統計:
パケット数: 送信 = 4、受信 = 4、損失 = 0 (0% の損失)、
ラウンド トリップの概算時間 (ミリ秒):
最小 = 0ms、最大 = 1ms、平均 = 0ms
名前もしっかり解決して Ping も通ってるようなので、1 および 2 は OK ということですね。
あとは 3 だと。
では jpdsfim にログオンして、winrm qc をしてみます。
PS C:\Windows\system32> winrm qc
WinRM は既にこのコンピューター上で要求を受信するように設定されています。
WinRM は、管理用にこのコンピューターへのリモート アクセスを許可するように設定されていません。
次の変更を行う必要があります:このコンピューター上のあらゆる IP への WS-Man 要求を受け付けるため、https://* 上に WinRM リスナーを作成します。
WinRM ファイアウォールの例外を有効にします。変更しますか [y/n]?
と表示されました。どうも、WinRM ファイアウオールの例外設定はこれから有効にしないとだめ見たいです。ためしに y を実行して、リモート管理用に WinRM の更新を実施します。
変更しますか [y/n]? y
WinRM はリモート管理用に更新されました。
このコンピューター上のあらゆる IP への WS-Man 要求を受け付けるため、https://* 上に WinRM リスナーを作成しました。
WinRM ファイアウォールの例外を有効にしました。
PS C:\Windows\system32>
これでもう一度、クライアントから同じコマンドを実行すると…
PS C:\temp> Invoke-Command -ComputerName jpdsfim -ScriptBlock {Get-Service}
Status Name DisplayName PSComputerName
------ ---- ----------- --------------
Running AeLookupSvc Application Experience jpdsfim
Stopped ALG Application Layer Gateway Service jpdsfim
Stopped AppIDSvc Application Identity jpdsfim
Running Appinfo Application Information jpdsfim
Stopped AppMgmt Application Management jpdsfim
Stopped aspnet_state ASP.NET 状態サービス jpdsfim
Stopped AudioEndpointBu... Windows Audio Endpoint Builder jpdsfim
Stopped AudioSrv Windows Audio jpdsfim
… (以下省略) …
おお、行けました。
こんな感じで、比較的判りやすいメッセージで、具体的に何をすればよいか割と判る感じになっています。
では、ついでなので、実行元のクライアント側で、失敗時と成功時、それぞれイベントログではどう出ているか見てみましょう。
実行元のクライアントマシン上のイベントビューアを開きます。
[スタート] メニュー上の、[ファイル名を指定して実行] もしくは [プログラムとファイルの検索] で
eventvwr
と入力し、Enter キーを激しく叩きます。壊れない程度に。
イベントビューアが開きますので、左ペインを以下のように展開してください。
[イベント ビューアー (ローカル)]
+ [アプリケーション ログとサービス ログ]
+ [Microsoft]
+ [Windows]
+ [Windows Remote Management]
- Operational
ここに WinRM 関連のログが表示されます。失敗時の処理の流れを抜粋していきますね。冗長ですが、処理の流れがとてもつかめると思いますです。
ちなみに以下は割愛していますが、接続に使われたユーザ名等も判ります。
失敗時のログの流れ from イベントビューア
情報 2010/10/12 17:39:41 Windows Remote Management 2 WSMan API の初期化
「WSMan API を初期化しています」
情報 2010/10/12 17:39:41 Windows Remote Management 29 WSMan API の初期化
「WSMan API の初期化が正常に完了しました」
情報 2010/10/12 17:39:41 Windows Remote Management 6 WSMan セッションの初期化
「WSMan セッションを作成しています。 接続文字列は jpdsfim/wsman?PSVersion=2.0 です」
情報 2010/10/12 17:39:41 Windows Remote Management 31 WSMan セッションの初期化
「WSMan セッションの作成操作が正常に完了しました」
情報 2010/10/12 17:39:41 Windows Remote Management 27 WSMan API 呼び出し
「WSMan セッション オプション (29) を取得しています」
情報 2010/10/12 17:39:41 Windows Remote Management 10 WSMan API 呼び出し
「WSMan セッションのオプション (25) に値 (ja-JP) を正常に設定しました」
情報 2010/10/12 17:39:41 Windows Remote Management 10 WSMan API 呼び出し
「WSMan セッションのオプション (1) に値 (180000) を正常に設定しました」
情報 2010/10/12 17:39:41 Windows Remote Management 10 WSMan API 呼び出し
「WSMan セッションのオプション (12) に値 (180000) を正常に設定しました」
情報 2010/10/12 17:39:41 Windows Remote Management 10 WSMan API 呼び出し
「WSMan セッションのオプション (17) に値 (60000) を正常に設定しました」
情報 2010/10/12 17:39:41 Windows Remote Management 10 WSMan API 呼び出し
「WSMan セッションのオプション (16) に値 (60000) を正常に設定しました」
情報 2010/10/12 17:39:41 Windows Remote Management 11 WSMan API 呼び出し
「WSMan シェルをリソース URI https://schemas.microsoft.com/powershell/Microsoft.PowerShell で作成しています」
情報 2010/10/12 17:39:41 Windows Remote Management 166 ユーザーの認証
「選択された認証機構は Kerberos です」
情報 2010/10/12 17:39:41 Windows Remote Management 80 要求の処理
「操作 CreateShell の要求を送信しています。送信先コンピューターおよびポート jpdsfim:5985」
情報 2010/10/12 17:39:41 Windows Remote Management 166 ユーザーの認証
「選択された認証機構は Kerberos です」
エラー 2010/10/12 17:40:44 Windows Remote Management 138 応答の処理
「クライアントがネットワーク レイヤーからタイムアウトを受信しました (ERROR_WINHTTP_TIMEOUT)」
エラー 2010/10/12 17:40:44 Windows Remote Management 142 応答の処理
「WSMan の操作 CreateShell に失敗しました。エラー コード 2150859046」
情報 2010/10/12 17:40:44 Windows Remote Management 26 WSMan API 呼び出し
「エラー コード 2150859046 のメッセージ取得が正常に完了しました。languageCode パラメーターは ja-JP でした。」
情報 2010/10/12 17:40:44 Windows Remote Management 16 WSMan API 呼び出し
「WSMan シェルを閉じています」
情報 2010/10/12 17:40:44 Windows Remote Management 8 WSMan セッションの初期化解除
「WSMan セッションを閉じています」
情報 2010/10/12 17:40:44 Windows Remote Management 33 WSMan セッションの初期化解除
「WSMan セッションを閉じる操作が正常に完了しました」
上記のオプションであんまり指定した覚えのないものもありますがこれらの流れで興味深い情報は以下のあたりです。
・ユーザの認証は Kerberos が使われている
・Windows 7 は WinRM 2.0 なので、何もいじっていない状態（既定）では ポート 5985 番が使われている
・タイムアウト (ERROR_WINHTTP_TIMEOUT) を契機に失敗している
※ WinRM 2.0 では既定の場合 HTTP:5985、HTTPS:5986 が使われますが、WinRM 1.1 の場合、既定値として HTTP:80、HTTPS:443 が使われます。
どうも、通信先で WinRM のリモート管理の構成がなされていない場合は、タイムアウトとして現れるんですね。2150859046 = 80338126 ですが、これは一般的なエラーを示すだけのものと思ってよいようです。この番号だけで何かがわかるという類のコードではないということです。
ちなみにうまくいく場合は、上記の "ユーザーの認証「選択された認証機構は Kerberos です」" の直後のイベントで、HTTP_STATUS_OK が返され処理が進みます。エラー時は ERROR_WINHTTP_TIMEOUT だったところです。
ログの名前: Microsoft-Windows-WinRM/Operational
ソース: Microsoft-Windows-WinRM
日付: 2010/10/13 12:01:58
イベント ID: 143
タスクのカテゴリ: 応答の処理
レベル: 情報
キーワード: クライアント
ユーザー: FAREAST\uikou
コンピューター: uikou-seven.fareast.corp.microsoft.com
説明:
ネットワーク レイヤーから応答を受信しました。状態: 200 (HTTP_STATUS_OK)
参考：WinRM の規定ポートを変更する方法
Installation and Configuration for Windows Remote Management
https://msdn.microsoft.com/en-us/library/aa384372(VS.85).aspx
なお、WinRM の 1.1 - 2.0 間の既定ポート値の違いが元でおこる問題など、WinRM の使う規定ポートを変更したい場合は、上記参考資料の "Default ports changed for WinRM and PowerShell remoting" (ずいぶん下のほうにスクロールするとあります) を参照ください。本日 2010/10/13 現在、2010/6/24 が最新の更新です。
それではまた。
ういこう