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

ConsoleLog is missing build output

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Minor
    • Resolution: Incomplete
    • Component/s: durable-task-plugin
    • Labels:
      None
    • Environment:
      Linux x86_64 (Ubuntu 16.04), Jenkins 2.121.1, Chrome (on MacOS)
    • Similar Issues:

      Description

      I have run into an issue with the Console Output often failing to include build failure messages, due to the output being truncated.

      In an attempt to discover why our builds were failing, I discovered the transient durable jenkins-log.txt file(s) - they appear to be removed upon completion of the build.

      (e.g., ... /project@tmp/durable-472431c5/jenkins-log.txt)

      I also noticed I could tail the file to eventually find failures in our build, and in the process, I realized this file seems to be getting reset/truncated, and the remaining log messages appear to start from the beginning of the file.  I'm assuming this may explain the lack of progress in the Console Output, which stops progressing beyond this point, and is often missing important build failure information.

      I don't know what causes it, but I have tried a "tail -F jenkins-log.txt >> saved_log.txt 2>&1" on the file, and see something similar to:

      [... snip ...]
      >>> qt5base 5.6.2 Configuring
      /usr/bin/install -m 0644 -D package/qt5/qt5base//qmake.conf /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/mkspecs/devices/linux-buildroot-g++/qmake.conf
      /usr/bin/install -m 0644 -D package/qt5/qt5base//qplatformdefs.h /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/mkspecs/devices/linux-buildroot-g++/qplatformdefs.h
      (cd /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2; PATH="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/bin:/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/sbin:/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/bin:/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/sbin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games:/snap/bin" PKG_CONFIG="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/bin/pkg-config" PKG_CONFIG_LIBDIR="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot/usr/lib/pkgconfig" PKG_CONFIG_SYSROOT_DIR="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot" MAKEFLAGS=" -- V=1 -j29" ./configure -v -prefix /usr -hostprefix /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr -headerdir /usr/include/qt5 -sysroot /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot -plugindir /usr/lib/qt/plugins -examplesdir /usr/lib/qt/examples -no-rpath -nomake tests -device buildroot -device-option CROSS_COMPILE="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/bin/arm-cortexa9_neon-linux-gnueabihf-" -device-option BR_COMPILER_CFLAGS="-D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -D_FILE_OFFSET_BITS=64  -Os -g2 -fstack-protector-strong " -device-option BR_COMPILER_CXXFLAGS="-D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -D_FILE_OFFSET_BITS=64  -Os -g2 -fstack-protector-strong -fstack-protector-strong " -optimized-qmake -no-cups -no-iconv -system-zlib -system-pcre -no-pch -shared  -no-kms -debug -largefile -opensource -confirm-license -no-sql-mysql -no-sql-psql  -system-sqlite  -no-gui -no-freetype -no-widgets -no-linuxfb -no-directfb -no-xcb -no-opengl  -no-eglfs -openssl -no-fontconfig -no-gif -no-libjpeg -no-libpng -dbus -no-tslib -glib -no-icu -nomake examples -no-gstreamer -no-libinput )
      
      This is the Qt Open Source Edition.
      
      You are licensed to use this software under the terms of
      the Lesser GNU General Public License (LGPL) versions 2.1.
      You are also licensed to use this software under the terms of
      the GNU Lesser General Public License (LGPL) versions 3.
      
      You have already accepted the terms of the Open Source license.
      
      Running configuration tests (phase 1)...
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/bin/arm-cortexa9_neon-linux-gnueabihf-g++ -c -fvisibility=hidden fvisibility.c
      Symbol visibility control enabled.
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/bin/arm-cortexa9_neon-linux-gnueabihf-g++ --sysroot=/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot -o libtest.so -shared -Wl,-Bsymbolic-functions -fPIC bsymbolic_functions.c
      bsymbolic_functions.c:2:2: error: #error "Symbolic function binding on this architecture may be broken, disabling it (see QTBUG-36129)."
       #error "Symbolic function binding on this architecture may be broken, disabling it (see QTBUG-36129)."
        ^
      Symbolic function binding disabled.
      tail: jenkins-log.txt: file truncated
      DEFAULT_INCDIRS="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/arm-cortexa9_neon-linux-gnueabihf/include/c++/5.4.0
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/arm-cortexa9_neon-linux-gnueabihf/include/c++/5.4.0/arm-cortexa9_neon-linux-gnueabihf
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/arm-cortexa9_neon-linux-gnueabihf/include/c++/5.4.0/backward
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/lib/gcc/arm-cortexa9_neon-linux-gnueabihf/5.4.0/include
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/lib/gcc/arm-cortexa9_neon-linux-gnueabihf/5.4.0/include-fixed
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/arm-cortexa9_neon-linux-gnueabihf/include
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot/usr/include
      "
      DEFAULT_LIBDIRS="/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/lib/gcc/arm-cortexa9_neon-linux-gnueabihf/5.4.0
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/lib/gcc
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/opt/ext-toolchain/arm-cortexa9_neon-linux-gnueabihf/lib
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot/lib
      /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/host/usr/arm-buildroot-linux-gnueabihf/sysroot/usr/lib
      "
      Done running configuration tests.
      Creating qmake...
      make[1]: Entering directory '/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake'
      g++ -c -o project.o -pipe -ffunction-sections -O2 -g  -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/library -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/generators -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/generators/unix -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/generators/win32 -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/generators/mac -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/generators/integrity -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/include -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/include/QtCore -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/include/QtCore/5.6.2 -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/include/QtCore/5.6.2/QtCore -I../src/corelib/global -DHAVE_QCONFIG_CPP -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/mkspecs/linux-g++ -I/var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/tools/shared -DQT_VERSION_STR=\"5.6.2\" -DQT_VERSION_MAJOR=5 -DQT_VERSION_MINOR=6 -DQT_VERSION_PATCH=2 -DQT_BUILD_QMAKE -DQT_BOOTSTRAPPED -DPROEVALUATOR_FULL -DQT_NO_TEXTCODEC -DQT_NO_UNICODETABLES -DQT_NO_COMPONENT -DQT_NO_COMPRESS -DQT_NO_THREAD -DQT_NO_QOBJECT -DQT_NO_GEOM_VARIANT -DQT_NO_DATASTREAM -DQT_CRYPTOGRAPHICHASH_ONLY_SHA1 -DQT_JSON_READONLY -DQT_NO_STANDARDPATHS /var/lib/jenkins/workspace/top_project/sub_project/ver_4.7.3/output/build/qt5base-5.6.2/qmake/project.cpp
      [... snip ...]
      

      Specifically, notice the output above includes a "tail: jenkins-log.txt: file truncated" message (this was part of the "saved_log.txt" file, created using the tail command above).

       

      Qt 5.6.2 is being built from buildroot, and it always seems to reset/truncate at the same point in the build - I'm not sure if that's relevant, or just coincidental.

       

      The size of the log at this point is roughly 40MB.

       

      I've also seen JENKINS-29198, and don't know if this is related, but since I'm specifically looking at the durable jenkins-log.txt file I decided to create a new Jira case.

       

      I'm pretty new to Jenkins as it is, and don't really understand the inner workings, so I'm hoping someone else has a clue.

       

      I'm also not sure how to proceed at this point.  I'm happy to help test/debug/verify any thoughts/ideas anyone may have.

       

        Attachments

          Activity

          Hide
          bmoyle Brian Moyle added a comment -

          Jesse Glick - I was curious if I could intentionally reset stdout (without any leading NUL bytes as well).

          (honestly, before this issue, I didn't even know this was possible - just thought I'd share the results)

          $ cat << EOF > your-program.c
          #include <stdio.h>
          #include <unistd.h>
          
          int main(void)
          {
             printf("hello\n");
             printf("world\n");
             rewind(stdout);
             ftruncate(1,0);
             printf("doh!\n");
          }
          EOF
          $ make your-program
          $ ./your-program > your-program.out
          $ hexdump -C your-program.out
          00000000  64 6f 68 21 0a                                    |doh!.|
          00000005
          $ ./your-program | cat
          hello
          world
          doh!
          $ 
          

          Not sure it's a good argument for piping durable task output elsewhere first, but it's interesting nonetheless.

          Show
          bmoyle Brian Moyle added a comment - Jesse Glick - I was curious if I could intentionally reset stdout (without any leading NUL bytes as well). (honestly, before this issue, I didn't even know this was possible - just thought I'd share the results) $ cat << EOF > your-program.c #include <stdio.h> #include <unistd.h> int main(void) { printf("hello\n"); printf("world\n"); rewind(stdout); ftruncate(1,0); printf("doh!\n"); } EOF $ make your-program $ ./your-program > your-program.out $ hexdump -C your-program.out 00000000  64 6f 68 21 0a                                    |doh!.| 00000005 $ ./your-program | cat hello world doh! $ Not sure it's a good argument for piping durable task output elsewhere first, but it's interesting nonetheless.
          Hide
          jglick Jesse Glick added a comment -

          In the first case the aggregated log file actually starts with 12 NUL bytes, where hello\nworld\n should have been. I guess the combination of /dev/std* pseudo-files and stream redirection wreaks havoc somewhere, though I do not understand it exactly.

          Show
          jglick Jesse Glick added a comment - In the first case the aggregated log file actually starts with 12 NUL bytes, where hello\nworld\n should have been. I guess the combination of /dev/std* pseudo-files and stream redirection wreaks havoc somewhere, though I do not understand it exactly.
          Hide
          bmoyle Brian Moyle added a comment -

          btw, if you pipe the above script through "cat" first, you can see a difference:

          $ (sh your-script 2>&1 | cat) > some-log-file.out 2>&1
          $ cat some-log-file.out
          hello
          world
          doh!
          $ 
          
          Show
          bmoyle Brian Moyle added a comment - btw, if you pipe the above script through "cat" first, you can see a difference: $ (sh your-script 2>&1 | cat) > some-log-file.out 2>&1 $ cat some-log-file.out hello world doh! $
          Hide
          bmoyle Brian Moyle added a comment -

          Jesse Glick, I don't claim to understand the details, but I suspect it's a variation on this:

          $ cat << EOF > your-script
          echo "hello"
          echo "world"
          echo -n "" | tee /dev/stderr
          echo "doh!"
          EOF
          $ sh your-script > some-log-file.out 2>&1
          $ cat some-log-file.out
          doh!
          $ 
          
          Show
          bmoyle Brian Moyle added a comment - Jesse Glick , I don't claim to understand the details, but I suspect it's a variation on this: $ cat << EOF > your-script echo "hello" echo "world" echo -n "" | tee /dev/stderr echo "doh!" EOF $ sh your-script > some-log-file.out 2>&1 $ cat some-log-file.out doh! $
          Hide
          jglick Jesse Glick added a comment -

          OK? I am not sure what the effect of using things like /dev/stderr would be, as the durable task wrapper script effectively does something like

          sh your-script > some-log-file.txt 2>&1
          
          Show
          jglick Jesse Glick added a comment - OK? I am not sure what the effect of using things like /dev/stderr would be, as the durable task wrapper script effectively does something like sh your-script > some-log-file.txt 2>&1

            People

            • Assignee:
              Unassigned
              Reporter:
              bmoyle Brian Moyle
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: