Get-Winevent Part III: Querying the Event Log for Logons (Part A)

The following is a digression on using Powershell's where-object (filter) to query System and Administrative events with 'Get-WinEvent'.  I like this method of querying the event logs because it is "pipeline" oriented and allows me to re-use/amend/copy previous syntax.  I was having some concern understanding a mysterious problem: my Windows 7 PC spontaneously un-sleeps itself and seemingly commences a log-on. I wanted to understand why this happened and if there was evidence of ex-filtration or malware.
  

With Powershell's 'where-object', I am going to filter select events. I can query the entire set of all Windows events, but limit the query with the '-max' parameter, otherwise the query will take much to long. To look at events with "Pnp" in the message body, I found I need 'findstr':

get-winevent -max 100 | where {$_.Message | findstr "Pnp"} | Select Timecreated,ID,RecordID, Message | ft -auto -wrap

TimeCreated Id RecordId Message
----------- -- -------- -------
6/28/2011 10:15:16 AM 2102 14420 Forwarded a finished Pnp or Power operation (22, 2) to the lower driver for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RIMSPCI#DISK&VEN_RIC
OH&PROD_MEMORYSTICKSTORAGE&REV_1.00#MS0001# with status 0xC00000BB.
6/28/2011 10:15:16 AM 2100 14419 Received a Pnp or Power operation (22, 2) for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RIMSPCI#DISK&VEN_RICOH&PROD_MEMORYSTICKSTORAGE&REV
_1.00#MS0001#.
6/28/2011 10:15:16 AM 2102 14418 Forwarded a finished Pnp or Power operation (22, 2) to the lower driver for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RISD#DISK&VEN_RICOH&
PROD_SD#MMCSTORAGE&REV_2.00#0001# with status 0xC00000BB.
6/28/2011 10:15:16 AM 2100 14417 Received a Pnp or Power operation (22, 2) for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RISD#DISK&VEN_RICOH&PROD_SD#MMCSTORAGE&REV_2.00#00
01#.
6/27/2011 10:48:10 PM 2102 14416 Forwarded a finished Pnp or Power operation (22, 2) to the lower driver for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RISD#DISK&VEN_RICOH&
PROD_SD#MMCSTORAGE&REV_2.00#0001# with status 0xC00000BB.
6/27/2011 10:48:10 PM 2100 14415 Received a Pnp or Power operation (22, 2) for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RISD#DISK&VEN_RICOH&PROD_SD#MMCSTORAGE&REV_2.00#00
01#.
6/27/2011 10:48:10 PM 2102 14414 Forwarded a finished Pnp or Power operation (22, 2) to the lower driver for device WPDBUSENUMROOT\UMB\2&37C186B&1&STORAGE#VOLUME#_??_RIMSPCI#DISK&VEN_RIC
OH&PROD_MEMORYSTICKSTORAGE&REV_1.00#MS0001# with status 0xC00000BB.
  
  
But I can also look at "sleep" events with the '-imatch' operator:

get-winevent -max 1000 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames,Message | where {$_.Message -imatch "sleep"} | ft -wrap -auto


ProcessId TimeCreated Id Task TaskDisplayName KeywordsDisplayNames Message--------- ----------- -- ---- --------------- -------------------- -------
1608 6/28/2011 10:15:24 AM 1 0 {} The system has resumed from sleep.

Sleep Time: ‎2011‎-‎06‎-‎28T05:47:49.589233900Z
Wake Time: ‎2011‎-‎06‎-‎28T17:15:17.711126400Z

Wake Source: Unknown
4 6/27/2011 10:48:05 PM 42 64 {} The system is entering sleep.

Sleep Reason: Hibernate from Sleep
1608 6/27/2011 10:47:54 PM 1 0 {} The system has resumed from sleep.

Sleep Time: ‎2011‎-‎06‎-‎28T05:47:49.589233900Z
Wake Time: ‎2011‎-‎06‎-‎28T05:47:49.587233800Z

Wake Source: S4 Doze to Hibernate
4 6/27/2011 4:47:43 PM 42 64 {} The system is entering sleep.

Sleep Reason: Button or Lid
1608 6/27/2011 3:55:48 PM 1 0 {} The system has resumed from sleep.

Sleep Time: ‎2011‎-‎06‎-‎27T07:04:00.443168300Z
Wake Time: ‎2011‎-‎06‎-‎27T22:55:37.240099500Z
   
Since the 10:15 AM login is my recent interactive logon and I know I did not logon interactively at 10:48 PM (the night before), I wanted to understand why that was happening at that odd hour in the evening.  The next series of commands helped me see if my ID was responsible for a "Logon" or "Special Logon" for that 10:48 PM "Pnp" or "resume from sleep" event: 

get-winevent -ProviderName "Microsoft-Windows-Security-Auditing" -max 100 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames | where {$_.TaskDisplayName -like "Logon"} | ft -wrap -auto | more
 
