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

Regular 404s for running builds that get better after build is finished.

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Labels:
      None
    • Environment:
    • Similar Issues:

      Description

      For some large (50%?) number of builds (across several projects):

      • The build starts.

      As expected:

      After running for several minutes:

      However:

      • the list of workers still shows the build as occupying the worker (and provides a link which goes to the now 404-ing build page)
      • the build runs to completion successfully.
      • Build-related URLs for other builds still work ok at this point.

      After the build has run to completion, all of the build related URLs which started 404ing work again (for example the complete console output can be seen).

      A screenshot of progressive console output breaking part way due to this is attached - to be clear, this happens for all URLs related to the build, not just the progressive console.

      This has happened in all of the weekly releases that I've tried (three or four over the past two months); previous to that I was not using Jenkins on this codebase/machine.

        Attachments

          Activity

          Hide
          danielbeck Daniel Beck added a comment -

          Which is it in your issue description: Job/Project, or Run/Build?

          Show
          danielbeck Daniel Beck added a comment - Which is it in your issue description: Job/Project, or Run/Build?
          Hide
          benclifford Ben Clifford added a comment -

          I don't understand the question.

          Show
          benclifford Ben Clifford added a comment - I don't understand the question.
          Hide
          danielbeck Daniel Beck added a comment -

          Project/Job is the thing you configure. Run/Build is the thing that has a start time and duration. I'm pretty sure at least some uses of "job" in the issue description should be "build", but it's not clear whether it's all of them.

          Show
          danielbeck Daniel Beck added a comment - Project/Job is the thing you configure. Run/Build is the thing that has a start time and duration. I'm pretty sure at least some uses of "job" in the issue description should be "build", but it's not clear whether it's all of them.
          Hide
          benclifford Ben Clifford added a comment -

          updated

          Show
          benclifford Ben Clifford added a comment - updated
          Hide
          danielbeck Daniel Beck added a comment -

          This is a Workflow Multibranch project, right?

          Go to the Jenkins script console, and run this command:

          org.kohsuke.stapler.Dispatcher.TRACE = true

          Now, when requesting a build related URL, check the HTTP response headers sent by Jenkins. There will be headers named X-Stapler-Trace-001 or similar. Please provide all of them.

          CC Jesse Glick

          Show
          danielbeck Daniel Beck added a comment - This is a Workflow Multibranch project, right? Go to the Jenkins script console, and run this command: org.kohsuke.stapler.Dispatcher.TRACE = true Now, when requesting a build related URL, check the HTTP response headers sent by Jenkins. There will be headers named X-Stapler-Trace-001 or similar. Please provide all of them. CC Jesse Glick
          Hide
          benclifford Ben Clifford added a comment -

          For a working, finished build:

          {{> GET /job/benc-master-db/47/console HTTP/1.1
          > Host: loris.beautifuldestinations.com:2000
          > Accept-Encoding: deflate, gzip
          > User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:44.0) Gecko/20100101 Firefox/44.0 Iceweasel/44.0.2
          > Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8
          > Accept-Language: en-US,en;q=0.5
          > DNT: 1
          > Referer: http://loris.beautifuldestinations.com:2000/job/benc-master-db/47/
          > Cookie: *ELIDED BY benclifford*
          > Connection: keep-alive
          > Cache-Control: max-age=0
          >
          < HTTP/1.1 200 OK
          < Date: Mon, 13 Jun 2016 21:20:15 GMT
          < X-Content-Type-Options: nosniff
          < Stapler-Trace-001: -> evaluate(<hudson.model.Hudson@1253fcf2> :hudson.model.Hudson,"/job/benc-master-db/47/console")
          < Stapler-Trace-002: -> evaluate(((StaplerProxy)<hudson.model.Hudson@1253fcf2>).getTarget(),"/job/benc-master-db/47/console")
          < Stapler-Trace-003: -> evaluate(<hudson.model.Hudson@1253fcf2>.getJob("benc-master-db"),"/47/console")
          < Stapler-Trace-004: -> evaluate(<hudson.model.FreeStyleProject@71273b20[benc-master-db]> :hudson.model.FreeStyleProject,"/47/console")
          < Stapler-Trace-005: -> evaluate(<hudson.model.FreeStyleProject@71273b20[benc-master-db]>.getDynamic("47",...),"/console")
          < Stapler-Trace-006: -> evaluate(<benc-master-db #47> :hudson.model.FreeStyleBuild,"/console")
          < Stapler-Trace-007: -> hudson/model/Run/console.jelly on <benc-master-db #47>
          < Content-Encoding: gzip
          < Expires: 0
          < Cache-Control: no-cache,no-store,must-revalidate
          < X-Hudson-Theme: default
          < Content-Type: text/html;charset=UTF-8
          < X-Hudson: 1.395
          < X-Jenkins: 2.8
          < X-Jenkins-Session: 7ae07cb4
          < X-Frame-Options: sameorigin
          < X-Instance-Identity: *ELIDED BY benclifford*
          < X-SSH-Endpoint: loris.beautifuldestinations.com:43014
          < X-ConsoleAnnotator: *ELIDED BY benclifford*
          < Content-Length: 9165
          < Server: Jetty(9.2.z-SNAPSHOT)
          }}

          I'll get some from a failing case when I can poke it into happening.

          Show
          benclifford Ben Clifford added a comment - For a working, finished build: {{> GET /job/benc-master-db/47/console HTTP/1.1 > Host: loris.beautifuldestinations.com:2000 > Accept-Encoding: deflate, gzip > User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:44.0) Gecko/20100101 Firefox/44.0 Iceweasel/44.0.2 > Accept: text/html,application/xhtml+xml,application/xml;q=0.9, / ;q=0.8 > Accept-Language: en-US,en;q=0.5 > DNT: 1 > Referer: http://loris.beautifuldestinations.com:2000/job/benc-master-db/47/ > Cookie: * ELIDED BY benclifford * > Connection: keep-alive > Cache-Control: max-age=0 > < HTTP/1.1 200 OK < Date: Mon, 13 Jun 2016 21:20:15 GMT < X-Content-Type-Options: nosniff < Stapler-Trace-001: -> evaluate(<hudson.model.Hudson@1253fcf2> :hudson.model.Hudson,"/job/benc-master-db/47/console") < Stapler-Trace-002: -> evaluate(((StaplerProxy)<hudson.model.Hudson@1253fcf2>).getTarget(),"/job/benc-master-db/47/console") < Stapler-Trace-003: -> evaluate(<hudson.model.Hudson@1253fcf2>.getJob("benc-master-db"),"/47/console") < Stapler-Trace-004: -> evaluate(<hudson.model.FreeStyleProject@71273b20 [benc-master-db] > :hudson.model.FreeStyleProject,"/47/console") < Stapler-Trace-005: -> evaluate(<hudson.model.FreeStyleProject@71273b20 [benc-master-db] >.getDynamic("47",...),"/console") < Stapler-Trace-006: -> evaluate(<benc-master-db #47> :hudson.model.FreeStyleBuild,"/console") < Stapler-Trace-007: -> hudson/model/Run/console.jelly on <benc-master-db #47> < Content-Encoding: gzip < Expires: 0 < Cache-Control: no-cache,no-store,must-revalidate < X-Hudson-Theme: default < Content-Type: text/html;charset=UTF-8 < X-Hudson: 1.395 < X-Jenkins: 2.8 < X-Jenkins-Session: 7ae07cb4 < X-Frame-Options: sameorigin < X-Instance-Identity: * ELIDED BY benclifford * < X-SSH-Endpoint: loris.beautifuldestinations.com:43014 < X-ConsoleAnnotator: * ELIDED BY benclifford * < Content-Length: 9165 < Server: Jetty(9.2.z-SNAPSHOT) }} I'll get some from a failing case when I can poke it into happening.
          Hide
          benclifford Ben Clifford added a comment - - edited

          The previous paste is from a working build that is not a multi-branch project build, but on the relevant jenkins install. Most of our builds are under multi-branch projects, though I haven't particularly paid attention to whether this happens only on those or not.

          Show
          benclifford Ben Clifford added a comment - - edited The previous paste is from a working build that is not a multi-branch project build, but on the relevant jenkins install. Most of our builds are under multi-branch projects, though I haven't particularly paid attention to whether this happens only on those or not.
          Hide
          benclifford Ben Clifford added a comment - - edited

          Here are the headers from a multibranch project that i) I got to show this error, and then ii) shows itself getting better at the end of the build:

          i) not working after a few minutes:
          {{
          < Stapler-Trace-001: -> evaluate(<hudson.model.Hudson@1253fcf2> :hudson.model.Hudson,"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-002: -> evaluate(((StaplerProxy)<hudson.model.Hudson@1253fcf2>).getTarget(),"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-003: -> evaluate(<hudson.model.Hudson@1253fcf2>.getJob("beautilytics"),"/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-004: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4[beautilytics]> :com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject,"/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-005: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4[beautilytics]>.getBranch("benc-tmp-debug-jenkins-1"),"/1/console")
          < Stapler-Trace-006: -> evaluate(<hudson.model.FreeStyleProject@736075be[beautilytics/benc-tmp-debug-jenkins-1]> :hudson.model.FreeStyleProject,"/1/console")
          < Stapler-Trace-007: -> evaluate(<hudson.model.FreeStyleProject@736075be[beautilytics/benc-tmp-debug-jenkins-1]>.getDynamic("1",...),"/console")
          < Stapler-Trace-008: hudson.model.FreeStyleProject@736075be[beautilytics/benc-tmp-debug-jenkins-1].getDynamic("1",...)==null. Back tracking.

          and
          }}
          ii) working after the build has finished:

          {{< Stapler-Trace-001: -> evaluate(<hudson.model.Hudson@1253fcf2> :hudson.model.Hudson,"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-002: -> evaluate(((StaplerProxy)<hudson.model.Hudson@1253fcf2>).getTarget(),"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-003: -> evaluate(<hudson.model.Hudson@1253fcf2>.getJob("beautilytics"),"/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-004: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4[beautilytics]> :com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject,"/branch/benc-tmp-debug-jenkins-1/1/console")
          < Stapler-Trace-005: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4[beautilytics]>.getBranch("benc-tmp-debug-jenkins-1"),"/1/console")
          < Stapler-Trace-006: -> evaluate(<hudson.model.FreeStyleProject@736075be[beautilytics/benc-tmp-debug-jenkins-1]> :hudson.model.FreeStyleProject,"/1/console")
          < Stapler-Trace-007: -> evaluate(<hudson.model.FreeStyleProject@736075be[beautilytics/benc-tmp-debug-jenkins-1]>.getDynamic("1",...),"/console")
          < Stapler-Trace-008: -> evaluate(<beautilytics/benc-tmp-debug-jenkins-1 #1> :hudson.model.FreeStyleBuild,"/console")
          < Stapler-Trace-009: -> hudson/model/Run/console.jelly on <beautilytics/benc-tmp-debug-jenkins-1 #1>
          }}

          Show
          benclifford Ben Clifford added a comment - - edited Here are the headers from a multibranch project that i) I got to show this error, and then ii) shows itself getting better at the end of the build: i) not working after a few minutes: {{ < Stapler-Trace-001: -> evaluate(<hudson.model.Hudson@1253fcf2> :hudson.model.Hudson,"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-002: -> evaluate(((StaplerProxy)<hudson.model.Hudson@1253fcf2>).getTarget(),"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-003: -> evaluate(<hudson.model.Hudson@1253fcf2>.getJob("beautilytics"),"/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-004: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4 [beautilytics] > :com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject,"/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-005: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4 [beautilytics] >.getBranch("benc-tmp-debug-jenkins-1"),"/1/console") < Stapler-Trace-006: -> evaluate(<hudson.model.FreeStyleProject@736075be [beautilytics/benc-tmp-debug-jenkins-1] > :hudson.model.FreeStyleProject,"/1/console") < Stapler-Trace-007: -> evaluate(<hudson.model.FreeStyleProject@736075be [beautilytics/benc-tmp-debug-jenkins-1] >.getDynamic("1",...),"/console") < Stapler-Trace-008: hudson.model.FreeStyleProject@736075be [beautilytics/benc-tmp-debug-jenkins-1] .getDynamic("1",...)==null. Back tracking. and }} ii) working after the build has finished: {{< Stapler-Trace-001: -> evaluate(<hudson.model.Hudson@1253fcf2> :hudson.model.Hudson,"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-002: -> evaluate(((StaplerProxy)<hudson.model.Hudson@1253fcf2>).getTarget(),"/job/beautilytics/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-003: -> evaluate(<hudson.model.Hudson@1253fcf2>.getJob("beautilytics"),"/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-004: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4 [beautilytics] > :com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject,"/branch/benc-tmp-debug-jenkins-1/1/console") < Stapler-Trace-005: -> evaluate(<com.github.mjdetullio.jenkins.plugins.multibranch.FreeStyleMultiBranchProject@679702b4 [beautilytics] >.getBranch("benc-tmp-debug-jenkins-1"),"/1/console") < Stapler-Trace-006: -> evaluate(<hudson.model.FreeStyleProject@736075be [beautilytics/benc-tmp-debug-jenkins-1] > :hudson.model.FreeStyleProject,"/1/console") < Stapler-Trace-007: -> evaluate(<hudson.model.FreeStyleProject@736075be [beautilytics/benc-tmp-debug-jenkins-1] >.getDynamic("1",...),"/console") < Stapler-Trace-008: -> evaluate(<beautilytics/benc-tmp-debug-jenkins-1 #1> :hudson.model.FreeStyleBuild,"/console") < Stapler-Trace-009: -> hudson/model/Run/console.jelly on <beautilytics/benc-tmp-debug-jenkins-1 #1> }}
          Hide
          danielbeck Daniel Beck added a comment -

          Looks like an issue in https://github.com/jenkinsci/multi-branch-project-plugin so assigned to that component.

          Show
          danielbeck Daniel Beck added a comment - Looks like an issue in https://github.com/jenkinsci/multi-branch-project-plugin so assigned to that component.
          Hide
          ivananishchuk Ivan Anishchuk added a comment -

          Any news? We've been suffering from this for a while now.

          Show
          ivananishchuk Ivan Anishchuk added a comment - Any news? We've been suffering from this for a while now.
          Hide
          benclifford Ben Clifford added a comment -

          I had a bit of a poke at this.

          At some point, the RunMap is being somehow refreshed/reloaded/reset for all branches in this job.

          When the RunMap subsequently tries to load the information for the sometimes-missing-build, it wants a build.xml file to be present in the build directory. That build.xml file is not present, so as far as RunMap.retrieve is concerned, this job does not exist.

          I don't know enough of Jenkins innards to know if: i) it is wrong that the RunMap is being emptied/reloaded or ii) build.xml should be present during the job run.

          Show
          benclifford Ben Clifford added a comment - I had a bit of a poke at this. At some point, the RunMap is being somehow refreshed/reloaded/reset for all branches in this job. When the RunMap subsequently tries to load the information for the sometimes-missing-build, it wants a build.xml file to be present in the build directory. That build.xml file is not present, so as far as RunMap.retrieve is concerned, this job does not exist. I don't know enough of Jenkins innards to know if: i) it is wrong that the RunMap is being emptied/reloaded or ii) build.xml should be present during the job run.
          Hide
          benclifford Ben Clifford added a comment -

          The refresh/reset/reload seems to happen here:

          at jenkins.model.lazy.AbstractLazyLoadRunMap.loadNumberOnDisk(AbstractLazyLoadRunMap.java:189)
          at jenkins.model.lazy.AbstractLazyLoadRunMap.initBaseDir(AbstractLazyLoadRunMap.java:153)
          at jenkins.model.lazy.AbstractLazyLoadRunMap.<init>(AbstractLazyLoadRunMap.java:145)
          at hudson.model.RunMap.<init>(RunMap.java:86)
          at jenkins.model.lazy.LazyBuildMixIn.createBuildRunMap(LazyBuildMixIn.java:131)
          at jenkins.model.lazy.LazyBuildMixIn.onCreatedFromScratch(LazyBuildMixIn.java:94)
          at hudson.model.AbstractProject.onCreatedFromScratch(AbstractProject.java:312)
          at com.cloudbees.hudson.plugins.folder.computed.ComputedFolder$1.created(ComputedFolder.java:180)
          at com.github.mjdetullio.jenkins.plugins.multibranch.AbstractMultiBranchProject.computeChildren(AbstractMultiBranchProject.java:634)
          at com.cloudbees.hudson.plugins.folder.computed.ComputedFolder.updateChildren(ComputedFolder.java:157)
          at com.cloudbees.hudson.plugins.folder.computed.FolderComputation.run(FolderComputation.java:122)
          at hudson.model.ResourceController.execute(ResourceController.java:98)
          at hudson.model.Executor.run(Executor.java:410)

          Show
          benclifford Ben Clifford added a comment - The refresh/reset/reload seems to happen here: at jenkins.model.lazy.AbstractLazyLoadRunMap.loadNumberOnDisk(AbstractLazyLoadRunMap.java:189) at jenkins.model.lazy.AbstractLazyLoadRunMap.initBaseDir(AbstractLazyLoadRunMap.java:153) at jenkins.model.lazy.AbstractLazyLoadRunMap.<init>(AbstractLazyLoadRunMap.java:145) at hudson.model.RunMap.<init>(RunMap.java:86) at jenkins.model.lazy.LazyBuildMixIn.createBuildRunMap(LazyBuildMixIn.java:131) at jenkins.model.lazy.LazyBuildMixIn.onCreatedFromScratch(LazyBuildMixIn.java:94) at hudson.model.AbstractProject.onCreatedFromScratch(AbstractProject.java:312) at com.cloudbees.hudson.plugins.folder.computed.ComputedFolder$1.created(ComputedFolder.java:180) at com.github.mjdetullio.jenkins.plugins.multibranch.AbstractMultiBranchProject.computeChildren(AbstractMultiBranchProject.java:634) at com.cloudbees.hudson.plugins.folder.computed.ComputedFolder.updateChildren(ComputedFolder.java:157) at com.cloudbees.hudson.plugins.folder.computed.FolderComputation.run(FolderComputation.java:122) at hudson.model.ResourceController.execute(ResourceController.java:98) at hudson.model.Executor.run(Executor.java:410)
          Hide
          benclifford Ben Clifford added a comment -

          It looks like this can be reproduced by clicking "Sync Branches" to cause the above update to happen. In my production environment, I have this scheduled to happen every 10 minutes or so.

          Show
          benclifford Ben Clifford added a comment - It looks like this can be reproduced by clicking "Sync Branches" to cause the above update to happen. In my production environment, I have this scheduled to happen every 10 minutes or so.

            People

            • Assignee:
              mjdetullio Matthew DeTullio
              Reporter:
              benclifford Ben Clifford
            • Votes:
              1 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated: