Skip to content

test flake: TestPatchCancelWorkspaceBuild #9331

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
johnstcn opened this issue Aug 25, 2023 · 2 comments
Closed

test flake: TestPatchCancelWorkspaceBuild #9331

johnstcn opened this issue Aug 25, 2023 · 2 comments
Assignees
@spikecurtis
Labels
s4 Internal bugs (e.g. test flakes), extreme edge cases, and bug risks

Comments

@johnstcn
Copy link
Member

Seen in: https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330

=== FAIL: coderd TestPatchCancelWorkspaceBuild/User_is_not_allowed_to_cancel (2.00s)
    t.go:85: 2023-08-25 09:27:18.518 [debu]  workspaceapps.stats_collector: workspace app stats collector started
    t.go:85: 2023-08-25 09:27:18.522 [debu]  provisionerd: successfully connected to coderd
    t.go:85: 2023-08-25 09:27:18.529 [debu]  metrics_cache: deployment stats metrics refreshed  took=11.236888ms  interval=5m0s
    t.go:85: 2023-08-25 09:27:18.572 [debu]  metrics_cache: template daus metrics refreshed  took=54.565245ms  interval=1h0m0s
    t.go:85: 2023-08-25 09:27:18.577 [debu]  POST  host=localhost:36613  path=/api/v2/users/first  proto=HTTP/1.1  remote_addr=127.0.0.1  took=56.731121ms  status_code=201  latency_ms=56  request_id=94f2b3c0-60de-474b-928b-f4421a4245e6
    t.go:85: 2023-08-25 09:27:18.592 [debu]  POST  host=localhost:36613  path=/api/v2/users/login  proto=HTTP/1.1  remote_addr=127.0.0.1  took=13.958847ms  status_code=201  latency_ms=13  request_id=85bd0fc4-d9c8-4341-8586-8586beb30d67
    t.go:85: 2023-08-25 09:27:18.608 [debu]  POST  host=localhost:36613  path=/api/v2/files  proto=HTTP/1.1  remote_addr=127.0.0.1  took=16.65122ms  status_code=201  latency_ms=16  request_id=1925d724-1943-496e-a67e-0b3c60747582
    t.go:85: 2023-08-25 09:27:18.656 [debu]  POST  host=localhost:36613  path=/api/v2/organizations/6714fa77-fca9-40a0-83e7-030b323e98c7/templateversions  proto=HTTP/1.1  remote_addr=127.0.0.1  took=47.149692ms  status_code=201  latency_ms=47  request_id=44fa8160-91ee-438d-ad27-251f067da71b
    workspacebuilds_test.go:426: waiting for template version job 27bc9ac0-d2b4-4067-baeb-f170debd428b
    t.go:85: 2023-08-25 09:27:18.704 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=22.624523ms  status_code=200  latency_ms=22  request_id=cd1cc5ee-1bf1-4990-aab3-5f729a87cc4a
    t.go:85: 2023-08-25 09:27:18.722 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=14.500303ms  status_code=200  latency_ms=14  request_id=e7731d82-a36e-4d22-832a-8e62c1533127
    t.go:85: 2023-08-25 09:27:18.746 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=14.570366ms  status_code=200  latency_ms=14  request_id=475a22b7-464a-452d-9111-9f9e98515df0
    t.go:85: 2023-08-25 09:27:18.783 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=23.673239ms  status_code=200  latency_ms=23  request_id=a870d183-f2df-4d21-802d-eb00c111ed3b
    t.go:85: 2023-08-25 09:27:18.819 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=32.828863ms  status_code=200  latency_ms=32  request_id=81960cc7-ac8a-470f-82d0-23e65d2f78d3
    t.go:85: 2023-08-25 09:27:18.839 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=19.656181ms  status_code=200  latency_ms=19  request_id=f6adc2bb-68d5-4ed6-96f4-3c9a741dffbb
    t.go:85: 2023-08-25 09:27:18.886 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=46.22388ms  status_code=200  latency_ms=46  request_id=1c57fa16-f270-44a8-9887-8887d0c07f2d
    t.go:85: 2023-08-25 09:27:18.938 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=52.08111ms  status_code=200  latency_ms=52  request_id=fc6039ae-4bc1-4135-ad2a-1b98d3dd44b8
    t.go:85: 2023-08-25 09:27:18.969 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=31.170839ms  status_code=200  latency_ms=31  request_id=c119b4cb-0de7-4a8d-b8ef-97153c6c6aff
    t.go:85: 2023-08-25 09:27:18.999 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=29.109685ms  status_code=200  latency_ms=29  request_id=9eed2d6b-4656-4060-8a3a-9c27358d3995
    t.go:85: 2023-08-25 09:27:19.033 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=33.831[281](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:282)ms  status_code=200  latency_ms=33  request_id=7db46ed8-255c-4a9f-8658-4d89bcb61e58
    t.go:85: 2023-08-25 09:27:19.062 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=28.170749ms  status_code=200  latency_ms=28  request_id=86b8c1b6-d9e0-47ae-b2e5-8079a248e899
    t.go:85: 2023-08-25 09:27:19.083 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=18.506702ms  status_code=200  latency_ms=18  request_id=a9e14960-e5af-4d49-b58a-97fd652a709e
    t.go:85: 2023-08-25 09:27:19.102 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=17.001403ms  status_code=200  latency_ms=17  request_id=649ce8a6-eb1a-475d-97a0-a62eec99c151
    t.go:85: 2023-08-25 09:27:19.121 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=14.483175ms  status_code=200  latency_ms=14  request_id=e0a36d2c-cb17-46fa-9eef-e290f8892149
    t.go:85: 2023-08-25 09:27:19.141 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=8.065019ms  status_code=200  latency_ms=8  request_id=5cf07e3e-624a-4431-9f07-170414a85fd3
    t.go:85: 2023-08-25 09:27:19.194 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=36.905368ms  status_code=200  latency_ms=36  request_id=0f44d4c9-82b2-4772-b502-6b01ad072c57
    t.go:85: 2023-08-25 09:27:19.238 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=43.570709ms  status_code=200  latency_ms=43  request_id=b5c9a405-a9a5-4434-8425-7d7b3b99bb25
    t.go:85: 2023-08-25 09:27:19.[283](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:284) [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=45.359521ms  status_code=200  latency_ms=45  request_id=2256f08e-8570-46d4-b530-aaf833c6a021
    t.go:85: 2023-08-25 09:27:19.377 [debu]  provisionerd-nifty_babbage9: locked job from database  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.385 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=101.594795ms  status_code=200  latency_ms=101  request_id=b224f018-7055-464b-be34-84794dbea943
    t.go:85: 2023-08-25 09:27:19.404 [debu]  provisionerd: acquired job  initiator_username=testuser  provisioner=echo  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.404 [debu]  provisionerd.runner: acquired job is template import  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  user_variable_values=[]
    t.go:85: 2023-08-25 09:27:19.404 [info]  echo: unpacking template source archive  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a  size_bytes=3072
    t.go:85: 2023-08-25 09:27:19.404 [debu]  echo: extracted file  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a  size_bytes=2  path=/tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Sessione1b223d9-8a12-462f-b821-96509c4c8d3a/0.parse.protobuf  mode=-rw-r--r--
    t.go:85: 2023-08-25 09:27:19.404 [debu]  echo: extracted file  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a  size_bytes=2  path=/tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Sessione1b223d9-8a12-462f-b821-96509c4c8d3a/0.apply.protobuf  mode=-rw-r--r--
    t.go:85: 2023-08-25 09:27:19.404 [debu]  echo: extracted file  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a  size_bytes=2  path=/tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Sessione1b223d9-8a12-462f-b821-96509c4c8d3a/0.plan.protobuf  mode=-rw-r--r--
    t.go:85: 2023-08-25 09:27:19.405 [debu]  echo: failed to parse readme (missing ok)  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a  error="open /tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Sessione1b223d9-8a12-462f-b821-96509c4c8d3a/README.md: no such file or directory"
    t.go:85: 2023-08-25 09:27:19.405 [debu]  provisionerd.runner: parse complete  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  template_variables=[]  readme_len=0  error=""
    t.go:85: 2023-08-25 09:27:19.405 [debu]  provisionerd-nifty_babbage9: stage UpdateJob starting  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.423 [info]  provisionerd.runner: parse dry-run provision successful  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  resource_count=0  resources=[]
    t.go:85: 2023-08-25 09:27:19.423 [info]  provisionerd.runner: parse dry-run provision successful  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  resource_count=0  resources=[]
    t.go:85: 2023-08-25 09:27:19.423 [debu]  provisionerd-nifty_babbage9: stage UpdateJob starting  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.434 [debu]  provisionerd-nifty_babbage9: job log  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  stage="Setting up"  output=""
    t.go:85: 2023-08-25 09:27:19.434 [debu]  provisionerd-nifty_babbage9: job log  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  stage="Parsing template parameters"  output=""
    t.go:85: 2023-08-25 09:27:19.434 [debu]  provisionerd-nifty_babbage9: job log  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  stage="Detecting persistent resources"  output=""
    t.go:85: 2023-08-25 09:27:19.434 [debu]  provisionerd-nifty_babbage9: job log  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  stage="Detecting ephemeral resources"  output=""
    t.go:85: 2023-08-25 09:27:19.434 [debu]  provisionerd-nifty_babbage9: job log  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5  stage="Cleaning Up"  output=""
    t.go:85: 2023-08-25 09:27:19.437 [debu]  provisionerd-nifty_babbage9: inserted job logs  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.441 [debu]  provisionerd-nifty_babbage9: published job logs  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.441 [debu]  provisionerd.runner: sending CompletedJob  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.441 [info]  echo: recv done on Session  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a  error=EOF
    t.go:85: 2023-08-25 09:27:19.441 [debu]  echo: cleaned up work directory  session_id=e1b223d9-8a12-462f-b821-96509c4c8d3a
    t.go:85: 2023-08-25 09:27:19.441 [debu]  provisionerd-nifty_babbage9: stage CompleteJob starting  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.450 [debu]  provisionerd-nifty_babbage9: marked import job as completed  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.450 [debu]  provisionerd-nifty_babbage9: stage CompleteJob done  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.451 [debu]  provisionerd.runner: sent CompletedJob  job_id=e995eea1-efd2-440a-b077-e8e8a03efcb5
    t.go:85: 2023-08-25 09:27:19.470 [debu]  GET  host=localhost:36613  path=/api/v2/templateversions/27bc9ac0-d2b4-4067-baeb-f170debd428b  proto=HTTP/1.1  remote_addr=127.0.0.1  took=84.154683ms  status_code=200  latency_ms=84  request_id=3d977060-6962-4814-8799-73db033e9d6e
    workspacebuilds_test.go:426: got template version job 27bc9ac0-d2b4-4067-baeb-f170debd428b
    t.go:85: 2023-08-25 09:27:19.517 [debu]  POST  host=localhost:36613  path=/api/v2/organizations/6714fa77-fca9-40a0-83e7-030b323e98c7/templates  proto=HTTP/1.1  remote_addr=127.0.0.1  took=46.800146ms  status_code=201  latency_ms=46  request_id=a7afda8a-f933-4cf1-872a-c1121190cc16
    t.go:85: 2023-08-25 09:27:19.534 [debu]  POST  host=localhost:36613  path=/api/v2/users  proto=HTTP/1.1  remote_addr=127.0.0.1  took=16.249484ms  status_code=201  latency_ms=16  request_id=6f99a436-40b5-4240-8cb1-a803742cc7ec
    t.go:85: 2023-08-25 09:27:19.545 [debu]  POST  host=localhost:36613  path=/api/v2/users/login  proto=HTTP/1.1  remote_addr=127.0.0.1  took=10.417468ms  status_code=201  latency_ms=10  request_id=86570b23-886d-49a2-b8e7-539c051d08cd
    t.go:85: 2023-08-25 09:27:19.552 [debu]  GET  host=localhost:36613  path=/api/v2/users/dazzling-margulis7-F8W  proto=HTTP/1.1  remote_addr=127.0.0.1  took=7.197789ms  status_code=200  latency_ms=7  request_id=56790257-1ce3-44b9-8348-ec938c[293](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:294)0f2
    t.go:85: 2023-08-25 09:27:19.623 [debu]  POST  host=localhost:36613  path=/api/v2/organizations/6714fa77-fca9-40a0-83e7-030b323e98c7/members/me/workspaces  proto=HTTP/1.1  remote_addr=127.0.0.1  took=67.926689ms  status_code=201  latency_ms=67  request_id=6aa09d0f-379f-4604-a565-d4ad5d35137c
    t.go:85: 2023-08-25 09:27:19.660 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=10.93666ms  status_code=200  latency_ms=10  request_id=ba4c645b-a390-4dfd-8141-7b88e2cccf74
    t.go:85: 2023-08-25 09:27:19.699 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=24.730728ms  status_code=200  latency_ms=24  request_id=46[300](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:301)8a2-b097-43d9-9500-4f69a486fa4d
    t.go:85: 2023-08-25 09:27:19.755 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=55.671476ms  status_code=200  latency_ms=55  request_id=4f2c97c1-942e-4ee4-b6f4-bed4d3b41a76
    t.go:85: 2023-08-25 09:27:19.796 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=40.535602ms  status_code=200  latency_ms=40  request_id=69635ccc-1fea-4743-9754-6b8aa3dcc90b
    t.go:85: 2023-08-25 09:27:19.812 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=15.13946ms  status_code=200  latency_ms=15  request_id=2a586315-1084-4eb9-b9f7-1a1a1f3863f0
    t.go:85: 2023-08-25 09:27:19.825 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=10.306977ms  status_code=200  latency_ms=10  request_id=3d943fe9-5d3f-469a-909c-d43c973363f4
    t.go:85: 2023-08-25 09:27:19.833 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=8.373378ms  status_code=200  latency_ms=8  request_id=a25a2bdc-fbaa-4ed9-97d8-00ee8b0ea408
    t.go:85: 2023-08-25 09:27:19.882 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=32.163386ms  status_code=200  latency_ms=32  request_id=8ed422fc-4109-4f3e-9afe-82cc02358f80
    t.go:85: 2023-08-25 09:27:19.944 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=62.07146ms  status_code=200  latency_ms=62  request_id=ca71c3a2-e69e-45a5-a7a5-69267d703b8d
    t.go:85: 2023-08-25 09:27:19.972 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=27.271869ms  status_code=200  latency_ms=27  request_id=53d52be2-c2f0-47ae-ba2b-f18488de50c6
    t.go:85: 2023-08-25 09:27:20.027 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=54.743308ms  status_code=200  latency_ms=54  request_id=c70014c9-16c6-4e7e-8385-72be6ac8b3ef
    t.go:85: 2023-08-25 09:27:20.052 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=24.353[302](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:303)ms  status_code=200  latency_ms=24  request_id=91960d2a-e6c0-466a-ae9a-e40d230e01c5
    t.go:85: 2023-08-25 09:27:20.086 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=32.674172ms  status_code=200  latency_ms=32  request_id=10c25be7-3736-459d-adca-dc3af8e83dfe
    t.go:85: 2023-08-25 09:27:20.099 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=12.600182ms  status_code=200  latency_ms=12  request_id=16e18f98-63c7-41de-936f-552a4b4b6962
    t.go:85: 2023-08-25 09:27:20.106 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=6.559141ms  status_code=200  latency_ms=6  request_id=7d4a9048-94dc-42c1-93f1-11fca1ff120b
    t.go:85: 2023-08-25 09:27:20.131 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=5.11543ms  status_code=200  latency_ms=5  request_id=d4f22ca0-eed7-4cfc-a17b-7e8aba1aefd1
    t.go:85: 2023-08-25 09:27:20.166 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=16.314743ms  status_code=200  latency_ms=16  request_id=ef92e351-0fac-4b29-86a0-8aaf18a0a673
    t.go:85: 2023-08-25 09:27:20.206 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=32.266052ms  status_code=200  latency_ms=32  request_id=49516aad-4266-480c-b1c8-9a953e121d5c
    t.go:85: 2023-08-25 09:27:20.230 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=23.105217ms  status_code=200  latency_ms=23  request_id=454705bd-487b-48c2-81f7-8c40c22064ab
    t.go:85: 2023-08-25 09:27:20.261 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=30.486268ms  status_code=200  latency_ms=30  request_id=b350540e-7836-4818-9a9f-0e33478dccf3
    t.go:85: 2023-08-25 09:27:20.309 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=47.004121ms  status_code=200  latency_ms=47  request_id=10e5654c-d96c-4792-bb64-9678c25eaf07
    t.go:85: 2023-08-25 09:27:20.351 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=41.965557ms  status_code=200  latency_ms=41  request_id=0fa05f7a-2426-433f-a165-aebd6055d6dd
    t.go:85: 2023-08-25 09:27:20.352 [debu]  provisionerd-nifty_babbage9: locked job from database  job_id=4d745213-806e-446f-b185-a09148e3ebc9
    t.go:85: 2023-08-25 09:27:20.388 [debu]  GET  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414  proto=HTTP/1.1  remote_addr=127.0.0.1  took=36.43868ms  status_code=200  latency_ms=36  request_id=1167e6b1-a236-419c-ac66-52268567602c
    t.go:85: 2023-08-25 09:27:20.401 [debu]  provisionerd: acquired job  initiator_username=dazzling-margulis7-F8W  provisioner=echo  job_id=4d745213-806e-446f-b185-a09148e3ebc9  workspace_transition=START  workspace_owner=dazzling-margulis7-F8W  template_name=pedantic-dirac1-kHj  template_version=beautiful_dewdney3  workspace_build_id=702c90e8-26af-412d-8687-2190a0bab414  workspace_id=f7233dd4-ffb1-47e9-8bbe-77dfe5203741  workspace_name=priceless-torvalds4-25c
    t.go:85: 2023-08-25 09:27:20.401 [debu]  provisionerd.runner: acquired job is workspace provision  job_id=4d745213-806e-446f-b185-a09148e3ebc9  template_name=pedantic-dirac1-kHj  template_version=beautiful_dewdney3  workspace_build_id=702c90e8-26af-412d-8687-2190a0bab414  workspace_id=f7233dd4-ffb1-47e9-8bbe-77dfe5203741  workspace_name=priceless-torvalds4-25c  workspace_owner=dazzling-margulis7-F8W  workspace_transition=start  workspace_name=priceless-torvalds4-25c  state_length=0  rich_parameter_values=[]  variable_values=[]
    t.go:85: 2023-08-25 09:27:20.401 [info]  echo: unpacking template source archive  session_id=5920f84e-f7ce-481b-a9ed-2edeb8320183  size_bytes=[307](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:308)2
    t.go:85: 2023-08-25 09:27:20.401 [debu]  echo: extracted file  session_id=5920f84e-f7ce-481b-a9ed-2edeb8[320](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:321)183  size_bytes=2  path=/tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Session5920f84e-f7ce-481b-a9ed-2edeb8320183/0.parse.protobuf  mode=-rw-r--r--
    t.go:85: 2023-08-25 09:27:20.402 [debu]  echo: extracted file  session_id=5920f84e-f7ce-481b-a9ed-2edeb8320183  size_bytes=2  path=/tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Session5920f84e-f7ce-481b-a9ed-2edeb8320183/0.apply.protobuf  mode=-rw-r--r--
    t.go:85: 2023-08-25 09:27:20.402 [debu]  echo: extracted file  session_id=5920f84e-f7ce-481b-a9ed-2edeb8320183  size_bytes=2  path=/tmp/TestPatchCancelWorkspaceBuildUser_is_not_allowed_to_cancel2227389711/002/Session5920f84e-f7ce-481b-a9ed-2edeb8320183/0.plan.protobuf  mode=-rw-r--r--
    t.go:85: 2023-08-25 09:27:20.402 [info]  provisionerd.runner: plan request successful  job_id=4d745213-806e-446f-b185-a09148e3ebc9  template_name=pedantic-dirac1-kHj  template_version=beautiful_dewdney3  workspace_build_id=702c90e8-26af-412d-8687-2190a0bab414  workspace_id=f7233dd4-ffb1-47e9-8bbe-77dfe5203741  workspace_name=priceless-torvalds4-25c  workspace_owner=dazzling-margulis7-F8W  workspace_transition=start  resource_count=0  resources=[]
    t.go:85: 2023-08-25 09:27:20.402 [debu]  provisionerd-nifty_babbage9: stage UpdateJob starting  job_id=4d745213-806e-446f-b185-a09148e3ebc9
    t.go:85: 2023-08-25 09:27:20.405 [debu]  PATCH  host=localhost:36613  path=/api/v2/workspacebuilds/702c90e8-26af-412d-8687-2190a0bab414/cancel  proto=HTTP/1.1  remote_addr=127.0.0.1  took=16.611851ms  status_code=403  latency_ms=16  request_id=a1c1bb50-fa44-4cfd-828a-82[345](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:346)9f64647
    t.go:85: 2023-08-25 09:27:20.415 [debu]  provisionerd-nifty_babbage9: job log  job_id=4d745213-806e-446f-b185-a09148e3ebc9  stage="Setting up"  output=""
    t.go:85: 2023-08-25 09:27:20.417 [debu]  provisionerd-nifty_babbage9: inserted job logs  job_id=4d745213-806e-446f-b185-a09148e3ebc9
    t.go:85: 2023-08-25 09:27:20.418 [debu]  provisionerd-nifty_babbage9: published job logs  job_id=4d745213-806e-446f-b185-a09148e3ebc9
    t.go:85: 2023-08-25 09:27:20.418 [debu]  provisionerd.runner: committing quota  job_id=4d745213-806e-446f-b185-a09148e3ebc9  template_name=pedantic-dirac1-kHj  template_version=beautiful_dewdney3  workspace_build_id=702c90e8-26af-412d-8687-2190a0bab414  workspace_id=f7233dd4-ffb1-47e9-8bbe-77dfe520[374](https://github.com/coder/coder/actions/runs/5974225410/job/16207962514?pr=9330#step:5:375)1  workspace_name=priceless-torvalds4-25c  workspace_owner=dazzling-margulis7-F8W  workspace_transition=start  resources=[]  cost=0
    t.go:85: 2023-08-25 09:27:20.418 [debu]  provisionerd-nifty_babbage9: stage UpdateJob starting  job_id=4d745213-806e-446f-b185-a09148e3ebc9
    t.go:85: 2023-08-25 09:27:20.426 [debu]  provisionerd-nifty_babbage9: stage FailJob starting  job_id=4d745213-806e-446f-b185-a09148e3ebc9
    t.go:85: 2023-08-25 09:27:20.481 [debu]  provisionerd: closing server with error  error=<nil>
    t.go:85: 2023-08-25 09:27:20.482 [debu]  drpc server error ...
        error= context canceled
               	storj.io/drpc/drpcserver.(*Server).ServeOne:64
               	storj.io/drpc/drpcserver.(*Server).Serve.func2:114
               	storj.io/drpc/drpcctx.(*Tracker).track:35
    t.go:85: 2023-08-25 09:27:20.482 [debu]  workspaceapps.stats_collector: flushing workspace app stats
    t.go:85: 2023-08-25 09:27:20.482 [debu]  workspaceapps.stats_collector: flushed workspace app stats
    t.go:85: 2023-08-25 09:27:20.482 [debu]  workspaceapps.stats_collector: workspace app stats collector stopped
    t.go:90: 2023-08-25 09:27:20.482 [erro]  echo: failed to transmit log  session_id=5920f84e-f7ce-481b-a9ed-2edeb8320183  level=TRACE  output=""
    t.go:85: 2023-08-25 09:27:20.482 [info]  echo: recv done on Session  session_id=5920f84e-f7ce-481b-a9ed-2edeb8320183  error="context canceled"
    t.go:85: 2023-08-25 09:27:20.482 [debu]  echo: cleaned up work directory  session_id=5920f84e-f7ce-481b-a9ed-2edeb8320183
    stuntest.go:63: STUN server shutdown

=== FAIL: coderd TestPatchCancelWorkspaceBuild (0.00s)
@johnstcn johnstcn mentioned this issue Aug 25, 2023
Merged
@spikecurtis
Copy link
Contributor

it's the error log..., which is legit because we shut everything down while the Echo provisioner is still trying to do stuff.

@johnstcn johnstcn added flake s4 Internal bugs (e.g. test flakes), extreme edge cases, and bug risks labels Aug 25, 2023
@spikecurtis
Copy link
Contributor

Fixed in #9330

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@spikecurtis spikecurtis

Labels
s4 Internal bugs (e.g. test flakes), extreme edge cases, and bug risks
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@johnstcn @spikecurtis