ProcessId TimeCreated Id Task TaskDisplayName KeywordsDisplayNames
--------- ----------- -- ---- --------------- --------------------
632 6/28/2011 10:31:34 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:25:19 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:25:05 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:22:18 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:20:55 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:20:54 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:18:52 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:18:34 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:18:34 AM 4624 12544 Logon {Audit Success}
632 6/28/2011 10:18:34 AM 4648 12544 Logon {Audit Success}
632 6/27/2011 3:58:55 PM 4624 12544 Logon {Audit Success}
632 6/27/2011 3:56:07 PM 4624 12544 Logon {Audit Success}
632 6/27/2011 3:56:07 PM 4624 12544 Logon {Audit Success}
632 6/27/2011 3:56:07 PM 4648 12544 Logon {Audit Success}
....

get-winevent -ProviderName "Microsoft-Windows-Security-Auditing" -max 100 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames | where {$_.TaskDisplayName -like "Special Logon"} | ft -wrap -auto | more

ProcessId TimeCreated Id Task TaskDisplayName KeywordsDisplayNames
--------- ----------- -- ---- --------------- --------------------
632 6/28/2011 10:31:34 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:25:19 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:25:05 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:22:18 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:20:55 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:20:54 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:18:52 AM 4672 12548 Special Logon {Audit Success}
632 6/28/2011 10:18:34 AM 4672 12548 Special Logon {Audit Success}
632 6/27/2011 3:58:55 PM 4672 12548 Special Logon {Audit Success}
632 6/27/2011 3:56:07 PM 4672 12548 Special Logon {Audit Success}
... 

No evidence of a "Logon" or "Special Logon" at the 10:00 PM hour yesterday!
As a side note, if I wanted to see more information about "Special Logon" attempts, I could structure a provider query as below, pumping all the information to out-gridview which I could paste and copy into a spreadsheet.
  
get-winevent -ProviderName "Microsoft-Windows-Security-Auditing" -max 1000 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames | where {$_.TaskDisplayName -like "Special Logon"} | ogv

If I want to look a little more thoroughly at "Special Logon" events, I can use:
 
get-winevent -ProviderName "Microsoft-Windows-Security-Auditing" -max 10 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames | where {$_.TaskDisplayName -like "Special Logon"} | fl * | more

 
ProcessId : 632TimeCreated : 6/28/2011 10:44:30 AM
Id : 4672
Task : 12548
TaskDisplayName : Special Logon
KeywordsDisplayNames : {Audit Success}

ProcessId : 632
TimeCreated : 6/28/2011 10:31:34 AM
Id : 4672
Task : 12548
TaskDisplayName : Special Logon
KeywordsDisplayNames : {Audit Success}
...

If I want to look at all details of "Special Logon" event entries:

get-winevent -ProviderName "Microsoft-Windows-Security-Auditing" -max 100 | Select * | where {$_.TaskDisplayName -like "Special Logon"} | fl * | more

...

Message : Special privileges assigned to new logon.

Subject:
Security ID: S-1-5-18
Account Name: SYSTEM
Account Domain: NT AUTHORITY
Logon ID: 0x3e7

Privileges: SeAssignPrimaryTokenPrivilege
SeTcbPrivilege
SeSecurityPrivilege
SeTakeOwnershipPrivilege
SeLoadDriverPrivilege
SeBackupPrivilege
SeRestorePrivilege
SeDebugPrivilege
SeAuditPrivilege
SeSystemEnvironmentPrivilege
SeImpersonatePrivilege
Id : 4672
Version : 0
Qualifiers :
Level : 0
Task : 12548
Opcode : 0
Keywords : -9214364837600034816
RecordId : 16766
ProviderName : Microsoft-Windows-Security-Auditing
ProviderId : 54849625-5478-4994-a5ba-3e3b0328c30d
LogName : Security
ProcessId : 632
ThreadId : 752
MachineName : rmfvpc
UserId :
TimeCreated : 6/28/2011 10:44:30 AM
ActivityId : 4f32adc8-0278-0270-8105-0000ca77ff7e
RelatedActivityId :
ContainerLog : security
MatchedQueryIds : {}
Bookmark : System.Diagnostics.Eventing.Reader.EventBookmark
LevelDisplayName : Information
OpcodeDisplayName : Info
TaskDisplayName : Special Logon
KeywordsDisplayNames : {Audit Success}
Properties : {System.Diagnostics.Eventing.Reader.EventProperty, System.Diagnostics.Eventing.Reader.EventProperty, System.Diagnostics.Eventing.Reader.EventProperty, System.Diagnostics.Eventing.Reader.EventProperty...}

...

This last command is important because it gives a complete readout of the entire event log entry and query fields. But really, I just want to know what happened yesterday around the time my system un-hibernated. For this, I can run a "match" query on a particular date:

get-winevent -max 1000 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames | where {$_.TimeCreated -match "6/27/2011"} | ft -wrap -auto | more 

Alternatively,I can add the "message" to the query. For security reasons, I will leave this as an exercise for the reader:

get-winevent -max 400 | Select ProcessID,TimeCreated,ID,Task,TaskDisplayName,KeywordsDisplayNames,Message | where {$_.TimeCreated -match "6/27/2011"} | ft -wrap -auto 

At this point, I still do not know what caused the "resume from sleep" event. Please see
Get-Winevent Part III: Querying the Event Log for Logons (Part B)