Skip to content

Better fix to [JENKINS-25519] -- avoid errors when trying to read exitStatus from durable task before finished writing #66

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
svanoort merged 8 commits into from
Mar 6, 2018
Merged

Better fix to [JENKINS-25519] -- avoid errors when trying to read exitStatus from durable task before finished writing #66

Show file tree
Hide file tree
Changes from 5 commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
fce0a64
Basic linux fix to do atomic write of exitStatus + 0-length check
svanoort Mar 3, 2018
3e5c724
Attempt atomic write for Batch version
svanoort Mar 3, 2018
031732c
Use a FileCallable for exit status check to avoid roundtrips
svanoort Mar 3, 2018
72ab895
Fix small oopsy
svanoort Mar 4, 2018
b90d99e
Fix trimming of StatusCheck
svanoort Mar 5, 2018
664a6ae
Remove needless TODO
svanoort Mar 5, 2018
989f290
Fix one oopsy
svanoort Mar 5, 2018
8660ea5
Maybe do not be as cautious
svanoort Mar 5, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 9 additions & 5 deletions src/main/java/org/jenkinsci/plugins/durabletask/BourneShellScript.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -138,9 +138,12 @@ public String getScript() {
String cmd;
FilePath logFile = c.getLogFile(ws);
FilePath resultFile = c.getResultFile(ws);
if (resultFile.exists()) {
resultFile.delete(); // Maybe overly cautious, but better safe than sorry, similarly we should make sure no duplicate logfile?
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, the whole control directory should not exist before we start, or should be empty.

}
FilePath controlDir = c.controlDir(ws);
if (capturingOutput) {
cmd = String.format("{ while [ -d '%s' -a \\! -f '%s' ]; do touch '%s'; sleep 3; done } & jsc=%s; %s=$jsc '%s' > '%s' 2> '%s'; echo $? > '%s'; wait",
cmd = String.format("{ while [ -d '%s' -a \\! -f '%s' ]; do touch '%s'; sleep 3; done } & jsc=%s; %s=$jsc '%s' > '%s' 2> '%s'; echo $? > '%s.tmp'; mv '%s.tmp' '%s'; wait",
controlDir,
resultFile,
logFile,
Expand All @@ -149,17 +152,17 @@ public String getScript() {
scriptPath,
c.getOutputFile(ws),
logFile,
resultFile);
resultFile, resultFile, resultFile);
} else {
cmd = String.format("{ while [ -d '%s' -a \\! -f '%s' ]; do touch '%s'; sleep 3; done } & jsc=%s; %s=$jsc '%s' > '%s' 2>&1; echo $? > '%s'; wait",
cmd = String.format("{ while [ -d '%s' -a \\! -f '%s' ]; do touch '%s'; sleep 3; done } & jsc=%s; %s=$jsc '%s' > '%s' 2>&1; echo $? > '%s.tmp'; mv '%s.tmp' '%s'; wait",
controlDir,
resultFile,
logFile,
cookieValue,
cookieVariable,
scriptPath,
logFile,
resultFile);
resultFile, resultFile, resultFile);
}
cmd = cmd.replace("$", "$$"); // escape against EnvVars jobEnv in LocalLauncher.launch

Expand Down Expand Up @@ -207,6 +210,7 @@ private FilePath pidFile(FilePath ws) throws IOException, InterruptedException {
return controlDir(ws).child("pid");
}

// TODO run as one big MasterToSlaveCallable<Integer> to avoid extra network roundtrips
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Irrelevant after #60.

Copy link
Member Author

@svanoort svanoort Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assuming #60 is fundamentally reliable. We can always remove the comment if it tests clean. And we may have to do yet another emergency fix due to something introduced in #49 before that gets integrated.

@Override public Integer exitStatus(FilePath workspace, Launcher launcher, TaskListener listener) throws IOException, InterruptedException {
Integer status = super.exitStatus(workspace, launcher, listener);
if (status != null) {
Expand All @@ -231,7 +235,7 @@ private FilePath pidFile(FilePath ws) throws IOException, InterruptedException {
if (pidFile.exists()) {
listener.getLogger().println("still have " + pidFile + " so heartbeat checks unreliable; process may or may not be alive");
} else {
listener.getLogger().println("wrapper script does not seem to be touching the log file in " + controlDir);
listener.getLogger().println("s " + controlDir);
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Uh…?

Copy link
Member Author

@svanoort svanoort Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Erm, I have no idea where that came from. Best guess It was a hotkeying error somewhere, but fixing now.

listener.getLogger().println("(JENKINS-48300: if on a laggy filesystem, consider -Dorg.jenkinsci.plugins.durabletask.BourneShellScript.HEARTBEAT_CHECK_INTERVAL=300)");
return recordExitStatus(workspace, -1);
}
Expand Down
43 changes: 34 additions & 9 deletions src/main/java/org/jenkinsci/plugins/durabletask/FileMonitoringTask.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@

package org.jenkinsci.plugins.durabletask;

import com.google.common.io.Files;
import hudson.EnvVars;
import hudson.FilePath;
import hudson.Launcher;
Expand All @@ -40,6 +41,7 @@
import java.io.OutputStream;
import java.io.RandomAccessFile;
import java.io.StringWriter;
import java.nio.charset.Charset;
import java.util.Collections;
import java.util.Map;
import java.util.TreeMap;
Expand All @@ -48,6 +50,9 @@
import java.util.logging.Logger;
import jenkins.MasterToSlaveFileCallable;
import org.apache.commons.io.IOUtils;
import org.jenkinsci.remoting.RoleChecker;

import javax.annotation.CheckForNull;

/**
* A task which forks some external command and then waits for log and status files to be updated/created.
Expand Down Expand Up @@ -160,20 +165,40 @@ private static class WriteLog extends MasterToSlaveFileCallable<Long> {
}
}

// TODO would be more efficient to allow API to consolidate writeLog with exitStatus (save an RPC call)
@Override public Integer exitStatus(FilePath workspace, Launcher launcher, TaskListener listener) throws IOException, InterruptedException {
FilePath status = getResultFile(workspace);
if (status.exists()) {
try {
return Integer.parseInt(status.readToString().trim());
} catch (NumberFormatException x) {
throw new IOException("corrupted content in " + status + ": " + x, x);
/** Avoids excess round-tripping when reading status file. */
static class StatusCheck extends MasterToSlaveFileCallable<Integer> {
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is just gratuitous merge conflict creation against #60. Better to keep the patch short and to the point.

Copy link
Member Author

@svanoort svanoort Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We have one particular user who has longer latencies and this change likely helps keep them under the timeouts - thus it is hardly "gratuitous."

@Override
@CheckForNull
public Integer invoke(File f, VirtualChannel channel) throws IOException, InterruptedException {
if (f.exists() && f.length() > 0) {
try {
String fileString = Files.readFirstLine(f, Charset.defaultCharset());
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Anyway you could just get rid of the exists check and use a single readToString call, catching FileNotFoundException and ignoring.

Copy link
Member Author

@svanoort svanoort Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If it's all agent-local then it doesn't really matter, does it? Also: as a rule of thumb in Java one should not be throwing Exceptions to signal routine and expected conditions. They come with a higher than normal level of baggage.

As opposed to Python where that's the idiomatic way to signal things like an Iterator being done.

Copy link
Member

@jglick jglick Mar 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, packaging all of this up in a Remoting call is a pretty high level of baggage, which would swamp any tiny overhead of Throwable.fillInStackTrace in this case.

Copy link
Member

@jglick jglick Mar 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Minor note: use of defaultCharset could theoretically cause issues on z/OS. Since we are expecting this file to be ASCII (it should in fact just contain [0-9]+), it is safer and clearer to use StandardCharsets.ASCII.

Copy link
Member Author

@svanoort svanoort Mar 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A really critical point - it looks like this is already broken, per #28 -- I think we'd need to address it in more comprehensive work to get it to play nicely in any case.

if (fileString == null || fileString.isEmpty()) {
return null;
} else {
fileString = fileString.trim();
if (fileString.isEmpty()) {
return null;
} else {
return Integer.parseInt(fileString);
}
}
} catch (NumberFormatException x) {
throw new IOException("corrupted content in " + f + ": " + x, x);
}
}
} else {
return null;
}
}

static final StatusCheck STATUS_CHECK_INSTANCE = new StatusCheck();
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You know act is doing object allocation anyway, right?


// TODO would be more efficient to allow API to consolidate writeLog with exitStatus (save an RPC call)
@Override public Integer exitStatus(FilePath workspace, Launcher launcher, TaskListener listener) throws IOException, InterruptedException {
FilePath status = getResultFile(workspace);
return status.act(STATUS_CHECK_INSTANCE);
}

@Override public byte[] getOutput(FilePath workspace, Launcher launcher) throws IOException, InterruptedException {
// TODO could perhaps be more efficient for large files to send a MasterToSlaveFileCallable<byte[]>
try (InputStream is = getOutputFile(workspace).read()) {
Expand Down
9 changes: 5 additions & 4 deletions src/main/java/org/jenkinsci/plugins/durabletask/WindowsBatchScript.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,17 +60,18 @@ public String getScript() {
BatchController c = new BatchController(ws);

String cmd;
String quotedResultFile = quote(c.getResultFile(ws));
if (capturingOutput) {
cmd = String.format("@echo off \r\ncmd /c \"\"%s\"\" > \"%s\" 2> \"%s\"\r\necho %%ERRORLEVEL%% > \"%s\"\r\n",
cmd = String.format("@echo off \r\ncmd /c \"\"%s\"\" > \"%s\" 2> \"%s\"\r\necho %%ERRORLEVEL%% > \"%s.tmp\"\r\nmove \"%s.tmp\" \"%s\"\r\n",
Copy link
Member

@jglick jglick Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And PowerShell?

Copy link
Member Author

@svanoort svanoort Mar 5, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Powershell is caught by the 0-length check -- I have no idea how we'd even begin applying this to it and was planning to ask @gabloe or @jtnord because they know the Windows side of things.

Can at least still write a Batch script though, so I included that.

Copy link
Member

@jglick jglick Mar 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sensible.

quote(c.getBatchFile2(ws)),
quote(c.getOutputFile(ws)),
quote(c.getLogFile(ws)),
quote(c.getResultFile(ws)));
quotedResultFile, quotedResultFile, quotedResultFile);
} else {
cmd = String.format("@echo off \r\ncmd /c \"\"%s\"\" > \"%s\" 2>&1\r\necho %%ERRORLEVEL%% > \"%s\"\r\n",
cmd = String.format("@echo off \r\ncmd /c \"\"%s\"\" > \"%s\" 2>&1\r\necho %%ERRORLEVEL%% > \"%s.tmp\"\r\nmove \"%s.tmp\" \"%s\"\n",
quote(c.getBatchFile2(ws)),
quote(c.getLogFile(ws)),
quote(c.getResultFile(ws)));
quotedResultFile, quotedResultFile, quotedResultFile);
}
c.getBatchFile1(ws).write(cmd, "UTF-8");
c.getBatchFile2(ws).write(script, "UTF-8");
Expand Down