How do I log postgres driver messages with slf4j?

StackOverflow https://stackoverflow.com//questions/20028036

Question

I'm using postgres db in my webapp.

I added following dependencies in my pom.xml:

    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.5</version>
    </dependency>

    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>jul-to-slf4j</artifactId>
        <version>1.7.5</version>
    </dependency>

    <dependency>
        <groupId>ch.qos.logback</groupId>
        <artifactId>logback-classic</artifactId>
        <version>1.0.13</version>
    </dependency>

In IntelliJ Idea console log I see the following piece of text (darkred color, which means it was stdout-ed):

Nov 17, 2013 12:32:40 PM org.apache.naming.NamingContext lookup
WARNING: Unexpected exception resolving reference
org.postgresql.util.PSQLException: пїЅпїЅпїЅпїЅпїЅ: пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ "traffic" пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ (пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ)
    at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:291)
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:108)
    at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:66)
    at org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:125)
    at org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:30)
    at org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:22)
    at org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:30)
    at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
    at org.postgresql.Driver.makeConnection(Driver.java:393)
    at org.postgresql.Driver.connect(Driver.java:267)
    at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:267)

    [...skipped...]

 javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1420)
    at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:848)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:322)
    at sun.rmi.transport.Transport$1.run(Transport.java:177)
    at sun.rmi.transport.Transport$1.run(Transport.java:174)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.rmi.transport.Transport.serviceCall(Transport.java:173)
    at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:556)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:811)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:670)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:724)

Nov 17, 2013 12:32:40 PM org.apache.catalina.core.NamingContextListener addResource
WARNING: Failed to register in JMX: javax.naming.NamingException: пїЅпїЅпїЅпїЅпїЅ: пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ "traffic" пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ (пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ)

The question is how to force that messages from postgres to be logged with slf4j?

logging.properties

handlers = org.slf4j.bridge.SLF4JBridgeHandler

logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="destination" value="${catalina.base:-./temp}/logs/billing" />

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${destination}.log</file>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${destination}-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
            <maxFileSize>100MB</maxFileSize>
        </timeBasedFileNamingAndTriggeringPolicy>
    </appender>

    <logger name="net.kerba" level="TRACE"/>

    <logger name="org" level="INFO" />

    <root level="debug">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="ROLLING" />
    </root>
</configuration>

Full console output when starting project:

D:\opt\apache-tomcat-7.0.25\bin\catalina.bat run
[2013-11-17 12:32:31,305] Artifact billing-filter:war exploded: Server is not connected. Deploy is not available.
Using CATALINA_BASE:   "D:\home\kerb\.IntelliJIdea12\system\tomcat\Unnamed_billing-filter"
Using CATALINA_HOME:   "D:\opt\apache-tomcat-7.0.25"
Using CATALINA_TMPDIR: "D:\opt\apache-tomcat-7.0.25\temp"
Using JRE_HOME:        "C:\Program Files\Java\jdk1.7.0_40"
Using CLASSPATH:       "D:\opt\apache-tomcat-7.0.25\bin\bootstrap.jar;D:\opt\apache-tomcat-7.0.25\bin\tomcat-juli.jar"
Connected to the target VM, address: '127.0.0.1:52288', transport: 'socket'
Nov 17, 2013 12:32:32 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jdk1.7.0_40\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Program Files (x86)\JetBrains\IntelliJ IDEA 12.1\bin\..\.\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\pgmodeler\lib;C:\Program Files (x86)\GammaTech\TumarCSP\lib;C:\Program Files (x86)\GammaTech\TumarCSP\lib64;C:\Program Files\MySQL\MySQL Server 5.1\bin;C:\Program Files\erl5.10.2\bin;C:\Program Files\SlikSvn\bin;C:\Program Files\OpenVPN\bin;C:\Program Files\TortoiseHg\;D:\opt\maven3\bin;D:\opt\instantclient_11_2;D:\opt\wget\bin;D:\opt\conemu;C:\Program Files\Far Manager;C:\Program Files\PostgreSQL\9.2\bin;C:\Program Files (x86)\cwRsync\bin;C:\Program Files\WinRAR;C:\Program Files\7-Zip;c:\program files\java\jdk1.7.0_40\jre\bin;.
Nov 17, 2013 12:32:32 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Nov 17, 2013 12:32:32 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8009"]
Nov 17, 2013 12:32:32 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 900 ms
Nov 17, 2013 12:32:32 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Nov 17, 2013 12:32:32 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.25
Nov 17, 2013 12:32:32 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Nov 17, 2013 12:32:32 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Nov 17, 2013 12:32:32 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 49 ms
Connected to server
[2013-11-17 12:32:32,966] Artifact billing-filter:war exploded: Artifact is being deployed, please wait...
12:32:38,593 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
12:32:38,594 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
12:32:38,594 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/D:/projects/billing-filter/target/check2/WEB-INF/classes/logback.xml]
12:32:38,612 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
12:32:38,617 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
12:32:38,618 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
12:32:38,662 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
12:32:38,662 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ROLLING]
12:32:38,685 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
12:32:38,686 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern D:/home/kerb/.IntelliJIdea12/system/tomcat/Unnamed_billing-filter/logs/billing-%d{yyyy-MM-dd}.%i.log for the active file
12:32:38,688 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern 'D:/home/kerb/.IntelliJIdea12/system/tomcat/Unnamed_billing-filter/logs/billing-%d{yyyy-MM-dd}.%i.log'.
12:32:38,688 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
12:32:38,688 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Sun Nov 17 12:25:59 ALMT 2013
12:32:38,689 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@20:107 - no applicable action for [timeBasedFileNamingAndTriggeringPolicy], current ElementPath  is [[configuration][appender][timeBasedFileNamingAndTriggeringPolicy]]
12:32:38,689 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@21:26 - no applicable action for [maxFileSize], current ElementPath  is [[configuration][appender][timeBasedFileNamingAndTriggeringPolicy][maxFileSize]]
12:32:38,690 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ROLLING] - Active log file name: D:\home\kerb\.IntelliJIdea12\system\tomcat\Unnamed_billing-filter/logs/billing.log
12:32:38,690 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ROLLING] - File property is set to [D:\home\kerb\.IntelliJIdea12\system\tomcat\Unnamed_billing-filter/logs/billing.log]
12:32:38,691 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [net.kerba] to TRACE
12:32:38,691 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org] to INFO
12:32:38,691 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
12:32:38,691 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
12:32:38,692 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ROLLING] to Logger[ROOT]
12:32:38,692 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
12:32:38,692 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@2f163915 - Registering current configuration as safe fallback point

