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

Logging verbosity for opening a connection increased in 1.3.0 #956

Closed
azhe403 opened this issue Mar 11, 2021 · 4 comments · Fixed by sjp/Schematic#566 or BrighterCommand/Brighter#1432
Assignees
Labels

Comments

@azhe403
Copy link

azhe403 commented Mar 11, 2021

How to reduce logging about ping server without changing log level?

gambar

@bgrainger
Copy link
Member

Changing log levels is the intended way to reduce logging verbosity.

FWIW, the ping message has been at Info level since it was introduced three years ago: dc6f058#diff-22f5eec5ea345b8f0fd8c96f47bb2a7e59d35071c7ad2525d6f251a5ece19d5cR520

The semaphore logging is new in 1.3.0 to help diagnose the new background reset code if there are problems.

It's possible that the level of one or both of those could be reduced (to Debug) in the MySqlConnector code. Is there a reason that you can't set MySqlConnector logging to "WARN" or higher in your logging configuration? Are there INFO messages you need to log?

@bgrainger
Copy link
Member

FWIW, the ping message has been at Info level since it was introduced three years ago

But that code path may not have been executed with the old connection reset logic, so this effectively appears to be a new log statement in 1.3.0. In that case, this probably should be reduced to Debug to match the effective behaviour of 1.2.1 and earlier.

@bgrainger
Copy link
Member

Logging for opening 10 connections in 1.2.1:

[INFO]  ConnectionPool  Pool1 creating new connection pool for ConnectionString: Server=localhost;User Id=root
[INFO]  ConnectionPool  Pool1 no pooled session available; created new Session1.1
[INFO]  ServerSession  Session1.1 connecting to IpAddress 127.0.0.1 for HostName 'localhost'
[INFO]  ServerSession  Session1.1 made connection; ServerVersion=5.7.33; ConnectionId=404; Compression=False; Attributes=True; DeprecateEof=True; Ssl=True; SessionTrack=True

Logging for opening 10 connections in 1.3.0:

[INFO]  ConnectionPool  Pool1 creating new connection pool for ConnectionString: Server=localhost;User Id=root
[INFO]  BackgroundConnectionResetHelper  Starting BackgroundConnectionResetHelper worker.
[INFO]  BackgroundConnectionResetHelper  Started BackgroundConnectionResetHelper worker.
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  ConnectionPool  Pool1 no pooled session available; created new Session1.1
[INFO]  ServerSession  Session1.1 connecting to IpAddress 127.0.0.1 for HostName 'localhost'
[INFO]  ServerSession  Session1.1 made connection; ServerVersion=5.7.33; ConnectionId=401; Compression=False; Attributes=True; DeprecateEof=True; Ssl=True; SessionTrack=True
[INFO]  ConnectionPool  Pool1 no pooled session available; created new Session1.2
[INFO]  ServerSession  Session1.2 connecting to IpAddress 127.0.0.1 for HostName 'localhost'
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  ServerSession  Session1.2 made connection; ServerVersion=5.7.33; ConnectionId=402; Compression=False; Attributes=True; DeprecateEof=True; Ssl=True; SessionTrack=True
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  ServerSession  Session1.1 successfully pinged server
[INFO]  ServerSession  Session1.2 successfully pinged server
[INFO]  ConnectionPool  Pool1 no pooled session available; created new Session1.3
[INFO]  ServerSession  Session1.3 connecting to IpAddress 127.0.0.1 for HostName 'localhost'
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  ServerSession  Session1.3 made connection; ServerVersion=5.7.33; ConnectionId=403; Compression=False; Attributes=True; DeprecateEof=True; Ssl=True; SessionTrack=True
[INFO]  ServerSession  Session1.2 successfully pinged server
[INFO]  ServerSession  Session1.1 successfully pinged server
[INFO]  ServerSession  Session1.3 successfully pinged server
[INFO]  ServerSession  Session1.2 successfully pinged server
[INFO]  ServerSession  Session1.1 successfully pinged server
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.
[INFO]  BackgroundConnectionResetHelper  Waiting for semaphore.

The "ping" and "semaphore" messages are clearly an increase in verbosity since 1.2.1.

@bgrainger bgrainger self-assigned this Mar 11, 2021
@bgrainger bgrainger added the bug label Mar 11, 2021
@bgrainger bgrainger changed the title Reduce Logging Logging verbosity for opening a connection increased in 1.3.0 Mar 11, 2021
@bgrainger
Copy link
Member

Fixed in 1.3.1.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment