VBScript Production Debugging

An error typically occurs in an ASP application running VB Script when either

1. An On Error Resume Next statement is called prior to executing some script. A number of method calls are then made which can potentially raise errors. After each statement is completed the Err.Number property is usually checked and action taken such as logging the error and providing user friendly messages.
2. No On Error Resume Next statement is called prior to executing some script . In this case any statements that follow will halt the processing of the script and return a runtime application error to the user.

Whilst the first case is the preferred approach to handle errors gracefully most developers typically do not check most statements for errors. If Err.Number is not checked errors can be silently ignored by the server side script, and then consequently cause other errors which are logged. It is therefore essential to be able to log information on the original error, namely the source, description and number.

Unlike languages such as C++ / VB or .NET exceptions aren’t raised to the debugger from scripting engines such as VBScript. Consequently we can’t use adplus to capture a dump file when a specific type of exception occurs. However when an error is raised a number of functions are called within the scripting runtime.

• vbscript!COleScript::OnScriptError. This is called when a script occurs in the 2nd case above
• vbscript!CScriptRuntime::RecordErrorContext. This is called to record an error in the scripting runtime when On Error Resume Next has been called.

Although we can’t use adplus to create a dump file on an exception (because none is raised) we can use it to create a dump when a specific break point is reached. Opening the dump file shows the following call stack

0:023> kvn
# ChildEBP RetAddr Args to Child
00 0148f4a8 733183bf 0003aa70 000b5f48 00000000 vbscript!CScriptRuntime::RecordErrorContext
01 0148f4c4 73318320 0003aa70 0148f5cc 00000010 vbscript!CSession::RecordExcepInfoAndClear
02 0148f5b8 73304b01 0003a9c0 000b5f48 60030001 vbscript!InvokeDispatch

If we dump the first argument plus 8 we can see the EXCEPINFO structure which is passed to this method. EXCEPINFO is the automation structure which defines an error i.e.

struct EXCEPINFOA, 9 elements, 0x20 bytes
+0x000 wCode : Uint2B
+0x002 EXC_unused1 : UChar
+0x004 bstrSource : Ptr32 to Void
+0x008 bstrDescription : Ptr32 to Void
+0x00c bstrHelpFile : Ptr32 to Void
+0x010 dwHelpContext : Uint4B
+0x014 EXC_unused2 : UChar
+0x018 pfnDeferredFillIn : Ptr32 to Void
+0x01c scode : Uint4B

Reviewing the dump we see

0:023> dd 0003aa70 + 8
0003aa78 00000000 000b85bc 00121254 00000000
0003aa88 000f43e8 00000000 00000000 800a0063
0003aa98 00000000 00000000 00000000 00000000
0003aaa8 00000000 00000000 000a0004 0008012a

To find the source and description we can use the du command i.e.

0:023> du 000b85bc
000b85bc "MyVBClass"
0:023> du 00121254
00121254 "Failed to get supplier invoice, "
00121294 "Reason=Failed to open connection"
001212d4 ", reason=Object required"

However to get this information a full dump needs to be created. If many script errors occur this maybe unworkable in a production environment. A more elegant approach involves using a custom action in an adplus config file to extract the source, description and number and add to the log file adplus produces. i.e.

<ADPlus>
<Settings>
<RunMode>CRASH</RunMode>
<ProcessID><Put process id in here></ProcessID>
</Settings>
<Breakpoints>
<NewBP>
<Address>vbscript!CScriptRuntime::RecordErrorContext</Address>
<CustomActions>.echo -----;.echo VB Script On Error Resume Next error occurred.;.echo;.echo Source:;du poi(poi(esp+4)+c);.echo Description:;du
poi(poi(esp+4)+10);.echo Code:;?poi(poi(esp+4)+24);g</CustomActions>
<Actions>Log;Stack;</Actions>
<ReturnAction>G</ReturnAction>
</NewBP>
<NewBP>
<Address>vbscript!COleScript::OnScriptError </Address>
<CustomActions>.echo -----;.echo VB Script On Error Resume Next error occurred.;.echo;.echo Source:;du poi(poi(esp+4)+c);.echo Description:;du
poi(poi(esp+4)+10);.echo Code:;?poi(poi(esp+4)+24);g</CustomActions>
<Actions>Log;Stack;</Actions>
<ReturnAction>G</ReturnAction>
</NewBP>
</Breakpoints>
</ADPlus>

The most interesting line in the config file is

.echo Source:;du poi(poi(esp+4)+c);.echo Description:;du poi(poi(esp+4)+10);.echo Code:;?poi(poi(esp+4)+24);

The source and description are output as strings using the du command. From the parameter poi(poi(esp+4)+c), esp+4 is the stack pointer + 1 DWORD which equals the first parameter to the function were breaking on ( RecordErrorContext or OnScriptError ). This is dereferenced using the poi operator from which we then add 0xC to get to the offset of the Source member in the EXCEPINFO structure. The Source member is just a pointer to a string so poi is used again to dereference it. Description is handled the same and the error code is simply output using the ? evaluate expression command.

When a VB Script exception occurs you get all the relevant information provided in the log file along with any other exceptions which are raised i.e.

VB Script On Error Resume Next error occurred.

Source:
0017edf4 "MyVBClass"
Description:
0017eeac "Failed to get supplier invoice, "
0017eeec "Reason=Failed to open connection"
0017ef2c ", reason=Object required"
Code:
Evaluate expression: -2146828189 = 800a0063

Getting dumps for apps failing on start up using terminal services

In my previous post http://mattadamson.blogspot.com/2005/05/getting-dumps-for-apps-failing-on.html I discussed the use of gflags to invoke a debugger to start when a process starts and then sending debugger commands to create dumps when exceptions occur. However if your trying to debug against a process run in session 0, e.g. a web application or service, this technique will not work. As most support teams will probably be using terminal services to access production servers clearly we need a technique to get the dumps.

Remote debugging is commonly used to debug across two machines i.e. setting up a debugger on the server and using a debugging client to connect to it using named pipes or tcp. However there is nothing stopping us using the same machine to host the debugging server and the client. We need to set up a debugger server which runs in session 0 and a debugger client which runs in the terminal services session i.e. 3 in our example.

As before open gflags and specify the image module name you need to debug however instead of simply entering the path to the debugger you should specify some command line options to tell windbg to start as a debugging server. Enter the following in the debugger field

C:\Debuggers\windbg.exe -server tcp:port=123 –Q

The server option creates a debugging server and the tcp:port option specifies the port number. The –Q option suppresses the “Save workspace” dialog which is important if the debugger is running in session 0 and can’t interact with the user. Note the command line options are case sensitive so be sure to copy this exactly as it appears. As soon as the process your debugging starts the windbg debugee should be loaded in session 0 and broken in on the LdrpInitializeProcess method.

To control the debugger server start a new instance of windbg as the debugging client. Press Ctrl+R to connect to a remote debugger session and enter the following

tcp:server=MACHINENAME,port=123

When you connect the windbg instance will connect to the remote debugger and allow you full control to enter commands e.g. you can enter

Sxe *
g

to break on all exceptions and then continue. You can also send the same commands to create dump files as mentioned in my previous post. Or you could simply use .dump to create a dump when a specific exception is raised e.g.

.dump /ma c:\debugger\ExceptionDump.dmp

If you look at task manager you should also see two instances of windbg open. If you select the “Session ID” column you can see the different terminal services sessions used for each instance.