Log4j 2 added to my "sakila" Project!

So I can understand what is going on! Log4j 2..

I added the following dependencies to my project:
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.0</version>
    <scope>compile</scope>
</dependency>
 
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.0</version>
    <scope>runtime</scope>
</dependency>
 
<!-- Adapter for SLF4J API, used by c3p0 -->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>2.0</version>
    <scope>runtime</scope>
</dependency>
 
<!-- Adapter for Commons Logging API, not used currently, maybe one day -->
<!--dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-jcl</artifactId>
    <version>2.0</version>
    <scope>runtime</scope>
</dependency-->

and under test\resources I added the following file..

log4j2-test.xml
<?xml version="1.0" encoding="utf-8"?>
<configuration status="WARN">
    <appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d %p %c [%t] %m%n"/>
        </Console>
        <File name="LogFile" fileName="c:\Users\Koray Tugay\Desktop\log.txt">
            <PatternLayout>
                <Pattern>%d %p %c [%t] %m%n</Pattern>
            </PatternLayout>
        </File>
    </appenders>
    <loggers>
        <root level="INFO">
            <appender-ref ref="Console"/>
            <appender-ref ref="LogFile"/>
        </root>
    </loggers>
</configuration>

and I will simply run the following Test Class..
package biz.tugay.sakilaconsole.model.service.impl;
 
import biz.tugay.sakilaconsole.model.entity.Actor;
import biz.tugay.sakilaconsole.model.entity.Film;
import biz.tugay.sakilaconsole.model.entity.FilmActor;
import biz.tugay.sakilaconsole.model.persistence.PersistenceUtil;
import biz.tugay.sakilaconsole.model.persistence.impl.PersistenceUtilImpl;
import org.hibernate.LazyInitializationException;
import org.junit.After;
import org.junit.Assert;
import org.junit.Before;
import org.junit.Test;
 
import java.util.ArrayList;
import java.util.Collection;
import java.util.List;
 
/**
 * User: Koray Tugay (koray@tugay.biz)
 * Date: 10/23/2016
 * Time: 1:44 PM
 */
public class ActorServiceImplTest {
 
    private PersistenceUtil persistenceUtil;
    private ActorServiceImpl actorService;
 
    @Before
    public void init() {
        persistenceUtil = new PersistenceUtilImpl("sakiladb");
        actorService = new ActorServiceImpl(persistenceUtil);
    }
 
    @After
    public void tearDown() {
        persistenceUtil.closeFactory();
    }
 
    @Test
    public void shouldReturnTenActors() {
        final List<Actor> actors = actorService.actorsLimitBy(10);
        Assert.assertTrue(!actors.isEmpty());
        Assert.assertTrue(actors.size() == 10);
    }
 
    @Test
    public void shouldReturnAllActors() {
        final List<Actor> actors = actorService.allActors();
        Assert.assertTrue(actors.size() == 200);
    }
 
    @Test
    public void shouldReturnPenelope() {
        final Actor actorById = actorService.getActorById(1);
        Assert.assertTrue(actorById.getFirstname().equals("PENELOPE"));
    }
 
    @Test(expected = LazyInitializationException.class)
    public void testGetActorsOfFilmLazyInit() {
        final FilmServiceImpl filmService = new FilmServiceImpl(persistenceUtil);
        final Film film = filmService.filmById(1);
        final List<Actor> actors = new ArrayList<Actor>();
        final Collection<FilmActor> filmActors = film.getFilmActors();
        for (FilmActor filmActor : filmActors) {
            actors.add(filmActor.getActor());
        }
        System.out.println(actors.size()); // This line will throw Lazy Init!
    }
 
    @Test
    public void testGetActorsOfFilm() {
        final Film film = new Film();
        film.setId(1);
        final List<Actor> actors = actorService.getActorsOfFilm(film);
        Assert.assertTrue(actors.size() == 10);
    }
}

and I will find the file log.txt on my Desktop folder with the following contents:
2016-12-07 16:10:34,131 INFO org.hibernate.jpa.internal.util.LogHelper [main] HHH000204: Processing PersistenceUnitInfo [
 name: sakiladb
 ...]
