Skip to content

Commit

Permalink
[JENKINS-67466] Add timeout to JGit remote operations
Browse files Browse the repository at this point in the history 
Uses the JGit timeout implementation to prevent JGit operations
from hanging indefinitely.

The JGit timeout implementation has a very different behavior than
the timeout implementation for command line git.  The command line git
implementation stops once the timeout has expired.  The JGit timeout
implementation stops after timeout period has completed with no traffic
during the timeout period.

See JENKINS-22400 for examples of other operations which still need
timeout support.

This does not add timeout support to JGit checkout because JGit checkout
does not provide a timeout API.
  • Loading branch information
@MarkEWaite
MarkEWaite committed Dec 31, 2021
1 parent 236b0bf commit 4c0b546
Show file tree
Hide file tree
Showing 8 changed files with 201 additions and 71 deletions.
16 changes: 16 additions & 0 deletions README.adoc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,22 @@ Click the "*Add Git*" button in the "*Global Tool Configuration*" section under

image::images/enable-jgit.png[Enable JGit or JGit with Apache HTTP Client]

=== JGit timeout

The command line git implementation in the git client plugin provides a timeout setting for many operations like fetch and checkout.
Operations that take more than the specified time are canceled.
When the timeout is exceeded, the command line git process fails and the git client plugin API operation fails.

The JGit implementation in the git client plugin uses a different concept of timeout.
The JGit timeout is a network level transport timeout rather than a timeout of a higher level JGit operation.
If the JGit network transport does not receive a response within the defined timeout, the JGit API call fails.
The link:https://javadoc.io/static/org.eclipse.jgit/org.eclipse.jgit/5.13.0.202109080827-r/org/eclipse/jgit/transport/Transport.html#setTimeout-int-[JGit javadoc] describes the JGit API.

The JGit timeout implementation prevents JGit operations from hanging indefinitely when a remote server stops responding.
It does not stop a JGit operation if it has executed for more than a specified time.
The JGit timeout counter is reset each time a response is received from the remote server during the JGit API call.
The command line git timeout counter is set at the start of the command line git call and is not reset during the call.

[#jgit-with-apache-http-client]
=== JGit with Apache HTTP Client

Expand Down
51 changes: 45 additions & 6 deletions src/main/java/org/jenkinsci/plugins/gitclient/JGitAPIImpl.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,8 @@
import static org.eclipse.jgit.lib.Constants.typeString;
import static org.eclipse.jgit.transport.RemoteRefUpdate.Status.OK;
import static org.eclipse.jgit.transport.RemoteRefUpdate.Status.UP_TO_DATE;
import static org.jenkinsci.plugins.gitclient.CliGitAPIImpl.TIMEOUT; // Default timeout
import static org.jenkinsci.plugins.gitclient.CliGitAPIImpl.TIMEOUT_LOG_PREFIX;

import hudson.FilePath;
import hudson.Util;
Expand Down Expand Up @@ -59,6 +61,7 @@
import org.eclipse.jgit.api.MergeCommand.FastForwardMode;
import org.eclipse.jgit.api.ResetCommand;
import org.eclipse.jgit.api.ShowNoteCommand;
import org.eclipse.jgit.api.TransportCommand;
import org.eclipse.jgit.api.errors.CheckoutConflictException;
import org.eclipse.jgit.api.errors.GitAPIException;
import org.eclipse.jgit.api.errors.JGitInternalException;
Expand Down Expand Up @@ -539,6 +542,35 @@ public boolean tagExists(String tagName) throws GitException {
}
}

static final int MAX_TIMEOUT = 1 << 15; // Avoid JGit integer overflow

private void setTransportTimeout(TransportCommand transport, String operationName, Integer timeoutInMinutes) {
if (timeoutInMinutes == null) {
/* Use the default timeout */
timeoutInMinutes = TIMEOUT;
}

/* Range check for timeoutInMinutes */
if (timeoutInMinutes > MAX_TIMEOUT) {
listener.getLogger().println("[WARNING] JGit ignoring timeout " + timeoutInMinutes + " > " + MAX_TIMEOUT + " for " + operationName);
timeoutInMinutes = MAX_TIMEOUT;
} else if (timeoutInMinutes < 1) {
listener.getLogger().println("[WARNING] JGit ignoring timeout " + timeoutInMinutes + " < 1 for " + operationName);
timeoutInMinutes = TIMEOUT; /* Use system default timeout */
}

/* Convert timeoutInMinutes to timeoutInSeconds */
int timeoutInSeconds = 10 * 60;
try {
timeoutInSeconds = Math.multiplyExact(timeoutInMinutes, 60);
} catch (ArithmeticException ae) {
listener.getLogger().println("[WARNING] JGit ignoring excessive " + timeoutInMinutes + " minute timeout for " + operationName);
}

transport.setTimeout(timeoutInSeconds);
listener.getLogger().println(" > JGit " + operationName + TIMEOUT_LOG_PREFIX + timeoutInMinutes);
}

/**
* fetch_.
*
Expand All @@ -551,6 +583,7 @@ public org.jenkinsci.plugins.gitclient.FetchCommand fetch_() {
private List<RefSpec> refspecs;
private boolean shouldPrune = false;
private boolean tags = true;
private Integer timeout;

@Override
public org.jenkinsci.plugins.gitclient.FetchCommand from(URIish remote, List<RefSpec> refspecs) {
Expand Down Expand Up @@ -580,7 +613,7 @@ public org.jenkinsci.plugins.gitclient.FetchCommand shallow(boolean shallow) {

@Override
public org.jenkinsci.plugins.gitclient.FetchCommand timeout(Integer timeout) {
// noop in jgit
this.timeout = timeout;
return this;
}

Expand Down Expand Up @@ -625,7 +658,7 @@ public void execute() throws GitException {

fetch.setRefSpecs(allRefSpecs);
fetch.setRemoveDeletedRefs(shouldPrune);

setTransportTimeout(fetch, "fetch", timeout);
fetch.call();
} catch (GitAPIException e) {
throw new GitException(e);
Expand Down Expand Up @@ -661,7 +694,7 @@ public void fetch(String remoteName, RefSpec... refspec) throws GitException {
if (rs != null)
refSpecs.add(rs);
fetch.setRefSpecs(refSpecs);

setTransportTimeout(fetch, "fetch", TIMEOUT);
fetch.call();
} catch (GitAPIException e) {
throw new GitException(e);
Expand Down Expand Up @@ -776,6 +809,7 @@ public Map<String, ObjectId> getRemoteReferences(String url, String pattern, boo
}
lsRemote.setRemote(url);
lsRemote.setCredentialsProvider(getProvider());
setTransportTimeout(lsRemote, "ls-remote", TIMEOUT);
Collection<Ref> refs = lsRemote.call();
for (final Ref r : refs) {
final String refName = r.getName();
Expand Down Expand Up @@ -810,6 +844,7 @@ public Map<String, String> getRemoteSymbolicReferences(String url, String patter
LsRemoteCommand lsRemote = new LsRemoteCommand(repo);
lsRemote.setRemote(url);
lsRemote.setCredentialsProvider(getProvider());
setTransportTimeout(lsRemote, "ls-remote", TIMEOUT);
Collection<Ref> refs = lsRemote.call();
for (final Ref r : refs) {
if (!r.isSymbolic()) { // Skip reference if it is not symbolic
Expand Down Expand Up @@ -1444,7 +1479,7 @@ else if (!referencePath.isDirectory())
.setCredentialsProvider(getProvider())
.setTagOpt(tags ? TagOpt.FETCH_TAGS : TagOpt.NO_TAGS)
.setRefSpecs(refspecs);
if (timeout != null) fetch.setTimeout(timeout);
setTransportTimeout(fetch, "fetch", timeout);
fetch.call();

StoredConfig config = repository.getConfig();
Expand Down Expand Up @@ -1834,6 +1869,7 @@ public PushCommand push() {
private String refspec;
private boolean force;
private boolean tags;
private Integer timeout;

@Override
public PushCommand to(URIish remote) {
Expand Down Expand Up @@ -1866,7 +1902,7 @@ public PushCommand tags(boolean tags) {

@Override
public PushCommand timeout(Integer timeout) {
// noop in jgit
this.timeout = timeout;
return this;
}

Expand All @@ -1888,6 +1924,7 @@ public void execute() throws GitException {
if(tags) {
pc.setPushTags();
}
setTransportTimeout(pc, "push", timeout);
Iterable<PushResult> results = pc.call();
for(PushResult result:results) for(RemoteRefUpdate update:result.getRemoteUpdates()) {
RemoteRefUpdate.Status status = update.getStatus();
Expand Down Expand Up @@ -2183,6 +2220,7 @@ public org.jenkinsci.plugins.gitclient.SubmoduleUpdateCommand submoduleUpdate()
private boolean recursive = false;
private boolean remoteTracking = false;
private String ref = null;
private Integer timeout;

@Override
public org.jenkinsci.plugins.gitclient.SubmoduleUpdateCommand recursive(boolean recursive) {
Expand Down Expand Up @@ -2210,7 +2248,7 @@ public org.jenkinsci.plugins.gitclient.SubmoduleUpdateCommand ref(String ref) {

@Override
public org.jenkinsci.plugins.gitclient.SubmoduleUpdateCommand timeout(Integer timeout) {
// noop in jgit
this.timeout = timeout;
return this;
}

Expand Down Expand Up @@ -2260,6 +2298,7 @@ public void execute() throws GitException, InterruptedException {
try (Repository repo = getRepository()) {
SubmoduleUpdateCommand update = git(repo).submoduleUpdate();
update.setCredentialsProvider(getProvider());
setTransportTimeout(update, "update", timeout);
update.call();
if (recursive) {
for (JGitAPIImpl sub : submodules()) {
Expand Down
1 change: 0 additions & 1 deletion src/test/java/org/jenkinsci/plugins/gitclient/CliGitAPIImplTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,6 @@ protected void runTest() throws Throwable {
Method m = getClass().getMethod(getName());

if (m.getAnnotation(NotImplementedInCliGit.class) != null) {
setTimeoutVisibleInCurrentTest(false); /* No timeout if not implemented in CliGitAPIImpl */
return; // skip this test case
}
try {
Expand Down
53 changes: 0 additions & 53 deletions src/test/java/org/jenkinsci/plugins/gitclient/GitClientCliCloneTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -68,51 +68,6 @@ public void setUpRepositories() throws Exception {
testGitClient = workspace.getGitClient();
}

/* JENKINS-33258 detected many calls to git rev-parse. This checks
* those calls are not being made. The checkoutRandomBranch call
* creates a branch with a random name. The later assertion checks that
* the random branch name is not mentioned in a call to git rev-parse.
*/
private String checkoutRandomBranch() throws GitException, InterruptedException {
String branchName = "rev-parse-branch-" + UUID.randomUUID();
testGitClient.checkout().ref("origin/master").branch(branchName).execute();
Set<String> branchNames = testGitClient.getBranches().stream().map(Branch::getName).collect(Collectors.toSet());
assertThat(branchNames, hasItem(branchName));
return branchName;
}

@Test
public void test_clone_default_timeout_logging() throws Exception {
testGitClient.clone_().url(workspace.localMirror()).repositoryName("origin").execute();
assertTimeout(testGitClient, "git fetch", CliGitAPIImpl.TIMEOUT);
}

@Test
public void test_clone_timeout_logging() throws Exception {
int largerTimeout = CliGitAPIImpl.TIMEOUT + 1 + random.nextInt(600);
testGitClient.clone_().url(workspace.localMirror()).timeout(largerTimeout).repositoryName("origin").execute();
assertTimeout(testGitClient, "git fetch", largerTimeout);
}

@Test
public void test_fetch_default_timeout_logging() throws Exception {
testGitClient.clone_().url(workspace.localMirror()).repositoryName("origin").execute();
String randomBranchName = checkoutRandomBranch();
testGitClient.fetch_().from(new URIish("origin"), null).prune(true).execute();
assertTimeout(testGitClient, "git fetch", CliGitAPIImpl.TIMEOUT);
assertRevParseNotCalled(testGitClient, randomBranchName);
}

@Test
public void test_fetch_timeout_logging() throws Exception {
int largerTimeout = CliGitAPIImpl.TIMEOUT + 1 + random.nextInt(600);
testGitClient.clone_().url(workspace.localMirror()).repositoryName("origin").execute();
String randomBranchName = checkoutRandomBranch(); // Check that prune(true) does not call git rev-parse
testGitClient.fetch_().from(new URIish("origin"), null).prune(true).timeout(largerTimeout).execute();
assertTimeout(testGitClient, "git fetch .* origin", largerTimeout);
assertRevParseNotCalled(testGitClient, randomBranchName);
}

@Test
public void test_checkout_default_timeout_logging() throws Exception {
testGitClient.clone_().url(workspace.localMirror()).repositoryName("origin").execute();
Expand Down Expand Up @@ -202,12 +157,4 @@ private void assertLoggedMessage(GitClient gitClient, final String candidateSubs
private void assertTimeout(GitClient gitClient, final String substring, int expectedTimeout) {
assertLoggedMessage(gitClient, substring, " [#] timeout=" + expectedTimeout, true);
}

/* JENKINS-33258 detected many calls to git rev-parse. This checks
* those calls that unexpectedBranchName is not referenced in the
* log.
*/
private void assertRevParseNotCalled(GitClient gitClient, String unexpectedBranchName) {
assertLoggedMessage(gitClient, "git rev-parse ", unexpectedBranchName, false);
}
}
61 changes: 61 additions & 0 deletions src/test/java/org/jenkinsci/plugins/gitclient/GitClientCloneTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
import org.eclipse.jgit.lib.Constants;
import org.eclipse.jgit.lib.Repository;
import org.eclipse.jgit.transport.RefSpec;
import org.eclipse.jgit.transport.URIish;
import org.junit.Before;
import org.junit.BeforeClass;
import org.junit.Rule;
Expand All @@ -28,8 +29,10 @@
import java.util.List;
import java.util.Random;
import java.util.Set;
import java.util.UUID;
import java.util.logging.Level;
import java.util.logging.Logger;
import java.util.stream.Collectors;

import static java.util.stream.Collectors.toList;
import static org.hamcrest.MatcherAssert.*;
Expand Down Expand Up @@ -322,6 +325,35 @@ public void test_addRemoteUrl_local_clone() throws Exception {
assertThat("Origin URL after add", testGitClient.getRemoteUrl("origin"), is(workspace.localMirror()));
}

@Test
public void test_clone_default_timeout_logging() throws Exception {
testGitClient.clone_().url(workspace.localMirror()).repositoryName("origin").execute();
assertTimeout(testGitClient, "fetch", CliGitAPIImpl.TIMEOUT);
}

@Test
public void test_clone_timeout_logging() throws Exception {
int largerTimeout = CliGitAPIImpl.TIMEOUT + 1 + random.nextInt(600);
testGitClient.clone_().url(workspace.localMirror()).timeout(largerTimeout).repositoryName("origin").execute();
assertTimeout(testGitClient, "fetch", largerTimeout);
}

@Test
public void test_max_timeout_logging() throws Exception {
int maxTimeout = JGitAPIImpl.MAX_TIMEOUT;
testGitClient.clone_().url(workspace.localMirror()).timeout(maxTimeout).repositoryName("origin").execute();
assertTimeout(testGitClient, "fetch", maxTimeout);
}

@Test
public void test_clone_huge_timeout_logging() throws Exception {
int hugeTimeout = JGitAPIImpl.MAX_TIMEOUT + 1 + random.nextInt(Integer.MAX_VALUE - 1 - JGitAPIImpl.MAX_TIMEOUT);
testGitClient.clone_().url(workspace.localMirror()).timeout(hugeTimeout).repositoryName("origin").execute();
/* Expect fallback value from JGit for this nonsense timeout value */
int expectedValue = gitImplName.startsWith("jgit") ? JGitAPIImpl.MAX_TIMEOUT : hugeTimeout;
assertTimeout(testGitClient, "fetch", expectedValue);
}

private void assertAlternatesFileExists() {
final String alternates = ".git" + File.separator + "objects" + File.separator + "info" + File.separator + "alternates";
assertThat(new File(testGitDir, alternates), is(anExistingFile()));
Expand Down Expand Up @@ -397,4 +429,33 @@ private void check_remote_url(WorkspaceWithRepo workspace, GitClient gitClient,
assertThat("Updated URL", remotes, containsString(workspace.localMirror()));
}

private void assertLoggedMessage(GitClient gitClient, final String candidateSubstring, final String expectedValue, final boolean expectToFindMatch) {
List<String> messages = handler.getMessages();
List<String> candidateMessages = new ArrayList<>();
List<String> matchedMessages = new ArrayList<>();
final String messageRegEx = ".*\\b" + candidateSubstring + "\\b.*"; // the expected substring
final String timeoutRegEx = messageRegEx + expectedValue + "\\b.*"; // # timeout=<value>
for (String message : messages) {
if (message.matches(messageRegEx)) {
candidateMessages.add(message);
}
if (message.matches(timeoutRegEx)) {
matchedMessages.add(message);
}
}
assertThat("No messages logged", messages, is(not(empty())));
if (expectToFindMatch) {
assertThat("No messages matched substring '" + candidateSubstring + "'", candidateMessages, is(not(empty())));
assertThat("Messages matched substring '" + candidateSubstring + "', found: " + candidateMessages + "\nExpected " + expectedValue, matchedMessages, is(not(empty())));
assertThat("All candidate messages matched", matchedMessages, is(candidateMessages));
} else {
assertThat("Messages matched substring '" + candidateSubstring + "' unexpectedly", candidateMessages, is(empty()));
}
}

private void assertTimeout(GitClient gitClient, final String substring, int expectedTimeout) {
String implName = gitImplName.equals("git") ? "git" : "JGit";
String operationName = implName + " " + substring;
assertLoggedMessage(gitClient, operationName, " [#] timeout=" + expectedTimeout, true);
}
}

0 comments on commit 4c0b546

Please sign in to comment.