Skip to content

flake: TestNewServer_CloseActiveConnections/Shutdown #558

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
Closed
sreya opened this issue Apr 4, 2025 · 3 comments · Fixed by coder/coder#17271 or coder/coder#17313
Closed

flake: TestNewServer_CloseActiveConnections/Shutdown #558

sreya opened this issue Apr 4, 2025 · 3 comments · Fixed by coder/coder#17271 or coder/coder#17313
Assignees
@mafredri
Labels
flake

Comments

@sreya
Copy link

sreya commented Apr 4, 2025 

=== FAIL: agent/agentssh TestNewServer_CloseActiveConnections/Shutdown (60.61s)
    t.go:106: 2025-04-04 16:18:25.039 [info]  started serving listener  listen_addr=127.0.0.1:49265
    t.go:106: 2025-04-04 16:18:25.041 [info]  started serving connection  remote_addr=127.0.0.1:49266  local_addr=127.0.0.1:49265  listen_addr=127.0.0.1:49265
    t.go:106: 2025-04-04 16:18:25.046 [info]  started serving connection  remote_addr=127.0.0.1:49267  local_addr=127.0.0.1:49265  listen_addr=127.0.0.1:49265
    t.go:106: 2025-04-04 16:18:25.047 [info]  started serving connection  remote_addr=127.0.0.1:49268  local_addr=127.0.0.1:49265  listen_addr=127.0.0.1:49265
    t.go:106: 2025-04-04 16:18:25.047 [info]  started serving connection  remote_addr=127.0.0.1:49269  local_addr=127.0.0.1:49265  listen_addr=127.0.0.1:49265
    t.go:106: 2025-04-04 16:18:25.047 [info]  handling ssh session  remote_addr=127.0.0.1:49266  local_addr=127.0.0.1:49265  id=61716f14-aeef-4284-867c-8b3439401b44
    t.go:106: 2025-04-04 16:18:25.052 [info]  handling ssh session  remote_addr=127.0.0.1:49268  local_addr=127.0.0.1:49265  id=2f5eef27-73c7-49a9-93d8-6987a0baedb1
    t.go:106: 2025-04-04 16:18:25.066 [info]  handling ssh session  remote_addr=127.0.0.1:49269  local_addr=127.0.0.1:49265  id=0cf52c36-a73e-4a23-b3ed-5ef0fa28a139
    t.go:106: 2025-04-04 16:18:25.071 [info]  handling ssh session  remote_addr=127.0.0.1:49267  local_addr=127.0.0.1:49265  id=c8ced812-21b8-4114-8c4c-a583a60bc048
    t.go:106: 2025-04-04 16:18:25.071 [debu]  closing server
    t.go:106: 2025-04-04 16:18:25.071 [debu]  closing all active listeners  count=1
    t.go:106: 2025-04-04 16:18:25.071 [debu]  closing all active sessions  count=3
    t.go:106: 2025-04-04 16:18:25.071 [debu]  closing all active connections  count=4
    t.go:106: 2025-04-04 16:18:25.071 [debu]  closing SSH server
    t.go:106: 2025-04-04 16:18:25.071 [info]  ssh connection complete  remote_addr=127.0.0.1:49269  local_addr=127.0.0.1:49265  error="read tcp 127.0.0.1:49265->127.0.0.1:49269: use of closed network connection"
    t.go:106: 2025-04-04 16:18:25.071 [debu]  cmdCancel: sending SIGHUP to process and children  remote_addr=127.0.0.1:49266  local_addr=127.0.0.1:49265  id=61716f14-aeef-4284-867c-8b3439401b44  pid=6691
    t.go:106: 2025-04-04 16:18:25.071 [info]  ssh connection complete  remote_addr=127.0.0.1:49268  local_addr=127.0.0.1:49265  error="read tcp 127.0.0.1:49265->127.0.0.1:49268: use of closed network connection"
    t.go:106: 2025-04-04 16:18:25.071 [debu]  waiting for all goroutines to exit
    t.go:106: 2025-04-04 16:18:25.071 [info]  unable to accept new session, server is closing  remote_addr=127.0.0.1:49267  local_addr=127.0.0.1:49265  id=c8ced812-21b8-4114-8c4c-a583a60bc048
    t.go:106: 2025-04-04 16:18:25.072 [info]  stopped serving listener  listen_addr=127.0.0.1:49265  error="accept tcp 127.0.0.1:49265: use of closed network connection"
    t.go:106: 2025-04-04 16:18:25.072 [info]  ssh connection complete  remote_addr=127.0.0.1:49267  local_addr=127.0.0.1:49265  error="read tcp 127.0.0.1:49265->127.0.0.1:49267: use of closed network connection"
    t.go:106: 2025-04-04 16:18:25.072 [info]  ssh connection complete  remote_addr=127.0.0.1:49266  local_addr=127.0.0.1:49265  error="read tcp 127.0.0.1:49265->127.0.0.1:49266: use of closed network connection"
    t.go:106: 2025-04-04 16:18:25.072 [debu]  copy output done  remote_addr=127.0.0.1:49268  local_addr=127.0.0.1:49265  id=2f5eef27-73c7-49a9-93d8-6987a0baedb1  bytes=0  error=<nil>
    t.go:106: 2025-04-04 16:18:25.072 [info]  ssh session returned  remote_addr=127.0.0.1:49268  local_addr=127.0.0.1:49265  id=2f5eef27-73c7-49a9-93d8-6987a0baedb1  error="signal: killed"  process_exit_code=-1  exit_code=255
    t.go:106: 2025-04-04 16:18:25.084 [warn]  ssh session failed  remote_addr=127.0.0.1:49269  local_addr=127.0.0.1:49265  id=0cf52c36-a73e-4a23-b3ed-5ef0fa28a139 ...
        error= start command:
                   github.com/coder/coder/v2/agent/agentssh.(*Server).startPTYSession
                       /Users/runner/work/coder/coder/agent/agentssh/agentssh.go:675
                 - start:
                   github.com/coder/coder/v2/pty.startPty
                       /Users/runner/work/coder/coder/pty/start_other.go:55
                 - context canceled
    t.go:106: 2025-04-04 16:19:25.076 [info]  ssh session returned  remote_addr=127.0.0.1:49266  local_addr=127.0.0.1:49265  id=61716f14-aeef-4284-867c-8b3439401b44  error="signal: hangup"  process_exit_code=-1  exit_code=255
    t.go:106: 2025-04-04 16:19:25.076 [debu]  closing server done
    agentssh_test.go:223: 
        	Error Trace:	/Users/runner/work/coder/coder/agent/agentssh/agentssh_test.go:223
        	Error:      	Received unexpected error:
        	            	close server:
        	            	    github.com/coder/coder/v2/agent/agentssh.(*Server).Shutdown
        	            	        /Users/runner/work/coder/coder/agent/agentssh/agentssh.go:1132
        	            	  - context deadline exceeded
        	Test:       	TestNewServer_CloseActiveConnections/Shutdown
    t.go:106: 2025-04-04 16:19:25.076 [debu]  closing server
    t.go:106: 2025-04-04 16:19:25.076 [debu]  closing all active listeners  count=0
    ptytest.go:121: 2025-04-04 16:19:25.077: cmd: copy done: <nil>
    ptytest.go:96: 2025-04-04 16:19:25.077: cmd: closing expecter: PTY close
    t.go:106: 2025-04-04 16:19:25.077 [debu]  closing all active sessions  count=0
    ptytest.go:122: 2025-04-04 16:19:25.077: cmd: closing out
    t.go:106: 2025-04-04 16:19:25.077 [debu]  closing all active connections  count=0
    ptytest.go:124: 2025-04-04 16:19:25.077: cmd: closed out: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logw
    t.go:106: 2025-04-04 16:19:25.077 [debu]  closing SSH server
    t.go:106: 2025-04-04 16:19:25.077 [debu]  waiting for all goroutines to exit
    t.go:106: 2025-04-04 16:19:25.077 [debu]  closing server done
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logw: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logr
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logr: <nil>
    ptytest.go:113: 2025-04-04 16:19:25.077: cmd: closed expecter
    ptytest.go:96: 2025-04-04 16:19:25.077: cmd: closing expecter: PTY close
    ptytest.go:121: 2025-04-04 16:19:25.077: cmd: copy done: <nil>
    ptytest.go:122: 2025-04-04 16:19:25.077: cmd: closing out
    ptytest.go:124: 2025-04-04 16:19:25.077: cmd: closed out: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logw
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logw: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logr
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logr: <nil>
    ptytest.go:113: 2025-04-04 16:19:25.077: cmd: closed expecter
    ptytest.go:96: 2025-04-04 16:19:25.077: cmd: closing expecter: PTY close
    ptytest.go:121: 2025-04-04 16:19:25.077: cmd: copy done: <nil>
    ptytest.go:122: 2025-04-04 16:19:25.077: cmd: closing out
    ptytest.go:124: 2025-04-04 16:19:25.077: cmd: closed out: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logw
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logw: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logr
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logr: <nil>
    ptytest.go:113: 2025-04-04 16:19:25.077: cmd: closed expecter
    ptytest.go:96: 2025-04-04 16:19:25.077: cmd: closing expecter: PTY close
    ptytest.go:121: 2025-04-04 16:19:25.077: cmd: copy done: <nil>
    ptytest.go:122: 2025-04-04 16:19:25.077: cmd: closing out
    ptytest.go:124: 2025-04-04 16:19:25.077: cmd: closed out: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logw
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logw: <nil>
    ptytest.go:87: 2025-04-04 16:19:25.077: cmd: closing logr
    ptytest.go:89: 2025-04-04 16:19:25.077: cmd: closed logr: <nil>
    ptytest.go:113: 2025-04-04 16:19:25.077: cmd: closed expecter
@sreya sreya added the flake label Apr 4, 2025
@spikecurtis
Copy link

Also seen here: https://github.com/coder/coder/runs/40078890071

mafredri added a commit to coder/coder that referenced this issue Apr 7, 2025
@mafredri
test(agent/agentssh): fix early close of server in test
dbaeb0b 
Fixes coder/internal#558
@mafredri mafredri mentioned this issue Apr 7, 2025
Merged
@ethanndickson
Copy link
Member

Spotted again on main https://github.com/coder/coder/actions/runs/14328832167

@ethanndickson ethanndickson reopened this Apr 8, 2025
@johnstcn
Copy link
Member

johnstcn commented Apr 8, 2025

Seen here also: https://github.com/coder/coder/actions/runs/14336338041/job/40184322882?pr=17291#step:7:1324

mafredri added a commit to coder/coder that referenced this issue Apr 9, 2025
@mafredri
test(agent/agentssh): fix macos signal flake during close
e11ac70 
I haven't been able to verify this fix, but I'm hoping this'll do it.

Fixes coder/internal#558
@mafredri mafredri mentioned this issue Apr 9, 2025
Merged
mafredri added a commit to coder/coder that referenced this issue Apr 9, 2025
@mafredri
test(agent/agentssh): fix macos signal flake during close (#17313)
98c05b3 
Fixes coder/internal#558
johnstcn pushed a commit to coder/coder that referenced this issue Apr 10, 2025
@mafredri @johnstcn
test(agent/agentssh): fix macos signal flake during close (#17313)
7360cd9 
Fixes coder/internal#558
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mafredri mafredri

Labels
flake
Projects
None yet
Milestone
No milestone
5 participants
@mafredri @sreya @johnstcn @spikecurtis @ethanndickson