-
Notifications
You must be signed in to change notification settings - Fork 1k
Closed
Labels
s4Internal bugs (e.g. test flakes), extreme edge cases, and bug risksInternal bugs (e.g. test flakes), extreme edge cases, and bug risks
Description
Seen here: https://github.com/coder/coder/actions/runs/5865237892/job/15901814232
Relevant excerpt:
2023-08-15T08:41:07.9174591Z t.go:85: 2023-08-15 08:40:14.373 [debu] read stats report request_id=df4a2f52-2d3e-42e2-bee6-e368293de12f interval=5m0s workspace_agent_id=7804b8b1-e4a4-4ac5-9606-4f22e5730769 workspace_id=d3093ff2-06b0-4de1-a5cf-b0daf6c45bcc payload={"connections_by_proto":{"TCP":1},"connection_count":7,"connection_median_latency_ms":8000,"rx_packets":0,"rx_bytes":2,"tx_packets":0,"tx_bytes":1,"session_count_vscode":3,"session_count_jetbrains":4,"session_count_reconnecting_pty":5,"session_count_ssh":6,"metrics":null}
2023-08-15T08:41:07.9175423Z t.go:85: 2023-08-15 08:40:14.446 [debu] activity_bump: bumped deadline from activity request_id=df4a2f52-2d3e-42e2-bee6-e368293de12f workspace_id=d3093ff2-06b0-4de1-a5cf-b0daf6c45bcc
2023-08-15T08:41:07.9176214Z t.go:85: 2023-08-15 08:40:14.471 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=112.639486ms status_code=200 latency_ms=112 request_id=df4a2f52-2d3e-42e2-bee6-e368293de12f
2023-08-15T08:41:07.9177515Z t.go:85: 2023-08-15 08:40:14.509 [debu] read stats report request_id=90ffedc8-354e-41ce-9a1e-b987f6af2b1b interval=5m0s workspace_agent_id=6fcc9420-153d-4465-ba76-8eec460d15f1 workspace_id=3231f8fa-6c99-48aa-8ad8-e8a93d577eac payload={"connections_by_proto":{"TCP":1},"connection_count":8,"connection_median_latency_ms":10000,"rx_packets":0,"rx_bytes":4,"tx_packets":0,"tx_bytes":2,"session_count_vscode":6,"session_count_jetbrains":8,"session_count_reconnecting_pty":10,"session_count_ssh":12,"metrics":null}
2023-08-15T08:41:07.9178389Z t.go:85: 2023-08-15 08:40:14.536 [debu] activity_bump: bumped deadline from activity request_id=90ffedc8-354e-41ce-9a1e-b987f6af2b1b workspace_id=3231f8fa-6c99-48aa-8ad8-e8a93d577eac
2023-08-15T08:41:07.9179151Z t.go:85: 2023-08-15 08:40:14.541 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=69.593232ms status_code=200 latency_ms=69 request_id=90ffedc8-354e-41ce-9a1e-b987f6af2b1b
2023-08-15T08:41:07.9180409Z t.go:85: 2023-08-15 08:40:14.553 [debu] read stats report request_id=cd30a872-65d7-4eaf-8a3f-0aef75f8832f interval=5m0s workspace_agent_id=1de64d4f-2a05-449b-b9ee-67e7d09967ad workspace_id=0a3e4daf-3e6d-4785-8ec1-e4dd9ceffedf payload={"connections_by_proto":{"TCP":1},"connection_count":9,"connection_median_latency_ms":12000,"rx_packets":0,"rx_bytes":6,"tx_packets":0,"tx_bytes":3,"session_count_vscode":12,"session_count_jetbrains":14,"session_count_reconnecting_pty":16,"session_count_ssh":18,"metrics":null}
2023-08-15T08:41:07.9181317Z t.go:85: 2023-08-15 08:40:14.564 [debu] activity_bump: bumped deadline from activity request_id=cd30a872-65d7-4eaf-8a3f-0aef75f8832f workspace_id=0a3e4daf-3e6d-4785-8ec1-e4dd9ceffedf
2023-08-15T08:41:07.9182059Z t.go:85: 2023-08-15 08:40:14.573 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=32.244629ms status_code=200 latency_ms=32 request_id=cd30a872-65d7-4eaf-8a3f-0aef75f8832f
2023-08-15T08:41:07.9183333Z t.go:85: 2023-08-15 08:40:14.583 [debu] read stats report request_id=3c61c16a-93db-4aa0-ac1d-6a0f6e31c8a1 interval=5m0s workspace_agent_id=7804b8b1-e4a4-4ac5-9606-4f22e5730769 workspace_id=d3093ff2-06b0-4de1-a5cf-b0daf6c45bcc payload={"connections_by_proto":{"TCP":1},"connection_count":8,"connection_median_latency_ms":8000,"rx_packets":0,"rx_bytes":3,"tx_packets":0,"tx_bytes":2,"session_count_vscode":4,"session_count_jetbrains":5,"session_count_reconnecting_pty":6,"session_count_ssh":7,"metrics":null}
2023-08-15T08:41:07.9184169Z t.go:85: 2023-08-15 08:40:14.600 [debu] activity_bump: bumped deadline from activity request_id=3c61c16a-93db-4aa0-ac1d-6a0f6e31c8a1 workspace_id=d3093ff2-06b0-4de1-a5cf-b0daf6c45bcc
2023-08-15T08:41:07.9184905Z t.go:85: 2023-08-15 08:40:14.605 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=31.20304ms status_code=200 latency_ms=31 request_id=3c61c16a-93db-4aa0-ac1d-6a0f6e31c8a1
2023-08-15T08:41:07.9186175Z t.go:85: 2023-08-15 08:40:14.619 [debu] read stats report request_id=c8d6d363-c53a-421b-9240-97dc7fa75943 interval=5m0s workspace_agent_id=6fcc9420-153d-4465-ba76-8eec460d15f1 workspace_id=3231f8fa-6c99-48aa-8ad8-e8a93d577eac payload={"connections_by_proto":{"TCP":1},"connection_count":9,"connection_median_latency_ms":10000,"rx_packets":0,"rx_bytes":5,"tx_packets":0,"tx_bytes":3,"session_count_vscode":7,"session_count_jetbrains":9,"session_count_reconnecting_pty":11,"session_count_ssh":13,"metrics":null}
2023-08-15T08:41:07.9186999Z t.go:85: 2023-08-15 08:40:14.625 [debu] activity_bump: bumped deadline from activity request_id=c8d6d363-c53a-421b-9240-97dc7fa75943 workspace_id=3231f8fa-6c99-48aa-8ad8-e8a93d577eac
2023-08-15T08:41:07.9187848Z t.go:85: 2023-08-15 08:40:14.627 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=22.36924ms status_code=200 latency_ms=22 request_id=c8d6d363-c53a-421b-9240-97dc7fa75943
2023-08-15T08:41:07.9189193Z t.go:85: 2023-08-15 08:40:14.634 [debu] read stats report request_id=8252bc6a-6e30-4a2c-acfc-3e21a7148fdf interval=5m0s workspace_agent_id=1de64d4f-2a05-449b-b9ee-67e7d09967ad workspace_id=0a3e4daf-3e6d-4785-8ec1-e4dd9ceffedf payload={"connections_by_proto":{"TCP":1},"connection_count":10,"connection_median_latency_ms":12000,"rx_packets":0,"rx_bytes":7,"tx_packets":0,"tx_bytes":4,"session_count_vscode":13,"session_count_jetbrains":15,"session_count_reconnecting_pty":17,"session_count_ssh":19,"metrics":null}
2023-08-15T08:41:07.9190056Z t.go:85: 2023-08-15 08:40:14.646 [debu] activity_bump: bumped deadline from activity request_id=8252bc6a-6e30-4a2c-acfc-3e21a7148fdf workspace_id=0a3e4daf-3e6d-4785-8ec1-e4dd9ceffedf
2023-08-15T08:41:07.9190814Z t.go:85: 2023-08-15 08:40:14.647 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=19.327856ms status_code=200 latency_ms=19 request_id=8252bc6a-6e30-4a2c-acfc-3e21a7148fdf
2023-08-15T08:41:07.9192045Z t.go:85: 2023-08-15 08:40:14.661 [debu] read stats report request_id=51920ba1-2876-46a1-a659-732c21b962f3 interval=5m0s workspace_agent_id=7804b8b1-e4a4-4ac5-9606-4f22e5730769 workspace_id=d3093ff2-06b0-4de1-a5cf-b0daf6c45bcc payload={"connections_by_proto":{"TCP":1},"connection_count":9,"connection_median_latency_ms":8000,"rx_packets":0,"rx_bytes":4,"tx_packets":0,"tx_bytes":3,"session_count_vscode":5,"session_count_jetbrains":6,"session_count_reconnecting_pty":7,"session_count_ssh":8,"metrics":null}
2023-08-15T08:41:07.9192951Z t.go:85: 2023-08-15 08:40:14.663 [debu] activity_bump: bumped deadline from activity request_id=51920ba1-2876-46a1-a659-732c21b962f3 workspace_id=d3093ff2-06b0-4de1-a5cf-b0daf6c45bcc
2023-08-15T08:41:07.9193671Z t.go:85: 2023-08-15 08:40:14.664 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=16.628788ms status_code=200 latency_ms=16 request_id=51920ba1-2876-46a1-a659-732c21b962f3
2023-08-15T08:41:07.9194902Z t.go:85: 2023-08-15 08:40:14.669 [debu] read stats report request_id=43927a78-72a5-474d-bee6-9457847f0d7e interval=5m0s workspace_agent_id=6fcc9420-153d-4465-ba76-8eec460d15f1 workspace_id=3231f8fa-6c99-48aa-8ad8-e8a93d577eac payload={"connections_by_proto":{"TCP":1},"connection_count":10,"connection_median_latency_ms":10000,"rx_packets":0,"rx_bytes":6,"tx_packets":0,"tx_bytes":4,"session_count_vscode":8,"session_count_jetbrains":10,"session_count_reconnecting_pty":12,"session_count_ssh":14,"metrics":null}
2023-08-15T08:41:07.9195749Z t.go:85: 2023-08-15 08:40:14.689 [debu] activity_bump: bumped deadline from activity request_id=43927a78-72a5-474d-bee6-9457847f0d7e workspace_id=3231f8fa-6c99-48aa-8ad8-e8a93d577eac
2023-08-15T08:41:07.9196714Z t.go:85: 2023-08-15 08:40:14.690 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=26.307904ms status_code=200 latency_ms=26 request_id=43927a78-72a5-474d-bee6-9457847f0d7e
2023-08-15T08:41:07.9197988Z t.go:85: 2023-08-15 08:40:14.708 [debu] read stats report request_id=3b9c2da7-b0ba-40cb-922f-4395ed11141b interval=5m0s workspace_agent_id=1de64d4f-2a05-449b-b9ee-67e7d09967ad workspace_id=0a3e4daf-3e6d-4785-8ec1-e4dd9ceffedf payload={"connections_by_proto":{"TCP":1},"connection_count":11,"connection_median_latency_ms":12000,"rx_packets":0,"rx_bytes":8,"tx_packets":0,"tx_bytes":5,"session_count_vscode":14,"session_count_jetbrains":16,"session_count_reconnecting_pty":18,"session_count_ssh":20,"metrics":null}
2023-08-15T08:41:07.9198847Z t.go:85: 2023-08-15 08:40:14.748 [debu] activity_bump: bumped deadline from activity request_id=3b9c2da7-b0ba-40cb-922f-4395ed11141b workspace_id=0a3e4daf-3e6d-4785-8ec1-e4dd9ceffedf
2023-08-15T08:41:07.9199586Z t.go:85: 2023-08-15 08:40:14.754 [debu] POST host=localhost:38147 path=/api/v2/workspaceagents/me/report-stats proto=HTTP/1.1 remote_addr=127.0.0.1 took=63.120834ms status_code=200 latency_ms=63 request_id=3b9c2da7-b0ba-40cb-922f-4395ed11141b
2023-08-15T08:41:07.9199962Z prometheusmetrics_test.go:457:
2023-08-15T08:41:07.9200571Z Error Trace: /home/runner/actions-runner/_work/coder/coder/coderd/prometheusmetrics/prometheusmetrics_test.go:457
2023-08-15T08:41:07.9200932Z Error: Condition never satisfied
2023-08-15T08:41:07.9201174Z Test: TestAgentStats
2023-08-15T08:41:07.9201457Z prometheusmetrics_test.go:489:
2023-08-15T08:41:07.9202022Z Error Trace: /home/runner/actions-runner/_work/coder/coder/coderd/prometheusmetrics/prometheusmetrics_test.go:489
2023-08-15T08:41:07.9202325Z Error: Not equal:
2023-08-15T08:41:07.9210285Z expected: map[string]int{"testuser:workspace-1:example:coderd_agentstats_connection_count":9, "testuser:workspace-1:example:coderd_agentstats_connection_median_latency_seconds":8, "testuser:workspace-1:example:coderd_agentstats_rx_bytes":9, "testuser:workspace-1:example:coderd_agentstats_session_count_jetbrains":6, "testuser:workspace-1:example:coderd_agentstats_session_count_reconnecting_pty":7, "testuser:workspace-1:example:coderd_agentstats_session_count_ssh":8, "testuser:workspace-1:example:coderd_agentstats_session_count_vscode":5, "testuser:workspace-1:example:coderd_agentstats_tx_bytes":6, "testuser:workspace-2:example:coderd_agentstats_connection_count":10, "testuser:workspace-2:example:coderd_agentstats_connection_median_latency_seconds":10, "testuser:workspace-2:example:coderd_agentstats_rx_bytes":15, "testuser:workspace-2:example:coderd_agentstats_session_count_jetbrains":10, "testuser:workspace-2:example:coderd_agentstats_session_count_reconnecting_pty":12, "testuser:workspace-2:example:coderd_agentstats_session_count_ssh":14, "testuser:workspace-2:example:coderd_agentstats_session_count_vscode":8, "testuser:workspace-2:example:coderd_agentstats_tx_bytes":9, "testuser:workspace-3:example:coderd_agentstats_connection_count":11, "testuser:workspace-3:example:coderd_agentstats_connection_median_latency_seconds":12, "testuser:workspace-3:example:coderd_agentstats_rx_bytes":21, "testuser:workspace-3:example:coderd_agentstats_session_count_jetbrains":16, "testuser:workspace-3:example:coderd_agentstats_session_count_reconnecting_pty":18, "testuser:workspace-3:example:coderd_agentstats_session_count_ssh":20, "testuser:workspace-3:example:coderd_agentstats_session_count_vscode":14, "testuser:workspace-3:example:coderd_agentstats_tx_bytes":12}
2023-08-15T08:41:07.9219755Z actual : map[string]int{"testuser:workspace-1:example:coderd_agentstats_connection_count":9, "testuser:workspace-1:example:coderd_agentstats_connection_median_latency_seconds":8, "testuser:workspace-1:example:coderd_agentstats_rx_bytes":9, "testuser:workspace-1:example:coderd_agentstats_session_count_jetbrains":6, "testuser:workspace-1:example:coderd_agentstats_session_count_reconnecting_pty":7, "testuser:workspace-1:example:coderd_agentstats_session_count_ssh":8, "testuser:workspace-1:example:coderd_agentstats_session_count_vscode":5, "testuser:workspace-1:example:coderd_agentstats_tx_bytes":6, "testuser:workspace-2:example:coderd_agentstats_connection_count":10, "testuser:workspace-2:example:coderd_agentstats_connection_median_latency_seconds":10, "testuser:workspace-2:example:coderd_agentstats_rx_bytes":15, "testuser:workspace-2:example:coderd_agentstats_session_count_jetbrains":10, "testuser:workspace-2:example:coderd_agentstats_session_count_reconnecting_pty":12, "testuser:workspace-2:example:coderd_agentstats_session_count_ssh":14, "testuser:workspace-2:example:coderd_agentstats_session_count_vscode":8, "testuser:workspace-2:example:coderd_agentstats_tx_bytes":9, "testuser:workspace-3:example:coderd_agentstats_connection_count":10, "testuser:workspace-3:example:coderd_agentstats_connection_median_latency_seconds":12, "testuser:workspace-3:example:coderd_agentstats_rx_bytes":13, "testuser:workspace-3:example:coderd_agentstats_session_count_jetbrains":15, "testuser:workspace-3:example:coderd_agentstats_session_count_reconnecting_pty":17, "testuser:workspace-3:example:coderd_agentstats_session_count_ssh":19, "testuser:workspace-3:example:coderd_agentstats_session_count_vscode":13, "testuser:workspace-3:example:coderd_agentstats_tx_bytes":7}
2023-08-15T08:41:07.9221296Z
2023-08-15T08:41:07.9221543Z Diff:
2023-08-15T08:41:07.9221831Z --- Expected
2023-08-15T08:41:07.9222080Z +++ Actual
2023-08-15T08:41:07.9222393Z @@ -17,10 +17,10 @@
2023-08-15T08:41:07.9223097Z (string) (len=55) "testuser:workspace-2:example:coderd_agentstats_tx_bytes": (int) 9,
2023-08-15T08:41:07.9223809Z - (string) (len=63) "testuser:workspace-3:example:coderd_agentstats_connection_count": (int) 11,
2023-08-15T08:41:07.9224529Z + (string) (len=63) "testuser:workspace-3:example:coderd_agentstats_connection_count": (int) 10,
2023-08-15T08:41:07.9225371Z (string) (len=80) "testuser:workspace-3:example:coderd_agentstats_connection_median_latency_seconds": (int) 12,
2023-08-15T08:41:07.9226149Z - (string) (len=55) "testuser:workspace-3:example:coderd_agentstats_rx_bytes": (int) 21,
2023-08-15T08:41:07.9226888Z - (string) (len=70) "testuser:workspace-3:example:coderd_agentstats_session_count_jetbrains": (int) 16,
2023-08-15T08:41:07.9227751Z - (string) (len=77) "testuser:workspace-3:example:coderd_agentstats_session_count_reconnecting_pty": (int) 18,
2023-08-15T08:41:07.9228502Z - (string) (len=64) "testuser:workspace-3:example:coderd_agentstats_session_count_ssh": (int) 20,
2023-08-15T08:41:07.9229252Z - (string) (len=67) "testuser:workspace-3:example:coderd_agentstats_session_count_vscode": (int) 14,
2023-08-15T08:41:07.9229934Z - (string) (len=55) "testuser:workspace-3:example:coderd_agentstats_tx_bytes": (int) 12
2023-08-15T08:41:07.9230605Z + (string) (len=55) "testuser:workspace-3:example:coderd_agentstats_rx_bytes": (int) 13,
2023-08-15T08:41:07.9231346Z + (string) (len=70) "testuser:workspace-3:example:coderd_agentstats_session_count_jetbrains": (int) 15,
2023-08-15T08:41:07.9232144Z + (string) (len=77) "testuser:workspace-3:example:coderd_agentstats_session_count_reconnecting_pty": (int) 17,
2023-08-15T08:41:07.9232876Z + (string) (len=64) "testuser:workspace-3:example:coderd_agentstats_session_count_ssh": (int) 19,
2023-08-15T08:41:07.9233636Z + (string) (len=67) "testuser:workspace-3:example:coderd_agentstats_session_count_vscode": (int) 13,
2023-08-15T08:41:07.9234303Z + (string) (len=55) "testuser:workspace-3:example:coderd_agentstats_tx_bytes": (int) 7
2023-08-15T08:41:07.9234601Z }
2023-08-15T08:41:07.9234840Z Test: TestAgentStats
2023-08-15T08:41:07.9235207Z t.go:88: 2023-08-15 08:40:24.759 [erro] can't get agent stats error="context canceled"
2023-08-15T08:41:07.9235619Z t.go:85: 2023-08-15 08:40:24.759 [debu] provisionerd: closing server with error error=<nil>
2023-08-15T08:41:07.9236047Z t.go:85: 2023-08-15 08:40:24.759 [warn] context done, flushing before exit
2023-08-15T08:41:07.9236333Z
Metadata
Metadata
Assignees
Labels
s4Internal bugs (e.g. test flakes), extreme edge cases, and bug risksInternal bugs (e.g. test flakes), extreme edge cases, and bug risks