Closed
Description
Seen here: https://github.com/coder/coder/actions/runs/6096050093/job/16540816865?pr=9522#step:5:261
Failed under race detector (but not a data race)
Logs:
=== Failed
=== FAIL: coderd TestPatchTemplateMeta/Modified (0.19s)
t.go:85: 2023-09-06 10:46:10.268 [debu] metrics_cache: deployment stats metrics refreshed took=6.143µs interval=5m0s
t.go:85: 2023-09-06 10:46:10.269 [debu] workspaceapps.stats_collector: workspace app stats collector started
t.go:85: 2023-09-06 10:46:10.273 [debu] metrics_cache: template daus metrics refreshed took=4.11[261](https://github.com/coder/coder/actions/runs/6096050093/job/16540816865?pr=9522#step:5:262)9ms interval=1h0m0s
t.go:85: 2023-09-06 10:46:10.288 [debu] provisionerd: successfully connected to coderd
t.go:85: 2023-09-06 10:46:10.300 [debu] POST host=localhost:41073 path=/api/v2/users/first proto=HTTP/1.1 remote_addr=127.0.0.1 took=11.536395ms status_code=201 latency_ms=11 request_id=43c02d05-60cf-4584-ab8c-27087d864670
t.go:85: 2023-09-06 10:46:10.309 [debu] POST host=localhost:41073 path=/api/v2/users/login proto=HTTP/1.1 remote_addr=127.0.0.1 took=5.188179ms status_code=201 latency_ms=5 request_id=af277a82-020c-4058-bec3-7581c6ff13ce
t.go:85: 2023-09-06 10:46:10.323 [debu] POST host=localhost:41073 path=/api/v2/files proto=HTTP/1.1 remote_addr=127.0.0.1 took=12.318649ms status_code=201 latency_ms=12 request_id=835fb11b-27df-4a44-b140-fe92aad36a31
t.go:85: 2023-09-06 10:46:10.354 [debu] POST host=localhost:41073 path=/api/v2/organizations/440491d6-cec5-49aa-a0d3-a781a8ef7f93/templateversions proto=HTTP/1.1 remote_addr=127.0.0.1 took=30.30254ms status_code=201 latency_ms=30 request_id=ff6da039-74bb-4e0d-ac62-feca8fc6f7a3
t.go:85: 2023-09-06 10:46:10.354 [debu] provisionerd-cool_ardinghelli4: locked job from database job_id=322dfcb7-7cdf-4b4a-944e-97c9f3afb1d8
t.go:85: 2023-09-06 10:46:10.368 [debu] POST host=localhost:41073 path=/api/v2/organizations/440491d6-cec5-49aa-a0d3-a781a8ef7f93/templates proto=HTTP/1.1 remote_addr=127.0.0.1 took=12.4857ms status_code=201 latency_ms=12 request_id=5455a2f4-11c2-4782-8322-c88adfe865e8
t.go:85: 2023-09-06 10:46:10.374 [debu] provisionerd: called AcquireJob on client job_id=322dfcb7-7cdf-4b4a-944e-97c9f3afb1d8 error=<nil>
t.go:85: 2023-09-06 10:46:10.374 [debu] provisionerd: acquired job initiator_username=testuser provisioner=echo job_id=322dfcb7-7cdf-4b4a-944e-97c9f3afb1d8
t.go:85: 2023-09-06 10:46:10.375 [debu] provisionerd.runner: acquired job is template import job_id=322dfcb7-7cdf-4b4a-944e-97c9f3afb1d8 user_variable_values=[]
t.go:85: 2023-09-06 10:46:10.388 [debu] PATCH host=localhost:41073 path=/api/v2/templates/43b59658-86f0-4283-89cf-dc318315db31 proto=HTTP/1.1 remote_addr=127.0.0.1 took=12.754154ms status_code=200 latency_ms=12 request_id=b7a605a7-503d-41b4-ab00-01b216807133
t.go:85: 2023-09-06 10:46:10.389 [debu] GET host=localhost:41073 path=/api/v2/templates/43b59658-86f0-4283-89cf-dc318315db31 proto=HTTP/1.1 remote_addr=127.0.0.1 took=641.969µs status_code=200 latency_ms=0 request_id=03f15dc5-9e85-4d0f-bd08-51ac1a63ad75
t.go:85: 2023-09-06 10:46:10.398 [info] echo: unpacking template source archive session_id=b02f3841-7995-4859-90ab-edef8cd01183 size_bytes=3072
t.go:85: 2023-09-06 10:46:10.408 [debu] provisionerd-cool_ardinghelli4: stage FailJob starting job_id=322dfcb7-7cdf-4b4a-944e-97c9f3afb1d8
t.go:85: 2023-09-06 10:46:10.408 [debu] provisionerd: closing server with error error=<nil>
t.go:85: 2023-09-06 10:46:10.408 [debu] workspaceapps.stats_collector: flushing workspace app stats
t.go:85: 2023-09-06 10:46:10.408 [debu] workspaceapps.stats_collector: flushed workspace app stats
t.go:85: 2023-09-06 10:46:10.408 [debu] workspaceapps.stats_collector: workspace app stats collector stopped
t.go:85: 2023-09-06 10:46:10.412 [debu] echo: extracted file session_id=b02f3841-7995-4859-90ab-edef8cd01183 size_bytes=2 path=/tmp/TestPatchTemplateMetaModified2[262](https://github.com/coder/coder/actions/runs/6096050093/job/16540816865?pr=9522#step:5:263)569406/002/Sessionb02f3841-7995-4859-90ab-edef8cd01183/0.parse.protobuf mode=-rw-r--r--
t.go:85: 2023-09-06 10:46:10.413 [debu] echo: extracted file session_id=b02f3841-7995-4859-90ab-edef8cd01183 size_bytes=2 path=/tmp/TestPatchTemplateMetaModified2262569406/002/Sessionb02f3841-7995-4859-90ab-edef8cd01183/0.apply.protobuf mode=-rw-r--r--
testing.go:1206: TempDir RemoveAll cleanup: unlinkat /tmp/TestPatchTemplateMetaModified2262569406/002/Sessionb02f3841-7995-4859-90ab-edef8cd01183: directory not empty
t.go:85: 2023-09-06 10:46:10.413 [debu] echo: extracted file session_id=b02f3841-7995-4859-90ab-edef8cd01183 size_bytes=2 path=/tmp/TestPatchTemplateMetaModified2262569406/002/Sessionb02f3841-7995-4859-90ab-edef8cd01183/0.plan.protobuf mode=-rw-r--r--
stuntest.go:63: STUN server shutdown
=== FAIL: coderd TestPatchTemplateMeta (0.00s)
This bit looks sus:
// It is unfortunate we need to sleep, but the test can fail if the
// updatedAt is too close together.
time.Sleep(time.Millisecond * 5)