Supporting dynamic Malware Analysis with WinHttp library debug logs (tracing)

Posted on by

Dynamic Malware Analysis is a tricky business. If you don’t use a dedicated sandbox, or an API monitor, it’s often hard to say what’s going on under the hood. Relying on differential analysis may not be enough and having multiple ways to get more information out of the session is always welcome. Process Monitor, DebugView, Performance/EWT logging, etc. are really handy as a support for black-box analysis, and so it is (or may be) enabling of the NtGlobalFlag. In this post I will describe one more hidden flag that can help to trace what’s going on when malware runs.

It turns out that WinHttp library has a built in debugging/tracing mechanism that enables it to log a lot of interesting details and send it either to a file, or directly to a debugger (or both). Lo and behold – it actually has a built-in API monitoring for us! It would be handy if this feature could become an integral part of popular debuggers (or a OllyDbg/Xdbg plug-in).

To enable the logging, you can either add the tracing options directly to Registry under the following key:

  • HKLM\SOFTWARE\Microsoft\Windows\
    CurrentVersion\Internet Settings\WinHttp\Tracing

f.ex. by using a reg file:

Windows Registry Editor Version 5.00

[HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\Internet Settings\WinHttp\Tracing]
"Enabled"=dword:00000001
"LogFilePrefix"="winhttp"
"ToFileOrDebugger"=dword:00000000
"ShowBytes"=dword:00000001
"ShowApiTrace"=dword:00000001
"MaxFileSize"=dword:01312d00

or use a winhttptracecfg tool which is a part of Windows Server 2003 Resource Kit Tools.

The tool is handy, and we can run it like this:

  • winhttptracecfg -l winhttp -e 1 -d 0 -s 1 -t 1 -m 20000000

Running the tool gives us the following output:

The meaning of the options is as follows:

  • -e : 1: enable tracing; 0: disable tracing
  • -l : [trace-file-prefix], i.e., “C:\Temp\Test3”; or simply: “Test3”
  • -d : 0: output to file; 1: output to debugger; 2: output to both
  • -s : 0: show HTTP headers only; 1: ANSI output; 2: Hex output  (note, this doesn’t seem to work on newer versions of Windows)
  • -t : 1: enable top-level API traces; 0: disable top-level API traces
  • -m : Maximum size the trace file can grow to

and in our case:

  • -e 1 –> TracingEnabled: 1  –> enable tracing
  • -d 0 –> ToFileOrDebugger: 0 –> save to file only
  • -s 1 –> ShowBytes: 1 –> show ANSI output (test on Windows XP)
  • -t 1 –> ShowApiTrace: 1  –> enables API monitoring
  • -m 20000000 –> MaxFileSize: 20000000 –> file should be large enough
  • -l winhttp –> FileNamePrefix: winhttp –> prefix used for a file name

Let’s run a test.

One tool that uses WinHttp library is Autoruns. When you launch it with the tracing enabled you should see a log file immediately or almost immediately created f.ex.:

  • winhttp-autoruns.exe-4020.22.11.42.035-12.15.2016.LOG

where ‘winhttp’ is a prefix we provided in the tracing options, followed by the process name ‘autoruns.exe’, then 4020 which is a PID of the process, then time and date.

The example content looks as below, note that:

  • API calls and their parameters are clearly visible
  • Return values are provided
  • Lots of internal state-related debug info is also provided

(If you don’t see the .log file, check the file / process with VirusTotal)

22:11:42.035 ::>>>> WinHttp Version 6.0 Build 6.1.7601 >>>>Process autoruns.exe [4020 (0xfb4)] started at 22:11:42.035 12/15/2016
22:11:42.035 ::WinHttpOpen("Microsoft-CryptoAPI/6.1", WINHTTP_ACCESS_TYPE_DEFAULT_PROXY (0), "", "", 0x0)
22:11:42.035 ::winhttp-dll added a reference to winhttp.dll (via LoadLibrary() call)
22:11:42.035 ::thread-pool created
22:11:42.035 ::thread pool initialized successfully
22:11:42.035 ::_SvcsStartup() succeeded; async-count = 1
22:11:42.035 ::WinHttpOpen() returning handle 0x38fcb98
22:11:42.035 ::WinHttpSetTimeouts(0x38fcb98, 0, 60000, 60000, 60000)
...
22:15:26.005 ::WinHttpOpen() returning handle 0x39ef730
22:15:26.005 ::WinHttpConnect(0x39ef730, "www.virustotal.com", 443, 0x0)
22:15:26.005 ::Indicate Status 0x39efad0, 0x0, WINHTTP_CALLBACK_STATUS_HANDLE_CREATED (1024), 0x12edd4 [0x39efad0], 4
22:15:26.005 ::WinHttpConnect() returning handle 0x39efad0
22:15:27.066 ::WinHttpOpenRequest(0x39efad0, "POST", "/partners/sysinternals/file-reports?apikey=4e3202fdbe953d628f650229af5b3eb49cd46", "", "", 0x0, 0x00800000)
22:15:27.066 ::Indicate Status 0x395ebe8, 0x0, WINHTTP_CALLBACK_STATUS_HANDLE_CREATED (1024), 0x2cefc84 [0x395ebe8], 4
22:15:27.066 ::WinHttpCreateUrl(0x2cefc20, 0x0, 0x0, 0x2cefc70)
22:15:27.066 ::    WinHttpCreateUrl(); URL = (null), URL Length = 0
22:15:27.066 ::    WinHttpCreateUrl: error 122 [ERROR_INSUFFICIENT_BUFFER]
22:15:27.066 ::WinHttpCreateUrl() returning FALSE
22:15:27.066 ::WinHttpCreateUrl(0x2cefc20, 0x0, 0x2af5b8, 0x2cefc70)
22:15:27.066 ::    WinHttpCreateUrl(); URL = https://www.virustotal.com/partners/sysinternals/file-reports?apikey=4e3202fdbe9, URL Length = 133
22:15:27.066 ::WinHttpCreateUrl() returning TRUE
22:15:27.066 ::WinHttpOpenRequest() returning handle 0x395ebe8
22:15:27.066 ::WinHttpGetProxyForUrl(0x39ef730, "https://www.virustotal.com", 0x2cefd9c, 0x2cefdb4)

On XP, the ShowBytes enables inclusions of the additional data dumps for headers f.ex.:

11:51:55.106 ::*0000001* :: sending data:
11:51:55.106 ::*0000001* :: 177 (0xb1) bytes
11:51:55.106 ::*0000001* :: <<<<-------- HTTP stream follows below ----------------------------------------------->>>>
11:51:55.106 ::*0000001* :: GET /wpad.dat HTTP/1.1
11:51:55.106 ::*0000001* :: Accept: */*
11:51:55.106 ::*0000001* :: User-Agent: Mozilla/4.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0; .NET5.0C; .NET5.0E)
11:51:55.106 ::*0000001* :: Host: 127.0.0.1
11:51:55.106 ::*0000001* :: Connection: Keep-Alive
11:51:55.122 ::*0000001* :: 
11:51:55.122 ::*0000001* :: 
11:51:55.122 ::*0000001* :: <<<<-------- End ----------------------------------------------->>>>
11:51:55.122 ::*0000001* :: WinHttpSendRequest() returning TRUE
11:51:55.122 ::*0000001* :: WinHttpReceiveResponse(0xaf2000, 0x0)
11:51:55.122 ::*0000001* :: received data:
11:51:55.122 ::*0000001* :: 67 (0x43) bytes
11:51:55.122 ::*0000001* :: <<<<-------- HTTP stream follows below ----------------------------------------------->>>>
11:51:55.122 ::*0000001* :: HTTP/1.1 200 OK
11:51:55.122 ::*0000001* :: Content-Length: 59745
11:51:55.122 ::*0000001* :: Content-Type: text/html
11:51:55.122 ::*0000001* :: 
11:51:55.122 ::*0000001* :: 
11:51:55.122 ::*0000001* :: <<<<-------- End ----------------------------------------------->>>>