[JIRA] (JENKINS-41243) Randomly missing TagAction(SYNTHETIC

Randomly missing TagAction(SYNTHETIC_STAGE)

Issue Type:	Bug
Assignee:	Andrew Bayer
Components:	pipeline-model-definition-plugin
Created:	2017/Jan/20 7:01 AM
Environment:	0.8.1 version
Priority:	Major
Reporter:	Vivek Pandey

While running this pipeline: https://github.com/i386/app-store-demo and polling FlowNodes from current heads, "Declarative: Checkout SCM" stage has missing SYNTHETIC_STAGE TagAction.

BlueOcean hides any stage that has SYNTHETIC_STAGE TagAction present, due to this issue synthetic stage such as "Declarative: Checkout SCM" starts appearing in the node graph.

This message was sent by Atlassian JIRA (v7.1.7#71011-sha1:2526d7c)

andrew.bayer@gmail.com (JIRA)

unread,

Jan 20, 2017, 11:33:02 AM1/20/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

Do you mean on some runs the synthetic marker isn't there but on others it is, or during some runs, sometimes the marker is there but sometimes in the same run it isn't?

andrew.bayer@gmail.com (JIRA)

unread,

Jan 20, 2017, 2:32:01 PM1/20/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

Upon further investigation, it appears that FlowNode was changed in late 2016 to no longer automatically persist/save when addAction(...) was called. So what seems to be happening is that the addAction call isn't persisting until the stage actually completes and gets persisted/saved anyway. Now we're trying to figure out what we should be doing in this scenario.

vivek.pandey@gmail.com (JIRA)

unread,

Jan 20, 2017, 5:00:02 PM1/20/17

to jenkinsc...@googlegroups.com

Vivek Pandey commented on

https://gist.github.com/vivek/cf66ab4a6a135bf7115ecb0f388e25e2

Sam Van Oort Andrew Bayer Here is the logs you requested. I am printing StatusAndTiming.printNodes(run, true, true), that is with timing info and actions when chunk.getFirstNode().getDisplayName().equals("Declarative: Checkout SCM") is true.

Line 2 is printed when no TagsAction is found for "Declarative: Checkout SCM" stage
#Line 23 is printed in later scan of flow nodes when no TagsAction is found for "Declarative: Checkout SCM" stage
[Line 64] Shows declarative plugin adding TagsAction. and then Line 66 shows BO printing in its next scan the TagsAction key/value.

As you can see according to log, 1 and 2 happened before TagsAction was added later than declarative checkout stage.

andrew.bayer@gmail.com (JIRA)

unread,

Jan 20, 2017, 5:12:01 PM1/20/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

So I guess you are scanning the nodes during that very very brief time between the creation of the FlowNode for the stage and the TagsAction getting attached. I don't know if there's any way to prevent there being that less-than-a-second gap.

jglick@cloudbees.com (JIRA)

unread,

Jan 20, 2017, 6:04:01 PM1/20/17

to jenkinsc...@googlegroups.com

Jesse Glick commented on

I don't know if there's any way to prevent there being that less-than-a-second gap.

The only way is to use an asynchronous listener, so that event delivery is delayed until after the CPS VM runs a chunk, which would include the StepExecution.start that typically attaches actions before passing off control.

andrew.bayer@gmail.com (JIRA)

unread,

Jan 20, 2017, 6:46:01 PM1/20/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

Jesse Glick - there'd still be some gap, right? Would that really be much less of a gap than what we have now, where the tagging is the first thing to be called inside the stage block?

svanoort@cloudbees.com (JIRA)

unread,

Jan 20, 2017, 6:57:01 PM1/20/17

to jenkinsc...@googlegroups.com

Sam Van Oort commented on

This should only happen when the stage step is the current head, right?

Could we do a workaround to not render the stage until we have a step in it (or the stage has completed if empty)?

andrew.bayer@gmail.com (JIRA)

unread,

Jan 20, 2017, 7:19:01 PM1/20/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

We could also provide the possible names for stages that could get marked as synthetic - then if it's one of those, you'd wait 'til it had a tag before rendering?

fwiw, just did some tests to see how much of a time difference the current approach vs GraphListener approach would be. Comparing from the time right before the stage call until the TagsAction is about to actually be attached, with 5 runs of each approach, we get an average of 40.8ms for the current approach to 15.4ms for the GraphListener approach. I gotta think that even if we cut down to that 15.4ms average, we'd still see Blue Ocean sometimes hitting this.

andrew.bayer@gmail.com (JIRA)

unread,

Jan 20, 2017, 7:25:02 PM1/20/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

I've put up a PR of the first draft of the GraphListener approach at https://github.com/jenkinsci/pipeline-model-definition-plugin/pull/97. I'm fairly sure it's deeply flawed, but what the hell.

mneale@cloudbees.com (JIRA)

unread,

Jan 23, 2017, 4:50:01 PM1/23/17

to jenkinsc...@googlegroups.com

Michael Neale commented on

Andrew Bayer sounds like vivek tried it out and it worked much better for him (FWIW)

andrew.bayer@gmail.com (JIRA)

unread,

Jan 23, 2017, 5:00:01 PM1/23/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

Ok. That still leaves the open question of how to ensure it gets reattached in a resumed Pipeline run...

andrew.bayer@gmail.com (JIRA)

unread,

Jan 24, 2017, 3:33:02 PM1/24/17

to jenkinsc...@googlegroups.com

Andrew Bayer updated

Jenkins /

Randomly missing TagAction(SYNTHETIC_STAGE)

Change By:	Andrew Bayer
Status:	In Progress Review

andrew.bayer@gmail.com (JIRA)

unread,

Jan 24, 2017, 3:33:02 PM1/24/17

to jenkinsc...@googlegroups.com

Andrew Bayer started work on

Change By:	Andrew Bayer
Status:	Open In Progress

andrew.bayer@gmail.com (JIRA)

unread,

Jan 24, 2017, 5:07:01 PM1/24/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

Blergh. Still stuck on the attaching-on-resume problem - I thought maybe FlowNodeAction.onLoad would be helpful, but it isn't. The only thing I can find that triggers on a resume is StepExecution.onResume, but I'm not actually running this in a Step so I'm...stymied.

andrew.bayer@gmail.com (JIRA)

unread,

Jan 24, 2017, 5:20:02 PM1/24/17

to jenkinsc...@googlegroups.com

Andrew Bayer commented on

Ah-ha - I switched to a RunAction2 and I seem to be good to go.

scm_issue_link@java.net (JIRA)

unread,

Jan 25, 2017, 1:39:07 PM1/25/17

to jenkinsc...@googlegroups.com

SCM/JIRA link daemon commented on

Code changed in jenkins
User: Andrew Bayer
Path:
pipeline-model-definition/src/main/groovy/org/jenkinsci/plugins/pipeline/modeldefinition/SyntheticStageNames.groovy
pipeline-model-definition/src/main/groovy/org/jenkinsci/plugins/pipeline/modeldefinition/Utils.groovy
pipeline-model-definition/src/main/java/org/jenkinsci/plugins/pipeline/modeldefinition/SyntheticStageGraphListener.java
pipeline-model-definition/src/main/resources/org/jenkinsci/plugins/pipeline/modeldefinition/ModelInterpreter.groovy
pipeline-model-definition/src/main/resources/org/jenkinsci/plugins/pipeline/modeldefinition/agent/impl/DockerPipelineFromDockerfileScript.groovy
pipeline-model-definition/src/main/resources/org/jenkinsci/plugins/pipeline/modeldefinition/agent/impl/DockerPipelineScript.groovy
pipeline-model-definition/src/main/resources/org/jenkinsci/plugins/pipeline/modeldefinition/agent/impl/LabelScript.groovy
http://jenkins-ci.org/commit/pipeline-model-definition-plugin/c24cef8c9e4a4686ee604d03d3b0400eabc375aa
Log:
~~JENKINS-41243~~ Slightly faster tagging of synthetic stages

This approach yielded an average time from just before the stage call
to just before actually attaching the tag of 15.4ms over 5 runs, vs
40.8ms over 5 runs with the previous approach. I'm sure there are many
things wrong with this approach, though.

scm_issue_link@java.net (JIRA)

unread,

Jan 25, 2017, 1:39:08 PM1/25/17

to jenkinsc...@googlegroups.com

SCM/JIRA link daemon commented on