Hi Christopher,

Thanks for the suggestion, we do add some jars to Tomcat lib (mainly 
Prometheus, Hazelcast)
I expanded every jar inside tomcat/lib and ran a find command.

root@05ae85e03d7d:/# find ./ -type f -name logging.properties
./usr/local/tomcat/conf/logging.properties
./opt/java/openjdk/conf/logging.properties

The only other logging.properties is the one from JDK. I tried changing its 
content just to see if that was what was being used, but it had no effect.

So the issue still remains, but we have worked around it by configuring tomcat 
to use log4j2 as per this documentation: 
https://logging.apache.org/log4j/2.x/log4j-appserver.html
 
With this and the log4j-jul bridge, all logs are now formatted correctly.

> Em 29 de set. de 2023, à(s) 08:56, Christopher Schultz 
> <ch...@christopherschultz.net> escreveu:
> 
> Alcides,
> 
> On 9/28/23 14:55, Alcides Moraes wrote:
>> 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.
> 
> I feel like I've heard of things like this happening before. It had something 
> to do with an application re-initializing and having a private 
> logging.properties file which ended up updating the global logging 
> configuration.
> 
> Can you search the entire (container's) disk for logging.properties files 
> /and also all the JAR files you are using/ to see if there is a stray file 
> somewhere that could be picked-up at some point after initial boot?
> 
> -chris
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
> 

Reply via email to