2016-12-07 16:10:34,241 INFO org.hibernate.Version [main] HHH000412: Hibernate Core {5.1.0.Final}
2016-12-07 16:10:34,241 INFO org.hibernate.cfg.Environment [main] HHH000205: Loaded properties from resource hibernate.properties: {hibernate.c3p0.timeout=300, hibernate.connection.driver_class=com.mysql.jdbc.Driver, hibernate.c3p0.max_statements=5, hibernate.c3p0.unreturnedConnectionTimeout=2, hibernate.c3p0.max_size=3, hibernate.connection.useUnicode=true, hibernate.connection.useSSL=false, hibernate.c3p0.min_size=2, hibernate.connection.username=root, hibernate.hbm2ddl.auto=update, hibernate.connection.url=jdbc:mysql://localhost:3306/sakila, hibernate.show_sql=false, hibernate.bytecode.use_reflection_optimizer=false, hibernate.connection.password=****, hibernate.connection.characterEncoding=utf-8}
2016-12-07 16:10:34,241 INFO org.hibernate.cfg.Environment [main] HHH000021: Bytecode provider name : javassist
2016-12-07 16:10:34,301 INFO org.hibernate.annotations.common.Version [main] HCANN000001: Hibernate Commons Annotations {5.0.1.Final}
2016-12-07 16:10:34,481 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/sakila
2016-12-07 16:10:34,481 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001001: Connection properties: {useUnicode=true, user=root, password=****, characterEncoding=utf-8, useSSL=false}
2016-12-07 16:10:34,481 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001003: Autocommit mode: false
2016-12-07 16:10:34,501 INFO com.mchange.v2.log.MLog [MLog-Init-Reporter] MLog clients using slf4j logging.
2016-12-07 16:10:34,641 INFO com.mchange.v2.c3p0.C3P0Registry [main] Initializing c3p0-0.9.5.2 [built 08-December-2015 22:06:04 -0800; debug? true; trace: 10]
2016-12-07 16:10:34,681 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001007: JDBC isolation level: <unknown>
2016-12-07 16:10:34,701 INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource [main] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@ab5a39a0 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@3dbcc473 [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|895ee9f, idleConnectionTestPeriod -> 0, initialPoolSize -> 2, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 3, maxStatements -> 5, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@ec17ffbb [ description -> null, driverClass -> null, factoryClassLocation -> null, forceUseNamedDriverClass -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|b53bf3, jdbcUrl -> jdbc:mysql://localhost:3306/sakila, properties -> {useUnicode=true, user=******, password=******, characterEncoding=utf-8, useSSL=false} ], preferredTestQuery -> null, privilegeSpawnedThreads -> false, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 2, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, extensions -> {}, factoryClassLocation -> null, identityToken -> 1hge1dg9k1odrezx11ncc0o|6fecc906, numHelperThreads -> 3 ]
2016-12-07 16:10:34,921 INFO org.hibernate.dialect.Dialect [main] HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect
2016-12-07 16:10:35,748 INFO org.hibernate.jpa.internal.util.LogHelper [main] HHH000204: Processing PersistenceUnitInfo [
 name: sakiladb
 ...]
2016-12-07 16:10:35,758 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/sakila
2016-12-07 16:10:35,758 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001001: Connection properties: {useUnicode=true, user=root, password=****, characterEncoding=utf-8, useSSL=false}
2016-12-07 16:10:35,758 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001003: Autocommit mode: false
2016-12-07 16:10:35,788 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001007: JDBC isolation level: <unknown>
2016-12-07 16:10:35,788 INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource [main] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@85126d7 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@b4c4064a [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|6fa4c25c, idleConnectionTestPeriod -> 0, initialPoolSize -> 2, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 3, maxStatements -> 5, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@ab7d4671 [ description -> null, driverClass -> null, factoryClassLocation -> null, forceUseNamedDriverClass -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|6feb54f3, jdbcUrl -> jdbc:mysql://localhost:3306/sakila, properties -> {useUnicode=true, user=******, password=******, characterEncoding=utf-8, useSSL=false} ], preferredTestQuery -> null, privilegeSpawnedThreads -> false, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 2, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, extensions -> {}, factoryClassLocation -> null, identityToken -> 1hge1dg9k1odrezx11ncc0o|35bb43c5, numHelperThreads -> 3 ]
2016-12-07 16:10:35,798 INFO org.hibernate.dialect.Dialect [main] HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect
2016-12-07 16:10:35,988 INFO org.hibernate.jpa.internal.util.LogHelper [main] HHH000204: Processing PersistenceUnitInfo [
 name: sakiladb
 ...]
2016-12-07 16:10:36,008 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/sakila
2016-12-07 16:10:36,008 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001001: Connection properties: {useUnicode=true, user=root, password=****, characterEncoding=utf-8, useSSL=false}
2016-12-07 16:10:36,008 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001003: Autocommit mode: false
2016-12-07 16:10:36,038 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001007: JDBC isolation level: <unknown>
2016-12-07 16:10:36,038 INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource [main] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@ed7d2edf [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@61e67c5e [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|304321e6, idleConnectionTestPeriod -> 0, initialPoolSize -> 2, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 3, maxStatements -> 5, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@60a63264 [ description -> null, driverClass -> null, factoryClassLocation -> null, forceUseNamedDriverClass -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|141a23d6, jdbcUrl -> jdbc:mysql://localhost:3306/sakila, properties -> {useUnicode=true, user=******, password=******, characterEncoding=utf-8, useSSL=false} ], preferredTestQuery -> null, privilegeSpawnedThreads -> false, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 2, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, extensions -> {}, factoryClassLocation -> null, identityToken -> 1hge1dg9k1odrezx11ncc0o|617e3038, numHelperThreads -> 3 ]
2016-12-07 16:10:36,048 INFO org.hibernate.dialect.Dialect [main] HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect
2016-12-07 16:10:36,208 INFO org.hibernate.hql.internal.QueryTranslatorFactoryInitiator [main] HHH000397: Using ASTQueryTranslatorFactory
2016-12-07 16:10:36,348 INFO org.hibernate.jpa.internal.util.LogHelper [main] HHH000204: Processing PersistenceUnitInfo [
 name: sakiladb
 ...]
2016-12-07 16:10:36,358 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/sakila
2016-12-07 16:10:36,358 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001001: Connection properties: {useUnicode=true, user=root, password=****, characterEncoding=utf-8, useSSL=false}
2016-12-07 16:10:36,358 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001003: Autocommit mode: false
2016-12-07 16:10:36,390 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001007: JDBC isolation level: <unknown>
2016-12-07 16:10:36,390 INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource [main] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@7b700ec8 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@f4e2c0a5 [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|117e2d16, idleConnectionTestPeriod -> 0, initialPoolSize -> 2, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 3, maxStatements -> 5, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@824c7996 [ description -> null, driverClass -> null, factoryClassLocation -> null, forceUseNamedDriverClass -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|2ee5e7fe, jdbcUrl -> jdbc:mysql://localhost:3306/sakila, properties -> {useUnicode=true, user=******, password=******, characterEncoding=utf-8, useSSL=false} ], preferredTestQuery -> null, privilegeSpawnedThreads -> false, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 2, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, extensions -> {}, factoryClassLocation -> null, identityToken -> 1hge1dg9k1odrezx11ncc0o|20b07a5a, numHelperThreads -> 3 ]
2016-12-07 16:10:36,400 INFO org.hibernate.dialect.Dialect [main] HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect
2016-12-07 16:10:36,580 INFO org.hibernate.jpa.internal.util.LogHelper [main] HHH000204: Processing PersistenceUnitInfo [
 name: sakiladb
 ...]
2016-12-07 16:10:36,600 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH010002: C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://localhost:3306/sakila
2016-12-07 16:10:36,600 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001001: Connection properties: {useUnicode=true, user=root, password=****, characterEncoding=utf-8, useSSL=false}
2016-12-07 16:10:36,600 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001003: Autocommit mode: false
2016-12-07 16:10:36,640 INFO org.hibernate.c3p0.internal.C3P0ConnectionProvider [main] HHH10001007: JDBC isolation level: <unknown>
2016-12-07 16:10:36,640 INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource [main] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@69cb336f [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1e4e9c3 [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|19e41e62, idleConnectionTestPeriod -> 0, initialPoolSize -> 2, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 3, maxStatements -> 5, maxStatementsPerConnection -> 0, minPoolSize -> 2, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@3e7642b1 [ description -> null, driverClass -> null, factoryClassLocation -> null, forceUseNamedDriverClass -> false, identityToken -> 1hge1dg9k1odrezx11ncc0o|3a6298b2, jdbcUrl -> jdbc:mysql://localhost:3306/sakila, properties -> {useUnicode=true, user=******, password=******, characterEncoding=utf-8, useSSL=false} ], preferredTestQuery -> null, privilegeSpawnedThreads -> false, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 2, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, extensions -> {}, factoryClassLocation -> null, identityToken -> 1hge1dg9k1odrezx11ncc0o|17f6a75d, numHelperThreads -> 3 ]
2016-12-07 16:10:36,650 INFO org.hibernate.dialect.Dialect [main] HHH000400: Using dialect: org.hibernate.dialect.MySQL5Dialect
2016-12-07 16:10:36,802 INFO org.hibernate.hql.internal.QueryTranslatorFactoryInitiator [main] HHH000397: Using ASTQueryTranslatorFactory

How did this work?

Checking the logging guide for Hibernate, we see..
JBoss Logging understands the following back-ends as first-class citizens:
  • JBoss LogManager (mainly used only inside the WildFly app server)
  • Log4j 2
  • ..
By default JBoss Logging will search the ClassLoader for the availability of classes that indicate one of the above "providers" being available.
Most of the time, the discovery process JustWorks. The discovery process relies on the jars available on the classpath. The jboss-logging jar is a required dependency of Hibernate and therefore will always need to be on the classpath.
To use JBoss Logging with Log4j2, the log4j2 jar would also need to be available on the classpath.
And it seems like c3p0 is happy as well.. Checking the documentation of c3p0 we see:
c3p0 uses a custom logging library similar to jakarta commons-logging. Log messages can be directed to the to the popular slf4j.