[logback-user] logback ignores my logger/level config

[Eric Swenson]

I have a utility (written in Scala and built with SBT) that includes a logback.xml:

<configuration debug="true">
    <appender name="STDOUT"
              class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{ISO8601} | %-5level | %thread | %logger{1} | %m%n</pattern>
        </encoder>
    </appender>

    <logger name="com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder" level="ERROR" />
    <logger name="com.typesafe.sslconfig.ssl.AlgorithmChecker" level="ERROR" />

    <root level="ERROR">
        <appender-ref ref="STDOUT" />
    </root>

</configuration>

I added the ‘debug=“true”’ to help me diagnose why, despite the <logger/> elements that attempt to set the loglevel of log messages from the packages defined in the “name” attribute to “ERROR”, I’m seeing “WARN” messages in the console output when I run the command.  I fragment of the first few lines of output appears below:

java -jar xxx.jar <arguments>
[WARN] [07/25/2017 17:05:59.490] [main] [com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder] validateStore: Skipping certificate with weak key size in thawtepremiumserverca: Certificate failed: cert = "1.2.840.113549.1.9.1=#16197072656d69756d2d736572766572407468617774652e636f6d,CN=Thawte Premium Server CA,OU=Certification Services Division,O=Thawte Consulting cc,L=Cape Town,ST=Western Cape,C=ZA" failed on constraint RSA keySize < 2048, algorithm = RSA, keySize = 1024
[WARN] [07/25/2017 17:05:59.490] [main] [com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder] validateStore: Skipping certificate with weak key size in thawteserverca: Certificate failed: cert = "1.2.840.113549.1.9.1=#16177365727665722d6365727473407468617774652e636f6d,CN=Thawte Server CA,OU=Certification Services Division,O=Thawte Consulting cc,L=Cape Town,ST=Western Cape,C=ZA" failed on constraint RSA keySize < 2048, algorithm = RSA, keySize = 1024
….
[WARN] [07/25/2017 17:05:59.500] [main] [com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder] validateStore: Skipping certificate with weak key size in verisignclass1g2ca: Certificate failed: cert = "OU=VeriSign Trust Network,OU=(c) 1998 VeriSign\, Inc. - For authorized use only,OU=Class 1 Public Primary Certification Authority - G2,O=VeriSign\, Inc.,C=US" failed on constraint RSA keySize < 2048, algorithm = RSA, keySize = 1024
17:05:59,530 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
17:05:59,530 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
17:05:59,530 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/Users/eswenson/Projects/Modulus/ws/modulus-shared-libraries/modules/dataset-client-cli/target/scala-2.11/dataset-client-cli-assembly-1.0.dev.jar!/logback.xml]
17:05:59,540 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList at 257cc1fc - URL [jar:file:/Users/eswenson/Projects/Modulus/ws/modulus-shared-libraries/modules/dataset-client-cli/target/scala-2.11/dataset-client-cli-assembly-1.0.dev.jar!/logback.xml] is not of type file
17:05:59,584 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
17:05:59,586 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
17:05:59,616 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder] to ERROR
17:05:59,617 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.typesafe.sslconfig.ssl.AlgorithmChecker] to ERROR
17:05:59,617 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to ERROR
17:05:59,617 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
17:05:59,617 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
17:05:59,618 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator at 5a67e962 - Registering current configuration as safe fallback point
[WARN] [07/25/2017 17:05:59.830] [main] [com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder] validateStore: Skipping certificate with weak key size in thawtepremiumserverca: Certificate failed: cert = "1.2.840.113549.1.9.1=#16197072656d69756d2d736572766572407468617774652e636f6d,CN=Thawte Premium Server CA,OU=Certification Services Division,O=Thawte Consulting cc,L=Cape Town,ST=Western Cape,C=ZA" failed on constraint RSA keySize < 2048, algorithm = RSA, keySize = 1024
…
<command output>

There of two things of note in the output above:  there are log messages that appear BEFORE we see the logging output due to the logback “debug=true” option.  Second, we see many of these WARN messages from com.typesafe.sslconfig.ssl.ConfigSSLContextBuilder both before and after the logback debug output.

Why is logback not suppressing the [WARN] messages?  

The com.typesafe.sslconfig.ssl code uses akka.event.Logging. I’ve tried to look into this code, and quickly got lost.  I’m not sure what low-level logging this package is using, but whatever it is, it isn’t being captured by logback.  
I suspect I need to use some logback bridge, although I’ve tried various and get errors that I have multiple slf4j providers and it makes no difference to the logging output.

How do I track down what is going on here?

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20170725/27a19a13/attachment.html>