Announcement

Collapse
No announcement yet.
X
  • Filter
  • Time
Clear All
new posts

    Warning/Error Messages Missing Stack Trace

    Enterprise edition 14.1-p20251203

    We had a bug in one of our production instances where we got a NullPointerException during a datasource operation. It looks like the NullPointer was received from the framework, but there's no stack trace from the logs or anything so it's difficult to diagnose what the issue was.

    Here's the log messages we received:

    Code:
    2026-01-19 13:06:01.204 WARN com.isomorphic.datasource.DSRequest: - 696e2c37000000005df60369f374bd97 8145044541552649700 - Caught Exception trying to derive requestMaxRows java.lang.NullPointerException
    2026-01-19 13:06:01.205 WARN  com.isomorphic.sql.SQLTransform: - 696e2c37000000005df60369f374bd97 8145044541552649700 - Crashed trying to getObject for column documentId
    2026-01-19 13:06:01.211 WARN com.isomorphic.datasource.DSRequest: - 696e2c37000000005df60369f374bd97 8145044541552649700 - Exception trying to getDataSource() java.lang.NullPointerException
    2026-01-19 13:06:01.212 ERROR com.example.server.services.impl.ProposalGeneratorServiceImpl:200 - 696e2c37000000005df60369f374bd97 8145044541552649700 - java.lang.NullPointerException
    com.example.exceptionhandling.core.ApplicationException: java.lang.NullPointerException
        at com.example.server.services.impl.ProposalGeneratorServiceImpl.saveProposalAfterProposalGeneration(ProposalGeneratorServiceImpl.java:120)
        at com.example.server.services.impl.ProposalGeneratorServiceImpl.lambda$generateChangeProposal$0(ProposalGeneratorServiceImpl.java:198)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:545)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:328)
        at com.example.server.Config.lambda$taskDecorator$1(Config.java:153)
        at java.base/java.lang.VirtualThread.run(VirtualThread.java:456)
    Caused by: java.lang.NullPointerException
    Not really sure where to go from this one, difficult to diagnose these warning messages, they're not giving us much context.

    #2
    The reason you're not seeing stack traces is that your log4j configuration uses a custom pattern that doesn't include %throwable. Your log format differs from our default (different timestamp format, full class names, etc.), so you've customized it.

    For an immediate fix to get a stack trace, add %throwable to your PatternLayout pattern, e.g.:

    Code:
      <PatternLayout pattern="%d %-5p %c - %m%throwable%n" />
    Going forward, we've improved the framework so that when getDataSource() fails, the stack trace is now embedded directly in the log message itself. This means you'll see full diagnostics regardless of your log4j pattern configuration. This fix will be in the next nightly build.

    Comment


      #3
      We have customized the format, but we see stack traces, there's one in my example.

      From the documentation: https://logging.apache.org/log4j/2.x...rn-layout.html

      Click image for larger version

Name:	Screenshot 2026-01-22 at 12.05.11 PM.png
Views:	13
Size:	6.4 KB
ID:	277050
      Here's an example from the same system for a log message from a com.isomorphic* logger:

      Code:
      2026-01-22 05:42:33.678 user= ERROR com.isomorphic.compression.Compression: - 6971b8c9000000005b46fe3b0433374b 4808535600247817658 - Caught exception in doFilter() - for URI: /
      java.lang.IllegalArgumentException: Illegal character in query at index 24: https://54.144.185.122/?{alert(document.domain)}
          at java.base/java.net.URI.create(URI.java:936)
          at org.jboss.resteasy.specimpl.ResteasyUriInfo.getRequestUri(ResteasyUriInfo.java:317)
          at org.jboss.resteasy.core.providerfactory.DefaultExceptionMapper.process(DefaultExceptionMapper.java:78)
          at org.jboss.resteasy.core.providerfactory.DefaultExceptionMapper.toResponse(DefaultExceptionMapper.java:55)
          at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:353)
          at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:205)
          at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invokePropagateNotFound$6(SynchronousDispatcher.java:270)
          at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
          at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:333)
          at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
          at org.jboss.resteasy.core.SynchronousDispatcher.invokePropagateNotFound(SynchronousDispatcher.java:260)
          at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:224)
          at org.jboss.resteasy.plugins.server.servlet.FilterDispatcher.doFilter(FilterDispatcher.java:62)
          at org.eclipse.jetty.ee11.servlet.FilterHolder.doFilter(FilterHolder.java:205)
          at org.eclipse.jetty.ee11.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1640)
          at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:108)
          at org.springframework.security.web.FilterChainProxy.lambda$doFilterInternal$3(FilterChainProxy.java:235)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:371)
          at org.springframework.security.web.access.intercept.AuthorizationFilter.doFilter(AuthorizationFilter.java:101)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:126)
          at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:120)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:100)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:181)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.authentication.ui.DefaultLogoutPageGeneratingFilter.doFilterInternal(DefaultLogoutPageGeneratingFilter.java:60)
          at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.authentication.ui.DefaultLoginPageGeneratingFilter.doFilter(DefaultLoginPageGeneratingFilter.java:246)
          at org.springframework.security.web.authentication.ui.DefaultLoginPageGeneratingFilter.doFilter(DefaultLoginPageGeneratingFilter.java:232)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.authentication.ui.DefaultResourcesFilter.doFilter(DefaultResourcesFilter.java:73)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:245)
          at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:239)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.oauth2.client.web.OAuth2AuthorizationRequestRedirectFilter.doFilterInternal(OAuth2AuthorizationRequestRedirectFilter.java:195)
          at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110)
          at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:96)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:118)
          at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
          at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
          at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.context.SecurityContextHolderFilter.doFilter(SecurityContextHolderFilter.java:82)
          at org.springframework.security.web.context.SecurityContextHolderFilter.doFilter(SecurityContextHolderFilter.java:69)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:62)
          at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42)
          at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
          at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
          at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:237)
          at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:195)
          at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113)
          at org.springframework.web.filter.ServletRequestPathFilter.doFilter(ServletRequestPathFilter.java:52)
          at org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113)
          at org.springframework.web.filter.CompositeFilter.doFilter(CompositeFilter.java:74)
          at org.springframework.security.config.annotation.web.configuration.WebSecurityConfiguration$CompositeFilterChainProxy.doFilter(WebSecurityConfiguration.java:317)
          at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:355)
          at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:272)
          at org.eclipse.jetty.ee11.servlet.FilterHolder.doFilter(FilterHolder.java:205)
          at org.eclipse.jetty.ee11.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1640)
          at com.isomorphic.servlet.CompressionFilter._doFilter(CompressionFilter.java:263)
          at com.isomorphic.servlet.BaseFilter.doFilter(BaseFilter.java:91)
          at org.eclipse.jetty.ee11.servlet.FilterHolder.doFilter(FilterHolder.java:208)
          at org.eclipse.jetty.ee11.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1640)
          at org.eclipse.jetty.ee11.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:199)
          at org.eclipse.jetty.ee11.servlet.FilterHolder.doFilter(FilterHolder.java:205)
          at org.eclipse.jetty.ee11.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1640)
          at org.eclipse.jetty.ee11.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1602)
          at org.eclipse.jetty.ee11.servlet.ServletChannel.dispatch(ServletChannel.java:868)
          at org.eclipse.jetty.ee11.servlet.ServletChannel.handle(ServletChannel.java:449)
          at org.eclipse.jetty.ee11.servlet.ServletHandler.handle(ServletHandler.java:470)
          at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:546)
          at org.eclipse.jetty.ee11.servlet.SessionHandler.handle(SessionHandler.java:763)
          at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1224)
          at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:148)
          at org.eclipse.jetty.server.Server.handle(Server.java:197)
          at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:720)
          at datadog.trace.instrumentation.jetty12.JettyRunnableWrapper.run(JettyRunnableWrapper.java:23)
          at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:412)
          at org.eclipse.jetty.server.internal.HttpConnection$FillableCallback.succeeded(HttpConnection.java:1810)
          at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
          at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:54)
          at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:492)
          at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.epcRunTask(AdaptiveExecutionStrategy.java:428)
          at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:401)
          at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:255)
          at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:204)
          at org.eclipse.jetty.util.thread.VirtualThreadPool.lambda$execute$0(VirtualThreadPool.java:276)
          at java.base/java.util.concurrent.ThreadPerTaskExecutor$TaskRunner.run(ThreadPerTaskExecutor.java:291)
          at java.base/java.lang.VirtualThread.run(VirtualThread.java:456)
      Caused by: java.net.URISyntaxException: Illegal character in query at index 24: https://54.144.185.122/?{alert(document.domain)}
          at java.base/java.net.URI$Parser.fail(URI.java:3003)
          at java.base/java.net.URI$Parser.checkChars(URI.java:3174)
          at java.base/java.net.URI$Parser.parseHierarchical(URI.java:3262)
          at java.base/java.net.URI$Parser.parse(URI.java:3204)
          at java.base/java.net.URI.<init>(URI.java:649)
          at java.base/java.net.URI.create(URI.java:934)
          ... 102 more
      Our current pattern is:

      Code:
      <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} user=%X{user.name} %-5p %c:%L - %X{dd.trace_id} %X{dd.span_id} - %m%n"/>

      Comment


        #4
        The difference here is whether we explicitly get the stack trace vs just hand the Throwable to log4j, such that log4j decides whether to output a stack trace.

        When we do this:

        Code:
        log.warn("Exception trying to getDataSource()", e);
        .. log4j decides whether to output a stacktrace, and you need %throwable% in there to see it.

        Elsewhere (and now in this spot) we do this:

        Code:
          log.warn("...message..." + ":\n" + DataTools.getStackTrace(e));
        And then you're going to see a stack trace no matter what pattern you use with log4j.

        Comment


          #5
          Right, we use the same coding standard for all of our exception handling:

          Code:
          log.error("error message", e);
          Always passing the exception to the logger.

          If our pattern didn't include the the "ex|exception|throwable" converter then we'd never see stack traces at all, but we do. I already pointed out that in the Log4j documentation, if there isn't a converter for the exception, they automatically parse the pattern appending "%n%ex" to the end of it, which is why we see exceptions, both from our code and the SmartGWT framework.

          Comment


            #6
            That's a good pattern, and we agree that from what you've told us about your log4j config, you would expect to see a stack trace. However, you are not.

            And as far as the code that generated these logs:

            2026-01-19 13:06:01.204 WARN com.isomorphic.datasource.DSRequest: - 696e2c37000000005df60369f374bd97 8145044541552649700 - Caught Exception trying to derive requestMaxRows java.lang.NullPointerException 2026-01-19 13:06:01.205 WARN com.isomorphic.sql.SQLTransform: - 696e2c37000000005df60369f374bd97 8145044541552649700 - Crashed trying to getObject for column documentId 2026-01-19 13:06:01.211 WARN com.isomorphic.datasource.DSRequest: - 696e2c37000000005df60369f374bd97 8145044541552649700 - Exception trying to getDataSource() java.lang.NullPointerException
            Here's the diff of the changes we applied yesterday, to make it so you get a stack trace regardless of log4j's config. As you can see, before this change, we were already passing the exception.

            Code:
              } catch(Exception e) {
            - log.warn("Caught Exception trying to derive requestMaxRows", e);
            + log.warn("Caught Exception trying to derive requestMaxRows for DSRequest " + + "(dataSourceName: '" + getDataSourceName() + "', operationType: '" + + getOperationType() + "'):" + "\n" + DataTools.getStackTrace(e));
              }
            So, one way or another, log4j is squelching the stack trace - it could be something like a second config block somewhere with a subtly different output pattern or other setting.

            Anyway, from here you could either:

            1) keep working with the existing build, and try to figure out why log4j isn't outputting stack traces

            .. or ..

            2) grab the new build which explicitly logs the traces

            Note you probably want to eventually figure out #1, because we didn't change every single instance of this (valid!) pattern in the framework. So you may be missing other traces.

            Comment


              #7
              Ok thanks. We'll try the new build and see if anything is different about our config.

              Comment

              Working...
              X