Troubleshooting WinRM and PowerShell Remoting (Part 1)

One of the neat things about being an MVP Award recipient is the annual MVP Summit, where Microsoft invites its MVPs to the Redmond campus for a week of technical sessions, the occasional dinner out, and a lot of product feedback-gathering. Last week, I had the pleasure of spending most of the time with various members of the Windows PowerShell team. In addition to bouncing ideas off of us, talking about the issues we were seeing in the community, and so forth, we also got a great demo of how to troubleshoot WinRM.

The demo arose from our complaint that WinRM error messages tended to be vague ("access denied"), and that WinRM contained too many undocumented "moving parts" for us (or anyone) to accurately troubleshoot. One team member asked if we'd ever had any luck in using the PSDiagnostics module. After we stared blankly for a few minutes, he felt a demo was in order.

PSDiagnostics is a Microsoft-supplied module that's included with PowerShell v2. Unfortunately, it (unlike most Microsoft-shipped modules) contains zero documentation, so most of us have been a bit leery of trying it. Get started by running Import-Module PSDiagnostics. Essentially, you're going to turn on trace messages by running a command. Once tracing is turned on, you'll run whatever Remoting commands you want, and then check out the trace log for error messages and so forth. When you're finished, be sure to turn tracing back off again. Trace information goes into two of the new-style Windows event logs, which are viewable in the Event Viewer, or by running the Get-WinEvent command. Here's an example:
 

Import-Module PSDiagnostics
Enable-PsWsmanCombinedTrace
Invoke-Command -script { get-service } -computer SERVER-R2,NOTONLINE<br />
                Disable-PsWsmanCombinedTrace

One of those two computers is on my network; NOTONLINE is a bogus name. After running this, I popped open Server Manager. Under Event Viewer, go to "Applications and Services Logs" > Microsoft > Windows. From there, locate PowerShell and "Windows Remote Management." Both can contain two logs: Operational and Analysis. The Operational log is intended to be human-readable; the Analysis log contains more detailed information, but requires special Microsoft tools to decode. Here's a trick: Right-click a log and open its properties. Right at the top, you'll see its full name, such as Microsoft-Windows-PowerShell/Operational. You can use that with Get-WinEvent to query the log in PowerShell itself. After running the above, I found this:
 

PS C:\> get-winevent -logname Microsoft-Windows-PowerShell/Operational -max 12 | select message
 
Message
-------
Modifying activity Id and correlating
Modifying activity Id and correlating
Modifying activity Id and correlating
Runspace Id: fecea362-466d-46f3-99f6-dd3557aa1112 Pipeline Id: 00000000-0000-0000-0000-000000000000. WSMan re...
Runspace Id: fecea362-466d-46f3-99f6-dd3557aa1112 Pipeline Id: 00000000-0000-0000-0000-000000000000. WSMan re...
Opening RunspacePool
Opening RunspacePool
Creating RunspacePool object ...
Creating Runspace object ...
Creating RunspacePool object ...
Creating Runspace object ...
Modifying activity Id and correlating
 
 
PS C:\> get-winevent -logname Microsoft-Windows-WinRM/Operational -max 25 | select message
 
Message
-------
Closing WSMan Session completed successfuly
Closing WSMan Session
WSMan operation DeleteShell completed successfully
Received the response from Network layer; status: 200 (HTTP_STATUS_OK)
Sending response for operation DeleteShell
Sending response for operation Receive
Leaving the plugin for operation DeleteShell
Sending timeout response for operation: Receive
Entering the plugin for operation DeleteShell with a ResourceURI of http://schemas.microsoft.com/powershell/...
Processing client request for operation DeleteShell
Leaving the plugin for operation Signal
WSMan operation SignalShell failed, error code 995
Sending response for operation Signal
Entering the plugin for operation Signal with a ResourceURI of http://schemas.microsoft.com/powershell/Micro...
Processing client request for operation Signal
Authorizing the user
Received the response from Network layer; status: 200 (HTTP_STATUS_OK)
The authorization of the user was done successfully
Authorizing the user
User COMPANY\Administrator authenticated successfully using Kerberos authentication
Authorizing the user
The chosen authentication mechanism is Kerberos
Sending the request for operation DeleteShell to destination machine and port SERVER-R2:5985
Closing WSMan ReceiveShellOutput operation completed successfully
Closing WSMan operation

And that's just a subset - the WinRM log actually contained hundreds of messages. This is a LOT of detail, and can go a long way toward helping to troubleshoot WinRM operations. 

This should get you started, but in the next part of this article series I'll dive into the WinRM traffic log and explain what's going on with individual successful and failed connections. In later articles, I'll cover that Analysis log, and show you how to use a tool that can decode the information in it for an even more detailed look at what's happening in WinRM.

Please or Register to post comments.

What's PowerShell with a Purpose Blog?

Don Jones demystifies Windows PowerShell.

Blog Archive

Sponsored Introduction Continue on to (or wait seconds) ×