Skip to content

Commit aeb5e5f

Browse files
authored
Merge pull request hub4j#674 from v1v/master
Retry when SocketException with some sleep
2 parents 1c2e491 + eb4000f commit aeb5e5f

26 files changed

Lines changed: 2287 additions & 18 deletions

File tree

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

Lines changed: 66 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -31,13 +31,15 @@
3131
import java.io.IOException;
3232
import java.io.InputStream;
3333
import java.io.InputStreamReader;
34+
import java.io.InterruptedIOException;
3435
import java.io.Reader;
3536
import java.io.UnsupportedEncodingException;
3637
import java.lang.reflect.Array;
3738
import java.lang.reflect.Field;
3839
import java.net.HttpURLConnection;
3940
import java.net.MalformedURLException;
4041
import java.net.ProtocolException;
42+
import java.net.SocketException;
4143
import java.net.SocketTimeoutException;
4244
import java.net.URI;
4345
import java.net.URISyntaxException;
@@ -74,6 +76,7 @@
7476
* @author Kohsuke Kawaguchi
7577
*/
7678
class Requester {
79+
public static final int CONNECTION_ERROR_RETRIES = 2;
7780
private final GitHub root;
7881
private final List<Entry> args = new ArrayList<Entry>();
7982
private final Map<String, String> headers = new LinkedHashMap<String, String>();
@@ -104,6 +107,11 @@ private Entry(String key, Object value) {
104107
}
105108
}
106109