12:32:38.697 [RMI TCP Connection(3)-127.0.0.1] WARN  o.a.tomcat.jdbc.pool.ConnectionPool - maxIdle is smaller than minIdle, setting maxIdle to: 10
Nov 17, 2013 12:32:40 PM org.apache.naming.NamingContext lookup
WARNING: Unexpected exception resolving reference
org.postgresql.util.PSQLException: пїЅпїЅпїЅпїЅпїЅ: пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ "traffic" пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ (пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ)
    at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:291)
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:108)

[... skipped ...]

Nov 17, 2013 12:32:40 PM org.apache.catalina.core.NamingContextListener addResource
WARNING: Failed to register in JMX: javax.naming.NamingException: пїЅпїЅпїЅпїЅпїЅ: пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ "traffic" пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅпїЅ (пїЅпїЅ пїЅпїЅпїЅпїЅпїЅпїЅ)
12:32:40.211 [RMI TCP Connection(3)-127.0.0.1] INFO  o.a.c.c.C.[Catalina].[localhost].[/] - No Spring WebApplicationInitializer types detected on classpath
12:32:40.330 [RMI TCP Connection(3)-127.0.0.1] INFO  o.a.c.c.C.[Catalina].[localhost].[/] - Initializing Spring FrameworkServlet 'dispatcher'
12:32:40.330 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.web.servlet.DispatcherServlet - FrameworkServlet 'dispatcher': initialization started
12:32:40.343 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.c.s.XmlWebApplicationContext - Refreshing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Sun Nov 17 12:32:40 ALMT 2013]; root of context hierarchy
12:32:40.361 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from ServletContext resource [/WEB-INF/dispatcher-servlet.xml]
12:32:40.631 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.b.f.s.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@36db4683: defining beans [searchController,informationProviderRegistry,sessionDataHolder,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,viewResolver,org.springframework.context.annotation.ConfigurationClassPostProcessor.importAwareProcessor]; root of factory hierarchy
12:32:40.765 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-name] onto handler 'searchController'
12:32:40.766 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-name.*] onto handler 'searchController'
12:32:40.766 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-name/] onto handler 'searchController'
12:32:40.766 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-host] onto handler 'searchController'
12:32:40.766 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-host.*] onto handler 'searchController'
12:32:40.767 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-host/] onto handler 'searchController'
12:32:40.767 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/hostname-traffic-details/{uuid}] onto handler 'searchController'
12:32:40.767 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/hostname-traffic-details/{uuid}.*] onto handler 'searchController'
12:32:40.767 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/hostname-traffic-details/{uuid}/] onto handler 'searchController'
12:32:40.768 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/download/{uuid}] onto handler 'searchController'
12:32:40.768 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/download/{uuid}.*] onto handler 'searchController'
12:32:40.768 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/download/{uuid}/] onto handler 'searchController'
12:32:40.769 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search] onto handler 'searchController'
12:32:40.769 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search.*] onto handler 'searchController'
12:32:40.769 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/] onto handler 'searchController'
12:32:40.769 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/.*] onto handler 'searchController'
12:32:40.770 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/city/{city}] onto handler 'searchController'
12:32:40.770 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/city/{city}.*] onto handler 'searchController'
12:32:40.770 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/city/{city}/] onto handler 'searchController'
12:32:40.771 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-ip] onto handler 'searchController'
12:32:40.771 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-ip.*] onto handler 'searchController'
12:32:40.771 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/by-ip/] onto handler 'searchController'
12:32:40.771 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/ip-traffic-details/{uuid}] onto handler 'searchController'
12:32:40.772 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/ip-traffic-details/{uuid}.*] onto handler 'searchController'
12:32:40.772 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/ip-traffic-details/{uuid}/] onto handler 'searchController'
12:32:40.772 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/as-excel/{uuid}] onto handler 'searchController'
12:32:40.772 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/as-excel/{uuid}.*] onto handler 'searchController'
12:32:40.773 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.w.s.m.a.DefaultAnnotationHandlerMapping - Mapped URL path [/search/as-excel/{uuid}/] onto handler 'searchController'
12:32:41.058 [RMI TCP Connection(3)-127.0.0.1] INFO  o.s.web.servlet.DispatcherServlet - FrameworkServlet 'dispatcher': initialization completed in 728 ms
[2013-11-17 12:32:41,096] Artifact billing-filter:war exploded: Artifact is deployed successfully
12:32:42.416 [http-bio-8080-exec-1] INFO  o.a.j.compiler.TldLocationsCache - At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Was it helpful?

