The problem
In our company environment we use several batch files which use WMIC to retrieve the current time. Usually to print it to log files, but also to include the timestamp in a file name.
Starting with Windows 10 - we do not remember seeing this behavior on Windows 7 - we experienced that some of our log file parsers (they create some nice graphs for evaluation) seemed to draw weird stuff. After some research we found out, that for short time periods, the call to WMIC returns a different timestamp.
This is how we call WMIC, and what it returns.
C:\> WMIC.exe OS Get localdatetime /value
LocalDateTime=20191114112607.134000+060
Now we made an experiment and called WMIC every second for a larger period of time. Here is an excerpt of the resulting timestamps:
20191114112607.134000+060
20191114122608.394000+120
20191114122609.687000+120
[...]
20191114123105.161000+120
20191114123106.431000+120
20191114113107.672000+060
We live in a region in MEZ timezone, that is UTC+1. This is why we expect the timestamps with the +060
minute indication. We also do not expect it to change, unless twice a year, that is when day light savings time switches to MESZ (UTC+2) and vice versa.
As you can see in the timestamps above: For almost exactly 5 minutes, WMIC returns the +120
timestamp.
The analysis
I also logged the output of some other calls, to check whether this is a global Windows problem or rather a wmic behavior. All seems to be a sort of (buggy?) behavior of WMIC.
All functions/programs and even another WMIC call returned the expected time. This is my script
while ($true) {
Get-Date -Format G
Get-TimeZone
$timeservers | ForEach-Object {
$server = $_
w32tm.exe /stripchart /computer:$server /dataonly /samples:1 | Out-Default
}
cmd.exe /c date /T | Out-Default
cmd.exe /c time /T | Out-Default
WMIC.exe Path Win32_LocalTime Get /Format:value | Out-Default
# All 'correct' except:
WMIC.exe OS Get localdatetime /value | Out-Default
Start-Sleep -Seconds 1
}
The output of the above script shows that only the OS Get localdatetime
call is returning the 'wrong' timestamp. We have searched the System and Application event log for entries that could tell us why this happens, but there were no entries logged. I also checked the Task Scheduler if some action was scheduled to run when this happens, but nothing.
Registry time zone information
C:\>reg query HKLM\SYSTEM\CurrentControlSet\Control\TimeZoneInformation
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\TimeZoneInformation
Bias REG_DWORD 0xffffffc4
DaylightBias REG_DWORD 0xffffffc4
DaylightName REG_SZ @tzres.dll,-321
DaylightStart REG_BINARY 00000300050002000000000000000000
DynamicDaylightTimeDisabled REG_DWORD 0x0
StandardBias REG_DWORD 0x0
StandardName REG_SZ @tzres.dll,-322
StandardStart REG_BINARY 00000A00050003000000000000000000
TimeZoneKeyName REG_SZ W. Europe Standard Time
ActiveTimeBias REG_DWORD 0xffffffc4
The questions
- Can someone explain the behavior?
- What could influence the outcome of WMIC?
- Would you think this is a sort of bug?
- What other analysis could be done to narrow this down?