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.

Sign up for GitHub

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

Jump to bottom

pkg/component/runtime.TestManager_FakeShipper test is flaky #2301

Closed
cmacknz opened this issue Feb 21, 2023 · 0 comments · Fixed by #2483
Closed

pkg/component/runtime.TestManager_FakeShipper test is flaky #2301

cmacknz opened this issue Feb 21, 2023 · 0 comments · Fixed by #2483
Assignees
@blakerouse
Labels
bug Something isn't working flaky-test Unstable or unreliable test cases. Team:Elastic-Agent Label for the Agent team v8.7.0

Comments

@cmacknz
Copy link
Member

cmacknz commented Feb 21, 2023

Recent example failures, which occur primarily on Windows:

=== RUN   TestManager_FakeShipper
    manager_test.go:2274: component state changed: {State:STARTING Message:Starting: spawned pid '508' Units:map[{UnitType:input UnitID:fake-input}:{State:STARTING Message:Starting: spawned pid '508' Payload:map[] unitState:0 unitMessage:Starting unitPayload:map[] configStateIdx:0 err:<nil>} {UnitType:output UnitID:fake-default}:{State:STARTING Message:Starting: spawned pid '508' Payload:map[] unitState:0 unitMessage:Starting unitPayload:map[] configStateIdx:0 err:<nil>}] VersionInfo:{Name: Version: Meta:map[]} expectedUnits:map[{UnitType:0 UnitID:fake-input}:{state:2 configStateIdx:1 config:0xc0001a0240 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a01b0 err:<nil> logLevel:4}]}
    manager_test.go:2239: shipper state changed: {State:STARTING Message:Starting: spawned pid '1252' Units:map[{UnitType:input UnitID:fake-default}:{State:STARTING Message:Starting: spawned pid '1252' Payload:map[] unitState:0 unitMessage:Starting unitPayload:map[] configStateIdx:0 err:<nil>} {UnitType:output UnitID:fake-default}:{State:STARTING Message:Starting: spawned pid '1252' Payload:map[] unitState:0 unitMessage:Starting unitPayload:map[] configStateIdx:0 err:<nil>}] VersionInfo:{Name: Version: Meta:map[]} expectedUnits:map[{UnitType:0 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a0120 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a03f0 err:<nil> logLevel:4}]}
    manager_test.go:2274: component state changed: {State:HEALTHY Message:Healthy: communicating with pid '508' Units:map[{UnitType:input UnitID:fake-input}:{State:STARTING Message:Starting: spawned pid '508' Payload:map[] unitState:0 unitMessage: unitPayload:map[] configStateIdx:0 err:<nil>} {UnitType:output UnitID:fake-default}:{State:STARTING Message:Starting: spawned pid '508' Payload:map[] unitState:0 unitMessage: unitPayload:map[] configStateIdx:0 err:<nil>}] VersionInfo:{Name:fake Version:1.0 Meta:map[input:fake]} expectedUnits:map[{UnitType:0 UnitID:fake-input}:{state:2 configStateIdx:1 config:0xc0001a0240 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a01b0 err:<nil> logLevel:4}]}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering kill action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering set_state action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering send_event action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering kill action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"state":"HEALTHY","message":"updating unit state","time":"2023-02-21T20:09:16Z","level":"debug","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"trace","kill_on_interval":false,"time":"2023-02-21T20:09:16Z","message":"kill_on_interval config set value","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"info","time":"2023-02-21T20:09:16Z","message":"stopping interval killer","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"state":"CONFIGURING","message":"restarting shipper output","time":"2023-02-21T20:09:16Z","level":"debug","ecs.version":"1.6.0"}
    manager_test.go:2274: component state changed: {State:HEALTHY Message:Healthy: communicating with pid '508' Units:map[{UnitType:input UnitID:fake-input}:{State:HEALTHY Message:Fake Healthy Payload:map[] unitState:2 unitMessage:Fake Healthy unitPayload:map[] configStateIdx:1 err:<nil>} {UnitType:output UnitID:fake-default}:{State:CONFIGURING Message:Configuring Payload:map[] unitState:1 unitMessage:Configuring unitPayload:map[] configStateIdx:1 err:<nil>}] VersionInfo:{Name:fake Version:1.0 Meta:map[input:fake]} expectedUnits:map[{UnitType:0 UnitID:fake-input}:{state:2 configStateIdx:1 config:0xc0001a0240 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a01b0 err:<nil> logLevel:4}]}
    manager_test.go:2274: component state changed: {State:HEALTHY Message:Healthy: communicating with pid '508' Units:map[{UnitType:input UnitID:fake-input}:{State:HEALTHY Message:Fake Healthy Payload:map[] unitState:2 unitMessage:Fake Healthy unitPayload:map[] configStateIdx:1 err:<nil>} {UnitType:output UnitID:fake-default}:{State:HEALTHY Message:GRPC fake event pipe connected "\\\\.\\pipe\\elastic-agent-db5498662e32325f542ba491b5f0733bcf583443e8d95fc7a44a7aa00c9cf447-fake-shipper-default-pipe" Payload:map[] unitState:2 unitMessage:GRPC fake event pipe connected "\\\\.\\pipe\\elastic-agent-db5498662e32325f542ba491b5f0733bcf583443e8d95fc7a44a7aa00c9cf447-fake-shipper-default-pipe" unitPayload:map[] configStateIdx:1 err:<nil>}] VersionInfo:{Name:fake Version:1.0 Meta:map[input:fake]} expectedUnits:map[{UnitType:0 UnitID:fake-input}:{state:2 configStateIdx:1 config:0xc0001a0240 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a01b0 err:<nil> logLevel:4}]}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"message":"connected to output","time":"2023-02-21T20:09:16Z","level":"debug","state":"HEALTHY","ecs.version":"1.6.0"}
    manager_test.go:2239: shipper state changed: {State:HEALTHY Message:Healthy: communicating with pid '1252' Units:map[{UnitType:input UnitID:fake-default}:{State:STARTING Message:Starting: spawned pid '1252' Payload:map[] unitState:0 unitMessage: unitPayload:map[] configStateIdx:0 err:<nil>} {UnitType:output UnitID:fake-default}:{State:STARTING Message:Starting: spawned pid '1252' Payload:map[] unitState:0 unitMessage: unitPayload:map[] configStateIdx:0 err:<nil>}] VersionInfo:{Name:fake-shipper Version:1.0 Meta:map[shipper:fake-shipper]} expectedUnits:map[{UnitType:0 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a0120 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a03f0 err:<nil> logLevel:4}]}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"info","server":"\\\\.\\pipe\\elastic-agent-db5498662e32325f542ba491b5f0733bcf583443e8d95fc7a44a7aa00c9cf447-fake-shipper-default-pipe","time":"2023-02-21T20:09:16Z","message":"starting GRPC fake shipper server","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering kill action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"debug","state":"HEALTHY","message":"updating unit state","time":"2023-02-21T20:09:16Z","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering record event action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","time":"2023-02-21T20:09:16Z","message":"registering kill action for unit","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"debug","state":"HEALTHY","message":"updating unit state","time":"2023-02-21T20:09:16Z","ecs.version":"1.6.0"}
    manager_test.go:2239: shipper state changed: {State:HEALTHY Message:Healthy: communicating with pid '1252' Units:map[{UnitType:input UnitID:fake-default}:{State:HEALTHY Message:Healthy Payload:map[] unitState:2 unitMessage:Healthy unitPayload:map[] configStateIdx:1 err:<nil>} {UnitType:output UnitID:fake-default}:{State:STARTING Message:Starting Payload:map[] unitState:0 unitMessage:Starting unitPayload:map[] configStateIdx:1 err:<nil>}] VersionInfo:{Name:fake-shipper Version:1.0 Meta:map[shipper:fake-shipper]} expectedUnits:map[{UnitType:0 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a0120 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a03f0 err:<nil> logLevel:4}]}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"time":"2023-02-21T20:09:16Z","message":"registering record event action","level":"trace","id":"6617ee0c-ed4d-496c-88cb-2fc2076b6c46","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","id":"6617ee0c-ed4d-496c-88cb-2fc2076b6c46","time":"2023-02-21T20:09:16Z","message":"subscribing for an event","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"message":"executing send_event action","level":"trace","time":"2023-02-21T20:09:16Z","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","content":{"id":"6617ee0c-ed4d-496c-88cb-2fc2076b6c46"},"timestamp":"2023-02-21T20:09:16Z","time":"2023-02-21T20:09:17Z","message":"received event","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","id":"6617ee0c-ed4d-496c-88cb-2fc2076b6c46","time":"2023-02-21T20:09:17Z","message":"subscription exists for event id","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","content":{"id":"6617ee0c-ed4d-496c-88cb-2fc2076b6c46"},"timestamp":"2023-02-21T20:09:16Z","time":"2023-02-21T20:09:17Z","message":"record_event action got subscribed event","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-shipper-default","type":"fake-shipper"},"log":{"source":"fake-shipper-default"},"level":"trace","id":"6617ee0c-ed4d-496c-88cb-2fc2076b6c46","time":"2023-02-21T20:09:17Z","message":"unsubscribing for an event","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"time":"2023-02-21T20:09:26Z","message":"trace log ticker","level":"trace","log_timer":10000,"ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"message":"trace log ticker","level":"trace","log_timer":10000,"time":"2023-02-21T20:09:36Z","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"0000-01-01T00:00:00.000Z","message":"","component":{"binary":"","dataset":"elastic_agent.","id":"fake-default","type":"fake"},"log":{"source":"fake-default"},"level":"trace","log_timer":10000,"time":"2023-02-21T20:09:46Z","message":"trace log ticker","ecs.version":"1.6.0"}
    manager_test.go:2239: shipper state changed: {State:HEALTHY Message:Healthy: communicating with pid '1252' Units:map[{UnitType:input UnitID:fake-default}:{State:HEALTHY Message:Healthy Payload:map[] unitState:2 unitMessage:Healthy unitPayload:map[] configStateIdx:1 err:<nil>} {UnitType:output UnitID:fake-default}:{State:HEALTHY Message:Healthy Payload:map[] unitState:2 unitMessage:Healthy unitPayload:map[] configStateIdx:1 err:<nil>}] VersionInfo:{Name:fake-shipper Version:1.0 Meta:map[shipper:fake-shipper]} expectedUnits:map[{UnitType:0 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a0120 err:<nil> logLevel:4} {UnitType:1 UnitID:fake-default}:{state:2 configStateIdx:1 config:0xc0001a03f0 err:<nil> logLevel:4}]}
    manager_test.go:2335: 
        	Error Trace:	manager_test.go:2335
        	Error:      	Received unexpected error:
        	            	context deadline exceeded
        	Test:       	TestManager_FakeShipper
--- FAIL: TestManager_FakeShipper (32.45s)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@blakerouse blakerouse

Labels
bug Something isn't working flaky-test Unstable or unreliable test cases. Team:Elastic-Agent Label for the Agent team v8.7.0
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix TestManager_FakeShipper flakiness. blakerouse/elastic-agent
2 participants
@cmacknz @blakerouse