Monthly Archives: March 2013

Enhanced Windows logs example


I came across a software installation that I thought would make a great example case of how valuable enhanced Windows logs are. This software is not necessarily malicious, but exhibits behavior that caught the attention of my team.

The logs below are from WLS, a logging tool created to add contextual data to Windows process execution logs and log other relevant system information.

We’ll start with the launch of the process itself. Since process auditing is on, Windows will log this for us. Internet Explorer creates a process named “Productivity_3.1_B[1].exe”, which is “Productivity_3.1_B Toolbar” by “Conduit” and is tagged as recently downloaded and zone 3 (Internet).

2013-03-05T06:22:16-06:00 [host] Security: LogType=”WLS”, BaseFileName=”Productivity_3.1_B[1].exe”, CommandLine=”‘C:\Documents and Settings\[user]\Local Settings\Temporary Internet Files\Content.IE5\96RZWQUR\Productivity_3.1_B[1].exe'”, CompanyName=”Conduit”, CreatorProcessName=”iexplore”, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304892″, FileDescription=”Productivity_3.1_B Toolbar”, FileVersion=”6.10.3.27″, ImageFileName=”C:\Documents and Settings\[user]\Local Settings\Temporary Internet Files\Content.IE5\96RZWQUR\Productivity_3.1_B[1].exe”, Language=”Language Neutral”, Length=”1989472″, LogonID=”(0x0,0x47F98236)”, MD5=”F2AF78F217AD0E8A3BC0C712BCAD2C34″, NewHash=”True”, NewProcessId=”5308″, ProcessId=”4944″, Recent=”True”, SHA1=”F437FAD1624DD651F523FCA1D6A2C79F25847DD1″, Signed=”True”, UserName=”[user]”, ValidSignatureDate=”True”, Zone=”3″

Internet Explorer loads the “Microsoft COM Runtime Execution Engine”

2013-03-05T06:22:24-06:00 [host] ModuleMonitor: LogType=”WLS”, BaseFileName=”corpol.dll”, ChangeType=”Added”, CompanyName=”Microsoft Corporation”, WLSKey=”10647″, FileDescription=”Microsoft COM Runtime Execution Engine”, FileName=”c:\windows\system32\corpol.dll”, FileVersion=”2008.0.0.18702 (longhorn_ie8_rtm(wmbla).090308-0339)”, InternalName=”CORPOL.DLL”, Language=”English (United States)”, Length=”18944″, MD5=”8FCF03E4D7BE9B5587CCF11719959006″, NewHash=”True”, Process=”iexplore”, ProductVersion=”2008.0.0.18702″, SHA1=”281DF80AF9C7625586341E966467A752C9D466C3″, Zone=”0″

Productivity_3.1_B[1] loads nsdialogs.dll

2013-03-05T06:22:24-06:00 [host] ModuleMonitor: LogType=”WLS”, BaseFileName=”nsdialogs.dll”, ChangeType=”Added”, WLSKey=”10646″, FileName=”c:\docume~1\[user]\locals~1\temp\nsc431e.tmp\nsdialogs.dll”, Length=”9728″, MD5=”F7B92B78F1A00A872C8A38F40AFA7D65″, NewHash=”True”, Process=”Productivity_3.1_B[1]”, SHA1=”872522498F69AD49270190C74CF3AF28862057F2″, Zone=”0″

Productivity_3.1_B[1] loads the “Conduit Toolbar” dll

2013-03-05T06:22:24-06:00 [host] ModuleMonitor: LogType=”WLS”, BaseFileName=”nso431f.tmp.tbprod.dll”, ChangeType=”Added”, CompanyName=”Conduit Ltd.”, WLSKey=”10645″, FileDescription=”Conduit Toolbar”, FileName=”c:\docume~1\[user]\locals~1\temp\nso431f.tmp.tbprod.dll”, FileVersion=”6.10.3.27″, InternalName=”Conduit Toolbar”, Language=”English (United States)”, Length=”4495624″, MD5=”CEF32B574F8C732BACAFD93210642DBB”, NewHash=”True”, Process=”Productivity_3.1_B[1]”, ProductVersion=”6.10.3.27″, SHA1=”5C684D51F07A183EEA13D66F5C7E9630C48D93B5″, Zone=”0″

Productivity_3.1_B[1] loads system.dll

