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

bug(curation api): 504 returned from GET collection and datasets #7190

Open
Bento007 opened this issue Jun 13, 2024 · 4 comments
Open

bug(curation api): 504 returned from GET collection and datasets #7190

Bento007 opened this issue Jun 13, 2024 · 4 comments
Assignees
@Bento007
Labels
bug Someone made a missteak... discover api Work related to the Discover API product dp Data Platform workstream

Comments

@Bento007
Copy link
Contributor

Bento007 commented Jun 13, 2024 •
edited
Loading

Describe the bug

When making requests to GET /v1/collection with and without an API Key, a 504 is returned about 50% of the time.

Error


Gateway Time-out

<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN" "http://www.w3.org/TR/html4/loose.dtd">
<HTML><HEAD><META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=iso-8859-1">
<TITLE>ERROR: The request could not be satisfied</TITLE>
</HEAD><BODY>
<H1>504 ERROR</H1>
<H2>The request could not be satisfied.</H2>
<HR noshade size="1px">
CloudFront attempted to establish a connection with the origin, but either the attempt failed or the origin closed the connection.
We can't connect to the server for this app or website at this time. There might be too much traffic or a configuration error. Try again later, or contact the app or website owner.
<BR clear="all">
If you provide content to customers through CloudFront, you can find steps to troubleshoot and help prevent this error by reviewing the CloudFront documentation.
<BR clear="all">
<HR noshade size="1px">
<PRE>
Generated by cloudfront (CloudFront)
Request ID: 2yXpvcNQKTOWmetxS34Ul-Vj8QK1J6TvOSvaVOx3THJOvMP2Y9ovzw==
</PRE>
<ADDRESS>
</ADDRESS>
</BODY></HTML>

x-request-id: None

To Reproduce

curl https://api.cellxgene.cziscience.com/curation/v1/collections

or
curl https://api.cellxgene.cziscience.com/curation/v1/datasets

Expected behavior

the endpoints should never return a 504 under proper working conditions.

Environment

Curation API prod

Additional context

  • the cloudwatch request timeout is set to 60s
  • Looking at the logs in cloud watch, request to GET collection are taking up 78 second which is greater than the cloud watch timeout.
  • There is a keep-alive configuration in for the server set for 61 second which could be related
  • There were recent changes to the server configuration. Less CPU and memory. However looking at the CPU and memory activity there are no sign of running out of resources.
  • There was also a recent schema migration which would have added a lot more collections to our database.
  • in cloudwatch this filter was used to find slow endpoint {$.details.response_time > 60} and {$.request_id = "4c28ce0f-7ef5-402f-982a-b51c243b8aba"}. Here is one of the logs:
{
    "levelname": "INFO",
    "asctime": "2024-06-13T15:18:13.013Z",
    "name": "corpora-api-prod",
    "message": "",
    "lineno": 76,
    "pathname": "/single-cell-data-portal/backend/common/server/config.py",
    "request_id": "4c28ce0f-7ef5-402f-982a-b51c243b8aba",
    "type": "REQUEST",
    "details": {
        "url": "/curation/v1/collections",
        "method": "GET",
        "content_length": null
    }
}
{
    "levelname": "INFO",
    "asctime": "2024-06-13T15:19:20.013Z",
    "name": "corpora-api-prod",
    "message": "",
    "lineno": 88,
    "pathname": "/single-cell-data-portal/backend/common/server/config.py",
    "request_id": "4c28ce0f-7ef5-402f-982a-b51c243b8aba",
    "type": "RESPONSE",
    "details": {
        "status_code": 200,
        "content_length": 1617300,
        "response_time": 66.78523659706116
    }
}
@Bento007 Bento007 added the bug Someone made a missteak... label Jun 13, 2024
This was referenced Jun 13, 2024
Merged
Merged
@Bento007
Copy link
Contributor Author

The problem is still happening after the fixes. The metrics show that it's not the queries that are taking the longest. We should look closer at cloudfront to see if there is any caching we can do to improve the speed the same way we are doing it for the portal API.

@Bento007 Bento007 mentioned this issue Jun 20, 2024
Closed
@Bento007 Bento007 self-assigned this Jun 20, 2024
@Bento007
Copy link
Contributor Author

After adding additional instrumentation to an rdev, the GET curation/v1/collections from the backend server returns in less than 10 seconds. This was after mirroring prod database to the rdev environment. Still 504 are returned and responses can take over 60 seconds to complete. The load balancer metrics do show a 504 is returned in the logs which should be our next target to investigate.

@Bento007
Copy link
Contributor Author

Bento007 commented Jul 4, 2024

I've been using locust to test the system with this code. You'll need to grab the _oauth2_proxy token from the browser to run it if using an rdev.

from locust import HttpUser, task


class GetCollection(HttpUser):
    @task
    def hello_world(self):
        self.client.get(
            "/curation/v1/collections",
            cookies={"_oauth2_proxy": ""})

@Bento007
Copy link
Contributor Author

Bento007 commented Jul 4, 2024 •
edited
Loading

Here is an instance where is succeeded but still took upwards of 30 seconds from the browser.

    {
        "levelname": "INFO",
        "asctime": "2024-07-04T21:19:57.004Z",
        "name": "root",
        "message": "",
        "lineno": 89,
        "pathname": "/single-cell-data-portal/backend/common/utils/timer.py",
        "request_id": "5d37e959-f2e7-4416-be20-504f3663afed",
        "type": "METRIC",
        "details": {
            "group": "reshape_for_curation_api",
            "records": 223,
            "total_time": 5.167150974273682,
            "max_time": 0.42186570167541504,
            "min_time": 0.004987478256225586,
            "median_time": 0.012070894241333008,
            "_95th_percentile": 0.07090299129486065,
            "_99th_percentile": 0.18947099208831789,
            "unit": "seconds"
        }
    },
    {
        "levelname": "INFO",
        "asctime": "2024-07-04T21:19:58.004Z",
        "name": "corpora-api-rdev",
        "message": "",
        "lineno": 88,
        "pathname": "/single-cell-data-portal/backend/common/server/config.py",
        "request_id": "5d37e959-f2e7-4416-be20-504f3663afed",
        "type": "RESPONSE",
        "details": {
            "status_code": 200,
            "content_length": 2712878,
            "response_time": 6.117963790893555,
            "request": {
                "url": "/curation/v1/collections",
                "method": "GET"
            }
        }
    }

The logs show the backend server took 6 seconds to complete. This means that the load balancer is getting hung up on this response since rdev do not use cloudfront.

Request

GET https://pr-7217-backend.rdev.single-cell.czi.technology/curation/v1/collections?visibility=PUBLIC

Response Headers

Access-Control-Allow-Credentials: true
Access-Control-Allow-Origin: https://cellxgene.happy.dev.corpora.cziscience.com
Content-Length: 2712878
Content-Type: application/json
Date: Thu, 04 Jul 2024 21:25:04 GMT
Server: nginx/1.19.3
Vary: Origin
X-Request-Id: 4010cbfc-b112-4f5c-af8d-fd9c815ae65d

The response header shows that The returned payload was 2.7 MB and I don't think it is compressed.

@brianraymor brianraymor added dp Data Platform workstream discover api Work related to the Discover API product labels Jul 5, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Bento007 Bento007

Labels
bug Someone made a missteak... discover api Work related to the Discover API product dp Data Platform workstream
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Bento007 @brianraymor