[JENKINS-30088] Clean up step display in logs #215

amuniz · 2015-09-28T19:18:19Z

JENKINS-30088
Note that the first point described in the JIRA issue is fixed in #211 which is more focused on the Snippet Generator clean up.

A screenshot showing how the logs are printed given the following script:

node {
  echo 'Starting!'
  stage 'Checkout'
  git 'https://github.com/amuniz/maven-helloworld.git'
  stage 'Building'
  sh 'uname -a'
  ws('other-ws') {
    echo 'This is another workspace'
  }
  stage 'Release'
  echo 'Releasing...'
}

I'm not an UX expert, so any comment on how metadata log lines and the rest of the build log could live better together will be welcome!

@reviewbybees

ghost · 2015-09-28T19:19:03Z

This pull request originates from a CloudBees employee. At CloudBees, we require that all pull requests be reviewed by other CloudBees employees before we seek to have the change accepted. If you want to learn more about our process please see this explanation.

oleg-nenashev · 2015-09-28T19:44:26Z

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

@@ -656,7 +657,7 @@ public int hashCode() {
            }
            node.addAction(new TimingAction());

-            logNodeMessage(node, "Running: " + node.getDisplayName());
+            logNodeMessage(node);


Hm? Seems it deletes the "Running" text prefix. +1 from me for annotated logs, but I'm not sure how good it will appear in plain text

Yeah, I see the "Running:" prefix at the beginning of each metadata line as a way to easily identify metadata logs, but it is redundant now since we have the "[Workflow]" prefix, and it is quite obvious that a step is "Running" when you see something like [Workflow] node { or [Workflow] echo.

The plain text version would be something like this (where is still easy to identify the metadata log lines IMO):

Started by user anonymous [Workflow] Allocate node : Start Running on master in /home/amuniz/workspace-cloudbees/workflow-plugin/aggregator/work/jobs/test/workspace [Workflow] node { [Workflow] echo Hi! [Workflow] git > git rev-parse --is-inside-work-tree # timeout=10 Fetching changes from the remote Git repository > git config remote.origin.url https://github.com/amuniz/maven-helloworld.git # timeout=10 Fetching upstream changes from https://github.com/amuniz/maven-helloworld.git > git --version # timeout=10 > git fetch --tags --progress https://github.com/amuniz/maven-helloworld.git +refs/heads/*:refs/remotes/origin/* > git rev-parse refs/remotes/origin/master^{commit} # timeout=10 > git rev-parse refs/remotes/origin/origin/master^{commit} # timeout=10 Checking out Revision 197d621fea6a797cbb4a158df573580a83fd8b4f (refs/remotes/origin/master) > git config core.sparsecheckout # timeout=10 > git checkout -f 197d621fea6a797cbb4a158df573580a83fd8b4f > git rev-list 197d621fea6a797cbb4a158df573580a83fd8b4f # timeout=10 [Workflow] stage: After Git Clone Entering stage After Git Clone Proceeding [Workflow] echo Bye! [Workflow] sh [workspace] Running shell script mvn clean install [INFO] Scanning for projects... [INFO] [INFO] ------------------------------------------------------------------------ [INFO] Building example 1.0-SNAPSHOT [INFO] ------------------------------------------------------------------------ [INFO] [INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ example --- ...

Yes, it's much better

Looks great ... a lot less noise.

recena · 2015-09-28T20:05:25Z

@amuniz Have you considered something like that?

[Workflow::node]
[Workflow::echo] 
[Workflow::sh]

amuniz · 2015-09-29T08:08:05Z

@recena I followed the proposal described in JENKINS-30088. I personally like the current format, since there is a fixed length prefix that allows to easily identify metadata related log lines.

jtnord · 2015-09-30T20:36:49Z

disclaimer: I have not read the dull PR just skimmed though a few comments and the unit tests.

So a big thing is that the logs are cluttered and contain redundant (to me) information and miss some vital information.

[Workflow] Allocate node : Start
Running on master in /home/amuniz/workspace-cloudbees/workflow-plugin/aggregator/work/jobs/test/workspace
[Workflow] node {

So if you have node { you do not need [Workflow] Allocate node : Start you only need one (clutter)

[Workflow] Retry the body up to N times : Start",
[Workflow] retry {
/// some more logs
[Workflow] } //retry
[Workflow] retry {
/// some more logs
[Workflow] } //retry
[Workflow] retry {
/// some more logs
[Workflow] } //retry

retry { is not really valid syntax for the inner loop. It is missing the important information which is Which loop is this - the first or the 12th or the 100th? How many tries are remaining? (incorrect information and missing information)

amuniz · 2015-09-30T22:13:45Z

So if you have node { you do not need [Workflow] Allocate node : Start you only need one (clutter)

Both log lines were there before, I just replaced Allocate node : Start : Body with node {. If we want to remove the first message, it's ok for me, but it's not what was defined in the JIRA issue.

retry { is not really valid syntax for the inner loop.

Right. This a general log representation where every node with an execution body is represented as node_name { and } // node_name. It's not intended to be syntactically correct but useful when reading logs.

Which loop is this - the first or the 12th or the 100th?

Then the logging inside RetryStepExecution must be improved. The retry counter is not visible outside the execution class (and it shouldn't be), where this metadata logs are managed.

jtnord · 2015-09-30T23:05:11Z

So i think then i am saying the jira is off the mark.

To focus on the dsl the cruft should be removed so you have dsly stuff, stuff that is important in the context of the step and the outputs if any of the step. If you leave the clutter in then the dslish does not have as much use. If you use the dsl when it is not the dsl (retry loops) then this makes thing far worse for understandability.

tfennelly · 2015-10-01T08:14:06Z

cps/src/main/java/org/jenkinsci/plugins/workflow/cps/nodes/StepEndNode.java

+        StepDescriptor d = getDescriptor();
+        boolean isBody = getStartNode().isBody();
+        if (isBody) {
+            return "} //" + (d != null ? d.getFunctionName() : getStartNode().getStepName());


Is there an opening curly brace somewhere else?

Ah, I see it below ... ignore :)

tfennelly · 2015-10-01T08:29:18Z

🐝 insofar as I get it .... kinda skimmed through it.

tfennelly · 2015-10-01T08:40:17Z

🐝

jglick · 2015-10-02T16:04:38Z

If we want to remove the first message

I think we do, if possible, but at least for the case of retry this probably needs to wait for a fix of JENKINS-26156.

jglick · 2015-10-05T21:25:03Z

api/src/main/java/org/jenkinsci/plugins/workflow/graph/FlowNode.java

@@ -163,6 +177,19 @@ public BallColor getIconColor() {
    protected abstract String getTypeDisplayName();

    /**
+     * Gets the function name for this type of node.
+     *
+     * Note that this method should be abstract (suppossed to be implemented in all subclasses), but keeping 


jglick · 2015-10-05T21:40:02Z

Minor comments but 🐝 if you want to stop here.

As noted earlier, we can improve the display of block steps later.

jglick · 2015-10-05T21:40:26Z

BTW please include a note in CHANGES.md.

amuniz · 2015-10-06T09:29:07Z

@jglick I fixed some things. I can improve the use console note CSS later (and once I know how).

tfennelly · 2015-10-06T10:08:33Z

🐝 go for it @amuniz

amuniz · 2015-10-06T17:04:39Z

@reviewbybees done

ghost · 2015-10-07T10:05:43Z

This pull request has completed our internal processes and we now respectfully request the maintainers of this repository to consider our proposal contained within this pull request for merging.

jglick · 2015-10-07T16:33:36Z

api/src/main/java/org/jenkinsci/plugins/workflow/graph/FlowNode.java

+     * @return the text human-readable representation of the step function name
+     *      or {@link FlowNode#getDisplayName()} by default (if not overriden in subclasses)
+     */
+    protected /* abstract */ String getTypeFunctionName() {


Still seems like a poor name choice, since it is only a function name in the case of StepAtomNodes.

[JENKINS-30088] Clean up step display in logs

amuniz added 2 commits September 28, 2015 20:54

[JENKINS-30088] Use the function name instead of the display name

577f2ac

[JENKINS-30088] Annotate workflow metadata logs

7e2c3a0

oleg-nenashev reviewed Sep 28, 2015
View reviewed changes

Fix broken test (relying on console output)

df501b6

tfennelly reviewed Oct 1, 2015
View reviewed changes

Move strings constants to static fields (as @tfennelly suggested)

039c652

amuniz closed this Oct 4, 2015

amuniz reopened this Oct 4, 2015

jglick reviewed Oct 5, 2015
View reviewed changes

[JENKINS-30088] Improve javadoc and use getDisplayName() as default

dcaf836

jglick reviewed Oct 7, 2015
View reviewed changes

jglick added a commit that referenced this pull request Oct 7, 2015

Merge pull request #215 from amuniz/JENKINS-30088

9ae86c4

[JENKINS-30088] Clean up step display in logs

jglick merged commit 9ae86c4 into jenkinsci:master Oct 7, 2015

amuniz deleted the JENKINS-30088 branch October 15, 2015 09:13

jglick mentioned this pull request Apr 8, 2016

[JENKINS-26156] BodyInvoker.displayName was broken jenkinsci/workflow-cps-plugin#3

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[JENKINS-30088] Clean up step display in logs #215

[JENKINS-30088] Clean up step display in logs #215

amuniz commented Sep 28, 2015

ghost commented Sep 28, 2015

oleg-nenashev Sep 28, 2015

amuniz Sep 29, 2015

oleg-nenashev Oct 1, 2015

tfennelly Oct 1, 2015

recena commented Sep 28, 2015

amuniz commented Sep 29, 2015

jtnord commented Sep 30, 2015

amuniz commented Sep 30, 2015

jtnord commented Sep 30, 2015

tfennelly Oct 1, 2015

tfennelly Oct 1, 2015

tfennelly commented Oct 1, 2015

tfennelly commented Oct 1, 2015

jglick commented Oct 2, 2015

jglick Oct 5, 2015

jglick commented Oct 5, 2015

jglick commented Oct 5, 2015

amuniz commented Oct 6, 2015

tfennelly commented Oct 6, 2015

amuniz commented Oct 6, 2015

ghost commented Oct 7, 2015

jglick Oct 7, 2015

[JENKINS-30088] Clean up step display in logs #215

[JENKINS-30088] Clean up step display in logs #215

Conversation

amuniz commented Sep 28, 2015

ghost commented Sep 28, 2015

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

recena commented Sep 28, 2015

amuniz commented Sep 29, 2015

jtnord commented Sep 30, 2015

amuniz commented Sep 30, 2015

jtnord commented Sep 30, 2015

Choose a reason for hiding this comment

Choose a reason for hiding this comment

tfennelly commented Oct 1, 2015

tfennelly commented Oct 1, 2015

jglick commented Oct 2, 2015

Choose a reason for hiding this comment

jglick commented Oct 5, 2015

jglick commented Oct 5, 2015

amuniz commented Oct 6, 2015

tfennelly commented Oct 6, 2015

amuniz commented Oct 6, 2015

ghost commented Oct 7, 2015

Choose a reason for hiding this comment