2013-03-05T06:22:24-06:00 [host] ModuleMonitor: LogType=”WLS”, BaseFileName=”system.dll”, ChangeType=”Added”, WLSKey=”10644″, FileName=”c:\docume~1\[user]\locals~1\temp\nsc431e.tmp\system.dll”, Length=”11264″, MD5=”959EA64598B9A3E494C00E8FA793BE7E”, NewHash=”True”, Process=”Productivity_3.1_B[1]”, SHA1=”40F284A3B92C2F04B1038DEF79579D4B3D066EE0″, Zone=”0″

Productivity_3.1_B[1] launches tbProd.dll via rundll32 with parameters “DllHandleUserID”

2013-03-05T06:22:37-06:00 [host] Security: LogType=”WLS”, BaseFileName=”rundll32.exe”, CommandLine=”rundll32 ‘C:\Program Files\Productivity_3.1_B\tbProd.dll’ DllHandleUserID”, CompanyName=”Microsoft Corporation”, CreatorProcessName=”Productivity_3.1_B[1]”, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304893″, FileDescription=”Run a DLL as an App”, FileVersion=”5.1.2600.5512 (xpsp.080413-2105)”, ImageFileName=”C:\WINDOWS\system32\rundll32.exe”, InternalName=”rundll”, Language=”English (United States)”, Length=”33280″, LogonID=”(0x0,0x47F98236)”, MD5=”037B1E7798960E0420003D05BB577EE6″, NewProcessId=”2000″, ProcessId=”5308″, ProductVersion=”5.1.2600.5512″,  SHA1=”303A90020BF3BEAF9ACD0EA86487C853636A99A3″, Signed=”False”, UserName=”[user]”, Zone=”0″

Rundll32 completes

2013-03-05T06:22:40-06:00 [host] Security: LogType=”WLS”, BaseFileName=”rundll32.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304894″, ImageFileName=”C:\WINDOWS\system32\rundll32.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”2000″, UserName=”[user]”

Productivity_3.1_B[1] launches tbProd.dll via rundll32 with parameters “DllSendInstallationUsage New Installation”

2013-03-05T06:22:43-06:00 [host] Security: LogType=”WLS”, BaseFileName=”rundll32.exe”, Cached=”True”, CommandLine=”rundll32 ‘C:\Program Files\Productivity_3.1_B\tbProd.dll’ DllSendInstallationUsage New Installation”, CompanyName=”Microsoft Corporation”, CreatorProcessName=”Productivity_3.1_B[1]”, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304895″, FileDescription=”Run a DLL as an App”, FileVersion=”5.1.2600.5512 (xpsp.080413-2105)”, ImageFileName=”C:\WINDOWS\system32\rundll32.exe”, InternalName=”rundll”, Language=”English (United States)”, Length=”33280″, LogonID=”(0x0,0x47F98236)”, MD5=”037B1E7798960E0420003D05BB577EE6″, NewProcessId=”2672″, ProcessId=”5308″, ProductVersion=”5.1.2600.5512″,  SHA1=”303A90020BF3BEAF9ACD0EA86487C853636A99A3″, Signed=”False”, UserName=”[user]”, Zone=”0″

Productivity_3.1_B[1] launches tbProd.dll via rundll32 with parameters “DllRunIEMediumIntegrity”

2013-03-05T06:22:44-06:00 [host] Security: LogType=”WLS”, BaseFileName=”rundll32.exe”, Cached=”True”, CommandLine=”rundll32 ‘C:\Program Files\Productivity_3.1_B\tbProd.dll’ DllRunIEMediumIntegrity”, CompanyName=”Microsoft Corporation”, CreatorProcessName=”Productivity_3.1_B[1]”, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304896″, FileDescription=”Run a DLL as an App”, FileVersion=”5.1.2600.5512 (xpsp.080413-2105)”, ImageFileName=”C:\WINDOWS\system32\rundll32.exe”, InternalName=”rundll”, Language=”English (United States)”, Length=”33280″, LogonID=”(0x0,0x47F98236)”, MD5=”037B1E7798960E0420003D05BB577EE6″, NewProcessId=”5592″, ProcessId=”5308″, ProductVersion=”5.1.2600.5512″, SHA1=”303A90020BF3BEAF9ACD0EA86487C853636A99A3″, Signed=”False”, UserName=”[user]”, Zone=”0″

Productivity_3.1_B[1].exe terminates

2013-03-05T06:22:45-06:00 [host] Security: LogType=”WLS”, BaseFileName=”Productivity_3.1_B[1].exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304897″, ImageFileName=”C:\Documents and Settings\[user]\Local Settings\Temporary Internet Files\Content.IE5\96RZWQUR\Productivity_3.1_B[1].exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”5308″, UserName=”[user]”

