[Bug][Github] GraphQL API requests will eventually fail forever collecting large repositories data

[ClaudioMascaro]

Search before asking

• I had searched in the issues and found no similar issues.

What happened

We are facing trouble trying to collect data from a few very large repositories. This one in question has 57,425 workflow runs, with some of them having about 175 job runs. Eventually the stage fails retrying graphql api requests until token expires, without any success:

What do you expect to happen

This is a key project for our company, and there are other projects with the same problem. We are expecting to delivery metrics for our teams. we are using API_TIMEOUT: "120s" and API_RETRY: "20", but it doesn't seem that will resolve the problem increasing more.

How to reproduce

Adding a project for a large repository and collecting data. We run 2 pipelines at once, but when running this pipeline without concurrency, it will fails even earlier.

Anything else

No response

Version

v0.21.0-rc1

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct

[dosubot]

Hello, @ClaudioMascaro! I'm here to help you with any bugs, questions, or contributions. Let's work together to tackle this issue.

To address the issue of GraphQL API requests failing for large repositories with many workflow and job runs, despite setting API_TIMEOUT to "120s" and API_RETRY to "20", you can try the following approaches:

1. Increase the InputStep Value: The InputStep parameter in the InitGraphQLCollector function controls the number of items processed in each batch. Increasing this value can help reduce the number of API calls by processing more items per request.

2. Optimize the BuildQuery Function: Ensure that the BuildQuery function is efficiently constructing the GraphQL queries to minimize the payload size and complexity.

3. Adjust the PAGE_SIZE: The PAGE_SIZE constant in the CollectRuns function controls the number of entries per page. Although the API accepts a maximum of 100 entries per page, sometimes the response body is too large, leading to request failures. Reducing the PAGE_SIZE can help mitigate this issue.

Here is a relevant code snippet with the InputStep value increased and PAGE_SIZE adjusted:

const PAGE_SIZE = 30 // Adjusted to handle large response bodies

err = apiCollector.InitGraphQLCollector(helper.GraphqlCollectorArgs{
    Input:         iterator,
    InputStep:     50, // Increased from 20 to 50
    GraphqlClient: data.GraphqlClient,
    BuildQuery: func(reqData *helper.GraphqlRequestData) (interface{}, map[string]interface{}, error) {
        query := &GraphqlQueryCheckRunWrapper{}
        if reqData == nil {
            return query, map[string]interface{}{}, nil
        }
        workflowRuns := reqData.Input.([]interface{})
        checkSuiteIds := []map[string]interface{}{}
        for _, iWorkflowRuns := range workflowRuns {
            workflowRun := iWorkflowRuns.(*SimpleWorkflowRun)
            checkSuiteIds = append(checkSuiteIds, map[string]interface{}{
                `id`: graphql.ID(workflowRun.CheckSuiteNodeID),
            })
        }
        variables := map[string]interface{}{
            "node": checkSuiteIds,
        }
        return query, variables, nil
    },
    ResponseParser: func(queryWrapper any) (messages []json.RawMessage, err errors.Error) {
        query := queryWrapper.(*GraphqlQueryCheckRunWrapper)
        for _, node := range query.Node {
            for _, checkRun := range node.CheckSuite.CheckRuns.Nodes {
                updatedAt := checkRun.StartedAt
                if checkRun.CompletedAt != nil {
                    updatedAt = checkRun.CompletedAt
                }
                if apiCollector.GetSince() != nil && !apiCollector.GetSince().Before(*updatedAt) {
                    return messages, helper.ErrFinishCollect
                }
                messages = append(messages, errors.Must1(json.Marshal(node)))
            }
        }
        return
    },
    IgnoreQueryErrors: true,
})
if err != nil {
    return err
}

return collector.Execute()

By increasing the InputStep value and adjusting the PAGE_SIZE, you can reduce the number of API calls and potentially avoid hitting rate limits or timeouts ^[1][2].

To continue talking to Dosu, mention @dosu.

[klesh]

V0.21 is not supported anymore.
I recommend you try the latest version of v1.0.1 beta since it fixes some Github bugs and has some improvements that might help your situation.

[BhoopalanI]

I faced a similar issue in the latest version v1.0.1@e061ef2. I've also raised it in slack on Thursday and awaiting a response. My issue is that the pipeline shows data collected successfully. However, not all Github data is collected. I'm testing it with PRs. I tested trying to pull entire PR data using the query in the db: 
select
*
from
pull_requests

This is supposed to show the entire PR data. However, the data is collected only until March of 2024. I'm missing close to 400 PRs which were created before March of 2024. 

Below is part of the log of the pipeline: 
time="2024-10-03 09:00:37" level=info msg=" [pipeline service] [pipeline #1] [task #2] executing subtask Collect Pull Requests" time="2024-10-03 09:00:37" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] start graphql collection" time="2024-10-03 09:00:38" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 1(not exactly)" time="2024-10-03 09:00:41" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 5(not exactly)" time="2024-10-03 09:00:45" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 9(not exactly)" time="2024-10-03 09:00:48" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 12(not exactly)" time="2024-10-03 09:00:51" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 15(not exactly)" time="2024-10-03 09:00:54" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 18(not exactly)" time="2024-10-03 09:00:58" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 21(not exactly)" time="2024-10-03 09:01:01" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 24(not exactly)" time="2024-10-03 09:01:04" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 27(not exactly)" time="2024-10-03 09:01:08" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 30(not exactly)" time="2024-10-03 09:01:11" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 33(not exactly)" time="2024-10-03 09:01:14" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 36(not exactly)" time="2024-10-03 09:01:18" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 40(not exactly)" time="2024-10-03 09:01:21" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 43(not exactly)" time="2024-10-03 09:01:26" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 46(not exactly)" time="2024-10-03 09:01:29" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 50(not exactly)" time="2024-10-03 09:01:32" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 53(not exactly)" time="2024-10-03 09:01:36" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 56(not exactly)" time="2024-10-03 09:01:39" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 59(not exactly)" time="2024-10-03 09:01:43" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 63(not exactly)" time="2024-10-03 09:01:46" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 66(not exactly)" time="2024-10-03 09:01:49" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 69(not exactly)" time="2024-10-03 09:01:52" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 72(not exactly)" time="2024-10-03 09:01:56" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 76(not exactly)" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] collector finish by parser" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] finished records: 79(not exactly)" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] ended api collection without error" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] start graphql collection" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Collect Pull Requests] ended api collection without error" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] subtask Collect Pull Requests finished in 82507 ms" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] finished step: 5 / 36" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] executing subtask Extract Pull Requests" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Extract Pull Requests] get data from _raw_github_graphql_prs where params={\"ConnectionId\":1,\"Name\":\"<org>/<repo>\"} and got 779" time="2024-10-03 09:01:59" level=info msg=" [pipeline service] [pipeline #1] [task #2] [Extract Pull Requests] finished records: 1(not exactly)" time="2024-10-03 09:02:00" level=info msg=" [pipeline service] [pipeline #1] [task #2] subtask Extract Pull Requests finished in 810 ms"

[klesh]

@BhoopalanI I think it worked fine, the collector would stop when pipelines are out of date range specified in the Project's Sync Policy.

[ClaudioMascaro]

@klesh We just upgraded devlake to latest version and still didn't work.

After finishing a Extract Workflow Runs with a large volume of data, the Collect Job Runs task retries until failure right after it starts, probably caused by a wrong graphql query, just like the screenshot I sent before.

Here is a new screenshot from the new version:

[ClaudioMascaro]

@abeizn

[ClaudioMascaro]

I've drafted a PR with an implementation that might be the solution for this case: #8233