[JENKINS-54128] More efficient implementation of getLogFile that just uses the existing file when possible #118

jglick · 2018-11-08T03:11:24Z

JENKINS-54128 Some plugins apparently call this a lot so deal with it.

…ng file when possible.

dwnusbaum

Looks good, just minor comments.

src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java

dwnusbaum · 2018-11-08T14:16:18Z

src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java

    }

    @Override public File getLogFile() {
        LOGGER.log(Level.WARNING, "Avoid calling getLogFile on " + this, new UnsupportedOperationException());


Given the number of existing callers, should we only log the stack trace at FINE level?

Well…we only know about those callers because it is at WARNING. And this would be important e.g. for getting sentry.io to show violations in Evergreen.

Isn't this potentially going to generate a log of logspam though?

Also, I don't see that (at least on current Jenkins master branch) that Run.getLogFile is deprecated, which makes it feel very odd to me that we're deprecated its override in WorkflowJob

Isn't this potentially going to generate a log of logspam though?

Potentially. Note that the log call code was already there—not touched by this PR.

I don't see that (at least on current Jenkins master branch) that Run.getLogFile is deprecated

Yup, on my to-do list.

Why? While it may be satisfying to simple signal "stop using this API" by making it log a warning every time, for a user this looks like the Workflow Job plugin was broken by the update that added the logging - we've seen this before with "cosmetic" log warnings. Just not great optics or user experience.

Being able to point to deprecation of the extension point in core and an appropriate waiting period gives us more of a leg to stand on here.

so what do I call instead?
I'm making changes to the build-failure-analyzer plugin, and saw my logs being spammed here.
but there's no javadoc explaining what the replacement / another solution is?

It does look removeable as a whole potentially as all it does is get a file name off it but not sure the full implications

https://github.com/hmcts/build-failure-analyzer-plugin/blob/6176af08f11355b427a1db1a1c44c66dafe3de02/src/main/java/com/sonyericsson/jenkins/plugins/bfa/model/BuildLogFailureReader.java#L66

@timja Any log-related methods other than getLogFile. getLogText is the basic one. In your case I would suggest simply

-String currentFile = build.getLogFile().getName(); +String currentFile = "log";

Will give it a go later on thanks 👍

I don't see that (at least on current Jenkins master branch) that Run.getLogFile is deprecated

jenkinsci/jenkins#3963

Co-Authored-By: jglick <jglick@cloudbees.com>

dwnusbaum · 2018-11-08T20:52:55Z

The only other thing that came to mind while looking at this is that using the same file for non-FileLogStorage implementations seems like it could lead to strange bugs in the face of concurrent calls to getLogFile because the file could be overwritten while another thread is reading from it, but I couldn't really think of any better way to handle that.

svanoort · 2018-11-08T20:59:29Z

src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java

+        } else {
+            // Some other storage. Cache under the traditional name, but load from the defined source on each call.
+            try {
+                f.deleteOnExit();


Hey, isn't f potentially the original log file, not a "deprecated" temp file that we're copying to/from?

Which means we'd... delete the build log on exit? Unless there's something I missed here?

That would be the FileLogStorage branch. I.e., what is run if you do not have the CloudWatch Logs plugin installed.

Yeah, but in that case... isn't that the actual build log?

Gotta say it: we really, really, really should have a testcase covering these scenarios. Relying on code review alone to catch issues here is not a longterm path for success.

In the case of FileLogStorage, yes that is the actual build log, as it would be for freestyle builds.

🐛 So we're marking for Jenkins to... delete our build's actual logfile on exit. 🐛

Ah, except... due to magic the legacy logs magically have become a FileLogStorage due to the other weirdness of the LogStorage.of call. Which raises the question: what is this code addressing?

Unless some plugin adds an alternative, FileLogStorage is in use. It does not matter if this build predates JEP-210.

svanoort · 2018-11-08T21:26:33Z

src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java

-            try (OutputStream os = new FileOutputStream(f)) {
-                getLogText().writeRawLogTo(0, os);
+        File f = super.getLogFile();
+        if (LogStorage.of(asFlowExecutionOwner()) instanceof FileLogStorage) {


Is there a more direct way to accomplish this, by any chance? It seems like it's going to carry a fair bit of logic along with that invocation, i.e. some extra risk -- and IIUC won't https://github.com/jenkinsci/workflow-api-plugin/blob/master/src/main/java/org/jenkinsci/plugins/workflow/log/LogStorage.java#L127 result in it returning a FileLogStorage even if there's no index file associated (i.e. non-rewrite builds)?

Note that this might be an escape hatch for us.

returning a FileLogStorage even if there's no index file associated

Yup, and that is right. If there is no index file, log can still be read for the whole-log build. You will not get annotations about which lines came from particular steps, that is all.

I'll put it this way: that feels like an extremely surprising outcome for someone interacting with that API.

You should not be interacting with this API at all—it is deprecated—but if you do, it behaves exactly as it did before, and continues to do for freestyle builds: gives you a File containing the complete raw text (i.e., including encoded ConsoleNotes) of the build log.

I mean specifically the LogStorage.of API - agree that in an ideal world nobody would be trying to work with the file directly (although I bet it's still happening anyway)

svanoort

This really, really feels like it's missing testcases to cover both post logging-rewrite logfile and pre-rewrite logfile handling -- specifically making sure they don't get duplicated or removed on shutdown.

jglick · 2018-11-08T21:42:30Z

concurrent calls to getLogFile

Yes, but the alternative would be the absence of this PR and a separate file per call, which is much worse than any such issue.

If you are a nondefault log storage, you really want to treat all calls to getLogFile as bugs and have them fixed, so any implementation is a best effort.

svanoort · 2018-11-08T23:00:59Z

src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java

+        if (LogStorage.of(asFlowExecutionOwner()) instanceof FileLogStorage) {
+            // FileLogStorage does write a file with the same name and the same format as before JEP-210, so accept it if it is there.
+        } else {
+            // Some other storage. Cache under the traditional name, but load from the defined source on each call.


Question for @jglick - can you please enumerate in code comments which of these cases are meant to handle:

Traditional log storage on-master

The new log-rewrite log storage on-master

Cloud storage on-master

And I feel like we may actually be making a mistake by handing responsibility for those to the WorkflowJob or indeed the Job - it feels like the LogStorage itself ought to take ownership for these (including tests for each case).

can you please enumerate in code comments which of these cases are meant to handle

I already did, but I can try to reword the comments.

Traditional log storage on-master

The new log-rewrite log storage on-master

There is no difference between these two so far as the log file is concerned.

3. Cloud storage on-master

There is no such thing.

the LogStorage itself ought to take ownership for these

No. LogStorage handles writes to, and read from, logs wherever they may be stored, and defines the API for making that pluggable. Legacy code which presumes that the log is a file on the master has to be accommodated somehow, for compatibility.

There is no such thing.

Heh, typing fast, but you know what I meant. :)

No. LogStorage handles writes to, and read from, logs wherever they may be stored, and defines the API for making that pluggable

Per this: https://github.com/jenkinsci/jep/blob/master/jep/207/README.adoc#run-api-compatibility isn't the LogStorage method File toLogFile() supposed to be able to handle all of this?

What, concretely, is the else case addressing here? IIUC unless a key part was left un-implemented we might be able to remove most of this logic.

And if there is a concrete case that we know the 'else' branch is covering, where is its testcase?

JEP-207 is only implemented in an experimental branch and I did not propose that API.

The else case will be active when you run the pipeline-log-fluentd-cloudwatch plugin.

…eam: it should not strip console notes.

stale

dwnusbaum · 2018-11-09T14:33:41Z

src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java

        // Inefficient but probably rarely used anyway.
        ByteArrayOutputStream baos = new ByteArrayOutputStream();
-        writeLogTo(getLogText()::writeLogTo, baos);
+        writeLogTo(getLogText()::writeRawLogTo, baos);


Yikes, caused by my changes in #114. Good catch!

.

stale

svanoort

This is much cleaner and feels safer & more maintainable. I'm not going to quibble more about the deprecation exceptions for now (we'll see how often those come).

jglick · 2018-11-09T18:58:24Z

the deprecation exceptions

I am certainly open to changes in logging, but this is really a separate topic. Ideally I would like to have something in Jenkins consolidate similar warnings—like a custom log handler in Winstone?

More efficient implementation of getLogFile that just uses the existi…

58399b8

…ng file when possible.

jglick requested review from dwnusbaum and svanoort November 8, 2018 03:11

dwnusbaum approved these changes Nov 8, 2018

View reviewed changes

Use writeLogTo helper method.

660583a

Co-Authored-By: jglick <jglick@cloudbees.com>

svanoort reviewed Nov 8, 2018

View reviewed changes

svanoort previously requested changes Nov 8, 2018

View reviewed changes

svanoort reviewed Nov 8, 2018

View reviewed changes

jglick added 3 commits November 8, 2018 18:34

Merge branch 'master' into JENKINS-54128

f8f429f

Test for getLogFile which incidentally caught a bug in getLogInputStr…

ba8691d

…eam: it should not strip console notes.

For the copy-from-cloud case, clearer to use a nontraditional filename.

4a4256b

jglick requested a review from svanoort November 8, 2018 23:58

dwnusbaum previously approved these changes Nov 9, 2018

View reviewed changes

jglick mentioned this pull request Nov 9, 2018

[JENKINS-54128] Define an SPI in LogStorage to satisfy WorkflowRun.getLogFile jenkinsci/workflow-api-plugin#82

Merged

Implementing LogStorage.getLogFile from jenkinsci/workflow-api-plugin#82

6293f9b

.

jglick requested a review from dwnusbaum November 9, 2018 18:48

svanoort approved these changes Nov 9, 2018

View reviewed changes

dwnusbaum approved these changes Nov 9, 2018

View reviewed changes

dwnusbaum merged commit 779112f into jenkinsci:master Nov 9, 2018

jglick deleted the JENKINS-54128 branch November 9, 2018 20:04

Uh oh!

[JENKINS-54128] More efficient implementation of getLogFile that just uses the existing file when possible #118

[JENKINS-54128] More efficient implementation of getLogFile that just uses the existing file when possible #118

Uh oh!

Conversation

jglick commented Nov 8, 2018

Uh oh!

dwnusbaum left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

timja Nov 23, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dwnusbaum commented Nov 8, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

svanoort Nov 8, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

svanoort left a comment

Choose a reason for hiding this comment

Uh oh!

jglick commented Nov 8, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

timja Nov 23, 2018 •

edited

Loading

dwnusbaum commented Nov 8, 2018 •

edited

Loading

svanoort Nov 8, 2018 •

edited

Loading