Jump to content

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


Recommended Posts

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?

Link to post
Share on other sites

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

My UDFs and Tutorials:

Spoiler

UDFs:
Active Directory (NEW 2021-06-05 - Version 1.5.4.0) - Download - General Help & Support - Example Scripts - Wiki
OutlookEX (NEW 2021-06-14 - Version 1.6.5.0) - Download - General Help & Support - Example Scripts - Wiki
OutlookEX_GUI (2021-04-13 - Version 1.4.0.0) - Download
Outlook Tools (2019-07-22 - Version 0.6.0.0) - Download - General Help & Support - Wiki
ExcelChart (2017-07-21 - Version 0.4.0.1) - Download - General Help & Support - Example Scripts
PowerPoint (NEW 2021-07-28 - Version 1.1.0.0) - Download - General Help & Support
Excel - Example Scripts - Wiki
Word - Wiki
Task Scheduler (2019-12-03 - Version 1.5.1.0) - Download - General Help & Support - Wiki

Tutorials:
ADO - Wiki, WebDriver - Wiki

 

Link to post
Share on other sites

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... 😐

Link to post
Share on other sites

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/

My UDFs and Tutorials:

Spoiler

UDFs:
Active Directory (NEW 2021-06-05 - Version 1.5.4.0) - Download - General Help & Support - Example Scripts - Wiki
OutlookEX (NEW 2021-06-14 - Version 1.6.5.0) - Download - General Help & Support - Example Scripts - Wiki
OutlookEX_GUI (2021-04-13 - Version 1.4.0.0) - Download
Outlook Tools (2019-07-22 - Version 0.6.0.0) - Download - General Help & Support - Wiki
ExcelChart (2017-07-21 - Version 0.4.0.1) - Download - General Help & Support - Example Scripts
PowerPoint (NEW 2021-07-28 - Version 1.1.0.0) - Download - General Help & Support
Excel - Example Scripts - Wiki
Word - Wiki
Task Scheduler (2019-12-03 - Version 1.5.1.0) - Download - General Help & Support - Wiki

Tutorials:
ADO - Wiki, WebDriver - Wiki

 

Link to post
Share on other sites

@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.

Link to post
Share on other sites

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.

Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
  • Recently Browsing   0 members

    No registered users viewing this page.

×
×
  • Create New...