Setting default wait_time to 1 minute #2074

bachsh · 2022-06-19T21:57:22Z

While debugging my code against gitlab.com (SaaS, not self-hosted) I realized that the SDK bombards the API with the same request.
I found out that for some reason, headers such as Retry-After are missing from the response so only the default wait_time is taken into account. This means that the SDK basically doesn't wait at all.

Since for Gitlab.com most rate limits are calculated per 1 minute, I think it's better to set the default timeout to that value in case rate limit headers are missing.

For Gitlab.com most rate limits are calculated per 1 minute. Better to set the default timeout to that value

bachsh · 2022-06-19T21:59:17Z

In addition to that change, I think it makes sense to log (in DEBUG level) that a rate limit 429 has occurred, but IDK how the maintainers would like to add logging here, if at all. If anyone agrees with me on this I'd love to have guidance on how to add this logging.

codecov-commenter · 2022-06-19T23:57:14Z

Codecov Report

Merging #2074 (d637206) into main (ca98d88) will not change coverage.
The diff coverage is 100.00%.

@@           Coverage Diff           @@
##             main    #2074   +/-   ##
=======================================
  Coverage   94.64%   94.64%           
=======================================
  Files          78       78           
  Lines        5003     5003           
=======================================
  Hits         4735     4735           
  Misses        268      268

Flag	Coverage Δ
cli_func_v4	`82.45% <0.00%> (ø)`
py_func_v4	`81.03% <100.00%> (ø)`
unit	`85.60% <100.00%> (ø)`

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
gitlab/client.py	`98.67% <100.00%> (ø)`

nejch · 2022-06-20T07:51:07Z

Hi @bachsh thanks for looking into this! We've already had some discussion on how gitlab.com behaves - see #1889.

I'm not sure we can merge your change as is, this happens in a while loop and would make some of the other code dead, and it's quite aggressive with the wait. I'd have a few questions first:

is there a specific endpoint are you seeing this with?
could you paste some code and logs with enable_debug() (and tokens redacted) to Default value for max_retries is too short to "clear" all rate limit windows #1889 so we can take a look at the headers that are present?

If GitLab.com no longer returns any rate-limit headers I think we should take this discussion upstream as well - clients should have some reasonable idea of how to retry these limits instead of us figuring out arbitrary waits, IMO. Or worst case scenario we should have these defaults only if the url matches gitlab.com, if we really have no other option.

bachsh · 2022-06-20T08:16:25Z

hey @nejch, thanks for looking at my PR. I guess I should've looked at open issues before opening it :)

To your questions:

I ran into the rate limit on the /users/:id: endpoint.
Yes, attached to the end of this message. I first ran a short loop to make sure I've reached the rate limit, and then ran my code that fetched the data that I need. I've set max_retries=1 which is why you will see only 1 retry instead of the default 10.

And yes it seems that these headers no longer exist for gitlab-com; the reporter of #1889 mentioned that as well. It is possible that Cloudflare is not passing these headers along.

2022-06-20T11:14:03+0300 [DEBUG] urllib3.connectionpool - Starting new HTTPS connection (1): gitlab.com:443
send: b'GET /api/v4/groups?per_page=100&min_access_level=40 HTTP/1.1\r\nHost: gitlab.com\r\nUser-Agent: python-gitlab/3.5.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\nPRIVATE-TOKEN: ***\r\nContent-type: application/json\r\n\r\n'
reply: 'HTTP/1.1 200 OK\r\n'
header: Date: Mon, 20 Jun 2022 08:14:04 GMT
header: Content-Type: application/json
header: Transfer-Encoding: chunked
header: Connection: keep-alive
header: Cache-Control: max-age=0, private, must-revalidate
header: Etag: W/"c5ab47387a7f6b720554bb2425b3b2fe"
header: Link: <https://gitlab.com/api/v4/groups?min_access_level=40&order_by=name&owned=false&page=1&per_page=100&sort=asc&statistics=false&with_custom_attributes=false>; rel="first", <https://gitlab.com/api/v4/groups?min_access_level=40&order_by=name&owned=false&page=1&per_page=100&sort=asc&statistics=false&with_custom_attributes=false>; rel="last"
header: Vary: Origin
header: X-Content-Type-Options: nosniff
header: X-Frame-Options: SAMEORIGIN
header: X-Next-Page: 
header: X-Page: 1
header: X-Per-Page: 100
header: X-Prev-Page: 
header: X-Request-Id: 01G602T2JSZ1GM92BS4FV1QQX8
header: X-Runtime: 0.202389
header: X-Total: 20
header: X-Total-Pages: 1
header: Strict-Transport-Security: max-age=31536000
header: Referrer-Policy: strict-origin-when-cross-origin
header: GitLab-LB: fe-13-lb-gprd
header: GitLab-SV: api-gke-us-east1-c
header: CF-Cache-Status: DYNAMIC
header: Expect-CT: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
header: Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v3?s=Kax%2F2w4Ke3oK4eC%2BxRSkST%2B%2BlgKoD6aicEEb%2FtyX1TuxPR08UuWw0NwK%2BoWAVRnw9SKyUwFX%2BN9Q1PPn6AGTs%2Bbo4rqhIKnSg15srLa3YteFCMD264OgEhlRJq%2BXOicr8l2G6klgO%2BE%3D"}],"group":"cf-nel","max_age":604800}
header: NEL: {"success_fraction":0.01,"report_to":"cf-nel","max_age":604800}
header: Server: cloudflare
header: CF-RAY: 71e30c7c6f697d9e-TLV
header: Content-Encoding: gzip
2022-06-20T11:14:04+0300 [DEBUG] urllib3.connectionpool - https://gitlab.com:443 "GET /api/v4/groups?per_page=100&min_access_level=40 HTTP/1.1" 200 None
send: b'GET /api/v4/groups/16076036/members?per_page=100&min_access_level=40 HTTP/1.1\r\nHost: gitlab.com\r\nUser-Agent: python-gitlab/3.5.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\nPRIVATE-TOKEN: ***\r\nContent-type: application/json\r\n\r\n'
reply: 'HTTP/1.1 200 OK\r\n'
header: Date: Mon, 20 Jun 2022 08:14:05 GMT
header: Content-Type: application/json
header: Transfer-Encoding: chunked
header: Connection: keep-alive
header: Cache-Control: max-age=0, private, must-revalidate
header: Etag: W/"c3cd59286c4e3c98c5bd093619940c0c"
header: Link: <https://gitlab.com/api/v4/groups/16076036/members?id=16076036&min_access_level=40&page=1&per_page=100>; rel="first", <https://gitlab.com/api/v4/groups/16076036/members?id=16076036&min_access_level=40&page=1&per_page=100>; rel="last"
header: Vary: Origin
header: X-Content-Type-Options: nosniff
header: X-Frame-Options: SAMEORIGIN
header: X-Next-Page: 
header: X-Page: 1
header: X-Per-Page: 100
header: X-Prev-Page: 
header: X-Request-Id: 01G602T309ZWENB37JYNER4GH7
header: X-Runtime: 0.129332
header: X-Total: 12
header: X-Total-Pages: 1
header: Strict-Transport-Security: max-age=31536000
header: Referrer-Policy: strict-origin-when-cross-origin
header: GitLab-LB: fe-14-lb-gprd
header: GitLab-SV: api-gke-us-east1-d
header: CF-Cache-Status: DYNAMIC
header: Expect-CT: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
header: Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v3?s=tXC%2F%2FLFtAda5ObhwRZUsRARnvdhywJpEFy%2Fm5gVyAMe86Uo1U9bLadeX%2FIq0iwF3AvOVKuJ2L%2BXWpBWL6gLgiTPKMgGlBQ7ysk6lNkN8WQ92XGDQOUmzzmBByB5WOWhjwHEMpO%2FAXKY%3D"}],"group":"cf-nel","max_age":604800}
header: NEL: {"success_fraction":0.01,"report_to":"cf-nel","max_age":604800}
header: Server: cloudflare
header: CF-RAY: 71e30c7f4c297d9e-TLV
header: Content-Encoding: gzip
2022-06-20T11:14:04+0300 [DEBUG] urllib3.connectionpool - https://gitlab.com:443 "GET /api/v4/groups/16076036/members?per_page=100&min_access_level=40 HTTP/1.1" 200 None
send: b'GET /api/v4/users/10821733/ HTTP/1.1\r\nHost: gitlab.com\r\nUser-Agent: python-gitlab/3.5.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\nPRIVATE-TOKEN: ***\r\nContent-type: application/json\r\n\r\n'
reply: 'HTTP/1.1 429 Too Many Requests\r\n'
header: Date: Mon, 20 Jun 2022 08:14:05 GMT
header: Content-Type: application/json
header: Content-Length: 89
header: Connection: keep-alive
header: Cache-Control: no-cache
header: Vary: Origin
header: X-Content-Type-Options: nosniff
header: X-Frame-Options: SAMEORIGIN
header: X-Request-Id: 01G602T3CRRZ0AYAQA74CK41VH
header: X-Runtime: 0.044223
header: Strict-Transport-Security: max-age=31536000
header: Referrer-Policy: strict-origin-when-cross-origin
header: GitLab-LB: fe-25-lb-gprd
header: GitLab-SV: api-gke-us-east1-c
header: CF-Cache-Status: DYNAMIC
header: Expect-CT: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
header: Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v3?s=SCMaLNWcLLooykPtjJMaWYXilZsmlyr9FWguBvRtg5%2FQqF8h3Z9hfCO7ecFxErFy8M2UOG6wjEFso1zbpLR6ztI334%2FZTaDiHOZmPGczQbovD0dhCiQ0Q4rqFr0ApOLLML2rO83sanA%3D"}],"group":"cf-nel","max_age":604800}
header: NEL: {"success_fraction":0.01,"report_to":"cf-nel","max_age":604800}
header: Server: cloudflare
header: CF-RAY: 71e30c8188497d9e-TLV
2022-06-20T11:14:05+0300 [DEBUG] urllib3.connectionpool - https://gitlab.com:443 "GET /api/v4/users/10821733/ HTTP/1.1" 429 89
send: b'GET /api/v4/users/10821733/ HTTP/1.1\r\nHost: gitlab.com\r\nUser-Agent: python-gitlab/3.5.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\nPRIVATE-TOKEN: ***\r\nContent-type: application/json\r\n\r\n'
reply: 'HTTP/1.1 429 Too Many Requests\r\n'
header: Date: Mon, 20 Jun 2022 08:14:05 GMT
header: Content-Type: application/json
header: Content-Length: 89
header: Connection: keep-alive
header: Cache-Control: no-cache
header: Vary: Origin
header: X-Content-Type-Options: nosniff
header: X-Frame-Options: SAMEORIGIN
header: X-Request-Id: 01G602T3RSA1HGKBB4NW2GD366
header: X-Runtime: 0.027737
header: Strict-Transport-Security: max-age=31536000
header: Referrer-Policy: strict-origin-when-cross-origin
header: GitLab-LB: fe-22-lb-gprd
header: GitLab-SV: api-gke-us-east1-c
header: CF-Cache-Status: DYNAMIC
header: Expect-CT: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
header: Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v3?s=jfa01qENyS5pkJ6u2UEIEYxEbSPMDM74JeI1wKLru9GbKCdcUe8iToj6SAIu4MO3V4KCe1L7Bgt4FcNdEAKQtK5KLZzg2srWszdc3aR1eB1nDBZd7zc4C2aF21d4h6hMAlD0MtJDGCo%3D"}],"group":"cf-nel","max_age":604800}
header: NEL: {"success_fraction":0.01,"report_to":"cf-nel","max_age":604800}
header: Server: cloudflare
header: CF-RAY: 71e30c843d047d9e-TLV
2022-06-20T11:14:05+0300 [DEBUG] urllib3.connectionpool - https://gitlab.com:443 "GET /api/v4/users/10821733/ HTTP/1.1" 429 89
2022-06-20T11:14:05+0300 [WARNING] authomize.gitlab.client.gitlab_client - Hit rate limit not covered by SDK. Waiting 1 minute(s).

bachsh · 2022-07-03T07:56:57Z

@nejch I think it's going to take some time for gitlab.com to fix the issue.
In the meantime I've been thinking and the exponential backoff will result in wait time of 51.2 seconds in the end by default (since the default is 10 retries, and 2^9*0.1=51.2). So actually it's kinda hard for me to understand why the code fails after all these retries. If it bothers you to change the default time to 60 seconds, would it be ok to make the base wait_time configurable (currently 0.1 secs)?

bachsh · 2022-07-03T07:59:23Z

(also, CI is failing because of the format of the commit message and IDK how to fix this besides submitting a new one)

nejch · 2022-07-03T19:57:41Z

@nejch I think it's going to take some time for gitlab.com to fix the issue. In the meantime I've been thinking and the exponential backoff will result in wait time of 51.2 seconds in the end by default (since the default is 10 retries, and 2^9*0.1=51.2). So actually it's kinda hard for me to understand why the code fails after all these retries. If it bothers you to change the default time to 60 seconds, would it be ok to make the base wait_time configurable (currently 0.1 secs)?

@bachsh I agree, and I think the issue might never go away as it seems to be there because of user enumeration attacks.

Hmm I'm not sure why this happens, maybe each subsequent request further increases the backoff requirements without providing feedback.

Yes, a configurable wait_time would be the first step and would also open things up to solve a few more issues. Would you be willing to work on that as well? See also #1890. I think we'd be fine also increasing the default step a bit, just going with 60s wait from the start might be a bit harsh for instances/endpoints where you can handle more granular rate-limits.

