Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of myserver's time - Mailing list pgsql-jdbc

From Daniel Migowski
Subject Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of myserver's time
Date
Msg-id 41ED3F5450C90F4D8381BC4D8DF6BBDCAF6BDCB4@EXCHANGESERVER.ikoffice.de
Whole thread Raw
In response to Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of myserver's time  (Dave Cramer <pg@fastcrypt.com>)
Responses Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of my server's time  (Vladimir Sitnikov <sitnikov.vladimir@gmail.com>)
Re: 42.0.0.jre7, driver logging takes 30-40% of my server's time  (Vladimir Sitnikov <sitnikov.vladimir@gmail.com>)
List pgsql-jdbc

It is useful that you can plug arbitrary logging frameworks into it. I don’t know if that was possible before. But it is correct, this comes with overhead, which I measured also. I didn’t compare it thought.

 

Daniel Migowski

 

Von: davecramer@gmail.com [mailto:davecramer@gmail.com] Im Auftrag von Dave Cramer
Gesendet: Donnerstag, 23.
März 2017 14:23
An: Konstantinos Kougios <kostas.kougios@googlemail.com>
Cc: Daniel Migowski <dmigowski@ikoffice.de>; Jorge Solórzano <jorsol@gmail.com>; List <pgsql-jdbc@postgresql.org>
Betreff: Re: AW: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of my server's time

 

So as someone who doesn't use logging in this way. Is having java.util.logging useful ? The old logging mechanism didn't have these problems


 

On 23 March 2017 at 09:21, Konstantinos Kougios <kostas.kougios@googlemail.com> wrote:

Hi, after configuring propagator, the time it takes to run some heavy queries dropped from 5s to 1.7s !

Indeed a boolean will even make things faster, so I will update as soon as it is ready, thanks



On 23/03/17 13:19, Daniel Migowski wrote:

Hello,

 

At first: Did you configure the Level Change Propagator? https://logback.qos.ch/manual/configuration.html

 

Also: I am currently working on a patch that does exactly that for ResultSets, because not only can evaluating the log level be very slow when not using the same logging framework than the intented one, but also most of the log statements in PgConnection and PgResultSet have hidden object creation issues because primitive types are passed to calls that expect objects.

 

I would implement that in a way where the log level is only evaluated at query start, and then cached until the next query. Should be good enough for most scenarios and make the driver 5% faster out of the box. Expect some substantial performance improvements from this.

 

I will need a few days to be able to have this ready for a pull request, please standby.

 

Regards,

Daniel Migowski

 

Von: pgsql-jdbc-owner@postgresql.org [mailto:pgsql-jdbc-owner@postgresql.org] Im Auftrag von Konstantinos Kougios
Gesendet: Mittwoch, 22. März 2017 18:35
An: Dave Cramer <pg@fastcrypt.com>
Cc: Jorge Solórzano <jorsol@gmail.com>; List <pgsql-jdbc@postgresql.org>
Betreff: Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of my server's time

 

It continues. It must be a misconfig of logback+common logging

On 22/03/17 17:32, Dave Cramer wrote:

I'm confused when you say it passes this, does it return or continue after this if statement ?


 

On 22 March 2017 at 13:24, Konstantinos Kougios <kostas.kougios@googlemail.com> wrote:

I am using logback and I don't see any postgres-driver related logging, so I assume it should be off

Looking at the stacktrace of the profile though, it seems it passes this code:

if (!isLoggable(level)) {
    return;
}


So it seems as if it is ON though it doesn't log anything.



On 22/03/17 17:21, Jorge Solórzano wrote:

Have you enabled the Logger with a FINEST (TRACE) level?



On Wed, Mar 22, 2017 at 11:13 AM, Konstantinos Kougios <kostas.kougios@googlemail.com> wrote:

I tried to paste an image with a profile, but my email was rejected.

It seems logging is called in places like row.getInt(), row.getString() etc without a check for the logging level. Then it takes a lot of time for those to be processed, especially for queries that get a lot of data. It goes down to parsing strings and locale and it just is slow. I see postgres processing a query for 1 sec but on the java side it takes 5 secs to get the data back to my code. Part of this slowdown is due to the logging. Can it be optimized, i.e. having a boolean to true/false if logging is enabled and then do the calls?

Thanks




--
Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-jdbc

 

 

 

 

 

 

pgsql-jdbc by date:

Previous
From: Dave Cramer
Date:
Subject: Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of myserver's time
Next
From: Daniel Migowski
Date:
Subject: [JDBC] [pgjdbc/pgjdbc] a7e0c8: feat: improve waiting for notifications byprovidi...