When executing Powershell script, there could be slowness or Hang issue. In order to solve this kind of problems, what can we do? Ideally, we can just add more log and run the script again to reproduce the problem. While, in some condition, the script is just running in production environment and the log is not enough for us to make troubleshooting. Furthermore, we probably are not sure whether we can reproduce the issue again. In this post, I will demonstrate how to debug prowershell hang issue in production environment, figure out which line of the code is experiencing the hang problem.

Basically, Powershell is based on .Net, that means we can debug Powershell process just as we debug normal .Net application. Before proceeding, you need install Windbg and also know basic .Net SOS debugging commands. When you observes Powershell hang (actually probably just slowness) symptom, capture dump by select the powershell.exe process in task manager and “Select Dump File”. It is suggested to capture multiple dumps with several minutes interval, that will help us figure out it is hang or slowness.

In the following, I will use the below simple powershell script to reproduce hang and demo how to make the troubleshooting.

Write-Host "This is the first line"
Read-Host
Write-Host "This is the third line"
Read-Host

Open the dump by windbg, execute command “.loadby sos clr” will load the sos extension for further debugging. Normally speaking, thread 0 is the main thread for Powershell Host. As it is not the worker thread, in most condition, it is not the problematic thread. It is easy to figure out this thread as there is something like “ConsoleHost” in the call stack.



In this demo, our attention is the thread 6, its callstack is shown below. Actually, sometimes, callstack is good enough for us to identity a hang problem. For example, in this demo, we can see it is hanging in ReadHostCommand.




While, it is still not enough as there are multiple Read-Host cmdlet in the script, we need dig more. Execute “!dso” command to dump out all the objects in the stack, find the object whose type is “System.Management.Automation.ExecutionContext”, it has the context information of script execution. Then, dump this object by command “!DumpObj”. You will notice that there is one field named “currentCommandProcessor”.



Based on the commandProcessor got in the last step, we can see a field named “command” shown below.



Dump out the command object and we can confirm that current executed command is exactly ReadHostCommand. Furthermore, there are two fields “commandInfo” and “myInvocation” which contain more information.



Let’s have a look at the commandInfo firstly. Obviously, we are hanging on Read-Host cmdlet now.



myInvocation has more information regarding to the invocation position of the command. Dump it shown below, we can find a field named “scriptPosition” whose type is InternalScriptExtent in this demo. The field “startOffset” means current command’s start position in the script, “_positionHelper” is an object which has a “_lineStartMap” member.



Dump _lineStartMap object, it is actually one int32 array composed by each parsed command’s start position. In this demo, the array has 4 elements (4 lines of code), each value is 0x0, 0x25, 0x31 and 0x56. Change to decimal, they will be 0, 37, 49, 86.



But how to proceed? What’s the logic of code position in _lineStartMap? We need refer to the source code. There are two options. One is to use reflector tool to check the code of System.Management.Automation.dll. On the other hand, luckily, Powershell has been open source and we can get the source code as we want. In this scenario, we can get PositionHelper’s function LineFromOffset from https://github.com/PowerShell/PowerShell/blob/master/src/System.Management.Automation/engine/parser/Position.cs

internal int LineFromOffset(int offset)
{
int line = Array.BinarySearch(_lineStartMap, offset);
if (line {
line = ~line - 1;
}
return line + 1;
}

Based on the startOffset(86) we got previously, we can calculate the line of current execution is 4. So, without any log's help, we finally figure out it is the second Read-Host call experiencing hang.

Lastly, I want to mention in a more complex script,the call stack could be even complicated as there is script intercept process, while they will follow the similar pattern. Hope helpful for you.