Do not assume server time is in sync with local machine time on rate …

…limit path (#1972)

Co-authored-by: Liam Newman <[email protected]>

src/main/java/org/kohsuke/github/GitHubRateLimitHandler.java

@@ -5,6 +5,9 @@
 
 import java.io.IOException;
 import java.io.InterruptedIOException;
+import java.time.Duration;
+import java.time.ZonedDateTime;
+import java.time.format.DateTimeFormatter;
 
 import javax.annotation.Nonnull;
 
@@ -21,6 +24,11 @@
  */
 public abstract class GitHubRateLimitHandler extends GitHubConnectorResponseErrorHandler {
 
+    /**
+     * On a wait, even if the response suggests a very short wait, wait for a minimum duration.
+     */
+    private static final int MINIMUM_RATE_LIMIT_RETRY_MILLIS = 1000;
+
     /**
      * Create default GitHubRateLimitHandler instance
      */
@@ -71,15 +79,29 @@ public void onError(GitHubConnectorResponse connectorResponse) throws IOExceptio
                 throw (InterruptedIOException) new InterruptedIOException().initCause(ex);
             }
         }
+    };
 
-        private long parseWaitTime(GitHubConnectorResponse connectorResponse) {
-            String v = connectorResponse.header("X-RateLimit-Reset");
-            if (v == null)
-                return 60 * 1000; // can't tell, return 1 min
+    /*
+     * Exposed for testability. Given an http response, find the rate limit reset header field and parse it. If no
+     * header is found, wait for a reasonably amount of time.
+     */
+    long parseWaitTime(GitHubConnectorResponse connectorResponse) {
+        String v = connectorResponse.header("X-RateLimit-Reset");
+        if (v == null)
+            return Duration.ofMinutes(1).toMillis(); // can't tell, return 1 min
 
-            return Math.max(1000, Long.parseLong(v) * 1000 - System.currentTimeMillis());
+        // Don't use ZonedDateTime.now(), because the local and remote server times may not be in sync
+        // Instead, we can take advantage of the Date field in the response to see what time the remote server
+        // thinks it is
+        String dateField = connectorResponse.header("Date");
+        ZonedDateTime now;
+        if (dateField != null) {
+            now = ZonedDateTime.parse(dateField, DateTimeFormatter.RFC_1123_DATE_TIME);
+        } else {
+            now = ZonedDateTime.now();
         }
-    };
+        return Math.max(MINIMUM_RATE_LIMIT_RETRY_MILLIS, (Long.parseLong(v) - now.toInstant().getEpochSecond()) * 1000);
+    }
 
     /**
      * Fail immediately.

src/test/java/org/kohsuke/github/RateLimitHandlerTest.java

@@ -1,6 +1,7 @@
 package org.kohsuke.github;
 
 import com.github.tomakehurst.wiremock.core.WireMockConfiguration;
+import org.jetbrains.annotations.NotNull;
 import org.junit.Test;
 import org.kohsuke.github.connector.GitHubConnectorResponse;
 
@@ -117,16 +118,56 @@ public void testHandler_HttpStatus_Fail() throws Exception {
     /**
      * Test handler wait.
      *
-     * @throws Exception
+     * @throws IOException
      *             the exception
      */
     @Test
-    public void testHandler_Wait() throws Exception {
+    public void testHandler_Wait() throws IOException {
+        // Customized response that templates the date to keep things working
+        snapshotNotAllowed();
+
+        gitHub = getGitHubBuilder().withEndpoint(mockGitHub.apiServer().baseUrl())
+                .withRateLimitHandler(new GitHubRateLimitHandler() {
+
+                    @Override
+                    public void onError(@NotNull GitHubConnectorResponse connectorResponse) throws IOException {
+                        long waitTime = GitHubRateLimitHandler.WAIT.parseWaitTime(connectorResponse);
+                        assertThat(waitTime, equalTo(3 * 1000l));
+
+                        GitHubAbuseLimitHandler.WAIT.onError(connectorResponse);
+                    }
+                })
+                .build();
+
+        gitHub.getMyself();
+        assertThat(mockGitHub.getRequestCount(), equalTo(1));
+
+        getTempRepository();
+        assertThat(mockGitHub.getRequestCount(), equalTo(3));
+    }
+
+    /**
+     * Test the wait logic in the case where the "Date" header field is missing from the response.
+     *
+     * @throws IOException
+     *             if the code under test throws that exception
+     */
+    @Test
+    public void testHandler_Wait_Missing_Date_Header() throws IOException {
         // Customized response that templates the date to keep things working
         snapshotNotAllowed();
 
         gitHub = getGitHubBuilder().withEndpoint(mockGitHub.apiServer().baseUrl())
-                .withRateLimitHandler(GitHubRateLimitHandler.WAIT)
+                .withRateLimitHandler(new GitHubRateLimitHandler() {
+
+                    @Override
+                    public void onError(@NotNull GitHubConnectorResponse connectorResponse) throws IOException {
+                        long waitTime = GitHubRateLimitHandler.WAIT.parseWaitTime(connectorResponse);
+                        assertThat(waitTime, equalTo(3 * 1000l));
+
+                        GitHubAbuseLimitHandler.WAIT.onError(connectorResponse);
+                    }
+                })
                 .build();
 
         gitHub.getMyself();

src/test/resources/org/kohsuke/github/RateLimitHandlerTest/wiremock/testHandler_Wait/mappings/2-r_h_t_Wait.json

@@ -20,7 +20,7 @@
       "Status": "403 Forbidden",
       "X-RateLimit-Limit": "5000",
       "X-RateLimit-Remaining": "0",
-      "X-RateLimit-Reset": "{{testStartDate offset='3 seconds' format='unix'}}",
+      "X-RateLimit-Reset": "{{now offset='3 seconds' format='unix'}}",
       "Cache-Control": "private, max-age=60, s-maxage=60",
       "Vary": [
         "Accept, Authorization, Cookie, X-GitHub-OTP",

src/test/resources/org/kohsuke/github/RateLimitHandlerTest/wiremock/testHandler_Wait_Missing_Date_Header/__files/1-user.json

@@ -0,0 +1,45 @@
+{
+  "login": "bitwiseman",
+  "id": 1958953,
+  "node_id": "MDQ6VXNlcjE5NTg5NTM=",
+  "avatar_url": "https://avatars3.githubusercontent.com/u/1958953?v=4",
+  "gravatar_id": "",
+  "url": "https://api.github.com/users/bitwiseman",
+  "html_url": "https://github.com/bitwiseman",
+  "followers_url": "https://api.github.com/users/bitwiseman/followers",
+  "following_url": "https://api.github.com/users/bitwiseman/following{/other_user}",
+  "gists_url": "https://api.github.com/users/bitwiseman/gists{/gist_id}",
+  "starred_url": "https://api.github.com/users/bitwiseman/starred{/owner}{/repo}",
+  "subscriptions_url": "https://api.github.com/users/bitwiseman/subscriptions",
+  "organizations_url": "https://api.github.com/users/bitwiseman/orgs",
+  "repos_url": "https://api.github.com/users/bitwiseman/repos",
+  "events_url": "https://api.github.com/users/bitwiseman/events{/privacy}",
+  "received_events_url": "https://api.github.com/users/bitwiseman/received_events",
+  "type": "User",
+  "site_admin": false,
+  "name": "Liam Newman",
+  "company": "Cloudbees, Inc.",
+  "blog": "",
+  "location": "Seattle, WA, USA",
+  "email": "[email protected]",
+  "hireable": null,
+  "bio": "https://twitter.com/bitwiseman",
+  "public_repos": 181,
+  "public_gists": 7,
+  "followers": 146,
+  "following": 9,
+  "created_at": "2012-07-11T20:38:33Z",
+  "updated_at": "2020-02-06T17:29:39Z",
+  "private_gists": 8,
+  "total_private_repos": 10,
+  "owned_private_repos": 0,
+  "disk_usage": 33697,
+  "collaborators": 0,
+  "two_factor_authentication": true,
+  "plan": {
+    "name": "free",
+    "space": 976562499,
+    "collaborators": 0,
+    "private_repos": 10000
+  }
+}

src/test/resources/org/kohsuke/github/RateLimitHandlerTest/wiremock/testHandler_Wait_Missing_Date_Header/__files/3-r_h_t_Wait.json

@@ -0,0 +1,126 @@
+{
+  "id": 238757196,
+  "node_id": "MDEwOlJlcG9zaXRvcnkyMzg3NTcxOTY=",
+  "name": "temp-testHandler_Wait",
+  "full_name": "hub4j-test-org/temp-testHandler_Wait",
+  "private": false,
+  "owner": {
+    "login": "hub4j-test-org",
+    "id": 7544739,
+    "node_id": "MDEyOk9yZ2FuaXphdGlvbjc1NDQ3Mzk=",
+    "avatar_url": "https://avatars3.githubusercontent.com/u/7544739?v=4",
+    "gravatar_id": "",
+    "url": "https://api.github.com/users/hub4j-test-org",
+    "html_url": "https://github.com/hub4j-test-org",
+    "followers_url": "https://api.github.com/users/hub4j-test-org/followers",
+    "following_url": "https://api.github.com/users/hub4j-test-org/following{/other_user}",
+    "gists_url": "https://api.github.com/users/hub4j-test-org/gists{/gist_id}",
+    "starred_url": "https://api.github.com/users/hub4j-test-org/starred{/owner}{/repo}",
+    "subscriptions_url": "https://api.github.com/users/hub4j-test-org/subscriptions",
+    "organizations_url": "https://api.github.com/users/hub4j-test-org/orgs",
+    "repos_url": "https://api.github.com/users/hub4j-test-org/repos",
+    "events_url": "https://api.github.com/users/hub4j-test-org/events{/privacy}",
+    "received_events_url": "https://api.github.com/users/hub4j-test-org/received_events",
+    "type": "Organization",
+    "site_admin": false
+  },
+  "html_url": "https://github.com/hub4j-test-org/temp-testHandler_Wait",
+  "description": "A test repository for testing the github-api project: temp-testHandler_Wait",
+  "fork": false,
+  "url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait",
+  "forks_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/forks",
+  "keys_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/keys{/key_id}",
+  "collaborators_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/collaborators{/collaborator}",
+  "teams_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/teams",
+  "hooks_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/hooks",
+  "issue_events_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/issues/events{/number}",
+  "events_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/events",
+  "assignees_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/assignees{/user}",
+  "branches_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/branches{/branch}",
+  "tags_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/tags",
+  "blobs_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/git/blobs{/sha}",
+  "git_tags_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/git/tags{/sha}",
+  "git_refs_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/git/refs{/sha}",
+  "trees_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/git/trees{/sha}",
+  "statuses_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/statuses/{sha}",
+  "languages_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/languages",
+  "stargazers_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/stargazers",
+  "contributors_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/contributors",
+  "subscribers_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/subscribers",
+  "subscription_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/subscription",
+  "commits_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/commits{/sha}",
+  "git_commits_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/git/commits{/sha}",
+  "comments_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/comments{/number}",
+  "issue_comment_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/issues/comments{/number}",
+  "contents_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/contents/{+path}",
+  "compare_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/compare/{base}...{head}",
+  "merges_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/merges",
+  "archive_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/{archive_format}{/ref}",
+  "downloads_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/downloads",
+  "issues_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/issues{/number}",
+  "pulls_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/pulls{/number}",
+  "milestones_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/milestones{/number}",
+  "notifications_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/notifications{?since,all,participating}",
+  "labels_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/labels{/name}",
+  "releases_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/releases{/id}",
+  "deployments_url": "https://api.github.com/repos/hub4j-test-org/temp-testHandler_Wait/deployments",
+  "created_at": "2020-02-06T18:33:39Z",
+  "updated_at": "2020-02-06T18:33:43Z",
+  "pushed_at": "2020-02-06T18:33:41Z",
+  "git_url": "git://github.com/hub4j-test-org/temp-testHandler_Wait.git",
+  "ssh_url": "[email protected]:hub4j-test-org/temp-testHandler_Wait.git",
+  "clone_url": "https://github.com/hub4j-test-org/temp-testHandler_Wait.git",
+  "svn_url": "https://github.com/hub4j-test-org/temp-testHandler_Wait",
+  "homepage": "http://github-api.kohsuke.org/",
+  "size": 0,
+  "stargazers_count": 0,
+  "watchers_count": 0,
+  "language": null,
+  "has_issues": true,
+  "has_projects": true,
+  "has_downloads": true,
+  "has_wiki": true,
+  "has_pages": false,
+  "forks_count": 0,
+  "mirror_url": null,
+  "archived": false,
+  "disabled": false,
+  "open_issues_count": 0,
+  "license": null,
+  "forks": 0,
+  "open_issues": 0,
+  "watchers": 0,
+  "default_branch": "main",
+  "permissions": {
+    "admin": true,
+    "push": true,
+    "pull": true
+  },
+  "temp_clone_token": "",
+  "allow_squash_merge": true,
+  "allow_merge_commit": true,
+  "allow_rebase_merge": true,
+  "delete_branch_on_merge": false,
+  "organization": {
+    "login": "hub4j-test-org",
+    "id": 7544739,
+    "node_id": "MDEyOk9yZ2FuaXphdGlvbjc1NDQ3Mzk=",
+    "avatar_url": "https://avatars3.githubusercontent.com/u/7544739?v=4",
+    "gravatar_id": "",
+    "url": "https://api.github.com/users/hub4j-test-org",
+    "html_url": "https://github.com/hub4j-test-org",
+    "followers_url": "https://api.github.com/users/hub4j-test-org/followers",
+    "following_url": "https://api.github.com/users/hub4j-test-org/following{/other_user}",
+    "gists_url": "https://api.github.com/users/hub4j-test-org/gists{/gist_id}",
+    "starred_url": "https://api.github.com/users/hub4j-test-org/starred{/owner}{/repo}",
+    "subscriptions_url": "https://api.github.com/users/hub4j-test-org/subscriptions",
+    "organizations_url": "https://api.github.com/users/hub4j-test-org/orgs",
+    "repos_url": "https://api.github.com/users/hub4j-test-org/repos",
+    "events_url": "https://api.github.com/users/hub4j-test-org/events{/privacy}",
+    "received_events_url": "https://api.github.com/users/hub4j-test-org/received_events",
+    "type": "Organization",
+    "site_admin": false
+  },
+  "network_count": 0,
+  "subscribers_count": 6
+}

src/test/resources/org/kohsuke/github/RateLimitHandlerTest/wiremock/testHandler_Wait_Missing_Date_Header/mappings/1-user.json

@@ -0,0 +1,48 @@
+{
+  "id": "a60baf84-5b5c-4f86-af3d-cab0d609c7b2",
+  "name": "user",
+  "request": {
+    "url": "/user",
+    "method": "GET",
+    "headers": {
+      "Accept": {
+        "equalTo": "application/vnd.github+json"
+      }
+    }
+  },
+  "response": {
+    "status": 200,
+    "bodyFileName": "1-user.json",
+    "headers": {
+      "Date": "Thu, 06 Feb 2020 18:33:32 GMT",
+      "Content-Type": "application/json; charset=utf-8",
+      "Server": "GitHub.com",
+      "Status": "200 OK",
+      "X-RateLimit-Limit": "5000",
+      "X-RateLimit-Remaining": "4930",
+      "X-RateLimit-Reset": "{{now offset='3 seconds' format='unix'}}",
+      "Cache-Control": "private, max-age=60, s-maxage=60",
+      "Vary": [
+        "Accept, Authorization, Cookie, X-GitHub-OTP",
+        "Accept-Encoding"
+      ],
+      "ETag": "W/\"1cb30f031c67c499473b3aad01c7f7a5\"",
+      "Last-Modified": "Thu, 06 Feb 2020 17:29:39 GMT",
+      "X-OAuth-Scopes": "admin:org, admin:org_hook, admin:public_key, admin:repo_hook, delete_repo, gist, notifications, repo, user, write:discussion",
+      "X-Accepted-OAuth-Scopes": "",
+      "X-GitHub-Media-Type": "unknown, github.v3",
+      "Access-Control-Expose-Headers": "ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type",
+      "Access-Control-Allow-Origin": "*",
+      "Strict-Transport-Security": "max-age=31536000; includeSubdomains; preload",
+      "X-Frame-Options": "deny",
+      "X-Content-Type-Options": "nosniff",
+      "X-XSS-Protection": "1; mode=block",
+      "Referrer-Policy": "origin-when-cross-origin, strict-origin-when-cross-origin",
+      "Content-Security-Policy": "default-src 'none'",
+      "X-GitHub-Request-Id": "CC37:2605:3F884:4E941:5E3C5BFC"
+    }
+  },
+  "uuid": "a60baf84-5b5c-4f86-af3d-cab0d609c7b2",
+  "persistent": true,
+  "insertionIndex": 1
+}