The last rundll process starts IE with parameters “hxxp://Productivity31B.OurToolbar[.]com/SetupFinish” (neutralized to avoid accidental clicks)

2013-03-05T06:22:47-06:00 [host] Security: LogType=”WLS”, BaseFileName=”iexplore.exe”, Cached=”True”, CommandLine=”‘C:\Program Files\Internet Explorer\IEXPLORE.EXE’ hxxp://Productivity31B.OurToolbar[.]com/SetupFinish”, CompanyName=”Microsoft Corporation”, CreatorProcessName=”rundll32″, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304898″, FileDescription=”Internet Explorer”, FileVersion=”8.00.6001.18702 (longhorn_ie8_rtm(wmbla).090308-0339)”, ImageFileName=”C:\Program Files\Internet Explorer\iexplore.exe”, InternalName=”iexplore”, Language=”English (United States)”, Length=”638816″, LogonID=”(0x0,0x47F98236)”, MD5=”B60DDDD2D63CE41CB8C487FCFBB6419E”, NewProcessId=”4260″, ProcessId=”5592″, ProductVersion=”8.00.6001.18702″,  SHA1=”EADCE51C88C8261852C1903399DDE742FBA2061B”, Signed=”True”, UserName=”[user]”, ValidSignatureDate=”False”, Zone=”0″

Conduit creates a mutex

2013-03-05T06:22:48-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10650″, Name=”\BaseNamedObjects\CONDUIT_SHARED_MUTEX”, Type=”Mutant”

Rundll32 loads the “Conduit Toolbar” dll (this probably happened before the mutex above was created, time stamps are based on when the polling routine completes)

2013-03-05T06:22:49-06:00 [host] ModuleMonitor: LogType=”WLS”, BaseFileName=”tbprod.dll”, ChangeType=”Added”, CompanyName=”Conduit Ltd.”, WLSKey=”10652″, FileDescription=”Conduit Toolbar”, FileName=”c:\program files\productivity_3.1_b\tbprod.dll”, FileVersion=”6.10.3.27″, InternalName=”Conduit Toolbar”, Language=”English (United States)”, Length=”4495624″, MD5=”CEF32B574F8C732BACAFD93210642DBB”, NewHash=”True”, Process=”rundll32″, ProductVersion=”6.10.3.27″, SHA1=”5C684D51F07A183EEA13D66F5C7E9630C48D93B5″, Zone=”0″

IE launches another instance of itself

2013-03-05T06:22:50-06:00 [host] Security: LogType=”WLS”, BaseFileName=”iexplore.exe”, Cached=”True”, CommandLine=”‘C:\Program Files\Internet Explorer\IEXPLORE.EXE’ SCODEF:4260 CREDAT:79873″, CompanyName=”Microsoft Corporation”, CreatorProcessName=”iexplore”, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304899″, FileDescription=”Internet Explorer”, FileVersion=”8.00.6001.18702 (longhorn_ie8_rtm(wmbla).090308-0339)”, ImageFileName=”C:\Program Files\Internet Explorer\iexplore.exe”, InternalName=”iexplore”, Language=”English (United States)”, Length=”638816″, LogonID=”(0x0,0x47F98236)”, MD5=”B60DDDD2D63CE41CB8C487FCFBB6419E”, NewProcessId=”6076″, ProcessId=”4260″, ProductVersion=”8.00.6001.18702″,  SHA1=”EADCE51C88C8261852C1903399DDE742FBA2061B”, Signed=”True”, UserName=”[user]”, ValidSignatureDate=”False”, Zone=”0″

Rundll32 terminates

2013-03-05T06:22:51-06:00 [host] Security: LogType=”WLS”, BaseFileName=”rundll32.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304900″, ImageFileName=”C:\WINDOWS\system32\rundll32.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”5592″, UserName=”[user]”

IE loads it’s normal mutexes and semaphores

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10653″, Name=”\BaseNamedObjects\OleDfRoot0613563FD”, Type=”Semaphore”

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10654″, Name=”\BaseNamedObjects\ConnHashTable<4260>_HashTable_Mutex”, Type=”Mutant”

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10655″, Name=”\BaseNamedObjects\IEFrame!GetAsyncKeyStateQuery!4260″, Type=”Semaphore”

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10656″, Name=”\BaseNamedObjects\RSS Eventing Connection Database Mutex 000010a4″, Type=”Mutant”

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10657″, Name=”\BaseNamedObjects\MSCTF.Shared.MUTEX.EGG”, Type=”Mutant”

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10658″, Name=”\BaseNamedObjects\IEFrame!GetAsyncKeyStateReply!4260″, Type=”Semaphore”

2013-03-05T06:22:53-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10659″, Name=”\BaseNamedObjects\OleDfRoot061353668″, Type=”Semaphore”

IE loads Productivity_3.1_BToolbarHelper.exe with parameters “…DllCleanEnableExtensionDoing”

2013-03-05T06:23:00-06:00 [host] Security: LogType=”WLS”, BaseFileName=”Productivity_3.1_BToolbarHelper.exe”, CommandLine=”‘C:\Program Files\Productivity_3.1_B\Productivity_3.1_BToolbarHelper.exe’ DllRun ‘C:\Documents and Settings\[user]\Local Settings\Application Data\Productivity_3.1_B\tbProd.dll’ DllCleanEnableExtensionDoing”, CreatorProcessName=”iexplore”Domain=”[domain]”, EventID=”592″, EventRecordID=”5304902″, FileDescription=”ToolbarH Application”, FileVersion=”1, 0, 1, 0″, ImageFileName=”C:\Program Files\Productivity_3.1_B\Productivity_3.1_BToolbarHelper.exe”, InternalName=”ToolbarH”, Language=”English (United States)”, Length=”65832″, LogonID=”(0x0,0x47F98236)”, MD5=”DA11D78D765E4B8FA4CFA5A37E8A94FF”, NewHash=”True”, NewProcessId=”5704″, ProcessId=”6076″, ProductVersion=”1, 0, 1, 0″, Recent=”True”, SHA1=”E5AD99CE7C7362CA566156033ECB0F04F9437CA7″, Signed=”True”, UserName=”[user]”, ValidSignatureDate=”True”, Zone=”0″

IE loads Productivity_3.1_BToolbarHelper.exe with different parameters “…DllConnectToIE”

2013-03-05T06:23:00-06:00 [host] Security: LogType=”WLS”, BaseFileName=”Productivity_3.1_BToolbarHelper.exe”, CommandLine=”‘C:\Program Files\Productivity_3.1_B\Productivity_3.1_BToolbarHelper.exe’ DllRun ‘C:\Documents and Settings\[user]\Local Settings\Application Data\Productivity_3.1_B\tbProd.dll’ DllConnectToIE”,  CreatorProcessName=”iexplore”Domain=”[domain]”, EventID=”592″, EventRecordID=”5304903″, FileDescription=”ToolbarH Application”, FileVersion=”1, 0, 1, 0″, ImageFileName=”C:\Program Files\Productivity_3.1_B\Productivity_3.1_BToolbarHelper.exe”, InternalName=”ToolbarH”, Language=”English (United States)”, Length=”65832″, LogonID=”(0x0,0x47F98236)”, MD5=”DA11D78D765E4B8FA4CFA5A37E8A94FF”, NewHash=”True”, NewProcessId=”5976″, ProcessId=”6076″, ProductVersion=”1, 0, 1, 0″, Recent=”True”, SHA1=”E5AD99CE7C7362CA566156033ECB0F04F9437CA7″, Signed=”True”, UserName=”[user]”, ValidSignatureDate=”True”, Zone=”0″

Rundll terminates

2013-03-05T06:23:01-06:00 [host] Security: LogType=”WLS”, BaseFileName=”rundll32.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304904″, ImageFileName=”C:\WINDOWS\system32\rundll32.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”2672″, UserName=”[user]”

Conduit creates a mutex for the IE hook containing the process id of the second IE instance

2013-03-05T06:23:03-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10660″, Name=”\BaseNamedObjects\InitIEMenuHooks_Mutex_6076″, Type=”Mutant”

Conduit creates a mutex for their “gadgets”

2013-03-05T06:23:03-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10661″, Name=”\BaseNamedObjects\ConduitGadgetsMgrMutex_CT3282120″, Type=”Mutant”

A semaphore is created

2013-03-05T06:23:03-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10662″, Name=”\BaseNamedObjects\EI_LOGIC_SEMAPHORE”, Type=”Semaphore”

A mutex is created indicating activity with the first IE instance

2013-03-05T06:23:03-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10665″, Name=”\BaseNamedObjects\TryToInjectToIe4260″, Type=”Mutant”

Another mutex indicating an API hook with the second IE instance (with a typo?)

2013-03-05T06:23:03-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10666″, Name=”\BaseNamedObjects\API_HOOK_MUTES_6076″, Type=”Mutant”

Conduit creates and deletes a named pipe (I think IE was starting to shutdown just after the pipe was created)

