New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: use java.util.logging #722

Merged
merged 3 commits into from Feb 12, 2017

Conversation

Projects
None yet
4 participants
@jorsol
Contributor

jorsol commented Dec 27, 2016

This is a refactor to use java.util.logging so there is zero dependencies on external libraries, just the JDK.
I completly remove the custom Poor man's logging with JUL.
For "debug" or basically for protocol (FE=> <=BE) logging it use FINEST (lowest value) wich is basically "TRACE" in others log frameworks.

#566

@davecramer

This comment has been minimized.

Member

davecramer commented Dec 27, 2016

What is the advantage of removing the custom logger ? It is a pretty small piece of code. I can't see any library being faster ?

@vlsi

This comment has been minimized.

Member

vlsi commented Dec 27, 2016

@davecramer , as far as I understand, jul-logging has some "out of the box" way to configure log level, appenders, etc.

On the other hand, we would need to make log configuration option available via connection properties since end-users almost never ever configure java.util.logging directly (either they have no access, or it is too obscure).

@jorsol

This comment has been minimized.

Contributor

jorsol commented Dec 27, 2016

Is not a matter of being faster, the advantage is that it makes more easy to enable/disable on production, it makes more easy to debug just a single class instead the whole driver, it makes more easy to use log rotation, it makes more easy to debug just statements, it makes more easy to "plug" SLF4J.

@jorsol jorsol force-pushed the jorsol:jul-logging branch from 0ea2eed to f502be6 Dec 27, 2016

@jorsol

This comment has been minimized.

Contributor

jorsol commented Dec 27, 2016

On the other hand, we would need to make log configuration option available via connection properties since end-users almost never ever configure java.util.logging directly (either they have no access, or it is too obscure).

@vlsi, the only problem I see with that approach is that it will need a lot of parameter configuration to get it working.

Just as an example, you will need a paramenter to configure handlers (at least Console and File), a paramenter to set filename if the FileHandler is selected, a parameter to set the limit of the file size, the count, etc. IMO this is a little overkill and JUL (or any other logging framework) is not supposed to be used like that.

And for instance, how will work that configuration inside an application server? AFAIK the application server controls the logger configuration...

I believe that a good documentation on how to enable it makes more sense than enable it via connection properties, but if you or the community believes that it will help, I can consider it.

@davecramer

This comment has been minimized.

Member

davecramer commented Dec 27, 2016

@jorsol

This comment has been minimized.

Contributor

jorsol commented Dec 27, 2016

Yes @davecramer , inside an application server is trivial to enable and configure, at least in JBoss/WildFly where I have experience, and particularly that's why I don't like the idea to be configurable with "connection properties".

@jorsol jorsol force-pushed the jorsol:jul-logging branch from f502be6 to a209abc Dec 27, 2016

@vlsi

This comment has been minimized.

Member

vlsi commented Dec 27, 2016

And for instance, how will work that configuration inside an application server? AFAIK the application server controls the logger configuration

I think the logging we implement should be used in an application server. I do not mean tight integration with log of the particular server, but there should be an option to capture "pgjdbc trace" (e.g. into a separate file) so debugging, etc, can be done.

Just as an example, you will need a paramenter to configure handlers

I do not mean "every feature should be exposed via connection properties".
I mean:

  1. There are cases when people do not have full control over -Dsystem.properties
  2. There are cases when JUL is reset (reprogrammed) at runtime (e.g. by app server), so static configuration like -Djul.please.log=true does not just work
  3. The major case (I believe) is case-by-case analysis, so log rotation is likely not even an issue.
@codecov-io

This comment has been minimized.

codecov-io commented Dec 27, 2016

Codecov Report

Merging #722 into master will increase coverage by 1.04%.
The diff coverage is 59.94%.

@@             Coverage Diff              @@
##             master     #722      +/-   ##
============================================
+ Coverage     64.42%   65.47%   +1.04%     
- Complexity     3469     3485      +16     
============================================
  Files           164      164              
  Lines         15147    15086      -61     
  Branches       2501     2424      -77     
============================================
+ Hits           9759     9878     +119     
+ Misses         4156     4049     -107     
+ Partials       1232     1159      -73

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 63ed212...4744e76. Read the comment docs.

@jorsol

This comment has been minimized.

Contributor

jorsol commented Dec 27, 2016

In app servers it should work "out-of-the-box" and won't need the use of connection properties, since JUL is handled at runtime.

So you are targeting standalone apps which I think there is more control to use -Djava.util.logging.config.file=logging.properties. Is there really a need to add a layer to configure the logger with connection properties?