110+
/**
111+
* If timeout issues let's retry after milliseconds.
112+
*/
113+
private static final int retryTimeoutMillis = 500;
114+
107115
Requester(GitHub root) {
108116
this.root = root;
109117
}
@@ -492,8 +500,7 @@ private <T> T _fetch(String tailApiUrl, URL url, SupplierThrows<T, IOException>
492500
uc = setupConnection(url);
493501

494502
try {
495-
retryInvalidCached404Response();
496-
return supplier.get();
503+
return _fetchOrRetry(supplier, CONNECTION_ERROR_RETRIES);
497504
} catch (IOException e) {
498505
handleApiError(e);
499506
} finally {
@@ -502,6 +509,55 @@ private <T> T _fetch(String tailApiUrl, URL url, SupplierThrows<T, IOException>
502509
}
503510
}
504511

512+
private <T> T _fetchOrRetry(SupplierThrows<T, IOException> supplier, int retries) throws IOException {
513+
int responseCode = -1;
514+
String responseMessage = null;
515+
// When retries equal 0 the previous call must return or throw, not retry again
516+
if (retries < 0) {
517+
throw new IllegalArgumentException("'retries' cannot be less than 0");
518+
}
519+
520+
try {
521+
// This is where the request is sent and response is processing starts
522+
responseCode = uc.getResponseCode();
523+
responseMessage = uc.getResponseMessage();
524+
525+
// If we are caching and get an invalid cached 404, retry it.
526+
if (!retryInvalidCached404Response(responseCode, retries)) {
527+
return supplier.get();
528+
}
529+
} catch (FileNotFoundException e) {
530+
// java.net.URLConnection handles 404 exception as FileNotFoundException,
531+
// don't wrap exception in HttpException to preserve backward compatibility
532+
throw e;
533+
} catch (IOException e) {
534+
if (!retrySocketException(e, retries)) {
535+
throw new HttpException(responseCode, responseMessage, uc.getURL(), e);
536+
}
537+
}
538+
539+
// We did not fetch or throw, retry
540+
return _fetchOrRetry(supplier, retries - 1);
541+
542+
}
543+
544+
private boolean retrySocketException(IOException e, int retries) throws IOException {
545+
if ((e instanceof SocketException || e instanceof SocketTimeoutException) && retries > 0) {
546+
LOGGER.log(INFO,
547+
"timed out accessing " + uc.getURL() + ". Sleeping " + Requester.retryTimeoutMillis
548+
+ " milliseconds before retrying... ; will try " + retries + " more time(s)",
549+
e);
550+
try {
551+
Thread.sleep(Requester.retryTimeoutMillis);
552+
} catch (InterruptedException ie) {
553+
throw (IOException) new InterruptedIOException().initCause(e);
554+
}
555+
uc = setupConnection(uc.getURL());
556+
return true;
557+
}
558+
return false;
559+
}
560+
505561
private <T> T[] concatenatePages(Class<T[]> type, List<T[]> pages, int totalLength) {
506562

507563
T[] result = type.cast(Array.newInstance(type.getComponentType(), totalLength));
@@ -851,10 +907,8 @@ private <T> T parse(Class<T> type, T instance) throws IOException {
851907
private <T> T parse(Class<T> type, T instance, int timeouts) throws IOException {
852908
InputStreamReader r = null;
853909
int responseCode = -1;
854-
String responseMessage = null;
855910
try {
856911
responseCode = uc.getResponseCode();
857-
responseMessage = uc.getResponseMessage();
858912
if (responseCode == 304) {
859913
return null; // special case handling for 304 unmodified, as the content will be ""
860914
}
@@ -898,22 +952,12 @@ private <T> T parse(Class<T> type, T instance, int timeouts) throws IOException
898952
return setResponseHeaders(MAPPER.readerForUpdating(instance).<T>readValue(data));
899953
}
900954
return null;
901-
} catch (FileNotFoundException e) {
902-
// java.net.URLConnection handles 404 exception as FileNotFoundException,
903-
// don't wrap exception in HttpException to preserve backward compatibility
904-
throw e;
905-
} catch (IOException e) {
906-
if (e instanceof SocketTimeoutException && timeouts > 0) {
907-
LOGGER.log(INFO, "timed out accessing " + uc.getURL() + "; will try " + timeouts + " more time(s)", e);
908-
return parse(type, instance, timeouts - 1);
909-
}
910-
throw new HttpException(responseCode, responseMessage, uc.getURL(), e);
911955
} finally {
912956
IOUtils.closeQuietly(r);
913957
}
914958
}
915959

916-
private void retryInvalidCached404Response() throws IOException {
960+
private boolean retryInvalidCached404Response(int responseCode, int retries) throws IOException {
917961
// WORKAROUND FOR ISSUE #669:
918962
// When the Requester detects a 404 response with an ETag (only happpens when the server's 304
919963
// is bogus and would cause cache corruption), try the query again with new request header
@@ -924,16 +968,20 @@ private void retryInvalidCached404Response() throws IOException {
924968
// scenarios. If GitHub ever fixes their issue and/or begins providing accurate ETags to
925969
// their 404 responses, this will result in at worst two requests being made for each 404
926970
// responses. However, only the second request will count against rate limit.
927-
int responseCode = uc.getResponseCode();
928971
if (responseCode == 404 && Objects.equals(uc.getRequestMethod(), "GET") && uc.getHeaderField("ETag") != null
929-
&& !Objects.equals(uc.getRequestProperty("Cache-Control"), "no-cache")) {
972+
&& !Objects.equals(uc.getRequestProperty("Cache-Control"), "no-cache") && retries > 0) {
973+
LOGGER.log(FINE,
974+
"Encountered GitHub invalid cached 404 from " + uc.getURL()
975+
+ ". Retrying with \"Cache-Control\"=\"no-cache\"...");
976+
930977
uc = setupConnection(uc.getURL());
931978
// Setting "Cache-Control" to "no-cache" stops the cache from supplying
932979
// "If-Modified-Since" or "If-None-Match" values.
933980
// This makes GitHub give us current data (not incorrectly cached data)
934981
uc.setRequestProperty("Cache-Control", "no-cache");
935-
uc.getResponseCode();
982+
return true;
936983
}
984+
return false;
937985
}
938986

939987
private <T> T setResponseHeaders(T readValue) {
Lines changed: 148 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,148 @@
1+
package org.kohsuke.github;
2+
3+
import com.github.tomakehurst.wiremock.http.Fault;
4+
import com.github.tomakehurst.wiremock.stubbing.Scenario;
5+
import org.junit.Before;
6+
import org.junit.Test;
7+
8+
import java.io.ByteArrayOutputStream;
9+
import java.io.IOException;
10+
import java.io.OutputStream;
11+
import java.util.logging.Handler;
12+
import java.util.logging.Logger;
13+
import java.util.logging.StreamHandler;
14+
15+
import static com.github.tomakehurst.wiremock.client.WireMock.*;
16+
import static org.hamcrest.Matchers.*;
17+
18+
/**
19+
* @author Victor Martinez
20+
*/
21+
public class TimeoutRetryTest extends AbstractGitHubWireMockTest {
22+
23+
private static Logger log = Logger.getLogger(Requester.class.getName()); // matches the logger in the affected class
24+
private static OutputStream logCapturingStream;
25+
private static StreamHandler customLogHandler;
26+
27+
protected GHRepository getRepository() throws IOException {
28+
return getRepository(gitHub);
29+
}
30+
31+
private GHRepository getRepository(GitHub gitHub) throws IOException {
32+
return gitHub.getOrganization("github-api-test-org").getRepository("github-api");
33+
}
34+
35+
@Before
36+
public void attachLogCapturer() {
37+
logCapturingStream = new ByteArrayOutputStream();
38+
Handler[] handlers = log.getParent().getHandlers();
39+
customLogHandler = new StreamHandler(logCapturingStream, handlers[0].getFormatter());
40+
log.addHandler(customLogHandler);
41+
}
42+
43+
public String getTestCapturedLog() throws IOException {
44+
customLogHandler.flush();
45+
return logCapturingStream.toString();
46+
}
47+
48+
// Issue #539
49+
@Test
50+
public void testSocketConnectionAndRetry() throws Exception {
51+
// CONNECTION_RESET_BY_PEER errors result in two requests each
52+
// to get this failure for "3" tries we have to do 6 queries.
53+
this.mockGitHub.apiServer()
54+
.stubFor(get(urlMatching(".+/branches/test/timeout"))
55+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)));
56+
57+
GHRepository repo = getRepository();
58+
int baseRequestCount = this.mockGitHub.getRequestCount();
59+
try {
60+
repo.getBranch("test/timeout");
61+
fail();
62+
} catch (Exception e) {
63+
assertThat(e, instanceOf(HttpException.class));
64+
}
65+
66+
String capturedLog = getTestCapturedLog();
67+
assertTrue(capturedLog.contains("will try 2 more time"));
68+
assertTrue(capturedLog.contains("will try 1 more time"));
69+
70+
assertThat(this.mockGitHub.getRequestCount(), equalTo(baseRequestCount + 6));
71+
}
72+
73+
// Issue #539
74+
@Test
75+
public void testSocketConnectionAndRetry_StatusCode() throws Exception {
76+
// CONNECTION_RESET_BY_PEER errors result in two requests each
77+
// to get this failure for "3" tries we have to do 6 queries.
78+
this.mockGitHub.apiServer()
79+
.stubFor(get(urlMatching(".+/branches/test/timeout"))
80+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)));
81+
82+
int baseRequestCount = this.mockGitHub.getRequestCount();
83+
try {
84+
// status code is a different code path that should also be covered by this.
85+
gitHub.createRequest()
86+
.withUrlPath("/repos/github-api-test-org/github-api/branches/test/timeout")
87+
.fetchHttpStatusCode();
88+
fail();
89+
} catch (Exception e) {
90+
assertThat(e, instanceOf(HttpException.class));
91+
}
92+
93+
String capturedLog = getTestCapturedLog();
94+
assertTrue(capturedLog.contains("will try 2 more time"));
95+
assertTrue(capturedLog.contains("will try 1 more time"));
96+
97+
assertThat(this.mockGitHub.getRequestCount(), equalTo(baseRequestCount + 6));
98+
}
99+
100+
@Test
101+
public void testSocketConnectionAndRetry_Success() throws Exception {
102+
// CONNECTION_RESET_BY_PEER errors result in two requests each
103+
// to get this failure for "3" tries we have to do 6 queries.
104+
// If there are only 5 errors we succeed.
105+
this.mockGitHub.apiServer()
106+
.stubFor(get(urlMatching(".+/branches/test/timeout")).atPriority(0)
107+
.inScenario("Retry")
108+
.whenScenarioStateIs(Scenario.STARTED)
109+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)))
110+
.setNewScenarioState("Retry-1");
111+
this.mockGitHub.apiServer()
112+
.stubFor(get(urlMatching(".+/branches/test/timeout")).atPriority(0)
113+
.inScenario("Retry")
114+
.whenScenarioStateIs("Retry-1")
115+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)))
116+
.setNewScenarioState("Retry-2");
117+
this.mockGitHub.apiServer()
118+
.stubFor(get(urlMatching(".+/branches/test/timeout")).atPriority(0)
119+
.inScenario("Retry")
120+
.whenScenarioStateIs("Retry-2")
121+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)))
122+
.setNewScenarioState("Retry-3");
123+
this.mockGitHub.apiServer()
124+
.stubFor(get(urlMatching(".+/branches/test/timeout")).atPriority(0)
125+
.inScenario("Retry")
126+
.whenScenarioStateIs("Retry-3")
127+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)))
128+
.setNewScenarioState("Retry-4");
129+
this.mockGitHub.apiServer()
130+
.stubFor(get(urlMatching(".+/branches/test/timeout")).atPriority(0)
131+
.atPriority(0)
132+
.inScenario("Retry")
133+
.whenScenarioStateIs("Retry-4")
134+
.willReturn(aResponse().withFault(Fault.CONNECTION_RESET_BY_PEER)))
135+
.setNewScenarioState("Retry-5");
136+
137+
GHRepository repo = getRepository();
138+
int baseRequestCount = this.mockGitHub.getRequestCount();
139+
GHBranch branch = repo.getBranch("test/timeout");
140+
assertThat(branch, notNullValue());
141+
String capturedLog = getTestCapturedLog();
142+
assertTrue(capturedLog.contains("will try 2 more time"));
143+
assertTrue(capturedLog.contains("will try 1 more time"));
144+
145+
assertThat(this.mockGitHub.getRequestCount(), equalTo(baseRequestCount + 6));
146+
147+
}
148+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,42 @@
1+
{
2+
"login": "github-api-test-org",
3+
"id": 7544739,
4+
"node_id": "MDEyOk9yZ2FuaXphdGlvbjc1NDQ3Mzk=",
5+
"url": "https://api.github.com/orgs/github-api-test-org",
6+
"repos_url": "https://api.github.com/orgs/github-api-test-org/repos",
7+
"events_url": "https://api.github.com/orgs/github-api-test-org/events",
8+
"hooks_url": "https://api.github.com/orgs/github-api-test-org/hooks",
9+
"issues_url": "https://api.github.com/orgs/github-api-test-org/issues",
10+
"members_url": "https://api.github.com/orgs/github-api-test-org/members{/member}",
11+
"public_members_url": "https://api.github.com/orgs/github-api-test-org/public_members{/member}",
12+
"avatar_url": "https://avatars3.githubusercontent.com/u/7544739?v=4",
13+
"description": null,
14+
"is_verified": false,
15+
"has_organization_projects": true,
16+
"has_repository_projects": true,
17+
"public_repos": 9,
18+
"public_gists": 0,
19+
"followers": 0,
20+
"following": 0,
21+
"html_url": "https://github.com/github-api-test-org",
22+
"created_at": "2014-05-10T19:39:11Z",
23+
"updated_at": "2015-04-20T00:42:30Z",
24+
"type": "Organization",
25+
"total_private_repos": 0,
26+
"owned_private_repos": 0,
27+
"private_gists": 0,
28+
"disk_usage": 132,
29+
"collaborators": 0,
30+
"billing_email": "kk@kohsuke.org",
31+
"default_repository_permission": "none",
32+
"members_can_create_repositories": false,
33+
"two_factor_requirement_enabled": false,
34+
"members_allowed_repository_creation_type": "none",
35+
"plan": {
36+
"name": "free",
37+
"space": 976562499,
38+
"private_repos": 0,
39+
"filled_seats": 3,
40+
"seats": 0
41+
}
42+
}

0 commit comments

Comments
 (0)