quarkiverse / quarkus-logging-logback

Quarkus Logback extension
Apache License 2.0
13 stars 13 forks source link

NPE if Declaring class is null #157

Open leotu opened 11 months ago

leotu commented 11 months ago

When integrate quarkus-logging-logback + loki-logback-appender

Quarkus It occurs when "quarkus.console.color=true" the caller class name and method name maybe null, and LoggingEventWrapper.java trigger StackTraceElement.java constrcutor method raise NPE. "Objects.requireNonNull(...)"

Console log

=> format: "%d{HH:mm:ss.SSS} %-5p [${quarkus.profile}] [%t] [%C{0.}.%M():%L] %s%e%n" => log e.g. "11:08:46.617 INFO [dev] [Quarkus Main Thread] [null.null():-1] QuarkusMain main method"

11:08:46,815 |-INFO in io.quarkiverse.logback.runtime.LogbackRecorder$1@61cac409 - Registering current configuration as safe fallback point

__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
11:08:46.617 INFO  [dev] [Quarkus Main Thread] [null.null():-1] QuarkusMain main method
11:08:47,139 |-ERROR in ch.qos.logback.core.rolling.RollingFileAppender$$delayed[FILE] - Appender [FILE] failed to append. java.lang.NullPointerException: Declaring class is null
    at java.lang.NullPointerException: Declaring class is null
    at  at java.base/java.util.Objects.requireNonNull(Objects.java:233)
    at  at java.base/java.lang.StackTraceElement.<init>(StackTraceElement.java:162)
    at  at io.quarkiverse.logback.runtime.LoggingEventWrapper.getCallerData(LoggingEventWrapper.java:93)
    at  at ch.qos.logback.classic.pattern.ClassOfCallerConverter.getFullyQualifiedName(ClassOfCallerConverter.java:24)
    at  at ch.qos.logback.classic.pattern.NamedConverter.convert(NamedConverter.java:106)
    at  at ch.qos.logback.classic.pattern.NamedConverter.convert(NamedConverter.java:38)
    at  at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
    at  at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:116)
    at  at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:176)
    at  at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:39)
    at  at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(LayoutWrappingEncoder.java:114)
    at  at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:192)
    at  at ch.qos.logback.core.FileAppender.writeOut(FileAppender.java:247)
    at  at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:237)
    at  at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:253)
    at  at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
    at  at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:85)
    at  at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
    at  at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272)
    at  at ch.qos.logback.classic.Logger.callAppenders(Logger.java:259)
    at  at io.quarkiverse.logback.runtime.LogbackRecorder$3.doPublish(LogbackRecorder.java:155)
    at  at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:88)
    at  at org.jboss.logmanager.ExtHandler.publishToNestedHandlers(ExtHandler.java:122)
    at  at io.quarkus.bootstrap.logging.QuarkusDelayedHandler.activate(QuarkusDelayedHandler.java:292)
    at  at io.quarkus.bootstrap.logging.QuarkusDelayedHandler.setHandlers(QuarkusDelayedHandler.java:189)
    at  at io.quarkus.runtime.logging.LoggingSetupRecorder.initializeLogging(LoggingSetupRecorder.java:271)
    at  at io.quarkus.deployment.steps.LoggingResourceProcessor$setupLoggingRuntimeInit1899082837.deploy_0(Unknown Source)
    at  at io.quarkus.deployment.steps.LoggingResourceProcessor$setupLoggingRuntimeInit1899082837.deploy(Unknown Source)
    at  at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
    at  at io.quarkus.runtime.Application.start(Application.java:101)
    at  at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
    at  at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)

java.lang.StackTraceElement.java

https://github.com/openjdk/jdk17/blob/master/src/java.base/share/classes/java/lang/StackTraceElement.java#L162

Exception

 this.declaringClass  = Objects.requireNonNull(declaringClass, "Declaring class is null");
 this.methodName      = Objects.requireNonNull(methodName, "Method name is null");
  /**
     * Creates a stack trace element representing the specified execution
     * point.
     * ...
     *
     * @throws NullPointerException if {@code declaringClass} is {@code null}
     *         or {@code methodName} is {@code null}
     *
     * @since 9
     */
    public StackTraceElement(String classLoaderName,
                             String moduleName, String moduleVersion,
                             String declaringClass, String methodName,
                             String fileName, int lineNumber) {
        this.classLoaderName = classLoaderName;
        this.moduleName      = moduleName;
        this.moduleVersion   = moduleVersion;
        this.declaringClass  = Objects.requireNonNull(declaringClass, "Declaring class is null");
        this.methodName      = Objects.requireNonNull(methodName, "Method name is null");
        this.fileName        = fileName;
        this.lineNumber      = lineNumber;
    }
...

io.quarkiverse.logback.runtime.LoggingEventWrapper.java

https://github.com/quarkiverse/quarkus-logging-logback/blob/main/impl/runtime/src/main/java/io/quarkiverse/logback/runtime/LoggingEventWrapper.java#L90

Return null value

  logRecord.getSourceClassName(),
  logRecord.getSourceMethodName(),
   ...
  @Override
    public StackTraceElement[] getCallerData() {
        if (callerData == null) {
            callerData = new StackTraceElement[] {
                    new StackTraceElement(
                            null,
                            logRecord.getSourceModuleName(),
                            logRecord.getSourceModuleVersion(),
                            logRecord.getSourceClassName(),
                            logRecord.getSourceMethodName(),
                            logRecord.getSourceFileName(),
                            logRecord.getSourceLineNumber())
            };
        }
        return callerData;
    }
 ...

Expect adding judgment

     logRecord.getSourceClassName() == null ? "null" :  logRecord.getSourceClassName(),
     logRecord.getSourceMethodName() == null ? "null" :  logRecord.getSourceMethodName(),
@Override
    public StackTraceElement[] getCallerData() {
        if (callerData == null) {
            callerData = new StackTraceElement[] {
                    new StackTraceElement(
                            null,
                            logRecord.getSourceModuleName(),
                            logRecord.getSourceModuleVersion(),
                            logRecord.getSourceClassName() == null ? "null" : logRecord.getSourceClassName(),
                           logRecord.getSourceMethodName() == null ? "null" :  logRecord.getSourceMethodName(),
                            logRecord.getSourceFileName(),
                            logRecord.getSourceLineNumber())
            };
        }
        return callerData;
    }

Console ScreenShot

ScreenShot

Reproduction Project

logback-with-quarkus.zip