Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

winlogbeat: windows-11 TestPublisherMetadata/Windows_Error_Reporting/event_metadata – github.com/elastic/beats/v7/winlogbeat/sys/wineventlog #32468

Closed
v1v opened this issue Jul 22, 2022 · 4 comments · Fixed by #32519
Labels
flaky-test Unstable or unreliable test cases.

Comments

@v1v
Copy link
Member

v1v commented Jul 22, 2022

Flaky Test

  • Test Name: TestPublisherMetadata/Windows_Error_Reporting/event_metadata – github.com/elastic/beats/v7/winlogbeat/sys/wineventlog
  • Link: Link to file/line number in github.
  • Branch: ci: add extended support for windows-11 #32236
  • Artifact Link: If available, attach the generated zip artifact associated with the stack trace for this failure.
  • Notes: Additional details about the test. e.g. theory as to failure cause

Stack Trace

 === RUN   TestPublisherMetadata/Windows_Error_Reporting/event_metadata
    publisher_metadata_test.go:173: The system cannot find the file specified.
        failed to open event metadata enumerator with EvtOpenEventMetadataEnum
        github.com/elastic/beats/v7/winlogbeat/sys/wineventlog.NewEventMetadataIterator
        	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/src/github.com/elastic/beats/winlogbeat/sys/wineventlog/publisher_metadata.go:552
        github.com/elastic/beats/v7/winlogbeat/sys/wineventlog.(*PublisherMetadata).EventMetadataIterator
        	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/src/github.com/elastic/beats/winlogbeat/sys/wineventlog/publisher_metadata.go:157
        github.com/elastic/beats/v7/winlogbeat/sys/wineventlog.testPublisherMetadata.func1.13
        	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/src/github.com/elastic/beats/winlogbeat/sys/wineventlog/publisher_metadata_test.go:171
        testing.tRunner
        	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/.gvm/versions/go1.17.11.windows.amd64/src/testing/testing.go:1259
        runtime.goexit
        	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/.gvm/versions/go1.17.11.windows.amd64/src/runtime/asm_amd64.s:1581
        --- FAIL: TestPublisherMetadata/Windows_Error_Reporting/event_metadata (0.00s)
@v1v v1v added the flaky-test Unstable or unreliable test cases. label Jul 22, 2022
@botelastic botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Jul 22, 2022
@v1v
Copy link
Member Author

v1v commented Jul 22, 2022

Build output

[2022-07-07T13:44:32.019Z] 
[2022-07-07T13:44:32.019Z] C:\Users\jenkins\workspace\PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe\src\github.com\elastic\beats\winlogbeat>mage build unitTest 
[2022-07-07T13:44:50.284Z] >> build: Building winlogbeat
[2022-07-07T13:44:58.955Z] Generated fields.yml for winlogbeat to C:\Users\jenkins\workspace\PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe\src\github.com\elastic\beats\winlogbeat\build\fields\fields.yml
[2022-07-07T13:44:58.955Z] Generated fields.yml for winlogbeat to C:\Users\jenkins\workspace\PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe\src\github.com\elastic\beats\winlogbeat\build\fields\fields.common.yml
[2022-07-07T13:44:58.955Z] Generated fields.yml for winlogbeat to C:\Users\jenkins\workspace\PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe\src\github.com\elastic\beats\winlogbeat\build\fields\fields.all.yml
[2022-07-07T13:45:01.070Z] >> go test: Unit Testing
[2022-07-07T13:45:01.070Z] exec: gotestsum --no-color -f standard-quiet --junitfile build/TEST-go-unit.xml --jsonfile build/TEST-go-unit.out.json -- -tags null oracle -covermode=atomic -coverprofile=build\TEST-go-unit.cov ./...
[2022-07-07T13:45:05.684Z] ok  	github.com/elastic/beats/v7/winlogbeat/config	0.708s	coverage: 100.0% of statements
[2022-07-07T13:45:05.952Z] ok  	github.com/elastic/beats/v7/winlogbeat/sys	0.605s	coverage: 65.7% of statements
[2022-07-07T13:45:06.222Z] ok  	github.com/elastic/beats/v7/winlogbeat/sys/winevent	0.624s	coverage: 59.5% of statements
[2022-07-07T13:45:07.167Z] ok  	github.com/elastic/beats/v7/winlogbeat/beater	0.787s	coverage: 6.9% of statements
[2022-07-07T13:45:08.554Z] ok  	github.com/elastic/beats/v7/winlogbeat	0.278s	coverage: 0.0% of statements
[2022-07-07T13:45:09.937Z] FAIL
[2022-07-07T13:45:09.937Z] FAIL	github.com/elastic/beats/v7/winlogbeat/sys/wineventlog	3.480s
[2022-07-07T13:45:10.878Z] ok  	github.com/elastic/beats/v7/winlogbeat/checkpoint	5.816s	coverage: 75.5% of statements
[2022-07-07T13:45:10.878Z] ?   	github.com/elastic/beats/v7/winlogbeat/cmd	[no test files]
[2022-07-07T13:45:11.822Z] ok  	github.com/elastic/beats/v7/winlogbeat/eventlog	6.242s	coverage: 62.6% of statements
[2022-07-07T13:45:11.822Z] ?   	github.com/elastic/beats/v7/winlogbeat/include	[no test files]
[2022-07-07T13:45:11.822Z] ?   	github.com/elastic/beats/v7/winlogbeat/module	[no test files]
[2022-07-07T13:45:11.822Z] ?   	github.com/elastic/beats/v7/winlogbeat/scripts/mage	[no test files]
[2022-07-07T13:45:12.080Z] 
[2022-07-07T13:45:12.080Z] === Skipped
[2022-07-07T13:45:12.080Z] === SKIP: winlogbeat/eventlog TestBenchmarkRead (0.00s)
[2022-07-07T13:45:12.080Z]     bench_test.go:50: -benchtest not enabled
[2022-07-07T13:45:12.080Z] 
[2022-07-07T13:45:12.080Z] === SKIP: winlogbeat/sys/wineventlog TestFormatMessage/getMessageStringFromHandle/no_metadata (0.00s)
[2022-07-07T13:45:12.080Z]     format_message_test.go:45: This currently fails under Win10. The message strings are returned even though no metadata is passed.
[2022-07-07T13:45:12.080Z]         --- SKIP: TestFormatMessage/getMessageStringFromHandle/no_metadata (0.00s)
[2022-07-07T13:45:12.080Z] 
[2022-07-07T13:45:12.080Z] === SKIP: winlogbeat/sys/wineventlog TestFormatMessage/getEventXML/no_metadata (0.00s)
[2022-07-07T13:45:12.080Z]     format_message_test.go:143: This currently fails under Win10. The event XML is returned even though no metadata is passed.
[2022-07-07T13:45:12.080Z]         --- SKIP: TestFormatMessage/getEventXML/no_metadata (0.00s)
[2022-07-07T13:45:12.080Z] 
[2022-07-07T13:45:12.080Z] === Failed
[2022-07-07T13:45:12.080Z] === FAIL: winlogbeat/sys/wineventlog TestPublisherMetadata/Windows_Error_Reporting/event_metadata (0.00s)
[2022-07-07T13:45:12.080Z]     publisher_metadata_test.go:173: The system cannot find the file specified.
[2022-07-07T13:45:12.080Z]         failed to open event metadata enumerator with EvtOpenEventMetadataEnum
[2022-07-07T13:45:12.080Z]         github.com/elastic/beats/v7/winlogbeat/sys/wineventlog.NewEventMetadataIterator
[2022-07-07T13:45:12.080Z]         	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/src/github.com/elastic/beats/winlogbeat/sys/wineventlog/publisher_metadata.go:552
[2022-07-07T13:45:12.080Z]         github.com/elastic/beats/v7/winlogbeat/sys/wineventlog.(*PublisherMetadata).EventMetadataIterator
[2022-07-07T13:45:12.080Z]         	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/src/github.com/elastic/beats/winlogbeat/sys/wineventlog/publisher_metadata.go:157
[2022-07-07T13:45:12.080Z]         github.com/elastic/beats/v7/winlogbeat/sys/wineventlog.testPublisherMetadata.func1.13
[2022-07-07T13:45:12.080Z]         	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/src/github.com/elastic/beats/winlogbeat/sys/wineventlog/publisher_metadata_test.go:171
[2022-07-07T13:45:12.080Z]         testing.tRunner
[2022-07-07T13:45:12.080Z]         	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/.gvm/versions/go1.17.11.windows.amd64/src/testing/testing.go:1259
[2022-07-07T13:45:12.080Z]         runtime.goexit
[2022-07-07T13:45:12.080Z]         	C:/Users/jenkins/workspace/PR-32236-3-110895e7-0089-4aab-8a7c-d09e035e6afe/.gvm/versions/go1.17.11.windows.amd64/src/runtime/asm_amd64.s:1581
[2022-07-07T13:45:12.080Z]         --- FAIL: TestPublisherMetadata/Windows_Error_Reporting/event_metadata (0.00s)
[2022-07-07T13:45:12.080Z] 
[2022-07-07T13:45:12.080Z] === FAIL: winlogbeat/sys/wineventlog TestPublisherMetadata/Windows_Error_Reporting (0.05s)
[2022-07-07T13:45:12.081Z]     --- FAIL: TestPublisherMetadata/Windows_Error_Reporting (0.05s)
[2022-07-07T13:45:12.081Z] 
[2022-07-07T13:45:12.081Z] === FAIL: winlogbeat/sys/wineventlog TestPublisherMetadata (0.18s)
[2022-07-07T13:45:12.081Z] 
[2022-07-07T13:45:12.081Z] === FAIL: winlogbeat/sys/wineventlog TestRenderer/application-windows-error-reporting.evtx (0.03s)
[2022-07-07T13:45:12.081Z] {"log.level":"debug","@timestamp":"2022-07-07T13:45:09.943Z","log.logger":"renderer","log.origin":{"file.name":"wineventlog/metadata_store.go","file.line":261},"message":"Obtained unique event metadata from event handle. It differed from what was listed in the publisher's metadata.","publisher":"Windows Error Reporting","empty":true,"event_id":1001,"fingerprint":13417913915764132552,"default_event_metadata":null,"event_metadata":{"EventID":1001,"Version":0,"MsgStatic":"","EventData":[{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""},{"Name":"Data","InType":"","OutType":""}]},"ecs.version":"1.6.0"}
[2022-07-07T13:45:12.081Z] {"log.level":"debug","@timestamp":"2022-07-07T13:45:09.943Z","log.logger":"renderer","log.origin":{"file.name":"wineventlog/renderer.go","file.line":379},"message":"Falling back to EvtFormatMessage for event ID 1001.","ecs.version":"1.6.0"}
[2022-07-07T13:45:12.081Z]     renderer_test.go:188: Render failed: failed to load publisher metadata for Windows Error Reporting (returning an empty metadata store): failed to open event metadata enumerator with EvtOpenEventMetadataEnum: The system cannot find the file specified.
[2022-07-07T13:45:12.081Z]     --- FAIL: TestRenderer/application-windows-error-reporting.evtx (0.03s)
[2022-07-07T13:45:12.081Z] 
[2022-07-07T13:45:12.081Z] === FAIL: winlogbeat/sys/wineventlog TestRenderer (0.50s)
[2022-07-07T13:45:12.081Z] 
[2022-07-07T13:45:12.081Z] DONE 173 tests, 3 skipped, 5 failures in 11.042s
[2022-07-07T13:45:12.081Z] Error: failed to execute go: exit status 1
script returned exit code 1

@elasticmachine
Copy link
Collaborator

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

@botelastic botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Jul 25, 2022
@andrewkroh
Copy link
Member

andrewkroh commented Jul 26, 2022

It fails when dealing with "Windows Error Reporting".

// Classic without message metadata (no event-data XML templates).
testPublisherMetadata(t, "Windows Error Reporting")

According to the comment, this source did not have any message metadata. So possibly the behavior of EvtOpenEventMetadataEnum has changed to return an error when there is no message metadata.

On Windows 11 I would look at wevtutil output for this publisher. Like wevtutil.exe get-publisher "Windows Event Reporting" /f:xml /ge /gm. I would confirm that the comment is still true (no message metadata exists).

If this wasn't returning an error previously when there were no messages then maybe this is an error that we want to handle in EventMessageIterator() to keep the same behavior for our internal APIs?

@efd6
Copy link
Contributor

efd6 commented Jul 27, 2022

PS C:\Gopath\src\github.com\elastic\beats> wevtutil.exe get-publisher "Windows Event Reporting" /f:xml /ge /gm
Failed to open metadata for publisher Windows Event Reporting.
The system cannot find the file specified.

(This is consistent across 2019, 2022 and 11).

Looking into squelching the error in the iterator construction.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
flaky-test Unstable or unreliable test cases.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants