Imaging loading callback behavior

NTDEV
1

I’m tracking loaded images via a PsLoadImage callback. I’m seeing a few odd behaviors that I’m hoping someone can help me understand. I’m doing my testing on a VM running Win 7 x64.

First, sometimes I’ll get multiple callbacks for the same image loading into the same PID from the same context. I have a global counter which increments for at callback so these identical loadings will occur one right after the other. The second issue is I’m seeing a few images being loaded but no trace of them when enumerating the process in Process Explorer. For example, I can run calc.exe and when most of the standard libraries have loaded it will show that slui.exe, sppuinotify.dll, and sppsvc.exe are loaded into the calc.exe process while running in the calc.exe context. Here is a snippet of my debug output that highlights the two issues (calc ProcessId = 2388).

Image Load: ‘\Windows\System32\sppuinotify.dll’, nameLen = 66, opCnt = 1232, PsGetCurrentProcessId = 2388, ProcessId = 2388
Image Load: ‘\Windows\System32\sppuinotify.dll’, nameLen = 66, opCnt = 1233, PsGetCurrentProcessId = 2388, ProcessId = 2388
Image Load: ‘\Windows\System32\slui.exe’, nameLen = 52, opCnt = 1234, PsGetCurrentProcessId = 2388, ProcessId = 2388
Image Load: ‘\Windows\System32\slui.exe’, nameLen = 52, opCnt = 1235, PsGetCurrentProcessId = 2388, ProcessId = 2388
Image Load: ‘\Windows\System32\sppsvc.exe’, nameLen = 56, opCnt = 1236, PsGetCurrentProcessId = 2388, ProcessId = 2388
Image Load: ‘\Windows\System32\sppsvc.exe’, nameLen = 56, opCnt = 1237, PsGetCurrentProcessId = 2388, ProcessId = 2388

Lastly, some libraries have slightly mangled names. By that I mean the last two characters will be repeated so "\Program Files\proc.exe’ will be ‘\Program Files\proc.exexe’

It’s frustrating because I’m just printing what is available in the callback but what I’m seeing does not match with what I understand about loading and what the callback is supposed to provide. Thanks.

2

On the mangled names how are you printing them, this looks like a trying to
use %ws on the UNICODE_STRING buffer problem. I’ve never seen the mangling.

Don Burn
Windows Driver Consulting
Website: http://www.windrvr.com

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of
xxxxx@gmail.com
Sent: Wednesday, December 31, 2014 1:23 PM
To: Windows System Software Devs Interest List
Subject: [ntdev] Imaging loading callback behavior

I’m tracking loaded images via a PsLoadImage callback. I’m seeing a few odd
behaviors that I’m hoping someone can help me understand. I’m doing my
testing on a VM running Win 7 x64.

First, sometimes I’ll get multiple callbacks for the same image loading into
the same PID from the same context. I have a global counter which
increments for at callback so these identical loadings will occur one right
after the other. The second issue is I’m seeing a few images being loaded
but no trace of them when enumerating the process in Process Explorer. For
example, I can run calc.exe and when most of the standard libraries have
loaded it will show that slui.exe, sppuinotify.dll, and sppsvc.exe are
loaded into the calc.exe process while running in the calc.exe context.
Here is a snippet of my debug output that highlights the two issues (calc
ProcessId = 2388).

Image Load: ‘\Windows\System32\sppuinotify.dll’, nameLen = 66, opCnt = 1232,
PsGetCurrentProcessId = 2388, ProcessId = 2388 Image Load:
‘\Windows\System32\sppuinotify.dll’, nameLen = 66, opCnt = 1233,
PsGetCurrentProcessId = 2388, ProcessId = 2388 Image Load:
‘\Windows\System32\slui.exe’, nameLen = 52, opCnt = 1234,
PsGetCurrentProcessId = 2388, ProcessId = 2388 Image Load:
‘\Windows\System32\slui.exe’, nameLen = 52, opCnt = 1235,
PsGetCurrentProcessId = 2388, ProcessId = 2388 Image Load:
‘\Windows\System32\sppsvc.exe’, nameLen = 56, opCnt = 1236,
PsGetCurrentProcessId = 2388, ProcessId = 2388 Image Load:
‘\Windows\System32\sppsvc.exe’, nameLen = 56, opCnt = 1237,
PsGetCurrentProcessId = 2388, ProcessId = 2388

Lastly, some libraries have slightly mangled names. By that I mean the last
two characters will be repeated so "\Program Files\proc.exe’ will be
‘\Program Files\proc.exexe’

It’s frustrating because I’m just printing what is available in the callback
but what I’m seeing does not match with what I understand about loading and
what the callback is supposed to provide. Thanks.

NTDEV is sponsored by OSR

Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev

OSR is HIRING!! See http://www.osr.com/careers

For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars

To unsubscribe, visit the List Server section of OSR Online at
http://www.osronline.com/page.cfm?name=ListServer

3

DbgPrintEx(DPFLTR_IHVDRIVER_ID, DPFLTR_INFO_LEVEL, “Image Load: ‘%wZ’, nameLen = %d, opCnt = %d, PsGetCurrentProcessId = %d, ProcessId = %d\n”, FullImageName, FullImageName->Length, opCnt, PsGetCurrentProcessId(), ProcessId);

4

The mangling doesn’t happen all the time. And it’s not just printing. When I copy the name and send it to UM for logging, the extra characters will be there as well.

I’ve seen it enough that I now have to do a loop in UM removing one character at a time until a call to “DoesFileExist” returns true.

5

After some digging into calc.exe and a few other programs, I figured out the “duplicates” issue.

Turns out they are getting the version of these particular files (slui.exe, sppuinotify.dll, and sppsvc.exe) with calls to Version!GetFileVersionInfoSizeExW and Version!GetFileVersionInfoExW both of which call LoadLibrary and then FreeLibrary. Ipso-facto, two back-to-back library loads. It’d be nice if the Image Callback routine had an unload flag. So that solves the first two issues (and I probably should have done the disassembly before posting) however I am still stuck on the mangled file names.

6

Hello Paul,

According to your mangled names.
Isn’t it misinterpretation of UNICODE_STRING structure buffer?
I think Buffer field in UNICODE_STRING doesn’t necessarily be null terminated, so maybe just check length field.

Best regards.

7

Thanks for the reply xdc, but if it was a length issue with my copying/printing then I’m assuming I’d see this a lot more often often. And as you can see from my debug printout, I print the Length field just so I can manually count the characters to verify.

I put a break point on Kernel!LoadLibraryW and can see that the name is legit. I haven’t traced it all the way through the kernel yet but when I examine the FILE_OBJECT in the ImageCallback, the name there is mangled (and the Length value includes the 2 extra characters). So somewhere along the way in kernel space, something seems to be happening to the filename.