`TestIntegrations/AuditOn` flakiness #17224

tigrato · 2022-10-10T16:21:30Z

Failure

Link(s) to logs

https://console.cloud.google.com/cloud-build/builds/b4e20fae-f01e-4f8c-841f-3d7d33257efe?project=ci-account

Relevant snippet

{"caller":"regular/sshserver.go:1864","component":null,"level":"debug","message":"Received \"keepalive@openssh.com\": WantReply: true","timestamp":"2022-10-10T15:54:30Z"}
{"caller":"srv/sess.go:916","component":"session:node","level":"debug","message":"Copying from PTY to writer completed with error read /dev/ptmx: input/output error.","timestamp":"2022-10-10T15:54:30Z"}
{"caller":"regular/sshserver.go:1875","component":null,"level":"debug","message":"Replied to \"keepalive@openssh.com\"","timestamp":"2022-10-10T15:54:30Z"}
{"caller":"events/discard.go:99","component":null,"event_id":"","event_index":0,"event_time":"0001-01-01T00:00:00Z","event_type":"session.end","level":"debug","message":"Discarding stream event","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:622","component":"session:node","level":"info","message":"Stopping session 1b59d2dc-40d4-4e83-92ab-681f8cb90b59.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:651","component":"session:node","level":"info","message":"Closing session 1b59d2dc-40d4-4e83-92ab-681f8cb90b59.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:1586","component":"session:node","level":"info","message":"Closing party 624bdc74-987f-4285-a2de-082ecba3f7f5","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:1246","component":"session:node","level":"info","message":"Removing party ServerContext(127.0.0.1:35714-\u003e127.0.0.1:36325, user=ci, id=24) party(id=624bdc74-987f-4285-a2de-082ecba3f7f5) from session 1b59d2dc-40d4-4e83-92ab-681f8cb90b59","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:1254","component":"session:node","level":"debug","message":"No longer tracking participant: 624bdc74-987f-4285-a2de-082ecba3f7f5","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"events/discard.go:99","component":null,"event_id":"","event_index":0,"event_time":"0001-01-01T00:00:00Z","event_type":"session.leave","level":"debug","message":"Discarding stream event","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"regular/sshserver.go:1581","component":"node","level":"debug","message":"Exec request (\"/proc/self/exe\") complete: 0","timestamp":"2022-10-10T15:54:31Z","trace.fields":{"id":24,"local":{"IP":"127.0.0.1","Port":36325,"Zone":""},"login":"ci","remote":{"IP":"127.0.0.1","Port":35714,"Zone":""},"teleportUser":"ci"}}
{"caller":"srv/sess.go:924","component":"session:node","level":"debug","message":"Copying from reader to PTY completed with error \u003cnil\u003e.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"regular/sshserver.go:1587","component":"node","level":"info","message":"Failed to send exit status for /proc/self/exe: EOF","timestamp":"2022-10-10T15:54:31Z","trace.fields":{"id":24,"local":{"IP":"127.0.0.1","Port":36325,"Zone":""},"login":"ci","remote":{"IP":"127.0.0.1","Port":35714,"Zone":""},"teleportUser":"ci"}}
{"caller":"srv/monitor.go:253","component":"node","level":"debug","message":"Releasing associated resources - context has been closed.","timestamp":"2022-10-10T15:54:31Z","trace.fields":{"id":24,"local":{"IP":"127.0.0.1","Port":36325,"Zone":""},"login":"ci","remote":{"IP":"127.0.0.1","Port":35714,"Zone":""},"teleportUser":"ci"}}
{"caller":"srv/sess.go:995","component":"node:forward","level":"error","message":"Received error waiting for the interactive session d5837350-35a5-401f-b411-5f9b08b97122 to finish: wait: remote command exited without exit status or exit signal.","timestamp":"2022-10-10T15:54:31Z","trace.fields":{"id":23,"local":{"addr":"127.0.0.1:36325","network":"tcp"},"login":"ci","remote":{"IP":"127.0.0.1","Port":51574,"Zone":""},"teleportUser":"ci"}}
{"caller":"srv/sess.go:916","component":"session:node:forward","level":"debug","message":"Copying from PTY to writer completed with error \u003cnil\u003e.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:1450","component":"session:node","level":"debug","message":"Copying from Party 624bdc74-987f-4285-a2de-082ecba3f7f5 to session writer completed with error \u003cnil\u003e.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:622","component":"session:node:forward","level":"info","message":"Stopping session d5837350-35a5-401f-b411-5f9b08b97122.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:630","component":"session:node:forward","error":"EOF","level":"debug","message":"Failed to close the shell","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:633","component":"session:node:forward","error":"EOF","level":"debug","message":"Failed to kill the shell","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/term.go:299","component":"term:local","level":"debug","message":"Closed PTY","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"srv/sess.go:924","component":"session:node:forward","level":"debug","message":"Copying from reader to PTY completed with error \u003cnil\u003e.","timestamp":"2022-10-10T15:54:31Z"}
{"caller":"forward/sshserver.go:979","component":"node:forward","level":"debug","message":"Exec request (\"\") complete: 255","timestamp":"2022-10-10T15:54:31Z","trace.fields":{"id":23,"local":{"addr":"127.0.0.1:36325","network":"tcp"},"login":"ci","remote":{"IP":"127.0.0.1","Port":51574,"Zone":""},"teleportUser":"ci"}}
{"caller":"forward/sshserver.go:988","component":"node:forward","level":"debug","message":"Closing session request to 127.0.0.1:51574 in context 23.","timestamp":"2022-10-10T15:54:31Z","trace.fields":{"dst-addr":"127.0.0.1:36325","src-addr":"127.0.0.1:51574"}}
    integration_test.go:444: 
        	Error Trace:	/workspace/integration/integration_test.go:444
        	Error:      	Received unexpected error:
        	            	Process exited with status 255
        	Test:       	TestIntegrations/AuditOn/recording_proxy,_sync_recording
{"caller":"service/supervisor.go:383","component":"proc:16","event":"TeleportExit","l

The text was updated successfully, but these errors were encountered:

zmb3 · 2022-10-12T21:51:49Z

@espadolini could this just be racy shutdown behavior? The error that the ssh.node service is returning is context.Canceled, which happens as a result of the call to *TeleInstance.StopAll() when the test is shutting down.

ibeckermayer · 2022-10-14T20:14:27Z

https://console.cloud.google.com/cloud-build/builds/d5fffc6e-fc0f-48b3-bc15-f2efb9e7f8d4?project=ci-account

        	Test:       	TestIntegrations/AuditOn/recording_proxy
        	            	Process exited with status 255
        	Error:      	Received unexpected error:
        	Error Trace:	/workspace/integration/integration_test.go:444
    integration_test.go:444:

zmb3 · 2022-10-17T14:47:26Z

Looks like this started with https://github.com/gravitational/teleport/pull/16953/files

An error that previously went unchecked is now being checked.

espadolini · 2022-10-17T17:24:57Z

Seems to be some race in how we clean up sessions?

tigrato · 2022-10-19T17:30:12Z

https://console.cloud.google.com/cloud-build/builds/7af62c55-65c0-4049-bb53-a50ebb609473?project=ci-account

Today is being particularly difficult for this test to pass. It's about the tenth time it fails

ibeckermayer · 2022-10-19T17:44:35Z

https://console.cloud.google.com/cloud-build/builds/0fb3304e-97d9-4f7a-8f70-cc28afdd66a3?project=ci-account

ibeckermayer · 2022-10-21T20:38:28Z

https://console.cloud.google.com/cloud-build/builds/970c87a2-cff7-4930-8d6e-549128ee7fa4?project=ci-account

ibeckermayer · 2022-10-21T23:36:42Z

https://console.cloud.google.com/cloud-build/builds/48d4caa9-5acc-47a1-97f0-a9792fdf47ff?project=ci-account

ibeckermayer · 2022-10-21T23:39:35Z

@Joerger You vanquished this one in #12101 a while back, any ideas as to why it might be acting up again?

zmb3 · 2022-11-17T19:29:33Z

@jakule good to close this one?

jakule · 2022-11-17T19:49:12Z

Closing. Looks like #17687 fixed the issue.

jakule · 2023-10-05T20:30:58Z

It survived almost a year.... 😢
Failing build https://github.com/gravitational/teleport/actions/runs/6419752754/job/17430271963

{"caller":"auth/auth.go:1190","component":"auth","level":"debug","message":"Checking for new teleport releases via github api.","timestamp":"2023-10-05T13:34:49Z"}
    integration_test.go:498: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:498
        	Error:      	Received unexpected error:
        	            	context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/recording_proxy_with_upload_to_file_server
{"caller":"sshutils/server.go:425","component":"ssh:node","level":"debug","message":"Server 127.0.0.1:45281 has closed.","timestamp":"2023-10-05T13:34:54Z"}

zmb3 · 2023-10-18T20:36:21Z

https://github.com/gravitational/teleport/actions/runs/6564546618/job/17831123007

Same failure here. @jakule or @Joerger any ideas?

nklaassen · 2023-11-30T18:02:33Z

another in v14 merge queue https://github.com/gravitational/teleport/actions/runs/7050209642/job/19190382930

nklaassen · 2023-12-04T17:03:27Z

another hit off master https://github.com/gravitational/teleport/actions/runs/7066054434/job/19263411490

=== RUN   TestIntegrations/AuditOn/normal_teleport_with_upload_to_file_server
    integration_test.go:500: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:500
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/normal_teleport_with_upload_to_file_server
        --- FAIL: TestIntegrations/AuditOn/normal_teleport_with_upload_to_file_server (12.98s)

ptgott · 2023-12-12T21:44:39Z

Another: https://github.com/gravitational/teleport/actions/runs/7187322895/job/19574643836

ptgott · 2023-12-27T17:32:27Z

Another: https://github.com/gravitational/teleport/actions/runs/7339759493/job/19984550852#step:6:1679

zmb3 · 2024-01-10T17:03:58Z

v14: https://github.com/gravitational/teleport/actions/runs/7477999541/job/20351955564?pr=36516

    integration_test.go:500: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:500
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/recording_proxy_with_upload_to_file_server

ravicious · 2024-04-25T14:40:46Z

v14 https://github.com/gravitational/teleport/actions/runs/8834247032/job/24255465293#step:6:1026

     integration_test.go:504: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:504
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/normal_teleport

ravicious · 2024-06-03T16:30:55Z

v14 https://github.com/gravitational/teleport/actions/runs/9353591579/job/25744470753#step:6:996

    integration_test.go:504: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:504
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/recording_proxy_with_upload_to_file_server

nklaassen · 2024-08-13T17:41:16Z

I think this is still flaky

    integration_test.go:503: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:503
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/recording_proxy,_sync_recording

https://github.com/gravitational/teleport/actions/runs/10374191024/job/28721090769

rosstimothy · 2024-12-12T14:25:32Z

https://github.com/gravitational/teleport/actions/runs/12298031648/job/34320565286

        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:488
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/recording_proxy_with_upload_to_file_server

hugoShaka · 2024-12-17T21:25:04Z

https://github.com/gravitational/teleport/actions/runs/12379575184/job/34554038491?pr=49737#step:6:1512

    integration_test.go:488: 
        	Error Trace:	/__w/teleport/teleport/integration/integration_test.go:488
        	Error:      	Received unexpected error:
        	            	rpc error: code = DeadlineExceeded desc = context deadline exceeded
        	Test:       	TestIntegrations/AuditOn/normal_teleport

tigrato added the flaky tests label Oct 10, 2022

tigrato mentioned this issue Oct 10, 2022

Flaky Test Tracker #9492

Closed

jakule self-assigned this Nov 10, 2022

jakule closed this as completed Nov 17, 2022

jakule reopened this Oct 5, 2023

rosstimothy linked a pull request Aug 9, 2024 that will close this issue

Prevent exiting a session prior to output being consumed #45223

Merged

rosstimothy mentioned this issue Aug 9, 2024

Prevent exiting a session prior to output being consumed #45223

Merged

rosstimothy closed this as completed in #45223 Aug 12, 2024

nklaassen reopened this Aug 13, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`TestIntegrations/AuditOn` flakiness #17224

`TestIntegrations/AuditOn` flakiness #17224

tigrato commented Oct 10, 2022

zmb3 commented Oct 12, 2022

ibeckermayer commented Oct 14, 2022

zmb3 commented Oct 17, 2022

espadolini commented Oct 17, 2022

tigrato commented Oct 19, 2022

ibeckermayer commented Oct 19, 2022

ibeckermayer commented Oct 21, 2022

ibeckermayer commented Oct 21, 2022

ibeckermayer commented Oct 21, 2022

zmb3 commented Nov 17, 2022

jakule commented Nov 17, 2022

jakule commented Oct 5, 2023

zmb3 commented Oct 18, 2023

nklaassen commented Nov 30, 2023

nklaassen commented Dec 4, 2023

ptgott commented Dec 12, 2023

ptgott commented Dec 27, 2023

zmb3 commented Jan 10, 2024

ravicious commented Apr 25, 2024

ravicious commented Jun 3, 2024

nklaassen commented Aug 13, 2024

rosstimothy commented Dec 12, 2024 •

edited

Loading

hugoShaka commented Dec 17, 2024

TestIntegrations/AuditOn flakiness #17224

TestIntegrations/AuditOn flakiness #17224

Comments

tigrato commented Oct 10, 2022

Failure

Link(s) to logs

Relevant snippet

zmb3 commented Oct 12, 2022

ibeckermayer commented Oct 14, 2022

zmb3 commented Oct 17, 2022

espadolini commented Oct 17, 2022

tigrato commented Oct 19, 2022

ibeckermayer commented Oct 19, 2022

ibeckermayer commented Oct 21, 2022

ibeckermayer commented Oct 21, 2022

ibeckermayer commented Oct 21, 2022

zmb3 commented Nov 17, 2022

jakule commented Nov 17, 2022

jakule commented Oct 5, 2023

zmb3 commented Oct 18, 2023

nklaassen commented Nov 30, 2023

nklaassen commented Dec 4, 2023

ptgott commented Dec 12, 2023

ptgott commented Dec 27, 2023

zmb3 commented Jan 10, 2024

ravicious commented Apr 25, 2024

ravicious commented Jun 3, 2024

nklaassen commented Aug 13, 2024

rosstimothy commented Dec 12, 2024 • edited Loading

hugoShaka commented Dec 17, 2024

`TestIntegrations/AuditOn` flakiness #17224

`TestIntegrations/AuditOn` flakiness #17224

rosstimothy commented Dec 12, 2024 •

edited

Loading