Case of the Unknown Error App Crash – Debugging & Patching Someone Else’s .NET Race Condition

Posted on March 20, 2014 by chentiangemalc

We were testing an application Supply Chain Guru purchased by a customer, however on launch it we would see a splash screen for a second, then fail with dialog message box:

image

Clicking OK on the message box would quit the application.

Some interesting things about this issue:

  • Issue only occurred when laptop was connected to corporate network
  • Did not occur when connected to a 4G network
  • If you launched the app many times in a row, in rare cases it would work
  • Application always launched when disconnected from network, or connected to a network other than the corporate LAN
  • The issue did not occur if you launched application via Debugger (cdb/WinDbg) and hit “g” then on initial crash hit .restart and hit “g”again
  • Issue does not occur on a “clean install” OS (with no other 3rd party software
  • The issue would not occur if ProcMon is running

When issues don’t occur with ProcMon running, often we have a bug that is called a “race condition” or “race hazard” This is when the program relies on a certain sequence and timing of uncontrollable events…and turn into a bug when they execute out of the sequence the programmer intended.

For application crashes it is always wise to check the Application event log at first, as you often get very detailed information immediately just from there.  Sure enough we get a stack trace of the crash:

Application: SCGuru.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: System.NullReferenceException
Stack:
   at LLamasoft.SupplyChainGuru.Core.cErrorLog.WriteMessage(System.String, Boolean)
   at LLamasoft.SupplyChainGuru.Core.HelpManager.LoadTooltipHelpDictionary()
   at LLamasoft.SupplyChainGuru.Core.HelpManager._Lambda$__118(System.Object)
   at System.Threading.QueueUserWorkItemCallback.WaitCallback_Context(System.Object)
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
   at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()

This was provided to the vendor application support, but they were a bit lost. So we are going to need to help them out…

From this we can see two things:

1) From the System.Threading.IThreadPoolWorkItem.ExecuteWorkItem we have a worker thread – this confirms our suspicions of a race condition

2) A NullReferenceException occurs in function LLamasoft.SupplyChainGuru.Core.cErrorLog.WriteMessage function.

NullReferenceException in a .NET program occurs when attempting to access a property or call a method on an uninitialized object. Using .NET reflector let’s look at this function:

public static void WriteMessage(string strMessage, bool IncludeSystemData = true)
{

    GuruInformation.Instance.LogFactory.WriteLogMessage(SourceLevels.Verbose, strMessage, null, IncludeSystemData);
}

Just looking at this line of code, we can guess the most likely cause of a NullReferenceException is that GuruInformation.Instance.LogFactory has not been initialized, so attempt to access WriteLogMessage method results in a NullReferenceException.

Using .NET reflector we are also able to find the code that initializes LogFactory. In LLamasoft.SupplyChainGuru.WinClient.UserContext, within Initialize() function:

GuruInformation.Instance.InitializeLogging<LogFactory>(GuruModel.get_TemporaryModelFolder(), new Func<string>(cErrorLog.GetSystemData));

I had got a crash dump generated by an onsite engineer at time issue occurred using http://live.sysinternals.com/procdump.exe

We opened this in WinDbg (x86) from the Windows SDK. Because this is a .NET app we first load the sos debugging extension, however this failed:

0:015> .loadby sos clr
0:015> !eestack
Failed to load data access DLL, 0x80004005
Verify that 1) you have a recent build of the debugger (6.2.14 or newer)
            2) the file mscordacwks.dll that matches your version of clr.dll is
                in the version directory or on the symbol path
            3) or, if you are debugging a dump file, verify that the file
                mscordacwks_<arch>_<arch>_<version>.dll is on your symbol path.
            4) you are debugging on supported cross platform architecture as
                the dump file. For example, an ARM dump file must be debugged
                on an X86 or an ARM machine; an AMD64 dump file must be
                debugged on an AMD64 machine.

You can also run the debugger command .cordll to control the debugger’s
load of mscordacwks.dll.  .cordll -ve -u -l will do a verbose reload.
If that succeeds, the SOS command should work on retry.

If you are debugging a minidump, you need to make sure that your executable
path is pointing to clr.dll as well.

 

This issue is caused because you cannot debug .NET 4.0 apps with .NET 4.5.x installed, you will need

1) symbols configured to Microsoft symbol servers (i.e. run .symfix C:\symbols) and ensure mscorwks.dll comes down from MS Symbol Servers (You can verify with !sym noisy; .reload /f )

2) A copy of SOS DLL from a .NET 4.0 machine C:\Windows\Microsoft.NET\Framework\v4.0.30319\SOS.dll then load it with the full file path (If there is space in the file path don’t add quotes!)

0:015> .unload sos
Unloading C:\Windows\Microsoft.NET\Framework\v4.0.30319\sos extension DLL
0:015> .load C:\support\sos_4.0.dll

I used !EEstack to display all managed threads. We search for cErrorLog.WriteMessage

Which we find:

<blah blah blah>

Thread  11
Current frame: user32!NtUserWaitMessage+0x15
ChildEBP RetAddr  Caller, Callee

<blah blah blah>

System.Windows.Forms.MessageBoxButtons, System.Windows.Forms.MessageBoxIcon, System.Windows.Forms.MessageBoxDefaultButton, System.Windows.Forms.MessageBoxOptions, Boolean)), calling 52eab2a0
0be4cc04 5356844b (MethodDesc 52d21fec +0x23b System.Windows.Forms.MessageBox.ShowCore(System.Windows.Forms.IWin32Window, System.String, System.String, System.Windows.Forms.MessageBoxButtons, System.Windows.Forms.MessageBoxIcon, System.Windows.Forms.MessageBoxDefaultButton, System.Windows.Forms.MessageBoxOptions, Boolean)), calling 52eab2a0
0be4cc28 53568391 (MethodDesc 52d21fec +0x181 System.Windows.Forms.MessageBox.ShowCore(System.Windows.Forms.IWin32Window, System.String, System.String, System.Windows.Forms.MessageBoxButtons, System.Windows.Forms.MessageBoxIcon, System.Windows.Forms.MessageBoxDefaultButton, System.Windows.Forms.MessageBoxOptions, Boolean)), calling user32!GetActiveWindow
0be4cc98 535686d9 (MethodDesc 52d21f68 +0x19 System.Windows.Forms.MessageBox.Show(System.String, System.String, System.Windows.Forms.MessageBoxButtons, System.Windows.Forms.MessageBoxIcon)), calling (MethodDesc 52d21fec +0 System.Windows.Forms.MessageBox.ShowCore(System.Windows.Forms.IWin32Window, System.String, System.String, System.Windows.Forms.MessageBoxButtons, System.Windows.Forms.MessageBoxIcon, System.Windows.Forms.MessageBoxDefaultButton, System.Windows.Forms.MessageBoxOptions, Boolean))
0be4ccb8 08a8bb95 (MethodDesc 00dd5ef8 +0xf5 LLamasoft.SupplyChainGuru.WinClient.CustomExceptionHandler.OnDomainThreadException(System.Object, System.UnhandledExceptionEventArgs)), calling (MethodDesc 52d21f68 +0 System.Windows.Forms.MessageBox.Show(System.String, System.String, System.Windows.Forms.MessageBoxButtons, System.Windows.Forms.MessageBoxIcon))
<blah blah>
0be4dc84 08a8ba41 (MethodDesc 06b03f04 +0x31 LLamasoft.SupplyChainGuru.Core.cErrorLog.WriteMessage(System.String, Boolean)), calling 001d6852
0be4dcf0 08a8b5ab (MethodDesc 00ed05fc +0x1bb LLamasoft.SupplyChainGuru.Core.HelpManager.LoadTooltipHelpDictionary()), calling (MethodDesc 06b03f04 +0

So then I set active thread to 11:

0:011> ~11 s

looked for the exceptions with the nested option:

0:011> !pe -nested
Exception object: 0345fc60
Exception type:   System.NullReferenceException
Message:          Object reference not set to an instance of an object.
InnerException:   <none>
StackTrace (generated):
    SP       IP       Function
    0BE4CD54 08A8C353 SCGuru!LLamasoft.SupplyChainGuru.WinClient.UserContext.get_LogFilePath()+0x13
    0BE4CD5C 08A8C311 UNKNOWN!LLamasoft.SupplyChainGuru.Core.cErrorLog.get_ErrorLogLocation()+0x31
    0BE4CD68 08A8BB15 SCGuru!LLamasoft.SupplyChainGuru.WinClient.CustomExceptionHandler.OnDomainThreadException(System.Object, System.UnhandledExceptionEventArgs)+0x75

StackTraceString: <none>
HResult: 80004003

Nested exception ————————————————————-
Exception object: 03459d50
Exception type:   System.NullReferenceException
Message:          Object reference not set to an instance of an object.
InnerException:   <none>
StackTrace (generated):
    SP       IP       Function
    0BE4DCDC 08A8BA3B UNKNOWN!LLamasoft.SupplyChainGuru.Core.cErrorLog.WriteMessage(System.String, Boolean)+0x2b
    0BE4DCF8 08A8B5AB UNKNOWN!LLamasoft.SupplyChainGuru.Core.HelpManager.LoadTooltipHelpDictionary()+0x1bb
    0BE4ECF0 08A8B038 UNKNOWN!LLamasoft.SupplyChainGuru.Core.HelpManager._Lambda$__118(System.Object)+0x8
    0BE4ECF4 554FDA21 mscorlib_ni!System.Threading.QueueUserWorkItemCallback.WaitCallback_Context(System.Object)+0x2d
    0BE4ECFC 55484D85 mscorlib_ni!System.Threading.ExecutionContext.runTryCode(System.Object)+0x51
    0BE4F198 55484C8A mscorlib_ni!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+0x6a
    0BE4F1B0 55487F92 mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)+0x7e
    0BE4F1D4 554CB692 mscorlib_ni!System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()+0x5a
    0BE4F1E8 554CAF1F mscorlib_ni!System.Threading.ThreadPoolWorkQueue.Dispatch()+0x147
    0BE4F234 554CADC5 mscorlib_ni!System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()+0x2d

