=== Failed
=== FAIL: enterprise/coderd TestManagedAgentLimit (0.35s)
t.go:106: 2025-07-24 04:23:34.652 [debu] pubsub: pubsub dialing postgres network=tcp address=127.0.0.1:5432 timeout_ms=0
t.go:106: 2025-07-24 04:23:34.653 [debu] pubsub: pubsub postgres TCP connection established network=tcp address=127.0.0.1:5432 timeout_ms=0 elapsed_ms=0
t.go:106: 2025-07-24 04:23:34.664 [debu] pubsub: pubsub connected to postgres
t.go:106: 2025-07-24 04:23:34.664 [debu] pubsub: pubsub has started
coderdenttest.go:80: coderdtest server listening on 127.0.0.1:46613
coderdenttest.go:80: coderdtest server started on http://127.0.0.1:46613/
t.go:106: 2025-07-24 04:23:34.697 [debu] coderd.dbrollup: rolling up data
t.go:106: 2025-07-24 04:23:34.701 [debu] coderd.metrics_cache: metrics refreshed name="template build times" interval=1h0m0s took=3.667455ms
t.go:106: 2025-07-24 04:23:34.712 [debu] coderd.metrics_cache: metrics refreshed name="deployment stats" interval=5m0s took=15.71168ms
t.go:106: 2025-07-24 04:23:34.713 [debu] coderd.keyrotator: no valid keys detected, inserting new key feature=workspace_apps_token
t.go:106: 2025-07-24 04:23:34.716 [debu] coderd.keyrotator: inserted new key for feature feature=workspace_apps_token
t.go:106: 2025-07-24 04:23:34.716 [debu] coderd.keyrotator: no valid keys detected, inserting new key feature=workspace_apps_api_key
t.go:106: 2025-07-24 04:23:34.717 [debu] coderd.keyrotator: inserted new key for feature feature=workspace_apps_api_key
t.go:106: 2025-07-24 04:23:34.717 [debu] coderd.keyrotator: no valid keys detected, inserting new key feature=oidc_convert
t.go:106: 2025-07-24 04:23:34.719 [debu] coderd.dbrollup: rolled up data took=21.755049ms event={"template_usage_stats":true}
t.go:106: 2025-07-24 04:23:34.719 [debu] coderd.keyrotator: inserted new key for feature feature=oidc_convert
t.go:106: 2025-07-24 04:23:34.719 [debu] coderd.keyrotator: no valid keys detected, inserting new key feature=tailnet_resume
t.go:106: 2025-07-24 04:23:34.719 [debu] coderd.dbrollup: next rollup at next="2025-07-24T04:25:00Z"
t.go:106: 2025-07-24 04:23:34.720 [debu] coderd.keyrotator: inserted new key for feature feature=tailnet_resume
t.go:106: 2025-07-24 04:23:34.721 [debu] coderd.keyrotator: ctx canceled, stopping key rotation
t.go:106: 2025-07-24 04:23:34.722 [debu] pubsub: started listening to event channel event=provisioner_job_posted
t.go:106: 2025-07-24 04:23:34.722 [debu] coderd.acquirer: subscribed to job postings
t.go:106: 2025-07-24 04:23:34.722 [warn] coderd.site: could not parse install.sh, it will be unavailable error="open install.sh: file does not exist"
t.go:106: 2025-07-24 04:23:34.722 [debu] coderd.servertailnet: network isolation configuration use_netns=false use_soft_isolation=false
t.go:106: 2025-07-24 04:23:34.723 [debu] coderd.servertailnet.net.wgengine: [v1] using fake (no-op) tun device
t.go:106: 2025-07-24 04:23:34.723 [debu] coderd.servertailnet.net.wgengine: [v1] using fake (no-op) OS network configurator
t.go:106: 2025-07-24 04:23:34.723 [debu] coderd.servertailnet.net.wgengine: [v1] using fake (no-op) DNS configurator
t.go:106: 2025-07-24 04:23:34.723 [debu] coderd.servertailnet.net.wgengine: dns: using dns.noopManager
t.go:106: 2025-07-24 04:23:34.723 [debu] coderd.servertailnet.net.wgengine: link state: interfaces.State{defaultRoute=enp39s0 ifs={docker0:[172.17.0.1/16] enp39s0:[10.20.42.105/19]} v4=true v6=false}
Warning: 106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: [warning] failed to force-set UDP read buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)
Warning: 106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: [warning] failed to force-set UDP write buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)
t.go:106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: dontfrag: success on [::]:45353
Warning: 106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: [warning] failed to force-set UDP read buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)
Warning: 106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: [warning] failed to force-set UDP write buffer size to 7340032: operation not permitted; using kernel default values (impacts throughput only)
t.go:106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: dontfrag: success on 0.0.0.0:35926
t.go:106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: [v1] couldn't create raw v4 disco listener, using regular listener instead: raw disco listening disabled, SO_MARK unavailable
t.go:106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: [v1] couldn't create raw v6 disco listener, using regular listener instead: raw disco listening disabled, SO_MARK unavailable
t.go:106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: magicsock: disco key = d:10dbfd64a4587596
t.go:106: 2025-07-24 04:23:34.724 [debu] coderd.servertailnet.net.wgengine: Creating WireGuard device...
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: Bringing WireGuard device up...
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: wg: [v2] UDP bind has been updated
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Routine: receive incoming mkReceiveFunc - started
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Interface state was Down, requested Up, now Up
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: Bringing router up...
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Routine: receive incoming mkReceiveFunc - started
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: [v1] warning: fakeRouter.Up: not implemented.
t.go:106: 2025-07-24 04:23:34.726 [debu] coderd.servertailnet.net.wgengine: Clearing router settings...
t.go:106: 2025-07-24 04:23:34.725 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Routine: receive incoming receiveDERP - started
t.go:106: 2025-07-24 04:23:34.726 [debu] coderd.servertailnet.net.wgengine: [v1] warning: fakeRouter.Set: not implemented.
t.go:106: 2025-07-24 04:23:34.726 [debu] coderd.servertailnet.net.wgengine: Starting network monitor...
t.go:106: 2025-07-24 04:23:34.726 [debu] coderd.servertailnet.net.wgengine: Engine created.
t.go:106: 2025-07-24 04:23:34.726 [debu] coderd.servertailnet: magicsock debug logging disabled, use CODER_MAGICSOCK_DEBUG_LOGGING=true to enable
t.go:106: 2025-07-24 04:23:34.727 [debu] coderd.servertailnet.net.wgengine: magicsock: SetPrivateKey called (init)
t.go:106: 2025-07-24 04:23:34.730 [debu] coderd.servertailnet: skipped sending node; no node callback
t.go:106: 2025-07-24 04:23:34.730 [debu] coderd.servertailnet: updating engine network map network_map="netmap: self: [QJNwA] auth=machine-unknown u=? [fd7a:115c:a1e0:4b95:80b1:92c9:6748:d6eb/128]\n"
t.go:106: 2025-07-24 04:23:34.731 [debu] coderd.servertailnet.net.wgengine: [v1] magicsock: got updated network map; 0 peers
t.go:106: 2025-07-24 04:23:34.731 [debu] coderd.servertailnet.net.netstack: [v2] netstack: registered IP fd7a:115c:a1e0:4b95:80b1:92c9:6748:d6eb/128
t.go:106: 2025-07-24 04:23:34.731 [debu] coderd.workspaceapps.stats_collector: workspace app stats collector started
t.go:106: 2025-07-24 04:23:34.732 [debu] coderd.servertailnet.net.wgengine: wgengine: Reconfig: configuring userspace WireGuard config (with 0/0 peers)
t.go:106: 2025-07-24 04:23:34.732 [debu] coderd.servertailnet.net.wgengine: wg: [v2] UAPI: Updating private key
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: wgengine: Reconfig: configuring router
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: [v1] warning: fakeRouter.Set: not implemented.
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: wgengine: Reconfig: configuring DNS
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: dns: Set: {DefaultResolvers:[] Routes:{} SearchDomains:[] Hosts:0}
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: dns: Resolvercfg: {Routes:{} Hosts:0 LocalDomains:[], cloud="aws"}
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: dns: OScfg: {Nameservers:[] SearchDomains:[] MatchDomains:[] Hosts:[]}
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet.net.wgengine: [v1] wgengine: Reconfig done
t.go:106: 2025-07-24 04:23:34.733 [debu] coderd.servertailnet: updating engine filter filter="&{logf:0x37660c0 local:0xc01d6914d0 logIPs:0xc01d6914e8 matches4:[{IPProto:[6 17 1 58 132] Srcs:[{ip:{addr:{hi:0 lo:281470681743360} z:{value:0xc00025f860}} bitsPlusOne:1}] Dsts:[{Net:{ip:{addr:{hi:0 lo:281470681743360} z:{value:0xc00025f860}} bitsPlusOne:1} Ports:{First:0 Last:65535}}] Caps:[]}] matches6:[{IPProto:[6 17 1 58 132] Srcs:[{ip:{addr:{hi:0 lo:0} z:{value:0xc00025f878}} bitsPlusOne:1}] Dsts:[{Net:{ip:{addr:{hi:0 lo:0} z:{value:0xc00025f878}} bitsPlusOne:1} Ports:{First:0 Last:65535}}] Caps:[]}] cap4:[] cap6:[] state:0xc01d69a520 shieldsUp:false}"
t.go:106: 2025-07-24 04:23:34.734 [debu] coderd.coord: initPeer peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 peer_name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.734 [debu] coderd.coord: initial tunnel peers peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 peer_name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655 tunnel_peers=[]
t.go:106: 2025-07-24 04:23:34.734 [debu] coderd.servertailnet: obtained tailnet API v2+ client
t.go:106: 2025-07-24 04:23:34.734 [debu] coderd.servertailnet: serving coordinator
t.go:106: 2025-07-24 04:23:34.734 [debu] coderd.servertailnet: skipped sending node; no PreferredDERP node="&{ID:nodeid:1e31ed12d28f45 AsOf:2025-07-24 04:23:34.734898 +0000 UTC Key:nodekey:40937002bd509cac978ca60cd820d2d5d826233f2aa2512604c577cd9a84b01e DiscoKey:discokey:10dbfd64a4587596d2a81eff98d2c8502b8d21f9fb59770d4aa3018873e5b446 PreferredDERP:0 DERPLatency:map[] DERPForcedWebsocket:map[] Addresses:[fd7a:115c:a1e0:4b95:80b1:92c9:6748:d6eb/128] AllowedIPs:[fd7a:115c:a1e0:4b95:80b1:92c9:6748:d6eb/128] Endpoints:[]}"
t.go:106: 2025-07-24 04:23:34.748 [debu] pubsub: publish event=replica message_len=36
t.go:106: 2025-07-24 04:23:34.751 [debu] pubsub: started listening to event channel event=replica
t.go:106: 2025-07-24 04:23:34.754 [debu] coderd.provisionerd: dialing coderd
t.go:106: 2025-07-24 04:23:34.754 [debu] pubsub: started listening to event channel event=licenses
t.go:106: 2025-07-24 04:23:34.754 [debu] coderd: successfully subscribed to pubsub
t.go:106: 2025-07-24 04:23:34.754 [debu] coderd: syncing licensed entitlements
t.go:106: 2025-07-24 04:23:34.755 [debu] coderd: synced licensed entitlements
t.go:106: 2025-07-24 04:23:34.761 [debu] coderd: starting in-memory provisioner daemon name=test-daemon
t.go:106: 2025-07-24 04:23:34.762 [debu] coderd.provisionerd: successfully connected to coderd
t.go:106: 2025-07-24 04:23:34.762 [debu] coderd.provisionerd: start of acquireAndRunOne
t.go:106: 2025-07-24 04:23:34.762 [debu] coderd.acquirer: acquiring job organization_id=c63c2445-25c4-447c-9b34-d35ab02814bc worker_id=e01548ab-1d3b-47f8-becf-ee42ce75ced1 provisioner_types=[echo] tags={"owner":"","scope":"organization"}
t.go:106: 2025-07-24 04:23:34.762 [debu] coderd.acquirer: got clearance to call database organization_id=c63c2445-25c4-447c-9b34-d35ab02814bc worker_id=e01548ab-1d3b-47f8-becf-ee42ce75ced1 provisioner_types=[echo] tags={"owner":"","scope":"organization"}
t.go:106: 2025-07-24 04:23:34.779 [debu] coderd.acquirer: no job available organization_id=c63c2445-25c4-447c-9b34-d35ab02814bc worker_id=e01548ab-1d3b-47f8-becf-ee42ce75ced1 provisioner_types=[echo] tags={"owner":"","scope":"organization"}
t.go:106: 2025-07-24 04:23:34.831 [info] coderd: refresh entitlements now request_id=f7df5ff5-a6a9-4aaa-b38d-5ae52543f1a0
t.go:106: 2025-07-24 04:23:34.833 [debu] pubsub: publish event=licenses message_len=7
t.go:106: 2025-07-24 04:23:34.833 [debu] coderd: POST host=localhost:46613 path=/api/v2/users/first proto=HTTP/1.1 remote_addr=127.0.0.1 start="2025-07-24T04:23:34.762941888Z" requestor_name=System took=70.796311ms status_code=201 latency_ms=70 request_id=f7df5ff5-a6a9-4aaa-b38d-5ae52543f1a0
t.go:106: 2025-07-24 04:23:34.834 [debu] coderd: got pubsub update
t.go:106: 2025-07-24 04:23:34.834 [debu] coderd: syncing licensed entitlements
t.go:106: 2025-07-24 04:23:34.835 [debu] coderd: synced licensed entitlements
t.go:106: 2025-07-24 04:23:34.845 [debu] coderd: POST host=localhost:46613 path=/api/v2/users/login proto=HTTP/1.1 remote_addr=127.0.0.1 start="2025-07-24T04:23:34.834613337Z" requestor_id=a5d2aa5d-2958-4216-aae6-d060c79653ce requestor_name=testuser requestor_email=testuser@coder.com took=10.555841ms status_code=201 latency_ms=10 request_id=a93467e7-6440-4d37-99d3-70a9da8f0b23
t.go:106: 2025-07-24 04:23:34.877 [debu] pubsub: started listening to event channel event=tailnet_coordinator_heartbeat
t.go:106: 2025-07-24 04:23:34.877 [debu] pubsub: started listening to event channel event=tailnet_peer_update
t.go:106: 2025-07-24 04:23:34.877 [info] coderd.pgcoord.querier: subscribed to peer updates coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.878 [debu] pubsub: started listening to event channel event=tailnet_tunnel_update
t.go:106: 2025-07-24 04:23:34.878 [info] coderd.pgcoord.querier: subscribed to tunnel updates coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.878 [debu] coderd.pgcoord: ignoring our own heartbeat coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.878 [debu] coderd.pgcoord: sent heartbeat coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.878 [debu] pubsub: started listening to event channel event=tailnet_ready_for_handshake
t.go:106: 2025-07-24 04:23:34.878 [info] coderd.pgcoord.querier: subscribed to ready for handshakes coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.878 [info] coderd.pgcoord: starting coordinator coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.879 [debu] coderd.coord: got tunnel peers peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 tunnel_peers=[]
t.go:109: 2025-07-24 04:23:34.879 [erro] coderd.servertailnet: coordination protocol error error="coordinator closed"
t.go:106: 2025-07-24 04:23:34.879 [debu] coderd.pgcoord: completed cleanup coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.879 [debu] coderd.servertailnet: failed to read from protocol error=EOF
t.go:106: 2025-07-24 04:23:34.879 [debu] coderd: polling DERPMap exited
t.go:106: 2025-07-24 04:23:34.879 [debu] coderd.coord: peerReadLoop channel closed peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 peer_name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.880 [debu] coderd.coord: lostPeer peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.880 [debu] coderd.servertailnet: failed to receive DERP message error="context canceled"
t.go:106: 2025-07-24 04:23:34.880 [debu] pubsub: publish event=licenses message_len=3
t.go:106: 2025-07-24 04:23:34.880 [info] coderd.prebuilds: starting reconciler interval=1m0s backoff_interval=1m0s backoff_lookback=1h0m0s
t.go:106: 2025-07-24 04:23:34.880 [debu] coderd.servertailnet: tailnet API v2+ connection lost
t.go:106: 2025-07-24 04:23:34.880 [info] coderd.pgcoord: serving connection coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.880 [debu] coderd.servertailnet: obtained tailnet API v2+ client
t.go:106: 2025-07-24 04:23:34.881 [debu] coderd.pgcoord.querier: querying mappings coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.881 [debu] coderd.servertailnet: serving coordinator
t.go:106: 2025-07-24 04:23:34.881 [debu] coderd.servertailnet: skipped sending node; no PreferredDERP node="&{ID:nodeid:1e31ed12d28f45 AsOf:2025-07-24 04:23:34.881432 +0000 UTC Key:nodekey:40937002bd509cac978ca60cd820d2d5d826233f2aa2512604c577cd9a84b01e DiscoKey:discokey:10dbfd64a4587596d2a81eff98d2c8502b8d21f9fb59770d4aa3018873e5b446 PreferredDERP:0 DERPLatency:map[] DERPForcedWebsocket:map[] Addresses:[fd7a:115c:a1e0:4b95:80b1:92c9:6748:d6eb/128] AllowedIPs:[fd7a:115c:a1e0:4b95:80b1:92c9:6748:d6eb/128] Endpoints:[]}"
t.go:106: 2025-07-24 04:23:34.882 [debu] coderd: got pubsub update
t.go:106: 2025-07-24 04:23:34.882 [debu] coderd: syncing licensed entitlements
t.go:106: 2025-07-24 04:23:34.882 [debu] coderd: POST host=localhost:46613 path=/api/v2/licenses proto=HTTP/1.1 remote_addr=127.0.0.1 start="2025-07-24T04:23:34.846630212Z" requestor_id=a5d2aa5d-2958-4216-aae6-d060c79653ce requestor_name=testuser requestor_email=testuser@coder.com took=36.305279ms status_code=201 latency_ms=36 request_id=8747efd3-5c39-42ff-8c7d-d3350edcbe8b
t.go:106: 2025-07-24 04:23:34.884 [debu] coderd: GET host=localhost:46613 path=/api/v2/entitlements proto=HTTP/1.1 remote_addr=127.0.0.1 start="2025-07-24T04:23:34.884445086Z" took=528.285µs status_code=200 latency_ms=0 request_id=d5547bdc-6217-4365-888d-c9d92f2c7a64
coderd_test.go:654:
Error Trace: /home/runner/work/coder/coder/enterprise/coderd/coderd_test.go:654
Error: Should be empty, but was [Error getting managed agent count: context canceled]
Test: TestManagedAgentLimit
t.go:106: 2025-07-24 04:23:34.886 [info] coderd.provisionerd: attempting graceful shutdown
t.go:106: 2025-07-24 04:23:34.886 [debu] coderd.provisionerd: sending acquire job cancel
t.go:106: 2025-07-24 04:23:34.886 [debu] coderd.acquirer: acquiring job canceled organization_id=c63c2445-25c4-447c-9b34-d35ab02814bc worker_id=e01548ab-1d3b-47f8-becf-ee42ce75ced1 provisioner_types=[echo] tags={"owner":"","scope":"organization"} error="context canceled"
t.go:106: 2025-07-24 04:23:34.887 [debu] coderd.inmem-provisionerd-test-daemon: successful cancel
t.go:106: 2025-07-24 04:23:34.887 [debu] coderd.inmem-provisionerd-test-daemon: closed stream error=<nil>
t.go:106: 2025-07-24 04:23:34.887 [debu] coderd.provisionerd: graceful acquire done job_id="" error=<nil>
t.go:106: 2025-07-24 04:23:34.887 [debu] coderd.provisionerd: acquire job successfully canceled
t.go:106: 2025-07-24 04:23:34.888 [debu] coderd.provisionerd: exiting acquire; provisionerd is shutting down
t.go:106: 2025-07-24 04:23:34.888 [debu] coderd.provisionerd: acquire loop exited
t.go:106: 2025-07-24 04:23:34.888 [info] coderd.provisionerd: gracefully shutdown
t.go:106: 2025-07-24 04:23:34.888 [info] coderd.provisionerd: closing provisionerd
t.go:106: 2025-07-24 04:23:34.888 [debu] coderd.provisionerd: waiting for goroutines to exit
t.go:106: 2025-07-24 04:23:34.888 [debu] coderd.provisionerd: connect loop exited
t.go:106: 2025-07-24 04:23:34.888 [debu] coderd.provisionerd: closing server with error error=<nil>
t.go:106: 2025-07-24 04:23:34.888 [info] coderd.inmem-provisionerd-test-daemon: provisioner daemon disconnected ...
error= InmemoryListener is already closed: use of closed network connection
storj.io/drpc/drpcserver.(*Server).Serve:109
github.com/coder/coder/v2/coderd.(*API).CreateInMemoryTaggedProvisionerDaemon.func3:1920
t.go:106: 2025-07-24 04:23:34.888 [debu] pubsub: removing queueSet event=replica
t.go:106: 2025-07-24 04:23:34.888 [debu] pubsub: stopped listening to event channel event=replica
t.go:106: 2025-07-24 04:23:34.891 [debu] coderd: synced licensed entitlements
t.go:106: 2025-07-24 04:23:34.896 [debu] coderd.prebuilds.prebuilds_metrics_collector: fetched prebuilds metrics state duration_secs=0.02
t.go:106: 2025-07-24 04:23:34.900 [debu] coderd.pgcoord.querier: queried mappings coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 num_mappings=0
t.go:106: 2025-07-24 04:23:34.900 [debu] coderd.pgcoord.querier: sending mappings coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 mapping_len=0
t.go:106: 2025-07-24 04:23:34.900 [debu] coderd.pgcoord.querier: got new mappings coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.900 [debu] coderd.pgcoord.querier: skipping nil node update coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.907 [debu] pubsub: publish event=replica message_len=36
t.go:106: 2025-07-24 04:23:34.909 [info] coderd.pgcoord.querier: canceling ready for handshake subscription coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: binder exiting, waiting for workers coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.inmem-provisionerd-test-daemon: heartbeat loop canceled
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: tunneler exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: handshaker worker exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: updating peers to lost coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: handshaker worker exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: handshaker worker exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: handshaker worker exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.servertailnet: main context canceled; do graceful disconnect
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: ending cleanupLoop coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: binder exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.servertailnet: sent disconnect
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.servertailnet: failed to receive DERP message error="context canceled"
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: exiting io recvLoop; coordinator exit coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.910 [debu] coderd.servertailnet: stopped expiring old agents
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: removing queueSet event=licenses
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: stopped listening to event channel event=licenses
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: publish event=licenses message_len=10
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: removing queueSet event=tailnet_coordinator_heartbeat
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: stopped listening to event channel event=tailnet_coordinator_heartbeat
t.go:106: 2025-07-24 04:23:34.910 [debu] coderd.workspaceapps.stats_collector: flushing workspace app stats
t.go:106: 2025-07-24 04:23:34.910 [debu] coderd: polling DERPMap exited
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: removing queueSet event=tailnet_ready_for_handshake
t.go:106: 2025-07-24 04:23:34.910 [debu] pubsub: stopped listening to event channel event=tailnet_ready_for_handshake
t.go:106: 2025-07-24 04:23:34.910 [info] coderd.pgcoord.querier: canceling tunnel updates subscription coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.910 [debu] coderd.workspaceapps.stats_collector: flushed workspace app stats
t.go:106: 2025-07-24 04:23:34.910 [debu] coderd.workspaceapps.stats_collector: workspace app stats collector stopped
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: handshaker worker exiting coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.911 [debu] pubsub: removing queueSet event=tailnet_tunnel_update
t.go:106: 2025-07-24 04:23:34.911 [debu] pubsub: stopped listening to event channel event=tailnet_tunnel_update
t.go:106: 2025-07-24 04:23:34.911 [info] coderd.pgcoord.querier: canceling peer updates subscription coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.911 [debu] coderd.pgcoord: wrote response coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655
t.go:106: 2025-07-24 04:23:34.912 [debu] coderd.pgcoord: parent context expired while withdrawing bindings coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 name=inmemorye2cfe220-db22-40ae-b785-3cde2a0f9655 peer_id=e2cfe220-db22-40ae-b785-3cde2a0f9655 error="context canceled"
t.go:106: 2025-07-24 04:23:34.911 [info] coderd.servertailnet: closing server tailnet
t.go:106: 2025-07-24 04:23:34.912 [info] coderd.servertailnet: closing tailnet Conn
t.go:106: 2025-07-24 04:23:34.909 [debu] coderd.pgcoord: ending heartbeats coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3 error="context canceled"
t.go:106: 2025-07-24 04:23:34.912 [debu] coderd.servertailnet: closing configMaps configLoop
t.go:109: 2025-07-24 04:23:34.911 [erro] coderd.servertailnet: coordination protocol error error="coordinator closed"
t.go:106: 2025-07-24 04:23:34.913 [debu] coderd.servertailnet: failed to read from protocol error=EOF
t.go:106: 2025-07-24 04:23:34.913 [debu] coderd.servertailnet: closing nodeUpdater updateLoop
t.go:106: 2025-07-24 04:23:34.913 [debu] coderd.servertailnet: responses closed after disconnect
t.go:106: 2025-07-24 04:23:34.913 [debu] coderd.servertailnet: tailnet API v2+ connection lost
t.go:106: 2025-07-24 04:23:34.913 [debu] coderd.servertailnet: closed netstack
t.go:106: 2025-07-24 04:23:34.914 [debu] pubsub: removing queueSet event=provisioner_job_posted
t.go:106: 2025-07-24 04:23:34.914 [debu] pubsub: stopped listening to event channel event=provisioner_job_posted
t.go:106: 2025-07-24 04:23:34.914 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Routine: receive incoming mkReceiveFunc - stopped
t.go:106: 2025-07-24 04:23:34.914 [debu] coderd.servertailnet.net.wgengine: [v1] warning: fakeRouter.Close: not implemented.
t.go:106: 2025-07-24 04:23:34.914 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Routine: receive incoming mkReceiveFunc - stopped
t.go:106: 2025-07-24 04:23:34.914 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Device closing
t.go:106: 2025-07-24 04:23:34.915 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Routine: receive incoming receiveDERP - stopped
t.go:106: 2025-07-24 04:23:34.914 [debu] pubsub: removing queueSet event=tailnet_peer_update
t.go:106: 2025-07-24 04:23:34.915 [debu] pubsub: stopped listening to event channel event=tailnet_peer_update
t.go:106: 2025-07-24 04:23:34.915 [debu] coderd.servertailnet.net.wgengine: wg: [v2] Device closed
t.go:106: 2025-07-24 04:23:34.915 [debu] coderd.servertailnet: server tailnet close complete
t.go:106: 2025-07-24 04:23:34.915 [info] coderd.pgcoord: closing coordinator coordinator_id=a4d818dc-cd10-437c-b9bd-9e7ee5a52dd3
t.go:106: 2025-07-24 04:23:34.915 [debu] coderd.workspace_usage_tracker: workspace usage tracker loop exited
t.go:106: 2025-07-24 04:23:34.915 [info] coderd.prebuilds: gracefully stopping reconciler
t.go:106: 2025-07-24 04:23:34.915 [warn] coderd.prebuilds: reconciliation loop exited error="context canceled" cause="context canceled"
t.go:106: 2025-07-24 04:23:34.916 [info] coderd.prebuilds: reconciler stopped
stuntest.go:63: STUN server shutdown
coderdtest.go:462: closing coderdtest server on 127.0.0.1:46613
coderdtest.go:464: closed coderdtest server on 127.0.0.1:46613
t.go:106: 2025-07-24 04:23:34.916 [info] pubsub: pubsub is closing
t.go:106: 2025-07-24 04:23:34.916 [info] pubsub: pubsub listen stopped receiving notify
t.go:106: 2025-07-24 04:23:34.916 [debu] pubsub: pubsub closed
https://github.com/coder/coder/actions/runs/16487675790/job/46615655883#step:8:475