Bug 1554902

Are you using slaves? It can take time for the slaves images to pull and start before your pipeline will run.

What are you considering the "start" of the pipeline?

Yep, Ben's question could be on point wrt what is going on here.

In addition to answering that, please get the customer to provide:

a) the pipeline script used

b) the jenkins pod logs

c) the console logs for one of the runs where the delay was observed

OK, the data provided helped progress things a bit but was not precisely what I needed.  It did make me realize we need some more.

In addition to what was provided before

1) The blue ocean pipeline view is not sufficient, we need the console logs ... i.e. if he clicked "View logs" from that blue ocean view he provided

2) Lets get the openshift  build yaml ... i.e oc get build <build name> -o yaml
since he is starting the build from the jenkins console, we can try to gauge the time spent between the build getting created (i.e. when he hits start build from the console, and when the job gets started (which we'll see in the jenkins logs)

3) run oc get events -o yaml in the build namespace after everything is done ... we'll see if something is amiss on the openshift side 

4) we need the actual Jenkinsfile contents ... they are not embedded in the BC ... the BC references the Jenkinsfile from the git repo

One *POSSIBLE* cause, though I am not ready to declare that yet, is this exception that occurs while executing steps in the Jenkinsfile:

WARNING: Failed to resolve token macros
org.jenkinsci.plugins.tokenmacro.MacroEvaluationException: Unrecognized macro 'TEST_COUNTS' in '${TEST_COUNTS,var="pass"}'
	at org.jenkinsci.plugins.tokenmacro.Parser.processToken(Parser.java:326)
	at org.jenkinsci.plugins.tokenmacro.Action$KiHW1UeqOdqAwZul.run(Unknown Source)
	at org.parboiled.matchers.ActionMatcher.match(ActionMatcher.java:96)
	at org.parboiled.parserunners.BasicParseRunner.match(BasicParseRunner.java:77)
	at org.parboiled.MatcherContext.runMatcher(MatcherContext.java:351)
	at org.parboiled.matchers.SequenceMatcher.match(SequenceMatcher.java:46)
	at org.parboiled.parserunners.BasicParseRunner.match(BasicParseRunner.java:77)
	at org.parboiled.MatcherContext.runMatcher(MatcherContext.java:351)
	at org.parboiled.matchers.FirstOfMatcher.match(FirstOfMatcher.java:41)
	at org.parboiled.parserunners.BasicParseRunner.match(BasicParseRunner.java:77)
	at org.parboiled.MatcherContext.runMatcher(MatcherContext.java:351)
	at org.parboiled.matchers.FirstOfMatcher.match(FirstOfMatcher.java:41)
	at org.parboiled.parserunners.BasicParseRunner.match(BasicParseRunner.java:77)
	at org.parboiled.MatcherContext.runMatcher(MatcherContext.java:351)
	at org.parboiled.matchers.ZeroOrMoreMatcher.match(ZeroOrMoreMatcher.java:39)
	at org.parboiled.parserunners.BasicParseRunner.match(BasicParseRunner.java:77)
	at org.parboiled.MatcherContext.runMatcher(MatcherContext.java:351)
	at org.parboiled.matchers.SequenceMatcher.match(SequenceMatcher.java:46)
	at org.parboiled.parserunners.BasicParseRunner.match(BasicParseRunner.java:77)
	at org.parboiled.MatcherContext.runMatcher(MatcherContext.java:351)
	at org.parboiled.parserunners.BasicParseRunner.run(BasicParseRunner.java:72)
	at org.parboiled.parserunners.ReportingParseRunner.runBasicMatch(ReportingParseRunner.java:86)
	at org.parboiled.parserunners.ReportingParseRunner.run(ReportingParseRunner.java:66)
	at org.parboiled.parserunners.AbstractParseRunner.run(AbstractParseRunner.java:81)
	at org.parboiled.parserunners.AbstractParseRunner.run(AbstractParseRunner.java:76)
	at org.jenkinsci.plugins.tokenmacro.Parser.process(Parser.java:68)
	at org.jenkinsci.plugins.tokenmacro.TokenMacro.expand(TokenMacro.java:204)
	at org.jenkinsci.plugins.tokenmacro.TokenMacro.expand(TokenMacro.java:200)
	at jenkins.plugins.hipchat.impl.DefaultCardProvider.getAttributes(DefaultCardProvider.java:60)
	at jenkins.plugins.hipchat.impl.DefaultCardProvider.getCard(DefaultCardProvider.java:37)
	at jenkins.plugins.hipchat.workflow.HipChatSendStep$HipChatSendStepExecution.run(HipChatSendStep.java:192)
	at jenkins.plugins.hipchat.workflow.HipChatSendStep$HipChatSendStepExecution.run(HipChatSendStep.java:115)
	at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1$1.call(AbstractSynchronousNonBlockingStepExecution.java:47)
	at hudson.security.ACL.impersonate(ACL.java:260)
	at org.jenkinsci.plugins.workflow.steps.AbstractSynchronousNonBlockingStepExecution$1.run(AbstractSynchronousNonBlockingStepExecution.java:44)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)


Unclear to date whether it has any bearing.  Hopefully the other information will clear that up.

OK the build yaml i.e. my item 2 from the #Comment 8 would be the final piece here.

Also, let's confirm the they are using v3.7 of the openshift jenkins image.

Getting more and more convinced though that watches are becoming less and less of a reliable notification mechanism here, and we essentially have the same thing as https://github.com/openshift/jenkins-sync-plugin/issues/209

verified in brew-pulp-xxxxxx/openshift3/jenkins-2-rhel7 v3.10(v3.10.0.20180406.113022) 838c3e9ab0d9  with sync plugin:v1.0.10

steps:
1. Create jenkins resource with pipeline build 
 $oc new-app -f https://raw.githubusercontent.com/openshift/origin/master/examples/jenkins/pipeline/samplepipeline.yaml

2. Start a pipeline build and wait complete 
 $oc start-build sample-pipeline

3. Log in to jenkins, got to manage jenkins -> configure system, change the 	Build list interval to 400

4. go into pods to check value buildListInterval is 400
      $ oc rsh jenkins-1-nncsv
sh-4.2$ cd /var/lib/jenkins
sh-4.2$ more io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration.xml
<?xml version='1.1' encoding='UTF-8'?>
<io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration plugin="openshift-sync.10">
  <enabled>true</enabled>
  <server></server>
  <namespaces>
    <string>wewang</string>
  </namespaces>
  <jobNamePattern></jobNamePattern>
  <skipOrganizationPrefix></skipOrganizationPrefix>
  <skipBranchSuffix></skipBranchSuffix>
  <buildListInterval>400</buildListInterval>
  <buildConfigListInterval>300</buildConfigListInterval>
  <secretListInterval>300</secretListInterval>
  <configMapListInterval>300</configMapListInterval>
  <imageStreamListInterval>300</imageStreamListInterval>
</io.fabric8.jenkins.openshiftsync.GlobalPluginConfiguration>

5)Manage Jenkins -> System Log, and then click "add new log recorder".  type logwatch name, the click "add" and in the logger field, type in "io.fabric8.jenkins.openshiftsync.BuildWatcher" and click save.

6. Start a pipeline build
   $oc start-build sample-pipeline

7. Check the BuildWatcher and see build resources list at an internal
Apr 08, 2018 8:16:37 AM FINE io.fabric8.jenkins.openshiftsync.BuildWatcher
listing Build resources
Apr 08, 2018 8:16:37 AM FINE io.fabric8.jenkins.openshiftsync.BuildWatcher
handled Build resources
Apr 08, 2018 8:16:37 AM INFO io.fabric8.jenkins.openshiftsync.BuildWatcher reconcileRunsAndBuilds
Reconciling job runs and builds
Apr 08, 2018 8:16:37 AM INFO io.fabric8.jenkins.openshiftsync.BuildWatcher reconcileRunsAndBuilds
Checking runs for BuildConfig wewang/sample-pipeline

more logs about step7
you can see  the listed  resources in every 400s(8:23:17-8:16:37=400s)


Apr 08, 2018 8:16:37 AM FINE io.fabric8.jenkins.openshiftsync.BuildWatcher
listing Build resources
Apr 08, 2018 8:16:37 AM FINE io.fabric8.jenkins.openshiftsync.BuildWatcher
handled Build resources
Apr 08, 2018 8:16:37 AM INFO io.fabric8.jenkins.openshiftsync.BuildWatcher reconcileRunsAndBuilds
Reconciling job runs and builds
Apr 08, 2018 8:16:37 AM INFO io.fabric8.jenkins.openshiftsync.BuildWatcher reconcileRunsAndBuilds
Checking runs for BuildConfig wewang/sample-pipeline
Apr 08, 2018 8:23:17 AM FINE io.fabric8.jenkins.openshiftsync.BuildWatcher
listing Build resources
Apr 08, 2018 8:23:17 AM FINE io.fabric8.jenkins.openshiftsync.BuildWatcher
handled Build resources
Apr 08, 2018 8:23:17 AM INFO io.fabric8.jenkins.openshiftsync.BuildWatcher reconcileRunsAndBuilds
Reconciling job runs and builds
Apr 08, 2018 8:23:17 AM INFO io.fabric8.jenkins.openshiftsync.BuildWatcher reconcileRunsAndBuilds
Checking runs for BuildConfig wewang/sample-pipeline

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2018:1816