WMI Reports a different time than the Event Viewer

  • Thread starter Thread starter Marc Jellinek
  • Start date Start date
M

Marc Jellinek

I'm managing several SQL Servers. In order to make life easier, I query the
Application Event log for each machine running SQL Server using WMI and safe
it to an Access 2003 database.

Prior to 8 March 2009 (EST), everything worked fine. Event 17177 fired each
night at approximately 12:00am. After 9 March 2009, Daylight Savings Time is
in effect. While the Event Viewer on the machine reports that Event 17177
occurred at 12:00:34 on 3/10/2009 (see below "Event Viewer"), WMI reports
that the event occurred at 23:00:34.

Event Viewer:
----------------
Event Type: Information
Event Source: MSSQL$SQLVS02C
Event Category: (2)
Event ID: 17177
Date: 3/10/2009
Time: 12:00:34 AM
User: N/A
Computer: SQLVS02C
Description:
This instance of SQL Server has been using a process ID of 5920 since
2/9/2009 7:22:37 AM (local) 2/9/2009 12:22:37 PM (UTC). This is an
informational message only; no user action is required.

For more information, see Help and Support Center at
http://go.microsoft.com/fwlink/events.asp.
Data:
0000: 19 43 00 00 0a 00 00 00 .C......
0008: 12 00 00 00 53 00 51 00 ....S.Q.
0010: 4c 00 56 00 53 00 30 00 L.V.S.0.
0018: 32 00 43 00 5c 00 53 00 2.C.\.S.
0020: 51 00 4c 00 56 00 53 00 Q.L.V.S.
0028: 30 00 32 00 43 00 00 00 0.2.C...
0030: 07 00 00 00 6d 00 61 00 ....m.a.
0038: 73 00 74 00 65 00 72 00 s.t.e.r.
0040: 00 00 ..

Here is the code I use to pull the data from the Application Event Log
(Access 2003 VBA): (Feel free to steal... just give me an answer to my
question and you have have it... give me a good answer and I'll help convert
to VBScript or .NET)

Function ImportApplicationEventLog(strComputer As String, strEventLog As
String, Optional ctl As Control) As Boolean
Dim objWMIService As Object
Dim objEvent As Object
Dim colRetrievedItems As Object
Dim rs As Recordset

Dim intLatestEvent As Variant
Dim intLatestEvent_vtdate As Variant
Dim tmpDate As Variant

Dim strWMIQuery As String
Dim intStartingRecordCount As Long

'--- Application Event Log Table
' Date Text(255) -> Mid(objEvent.TimeGenerated, 5, 2) & "/" &
Mid (objEvent.TimeGenerated, 7, 2) & "/" & (Left(objEvent.TimeGenerated, 4)
' Time Text(255) -> Mid(objEvent.TimeGenerated, 9, 2) & ":" &
Mid(objEvent.TimeGenerated, 11, 2) & ":" & Mid(objEvent.TimeGenerated, 13, 2)
' Source Text(255) -> objEvent.SourceName
' Type Text(255) -> objEvent.Type
' Category Text(255) -> objEvent.Category
' Event Text(255) -> objEvent.EventCode
' User Text(255) -> objEvent.User
' Computer Text(255) -> objEvent.ComputerName
' Description Memo -> objEvent.Message
Debug.Print "Start of ImportEventLog: " & Now()


'--- get the latest event in Application Event Log
intLatestEvent = Nz(CurrentDb().QueryDefs("LatestEventLogRecord -
Date").OpenRecordset.Fields(0).Value, 0)


If intLatestEvent = 0 Then
Debug.Print "Zero event log records in [Application Event Log] table,
get all events"
strWMIQuery = "SELECT * FROM Win32_NTLogEvent WHERE Logfile = '" &
strEventLog & "'"
Else
Debug.Print "Latest Event Log Record was generated at: " &
intLatestEvent & " Getting all events generated after " & intLatestEvent
Set intLatestEvent_vtdate = CreateObject("WbemScripting.SWbemDateTime")
intLatestEvent_vtdate.SetVarDate (intLatestEvent)

strWMIQuery = "SELECT * FROM Win32_NTLogEvent WHERE LogFile = '" &
strEventLog & "' AND TimeGenerated > '" & intLatestEvent_vtdate & "'"
End If

Debug.Print "Running WMI query: " & strWMIQuery

Set rs = CurrentDb().TableDefs("Application Event Log").OpenRecordset
intStartingRecordCount = rs.RecordCount

Set tmpDate = CreateObject("WbemScripting.SWbemDateTime")

Set objWMIService =
GetObject("winmgmts:{impersonationLevel=impersonate}!\\" & strComputer &
"\root\cimv2")
Set colRetrievedItems = objWMIService.ExecQuery(strWMIQuery)
For Each objEvent In colRetrievedItems

tmpDate.Value = objEvent.TimeGenerated

rs.AddNew
rs.Fields("Date") = Mid(objEvent.TimeGenerated, 5, 2) & "/" &
Mid(objEvent.TimeGenerated, 7, 2) & "/" & Left(objEvent.TimeGenerated, 4)
rs.Fields("Time") = Mid(objEvent.TimeGenerated, 9, 2) & ":" &
Mid(objEvent.TimeGenerated, 11, 2) & ":" & Mid(objEvent.TimeGenerated, 13, 2)
rs.Fields("Date") = Format(tmpDate.GetVarDate, "mm/dd/yyyy")
rs.Fields("Time") = Format(tmpDate.GetVarDate, "hh:mm:ss")
rs.Fields("Source") = objEvent.SourceName
rs.Fields("Type") = objEvent.Type
rs.Fields("Category") = objEvent.Category
rs.Fields("Event") = objEvent.EventCode
rs.Fields("User") = objEvent.User
rs.Fields("Computer") = objEvent.ComputerName
rs.Fields("Description") = objEvent.Message
rs.Fields("RecordNumber") = objEvent.RecordNumber
rs.Update
If Not ctl Is Nothing Then
ctl.Caption = rs.RecordCount - intStartingRecordCount
ctl.Parent.Repaint
End If

Next

Set objEvent = Nothing
Set objWMIService = Nothing
Set colRetrievedItems = Nothing

rs.Close
Set rs = Nothing
Debug.Print "End of ImportEventLog: " & Now()
End Function
 
Mark:

It looks like there is a bug in WbemScripting.SWbemDateTime and how it
handles DST conversion when converting to local time. It appears to
calculate the 1st Sunday of November as the 8th and the 2nd Sunday of March
as the 15th, at least in the US... so it converts for DST one week later than
it should in 2009, 2015, 2020, and 2026.

I found this bug two weeks ago when troubleshooting password expiration
calculations. I sent a note to MS, haven't heard anything back. You could
argue this is a security bug, however, since security event log records (and
anything else you convert using WbemScripting.SWbemDateTime) will be off by
an hour for two weeks this year (and 2015, 2020, etc.).

Quick demo VBS code:
==============
Set oDT = CreateObject("WbemScripting.SWbemDateTime")
oDT.Value = "20091101120000.000000+000"
WScript.Echo "11/1/2009, should be non-DST local time: " &
oDT.GetVarDate(True)
oDT.Value = "20091107120000.000000+000"
WScript.Echo "11/7/2009, should be non-DST local time: " &
oDT.GetVarDate(True)
oDT.Value = "20091108120000.000000+000"
WScript.Echo "11/8/2009, finally shows non-DST local time: " &
oDT.GetVarDate(True)
' NOTE: The same issue is true for the week from 3/8/2009 - 3/14/2009
' and also affects years 2015, 2020, and 2026
==============

With any luck, someone from MS will read this and forward it to the
appropriate team. I'm not holding my breath, though.

-- GregCMCSE

--------------------------------------------------------

Marc Jellinek said:
I'm managing several SQL Servers. In order to make life easier, I query the
Application Event log for each machine running SQL Server using WMI and safe
it to an Access 2003 database.

Prior to 8 March 2009 (EST), everything worked fine. Event 17177 fired each
night at approximately 12:00am. After 9 March 2009, Daylight Savings Time is
in effect. While the Event Viewer on the machine reports that Event 17177
occurred at 12:00:34 on 3/10/2009 (see below "Event Viewer"), WMI reports
that the event occurred at 23:00:34.

Event Viewer:
----------------
Event Type: Information
Event Source: MSSQL$SQLVS02C
Event Category: (2)
Event ID: 17177
Date: 3/10/2009
Time: 12:00:34 AM
User: N/A
Computer: SQLVS02C
Description:
This instance of SQL Server has been using a process ID of 5920 since
2/9/2009 7:22:37 AM (local) 2/9/2009 12:22:37 PM (UTC). This is an
informational message only; no user action is required.

For more information, see Help and Support Center at
http://go.microsoft.com/fwlink/events.asp.
Data:
0000: 19 43 00 00 0a 00 00 00 .C......
0008: 12 00 00 00 53 00 51 00 ....S.Q.
0010: 4c 00 56 00 53 00 30 00 L.V.S.0.
0018: 32 00 43 00 5c 00 53 00 2.C.\.S.
0020: 51 00 4c 00 56 00 53 00 Q.L.V.S.
0028: 30 00 32 00 43 00 00 00 0.2.C...
0030: 07 00 00 00 6d 00 61 00 ....m.a.
0038: 73 00 74 00 65 00 72 00 s.t.e.r.
0040: 00 00 ..

Here is the code I use to pull the data from the Application Event Log
(Access 2003 VBA): (Feel free to steal... just give me an answer to my
question and you have have it... give me a good answer and I'll help convert
to VBScript or .NET)

Function ImportApplicationEventLog(strComputer As String, strEventLog As
String, Optional ctl As Control) As Boolean
Dim objWMIService As Object
Dim objEvent As Object
Dim colRetrievedItems As Object
Dim rs As Recordset

Dim intLatestEvent As Variant
Dim intLatestEvent_vtdate As Variant
Dim tmpDate As Variant

Dim strWMIQuery As String
Dim intStartingRecordCount As Long

'--- Application Event Log Table
' Date Text(255) -> Mid(objEvent.TimeGenerated, 5, 2) & "/" &
Mid (objEvent.TimeGenerated, 7, 2) & "/" & (Left(objEvent.TimeGenerated, 4)
' Time Text(255) -> Mid(objEvent.TimeGenerated, 9, 2) & ":" &
Mid(objEvent.TimeGenerated, 11, 2) & ":" & Mid(objEvent.TimeGenerated, 13, 2)
' Source Text(255) -> objEvent.SourceName
' Type Text(255) -> objEvent.Type
' Category Text(255) -> objEvent.Category
' Event Text(255) -> objEvent.EventCode
' User Text(255) -> objEvent.User
' Computer Text(255) -> objEvent.ComputerName
' Description Memo -> objEvent.Message
Debug.Print "Start of ImportEventLog: " & Now()


'--- get the latest event in Application Event Log
intLatestEvent = Nz(CurrentDb().QueryDefs("LatestEventLogRecord -
Date").OpenRecordset.Fields(0).Value, 0)


If intLatestEvent = 0 Then
Debug.Print "Zero event log records in [Application Event Log] table,
get all events"
strWMIQuery = "SELECT * FROM Win32_NTLogEvent WHERE Logfile = '" &
strEventLog & "'"
Else
Debug.Print "Latest Event Log Record was generated at: " &
intLatestEvent & " Getting all events generated after " & intLatestEvent
Set intLatestEvent_vtdate = CreateObject("WbemScripting.SWbemDateTime")
intLatestEvent_vtdate.SetVarDate (intLatestEvent)

strWMIQuery = "SELECT * FROM Win32_NTLogEvent WHERE LogFile = '" &
strEventLog & "' AND TimeGenerated > '" & intLatestEvent_vtdate & "'"
End If

Debug.Print "Running WMI query: " & strWMIQuery

Set rs = CurrentDb().TableDefs("Application Event Log").OpenRecordset
intStartingRecordCount = rs.RecordCount

Set tmpDate = CreateObject("WbemScripting.SWbemDateTime")

Set objWMIService =
GetObject("winmgmts:{impersonationLevel=impersonate}!\\" & strComputer &
"\root\cimv2")
Set colRetrievedItems = objWMIService.ExecQuery(strWMIQuery)
For Each objEvent In colRetrievedItems

tmpDate.Value = objEvent.TimeGenerated

rs.AddNew
rs.Fields("Date") = Mid(objEvent.TimeGenerated, 5, 2) & "/" &
Mid(objEvent.TimeGenerated, 7, 2) & "/" & Left(objEvent.TimeGenerated, 4)
rs.Fields("Time") = Mid(objEvent.TimeGenerated, 9, 2) & ":" &
Mid(objEvent.TimeGenerated, 11, 2) & ":" & Mid(objEvent.TimeGenerated, 13, 2)
rs.Fields("Date") = Format(tmpDate.GetVarDate, "mm/dd/yyyy")
rs.Fields("Time") = Format(tmpDate.GetVarDate, "hh:mm:ss")
rs.Fields("Source") = objEvent.SourceName
rs.Fields("Type") = objEvent.Type
rs.Fields("Category") = objEvent.Category
rs.Fields("Event") = objEvent.EventCode
rs.Fields("User") = objEvent.User
rs.Fields("Computer") = objEvent.ComputerName
rs.Fields("Description") = objEvent.Message
rs.Fields("RecordNumber") = objEvent.RecordNumber
rs.Update
If Not ctl Is Nothing Then
ctl.Caption = rs.RecordCount - intStartingRecordCount
ctl.Parent.Repaint
End If

Next

Set objEvent = Nothing
Set objWMIService = Nothing
Set colRetrievedItems = Nothing

rs.Close
Set rs = Nothing
Debug.Print "End of ImportEventLog: " & Now()
End Function
Click to expand...
 
Back
Top