JUL is bassically a standard, it don't even need to change the app to enable it, the Java Logging API has a default logging configuration file located at "lib/logging.properties", inside the JRE directory for the "edge cases" where it cannot be configurated via system properties.

@vlsi

This comment has been minimized.

Member

vlsi commented Dec 27, 2016

In app servers it should work "out-of-the-box" and won't need the use of connection properties, since JUL is handled at runtime

Let me put that in another way: do you think we (as in pgjdbc project) should keep up to date documentation on how to enable logging in each particular app server?

I think connection property makes it way cleaner & reproducible.

@jorsol

This comment has been minimized.

Contributor

jorsol commented Dec 27, 2016

Let me put that in another way: do you think we (as in pgjdbc project) should keep up to date documentation on how to enable logging in each particular app server?

No, pgjdbc project don't need to keep up to date documentation on how to enable logging in each particular app server, simply saying that it use JUL then the user should search for up to date documentation for their particular app server. There is no driver AFAIK even comercial ones that explains every single combination, it's not our (the pgjdbc project) job to keep a documentation for each particular app server.

As I said, in the app servers it should work "out-of-the-box" and is the users job to search documentation for the app server is using.

@jorsol jorsol force-pushed the jorsol:jul-logging branch 2 times, most recently from 72907d2 to 86a20fb Dec 28, 2016

@jorsol

This comment has been minimized.

Contributor

jorsol commented Dec 29, 2016

@vlsi , following your recomendation, what do you think about just having 2 or 3 connection parameters?
I can work on add the following parameters:

logger.level = with the values: OFF, DEBUG, TRACE (I don't like the number notation),
logger.file = output filename (FileHandler), null by default (ConsoleHandler)

A potentially third parameter whould be logger.format, that will be the Formatter output, but I'm not sure if needed, since it is a bit cryptic: [%1$tT] %4$s: %5$s%n

In the levels I use most loggers frameworks notation (DEBUG, TRACE), since JUL use the less common FINE and FINEST, but if needed for consistency I can simply use those.

@vlsi

This comment has been minimized.

Member

vlsi commented Dec 29, 2016

logger.level = with the values: OFF, DEBUG, TRACE (I don't like the number notation),
logger.file = output filename (FileHandler), null by default (ConsoleHandler)

I think something like that would be great. logger.file would probably want some property expansion, so logger.file=logs/pgjdbc_${server.name}.log is possible (as far as I understand, connection pool is typically configured once, and that configuration is reused by app server nodes, so it might be not that good idea to write into the same file from multiple nodes).
OFF, DEBUG, TRACE make sense.

A single default format would be fine, so no need to make format user-configurable.

@jorsol jorsol force-pushed the jorsol:jul-logging branch from 100d541 to d3017fe Jan 6, 2017

@jorsol

This comment has been minimized.

Contributor

jorsol commented Jan 6, 2017

Now this is pretty much complete including the required connection properties, it even have the property expansion, I'm in testing phase now, everyone that wants/ask for logging before, is welcome to test.

@jorsol jorsol changed the title from WIP: feat: use java.util.logging to feat: use java.util.logging Jan 6, 2017

@vlsi

Thanks, it looks good in general. Will give it a spin.

if (driverLogLevel == null) {
return; // Don't mess with Logger if not set
}
if ("OFF".equals(driverLogLevel)) {

This comment has been minimized.

@vlsi

vlsi Jan 9, 2017

Member

Should this be equalsIgnoreCase?

This comment has been minimized.

@jorsol

jorsol Jan 9, 2017

Contributor

Yes, it can be equalsIgnoreCase.

try {
handler = new java.util.logging.FileHandler(driverLogFile, true);
} catch (Exception ex) {
// Cannot enable FileHandler, fallback to ConsoleHandler.

This comment has been minimized.

@vlsi

vlsi Jan 9, 2017

Member

Can we log this somehow?

This comment has been minimized.

@jorsol

jorsol Jan 9, 2017

Contributor

Yes, it can be used a System.err.println()

*/
public String getProperty(String key) {
String value = super.getProperty(key);
if (value != null) {

This comment has been minimized.

@vlsi

vlsi Jan 9, 2017

Member

I would prefer early exit in such cases.
E.g. if (value == null) { return null; }

if (org.postgresql.Driver.isRegistered()) {
LogManager manager = LogManager.getLogManager();
java.util.logging.Logger logger = manager.getLogger("org.postgresql");
switch (getLogLevel()) {

This comment has been minimized.

@vlsi

vlsi Jan 9, 2017

Member

I wonder if this is part of TestUtil required at all.
Wouldn't it be nice if exactly the same log-enablement approach was used for both unit testing and production purposes?

This comment has been minimized.

@jorsol

jorsol Jan 9, 2017

Contributor

mmm... let me see how I can change it to be more "transparent".

BTW, the recomended aproach is to use a configuration file, but I think I can make it more like you want.

@jorsol jorsol force-pushed the jorsol:jul-logging branch 3 times, most recently from 6a65274 to bef11e5 Jan 11, 2017

@jorsol jorsol force-pushed the jorsol:jul-logging branch 5 times, most recently from f7cc294 to 224b8d4 Jan 20, 2017

@jorsol jorsol force-pushed the jorsol:jul-logging branch from 224b8d4 to a95b72f Feb 8, 2017

@jorsol

This comment has been minimized.

Contributor

jorsol commented Feb 8, 2017

Now the documentation is ready for prime time, it probably needs more polish but for now it's ready.

@jorsol

This comment has been minimized.

Contributor

jorsol commented Feb 10, 2017

To get single line formater one can pass: -Djava.util.logging.SimpleFormatter.format="%1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS %4$s %2$s %5$s%6$s%n" or the format you wish.

But it just a matter of get used to, at first I dislike the two line formatter too, but now I found it useful.

}

handler.setFormatter(new java.util.logging.SimpleFormatter());
PARENT_LOGGER.setUseParentHandlers(false);

This comment has been minimized.

@vlsi

vlsi Feb 12, 2017

Member

@jorsol , could you please clarify why did you use setUseParentHandlers(false) here?
I would expect that to be used for FileHandler only.

This comment has been minimized.

@jorsol

jorsol Feb 12, 2017

Contributor

Technically parent handler are defined for the root Logger (.) And by default it is a console handler at level info, since we are programatically defining a handler, that explicitly means don't use console, use only what I want, (file or console).

But if you prefer I can remove that line.

@@ -452,7 +472,7 @@ public String getDefaultValue() {
* @return evaluated value for this connection parameter
*/
public String get(Properties properties) {
return properties.getProperty(_name, _defaultValue);
return new org.postgresql.util.ExpressionProperties(properties).getProperty(_name, _defaultValue);

This comment has been minimized.

@vlsi

vlsi Feb 12, 2017

Member

This would have an unexpected consequence if someone has dfwe${...}asdfa pattern right inside a password property.

This comment has been minimized.

@jorsol

jorsol Feb 12, 2017

Contributor

Good catch... I didn't notice it...

@vlsi vlsi force-pushed the jorsol:jul-logging branch from 3a45d07 to 6a30256 Feb 12, 2017

@vlsi vlsi force-pushed the jorsol:jul-logging branch from 6a30256 to 4744e76 Feb 12, 2017

@vlsi vlsi added this to the 42.0.0 milestone Feb 12, 2017

@vlsi vlsi merged commit 43e6505 into pgjdbc:master Feb 12, 2017

2 checks passed

codecov/project 65.47% (+1.04%) compared to 63ed212
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
@@ -46,7 +50,7 @@
private int portNumber = 0;

// Map for all other properties
private Properties properties = new Properties();
private Properties properties = new ExpressionProperties();

This comment has been minimized.

@jorsol

jorsol Feb 12, 2017

Contributor

I guess this should be reverted, for the unexpected consequence of passwords.

This comment has been minimized.

@vlsi

vlsi Feb 12, 2017

Member

Thanks, I've reverted it.

@davecramer

This comment has been minimized.

Member

davecramer commented Feb 17, 2017

I think we need to look at this again as there are more than a few cases where objects are created regardless of log level

@vlsi

This comment has been minimized.

Member

vlsi commented Feb 17, 2017

@jorsol , can you please look into log changes?

@jorsol

This comment has been minimized.

Contributor

jorsol commented Feb 17, 2017

Yes, let me wrap in a isLoggable

@davecramer

This comment has been minimized.

Member

davecramer commented Mar 13, 2017

DriverManager.setLogWriter no longer works with this

davecramer added a commit to davecramer/pgjdbc that referenced this pull request Sep 19, 2017

feat: use java.util.logging (pgjdbc#722)
Use java.util.logging to print log messages.
logging can be configured in a regular JUL way, and via
`-DloggerLevel=OFF/DEBUG/TRACE`
`-DloggerFile=logs/pgjdbc_${app}.log`     `${..}` can be used to use property names in the file name, including `System.properties`. `%u`, `%g`, etc patterns from https://docs.oracle.com/javase/7/docs/api/java/util/logging/FileHandler.html can be used as well.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment