You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Alcides Moraes <al...@gmail.com> on 2023/09/28 18:55:35 UTC
Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
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.
[#25519] Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Posted by "az.pl" <in...@az.pl>.
Nowe zgłoszenie w systemie: #25519
Data utworzenia: 2023-10-05
Temat: Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Hi Chris, We were already considering the jump to log4j for a number of reasons (Removal of an old custom formatter, adding BurstFilter) and the issue just made it easier. But I agree, the issue was not really solved, just worked around. It only happens when using JDK17 though, in either Tomcat 8.5 or 9. If you have any suggestions, I can check them out. Thanks for your help. > Em 2 de out. de 2023, à(s) 19:07, Christopher Schultz escreveu: > > Alcides, > > On 9/29/23 15:34, Alcides Moraes wrote: >> Forgot to expand the webapps/WEB-INF/lib jars as well… >> root@8ad4f1dcd125:/usr/local/tomcat# find ./ -type f -name logging.properties >> ./conf/logging.properties >> ./webapps/corporativo-comum/WEB-INF/lib/org/springframework/boot/logging/java/logging.properties >> So there’s springboot's logging.properties. Should it really affect tomcat’s logging? > > I wouldn't expect it to. But something is definitely triggering a re-load of the global logging configuration. > > If you have decided to move-on to log4j2, then that's great. But if you are only doing that because you can't explain what's happening, I think it would be better for you to track-down the root problem. If you don't track that down, you might be ignoring something important that really needs to get fixed. > > -chris > >>> Em 29 de set. de 2023, à(s) 16:18, Alcides Moraes escreveu: >>> >>> 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 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-unsubscribe@tomcat.apache.org >>>> For additional commands, e-mail: users-help@tomcat.apache.org >>>> >>> > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org > For additional commands, e-mail: users-help@tomcat.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org For additional commands, e-mail: users-help@tomcat.apache.org
---
Załączniki:
Re: Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Posted by Alcides Moraes <al...@gmail.com>.
Hi Chris,
We were already considering the jump to log4j for a number of reasons (Removal of an old custom formatter, adding BurstFilter)
and the issue just made it easier.
But I agree, the issue was not really solved, just worked around. It only happens when using JDK17 though, in either Tomcat 8.5 or 9.
If you have any suggestions, I can check them out.
Thanks for your help.
> Em 2 de out. de 2023, à(s) 19:07, Christopher Schultz <ch...@christopherschultz.net> escreveu:
>
> Alcides,
>
> On 9/29/23 15:34, Alcides Moraes wrote:
>> Forgot to expand the webapps/WEB-INF/lib jars as well…
>> root@8ad4f1dcd125:/usr/local/tomcat# find ./ -type f -name logging.properties
>> ./conf/logging.properties
>> ./webapps/corporativo-comum/WEB-INF/lib/org/springframework/boot/logging/java/logging.properties
>> So there’s springboot's logging.properties. Should it really affect tomcat’s logging?
>
> I wouldn't expect it to. But something is definitely triggering a re-load of the global logging configuration.
>
> If you have decided to move-on to log4j2, then that's great. But if you are only doing that because you can't explain what's happening, I think it would be better for you to track-down the root problem. If you don't track that down, you might be ignoring something important that really needs to get fixed.
>
> -chris
>
>>> Em 29 de set. de 2023, à(s) 16:18, Alcides Moraes <al...@gmail.com> escreveu:
>>>
>>> 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-unsubscribe@tomcat.apache.org
>>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>>
>>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Posted by Christopher Schultz <ch...@christopherschultz.net>.
Alcides,
On 9/29/23 15:34, Alcides Moraes wrote:
> Forgot to expand the webapps/WEB-INF/lib jars as well…
>
> root@8ad4f1dcd125:/usr/local/tomcat# find ./ -type f -name logging.properties
> ./conf/logging.properties
> ./webapps/corporativo-comum/WEB-INF/lib/org/springframework/boot/logging/java/logging.properties
>
> So there’s springboot's logging.properties. Should it really affect tomcat’s logging?
I wouldn't expect it to. But something is definitely triggering a
re-load of the global logging configuration.
If you have decided to move-on to log4j2, then that's great. But if you
are only doing that because you can't explain what's happening, I think
it would be better for you to track-down the root problem. If you don't
track that down, you might be ignoring something important that really
needs to get fixed.
-chris
>> Em 29 de set. de 2023, à(s) 16:18, Alcides Moraes <al...@gmail.com> escreveu:
>>
>> 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-unsubscribe@tomcat.apache.org
>>> For additional commands, e-mail: users-help@tomcat.apache.org
>>>
>>
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Posted by Alcides Moraes <al...@gmail.com>.
Forgot to expand the webapps/WEB-INF/lib jars as well…
root@8ad4f1dcd125:/usr/local/tomcat# find ./ -type f -name logging.properties
./conf/logging.properties
./webapps/corporativo-comum/WEB-INF/lib/org/springframework/boot/logging/java/logging.properties
So there’s springboot's logging.properties. Should it really affect tomcat’s logging?
> Em 29 de set. de 2023, à(s) 16:18, Alcides Moraes <al...@gmail.com> escreveu:
>
> 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-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
>
Re: Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Posted by Alcides Moraes <al...@gmail.com>.
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-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
Re: Migrating Tomcat 8/9 and a single webapp to Java 17 disconfigures Tomcat logs
Posted by Christopher Schultz <ch...@christopherschultz.net>.
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-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org