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

http://jenkins/job/jobname/1/timestamps return twice as big values compared to what it should

    XMLWordPrintable

    Details

    • Similar Issues:

      Description

      When requesting time stamps for a job via http://jenkins/job/jobname/1/timestamps a number of time stamps corresponding to number of console output lines is returned. Problem is that jenkins shows that job finished in time X but last line (in seconds) shows that build took 2X - twice as long.

        Attachments

        1. pluginList.txt
          1 kB
        2. screenshot-1.jpg
          screenshot-1.jpg
          266 kB
        3. timestamper.zip
          9 kB

          Activity

          Hide
          stevengbrown Steven G Brown added a comment -

          I haven't been able to reproduce this. If you could provide steps to reproduce from a new Jenkins install, that would be really useful. i.e. which version of Timestamper, which other plugins do I need, how should I configure the job.

          Show
          stevengbrown Steven G Brown added a comment - I haven't been able to reproduce this. If you could provide steps to reproduce from a new Jenkins install, that would be really useful. i.e. which version of Timestamper, which other plugins do I need, how should I configure the job.
          Hide
          aleksas aleksas added a comment - - edited

          Current software:

          • Jenkins ver. 1.509.4
          • Timestamper 1.5.7

          If checking timestamps via console output (http://jenkins/job/jobName/111/consoleFull), then they are consistent with time that jenkins reported duration.

          I'll try to reproduce on a clean install

          Show
          aleksas aleksas added a comment - - edited Current software: Jenkins ver. 1.509.4 Timestamper 1.5.7 If checking timestamps via console output ( http://jenkins/job/jobName/111/consoleFull ), then they are consistent with time that jenkins reported duration. I'll try to reproduce on a clean install
          Hide
          aleksas aleksas added a comment - - edited

          Could not reproduce neither on a clean latest jenkins from releases nor from LTS. However on my current production Jenkins created a job having Windows batch command "ping -n 100 google.com" and ran it, the result is consistent with bug description. Well seconds listed are not exactly 2x but somewhat in that range. Slave version 2.32.

          Show
          aleksas aleksas added a comment - - edited Could not reproduce neither on a clean latest jenkins from releases nor from LTS. However on my current production Jenkins created a job having Windows batch command "ping -n 100 google.com" and ran it, the result is consistent with bug description. Well seconds listed are not exactly 2x but somewhat in that range. Slave version 2.32.
          Hide
          stevengbrown Steven G Brown added a comment -

          OK, great. Which Jenkins plugins are installed on your production server?

          Could you also attach the contents of the timestamper directory for one of these builds (copy from your master Jenkins server), and let me know the duration of that build?

          Show
          stevengbrown Steven G Brown added a comment - OK, great. Which Jenkins plugins are installed on your production server? Could you also attach the contents of the timestamper directory for one of these builds (copy from your master Jenkins server), and let me know the duration of that build?
          Hide
          aleksas aleksas added a comment -

          Build took 14 min. 19 s.

          Show
          aleksas aleksas added a comment - Build took 14 min. 19 s.
          Hide
          scm_issue_link SCM/JIRA link daemon added a comment -

          Code changed in jenkins
          User: Steven Brown
          Path:
          src/main/java/hudson/plugins/timestamper/Timestamp.java
          src/main/java/hudson/plugins/timestamper/TimestamperOutputStream.java
          src/main/java/hudson/plugins/timestamper/io/DumpTimestamps.java
          src/main/java/hudson/plugins/timestamper/io/TimestampsReader.java
          src/main/java/hudson/plugins/timestamper/io/TimestampsWriter.java
          src/main/java/hudson/plugins/timestamper/io/TimestampsWriterImpl.java
          src/test/java/hudson/plugins/timestamper/TimestamperOutputStreamTest.java
          src/test/java/hudson/plugins/timestamper/action/TimestampsActionTest.java
          src/test/java/hudson/plugins/timestamper/annotator/TimestampAnnotatorTest.java
          src/test/java/hudson/plugins/timestamper/io/TimestampsIOTest.java
          src/test/java/hudson/plugins/timestamper/io/TimestampsReaderTest.java
          src/test/java/hudson/plugins/timestamper/io/TimestampsWriterImplTest.java
          http://jenkins-ci.org/commit/timestamper-plugin/4ec6bacdaa2c4dbd61fe3feb448c374ec30e1048
          Log:
          Rely on System.currentTimeMillis only (not nanoTime) due to JENKINS-19778

          On most Jenkins servers, System.nanoTime gives a more accurate reading of
          elapsed time, because it is unaffected when the clock is changed. However,
          on the Jenkins server in issue 19778, System.nanoTime jumps forwards
          several times during the build, by about 30-40 seconds each time. Once the
          build has finished, the Timestamper plugin reports an elapsed time of about
          twice what it should be.

          It does not seem possible for the plugin to reliably determine whether it
          can use System.nanoTime, especially when running within a virtual machine.

          Overall, it is not worthwhile for the plugin to rely on System.nanoTime.

          Compare: https://github.com/jenkinsci/timestamper-plugin/compare/830d25b5fe14...4ec6bacdaa2c

          Show
          scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Steven Brown Path: src/main/java/hudson/plugins/timestamper/Timestamp.java src/main/java/hudson/plugins/timestamper/TimestamperOutputStream.java src/main/java/hudson/plugins/timestamper/io/DumpTimestamps.java src/main/java/hudson/plugins/timestamper/io/TimestampsReader.java src/main/java/hudson/plugins/timestamper/io/TimestampsWriter.java src/main/java/hudson/plugins/timestamper/io/TimestampsWriterImpl.java src/test/java/hudson/plugins/timestamper/TimestamperOutputStreamTest.java src/test/java/hudson/plugins/timestamper/action/TimestampsActionTest.java src/test/java/hudson/plugins/timestamper/annotator/TimestampAnnotatorTest.java src/test/java/hudson/plugins/timestamper/io/TimestampsIOTest.java src/test/java/hudson/plugins/timestamper/io/TimestampsReaderTest.java src/test/java/hudson/plugins/timestamper/io/TimestampsWriterImplTest.java http://jenkins-ci.org/commit/timestamper-plugin/4ec6bacdaa2c4dbd61fe3feb448c374ec30e1048 Log: Rely on System.currentTimeMillis only (not nanoTime) due to JENKINS-19778 On most Jenkins servers, System.nanoTime gives a more accurate reading of elapsed time, because it is unaffected when the clock is changed. However, on the Jenkins server in issue 19778, System.nanoTime jumps forwards several times during the build, by about 30-40 seconds each time. Once the build has finished, the Timestamper plugin reports an elapsed time of about twice what it should be. It does not seem possible for the plugin to reliably determine whether it can use System.nanoTime, especially when running within a virtual machine. Overall, it is not worthwhile for the plugin to rely on System.nanoTime. Compare: https://github.com/jenkinsci/timestamper-plugin/compare/830d25b5fe14...4ec6bacdaa2c
          Hide
          stevengbrown Steven G Brown added a comment -

          aleksas, would you please try running Timestamper 1.5.8 on that server? Let me know whether it works.

          Show
          stevengbrown Steven G Brown added a comment - aleksas, would you please try running Timestamper 1.5.8 on that server? Let me know whether it works.

            People

            • Assignee:
              aleksas aleksas
              Reporter:
              aleksas aleksas
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: