"For ... In ..." is incredibly slowly "ending"

[hacktrap]

I've created the following WMI Query which tries to filter & read from the event log.

Note: I'm intentionally not using the _EventLog_* functions, because it doesn't let filtering and it may take way too much time to manually filter several ten thousands of logs.

 

My function:

Func GetLogs($source, $days)
    $targetDate = StringReplace(_DateAdd('D', -1 * $days, _NowCalcDate()), "/", "")
    $objWMIService = ObjGet("winmgmts:\\localhost\")
    $colItems = $objWMIService.ExecQuery("SELECT * FROM Win32_NTLogEvent WHERE SourceName='" & $source & "' AND TimeGenerated>'" & $targetDate & "'", "WQL", $wbemFlagReturnImmediately + $wbemFlagForwardOnly)

    If Not IsObj($colItems) Then
        Return ""
    EndIf

    Local $buffer
    Local $count = 0

    For $objItem In $colItems
        For $byte In $objItem.Data
            $buffer &= Chr($byte)
        Next
    Next

    Return $buffer
EndFunc   ;==>GetLogs

 

To be exact the behavior is the following:

It executes the WMI query in a pretty acceptable time, also iterates on it quickly, but AFTER the last element, when the code would exit from the loop my whole code & GUI freezes for about a minute. It happens on multiple of my machines, so I don't think it's an issue with my OS.

Any idea what causes this behavior? Do others experience this?

 

I also created a quick test snippet which you can try on your machine:

#include <EventLog.au3>

Global Const $wbemFlagReturnImmediately = 0x10
Global Const $wbemFlagForwardOnly = 0x20

Local $aData[4] = [3, 1, 2, 3]
$hEventLog = _EventLog__Open("", "MyPreciousEvent")
_EventLog__Report($hEventLog, 0, 0, 0, "Administrator", "BananaPhone", $aData)
_EventLog__Close($hEventLog)

$asd = GetLogs("MyPreciousEvent", 3)

Func GetLogs($source, $days)
    $targetDate = StringReplace(_DateAdd('D', -1 * $days, _NowCalcDate()), "/", "")
    $objWMIService = ObjGet("winmgmts:\\localhost\")
    $colItems = $objWMIService.ExecQuery("SELECT * FROM Win32_NTLogEvent WHERE SourceName='" & $source & "' AND TimeGenerated>'" & $targetDate & "'", "WQL", $wbemFlagReturnImmediately + $wbemFlagForwardOnly)

    If Not IsObj($colItems) Then
        Return ""
    EndIf

    Local $buffer

    For $objItem In $colItems
        For $byte In $objItem.Data
            $buffer &= Chr($byte)
        Next
        MsgBox(0, 0, "Saved the buffer...")
    Next

    MsgBox(0, 0, "Finished iterating")

    Return $buffer
EndFunc   ;==>GetLogs

Saved buffer should instantly pop up, but after it will wait like 1-2 min until it says "Finished iterating". So practically as I can see it's just sitting there waiting for something & doing nothing. Any idea why?

[water]

The problem is caused by the size of the eventlog. With flag $wbemFlagReturnImmediately set the call returns results without waiting for the operation to complete.
So the wait time is caused by WMI searching for further hits. As it does not find further records it looks like your script hangs for a minute or two.
It doesn't seem you can do anything about it.

https://docs.microsoft.com/en-us/openspecs/windows_protocols/ms-wmi/2bbdf995-93d8-4902-a39d-38f2a9790b85

[hacktrap]

That sounds pretty weird, since that's exactly why I specified the source & day selector. My earlier code was written in C# (which I'm trying to port to Autoit) and it returned almost instantly. Obviously I guess that uses different native way, but still pretty interesting why it would take that much time to filter the events.

While trying to prove that powershell does the same thing much faster I just realized that "goddamn it" it's also the same slow!
Get-WmiObject -Query "SELECT * FROM Win32_NTLogEvent WHERE SourceName='MyPreciousEvent' AND TimeGenerated>'20210313'"

Get-WmiObject -Query "SELECT * FROM Win32_NTLogEvent WHERE SourceName='MyPreciousEvent' AND TimeGenerated>'20210313'"

It looks I have to get into whether it is possible somehow to optimize the query... 😐

[water]

I think you can enhance the speed of your query. I searched the web (query: "search windows event log performance") and found a few very interesting sites:

https://devblogs.microsoft.com/scripting/check-performance-of-event-log-queries/

https://devblogs.microsoft.com/scripting/how-to-improve-the-performance-of-a-powershell-event-log-query/

[Nine]

@hacktrap One strategy you could use would be to create a background process to copy at specific period of time the content of the logs into SQLite.  Then all queries would be as fast as you would like it to.

[hacktrap]

Huh, I guess that's a bit overcomplication of the problem I'd like to solve In my case it's a rarely running, only a diagnostic-like tool. Well, I guess I'll stick to this slow solution then I tried to optimize the query a bit, but it's near 1%-ish win, so that didn't help too much.