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

Textfinder plugin fails intermittently

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Component/s: text-finder-plugin
    • Labels:
      None
    • Environment:
      linux (Ubuntu and CentOS)
    • Similar Issues:

      Description

      Infrequently (but reproducibly), the Text-finder plugin, will not find given text in the console output of a run of a job.

      Triggering a build at the time of failure will usually succeed.

      Resaving the current configuration - without changing anything - does not affect the above behavior.

      One of the tasks that is not working is a wget where what is searched for, in order to succeed, is "DOCTYPE".

      Some jobs are flagged as failures, even though the output does include DOCTYPE.

      Thanks.

      Reverting back to 1.371 does fix the problem.

        Attachments

          Activity

          Hide
          ken_graham ken_graham added a comment -

          The issue is the timing of the execution of the plugin.

          It is now executing before the console output has been fully flushed, so checking "console output" is occurring before it should.

          This does not happen every time.

          It does happen on farm (multi-configuration) and standard jobs.

          It appears to happen about 5 times per 1000 overall executions.

          Some jobs never fail - and these might be false negatives - they are configured to fail if the given text is found.

          The jobs that do seem to fail more frequently (5 to 10 times per day, and they run every minute) are simple (wget -O - ${URL}) to simply verify that a web service is up and running, or an ant task producing output and terminating (no forking).

          I now have output from a job (pasted below), where output from the plugin is interspersed with the output from the task, showing that the plugin began execution before the last task finished. As you can see, the expression would have been found, had the plugin started after the task finished.

          ================

              1. the search expression follows:
                (USERNAME|LOGNAME)=(hudson|dev-hudson|support-hudson)
                ###
                Started by upstream project "farm user is hudson" build number 240
                Building remotely on slave_computer
                Updating http://subversion.host.com/subversion/hudson
                At revision 32710
                no change for http://subversion.host.com/subversion/hudson since the previous build
                No emails were triggered.
                [hudson] $ /home/hudson/bin/apache-ant-1.7.1/bin/ant -file hudson_admin.xml -Dlabel=it_computer env
                Buildfile: hudson_admin.xml

          env:
          [exec] BUILD_URL=http://it-watcher.host.com:8080/job/farm%20user%20is%20hudson/./label=it_computer/240/
          [exec] os_name=redhat
          [exec] SHELL=/bin/bash
          [exec] HUDSON_SERVER_COOKIE=1473cef8caf508aa2378eac263877abe
          [exec] SSH_CLIENT=192.168.0.172 60653 22
          [exec] KDE_NO_IPV6=1
          [exec] BUILD_TAG=hudson-label=it_computer-240
          [exec] BASH=/bin/bash
          [exec] QTDIR=/usr/lib64/qt-3.3
          [exec] QTINC=/usr/lib64/qt-3.3/include
          [exec] JOB_URL=http://it-watcher.host.com:8080/job/farm%20user%20is%20hudson/./label=it_computer/
          [exec] WORKSPACE=/build/home_hudson/watcher_slave/workspace/farm user is hudson/label/it_computer
          [exec] ANT_HOME=/home/hudson/bin/apache-ant-1.7.1
          [exec] IT_HUDSON_URL=http://it-hudson.host.com:8181/
          [exec] USER=hudson
          [exec] LD_LIBRARY_PATH=/usr/java/jdk1.6.0_17/jre/lib/amd64/server:/usr/java/jdk1.6.0_17/jre/lib/amd64:/usr/java/jdk1.6.0_17/jre/../lib/amd64
          [exec] KDEDIR=/usr
          [exec] NLSPATH=/usr/dt/lib/nls/msg/%L/%N.cat
          [exec] MAIL=/var/mail/hudson
          [exec] PATH=/usr/java/jdk1.6.0_17//bin:/opt/CollabNet_Subversion/bin/:/home/hudson/bin:/usr/lib64/qt-3.3/bin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin
          [exec] PWD=/build/home_hudson/watcher_slave/workspace/farm user is hudson/label/it_computer/hudson
          [exec] JAVA_HOME=/usr/java/jdk1.6.0_17
          [exec] HUDSON_URL=http://hudson.host.com:8080
          [exec] KDE_IS_PRELINKED=1
          [exec] LANG=en_US.UTF-8
          [exec] JOB_NAME=farm user is hudson/label=it_computer
          [exec] XFILESEARCHPATH=/usr/dt/app-defaults/%L/Dt
          [exec] BUILD_ID=2010-11-19_08-27-16
          [exec] SVN_REVISION=23066
          Checking console output
          Email was triggered for: Failure
          Sending email for trigger: Failure
          [exec] WATCHER_HOME=/home/hudson/.hudson
          [exec] SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass
          [exec] SHLVL=2
          [exec] HOME=/home/hudson
          [exec] EXECUTOR_NUMBER=1
          [exec] NODE_LABELS=IT it_computer svn
          [exec] TMP=/tmp
          [exec] LOGNAME=hudson
          [exec] CVS_RSH=ssh
          [exec] QTLIB=/usr/lib64/qt-3.3/lib
          [exec] HUDSON_HOME=/build/home_hudson/.hudson/
          [exec] SSH_CONNECTION=192.168.0.172 60653 192.168.0.40 22
          [exec] NODE_NAME=it_computer
          Sending email to: hudson@rx3000.com
          [exec] LESSOPEN=|/usr/bin/lesspipe.sh %s
          [exec] BUILD_NUMBER=240
          [exec] HUDSON_COOKIE=ed5a63b5-18f8-4c97-9eb0-3e2bdf4634ce
          [exec] SSH_HUDSON_USER=hudson@hudson.host.com
          [exec] G_BROKEN_FILENAMES=1
          [exec] MACHINE_NAME=computer
          [exec] _=/bin/env

          BUILD SUCCESSFUL
          Total time: 0 seconds
          Notifying upstream projects of job completion
          Finished: FAILURE

          Page generated: Nov 19, 2010 8:59:30 AMHudson ver. 1.385

          Show
          ken_graham ken_graham added a comment - The issue is the timing of the execution of the plugin. It is now executing before the console output has been fully flushed, so checking "console output" is occurring before it should. This does not happen every time. It does happen on farm (multi-configuration) and standard jobs. It appears to happen about 5 times per 1000 overall executions. Some jobs never fail - and these might be false negatives - they are configured to fail if the given text is found. The jobs that do seem to fail more frequently (5 to 10 times per day, and they run every minute) are simple (wget -O - ${URL}) to simply verify that a web service is up and running, or an ant task producing output and terminating (no forking). I now have output from a job (pasted below), where output from the plugin is interspersed with the output from the task, showing that the plugin began execution before the last task finished. As you can see, the expression would have been found, had the plugin started after the task finished. ================ the search expression follows: (USERNAME|LOGNAME)=(hudson|dev-hudson|support-hudson) ### Started by upstream project "farm user is hudson" build number 240 Building remotely on slave_computer Updating http://subversion.host.com/subversion/hudson At revision 32710 no change for http://subversion.host.com/subversion/hudson since the previous build No emails were triggered. [hudson] $ /home/hudson/bin/apache-ant-1.7.1/bin/ant -file hudson_admin.xml -Dlabel=it_computer env Buildfile: hudson_admin.xml env: [exec] BUILD_URL= http://it-watcher.host.com:8080/job/farm%20user%20is%20hudson/./label=it_computer/240/ [exec] os_name=redhat [exec] SHELL=/bin/bash [exec] HUDSON_SERVER_COOKIE=1473cef8caf508aa2378eac263877abe [exec] SSH_CLIENT=192.168.0.172 60653 22 [exec] KDE_NO_IPV6=1 [exec] BUILD_TAG=hudson-label=it_computer-240 [exec] BASH=/bin/bash [exec] QTDIR=/usr/lib64/qt-3.3 [exec] QTINC=/usr/lib64/qt-3.3/include [exec] JOB_URL= http://it-watcher.host.com:8080/job/farm%20user%20is%20hudson/./label=it_computer/ [exec] WORKSPACE=/build/home_hudson/watcher_slave/workspace/farm user is hudson/label/it_computer [exec] ANT_HOME=/home/hudson/bin/apache-ant-1.7.1 [exec] IT_HUDSON_URL= http://it-hudson.host.com:8181/ [exec] USER=hudson [exec] LD_LIBRARY_PATH=/usr/java/jdk1.6.0_17/jre/lib/amd64/server:/usr/java/jdk1.6.0_17/jre/lib/amd64:/usr/java/jdk1.6.0_17/jre/../lib/amd64 [exec] KDEDIR=/usr [exec] NLSPATH=/usr/dt/lib/nls/msg/%L/%N.cat [exec] MAIL=/var/mail/hudson [exec] PATH=/usr/java/jdk1.6.0_17//bin:/opt/CollabNet_Subversion/bin/:/home/hudson/bin:/usr/lib64/qt-3.3/bin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin [exec] PWD=/build/home_hudson/watcher_slave/workspace/farm user is hudson/label/it_computer/hudson [exec] JAVA_HOME=/usr/java/jdk1.6.0_17 [exec] HUDSON_URL= http://hudson.host.com:8080 [exec] KDE_IS_PRELINKED=1 [exec] LANG=en_US.UTF-8 [exec] JOB_NAME=farm user is hudson/label=it_computer [exec] XFILESEARCHPATH=/usr/dt/app-defaults/%L/Dt [exec] BUILD_ID=2010-11-19_08-27-16 [exec] SVN_REVISION=23066 Checking console output Email was triggered for: Failure Sending email for trigger: Failure [exec] WATCHER_HOME=/home/hudson/.hudson [exec] SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass [exec] SHLVL=2 [exec] HOME=/home/hudson [exec] EXECUTOR_NUMBER=1 [exec] NODE_LABELS=IT it_computer svn [exec] TMP=/tmp [exec] LOGNAME=hudson [exec] CVS_RSH=ssh [exec] QTLIB=/usr/lib64/qt-3.3/lib [exec] HUDSON_HOME=/build/home_hudson/.hudson/ [exec] SSH_CONNECTION=192.168.0.172 60653 192.168.0.40 22 [exec] NODE_NAME=it_computer Sending email to: hudson@rx3000.com [exec] LESSOPEN=|/usr/bin/lesspipe.sh %s [exec] BUILD_NUMBER=240 [exec] HUDSON_COOKIE=ed5a63b5-18f8-4c97-9eb0-3e2bdf4634ce [exec] SSH_HUDSON_USER=hudson@hudson.host.com [exec] G_BROKEN_FILENAMES=1 [exec] MACHINE_NAME=computer [exec] _=/bin/env BUILD SUCCESSFUL Total time: 0 seconds Notifying upstream projects of job completion Finished: FAILURE Page generated: Nov 19, 2010 8:59:30 AMHudson ver. 1.385

            People

            • Assignee:
              drlewis drlewis
              Reporter:
              ken_graham ken_graham
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: