Skip to content

Write NewNodeConsoleNote to per-step logs instead of overall log #371

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

Closed
dwnusbaum wants to merge 2 commits into from
Closed

Write NewNodeConsoleNote to per-step logs instead of overall log #371

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
0465193
Write NewNodeConsoleNote to step logs instead of overall log
dwnusbaum Jul 18, 2023
8c8ef8c
Restore show/hide functionality in classic console view
dwnusbaum Jul 25, 2023
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
1 change: 1 addition & 0 deletions pom.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,7 @@
<dependency>
<groupId>org.jenkins-ci.plugins.workflow</groupId>
<artifactId>workflow-api</artifactId>
<version>1236.vb_763772ecd87</version> <!-- TODO: https://github.com/jenkinsci/workflow-api-plugin/pull/296 -->
</dependency>
<dependency>
<groupId>org.jenkins-ci.plugins.workflow</groupId>
Expand Down
20 changes: 19 additions & 1 deletion src/main/java/org/jenkinsci/plugins/workflow/job/WorkflowRun.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -86,6 +86,8 @@
import java.util.logging.Logger;
import edu.umd.cs.findbugs.annotations.CheckForNull;
import edu.umd.cs.findbugs.annotations.NonNull;
import java.io.Closeable;
import java.io.InterruptedIOException;
import jenkins.model.CauseOfInterruption;
import jenkins.model.Jenkins;
import jenkins.model.lazy.BuildReference;
Expand Down Expand Up @@ -1080,7 +1082,23 @@ private final class GraphL implements GraphListener {
*/
private final class NodePrintListener implements GraphListener.Synchronous {
@Override public void onNewHead(FlowNode node) {
NewNodeConsoleNote.print(node, getListener());
// TODO: Breaks show/hide links in the console because the line with the show/hide link gets hidden.
Copy link
Member Author

@dwnusbaum dwnusbaum Jul 18, 2023

Choose a reason for hiding this comment

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

Should be fixable, but I am not going to bother looking into it unless I really want to get this merged.

LogStorage storage = LogStorage.of(asFlowExecutionOwner());
try {
TaskListener listener = TaskListenerDecorator.apply(storage.nodeListener(node), asFlowExecutionOwner(), null);
try {
NewNodeConsoleNote.print(node, listener);
} finally {
if (listener instanceof Closeable) {
((Closeable) listener).close();
}
}
} catch (InterruptedIOException | InterruptedException e) {
Thread.currentThread().interrupt();
LOGGER.log(Level.FINE, e, () -> "Unable to write NewNodeConsoleNote for node " + node.getId());
} catch (IOException e) {
LOGGER.log(Level.FINE, e, () -> "Unable to write NewNodeConsoleNote for node " + node.getId());
}
}
}

Expand Down
13 changes: 9 additions & 4 deletions src/main/java/org/jenkinsci/plugins/workflow/job/console/NewNodeConsoleNote.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,7 @@
* @see LogStorage#startStep
*/
@Restricted(NoExternalUse.class)
public class NewNodeConsoleNote extends ConsoleNote<WorkflowRun> {
public class NewNodeConsoleNote extends ConsoleNote {
Copy link
Member Author

@dwnusbaum dwnusbaum Jul 18, 2023

Choose a reason for hiding this comment

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

This issue is kind of interesting. I am not sure if it has been reported previously, but any console notes that rely on a Run context totally break the per-step log view in the Pipeline steps view. (The notes aren't just skipped, they cause a ClassCastException here and break all log display!)

Perhaps LogStorage.stepLog should really return a AnnotatedLargeText<WorkflowRun> instead? Not sure if that can be changed compatibly at this point. ConsoleAnnotationOutputStream at least could probably be made more robust though.

There do not seem to be many implementations that would trigger the issue, see here and here.

Copy link
Member

@jglick jglick Jul 18, 2023

Choose a reason for hiding this comment

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

Hmm, does this have anything to do with jenkinsci/jenkins#3662?

Copy link
Member Author

@dwnusbaum dwnusbaum Jul 19, 2023 •
edited
Loading

Choose a reason for hiding this comment

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

Only tangentially I think, in that the whole API seems wrong. The problem as I see it is that when you create a ConsoleNote, you get to choose an arbitrary type parameter, but when using a ConsoleAnnotationOutputStream, the type parameter is fixed, so code like this is unsound, because the context type of an arbitrary note in the stream is not necessarily T. I think the compiler is only ok with that code because of erasure. If you replace final ConsoleNote a = ... with final ConsoleNote<?> a = ..., then you get the incompatible types: T cannot be converted to CAP#1 error that I would have expected.

Looking at actual usage, I think the context parameters in all associated classes should have just been hard-coded to be Run, and LogStorage.stepLog should have just returned AnnotatedLargeText<WorkflowRun> like overallLog. I guess KK's API design assumption was that you only write notes when you know they will be read with the same context, which doesn't work for Pipeline when we read one log file but return AnnotatedLargeText objects with different contexts.

As far as what we can do compatibly, we could at least catch ClassCastException somewhere in here (I'd have to double-check exactly where the exception gets thrown) so we just skip the note in question. I am not sure if we can get Class<?> witnesses reliably that we could use to pre-check the types instead of just catching exceptions.


private static final Logger LOGGER = Logger.getLogger(NewNodeConsoleNote.class.getName());

Expand Down Expand Up @@ -98,7 +98,7 @@ private NewNodeConsoleNote(FlowNode node) {
}

@Override
public ConsoleAnnotator<?> annotate(WorkflowRun context, MarkupText text, int charPos) {
public ConsoleAnnotator<?> annotate(Object context, MarkupText text, int charPos) {
try {
StringBuilder startTag = startTagFor(context, id, start, enclosing);
text.addMarkup(0, text.length(), startTag.toString(), "</span>");
Expand All @@ -109,15 +109,20 @@ public ConsoleAnnotator<?> annotate(WorkflowRun context, MarkupText text, int ch
}

@Restricted(NoExternalUse.class)
public static StringBuilder startTagFor(@NonNull WorkflowRun context, @NonNull String id, @CheckForNull String start, @CheckForNull String enclosing) {
public static StringBuilder startTagFor(@NonNull Object context, @NonNull String id, @CheckForNull String start, @CheckForNull String enclosing) {
StringBuilder startTag = new StringBuilder("<span class=\"pipeline-new-node\" nodeId=\"").append(id);
if (start != null) {
startTag.append("\" startId=\"").append(start);
}
if (enclosing != null) {
startTag.append("\" enclosingId=\"").append(enclosing);
}
FlowExecution execution = context.getExecution();
FlowExecution execution = null;
if (context instanceof WorkflowRun) {
execution = ((WorkflowRun) context).getExecution();
} else if (context instanceof FlowNode) {
execution = ((FlowNode) context).getExecution();
}
if (execution != null) {
try {
FlowNode node = execution.getNode(id);
Expand Down
31 changes: 24 additions & 7 deletions src/main/resources/org/jenkinsci/plugins/workflow/job/console/NewNodeConsoleNote/script.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -66,18 +66,35 @@ function showHidePipelineSection(link) {
link.textContent = 'hide'
link.parentNode.className = 'pipeline-show-hide'
}
var showHide = function(id, display) {
var showHide = function(id, display, isClickedElement) {
var sect = '.pipeline-node-' + id
var ss = document.styleSheets[0]
var foundCssRule = false;
for (var i = 0; i < ss.cssRules.length; i++) {
if (ss.cssRules[i].selectorText === sect) {
ss.cssRules[i].style.display = display
return
foundCssRule = true;
break;
}
}
if (!foundCssRule) {
ss.insertRule(sect + ' {display: ' + display + '}', ss.cssRules.length);
}
if (isClickedElement) {
// We have to move the console note with the show/hide link that got clicked outside of the section for the
// node before we hide it, otherwise the show link will be hidden.
var sectNode = document.querySelector(sect);
if (sectNode) {
var spanNode = document.querySelector('.pipeline-new-node[nodeId=\'' + id + '\']');
if (display === 'none') {
sectNode.insertAdjacentElement('beforebegin', spanNode);
} else {
sectNode.insertAdjacentElement('afterbegin', spanNode);
}
}
}
ss.insertRule(sect + ' {display: ' + display + '}', ss.cssRules.length)
}
showHide(id, display)
showHide(id, display, true);
if (span.getAttribute('startId') != null) {
// For a block node, look up other pipeline-new-node elements parented to this (transitively) and mask them and their text too.
var nodes = document.querySelectorAll('.pipeline-new-node')
Expand Down Expand Up @@ -110,14 +127,14 @@ function showHidePipelineSection(link) {
for (var i = 0; i < ids.length; i++) {
var oid = ids[i]
if (oid != id && encloses(id, oid, starts, enclosings)) {
showHide(oid, display)
var headers = document.querySelectorAll('.pipeline-new-node[nodeId=' + oid + ']');
showHide(oid, display, false);
var headers = document.querySelectorAll('.pipeline-new-node[nodeId=\'' + oid + '\']');
for (var j = 0; j < headers.length; j++) {
headers[j].style.display = display;
}
if (display === 'inline') {
// Mark all children as shown. TODO would be nicer to leave them collapsed if they were before, but this gets complicated.
var links = document.querySelectorAll('.pipeline-new-node[nodeId=' + oid + '] span a');
var links = document.querySelectorAll('.pipeline-new-node[nodeId=\'' + oid + '\'] span a');
for (var j = 0; j < links.length; j++) {
links[j].textContent = 'hide';
links[j].parentNode.className = 'pipeline-show-hide';
Expand Down
7 changes: 4 additions & 3 deletions src/test/java/org/jenkinsci/plugins/workflow/job/console/DefaultLogStorageTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -99,7 +99,7 @@ public class DefaultLogStorageTest {
assertLogContains(page, hudson.model.Messages.Cause_UserIdCause_ShortDescription(alice.getDisplayName()), alice.getUrl());
assertLogContains(page, "Running inside " + b.getDisplayName(), b.getUrl());
assertThat(page.getWebResponse().getContentAsString().replace("\r\n", "\n"),
containsString("<span class=\"pipeline-new-node\" nodeId=\"3\" enclosingId=\"2\">[Pipeline] hyperlink\n</span><span class=\"pipeline-node-3\">Running inside <a href="));
containsString("<span class=\"pipeline-node-3\"><span class=\"pipeline-new-node\" nodeId=\"3\" enclosingId=\"2\">[Pipeline] hyperlink\n</span>Running inside <a href="));
DepthFirstScanner scanner = new DepthFirstScanner();
scanner.setup(b.getExecution().getCurrentHeads());
List<FlowNode> nodes = Lists.newArrayList(scanner.filter(FlowScanningUtils.hasActionPredicate(LogAction.class)));
Expand Down Expand Up @@ -187,7 +187,8 @@ static class Execution extends SynchronousStepExecution<Void> {
assertNotNull(la);
baos = new ByteArrayOutputStream();
la.getLogText().writeRawLogTo(0, baos);
assertThat(baos.toString(), not(containsString("Pipeline")));
assertThat(baos.toString(), not(containsString("[Pipeline] Start of Pipeline")));
assertThat(baos.toString(), containsString("[Pipeline] echo"));
// Whole-build:
sw = new StringWriter();
start = System.nanoTime();
Expand Down Expand Up @@ -226,7 +227,7 @@ static class Execution extends SynchronousStepExecution<Void> {
start = System.nanoTime();
length = la.getLogText().length();
System.out.printf("Took %dms to compute length of one short node%n", (System.nanoTime() - start) / 1000 / 1000);
assertThat(length, lessThan(50L));
assertThat(length, lessThan(350L));
}

@Ignore("Currently not asserting anything, just here for interactive evaluation.")
Expand Down