StackTraceString: <none>
HResult: 80004003

Nested exception ————————————————————-
Exception object: 03459870
Exception type:   System.NullReferenceException
Message:          Object reference not set to an instance of an object.
InnerException:   <none>
StackTrace (generated):
    SP       IP       Function
    0BE4ECB8 08A8B479 UNKNOWN!LLamasoft.SupplyChainGuru.Core.HelpManager.LoadTooltipHelpDictionary()+0x89

StackTraceString: <none>
HResult: 80004003

0:000>

Here we can see the original exception is occurring in LoadTooltipHelpDictionary() … Let’s look at what this function is. First I get the method descriptor of the function uses !name2ee (If we know the module name you can place it instead of the *)

0:011> !name2ee *!LLamasoft.SupplyChainGuru.Core.HelpManager.LoadTooltipHelpDictionary
<blah blah blah>
——
Module:      00399b30
Assembly:    SupplyChainGuru.LowerCore.dll
Token:       06000a47
MethodDesc:  00ed05fc
Name:        LLamasoft.SupplyChainGuru.Core.HelpManager.LoadTooltipHelpDictionary()
JITTED Code Address: 08a8b3f0
———————————
<blah blah blah>

Now we can dump the IL code….

0:011> !dumpil 00ed05fc
ilAddr = 059440b8
IL_0000: ldarg.0
IL_0001: callvirt LLamasoft.SupplyChainGuru.Core.HelpManager::ClearTooltipHelpDictionary
.try
{
  IL_0006: newobj System.Data.DataTable::.ctor
  IL_000b: stloc.0
  .try
  {
    IL_000c: call LLamasoft.Data.DataSources.DataManager::get_Instance
    IL_0011: call LLamasoft.SupplyChainGuru.Core.CGuruLowerCore::get_Instance
    IL_0016: callvirt LLamasoft.SupplyChainGuru.Core.CGuruLowerCore::get_UserContext
    IL_001b: callvirt LLamasoft.SupplyChainGuru.Core.iUserContext::get_HelpFileDB
    IL_0020: callvirt LLamasoft.Data.DataSources.DataManager::CreateConnection
    IL_0025: stloc.1

<blah blah blah>
    } // end .try

} // end .try
.catch
{
  IL_008d: dup
  IL_008e: call Microsoft.VisualBasic.CompilerServices.ProjectDat::SetProjectError
  IL_0093: stloc.3
  IL_0094: ldstr “Failed to load help tooltips.”
  IL_0099: ldc.i4.1
  IL_009a: call LLamasoft.SupplyChainGuru.Core.cErrorLog::WriteMessage
  IL_009f: call Microsoft.VisualBasic.CompilerServices.ProjectDat::ClearProjectError
  IL_00a4: leave.s IL_00a6
} // end .catch
IL_00a6: ret

 

Looking at the code we can guess the attempt to create the connection to the HelpFileDB (a local MDB file, used to popular tool tips in the application) Is failing with a Null Reference Exception, resulting in hitting the “Catch” section of code, then attempting to write the error log. Which also fails due to a null reference exception…

So let’s inspect objects on the stack. NullReferenceException seems to be popular today :) However the object that interests me is the HelpManager that gets references in above code…

0:011> !DumpStackObjects
OS Thread Id: 0x20dc (11)
ESP/REG  Object   Name
0BE4CBDC 0345a4ac System.String    Fatal Error
0BE4CBE0 0345a4ac System.String    Fatal Error
0BE4CBF0 0345a4ac System.String    Fatal Error
0BE4CBF4 0345a4ac System.String    Fatal Error
0BE4CC44 0345a4ac System.String    Fatal Error
0BE4CC90 0345a038 System.String    An unexpected application error has occurred in one of the application’s
threads and has left the application in an unstable state.

The application is terminating.

Information about the problem has been written to the application error log at the following location:

0BE4CCB4 0345a4ac System.String    Fatal Error
0BE4CD98 03459fd8 System.UnhandledExceptionEventArgs
0BE4CE40 02b21338 System.AppDomain
0BE4CE44 02b524c0 System.UnhandledExceptionEventHandler
0BE4CE70 03459fd8 System.UnhandledExceptionEventArgs
0BE4D064 02b524c0 System.UnhandledExceptionEventHandler
0BE4D06C 02b21338 System.AppDomain
0BE4D074 03459fd8 System.UnhandledExceptionEventArgs
0BE4D0D0 03459fd8 System.UnhandledExceptionEventArgs
0BE4D0D8 03459d50 System.NullReferenceException
0BE4D174 03459fd8 System.UnhandledExceptionEventArgs
0BE4D1E8 02b524c0 System.UnhandledExceptionEventHandler
0BE4D2B0 02b21338 System.AppDomain
0BE4D3BC 03459d50 System.NullReferenceException
0BE4D568 03459e60 System.Runtime.Serialization.SafeSerializationManager
0BE4D9D8 03459d50 System.NullReferenceException
0BE4DA3C 03459d50 System.NullReferenceException
0BE4DA5C 03459d50 System.NullReferenceException
0BE4DB00 03459d50 System.NullReferenceException
0BE4DB34 03459d50 System.NullReferenceException
0BE4DB78 03459d50 System.NullReferenceException
0BE4DBC4 034536d8 System.String    Failed to load help tooltips.
0BE4DBC8 0345972c LLamasoft.Data.DataSources.DataManager
0BE4DCAC 034536d8 System.String    Failed to load help tooltips.
0BE4DCB4 0345972c LLamasoft.Data.DataSources.DataManager
0BE4DCE4 034536d8 System.String    Failed to load help tooltips.
0BE4DCE8 02b21228 System.String   
0BE4DCEC 03453740 System.Data.DataTable
0BE4DD08 03459870 System.NullReferenceException
0BE4DD1C 03459870 System.NullReferenceException
0BE4DD20 0345972c LLamasoft.Data.DataSources.DataManager
0BE4DD2C 02b21228 System.String   
0BE4DD30 03453740 System.Data.DataTable
0BE4E040 03459870 System.NullReferenceException
0BE4E054 03459870 System.NullReferenceException
0BE4E680 03459870 System.NullReferenceException
0BE4E77C 03453740 System.Data.DataTable
0BE4E784 02b21228 System.String   
0BE4E8F0 03453740 System.Data.DataTable
0BE4E8F4 02b21228 System.String   
0BE4E8F8 0345972c LLamasoft.Data.DataSources.DataManager
0BE4E8FC 02b21228 System.String   
0BE4EC7C 02b21228 System.String   
0BE4EC80 0345972c LLamasoft.Data.DataSources.DataManager
0BE4EC88 02b21228 System.String   
0BE4EC8C 03453740 System.Data.DataTable
0BE4EC9C 0345972c LLamasoft.Data.DataSources.DataManager
0BE4ECA0 03453740 System.Data.DataTable
0BE4ECAC 02b21228 System.String   
0BE4ECC0 03453740 System.Data.DataTable
0BE4ECC4 03448728 LLamasoft.SupplyChainGuru.Core.HelpManager

We can take the 2nd column value to inspect object:

0:011> !do 03448728
Name:        LLamasoft.SupplyChainGuru.Core.HelpManager
MethodTable: 00ed0698
EEClass:     00e69734
Size:        20(0x14) bytes
File:        C:\Program Files (x86)\Supply Chain Guru\SupplyChainGuru.LowerCore.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
00ed08e4  4000312        4 …nGuru.LowerCore]]  0 instance 0344873c _tooltipHelpDictionary
65a07728  4000313        8 System.Drawing.Image  0 instance 03452bbc _helpIcon
00ed0efc  4000314        c …Core.RoboHelp_CSH  0 instance 03453100 mRoboHelp
00ed0698  4000311       60 ….Core.HelpManager  0   static 03448728 _instance

 

Next we want to inspect the values of the _tooltipHelpDictionary using the MT & Field values from above:

0:011> !dumpvc 00ed08e4 4000312
Name:        System.Collections.Generic.Dictionary`2[[System.String, mscorlib],[LLamasoft.SupplyChainGuru.Core.TooltipHelpResource, SupplyChainGuru.LowerCore]]
MethodTable: 00ed08e4
EEClass:     552a99ac
Size:        52(0x34) bytes
File:        C:\WINDOWS\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
55572a94  4000c7d        0       System.Int32[]  0 instance 00000000 buckets
55d0e378  4000c7e        4 …non, mscorlib]][]  0 instance 00000000 entries
55572ad4  4000c7f       1c         System.Int32  1 instance        0 count
55572ad4  4000c80       20         System.Int32  1 instance        0 version
55572ad4  4000c81       24         System.Int32  1 instance        0 freeList
55572ad4  4000c82       28         System.Int32  1 instance        0 freeCount
55573134  4000c83        8 …Canon, mscorlib]]  0 instance 00000000 comparer
555657e8  4000c84        c …Canon, mscorlib]]  0 instance 00000000 keys
5556b88c  4000c85       10 …Canon, mscorlib]]  0 instance 00000000 values
5556f744  4000c86       14        System.Object  0 instance 00000000 _syncRoot
5556b8f0  4000c87       18 …SerializationInfo  0 instance 00000000 m_siInfo

 

What we confirm, here is that – this dictionary didn’t populate at all. So the exception must have occurred at connection to database…

By searching in .NET Reflector we found this HelpManager gets initialized when UserContext gets initialized.

image 

We find the thread in our dump with !eestack

0:00>!eestack
<blah blah blah>
Thread   9
Current frame: ntdll!ZwQueryFullAttributesFile+0x12
ChildEBP RetAddr  Caller, Callee
06c1e77c 75889bdf KERNELBASE!GetFileAttributesExW+0x93, calling ntdll!ZwQueryFullAttributesFile
06c1e7ac 68c0cf99 clr!WKS::GCHeap::SetCardsAfterBulkCopy+0x16
06c1e7b8 68c1152c clr!SystemNative::ArrayCopy+0x282
06c1e7c0 68c0da0b clr!SystemNative::ArrayCopy+0x28f, calling clr!Thread::CatchAtSafePoint
06c1e800 555100e2 (MethodDesc 552d29cc +0x52 DomainNeutralILStubClass.IL_STUB_PInvoke(System.String, Int32, WIN32_FILE_ATTRIBUTE_DATA ByRef))
06c1e824 555100e2 (MethodDesc 552d29cc +0x52 DomainNeutralILStubClass.IL_STUB_PInvoke(System.String, Int32, WIN32_FILE_ATTRIBUTE_DATA ByRef))
06c1e828 758774ec KERNELBASE!GetErrorMode+0x18, calling ntdll!ZwQueryInformationProcess
06c1e838 75877547 KERNELBASE!SetErrorMode+0x37, calling ntdll!ZwSetInformationProcess
06c1e858 5548770b (MethodDesc 552c3388 +0xa7 System.IO.File.FillAttributeInfo(System.String, WIN32_FILE_ATTRIBUTE_DATA ByRef, Boolean, Boolean)), calling 554294bc
06c1e874 554876ce (MethodDesc 552c3388 +0x6a System.IO.File.FillAttributeInfo(System.String, WIN32_FILE_ATTRIBUTE_DATA ByRef, Boolean, Boolean)), calling kernel32!SetErrorModeStub
06c1e894 55507c29 (MethodDesc 55385f14 +0x39 System.Security.Util.StringExpressionSet.AddExpressions(System.Collections.ArrayList, Boolean)), calling clr!JIT_WriteBarrierESI
06c1e8ec 554a9067 (MethodDesc 5533d5b4 +0x33 System.IO.DirectoryInfo.get_Exists()), calling (MethodDesc 552c3388 +0 System.IO.File.FillAttributeInfo(System.String, WIN32_FILE_ATTRIBUTE_DATA ByRef, Boolean, Boolean))
06c1e91c 08a81cfd (MethodDesc 05486dec +0x7d LLamasoft.SupplyChainGuru.WinClient.UserContext.CheckFolderSettingSaved(System.String, System.String))
06c1e934 05e633a5 (MethodDesc 05486610 +0x335 LLamasoft.SupplyChainGuru.WinClient.UserContext.Initialize()), calling (MethodDesc 05486dec +0 LLamasoft.SupplyChainGuru.WinClient.UserContext.CheckFolderSettingSaved(System.String, System.String))
06c1e954 00c9362a (MethodDesc 054865c4 +0x3a LLamasoft.SupplyChainGuru.WinClient.UserContext.get_Instance()), calling (MethodDesc 05486610 +0 LLamasoft.SupplyChainGuru.WinClient.UserContext.Initialize())
 

0:00>~9 s

0:009> !dumpstackobjects
OS Thread Id: 0x23a0 (9)
ESP/REG  Object   Name
06C1E7A4 03118adc System.Object[]    (System.String[])
06C1E7CC 031189b0 System.Object[]    (System.String[])
06C1E848 031187b0 System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E84C 031187b0 System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E87C 03118af0 System.Collections.ArrayList
06C1E880 03118af0 System.Collections.ArrayList
06C1E88C 03118b50 System.Collections.ArrayList
06C1E890 03118b38 System.Security.Util.StringExpressionSet
06C1E8A8 031187b0 System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E8E0 031187b0 System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E8E4 03118868 System.IO.DirectoryInfo
06C1E8E8 02eec9dc System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E910 031187b0 System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E914 02d121dc System.String    BackupFolder
06C1E918 02eec9dc System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E924 03118868 System.IO.DirectoryInfo
06C1E928 02d128f0 LLamasoft.SupplyChainGuru.GuruInformation
06C1E92C 02b5c95c LLamasoft.SupplyChainGuru.WinClient.UserContext <- This is the object we want
06C1E930 02d121dc System.String    BackupFolder
06C1E93C 02eec9dc System.String    \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Guru Model Backups
06C1E940 02d128f0 LLamasoft.SupplyChainGuru.GuruInformation
06C1E980 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1E9B8 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1EA1C 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1EA40 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1EB20 02b4aaec System.Windows.Forms.Control+ControlNativeWindow
06C1ED68 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1ED74 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1ED7C 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1ED84 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1ED8C 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1EE0C 02b4a648 LLamasoft.SupplyChainGuru.WinClient.FormSplash
06C1EE58 02b520a0 System.Windows.Forms.Application+ThreadContext
06C1EE88 02c16280 System.Reflection.RuntimeMethodInfo
06C1EE98 02b51fb0 System.Windows.Forms.ApplicationContext
06C1EEBC 02c16280 System.Reflection.RuntimeMethodInfo
06C1F364 02b51e88 System.Runtime.CompilerServices.RuntimeHelpers+TryCode
06C1F368 02b51ea8 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode
06C1F36C 02b51ec8 System.Threading.ExecutionContext+ExecutionContextRunData
06C1F3A0 02c16048 System.String    LeftInternal
06C1F3B4 02b51d74 System.Threading.ThreadHelper
06C1F3B8 02c16048 System.String    LeftInternal
06C1F3C4 02c16048 System.String    LeftInternal
06C1F3D8 02b51d74 System.Threading.ThreadHelper
06C1F668 02b28fb8 System.Security.Principal.WindowsPrincipal
06C1F670 02b51d88 System.Threading.ThreadStart
06C1F678 02b51d44 System.Threading.Thread

Now we dump the UserContext object…

0:009> !do 02b5c95c
Name:        LLamasoft.SupplyChainGuru.WinClient.UserContext
MethodTable: 057e1888
EEClass:     05542700
Size:        136(0x88) bytes
File:        C:\Program Files (x86)\Supply Chain Guru\SCGuru.exe
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
5556fb08  400067d        4        System.String  0 instance 02d12ffc defaultRoutingProvider
5556fb08  400067f        8        System.String  0 instance 02b21228 m_strApplicationVersion
5556fb08  4000680        c        System.String  0 instance 02b21228 m_strApplicationTitle
5556fb08  4000681       10        System.String  0 instance 02b21228 m_strApplicationName
5556fb08  4000682       14        System.String  0 instance 02b21228 m_strDataPath
5556fb08  4000683       18        System.String  0 instance 02b21228 m_strImagePath
5556fb08  4000684       1c        System.String  0 instance 02b21228 m_strSplashImagePath
5556fb08  4000685       20        System.String  0 instance 02b21228 m_strMapIconPath
5556fb08  4000686       24        System.String  0 instance 02b21228 m_strBaseModelFilePath
5556fb08  4000687       28        System.String  0 instance 02b21228 m_strDefaultCostingDataPath
5556fb08  4000688       2c        System.String  0 instance 02b21228 m_strDataStorePath
5556fb08  4000689       30        System.String  0 instance 03117ac8 m_strMacroPath
5556fb08  400068a       34        System.String  0 instance 02b21228 m_strTimerLogPath
00000000  400068b       38                       0 instance 00000000 m_SqlServerDatabase
00000000  400068c       3c                       0 instance 00000000 m_sqlExpress
5556fb08  400068d       40        System.String  0 instance 02b21228 m_strHelpDBFileName <- this is what we are interested in
5556fb08  400068e       44        System.String  0 instance 02b21228 m_strHelpFileName
55576788  400068f       80       System.Boolean  1 instance        0 m_UseProxyServer
5556fb08  4000690       48        System.String  0 instance 02b21228 m_ProxyServerAddress
5556fb08  4000691       4c        System.String  0 instance 02b21228 m_ProxyServerPort
55576788  4000692       81       System.Boolean  1 instance        0 m_ProxyUseIntegratedSecurity
5556fb08  4000693       50        System.String  0 instance 02b21228 m_ProxyUserName
5556fb08  4000694       54        System.String  0 instance 02b21228 m_ProxyUserPassword
5556fb08  4000695       58        System.String  0 instance 02b21228 m_ProxyUserDomain
55576788  4000696       82       System.Boolean  1 instance        0 m_UseCustomAgentString
5556fb08  4000698       5c        System.String  0 instance 02b21228 m_BaseHelpLocalWebPage
5556fb08  4000699       60        System.String  0 instance 02b21228 m_WebURL
5556fb08  400069b       64        System.String  0 instance 00000000 _enterpriseBackupFolder
55576788  400069c       83       System.Boolean  1 instance        0 _enterpriseServerSqlIntegratedSecurity
5556fb08  400069d       68        System.String  0 instance 03117f94 m_strDefaultProjectFolder
5556fb08  400069e       6c        System.String  0 instance 02b7cbf4 m_strDefaultEnterpriseFolder
5556fb08  400069f       70        System.String  0 instance 02b82c70 m_strTempPackageFolder <- we are just using this as a test
5556fb08  40006a0       74        System.String  0 instance 02c597a0 m_strCustomMapLayers
5556fb08  40006a1       78        System.String  0 instance 02b21228 _enterpriseServerWebPassword
5556fb08  40006a2       7c        System.String  0 instance 00000000 _enterpriseDataFolder
057e1888  400069a       54 …lient.UserContext  0   static 02b5c95c m_instance

 

As a test I checked contents of m_strTempPackageFolder – contents look OK.

0:009> !do 02b82c70 

Name:        System.String
MethodTable: 5556fb08
EEClass:     552a8bb0
Size:        172(0xac) bytes
File:        C:\WINDOWS\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      \\somecompany.local\filestore\MEL-Users\chentiangemalc\Documents\LLamasoft\Temp\Packages
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
55572ad4  4000103        4         System.Int32  1 instance       79 m_stringLength
55571f24  4000104        8          System.Char  1 instance       5c m_firstChar
5556fb08  4000105        8        System.String  0   shared   static Empty
    >> Domain:Value  00fd29b8:02b21228 <<

Now we check what we’re interested in m_strHelpDBFilename. It is empty. Note all the strings above with value of “02b21228” are empty

0:009> !do 02b21228
Name:        System.String
MethodTable: 5556fb08
EEClass:     552a8bb0
Size:        14(0xe) bytes
File:        C:\WINDOWS\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:     
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
55572ad4  4000103        4         System.Int32  1 instance        0 m_stringLength
55571f24  4000104        8          System.Char  1 instance        0 m_firstChar
5556fb08  4000105        8        System.String  0   shared   static Empty
>> Domain:Value  00fd29b8:02b21228 <<

 

So why is this value not initialized, before use. We need to ask – where is the initialization? I used Visual Studio 2013 (you need professional or higher) with .NET Reflector option “Debug an Executable” and traced it to CGuruAppUI.Instance.Initialize. This allowed me to step-by-step inspect code, set break points, change variables, etc, and I could use F11 “Step-into” as needed. For live debugging a .NET app it is much easier for many tasks than WinDbg. However debugging live with WinDbg is more stable, and doesn’t require Visual Studio Professional. If you need to use WinDbg for live debugging .NET apps I recommend you also use the sosex extension from http://www.stevestechspot.com/SOSEXV40NowAvailable.aspx as it is much easier to set breakpoints vs sos.(among other features).

image

 

Right clicking the method call we can decompile it:

image

 

This brought us to this code, here we see QueueUserWorkItem used. Based on MSDN documentation “http://msdn.microsoft.com/en-us/library/system.threading.threadpool.queueuserworkitem(v=vs.110).aspx” The method executes “when the thread pool becomes available.” Sounds like prime cause of our “race condition”

 

public void Initialize()
        {
            if (CGuruLowerCore.Instance.ApplicationType == ApplicationType.SupplyChainGuru)
            {
                System.Threading.ThreadPool.QueueUserWorkItem(new System.Threading.WaitCallback(this._Lambda$__118));
                if (this.mRoboHelp == null)
                {
                    this.mRoboHelp = new RoboHelp_CSH();
                }
                this.mRoboHelp.RH_AssociateOfflineHelp(@”http:\\supplychainguru.com\help.htm”, CGuruLowerCore.Instance.UserContext.BaseHelpLocalWebPage);
            }
        }

So with .NET Reflector + Reflexil ( http://reflexil.net/ ) I patched the binary, by adding a Sleep for 5 seconds after the CGuruAppUIInstance.Initialize function, to allow the work item to run. (5 seconds was over kill, but I was erring on safe side…)

Using reflixl I inserted the IL commands:

idc.i4 5000

call System.Void.System.Threading.Thread::Sleep(System.Int32)

When adding the “Call” method just keep in mind the browser for method is based on DLL not namespace. So do not browse to System.Threading but instead Mscorlib –> System.Threading

 

image

 

I was then able to save patched code. Because this was an EXE it was pretty straightforward.

Warning: .NET DLL patching is more of a pain, as you need to use the  “Strong Name Remover” feature of reflexil, which I have seen corrupt EXEs before…take a backup first, as strong name remover overwrites your existing files.

image

I closed, and reloaded the code in .NET reflector to confirm my IL code was correct.

image ware

Testing the application, the “Unknown Error” no longer occurred. Keep in mind I don’t recommend binary patching as a general practice for 3rd party software in production use. However it is very useful to prove cause of bug when vendor can’t resolve the issue. We can now tell vendor exactly where issue is…

About chentiangemalc

specializes in end-user computing technologies. disclaimer 1) use at your own risk. test any solution in your environment. if you do not understand the impact/consequences of what you're doing please stop, and ask advice from somebody who does. 2) views are my own at the time of posting and do not necessarily represent my current view or the view of my employer and family members/relatives. 3) over the years Microsoft/Citrix/VMWare have given me a few free shirts, pens, paper notebooks/etc. despite these gifts i will try to remain unbiased.
This entry was posted in Uncategorized. Bookmark the permalink.

Leave a comment