Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-54081

Timestamps missing for agent-based steps in Pipeline Job 2.26

    Details

    • Similar Issues:
    • Released As:
      1.9

      Description

      After upgrading to Pipeline Job 2.26 earlier today, in the Console Log for pipeline builds, I only appear to have timestamps for the operations performed by the master node (i.e., the initial git checkout), but all remaining build steps that are performed on agent nodes lack timestamps entirely. The job properly recognizes that timestamps were enabled in the first place, so provides the typical "System clock time" vs., "Elapsed time" options on the left, but these only have an effect for the master node-occurring timestamps; timestamps for steps taking place on agent nodes are missing regardless.

        Attachments

          Issue Links

            Activity

            Hide
            framillien Florian Ramillien added a comment -

            The result is the same, yes. But I don't think the cause was the same, in our case connection with agent is working unless some specific combinaison of components:

            • A long build with a simple task (ping during 20mn) is working
            • A shorter build (10mn) with hudge log generated by "bat" step, fail (see previous comment).
            • Removing "timestamps" step from pipeline fix this issue
            • Reverting from "push" to "pull" logs in "durable-task" fix this issue too.

            In our case, something occurs at the end of the job between master and slave, and master never receive the "OK" result from slave (nor the full logs). And after 9mn of inactivity build fail and agent is disconnected. It's always reproduced with hudge logs, but maybe logs size is just a factor triggering another hidden synchro/lock problem.

            For now "USE_WATCHING=false" is set in our Jenkins master and is an acceptable solution for us.

            Show
            framillien Florian Ramillien added a comment - The result is the same, yes. But I don't think the cause was the same, in our case connection with agent is working unless some specific combinaison of components: A long build with a simple task (ping during 20mn) is working A shorter build (10mn) with hudge log generated by "bat" step, fail (see previous comment). Removing "timestamps" step from pipeline fix this issue Reverting from "push" to "pull" logs in "durable-task" fix this issue too. In our case, something occurs at the end of the job between master and slave, and master never receive the "OK" result from slave (nor the full logs). And after 9mn of inactivity build fail and agent is disconnected. It's always reproduced with hudge logs, but maybe logs size is just a factor triggering another hidden synchro/lock problem. For now "USE_WATCHING=false" is set in our Jenkins master and is an acceptable solution for us.
            Hide
            jglick Jesse Glick added a comment -

            Florian Ramillien please discuss in JENKINS-53888.

            Show
            jglick Jesse Glick added a comment - Florian Ramillien please discuss in JENKINS-53888 .
            Hide
            ljubisap Ljubisa Punosevac added a comment - - edited

            Hi, 

            Unfortunately, this problem still prevails on Jenkins ver. 2.190.1 and timestamper version 1.10.
            I tried also older versions of this plugin for which has been written here to work, but again with the same results.
            Also, the following option has been set on Jenkins master as JVM parameter, but again with the same outcome:

            -Dorg.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep.USE_WATCHING=false
            

            All our jobs are pipelines and timestamps appear only in a few places. Most of the time they are gone.

            [Pipeline] configFileProvider
            [2019-10-11T11:22:10.289Z] provisioning config files...
            [2019-10-11T11:22:10.299Z] copy managed file [live-env-configuration.properties] to file:/var/lib/jenkins/workspace/generic-test-junit@tmp/config11258587709499260226tmp
            [Pipeline] {
            [Pipeline] readProperties
            [Pipeline] }
            [2019-10-11T11:22:10.350Z] Deleting 1 temporary files
            [Pipeline] // configFileProvider
            [Pipeline] sh
            [2019-10-11T11:22:09.383Z] Creating folder: /var/lib/jenkins/.m2
            [2019-10-11T11:22:09.388Z] Creating file: /var/lib/jenkins/.m2/settings.xml
            [2019-10-11T11:22:09.395Z] Creating folder: /var/lib/jenkins/workspace/generic-test-junit/.repository
            [2019-10-11T11:22:10.683Z] `s3/ec-test-release-pipeline/191011019/pipeline.properties` -> `pipeline.properties`
            [2019-10-11T11:22:10.683Z] Total: 962 B, Transferred: 962 B, Speed: 37.11 KiB/s
            [Pipeline] script
            [Pipeline] {
            [Pipeline] readProperties
            [Pipeline] }
            [Pipeline] // script
            [Pipeline] lock
            [2019-10-11T11:22:10.789Z] Trying to acquire lock on [Label: s3, Quantity: 1]
            [2019-10-11T11:22:10.789Z] Lock acquired on [Label: s3, Quantity: 1]
            [Pipeline] {
            [Pipeline] configFileProvider
            [2019-10-11T11:22:10.852Z] provisioning config files...
            [2019-10-11T11:22:10.862Z] copy managed file [live-env-configuration.properties] to file:/var/lib/jenkins/workspace/generic-test-junit@tmp/config1796990335769048953tmp
            [Pipeline] {
            [Pipeline] readProperties
            [Pipeline] }
            [2019-10-11T11:22:10.916Z] Deleting 1 temporary files
            [Pipeline] // configFileProvider
            [Pipeline] withCredentials
            [2019-10-11T11:22:10.958Z] Masking supported pattern matches of $S3_USERNAME or $S3_PASSWORD
            [Pipeline] {
            [Pipeline] sh
            Added `s3` successfully.
            [Pipeline] }
            [Pipeline] // withCredentials
            [Pipeline] withEnv
            [Pipeline] {
            [Pipeline] withEnv
            [Pipeline] {
            [Pipeline] fileExists
            [Pipeline] dir
            Running in /var/lib/jenkins/ramdisk
            [Pipeline] {
            [Pipeline] configFileProvider
            provisioning config files...
            copy managed file [live-env-configuration.properties] to file:/var/lib/jenkins/ramdisk@tmp/config2573695607279314921tmp
            [Pipeline] {
            [Pipeline] readProperties
            [Pipeline] }
            Deleting 1 temporary files
            [Pipeline] // configFileProvider
            

            Is there a solution to this problem?

            Best,
            Ljubisa.
             

            Show
            ljubisap Ljubisa Punosevac added a comment - - edited Hi,  Unfortunately, this problem still prevails on Jenkins ver. 2.190.1 and timestamper version 1.10 . I tried also older versions of this plugin for which has been written here to work, but again with the same results. Also, the following option has been set on Jenkins master as JVM parameter, but again with the same outcome: -Dorg.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep.USE_WATCHING= false All our jobs are pipelines and timestamps appear only in a few places. Most of the time they are gone. [Pipeline] configFileProvider [2019-10-11T11:22:10.289Z] provisioning config files... [2019-10-11T11:22:10.299Z] copy managed file [live-env-configuration.properties] to file:/ var /lib/jenkins/workspace/ generic -test-junit@tmp/config11258587709499260226tmp [Pipeline] { [Pipeline] readProperties [Pipeline] } [2019-10-11T11:22:10.350Z] Deleting 1 temporary files [Pipeline] // configFileProvider [Pipeline] sh [2019-10-11T11:22:09.383Z] Creating folder: / var /lib/jenkins/.m2 [2019-10-11T11:22:09.388Z] Creating file: / var /lib/jenkins/.m2/settings.xml [2019-10-11T11:22:09.395Z] Creating folder: / var /lib/jenkins/workspace/ generic -test-junit/.repository [2019-10-11T11:22:10.683Z] `s3/ec-test-release-pipeline/191011019/pipeline.properties` -> `pipeline.properties` [2019-10-11T11:22:10.683Z] Total: 962 B, Transferred: 962 B, Speed: 37.11 KiB/s [Pipeline] script [Pipeline] { [Pipeline] readProperties [Pipeline] } [Pipeline] // script [Pipeline] lock [2019-10-11T11:22:10.789Z] Trying to acquire lock on [Label: s3, Quantity: 1] [2019-10-11T11:22:10.789Z] Lock acquired on [Label: s3, Quantity: 1] [Pipeline] { [Pipeline] configFileProvider [2019-10-11T11:22:10.852Z] provisioning config files... [2019-10-11T11:22:10.862Z] copy managed file [live-env-configuration.properties] to file:/ var /lib/jenkins/workspace/ generic -test-junit@tmp/config1796990335769048953tmp [Pipeline] { [Pipeline] readProperties [Pipeline] } [2019-10-11T11:22:10.916Z] Deleting 1 temporary files [Pipeline] // configFileProvider [Pipeline] withCredentials [2019-10-11T11:22:10.958Z] Masking supported pattern matches of $S3_USERNAME or $S3_PASSWORD [Pipeline] { [Pipeline] sh Added `s3` successfully. [Pipeline] } [Pipeline] // withCredentials [Pipeline] withEnv [Pipeline] { [Pipeline] withEnv [Pipeline] { [Pipeline] fileExists [Pipeline] dir Running in / var /lib/jenkins/ramdisk [Pipeline] { [Pipeline] configFileProvider provisioning config files... copy managed file [live-env-configuration.properties] to file:/ var /lib/jenkins/ramdisk@tmp/config2573695607279314921tmp [Pipeline] { [Pipeline] readProperties [Pipeline] } Deleting 1 temporary files [Pipeline] // configFileProvider Is there a solution to this problem? Best, Ljubisa.  
            Hide
            jglick Jesse Glick added a comment -

            Ljubisa Punosevac it is hard to know offhand what your issue is. If you are consistently missing timestamps, it would be better to file a fresh bug with complete, self-contained steps to reproduce your problem from scratch, and link it to this one.

            Show
            jglick Jesse Glick added a comment - Ljubisa Punosevac it is hard to know offhand what your issue is. If you are consistently missing timestamps, it would be better to file a fresh bug with complete, self-contained steps to reproduce your problem from scratch , and link it to this one.
            Hide
            ljubisap Ljubisa Punosevac added a comment -

            Jesse GlickCreated new ticket JENKINS-59788 with simple dummy pipeline how to reproduce it.

            Show
            ljubisap Ljubisa Punosevac added a comment - Jesse Glick Created new ticket JENKINS-59788 with simple dummy pipeline how to reproduce it.

              People

              • Assignee:
                jglick Jesse Glick
                Reporter:
                medianick Nick Jones
              • Votes:
                9 Vote for this issue
                Watchers:
                18 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: