Re: 42.0.0.jre7, driver logging takes 30-40% of my server's time

Hallo Vladimir,

OK, I will provide. Just give me a few days, because I am very full of work at the moment.

Regards,
Daniel Migowski

Von: Vladimir Sitnikov [mailto:sitnikov(dot)vladimir(at)gmail(dot)com]
Gesendet: Sonntag, 16. April 2017 12:59
An: Daniel Migowski <dmigowski(at)ikoffice(dot)de>
Cc: Jorge Solórzano <jorsol(at)gmail(dot)com>; List <pgsql-jdbc(at)postgresql(dot)org>; Dave Cramer <pg(at)fastcrypt(dot)com>; Konstantinos Kougios <kostas(dot)kougios(at)googlemail(dot)com>
Betreff: Re: [JDBC] 42.0.0.jre7, driver logging takes 30-40% of my server's time

Daniel,

Would you please share your benchmarks?
I don't se how did you arrive at 30% overhead for the logging.
My benchmarks show no overhead attributed to java.util.logging.

I did try org.postgresql.benchmark.statement.ProcessResultSet.bindExecuteFetch, JDK 1.8.0_102,
columnIndexType = INDEX, getter = BEST, ncols = 5, nrows = 100, reuseStatement = false, type = BOOL, unique = false.

The results are:

9.4.1212:
150±8 us / op, 42032 bytes allocated / op
where op is "bind, execute, and fetch resultset of 100 rows, 5 bool columns each"

42.0.0:
120±8 us / op, 18032 bytes allocated / op

Note: bools are faster in 42.0.0 thanks to Jorge's improvement in https://github.com/pgjdbc/pgjdbc/commit/e69e4a1d5502319bc810e0e4529611ba52ea386c

String results are exactly the same:
9.4.1212:
140±6 us / op, 54103 bytes allocated / op

42.0.0:
140±3 us / op, 54103 bytes allocated / op

That basically means, logging is a no-op provided it is not activated.

JFR recordings show no evidence of java.util.logging on the hot methods list.
logging.isLoggable is rather simple method (it does not walk logger hierarchy), so current logging is expected to be lightweight.

Vladimir