Skip to content

Filtered-out logs are logged anyway during test execution #48346

@yrodiere

Description

@yrodiere

Describe the bug

Extensions can decide to filter out some logs from libraries that are too verbose for Quarkus standards, like this:

@BuildStep
void setupLogFilters(BuildProducer<LogCleanupFilterBuildItem> filters) {
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.Version", "HHH000412"));
//Disable details about bytecode reflection optimizer:
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.cfg.Environment", "HHH000406"));
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.jpa.internal.util.LogHelper", "HHH000204"));
filters.produce(new LogCleanupFilterBuildItem("SQL dialect", "HHH000400"));
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.orm.beans", "HHH10005002", "HHH10005004"));
// Silence incubating settings warnings as we will use some for compatibility
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.orm.incubating",
"HHH90006001"));
// Silence DB connection info logging because:
// 1. We don't implement the retrieval of information in QuarkusConnectionProvider
// 2. It's currently being logged even at static init when there is no connection
// See https://hibernate.atlassian.net/browse/HHH-18454
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.orm.connections.pooling",
"HHH10001005"));
//This "deprecation" warning isn't practical for the specific Quarkus needs, as it reminds users they don't need
//to set the 'hibernate.dialect' property, however it's being set by Quarkus buildsteps so they can't avoid it.
//Ignore for now, perhaps remove it upstream however this may make sense for other Hibernate users.
//Wondering if we should have the Quarkus build differentiate between an explicitly set vs an inferred Dialect
//property (we have a custom DialectFactory already so this could be trivial), however even in this case ORM
//can't guess things since there is no connection, so even if we did so, this message wouldn't be applicable.
filters.produce(new LogCleanupFilterBuildItem("org.hibernate.orm.deprecation", "HHH90000025"));
}

These filters don't seem to work anymore in @QuarkusTest.

Expected behavior

Filtered logs shouldn't appear in logs.

Actual behavior

For instance we get the line about "Hibernate ORM core version" if we run this from the Quarkus codebase (fully built beforehand, on main):

$ ./mvnw clean test -f integration-tests/jpa-h2 -Dtest=JPAFunctionalityTest
[...]
[INFO] Running io.quarkus.it.jpa.h2.JPAFunctionalityTest
2025-06-12 11:40:45,478 INFO  [org.hib.jpa.int.uti.LogHelper] (main) HHH000204: Processing PersistenceUnitInfo [name: <default>]
2025-06-12 11:40:45,502 INFO  [org.hib.Version] (main) HHH000412: Hibernate ORM core version 7.0.1.Final
2025-06-12 11:40:45,634 INFO  [org.hib.orm.con.pooling] (main) HHH10001005: Database info:
        Database JDBC URL [undefined/unknown]
        Database driver: undefined/unknown
        Database version: 2.3.230
        Autocommit mode: undefined/unknown
        Isolation level: <unknown>
        Pool: undefined/unknown
        Minimum pool size: undefined/unknown
        Maximum pool size: undefined/unknown
2025-06-12 11:40:46,536 INFO  [io.quarkus] (main) quarkus-integration-test-jpa-h2 999-SNAPSHOT on JVM (powered by Quarkus 999-SNAPSHOT) started in 2.811s. Listening on: http://localhost:8081
2025-06-12 11:40:46,537 INFO  [io.quarkus] (main) Profile test activated. 
2025-06-12 11:40:46,537 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, compose, hibernate-orm, jdbc-h2, narayana-jta, rest, smallrye-context-propagation, vertx]
list of stored Person names:
        Person with id=778b19b7-6f00-4f99-b0da-eaa5a5073447, name='Gizmo', address { Address with id=1, street='Street a7f45765-07d6-4550-92e6-8e711374a822' }Person with id=0a00e8de-fce2-49e5-8604-d2817a443e9c, name='Hibernate ORM', address { Address with id=3, street='Street d8ac188d-f876-4af8-86bd-deb3ac1a3a1c' }Person with id=e97868d9-95ae-425e-ae58-5e4bf8cb44ea, name='Quarkus', address { Address with id=2, street='Street f47bfefc-52a6-425a-aac7-9568f2bdc7b3' }
List complete.
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.997 s -- in io.quarkus.it.jpa.h2.JPAFunctionalityTest
[...]

How to Reproduce?

./mvnw clean test -f integration-tests/jpa-h2 -Dtest=JPAFunctionalityTest

These two lines (at least) shouldn't be there:

2025-06-12 11:40:45,502 INFO  [org.hib.Version] (main) HHH000412: Hibernate ORM core version 7.0.1.Final
2025-06-12 11:40:45,634 INFO  [org.hib.orm.con.pooling] (main) HHH10001005: Database info:
        Database JDBC URL [undefined/unknown]
        Database driver: undefined/unknown
        Database version: 2.3.230
        Autocommit mode: undefined/unknown
        Isolation level: <unknown>
        Pool: undefined/unknown
        Minimum pool size: undefined/unknown
        Maximum pool size: undefined/unknown

Output of uname -a or ver

No response

Output of java -version

No response

Quarkus version or git rev

No response

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

Interestingly, filters still work in production mode or with quarkus:run:

$ ./mvnw clean package quarkus:run -f integration-tests/jpa-h2 -DskipTests -Dquarkus.build.skip=false
[...]
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2025-06-12 11:47:26,748 WARN  [io.qua.config] (main) Unrecognized configuration key "quarkus.build.skip" was provided; it will be ignored; verify that the dependency extension for this configuration is set or that you did not make a typo
2025-06-12 11:47:27,506 INFO  [io.quarkus] (main) quarkus-integration-test-jpa-h2 999-SNAPSHOT on JVM (powered by Quarkus 999-SNAPSHOT) started in 1.409s. Listening on: http://0.0.0.0:8080                                                                            
2025-06-12 11:47:27,506 INFO  [io.quarkus] (main) Profile prod activated.                                                           
2025-06-12 11:47:27,506 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, jdbc-h2, narayana-jta, rest, smallrye-context-propagation, vertx]                                                                                                    

And they also work fine in @QuarkusUnitTest, e.g.:

$ ./mvnw clean test -f extensions/hibernate-orm/deployment -Dtest=SinglePersistenceUnitCdiSessionTest -Dtest-containers
[...]
[INFO] Running io.quarkus.hibernate.orm.singlepersistenceunit.SinglePersistenceUnitCdiSessionTest
2025-06-12 11:37:25,754 INFO  [io.quarkus] (main) quarkus-hibernate-orm-deployment 999-SNAPSHOT on JVM (powered by Quarkus 999-SNAPSHOT) started in 1.189s. Listening on: http://localhost:8081
2025-06-12 11:37:25,755 INFO  [io.quarkus] (main) Profile test activated. 
2025-06-12 11:37:25,755 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, compose, hibernate-orm, hibernate-validator, jdbc-h2, narayana-jta, resteasy-jackson, smallrye-context-propagation, smallrye-metrics, vertx]
2025-06-12 11:37:26,296 INFO  [io.quarkus] (main) quarkus-hibernate-orm-deployment stopped in 0.017s
[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 5.901 s -- in io.quarkus.hibernate.orm.singlepersistenceunit.SinglePersistenceUnitCdiSessionTest
[...]

Metadata

Metadata

Assignees

Labels

Type

No type

Projects

Status

In Progress

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions