Skip to content
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

fix: logger should be generally quiet #1187

Merged
merged 1 commit into from Jul 1, 2018

Conversation

Projects
None yet
3 participants
@jorsol
Copy link
Contributor

jorsol commented May 10, 2018

The logger used in the driver has some calls to levels WARNING and SEVERE, this lower the level to FINE to make the logger quiet.

Changing SEVERE to WARNING is not enough, as WARNING is higher than INFO the default global logging level.

fixes #1009
fixes #1162
closes #1149

@jorsol jorsol force-pushed the jorsol:remove-log-ex branch from b2294fb to d02a5fe May 10, 2018

@codecov-io

This comment has been minimized.

Copy link

codecov-io commented May 10, 2018

Codecov Report

Merging #1187 into master will increase coverage by 0.04%.
The diff coverage is 65%.

@@             Coverage Diff              @@
##             master    #1187      +/-   ##
============================================
+ Coverage     68.63%   68.67%   +0.04%     
- Complexity     3830     3833       +3     
============================================
  Files           173      173              
  Lines         15997    15996       -1     
  Branches       2609     2609              
============================================
+ Hits          10979    10986       +7     
+ Misses         3784     3778       -6     
+ Partials       1234     1232       -2
@vlsi
Copy link
Member

vlsi left a comment

I agree with some of the changes, however I think other lines should not be changed

@@ -125,7 +125,7 @@ private Properties loadDefaultProperties() throws IOException {
}

if (cl == null) {
LOGGER.log(Level.WARNING, "Can't find a classloader for the Driver; not loading driver configuration");
LOGGER.log(Level.FINE, "Can't find a classloader for the Driver; not loading driver configuration");

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

+1 regarding this case.
On top of that, it makes sense to add a word on org/postgresql/driverconfig.properties so it is clear which configuration was skipped.

@@ -232,7 +232,7 @@ public Connection connect(String url, Properties info) throws SQLException {
}
// parse URL and add more properties
if ((props = parseURL(url, props)) == null) {
LOGGER.log(Level.SEVERE, "Error in url: {0}", url);
LOGGER.log(Level.FINE, "Error in url: {0}", url);

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

TL;DR: -1 for the change.
Am I missing a case?

I think this warning could never appear in properly configured setup, so I think this logging should be enabled by default, so it highlights errors in configuration.

Looking a bit more, I think it could make logging more detailed (e.g. move it inside parseURL, so error messages are more focused).

@@ -260,7 +260,7 @@ public Connection connect(String url, Properties info) throws SQLException {
thread.start();
return ct.getResult(timeout);
} catch (PSQLException ex1) {
LOGGER.log(Level.SEVERE, "Connection error: ", ex1);
LOGGER.log(Level.FINE, "Connection error: ", ex1);

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

+1 The error is re-thrown, so logging level could be reduced.

@@ -270,7 +270,7 @@ public Connection connect(String url, Properties info) throws SQLException {
"Your security policy has prevented the connection from being attempted. You probably need to grant the connect java.net.SocketPermission to the database server host and port that you wish to connect to."),
PSQLState.UNEXPECTED_ERROR, ace);
} catch (Exception ex2) {
LOGGER.log(Level.SEVERE, "Unexpected connection error: ", ex2);
LOGGER.log(Level.FINE, "Unexpected connection error: ", ex2);

This comment has been minimized.

@vlsi
@@ -659,7 +659,7 @@ private static long timeout(Properties props) {
try {
return (long) (Float.parseFloat(timeout) * 1000);
} catch (NumberFormatException e) {
LOGGER.log(Level.WARNING, "Couldn't parse loginTimeout value: {0}", timeout);
LOGGER.log(Level.FINE, "Couldn't parse loginTimeout value: {0}", timeout);

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

-1 as this happens in case user provides loginTimeout property and it gets ignored.
Does that really happen often?
I think this log message would appear just in case one tries to put invalid value, and it would warn that the value is ignored.

@@ -97,7 +97,7 @@ public Connection getConnection(String user, String password) throws SQLExceptio
}
return con;
} catch (SQLException e) {
LOGGER.log(Level.SEVERE, "Failed to create a {0} for {1} at {2}: {3}",
LOGGER.log(Level.FINE, "Failed to create a {0} for {1} at {2}: {3}",

This comment has been minimized.

@vlsi
@@ -1369,7 +1369,7 @@ public boolean isValid(int timeout) throws SQLException {
// "current transaction aborted", assume the connection is up and running
return true;
}
LOGGER.log(Level.WARNING, GT.tr("Validating connection."), e);
LOGGER.log(Level.FINE, GT.tr("Validating connection."), e);

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

-1 The exception is not re-thrown, so hiding it by default might make "root cause analysis" harder.

This comment has been minimized.

@jorsol

jorsol May 19, 2018

Author Contributor

Yes, the exception is not re-thrown but the method returns a boolean indicating if the connection is Valid, the point of the method is not get the "root cause", is to validate the connection.

For instance if a connection pool every time it tries to borrow a connection check if is valid, this will flood the log for no reason.

This comment has been minimized.

@vlsi
@@ -88,17 +88,17 @@ public boolean isSSPISupported() {
* won't have JNA and this will throw a NoClassDefFoundError.
*/
if (!Platform.isWindows()) {
LOGGER.log(Level.WARNING, "SSPI not supported: non-Windows host");
LOGGER.log(Level.FINE, "SSPI not supported: non-Windows host");

This comment has been minimized.

@vlsi
return false;
}
/* Waffle must be on the CLASSPATH */
Class.forName("waffle.windows.auth.impl.WindowsSecurityContextImpl");
return true;
} catch (NoClassDefFoundError ex) {
LOGGER.log(Level.WARNING, "SSPI unavailable (no Waffle/JNA libraries?)", ex);
LOGGER.log(Level.FINE, "SSPI unavailable (no Waffle/JNA libraries?)", ex);

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

-1 as it might highlight configuration issues.
On the other hand, it could make sense to make this one-time-only log message (e.g. static boolean sspiUnavailable in SSPIClient class

@@ -63,7 +63,7 @@ public synchronized void releaseTimer() {
}
} else {
// Should not get here under normal circumstance, probably a bug in app code.
LOGGER.log(Level.WARNING,
LOGGER.log(Level.FINE,

This comment has been minimized.

@vlsi

vlsi May 17, 2018

Member

-1 as this should never happen, and the message highlights something fishy

@jorsol jorsol force-pushed the jorsol:remove-log-ex branch 3 times, most recently from 84e7204 to 823d3ed May 19, 2018

@vlsi

This comment has been minimized.

Copy link
Member

vlsi commented Jun 30, 2018

@jorsol , would you please rebase and add a CHANGELOG.md entry?

@vlsi vlsi added this to the 42.2.3 milestone Jun 30, 2018

@jorsol jorsol force-pushed the jorsol:remove-log-ex branch from 823d3ed to e94ad1d Jul 1, 2018

@jorsol

This comment has been minimized.

Copy link
Contributor Author

jorsol commented Jul 1, 2018

Rebased and CHANGELOG.md entry added.

@@ -178,23 +172,18 @@ public QueryExecutor openConnectionImpl(HostSpec[] hostSpecs, String user, Strin

// Set SO_RECVBUF read buffer size
int receiveBufferSize = PGProperty.RECEIVE_BUFFER_SIZE.getInt(info);
if (receiveBufferSize > -1) {

This comment has been minimized.

@vlsi

vlsi Jul 1, 2018

Member

AFAIK -1 was here to just use system default. Raising a warning for that case is not good

This comment has been minimized.

@vlsi

vlsi Jul 1, 2018

Member

Was that an intentional change?

This comment has been minimized.

@jorsol

jorsol Jul 1, 2018

Author Contributor

Reverted.

@jorsol jorsol force-pushed the jorsol:remove-log-ex branch from e94ad1d to 2034d76 Jul 1, 2018

fix: logger should be generally quiet
The logger used in the driver has some calls to levels WARNING and SEVERE
this lower the level to FINE to make the logger quiet in some cases.

@jorsol jorsol force-pushed the jorsol:remove-log-ex branch from 2034d76 to 814709f Jul 1, 2018

@vlsi

vlsi approved these changes Jul 1, 2018

@vlsi vlsi merged commit 30f06e1 into pgjdbc:master Jul 1, 2018

1 of 2 checks passed

continuous-integration/travis-ci/pr The Travis CI build failed
Details
codecov/project 68.67% (+0.04%) compared to 435e2f7
Details

@bokken bokken referenced this pull request Jul 3, 2018

Merged

Release notes for 42.2.3 #1238

rhavermans added a commit to bolcom/pgjdbc that referenced this pull request Jul 13, 2018

fix: logger should be generally quiet (pgjdbc#1187)
The logger used in the driver has some calls to levels WARNING and SEVERE
this lower the level to FINE to make the logger quiet in some cases.

fixes pgjdbc#1009
fixes pgjdbc#1162
closes pgjdbc#1149

rhavermans added a commit to bolcom/pgjdbc that referenced this pull request Jul 13, 2018

fix: logger should be generally quiet (pgjdbc#1187)
The logger used in the driver has some calls to levels WARNING and SEVERE
this lower the level to FINE to make the logger quiet in some cases.

fixes pgjdbc#1009
fixes pgjdbc#1162
closes pgjdbc#1149
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.