Regarding the commit message, git commit --amend lets you amend your last commit, and git rebase -i HEAD~n where n is the number of commits going back allows you to edit a longer history of commits :)

nejch · 2022-08-01T15:01:26Z

@bachsh let us know if you need any help here.

https://docs.github.com/en/pull-requests/committing-changes-to-your-project/creating-and-editing-commits/changing-a-commit-message explains how to commit amend commit message, and
feat: allow global retry_transient_errors #1565 is an example of a PR that adds config to global instance options (that goes a bit further and adds to the config file options, which is a bonus).

github-actions · 2022-10-31T03:26:42Z

This Pull Request (PR) was marked stale because it has been open 90 days with no activity. Please remove the stale label or comment on this PR. Otherwise, it will be closed in 15 days.

github-actions · 2022-11-16T03:02:44Z

This PR was closed because it has been marked stale for 15 days with no activity. If this PR is still valid, please re-open.

setting default wait_time to 1 minute

d637206

For Gitlab.com most rate limits are calculated per 1 minute. Better to set the default timeout to that value

nejch assigned bachsh Jun 20, 2022

nejch added the need info label Jun 20, 2022

nejch mentioned this pull request Jun 20, 2022

Formalize logging #2080

Open

github-actions bot added the stale label Oct 31, 2022

github-actions bot closed this Nov 16, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Setting default wait_time to 1 minute #2074

Setting default wait_time to 1 minute #2074

bachsh commented Jun 19, 2022

bachsh commented Jun 19, 2022

codecov-commenter commented Jun 19, 2022

nejch commented Jun 20, 2022

bachsh commented Jun 20, 2022 •

edited

Loading

bachsh commented Jul 3, 2022

bachsh commented Jul 3, 2022

nejch commented Jul 3, 2022 •

edited

Loading

nejch commented Aug 1, 2022

github-actions bot commented Oct 31, 2022

github-actions bot commented Nov 16, 2022

Setting default wait_time to 1 minute #2074

Setting default wait_time to 1 minute #2074

Conversation

bachsh commented Jun 19, 2022

bachsh commented Jun 19, 2022

codecov-commenter commented Jun 19, 2022

Codecov Report

nejch commented Jun 20, 2022

bachsh commented Jun 20, 2022 • edited Loading

bachsh commented Jul 3, 2022

bachsh commented Jul 3, 2022

nejch commented Jul 3, 2022 • edited Loading

nejch commented Aug 1, 2022

github-actions bot commented Oct 31, 2022

github-actions bot commented Nov 16, 2022

bachsh commented Jun 20, 2022 •

edited

Loading

nejch commented Jul 3, 2022 •

edited

Loading