How to troubleshoot logger not logging properly after Configurator change?

[c-k-ong]

I start my webapp with a logger for org.hibernate.type set to WARN in log4j2.properties. Then I use a feature in my webapp to programmatically set the logger level to TRACE.

Configurator.setLevel(logger.getName(), Level.toLevel(newLevel));

However, when I perform any Hibernate-related actions (e.g make a query), I don't see any TRACE logging in my log file.

This is an excerpt of my log4j2.properties:

rootLogger.level = INFO
rootLogger.appenderRef.stdout.ref = LOG_ROOT
rootLogger.appenderRef.startup.ref = START_UP_LOG
rootLogger.appenderRef.handler.ref = HANDLER_LOG

appender.LOG_ROOT.type = RollingFile
appender.LOG_ROOT.name = LOG_ROOT
appender.LOG_ROOT.fileName = logs/${hostName}_app.log
appender.LOG_ROOT.filePattern = logs/${hostName}_app.log.%d{yyyy-MM-dd}_%i.gz
appender.LOG_ROOT.layout.type = PatternLayout
appender.LOG_ROOT.layout.charset = UTF-8
appender.LOG_ROOT.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p - (%F:%L) %m%n
appender.LOG_ROOT.policies.type = Policies
appender.LOG_ROOT.policies.time.type = TimeBasedTriggeringPolicy
appender.LOG_ROOT.policies.time.interval = 1
appender.LOG_ROOT.policies.time.modulate = true
appender.LOG_ROOT.policies.size.type = SizeBasedTriggeringPolicy
appender.LOG_ROOT.policies.size.size=5120MB
appender.LOG_ROOT.strategy.type = DefaultRolloverStrategy
appender.LOG_ROOT.strategy.max = 180

# other appenders and loggers...

logger.ORG_HIBERNATE_TYPE.name = org.hibernate.type
logger.ORG_HIBERNATE_TYPE.level = WARN
logger.ORG_HIBERNATE_TYPE.additivity = false
logger.ORG_HIBERNATE_TYPE.appenderRef.rolling.ref = LOG_ROOT

My findings so far are as such:

• When I start with TRACE set in log4j2.properties, the TRACE logging appears successfully.
• When I start with TRACE set in log4j2.properties, then change to WARN using my webapp feature, the TRACE logging disables successfully.
• When I start with TRACE set in log4j2.properties, change to WARN using my webapp feature, then revert to TRACE using my webapp feature, the TRACE logging re-enables successfully.
• After I use my webapp feature to change levels, I use debug prints to show that the change in logger level is effective right before entering the code that generates Hibernate activity.
• I have set "status=TRACE" in my log4j2.properties. It shows the debugging output as my webapp starts, but there is no other such output when my webapp is running.
• My webapp is using 2.18.0. I have tried upgrading to the latest 2.23.1 but the problem still persists.

What could this error be related to? Is there any other troubleshooting that I can do on log4j2?

[ppkarwasz]

[Note: this question has also been posted to SO]

It appears that all your level changes are applied correctly. Could you clarify, what is exactly the problem you are struggling with?

[c-k-ong]

Yes, I posted that question too.

With TRACE output for org.hibernate.type, I should see log output similar to the following excerpt:

2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:151) binding 'DefaultJWTProvider' to parameter: 1
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:151) binding 'JWTProvider' to parameter: 2
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:193) returning 'V_42B' as column: ob1_1_0_
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:193) returning 'JWTProvider' as column: ob2_1_0_
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:193) returning '0' as column: ob3_1_0_
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:193) returning 'DefaultJWTProvider' as column: ob4_1_0_
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:187) returning null as column: ob6_1_0_
2024-04-19 09:55:12.482 [http-nio2-8080-exec-2] TRACE - (NullableType.java:193) returning 'DefaultJWTProvider' as column: ob7_1_0_

If I start with the log4j2.properties logger level as TRACE, I see this output when I query my database. When I change it to WARN using Configurator.setLevel, this output disappears as expected. When I revert it to TRACE, it reappears as expected - so far so good.

My problem is that if I start with WARN instead then change it to TRACE later, I don't see this expected TRACE output when I query my database.

[c-k-ong]

I came across this answer to another question - https://stackoverflow.com/a/65506860/10931326

Is there a reference for this?