Skip to content
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

argus.client.base.ArgusClientError: 'API Error encountered using endpoint on submit_results #492

Closed
juliayakovlev opened this issue Oct 27, 2024 · 13 comments · May be fixed by #535
Closed

argus.client.base.ArgusClientError: 'API Error encountered using endpoint on submit_results #492

juliayakovlev opened this issue Oct 27, 2024 · 13 comments · May be fixed by #535
Assignees
@k0machi

Comments

@juliayakovlev
Copy link

juliayakovlev commented Oct 27, 2024 •
edited
Loading

scylla-enterprise-perf-regression-predefined-throughput-steps-vnodes test runs 3 load stages.

write and read stages are passed:

read
write

But mixed stage failed with :

10:08:27  2024-10-27 08:06:16.817: (TestFrameworkEvent Severity.ERROR) period_type=one-time event_id=e8de7474-09f3-4770-bbb4-2b78159ce95b, source=PerformanceRegressionPredefinedStepsTest.test_mixed_gradual_increase_load (performance_regression_gradual_grow_throughput.PerformanceRegressionPredefinedStepsTest)() message=Traceback (most recent call last):
10:08:27  File "/home/ubuntu/scylla-cluster-tests/performance_regression_gradual_grow_throughput.py", line 72, in test_mixed_gradual_increase_load
10:08:27  self._base_test_workflow(workload=workload,
10:08:27  File "/home/ubuntu/scylla-cluster-tests/performance_regression_gradual_grow_throughput.py", line 127, in _base_test_workflow
10:08:27  self.run_gradual_increase_load(workload=workload,
10:08:27  File "/home/ubuntu/scylla-cluster-tests/performance_regression_gradual_grow_throughput.py", line 209, in run_gradual_increase_load
10:08:27  results = run_step(stress_cmds=workload.cs_cmd_tmpl, current_throttle=current_throttle,
10:08:27  File "/home/ubuntu/scylla-cluster-tests/sdcm/utils/decorators.py", line 272, in wrapped
10:08:27  send_result_to_argus(
10:08:27  File "/home/ubuntu/scylla-cluster-tests/sdcm/argus_results.py", line 165, in send_result_to_argus
10:08:27  argus_client.submit_results(result_table)
10:08:27  File "/usr/local/lib/python3.10/site-packages/argus/client/base.py", line 224, in submit_results
10:08:27  self.check_response(response)
10:08:27  File "/usr/local/lib/python3.10/site-packages/argus/client/base.py", line 68, in check_response
10:08:27  raise ArgusClientError(
10:08:27  argus.client.base.ArgusClientError: ('API Error encountered using endpoint: POST /api/v1/client/testrun/scylla-cluster-tests/7cb52991-e1ae-4e3e-8351-856c6b216b82/submit_results', '7cb52991-e1ae-4e3e-8351-856c6b216b82')

https://jenkins.scylladb.com/job/scylla-enterprise/job/perf-regression/job/scylla-enterprise-perf-regression-predefined-throughput-steps-vnodes/20/
@soyacz
Copy link
Collaborator

soyacz commented Oct 28, 2024

problem is that due some reason this run was not created in Argus at all:

< t:2024-10-27 04:14:54,161 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:14:54,729 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'Created', 'status': 'ok'}

I don't know yet the root cause.

@k0machi
Copy link
Collaborator

k0machi commented Nov 4, 2024

problem is that due some reason this run was not created in Argus at all:

< t:2024-10-27 04:14:54,161 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:14:54,729 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'Created', 'status': 'ok'}

I don't know yet the root cause.

This could mean that test failed creation on a separate stage, but then got re-created by the sct itself, hence the "run not found" exception. Next response indicates that it got created, but something maybe dropped it later. Maybe id re-use or a consistency issue. Need to check all stages that interacted with argus

@k0machi
Copy link
Collaborator

k0machi commented Nov 4, 2024

problem is that due some reason this run was not created in Argus at all:

< t:2024-10-27 04:14:54,161 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:14:54,729 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'Created', 'status': 'ok'}

I don't know yet the root cause.

This could mean that test failed creation on a separate stage, but then got re-created by the sct itself, hence the "run not found" exception. Next response indicates that it got created, but something maybe dropped it later. Maybe id re-use or a consistency issue. Need to check all stages that interacted with argus

It could also mean that another test (read/write) did this, but mixed didn't.

@fruch
Copy link
Contributor

fruch commented Nov 11, 2024

@k0machi what's up with this one ?

seems like we don't have "Create Argus Test Run" in the pefRegressionParallelPipeline.groovy

regardless we don't expect creation to fail, and we need to be able to lookup the logs for this failure, to understand it (on argus end)

@k0machi
Copy link
Collaborator

k0machi commented Nov 18, 2024

@k0machi what's up with this one ?

seems like we don't have "Create Argus Test Run" in the pefRegressionParallelPipeline.groovy

regardless we don't expect creation to fail, and we need to be able to lookup the logs for this failure, to understand it (on argus end)

Without the explicit stage the run is created inside "Run SCT Stages" stage, specifically during ClusterTester init, so the cause for failure should be visible in the logs for that particular SCT run.

@k0machi k0machi added the bug Something isn't working label Nov 18, 2024
@k0machi
Copy link
Collaborator

k0machi commented Nov 20, 2024

Looking into this, I see a weird issue:

So here's the write test, initializing succesfuly:

< t:2024-10-27 04:13:51,469 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '70fa1e8d-a52e-41ec-aeb0-9da8ef711ec6'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:13:52,035 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'Created', 'status': 'ok'}
< t:2024-10-27 04:13:52,387 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'updated', 'status': 'ok'}
< t:2024-10-27 04:13:52,743 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'added', 'status': 'ok'}

And here's the mixed test's argus.log:

< t:2024-10-27 04:14:54,161 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:14:54,729 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': 'Created', 'status': 'ok'}
< t:2024-10-27 04:14:55,080 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:14:55,430 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': [], 'exception': 'DoesNotExist'}, 'status': 'error'}
< t:2024-10-27 04:14:55,431 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:15:18,778 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': ['Run not found', '7cb52991-e1ae-4e3e-8351-856c6b216b82'], 'exception': 'SCTServiceException'}, 'status': 'error'}
< t:2024-10-27 04:15:25,812 f:base.py         l:65   c:argus.client.base    p:DEBUG > API Response: {'response': {'arguments': [], 'exception': 'DoesNotExist'}, 'status': 'error'}

So this is weird - API responded that it had succesfully saved the run, yet it does not exist for subsequent calls. Manually querying the run doesn't help - it indeed doesn't exist:
Image

I suspect something happened with scylla at that moment - unfortunately the logs for this are not available anymore (and I suspect the application logs won't show much, since the API did respond with success - which means something happened on scylla's end).

@fruch
Copy link
Contributor

fruch commented Nov 20, 2024

That is very disturbing.

Did you check on each node separately?

It's not the first time we run into such cases, last time it was during upgrade of Scylla or node replacement

What more information we can log to help figure out the next time

(We should collect logs, as soon as issues are reported, or archive logs periodically to s3 to something like that)

@k0machi
Copy link
Collaborator

k0machi commented Nov 20, 2024

That is very disturbing.

Did you check on each node separately?

It's not the first time we run into such cases, last time it was during upgrade of Scylla or node replacement

What more information we can log to help figure out the next time

(We should collect logs, as soon as issues are reported, or archive logs periodically to s3 to something like that)

I haven't checked individual nodes yet, I'll do that. We should collect logs periodically, maybe have a github action that would do a snapshot of last N hours of production each time an issue is reported?

@soyacz
Copy link
Collaborator

soyacz commented Nov 25, 2024

I suspect MV scylla issue - see both id and test_id are indexed columns - so when MV fails to update (which is not ensured by cql insert/update request) we may hit issue with insert being correct and querying for it not. @k0machi can you confirm this ID exists without using indexed column in query?

@k0machi
Copy link
Collaborator

k0machi commented Nov 25, 2024

I suspect MV scylla issue - see both id and test_id are indexed columns - so when MV fails to update (which is not ensured by cql insert/update request) we may hit issue with insert being correct and querying for it not. @k0machi can you confirm this ID exists without using indexed column in query?

No, the id doesn't exist at all - only two runs that have #20 as their build number exist for this one:
Image

@fruch
Copy link
Contributor

fruch commented Dec 2, 2024

@k0machi

what next ? what can we do to capture more data when it's gonna happen again ?

@fruch fruch removed the bug Something isn't working label Dec 2, 2024
@k0machi
Copy link
Collaborator

k0machi commented Dec 2, 2024

@k0machi

what next ? what can we do to capture more data when it's gonna happen again ?

I will add context dump to the exceptions happening in the submit requests (or we could just dump them wholly on every error to improve readability - session data, request body, etc.

k0machi added a commit to k0machi/argus that referenced this issue Dec 9, 2024
@k0machi
improvement(error_handlers): Add context dump to the exceptions
5420ca2 
This commit adds additional information and trace ids to the exception
that occur inside the API calls, allowing to collect more information
about the error, including the request data.

Fixes scylladb#492
@k0machi k0machi mentioned this issue Dec 9, 2024
Open
k0machi added a commit to k0machi/argus that referenced this issue Dec 9, 2024
@k0machi
improvement(error_handlers): Add context dump to the exceptions
8cde76e 
This commit adds additional information and trace ids to the exception
that occur inside the API calls, allowing to collect more information
about the error, including the request data.

Fixes scylladb#492
@fruch
Copy link
Contributor

fruch commented Dec 9, 2024

We can't identify the root cause, adding new logging for identify those

@fruch fruch closed this as completed Dec 9, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@k0machi k0machi

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

improvement(error_handlers): Add context dump to the exceptions k0machi/argus
4 participants
@fruch @k0machi @soyacz @juliayakovlev