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

slave.jar -loggingConfig argument not working as documented

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Minor
    • Resolution: Fixed
    • Component/s: remoting
    • Labels:
    • Environment:
      slave.jar version 3.14
      Slaves connecting via JNLP, launched from a script.
      Custom logging.properties file provided.
      (also, my slaves were on Windows, but this might be platform-agnostic)
    • Similar Issues:
    • Released As:
      Remoting 3.30, Jenkins 2.176

      Description

      TL;DR: -loggingConfig doesn't work; Workaround is to use -Djava.util.logging.config.file.

      Long version: 
      While trying to track down mysterious slave disconnects, I needed more logging than slave.jar provided by default so, after discovering the documentation I created a file "jenkins-slave.logging.properties" containing all the java.util.logging properties that I wanted set (logging more finely, and to both the console and logfiles).
      I then invoked the slave.jar with the argument -loggingConfig jenkins-slave.logging.properties.
      However, the console output from slave.jar was unaffected.
      What I expected was that the logging would be configured according to my properties file, (but it wasn't).

      I investigated and discovered that if, instead, I provide a JVM argument of -Djava.util.logging.config.file=jenkins-slave.logging.properties then that worked perfectly.

      I also found that, if I did both then org.jenkinsci.remoting.engine.WorkDirManager's setupLogging method logged a FINE message of "Reading Logging configuration from file: jenkins-slave.logging.properties", implying that the -loggingConfig argument is being passed through correctly.

      i.e. the CLI argument parsing is working, and the configuration is getting as far as WorkDirManager, but whatever is being done with it doesn't have the desired/expected effect.

      What I would expect is that passing in a -loggingConfig argument would be (nearly) functionally identical to using -Djava.util.logging.config.file. While I would expect that anything logged before "Reading Logging configuration from file: jenkins-slave.logging.properties" would be logged with the default logging configuration (as mentioned in the docs), I would expect all subsequent logging to use the specified configuration not the default, and that's what doesn't seem to be happening.

        Attachments

          Activity

          Hide
          jthompson Jeff Thompson added a comment -

          Thanks for the clear issue report.

          However, I haven't been able to reproduce the issue. I have Remoting 3.23 in this instance and it seems to work fine with the "-loggingConfig" parameter. My agent is also on Windows.

           

          Show
          jthompson Jeff Thompson added a comment - Thanks for the clear issue report. However, I haven't been able to reproduce the issue. I have Remoting 3.23 in this instance and it seems to work fine with the "-loggingConfig" parameter. My agent is also on Windows.  
          Hide
          wbrode William Brode added a comment -

          Jeff Thompson, how did you test this?  I just cloned the repo and tried to debug and found that -loggingConfig just doesn't work at all.  The tests work because they bypass the Launcher (wherein the problem resides).  So I'm wondering if you were just trying to reproduce using the maven tests?  In any case I'll fork the repo and do a pull request with what I think is the fix.

          Show
          wbrode William Brode added a comment - Jeff Thompson , how did you test this?  I just cloned the repo and tried to debug and found that -loggingConfig just doesn't work at all.  The tests work because they bypass the Launcher (wherein the problem resides).  So I'm wondering if you were just trying to reproduce using the maven tests?  In any case I'll fork the repo and do a pull request with what I think is the fix.
          Hide
          jthompson Jeff Thompson added a comment -

          I tested it with a Jenkins instance running on Mac and an agent on Windows. I tried to follow the documentation and the defect report, though I don't recall the details now. Things seemed to work the way I expected.

          If you could file a PR that would be great.

          Show
          jthompson Jeff Thompson added a comment - I tested it with a Jenkins instance running on Mac and an agent on Windows. I tried to follow the documentation and the defect report, though I don't recall the details now. Things seemed to work the way I expected. If you could file a PR that would be great.
          Hide
          pjdarton pjdarton added a comment -

          FYI, since I originally logged this bug, I uploaded the script that I use to run slave.jar onto the Jenkins wiki (as an example JNLP launcher script for use with the vSphere plugin, as folks kept getting stuck on this bit).
          This script shows how I was invoking slave.jar, which should help with reproducing the bug (if the bug is still present in the current version of the code).

          You can find it by going to the vSphere Cloud Plugin wiki page and looking for JenkinsSlaveStartup.cmd. That has a line (485) saying

          @SET _cmdLine=%JAVA_HOME%bin\java -Djava.util.logging.config.file=jenkins-slave.logging.properties %SLAVE_JVM_ARGS% -jar slave.jar -jnlpUrl %SLAVE_JNLP_URL% %SLAVE_PARAMS%
          

          where SLAVE_JVM_ARGS are typically "-Xms256M -Xmx4096M -Dhudson.remoting.RemoteClassLoader.force=com.sun.jna.Native", the SLAVE_JNLP_URL is what you'd expect and SLAVE_PARAMS typically contains "{{-secret }}...." and little else.
          ...and the next but-one line runs %_cmdLine% to invoke .../bin/java ... -jar slave.jar ...

          Show
          pjdarton pjdarton added a comment - FYI, since I originally logged this bug, I uploaded the script that I use to run slave.jar onto the Jenkins wiki (as an example JNLP launcher script for use with the vSphere plugin, as folks kept getting stuck on this bit). This script shows how I was invoking slave.jar, which should help with reproducing the bug (if the bug is still present in the current version of the code). You can find it by going to the vSphere Cloud Plugin wiki page and looking for JenkinsSlaveStartup.cmd . That has a line (485) saying @SET _cmdLine=%JAVA_HOME%bin\java -Djava.util.logging.config.file=jenkins-slave.logging.properties %SLAVE_JVM_ARGS% -jar slave.jar -jnlpUrl %SLAVE_JNLP_URL% %SLAVE_PARAMS% where SLAVE_JVM_ARGS are typically " -Xms256M -Xmx4096M -Dhudson.remoting.RemoteClassLoader.force=com.sun.jna.Native ", the SLAVE_JNLP_URL is what you'd expect and SLAVE_PARAMS typically contains "{{-secret }}...." and little else. ...and the next but-one line runs %_cmdLine% to invoke .../bin/java ... -jar slave.jar ...
          Hide
          wbrode William Brode added a comment -

          I've submitted a PR for the fix:

          https://github.com/jenkinsci/remoting/pull/317

          Show
          wbrode William Brode added a comment - I've submitted a PR for the fix: https://github.com/jenkinsci/remoting/pull/317
          Hide
          pjdarton pjdarton added a comment -

          Thanks for investigating and getting to the bottom of this

          Show
          pjdarton pjdarton added a comment - Thanks for investigating and getting to the bottom of this

            People

            • Assignee:
              wbrode William Brode
              Reporter:
              pjdarton pjdarton
            • Votes:
              1 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: