Different / custom datetime format causing error in Get-WinEvent filter returning all Application events, causing Crash Assistant to open every time
Appulcake opened this issue · 4 comments
Just thought I'd make a quick github report as it's easier to see here, we talked in FTB Discord's #java-support channel briefly about this, I was the one who had Crash Assistant open every single time after normally closing the game, thinking it crashed as it found a matching winevent of a java process being killed. This was pointed out by lupusagax, and it's evident by this near the top of the winevent log created:
Get-WinEvent : The following value is not in a valid DateTime format: Thu 31 07 19:06:35.
At line:1 char:38
+ ... 'Continue'; Get-WinEvent -FilterHashtable @{ LogName='Application'; ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
I realise this comes from me changing Windows' Clock and Region => Region => Additional Settings => Date's Short Date format at some point to ddd dd/MM, because this is what's used to show time + date in system tray clock and I preferred this format (I forget/mix up day of the week a lot). It seems that in Get-Winevent when passing through a (Get-Date).AddSeconds(-15) passes a correct datetime format, but in the actual event log it seems to just take the string value of the events' datetimes which is in this custom format that's not recognised as a valid datetime.
I wasn't really sure what'd be a good way to somehow query this information in a system region agnostic way of just getting the strict datetime object in those logs, so after searching around a bunch I found that you can set the current powershell session's thread culture temporarily to a culture independent (InvariantCulture) format which'd bypass whatever regional setting a user would have, and then at the end set it back to what it was. From what I understood this'd be safe to do because it's only changing it for this running powershell thread so even if it'd fail to set it back, user's regional settings wouldn't be affected (can't upload .ps1 here so renamed it to txt, was testing with an output to my/user's desktop for quick access:
Second idea is something chatgpt suggested, to instead query events based on criteria bypassing FilterHashtable, with a warning that this might be slightly less efficient but from simple test it seems to run instantly still so I don't think it'd be causing performance issues, seeing how it's only called once after Minecraft process disappeared I presume. For this I set a maxevents filter for 100 to have some kind of sanity limit in case it'd somehow return an insane amount of events from the past 15 seconds.
I've tested both of these and they both seem to return expected results despite custom/non standard region settings, but the log is in a slightly different format - the first one fills the log with a Get-WinEvent : No events were found that match the specified selection criteria. and a bit of extra context, the second just outputs an empty log if there's no valid entries found.
It's probably far from perfect but hoped it'd help towards a solution at least to make it easier on your end!
Seems like adding .ToUniversalTime() in filtering logic will fix issue, through needs testing, as I tried to cahnge format to non standart, but can't reproduce the isuue.
try this command. Will error occur?
$ErrorActionPreference = 'Continue';
Get-WinEvent -FilterHashtable @{
LogName='Application';
Level=2;
StartTime=(Get-Date).AddSeconds(-15).ToUniversalTime()
} *>&1 | Format-Table -Wrap -AutoSize | Out-File "win_event.txt" -Encoding UTF8Yes, that'll also have the same issue. ToUniversalTime doesn't address the issue - all that does is shift the datetime object to UTC time. So now that filter will try to filter for everything in the past 2 hours and 15 seconds in my example, because my time is 2 hours ahead of UTC.
If I reset my region to default format/settings, I can run the original version of the script fine (I modified it to show level 4 so it shows information level logs as there's plenty of those but not usually errors, and changed window to -1800 seconds to have a consistent window where I can see there's at least a couple info logs for testing purposes).
However, if I change the filter from StartTime=(Get-Date).AddSeconds(-1800) to StartTime=(Get-Date).AddSeconds(-1800).ToUniversalTime() , now what's happening is it takes UTC time (which is 2 hours less than my local time) and then minus 1800s on top of that, so when it's comparing entries to my logs, since those are logged in my own timezone, it'll be looking at 2.5 hours instead of 0.5 hours earlier than current time, and show much more entries.
Definitely don't include that ToUniversalTime() part to the filter unless you're also somehow shifting every winevent log entry's datetime format to match that too (as far as I'm aware those just get returned as they're written, without the timezone changed). This'd mean it should break for anyone who doesn't happen to be using UTC timezone where they live/on their PC.
The issue is not at the (Get-Date).AddSeconds(-15) section. If I print a Get-Date on my powershell, I get a correct DateTime object returned for my region's format, happens to display as dd MMMM yyyy. The display of that changes accordingly to my Region setting's Long Date format, presumably because the printout of this (DateTime.ToString()) converts the DateTime object to a string with the current user's culture setting.
The object itself should still be a culture invariant DateTime, and I can do things like:
$startDate = (Get-Date).AddSeconds(-30)
$endDate = (Get-Date).AddSeconds(-5)
$diff = New-TimeSpan -start $startDate -end $endDate
Write-Output $diffto manipulate this just fine, it correctly shows a difference of 25 seconds between those two, so I don't believe anything is wrong with how Get-Date works.
I can recreate this issue on multiple PCs, even asked a friend to help me who didn't change anything in datetime, where their crash assistant didn't have issues with this nor the ps1 test script that runs that, and after these changes they had the same issue with crash assistant and even just running the snippet of a script it uses.
Recreation steps:
They changed their region's short date setting to a custom format, mind you that's not what you see here because these are predefined formats:
But by changing the actual format string of short date in the Additional Settings then under Date tab:
And restarted powershell just to make sure it doesn't still have its old thread's culture unchanged, when executing the script Get-WinEvent with -FilterHashtable fails as soon as any time (like start or endtime) criteria/filter is included, because Event Viewer's Date and Time values for the events get changed to show in this new short date format.
I couldn't find any microsoft documentation on this at e.g. https://learn.microsoft.com/en-us/powershell/scripting/samples/creating-get-winevent-queries-with-filterhashtable?view=powershell-7.5 that'd account for this, it seems to be a classic case of "it works as long as you have a standard region format but good luck if you used our settings to change how you want to view your time because no one tested how this FilterHashtable will work with it".
I couldn't find a way to make Get-WinEvent -FilterHashtable parse the datetime object in the events' properties in invariant culture disregarding whichever format it's written in the log. So far I've only had luck with either setting the current powershell's thread to invariant culture with the first test script (test1.ps1), or by using Where-Object on a Get-WinEvent -LogName 'Application' -MaxEvents 100 which is according to MS the deprecated and less performant way of doing this, but 1) I don't think that's an issue since we're talking about only querying the last few logs, even on another lower end PC with tens of thousands of log entries I tested this with it ran at an instant, and assuming you don't run this more than once at end of a session when java process isn't detected anymore it shouldn't be causing performance issues and more importantly 2) this seems to (unlike filterhashtable) properly get the datetime properties of the events in a DateTime object format (thus ignoring any user facing formatting changes) instead of getting a string read from it which it tries to convert/interpret as a datetime object (in which case if it's a non standard/not expected string it fails). So the second script (test2.ps1) works for me even when customising region's date short date format:
Get-WinEvent -LogName 'Application' -MaxEvents 100 |
Where-Object { $_.Level -eq 2 -and $_.TimeCreated -ge (Get-Date).AddSeconds(-15) } *>&1 |
Format-Table -Wrap -AutoSize |
Out-File "$env:USERPROFILE\Desktop\win_event.txt" -Encoding UTF8Thanks for reproduction instruction. Now I can reproduce it.
Seems like I've found perfect solution.
Pass an Explicit ISO 8601 Formatted String
A more targeted approach is to convert the DateTime object to a specific string format that FilterHashtable is guaranteed to understand: the ISO 8601 "round-trip" format (o). This passes a pre-formatted string instead of an object, completely avoiding any risk of misinterpretation by the cmdlet. This is arguably the most robust fix.
Get-WinEvent -FilterHashtable @{
LogName='Application';
Level=2;
StartTime=((Get-Date).AddSeconds(-15).ToString('o'))
} *>&1 | Format-Table -Wrap -AutoSize | Out-File "win_event.txt" -Encoding UTF8Oh yep can also confirm that works here too!
I've only gotten as far as "maybe pass on the starttime criteria in a different format that makes it compatible" instead of inverse (trying to change the format it's reading the events as, where I found nothing about), I've gotten to try something like StartTime=((Get-Date).AddSeconds(-15).ToString() and forcing it to be some format once like ToString("yyyy-M-d HH:mm:ss") with some inspiration from https://stackoverflow.com/questions/25274223/powershell-get-winevent-change-output-date-format but got stuck.
Thank you for the fix and I learnt something!