2013-03-05T06:23:04-06:00 [host] NamedPipeMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10667″, Name=”GadgetsManagerPipeServerCT3282120″

2013-03-05T06:23:07-06:00 [host] NamedPipeMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10668″, Name=”GadgetsManagerPipeServerCT3282120″

The second IE instance terminates

2013-03-05T06:23:07-06:00 [host] Security: LogType=”WLS”, BaseFileName=”iexplore.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304905″, ImageFileName=”C:\Program Files\Internet Explorer\iexplore.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”6076″, UserName=”[user]”

The first IE instance terminates

2013-03-05T06:23:07-06:00 [host] Security: LogType=”WLS”, BaseFileName=”iexplore.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304906″, ImageFileName=”C:\Program Files\Internet Explorer\iexplore.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”4260″, UserName=”[user]”

Conduit loads another dll (again, this probably happened just before IE terminated)

2013-03-05T06:23:08-06:00 [host] ModuleMonitor: LogType=”WLS”, BaseFileName=”tbprod.dll”, ChangeType=”Added”, CompanyName=”Conduit Ltd.”, WLSKey=”10669″, FileDescription=”Conduit Toolbar”, FileName=”c:\documents and settings\[user]\local settings\application data\productivity_3.1_b\tbprod.dll”, FileVersion=”6.10.3.27″, InternalName=”Conduit Toolbar”, Language=”English (United States)”, Length=”4495624″, MD5=”CEF32B574F8C732BACAFD93210642DBB”, Process=”Productivity_3.1_BToolbarHelper”, ProductVersion=”6.10.3.27″, SHA1=”5C684D51F07A183EEA13D66F5C7E9630C48D93B5″, Zone=”0″

One Productivity_3.1_BToolbarHelper.exe terminates

2013-03-05T06:23:10-06:00 [host] Security: LogType=”WLS”, BaseFileName=”Productivity_3.1_BToolbarHelper.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304907″, ImageFileName=”C:\Program Files\Productivity_3.1_B\Productivity_3.1_BToolbarHelper.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”5704″, UserName=”[user]”

The other Productivity_3.1_BToolbarHelper.exe terminates

2013-03-05T06:23:10-06:00 [host] Security: LogType=”WLS”, BaseFileName=”Productivity_3.1_BToolbarHelper.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304908″, ImageFileName=”C:\Program Files\Productivity_3.1_B\Productivity_3.1_BToolbarHelper.exe”, LogonID=”(0x0,0x47F98236)”, ProcessId=”5976″, UserName=”[user]”

The mutexes and semaphores get cleaned up

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10670″, Name=”\BaseNamedObjects\CONDUIT_SHARED_MUTEX”, Type=”Mutant”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10671″, Name=”\BaseNamedObjects\OleDfRoot0613563FD”, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10672″, Name=”\BaseNamedObjects\ConnHashTable<4260>_HashTable_Mutex”, Type=”Mutant”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10673″, Name=”\BaseNamedObjects\IEFrame!GetAsyncKeyStateQuery!4260″, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10674″, Name=”\BaseNamedObjects\RSS Eventing Connection Database Mutex 000010a4″, Type=”Mutant”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10675″, Name=”\BaseNamedObjects\IEFrame!GetAsyncKeyStateReply!4260″, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10676″, Name=”\BaseNamedObjects\OleDfRoot061353668″, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10677″, Name=”\BaseNamedObjects\InitIEMenuHooks_Mutex_6076″, Type=”Mutant”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10678″, Name=”\BaseNamedObjects\ConduitGadgetsMgrMutex_CT3282120″, Type=”Mutant”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10679″, Name=”\BaseNamedObjects\EI_LOGIC_SEMAPHORE”, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10680″, Name=”\BaseNamedObjects\OleDfRoot061365026″, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10681″, Name=”\BaseNamedObjects\OleDfRoot061364E1D”, Type=”Semaphore”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10682″, Name=”\BaseNamedObjects\TryToInjectToIe4260″, Type=”Mutant”

2013-03-05T06:23:12-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Deleted”, WLSKey=”10683″, Name=”\BaseNamedObjects\API_HOOK_MUTES_6076″, Type=”Mutant”

Symantec runs… coincidence?

2013-03-05T06:23:49-06:00 [host] Security: LogType=”WLS”, BaseFileName=”SescLU.exe”, Cached=”True”, CompanyName=”Symantec Corporation”, CreatorProcessName=”svchost”, Domain=”[domain]”, EventID=”592″, EventRecordID=”5304909″, FileDescription=”Symantec Endpoint Security Client LiveUpdate”, FileVersion=”11.0.7200.157″, ImageFileName=”C:\Program Files\Symantec\Symantec Endpoint Protection\SescLU.exe”, InternalName=”SescLu”, Language=”English (United States)”, Length=”435616″, LogonID=”(0x0,0x3E7)”, MD5=”599B2D850C96B525845FA50457F0DD6E”, NewProcessId=”5348″, ProcessId=”1148″, ProductVersion=”11.0.7200.157″,  SHA1=”473CECF52718C5EC46D1EF01D2AEB90A3CB6A127″, Signed=”True”, UserName=”[host]$”, ValidSignatureDate=”True”, Zone=”0″

2013-03-05T06:23:49-06:00 [host] Security: LogType=”WLS”, Domain=”[domain]”, Domain1=”[domain]”, EventID=”600″, EventRecordID=”5304910″, ImageFileName=”C:\WINDOWS\system32\svchost.exe”, ImageFileName1=”C:\Program Files\Symantec\Symantec Endpoint Protection\SescLU.exe”, LogonID=”(0x0,0x3E7)”, LogonID1=”(0x0,0x3E7)”, ProcessId=”1148″, ProcessId1=”5348″, UserName=”[host]$”, UserName1=”[host]$”

2013-03-05T06:23:50-06:00 [host] WinObjectMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10684″, Name=”\BaseNamedObjects\SESCLU.EXE'”, Type=”Mutant”

2013-03-05T06:23:58-06:00 [host] Security: LogType=”WLS”, BaseFileName=”SescLU.exe”, Domain=”[domain]”, EventID=”593″, EventRecordID=”5304911″, ImageFileName=”C:\Program Files\Symantec\Symantec Endpoint Protection\SescLU.exe”, LogonID=”(0x0,0x3E7)”, ProcessId=”5348″, UserName=”[host]$”

Now, I know this in no way replaces traditional static or dynamic analysis, but it’s a great way to quickly assess a host and gather potential indicators; and you can search all your other host logs for the same activity. If you’d like more information on WLS, send me a note via the contact form.

Detecting malware with your proxy logs


If you use a web proxy that has categorization built-in and you log the requests to your central log system, you can add another layer of detection by alerting on multiple requests for a known malicious destination from a single source. Even though malware can come from almost any site or email, the call “home” is often to a site that is reused. This detection method caught a few infections that were not detected by anti-virus in the last month.

For this example Splunk is used to search BlueCoat logs. We’ll look for categories that indicate malicious sites and count them by user, host, and referrer. The site categories and count thresholds should be tuned to fit your needs.

index=proxy host=bluecoat “Malicious Sources” OR “Malicious Outbound Data” OR “Botnets” | stats count by cs_username, cs_host, cs_Referrer | where count > 1 | table cs_username, cs_host, cs_Referrer, count

Most of the time the results are probably benign, but it should be easy to spot when it hits. These were all for the same user, also note the blank referrer.

proxy

Schedule this to run periodically and let your logs tell you when there’s a potential infection.

Have your IOCs come to you


So, you’ve got the latest list of IOCs from a recent APT / malware report, time to kick off the scanner(s) / agent(s) of you choice and wait for the results. Wouldn’t it be nice to do a quick search of your logs and have the answer in seconds?  You’re already collecting logs from your Windows hosts (right?), shouldn’t they be doing more for you than providing logs?

Windows logging tools seem to have been stuck for a while at providing just the logs. The Splunk Universal Forwarder is an excellent example of a free, modern logging tool that does more than logs, and works with more than the Splunk server (hint hint); but even it does not provide what I believe is necessary data to support cyber security, forensics, and incident response.

Why not collect process hashes, named pipes, mutexes, semaphores, loaded modules, etc., and send them with the logs? Why not have these in real-time and be able to search your entire enterprise in seconds? There are plenty of server-side tools to collect, parse, and index  all of your logs; hosted on or off-site, free or pay. So, why not? You could know within minutes every new binary that is executed, including it’s metadata. You could know the initial infection vector, have the IOCs immediately, search all your hosts simultaneously, and that’s just the beginning!

Not finding a tool (at the time) that did what I wanted, I created WLS to provide exactly that; logs and the extra data to support answers I needed. There may be other programs that do this now (I’d love to know!), and I hope that others find this data as useful as I do.

Here are some WLS logs that answer example questions:

What did Firefox launch today that was downloaded from the internet?

Mar 15 09:05:24 [host] Security: LogType=”WLS”, BaseFileName=”Firefox Setup 19.0.2.exe”, Channel=”Security”, CommandLine=”‘C:\Users\Jason\Downloads\Firefox Setup 19.0.2.exe'”, CompanyName=”Mozilla”, Computer=”[host]”, CreatorProcessName=”firefox”, EventID=”4688″, EventRecordID=”65653″, ExecutionProcessID=”4″, ExecutionThreadID=”68″, FileDescription=”Firefox”, FileVersion=”4.42″, InternalName=”7zS.sfx”, Keywords=”0x8020000000000000″, Language=”English (United States)”, Length=”20564720″, Level=”0″, MD5=”68266231DF9FAF07018BAD5E028BDE67″, NewHash=”True”, NewProcessId=”0x1744″, NewProcessName=”C:\Users\Jason\Downloads\Firefox Setup 19.0.2.exe”, Opcode=”0″, ProcessId=”0xd58″, ProductVersion=”4.42″, ProviderGuid=”{54849625-5478-4994-A5BA-3E3B0328C30D}”, ProviderName=”Microsoft-Windows-Security-Auditing”, Recent=”True”, SHA1=”D0B0B20F1365BCDE53067012FFDAD23B52688028″, Signed=”True”, SubjectDomainName=”[host]”, SubjectLogonId=”0x25e5350″, SubjectUserName=”Jason”, SubjectUserSid=”[sid]”, Task=”13312″, TokenElevationType=”%%1938″, ValidSignatureDate=”True”, Version=”0″, Zone=”3″

Has a process with the  MD5 of 626A24ED1228580B9518C01930936DF9 executed?

Mar 22 19:29:00 [host] Security: LogType=”WLS”, BaseFileName=”GoogleUpdate.exe”, Cached=”True”, Channel=”Security”, CompanyName=”Google Inc.”, Computer=”[host]”, CreatorProcessName=”taskeng”, EventID=”4688″, EventRecordID=”67948″, ExecutionProcessID=”4″, ExecutionThreadID=”48″, FileDescription=”Google Installer”, FileVersion=”1.2.131.7″, InternalName=”Google Update”, Keywords=”0x8020000000000000″, Language=”English (United States)”, Length=”133104″, Level=”0″, MD5=”626A24ED1228580B9518C01930936DF9″, NewProcessId=”0x16b4″, NewProcessName=”C:\Users\Jason\AppData\Local\Google\Update\GoogleUpdate.exe”, Opcode=”0″, ProcessId=”0xfcc”, ProductVersion=”1.2.131.7″, ProviderGuid=”{54849625-5478-4994-A5BA-3E3B0328C30D}”, ProviderName=”Microsoft-Windows-Security-Auditing”, Recent=”True”, SHA1=”DCB86149B70829BB4320811B12686AE00131DBC3″, Signed=”True”, SubjectDomainName=”[host]”, SubjectLogonId=”0x25e5350″, SubjectUserName=”Jason”, SubjectUserSid=”[sid]”, Task=”13312″, TokenElevationType=”%%1938″, ValidSignatureDate=”False”, Version=”0″, Zone=”0″

What about a named pipe that starts with “chrome”?

Mar 19 23:44:51 [host] WLS_NamedPipeMonitor: LogType=”WLS”, ChangeType=”Created”, WLSKey=”10375″, Name=”chrome.5748.0.150278265″

Anything load mpengine.dll?

Mar 22 03:21:45 [host] WLS_ModuleMonitor: LogType=”WLS”, BaseFileName=”mpengine.dll”, ChangeType=”Added”, CompanyName=”Microsoft Corporation”, WLSKey=”14514″, FileDescription=”Microsoft Malware Protection Engine”, FileName=”c:\programdata\microsoft\microsoft antimalware\definition updates\{d9b17332-a27d-4442-8ff1-793d9607fc2e}\mpengine.dll”, FileVersion=”1.1.9302.0″, InternalName=”mpengine”, Language=”English (United States)”, Length=”7108640″, MD5=”9F4003841689C663254D54177EB97219″, Process=”MsMpEng”, ProductVersion=”1.1.9302.0″, SHA1=”F2F46BBE3F931B0927B2FEFE9707C0063C6872D6″, Zone=”0″

If you’d like more information on WLS, send me a note via the contact form.

Process Execution Logs (and WLS)


Something I’ve found useful when analyzing a Windows host is a record of what processes executed. If you’ve ever looked in Event Viewer, you’ll know that by default, they look like this:

(This space intentionally left blank.)

So, let’s turn process auditing on.  Enable auditing for “Audit Process Creation” and “Audit Process Termination”.

TurnAuditingOn

Now, anytime a process is created or terminated, you’ll get a log similar to the following:

A new process has been created.

Subject:
Security ID: [domain]/[user]
Account Name: [user]
Account Domain: [domain]
Logon ID: 0x9cb68

Process Information:
New Process ID: 0x18f8
New Process Name: C:\Windows\System32\mspaint.exe
Token Elevation Type: TokenElevationTypeDefault (1)
Creator Process ID: 0x1084

Token Elevation Type indicates the type of token that was assigned to the new process in accordance with User Account Control policy.

Type 1 is a full token with no privileges removed or groups disabled. A full token is only used if User Account Control is disabled or if the user is the built-in Administrator account or a service account.

Type 2 is an elevated token with no privileges removed or groups disabled. An elevated token is used when User Account Control is enabled and the user chooses to start the program using Run as administrator. An elevated token is also used when an application is configured to always require administrative privilege or to always require maximum privilege, and the user is a member of the Administrators group.

Type 3 is a limited token with administrative privileges removed and administrative groups disabled. The limited token is used when User Account Control is enabled, the application does not require administrative privilege, and the user does not choose to start the program using Run as administrator.

That’s an OK log, we know what executed and when, and could trace back the “Creator Process ID” to find the creating process. However, the log is rather long and contains quite a bit of useless information; this will chew up your Splunk (or other log aggregation tool) license in no time.

WLS can help us here. It will create key / value pairs from the log, add useful information, and not fill your logs with paragraphs of redundant information. The example below uses my default metadata settings for WLS, the bold text indicates the extra information WLS added to the log.

Mar 21 12:45:26 [host] Security: LogType=”WLS”, BaseFileName=”mspaint.exe”, Cached=”True”, Channel=”Security”, CommandLine=”‘C:\windows\system32\mspaint.exe’ ‘C:\Users\[user]\Desktop\blog\TurnAuditingOn.png'”, CompanyName=”Microsoft Corporation”, Computer=”[host].[domain]”, CreatorProcessName=”explorer”, Entropy=”6.17942325269204″, EventID=”4688″, EventRecordID=”1145730″, ExecutionProcessID=”4″, ExecutionThreadID=”48″, FileDescription=”Paint”, FileVersion=”6.1.7600.16385 (win7_rtm.090713-1255)”, InternalName=”MSPAINT”, Keywords=”0x8020000000000000″, Language=”English (United States)”, Length=”6676480″, Level=”0″, MD5=”458F4590F80563EB2A0A72709BFC2BD9″, NewProcessId=”0x18f8″, NewProcessName=”C:\Windows\System32\mspaint.exe”, Opcode=”0″, ProcessId=”0x1084″, ProductVersion=”6.1.7600.16385″, ProviderGuid=”{54849625-5478-4994-A5BA-3E3B0328C30D}”, ProviderName=”Microsoft-Windows-Security-Auditing”, SHA1=”3F97DC3BD1467C710C6A8D26B97BB6CF47DEB4C6″Signed=”False”, SubjectDomainName=”[domain]”, SubjectLogonId=”0x9cb68″, SubjectUserName=”[user]”, SubjectUserSid=”[sid]”, Task=”13312″, TokenElevationType=”%%1936″, Version=”0″, Zone=”0″

The standard windows log is 1,353 characters, the WLS log is 1,141 (with pretty much every optional data point added). Less data, higher quality, useful stuff. Now, what to do with all the data…

What is WLS?


The Windows Logging Service (WLS) is a Windows service that forwards your event logs, along with user defined contextual data, to your log server.

Each process execution log is augmented with:

  • Creator process name
  • Command line parameters

and optionally:

  • Any file metadata (attributes, MAC times, version, size, etc)
  • Digital signature flag
  • Entropy
  • Environmental variables (per process)
  • Hashes (MD5, RIPEMD160, SHA1, SHA256, SHA384, SHA512)
  • Zone

WLS can also log the following information to your log server:

  • Certificates
  • Devices
  • Drives
  • File system changes – including file metadata
  • Listening and connected ports, with associated process information
  • Loaded modules – including file metadata
  • Mutexes, semaphores, and other Windows objects
  • Named pipes
  • Optical media used
  • Performance counters
  • Registry changes
  • WMI information

I’ll cover the details of each of these features and configuration examples in upcoming posts, as well as provide example Splunk searches I use for day-to-day operations.

If you’d like more information on WLS, send me a note via the contact form. WLS is currently available to US entities, but does require a signed license agreement.