Poor Windows Event Query Performance on WEC with unknown Event Source

Question

Poor Windows Event Query Performance on WEC with unknown Event Source

TheGrea 11

Hi,

we have an issue, that it's really slow to query Windows Events on a Windows Event Collector e.g via Get-WinEvent when the Source is unknown (The description for Event ID xx from source yy cannot be found).

You can see in the API Monitor, that it takes quite long to execute EvtOpenPublisherMetadata:

Snap2

Content Format is set to Events and not RenderedText

If you copy the Registry Key HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\Application%Source%

from the source system that generated the event and set it on the Windows Event Collector the performance to query these events are about 10x times faster. Futhermore you don't see no more error codes 2 when executing EvtOpenPublisherMetadata and the calls also way faster.

Is there a way to solve this performance issue without registering every source on the Event Collector Server ?

Thanks in advance

Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-04T01:44:25.16+00:00

According to EvtOpenPublisherMetadata,

If you specify an archived log file, this function will check for the specified provider's metadata in the log file. If the provider's metadata is not found in the log file, the function will search for the provider in the list of registered providers on the local computer.

How did you call EvtOpenPublisherMetadata? Could you please provide a minimal sample?

And have you checked Setting up a Source Initiated Subscription?
TheGrea 11 Reputation points

2024-01-04T14:49:10.9766667+00:00

For this test I executed the powershell cmdlet Get-WinEvent which called EvtOpenPublisherMetadata. The original problem was, that Winlogbeat stopped shipping Windows Events from channels, that contained logs with unknown Publisher, because it took too long to retrieve the Windows Events from the Windows-API. The workaround was to set the Registry Keys mentioned above for specific Publishers. Yes I checked the article to set up a Source Initiated Subscription.

MotoX80 36,291

Can you use Invoke-Command? That way the Get-Winevent is executing on the remote server where the registry keys exist.

$sb = {
    Get-WinEvent -LogName Application -MaxEvents 10
}
$User = ".\admin"
$PWord = ConvertTo-SecureString -String "admin" -AsPlainText -Force

$Credential = New-Object -TypeName System.Management.Automation.PSCredential -ArgumentList $User, $PWord
$events = Invoke-Command -ComputerName test10 -ScriptBlock $sb -Credential $Credential 

$events | Format-Table

TheGrea 11 Reputation points

2024-01-04T16:46:55.64+00:00

It's faster if I use Invoke-Command and execute the command on the remote server, but unfortunately this doesn't help me, since I have to collect and read the events on the Windows Eventlog Collector server.
Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-05T02:15:22.65+00:00

What's your Get-WinEvent command? Your picture shows the log file Windows Event Collector generated cannot be found?

It seems Windows Event Collector needs a Query command, which is used by the event source for selecting events to forward to the event collector (EcSubscriptionQuery).
TheGrea 11 Reputation points

2024-01-05T07:57:10.4166667+00:00

This is the Query I use in the Subscription

There's no issue with collecting the log, but with with querying the events after they were collected using e.g the powershell command Get-WinEvent -FilterHashtable @{Logname="AppSrvApplication";ID=0} -MaxEvents 10
Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-05T08:25:27.0866667+00:00

Did your computer have the registry HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\AppSrvApplication? (I checked and no.)

See Example 18: Use FilterHashtable to get application errors and Creating Get-WinEvent queries with FilterHashtable for more information.

Another point

The Event Id is referenced in the hash table as the key ID and the value is a specific Event Id. Usually, the ProviderName is the name that appears in the Source field in the Windows Event Viewer.

Also check the available Lognames in the Windows Event Viewer.
TheGrea 11 Reputation points

2024-01-05T10:10:56.8566667+00:00

HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\AppSrvApplication does not exist. This is a custom log created similar like described in the article https://learn.microsoft.com/de-de/archive/blogs/russellt/creating-custom-windows-event-forwarding-logs . It exists in the Windows Event Viewer and e.g in the Registry under HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\WINEVT\Channels\AppSrvApplication . Thanks for the links how to filter Get-WinEvent but this is not suitable for me, since I need to query all Events from the Log.
Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-08T01:52:21.2933333+00:00

Get-WinEvent cannot find your AppSrvApplication log file. Use Get-WinEvent -ListLog * to check the available log files firstly.

And according to your blog link, shouldn't the Logname be WEC/Domain-Controllers, WEC/AppSrvApplication?
TheGrea 11 Reputation points

2024-01-08T09:35:22.9666667+00:00

That's not an issue, since I registered the log using the link I provided. I can query Windows Events using my Powershell Command. It's just too slow.

1 answer

Your answer

Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-04T01:44:25.16+00:00

According to EvtOpenPublisherMetadata,

