Skip to content

"Internal error preparing sql filter" due to cancelled request reflects in HTTP500 #9986

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.

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

Closed
mtojek opened this issue Oct 2, 2023 · 1 comment · Fixed by #10763
Closed
Assignees
Labels
s4 Internal bugs (e.g. test flakes), extreme edge cases, and bug risks

Comments

@mtojek
Copy link
Member

mtojek commented Oct 2, 2023

This was caught by our E2E tests:

2023-09-29T23:34:53.8487312Z [stderr] [create first user]:   �[38;5;45;1mpw:api �[0m<= browserContext.storageState succeeded �[38;5;45m+4ms�[0m
2023-09-29T23:34:53.8561010Z [stderr] [unknown]: [WebServer] �[0m2023-09-29 23:34:53.855 [warn]  coderd: GET  host=localhost:3000  path=/api/v2/workspaces  proto=HTTP/1.1  remote_addr=127.0.0.1  start="2023-09-29T23:34:53.854909951Z"  took=417.406µs  status_code=500  latency_ms=0  response_body="{\"message\":\"Internal error preparing sql filter.\",\"detail\":\"prepare filter: new partial authorizer: prepare: eval_cancel_error: caller cancelled query execution\"}\n"  request_id=ce08988e-6178-4afa-a3ba-3559a07e7a85
2023-09-29T23:34:53.8563849Z �[0m2023-09-29 23:34:53.855 [warn]  coderd: GET  host=localhost:3000  path=/api/v2/users  proto=HTTP/1.1  remote_addr=127.0.0.1  start="2023-09-29T23:34:53.853401857Z"  took=1.977349ms  status_code=500  latency_ms=1  response_body="{\"message\":\"Internal error fetching users.\",\"detail\":\"(dev error) prepare sql filter: new partial authorizer: prepare: eval_cancel_error: caller cancelled query execution\"}\n"  request_id=8a56a1a9-c1a9-4539-9c96-735fffa2c4b2
2023-09-29T23:34:53.8646211Z Finished test create first user: passed

Link: https://github.com/coder/coder/actions/runs/6358309656/attempts/1?pr=9907

Unfortunately, we lost pprof dump due to a job retry.

It also seems to affect also next E2E tests:

2023-09-29T23:34:55.1276518Z [stdout] [app]: [onRequest] method=POST url=http://localhost:3000/api/v2/organizations/31d5754e-64cd-40ca-9ed6-94e061faafea/templateversions postData={"storage_method":"file","file_id":"19beaf28-abda-4f0a-b080-8d61a3068a04","provisioner":"echo","tags":{}}
2023-09-29T23:34:55.1303344Z [stderr] [app]:   �[38;5;45;1mpw:api �[0m=> response.body started �[38;5;45m+44ms�[0m
2023-09-29T23:34:55.1306863Z [stdout] [app]: [onConsole] Failed to load resource: the server responded with a status of 404 (Not Found)
2023-09-29T23:34:55.1445452Z [stderr] [app]:   �[38;5;45;1mpw:api �[0m  click action done �[38;5;45m+14ms�[0m
2023-09-29T23:34:55.1446785Z [stderr] [app]:   �[38;5;45;1mpw:api �[0m  waiting for scheduled navigations to finish �[38;5;45m+0ms�[0m
2023-09-29T23:34:55.1447679Z [stderr] [app]:   �[38;5;45;1mpw:api �[0m<= response.body succeeded �[38;5;45m+0ms�[0m
2023-09-29T23:34:55.1449051Z [stdout] [app]: [onResponse] url=http://localhost:3000/api/v2/organizations/31d5754e-64cd-40ca-9ed6-94e061faafea/templateversions status=404 body={"message":"Resource not found or you do not have access to this resource"}
@cdr-bot cdr-bot bot added the bug label Oct 2, 2023
@mtojek mtojek added the flake label Oct 2, 2023
@matifali matifali added the s4 Internal bugs (e.g. test flakes), extreme edge cases, and bug risks label Oct 2, 2023
@Emyrk
Copy link
Member

Emyrk commented Nov 17, 2023

We correct this for Authorize calls here:

err = correctCancelError(err)

This was not done for Prepare. I'll fix this so it returns a proper context.Cancelled

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
s4 Internal bugs (e.g. test flakes), extreme edge cases, and bug risks
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants