Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-14319

[GSS](7.2.0) Amend NullPointerException in RegexFilter.isLoggable()

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Won't Do
    • Icon: Major Major
    • None
    • 7.1.0.GA
    • Logging
    • Hide
      • Unzip/Build attached helloworld-null-message-Exception.zip (mvn clean package)
      • Add a filter-spec in standalone.xml
                <subsystem xmlns="urn:jboss:domain:logging:3.0">
                    <console-handler name="CONSOLE">
                        <level name="INFO"/>
                        <filter-spec value="not(match(&quot;SOME_MESSAGE&quot;))"/>
                        <formatter>
        ...
        
      • Start EAP
      • Deploy helloworld-1.0.0.war
      • Access to http://localhost:8080/helloworld-1.0.0/hello

      Expected) Stacktrace is logged

      15:17:59,433 ERROR [org.example.HelloWorldServlet] (default task-1) null: java.lang.Exception
      	at org.example.HelloWorldServlet.doGet(HelloWorldServlet.java:28)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
      	at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
      	at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
      	at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
      	at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
      	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      	at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
      	at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
      	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      	at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
      	at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
      	at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
      	at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
      	at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
      	at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
      	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      	at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
      	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      	at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
      	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
      	at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
      	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
      	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
      	at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
      	at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
      	at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
      	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
      	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
      	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
      	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508)
      	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
      	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
      	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
      	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:326)
      	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      
      15:17:59,436 ERROR [stderr] (default task-1) *** Exception stacktrace should be logged above ***
      

      Actual) No stacktrace logged

      15:17:59,436 ERROR [stderr] (default task-1) *** Exception stacktrace should be logged above ***
      
      Show
      Unzip/Build attached helloworld-null-message-Exception.zip (mvn clean package) Add a filter-spec in standalone.xml <subsystem xmlns= "urn:jboss:domain:logging:3.0" > <console-handler name= "CONSOLE" > <level name= "INFO" /> <filter-spec value= "not(match(&quot;SOME_MESSAGE&quot;))" /> <formatter> ... Start EAP Deploy helloworld-1.0.0.war Access to http://localhost:8080/helloworld-1.0.0/hello Expected) Stacktrace is logged 15:17:59,433 ERROR [org.example.HelloWorldServlet] (default task-1) null: java.lang.Exception at org.example.HelloWorldServlet.doGet(HelloWorldServlet.java:28) at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60) at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77) at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50) at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292) at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135) at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48) at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272) at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:326) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 15:17:59,436 ERROR [stderr] (default task-1) *** Exception stacktrace should be logged above *** Actual) No stacktrace logged 15:17:59,436 ERROR [stderr] (default task-1) *** Exception stacktrace should be logged above ***

      When log message is null, RegexFilter.isLoggable() throws NullPointerException.

      https://github.com/jboss-logging/jboss-logmanager/blob/master/src/main/java/org/jboss/logmanager/filters/RegexFilter.java#L63

      It often results in unexpected outcomes. For example, assuming you have a filter-spec with "not(match(xxx))" to suppress some messages in your logger configuration:

          <subsystem xmlns="urn:jboss:domain:logging:3.0">
                  <console-handler name="CONSOLE">
                      <level name="INFO"/>
                      <filter-spec value="not(match(&quot;SOME_MESSAGE&quot;))"/>
                      <formatter>
                          <named-formatter name="COLOR-PATTERN"/>
                      </formatter>
                  </console-handler>
      

      and an application has a code like this:

              try {
                  ...
              } catch (Exception e) {
                  logger.error(e.getMessage(), e);
              }
      

      "e.getMessage()" could be null. But you want to log the stacktrace 'e' anyway.

      In this case, NullPointerException is thrown from RegexFilter and reaches to LoggerNode and disappears. ConsoleHandler cannot publish the log at all.

      https://github.com/jboss-logging/jboss-logmanager/blob/master/src/main/java/org/jboss/logmanager/LoggerNode.java#L317-L319

      I think 'null' message should simply return 'false' in RegexFilter.isLoggable().

              yborgess1@redhat.com Yeray Borges Santana
              rhn-support-tkobayas Toshiya Kobayashi
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: