Hello everyone, I’m new to the list even though I’ve been a Java web developer for many years, I’ve never had the need to post here, but this time I think I may have stumbled upon a bug, and nothing turns up online on this issue.
We’re migrating our containerized legacy webapps from Java 8/11 to Java 17. They all ran on Tomcat 8.5, now we’re upgrading to 9. We customize a base image from tomcat:9.0.80-jdk17-temurin-focal. Amongst other things, we add a logging.properties to customize tomcat’s log format. This always worked well, but after our upgrade to Java 17, there’s a weird behavior that has stumped us. During Tomcat’s startup, the logs are formatted correctly as we specify in logging.properties. However, after a certain point in the logs, the logs revert to the “default” JUL/JULI format. Apart from this, everything works as expected. But we need the formatted logs because we parse them with LogStash and OpenSearch. Here’s an excerpt of the logs when this happens: local-corporativo-comum-1 | 2023-09-27T18:57:34.188 INFO [org.apache.coyote.http11.Http11NioProtocol] (thread-1) Initializing ProtocolHandler ["http-nio-8080"] local-corporativo-comum-1 | 2023-09-27T18:57:34.266 INFO [org.apache.catalina.startup.Catalina] (thread-1) Server initialization in [3419] milliseconds local-corporativo-comum-1 | 2023-09-27T18:57:34.606 INFO [com.hazelcast.config.UrlXmlConfig] (thread-1) Configuring Hazelcast from 'file:/usr/local/tomcat/conf/hazelcast-local.xml'. local-corporativo-comum-1 | 2023-09-27T18:57:36.775 INFO [org.apache.catalina.core.StandardService] (thread-1) Starting service [Catalina] local-corporativo-comum-1 | 2023-09-27T18:57:36.789 INFO [org.apache.catalina.core.StandardEngine] (thread-1) Starting Servlet engine: [Secure Web Server] local-corporativo-comum-1 | 2023-09-27T18:57:36.863 INFO [org.apache.catalina.startup.HostConfig] (thread-1) Diretório de instalação da aplicação web [/usr/local/tomcat/webapps/corporativo-comum] local-corporativo-comum-1 | 2023-09-27T18:57:52.647 INFO [br.leg.senado.util.tomcat.DataSourceFactory] (thread-1) Criando instância do datasource corporativo-comumDS local-corporativo-comum-1 | set. 27, 2023 6:57:55 PM br.leg.senado.util.tomcat.DataSourceFactory getObjectInstance local-corporativo-comum-1 | INFORMAÇÕES: Criando instância do datasource monitoraaplDS local-corporativo-comum-1 | set. 27, 2023 6:57:55 PM org.apache.catalina.core.ApplicationContext log local-corporativo-comum-1 | INFORMAÇÕES: 1 Spring WebApplicationInitializers detected on classpath local-corporativo-comum-1 | set. 27, 2023 6:57:55 PM org.apache.catalina.core.ApplicationContext log local-corporativo-comum-1 | INFORMAÇÕES: Initializing Spring root WebApplicationContext local-corporativo-comum-1 | 18:57:55.751 [main] INFO org.springframework.web.context.ContextLoader - Root WebApplicationContext: initialization started The red text is tomcat logging using the defaults (which localize log levels to our locale which is pt-br). I suspect that the point where this happens is when the webapp is being initialized. A webapp shouldn’t be able to interfere with Tomcat’s log behavior, right? The webapp does not use JUL, it uses logback, and it logs correctly during and after its startup. The logs you see @ 18:57:52 that says “Criando instância...” are of custom datasource resources specified in a context.xml file. They have a custom factory class, passed from a custom jar in tomcat's class path. This jar has worked and logged correctly since ever, we didn’t even recompile them to Java 17, we kept them as they were (Java 8). I’ve tried changing the way this component logs, by calling org.apache.juli instead of java.util.logging, removed all logging whatsoever, but nothing changes this behavior. Any suggestions on debugging this? If you need more info don’t hesitate to ask. Thanks in advance for any help on this.
