Crash Dump Analysis Patterns (Part 64)
In addition to Module Variety there is another DLL Hell pattern that I call Duplicated Module. Here the same module is loaded at least twice and we can detect this when we see the module load address appended to its name in the output of lm commands (this is done to make the name of the module unique):
0:000> lm
start end module name
00b20000 0147f000 MSO_b20000
30000000 309a7000 EXCEL
30c90000 31848000 mso
71c20000 71c32000 tsappcmp
745e0000 7489e000 msi
76290000 762ad000 imm32
76b70000 76b7b000 psapi
76f50000 76f63000 secur32
77380000 77411000 user32
77670000 777a9000 ole32
77ba0000 77bfa000 msvcrt
77c00000 77c48000 gdi32
77c50000 77cef000 rpcrt4
77da0000 77df2000 shlwapi
77e40000 77f42000 kernel32
77f50000 77feb000 advapi32
7c800000 7c8c0000 ntdll
Usually his happens when the DLL is loaded from different locations. It can be exactly the same DLL version. The problems usually surface when there are different DLL versions and the new code loads the old version of the DLL and uses it. This may result in interface incompatibility issues and ultimately in application fault like an access violation.
In order to provide a dump to play with I created a small toy program called 2DLLs to model the worst case scenario similar to the one I encountered in a production environment a couple of days ago. The program periodically loads MyDLL module to call one of its functions. Unfortunately in one place it uses hardcoded relative path:
HMODULE hLib = LoadLibrary(L".\\DLL\\MyDLL.dll");
and in another place it relies on DLL search order:
hLib = LoadLibrary(L".\\MyDLL.dll");
PATH variable directories are used for search if this DLL was not found in other locations specified by DLL search order. We see that the problem can happen when another application is installed which uses the old version of that DLL and modifies PATH variable to point to its location. To model interface incompatibility I compiled the version of MyDLL that causes NULL pointer access violation when the same function is called from it. The DLL was placed into a separate folder and the PATH variable was modified to reference that folder:
C:\>set PATH=C:\OLD;%PATH%
The application crashes and the installed default postmortem debugger (CDB) saves its crash dump. If we open it we would see that it crashed in MyDLL_1e60000 module which should trigger suspicion:
0:000> r
rax=0000000001e61010 rbx=0000000000000000 rcx=0000775dcac00000
rdx=0000000000000000 rsi=0000000000000006 rdi=0000000000001770
rip=0000000001e61010 rsp=000000000012fed8 rbp=0000000000000000
r8=0000000000000000 r9=000000000012fd58 r10=0000000000000001
r11=000000000012fcc0 r12=0000000000000000 r13=0000000000000002
r14=0000000000000000 r15=0000000000000000
iopl=0 nv up ei pl nz na pe nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00010200
MyDLL_1e60000!fnMyDLL:
00000000`01e61010 c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=????????
0:000> kL
Child-SP RetAddr Call Site
00000000`0012fed8 00000001`40001093 MyDLL_1e60000!fnMyDLL
00000000`0012fee0 00000001`40001344 2DLLs+0×1093
00000000`0012ff10 00000000`773acdcd 2DLLs+0×1344
00000000`0012ff60 00000000`774fc6e1 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d
Looking at the list of modules we see two versions of MyDLL loaded from two different folders:
0:000> lm
start end module name
00000000`01e60000 00000000`01e71000 MyDLL_1e60000
00000000`772a0000 00000000`7736a000 user32
00000000`77370000 00000000`774a1000 kernel32
00000000`774b0000 00000000`7762a000 ntdll
00000001`40000000 00000001`40010000 2DLLs
00000001`80000000 00000001`80011000 MyDLL
000007fe`fc9e0000 000007fe`fca32000 uxtheme
000007fe`fe870000 000007fe`fe9a9000 rpcrt4
000007fe`fe9b0000 000007fe`fe9bc000 lpk
000007fe`fea10000 000007fe`feae8000 oleaut32
000007fe`fecd0000 000007fe`fed6a000 usp10
000007fe`fedd0000 000007fe`fefb0000 ole32
000007fe`fefb0000 000007fe`ff0af000 advapi32
000007fe`ff0d0000 000007fe`ff131000 gdi32
000007fe`ff2e0000 000007fe`ff381000 msvcrt
000007fe`ff390000 000007fe`ff3b8000 imm32
000007fe`ff4b0000 000007fe`ff5b4000 msctf
0:000> lmv m MyDLL_1e60000
start end module name
00000000`01e60000 00000000`01e71000 MyDLL_1e60000
Loaded symbol image file: MyDLL.dll
Image path: C:\OLD\MyDLL.dll
Image name: MyDLL.dll
Timestamp: Wed Jun 18 14:49:13 2008 (48591259)
[…]
0:000> lmv m MyDLL
start end module name
00000001`80000000 00000001`80011000 MyDLL
Image path: C:\2DLLs\DLL\MyDLL.dll
Image name: MyDLL.dll
Timestamp: Wed Jun 18 14:50:56 2008 (485912C0)
[...]
We can also see that the old version of MyDLL was the last loaded DLL:
0:000> !dlls -l
0x002c2680: C:\2DLLs\2DLLs.exe
Base 0x140000000 EntryPoint 0x1400013b0 Size 0x00010000
Flags 0x00004000 LoadCount 0x0000ffff TlsIndex 0x00000000
LDRP_ENTRY_PROCESSED
[...]
0x002ea9b0: C:\2DLLs\DLL\MyDLL.dll
Base 0x180000000 EntryPoint 0x1800013d0 Size 0x00011000
Flags 0x00084004 LoadCount 0x00000001 TlsIndex 0x00000000
LDRP_IMAGE_DLL
LDRP_ENTRY_PROCESSED
LDRP_PROCESS_ATTACH_CALLED
[...]
0x002ec430: C:\OLD\MyDLL.dll
Base 0×01e60000 EntryPoint 0×01e613e0 Size 0×00011000
Flags 0×00284004 LoadCount 0×00000001 TlsIndex 0×00000000
LDRP_IMAGE_DLL
LDRP_ENTRY_PROCESSED
LDRP_PROCESS_ATTACH_CALLED
LDRP_IMAGE_NOT_AT_BASE
We can also see that the PATH variable points to its location and this might explain why it was loaded:
0:000> !peb
PEB at 000007fffffd6000
[...]
Path=C:\OLD;C:\Windows\system32;C:\Windows;[…]
[…]
We might think that the module having address in its name was loaded the last but this is not true. If we save another copy of the dump from the existing one using .dump command and load the new dump file we would see that order of the module names is reversed:
0:000> kL
Child-SP RetAddr Call Site
00000000`0012fed8 00000001`40001093 MyDLL!fnMyDLL
00000000`0012fee0 00000001`40001344 2DLLs+0×1093
00000000`0012ff10 00000000`773acdcd 2DLLs+0×1344
00000000`0012ff60 00000000`774fc6e1 kernel32!BaseThreadInitThunk+0xd
00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d
0:000> lm
start end module name
00000000`01e60000 00000000`01e71000 MyDLL
00000000`772a0000 00000000`7736a000 user32
00000000`77370000 00000000`774a1000 kernel32
00000000`774b0000 00000000`7762a000 ntdll
00000001`40000000 00000001`40010000 2DLLs
00000001`80000000 00000001`80011000 MyDLL_180000000
000007fe`fc9e0000 000007fe`fca32000 uxtheme
000007fe`fe870000 000007fe`fe9a9000 rpcrt4
000007fe`fe9b0000 000007fe`fe9bc000 lpk
000007fe`fea10000 000007fe`feae8000 oleaut32
000007fe`fecd0000 000007fe`fed6a000 usp10
000007fe`fedd0000 000007fe`fefb0000 ole32
000007fe`fefb0000 000007fe`ff0af000 advapi32
000007fe`ff0d0000 000007fe`ff131000 gdi32
000007fe`ff2e0000 000007fe`ff381000 msvcrt
000007fe`ff390000 000007fe`ff3b8000 imm32
000007fe`ff4b0000 000007fe`ff5b4000 msctf
0:000> !dlls -l
[...]
0x002ec430: C:\OLD\MyDLL.dll
Base 0×01e60000 EntryPoint 0×01e613e0 Size 0×00011000
Flags 0×00284004 LoadCount 0×00000001 TlsIndex 0×00000000
LDRP_IMAGE_DLL
LDRP_ENTRY_PROCESSED
LDRP_PROCESS_ATTACH_CALLED
LDRP_IMAGE_NOT_AT_BASE
The postprocessed dump file can be downloaded from FTP to play with:
ftp://dumpanalysis.org/pub/CDAPatternDuplicatedModule.zip
- Dmitry Vostokov @ DumpAnalysis.org -
June 19th, 2008 at 5:20 pm
[…] Crash Dump Analysis Exploring Crash Dumps and Debugging Techniques on Windows Platforms « Crash Dump Analysis Patterns (Part 64) […]
February 17th, 2009 at 10:14 am
[…] Duplicated Module […]
February 28th, 2009 at 4:26 pm
> We can also see that the old version of MyDLL was the last loaded DLL
That statement contradicts the following output where it’s clear that the old DLL was loaded first:
0:000> lmv m MyDLL_1e60000
start end module name
00000000`01e60000 00000000`01e71000 MyDLL_1e60000
Loaded symbol image file: MyDLL.dll
Image path: C:\OLD\MyDLL.dll
Image name: MyDLL.dll
Timestamp: Wed Jun 18 14:49:13 2008 (48591259)
[…]
0:000> lmv m MyDLL
start end module name
00000001`80000000 00000001`80011000 MyDLL
Image path: C:\2DLLs\DLL\MyDLL.dll
Image name: MyDLL.dll
Timestamp: Wed Jun 18 14:50:56 2008 (485912C0)
[…]
March 1st, 2009 at 11:07 am
I don’t see contradiction here: Timestamp is for the link time not the load time and the loader is free to choose the base address. What do you think in the output contradicts that?
December 16th, 2009 at 3:44 pm
From the list of modules we are able to see two modules are duplicated. Is there any way to find out, who called the moduled to load into memory. I would like to see the calling function (the originator of duplication).
September 1st, 2010 at 2:59 pm
[…] I also thought that there was the same module loaded twice from different location like in Duplicated Module pattern. Unfortunately lm command didn’t show any duplicated loaded and unloaded modules as […]