If you specify an archived log file, this function will check for the specified provider's metadata in the log file. If the provider's metadata is not found in the log file, the function will search for the provider in the list of registered providers on the local computer.

How did you call EvtOpenPublisherMetadata? Could you please provide a minimal sample?

And have you checked Setting up a Source Initiated Subscription?
TheGrea 11 Reputation points

2024-01-04T14:49:10.9766667+00:00

For this test I executed the powershell cmdlet Get-WinEvent which called EvtOpenPublisherMetadata. The original problem was, that Winlogbeat stopped shipping Windows Events from channels, that contained logs with unknown Publisher, because it took too long to retrieve the Windows Events from the Windows-API. The workaround was to set the Registry Keys mentioned above for specific Publishers. Yes I checked the article to set up a Source Initiated Subscription.
MotoX80 36,291 Reputation points

2024-01-04T15:50:37.6333333+00:00

Can you use Invoke-Command? That way the Get-Winevent is executing on the remote server where the registry keys exist.

$sb = { Get-WinEvent -LogName Application -MaxEvents 10 } $User = ".\admin" $PWord = ConvertTo-SecureString -String "admin" -AsPlainText -Force $Credential = New-Object -TypeName System.Management.Automation.PSCredential -ArgumentList $User, $PWord $events = Invoke-Command -ComputerName test10 -ScriptBlock $sb -Credential $Credential $events | Format-Table
TheGrea 11 Reputation points

2024-01-04T16:46:55.64+00:00

It's faster if I use Invoke-Command and execute the command on the remote server, but unfortunately this doesn't help me, since I have to collect and read the events on the Windows Eventlog Collector server.
Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-05T02:15:22.65+00:00

What's your Get-WinEvent command? Your picture shows the log file Windows Event Collector generated cannot be found?

It seems Windows Event Collector needs a Query command, which is used by the event source for selecting events to forward to the event collector (EcSubscriptionQuery).
TheGrea 11 Reputation points

2024-01-05T07:57:10.4166667+00:00

This is the Query I use in the Subscription

There's no issue with collecting the log, but with with querying the events after they were collected using e.g the powershell command Get-WinEvent -FilterHashtable @{Logname="AppSrvApplication";ID=0} -MaxEvents 10
Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-05T08:25:27.0866667+00:00

Did your computer have the registry HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\AppSrvApplication? (I checked and no.)

See Example 18: Use FilterHashtable to get application errors and Creating Get-WinEvent queries with FilterHashtable for more information.

Another point

The Event Id is referenced in the hash table as the key ID and the value is a specific Event Id. Usually, the ProviderName is the name that appears in the Source field in the Windows Event Viewer.

Also check the available Lognames in the Windows Event Viewer.
TheGrea 11 Reputation points

2024-01-05T10:10:56.8566667+00:00

HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\AppSrvApplication does not exist. This is a custom log created similar like described in the article https://learn.microsoft.com/de-de/archive/blogs/russellt/creating-custom-windows-event-forwarding-logs . It exists in the Windows Event Viewer and e.g in the Registry under HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\WINEVT\Channels\AppSrvApplication . Thanks for the links how to filter Get-WinEvent but this is not suitable for me, since I need to query all Events from the Log.
Xiaopo Yang - MSFT 12,731 Reputation points Microsoft External Staff

2024-01-08T01:52:21.2933333+00:00

Get-WinEvent cannot find your AppSrvApplication log file. Use Get-WinEvent -ListLog * to check the available log files firstly.

And according to your blog link, shouldn't the Logname be WEC/Domain-Controllers, WEC/AppSrvApplication?
TheGrea 11 Reputation points

2024-01-08T09:35:22.9666667+00:00

That's not an issue, since I registered the log using the link I provided. I can query Windows Events using my Powershell Command. It's just too slow.

Answer 1

MotoX80 36,291

See if this works for you. I discovered that if you point wevtutil.exe directly at the event log .evtx file, it won't try to process the EventMessageFile. It just dumps the XML. I traced it with Process Monitor and did not see any eventlog registry reads. I used my Application log to test.

cls
$xml = New-Object -TypeName XML
$data =  wevtutil.exe qe /c:10 /rd:true /lf C:\Windows\System32\winevt\Logs\Application.evtx
$data = "<AllEvents>" + $data + "</AllEvents>"
$xml.LoadXml($data)
foreach ($e in $xml.AllEvents.Event) {
    [PSCustomObject] @{
        TOD = ([datetime]($e.System.TimeCreated).SystemTime).ToString("yyyy-MM-dd HH:mm:ss")
        EventID = $e.System.EventID.'#text'
        Provider = $e.System.Provider.Name
        Data = $e.EventData.Data -join ","
    }
}

The down side to this is that even if the event source is registered, you won't get the formatted message, you just get the data that plugs into the message.

User's image

TheGrea 11 Reputation points

2024-01-08T09:33:25.3566667+00:00

Wow, using this method it's incredibly fast to query events. Thanks for your work. But unfortunately my original problem is that it's really slow for a third party application to query events from the Eventlog and I can't change the way how it queries these events. Using the Powershell command Get-WinEvent I was able to reproduce the issue.
MotoX80 36,291 Reputation points

2024-01-08T14:00:21.2133333+00:00

I love a challenge.
MotoX80 36,291 Reputation points

2024-01-08T18:30:55.1766667+00:00

it's really slow for a third party application to query events

You can't be the only person with this problem. Have you contacted the support team for this application? Do they have a support forum where you can ask other users of this application if they have a solution?

You can see in the API Monitor, that it takes quite long to execute EvtOpenPublisherMetadata:

In the image that you posted, it shows "clr.dll". Is that the app itself or part of the .Net runtime (on behalf of the app)? When I trace get-winevent on my laptop with Process Monitor, I see svchost.exe reading the registry looking for the message file.

Disclaimer: I am just reading the Application event log. I do not have an event forwarding environment configured where I can test this.

If you trace Get-winevent with your API Monitor, does that also show calls to EvtOpenPublisherMetadata? Do they take the same amount of time?

If your eventlog name is AppSrvApplication, then nothing should be registered. It should only take a few milliseconds to try to read the registry. Is every EvtOpenPublisherMetadata call doing something like looping through all entries under \WINEVT\Channels?

Here is Process Monitor. https://learn.microsoft.com/en-us/sysinternals/downloads/procmon
TheGrea 11 Reputation points

2024-01-09T17:09:17.6+00:00

Thanks for your post.

You can't be the only person with this problem. Have you contacted the support team for this application? Do they have a support forum where you can ask other users of this application if they have a solution?

Yes they have a support forum. Since I was able to reproduce the issue using Powershell the issue must rely somewhere in the OS and not in the app. But you're right maybe someone else has had the same issue. I'll give it a try.

In the image that you posted, it shows "clr.dll". Is that the app itself or part of the .Net runtime (on behalf of the app)? When I trace get-winevent on my laptop with Process Monitor, I see svchost.exe reading the registry looking for the message file.

The image shows a trace of the Powershell process using API Monitor when I executed Get-Winevent . I guess it shows clr.dll as Module because Powershell is based on the .Net Framework. When I trace it using Process Monitor also svchost.exe is the process reading the registry.

If your eventlog name is AppSrvApplication, then nothing should be registered. It should only take a few milliseconds to try to read the registry. Is every EvtOpenPublisherMetadata call doing something like looping through all entries under \WINEVT\Channels?

In this procmon trace i queried a single event:

Yes, there are RegEnumKey Operations for every Key under \WINEVT\Channels . This Operations only happen if I query an Event.

There are also a lot of operations happening under HKLM\SOFTWARE\Microsoft\Windows\CurrentVersion\WINEVT\Publishers

But here I can't distinguish between the "background noise" of the Windows Eventlog Collector and the Event Query.
MotoX80 36,291 Reputation points

2024-01-10T01:59:12.1566667+00:00

I copied the app eventlog file to c:\temp and queried it like this.

Get-WinEvent -Path .\Application.evtx

I too see a lot of reads to WINEVT\Publishers. That's pretty much expected since I didn't register an eventlog.

If you see a lot of "not found" entries against HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\AppSrvApplication%Source% then its looking to me like your best bet is to register those sources.

I have not been able to find any way to control how the eventlog searches the registry.
TheGrea 11 Reputation points

2024-01-10T08:47:41.9233333+00:00

Ok, thank you. I really appreciated your help.
MotoX80 36,291 Reputation points

2024-01-10T14:49:49.8166667+00:00
Final thought, wevtutil has the /f option.

/{f | f/{f | format}:[XML|Text|RenderedXml] The default value is XML. If Text is specified, prints events in an easy to read text format, rather than in XML format. If RenderedXml, prints events in XML format with rendering information. Note that printing events in Text or RenderedXml formats is slower than printing in XML format.

I ran these tests and monitored it with procmon.

wevtutil.exe qe application /c:10 /rd:true /f:XML

No registry calls.

wevtutil.exe qe application /c:10 /rd:true /f:Text

7,700 registry reads to Winevt\Publishers

wevtutil.exe qe application /c:10 /rd:true /f:RenderedXml

7,700 registry reads to Winevt\Publishers

The key phrase is "with rendering information". Whatever API call wevtutil is making for /F:XML is telling the event system to not bother expanding the message.

You would need to ask your 3rd party app support if they can add a /F:XML equivalent option.

Good luck.

Share via

Poor Windows Event Query Performance on WEC with unknown Event Source

1 answer

Your answer