Solution

You can set a PrintWriter as the PostgresQL driver logging destination. For example, if you were using one of the driver data sources, you would use this method.

Now, all you need is an extension of PrintWriter that sends everything it receives to your logging system. Here is an example from Apache Jackrabbit.

OTHER TIPS

New Postgres driver 42.0.0 use java.util.logging, see changelog

To get logs:

  1. Add jul-to-slf4j bridge:

    <dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jul-to-slf4j</artifactId>
    <version>${slf4j.version}</version>
    <scope>runtime</scope>
</dependency>

  2. Add in logback.xml (logback-test.xml)

    <logger name="org.postgresql" level="trace"/>`

  3. Add in code

    static {
    SLF4JBridgeHandler.install();
}

When providing connection string, please specify &loglevel=<0,1,2> Default is 0 (no logging from org.postgresql.core.Logger). Level 2 is really verbose- you will may dozens lines for every SQL statements -details of driver protocoll, like

18:55:06.754 (1)  FE=> Bind(stmt=null,portal=null)
18:55:06.754 (1)  FE=> Describe(portal=null)
18:55:06.754 (1)  FE=> Execute(portal=null,limit=0)
18:55:06.754 (1)  FE=> Sync
18:55:06.946 (1)  <=BE ParseComplete [null]
18:55:06.946 (1)  <=BE BindComplete [null]
18:55:06.946 (1)  <=BE CommandStatus(BEGIN)
18:55:06.946 (1)  <=BE ParseComplete [null]
18:55:06.946 (1)  <=BE BindComplete [null]
18:55:06.946 (1)  <=BE NoData
18:55:06.946 (1)  <=BE CommandStatus(INSERT 0 1)
18:55:06.946 (1)  <=BE ReadyForQuery(T)
18:55:06.947 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandler@703fa45, maxRows=0, fetchSize=0, flags=22
18:55:06.947 (1)  FE=> Bind(stmt=S_1,portal=null)
18:55:06.947 (1)  FE=> Execute(portal=null,limit=1)
18:55:06.947 (1)  FE=> Sync
18:55:07.140 (1)  <=BE BindComplete [null]
18:55:07.140 (1)  <=BE CommandStatus(COMMIT)
18:55:07.140 (1)  <=BE ReadyForQuery(I)

I think it is not possible. Because postgres using neither log4j nor slf4j. Inside they have their own logger with only two log level debug and info. Also their logger not getting any configuration from outside. So we cannot control postgres logs.

To check this please see org.postgresql.core.Logger class inside the postgres jar.

Licensed under: CC-BY-SA with attribution
Not affiliated with StackOverflow
scroll top