[winlog] Reading from EventLogs returns EOF in some instances.

[ebeahan]

Reported instances where reading from EventLogs has returned EOF causing Winlogbeat to exit. Unable to consistently reproduce the behavior locally in order to fix.

An initial patch opened in #35662 but proposed patch needs testing from a system experiencing the issue.

Related errors observed

Failed to subscribe:

{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.680-0500","log.logger":"eventlog","log.origin":{"file.name":"eventlog/wineventlog.go","file.line":240},"message":"WinEventLog[WEC7-Active-Directory] error subscribing (first chance): The query result is stale or invalid and must be recreated. This may be due to the log being cleared or rolling over after the query result was created.","service.name":"winlogbeat","ecs.version":"1.6.0"}

No more events to read:

{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.679-0500","log.logger":"eventlog_detail","log.origin":{"file.name":"eventlog/wineventlog.go","file.line":362},"message":"WinEventLog[WEC2-Registry] No more events","service.name":"winlogbeat","ecs.version":"1.6.0"}

Winlogbeat shuts down gracefully:

{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.715-0500","log.logger":"winlogbeat","log.origin":{"file.name":"beater/eventlogger.go","file.line":172},"message":"Read() returned 0 records.","service.name":"winlogbeat","id":"WEC4-Hotpatching-Errors","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.715-0500","log.logger":"eventlog","log.origin":{"file.name":"eventlog/wineventlog.go","file.line":228},"message":"WinEventLog[WEC5-MSI-Packages] using subscription query=<QueryList>\n  <Query Id=\"0\">\n    <Select Path=\"WEC5-MSI-Packages\">*[System[TimeCreated[timediff(@SystemTime) &lt;= 604800000]]]</Select>\n  </Query>\n</QueryList>","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2023-05-03T14:25:45.715-0500","log.logger":"winlogbeat","log.origin":{"file.name":"beater/eventlogger.go","file.line":125},"message":"Stop processing.","service.name":"winlogbeat","id":"WEC-Powershell","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.715-0500","log.logger":"eventlog","log.origin":{"file.name":"eventlog/wineventlog.go","file.line":348},"message":"WinEventLog[WEC-Powershell] Closing handle","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.715-0500","log.logger":"eventlog","log.origin":{"file.name":"eventlog/wineventlog.go","file.line":228},"message":"WinEventLog[WEC4-Shares] using subscription query=<QueryList>\n  <Query Id=\"0\">\n    <Select Path=\"WEC4-Shares\">*[System[TimeCreated[timediff(@SystemTime) &lt;= 604800000]]]</Select>\n  </Query>\n</QueryList>","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":154},"message":"client: closing acker","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":159},"message":"client: done closing acker","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":161},"message":"client: unlink from queue","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":183},"message":"client: cancelled 0 events","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":163},"message":"client: done unlink","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":166},"message":"client: closing processors","service.name":"winlogbeat","ecs.version":"1.6.0"}
{"log.level":"debug","@timestamp":"2023-05-03T14:25:45.716-0500","log.logger":"publisher","log.origin":{"file.name":"pipeline/client.go","file.line":171},"message":"client: done closing processors","service.name":"winlogbeat","ecs.version":"1.6.0"}

• Version: 8.6.2+
• Operating System: Windows Server 2022 Standard build 20348

[elasticmachine]

Pinging @elastic/security-external-integrations (Team:Security-External Integrations)

[elasticmachine]

Pinging @elastic/sec-windows-platform (Team:Security-Windows Platform)