Skip to content

Commit ec6ccdd

Browse files
bgraingerbgrainger
committed
Merge log-levels into master. #984
Conflicts: src/MySqlConnector/Core/ServerSession.cs
2 parents 45c2e9c + 30aed32 commit ec6ccdd

File tree

9 files changed

+122
-122
lines changed

9 files changed

+122
-122
lines changed

‎src/MySqlConnector/Core/BackgroundConnectionResetHelper.cs‎

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -15,13 +15,13 @@ public static void AddSession(ServerSession session, MySqlConnection? owningConn
1515
lock (s_lock)
1616
s_resetTasks.Add(resetTask);
1717

18-
if (Log.IsDebugEnabled())
19-
Log.Debug("Started Session{0} reset in background; waiting TaskCount: {1}.", session.Id, s_resetTasks.Count);
18+
if (Log.IsTraceEnabled())
19+
Log.Trace("Started Session{0} reset in background; waiting TaskCount: {1}.", session.Id, s_resetTasks.Count);
2020

2121
// release only if it is likely to succeed
2222
if (s_semaphore.CurrentCount == 0)
2323
{
24-
Log.Debug("Releasing semaphore.");
24+
Log.Trace("Releasing semaphore.");
2525
try
2626
{
2727
s_semaphore.Release();
@@ -35,7 +35,7 @@ public static void AddSession(ServerSession session, MySqlConnection? owningConn
3535

3636
public static void Start()
3737
{
38-
Log.Info("Starting BackgroundConnectionResetHelper worker.");
38+
Log.Trace("Starting BackgroundConnectionResetHelper worker.");
3939
lock (s_lock)
4040
{
4141
if (s_workerTask is null)
@@ -45,7 +45,7 @@ public static void Start()
4545

4646
public static void Stop()
4747
{
48-
Log.Info("Stopping BackgroundConnectionResetHelper worker.");
48+
Log.Trace("Stopping BackgroundConnectionResetHelper worker.");
4949
s_cancellationTokenSource.Cancel();
5050
Task? workerTask;
5151
lock (s_lock)
@@ -61,12 +61,12 @@ public static void Stop()
6161
{
6262
}
6363
}
64-
Log.Info("Stopped BackgroundConnectionResetHelper worker.");
64+
Log.Trace("Stopped BackgroundConnectionResetHelper worker.");
6565
}
6666

6767
public static async Task ReturnSessionsAsync()
6868
{
69-
Log.Info("Started BackgroundConnectionResetHelper worker.");
69+
Log.Trace("Started BackgroundConnectionResetHelper worker.");
7070

7171
List<Task<bool>> localTasks = new();
7272

@@ -76,7 +76,7 @@ public static async Task ReturnSessionsAsync()
7676
try
7777
{
7878
// block until AddSession releases the semaphore
79-
Log.Debug("Waiting for semaphore.");
79+
Log.Trace("Waiting for semaphore.");
8080
await s_semaphore.WaitAsync(s_cancellationTokenSource.Token).ConfigureAwait(false);
8181

8282
// process all sessions that have started being returned
@@ -91,8 +91,8 @@ public static async Task ReturnSessionsAsync()
9191
if (localTasks.Count == 0)
9292
break;
9393

94-
if (Log.IsDebugEnabled())
95-
Log.Debug("Found TaskCount {0} task(s) to process.", localTasks.Count);
94+
if (Log.IsTraceEnabled())
95+
Log.Trace("Found TaskCount {0} task(s) to process.", localTasks.Count);
9696

9797
await Task.WhenAll(localTasks);
9898
localTasks.Clear();

‎src/MySqlConnector/Core/CachedProcedure.cs‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -51,15 +51,15 @@ internal sealed class CachedProcedure
5151
}
5252
catch (MySqlException ex)
5353
{
54-
Log.Warn("Session{0} failed to retrieve metadata for Schema={1} Component={2}; falling back to INFORMATION_SCHEMA. Error: {3}", connection.Session.Id, schema, component, ex.Message);
54+
Log.Info("Session{0} failed to retrieve metadata for Schema={1} Component={2}; falling back to INFORMATION_SCHEMA. Error: {3}", connection.Session.Id, schema, component, ex.Message);
5555
if (ex.ErrorCode == MySqlErrorCode.TableAccessDenied)
5656
connection.Session.ProcAccessDenied = true;
5757
}
5858
}
5959

6060
if (connection.Session.ServerVersion.Version < ServerVersions.SupportsProcedureCache)
6161
{
62-
Log.Warn("Session{0} ServerVersion={1} does not support cached procedures", connection.Session.Id, connection.Session.ServerVersion.OriginalString);
62+
Log.Info("Session{0} ServerVersion={1} does not support cached procedures", connection.Session.Id, connection.Session.ServerVersion.OriginalString);
6363
return null;
6464
}
6565

@@ -97,8 +97,8 @@ FROM information_schema.parameters
9797
}
9898
}
9999

100-
if (Log.IsInfoEnabled())
101-
Log.Info("Procedure for Schema={0} Component={1} has RoutineCount={2}, ParameterCount={3}", schema, component, routineCount, parameters.Count);
100+
if (Log.IsTraceEnabled())
101+
Log.Trace("Procedure for Schema={0} Component={1} has RoutineCount={2}, ParameterCount={3}", schema, component, routineCount, parameters.Count);
102102
return routineCount == 0 ? null : new CachedProcedure(schema, component, parameters);
103103
}
104104

‎src/MySqlConnector/Core/CommandExecutor.cs‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -23,8 +23,8 @@ public static async Task<MySqlDataReader> ExecuteReaderAsync(IReadOnlyList<IMySq
2323
// pre-requisite: Connection is non-null must be checked before calling this method
2424
var connection = command.Connection!;
2525

26-
if (Log.IsDebugEnabled())
27-
Log.Debug("Session{0} ExecuteReader {1} CommandCount: {2}", connection.Session.Id, ioBehavior, commands.Count);
26+
if (Log.IsTraceEnabled())
27+
Log.Trace("Session{0} ExecuteReader {1} CommandCount: {2}", connection.Session.Id, ioBehavior, commands.Count);
2828

2929
Dictionary<string, CachedProcedure?>? cachedProcedures = null;
3030
foreach (var command2 in commands)
@@ -61,7 +61,7 @@ public static async Task<MySqlDataReader> ExecuteReaderAsync(IReadOnlyList<IMySq
6161
}
6262
catch (MySqlException ex) when (ex.ErrorCode == MySqlErrorCode.QueryInterrupted && cancellationToken.IsCancellationRequested)
6363
{
64-
Log.Warn("Session{0} query was interrupted", connection.Session.Id);
64+
Log.Info("Session{0} query was interrupted", connection.Session.Id);
6565
throw new OperationCanceledException(ex. Message, ex, cancellationToken);
6666
}
6767
catch (Exception ex) when (payload.Span.Length > 4_194_304 && (ex is SocketException or IOException or MySqlProtocolException))

‎src/MySqlConnector/Core/ConcatenatedCommandPayloadCreator.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -19,8 +19,8 @@ public bool WriteQueryCommand(ref CommandListPosition commandListPosition, IDict
1919
do
2020
{
2121
var command = commandListPosition.Commands[commandListPosition.CommandIndex];
22-
if (Log.IsDebugEnabled())
23-
Log.Debug("Session{0} Preparing command payload; CommandText: {1}", command.Connection!.Session.Id, command.CommandText);
22+
if (Log.IsTraceEnabled())
23+
Log.Trace("Session{0} Preparing command payload; CommandText: {1}", command.Connection!.Session.Id, command.CommandText);
2424

2525
isComplete = SingleCommandPayloadCreator.WriteQueryPayload(command, cachedProcedures, writer);
2626
commandListPosition.CommandIndex++;

‎src/MySqlConnector/Core/ConnectionPool.cs‎

Lines changed: 27 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -28,15 +28,15 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
2828
// on the lock in RecoverLeakedSessions in high-concurrency situations
2929
if (IsEmpty && unchecked(((uint) Environment.TickCount) - m_lastRecoveryTime) >= 1000u)
3030
{
31-
Log.Info("Pool{0} is empty; recovering leaked sessions", m_logArguments);
31+
Log.Debug("Pool{0} is empty; trying to recover any leaked sessions", m_logArguments);
3232
await RecoverLeakedSessionsAsync(ioBehavior).ConfigureAwait(false);
3333
}
3434

3535
if (ConnectionSettings.MinimumPoolSize > 0)
3636
await CreateMinimumPooledSessions(ioBehavior, cancellationToken).ConfigureAwait(false);
3737

3838
// wait for an open slot (until the cancellationToken is cancelled, which is typically due to timeout)
39-
Log.Debug("Pool{0} waiting for an available session", m_logArguments);
39+
Log.Trace("Pool{0} waiting for an available session", m_logArguments);
4040
if (ioBehavior == IOBehavior.Asynchronous)
4141
await m_sessionSemaphore.WaitAsync(cancellationToken).ConfigureAwait(false);
4242
else
@@ -56,12 +56,12 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
5656
}
5757
if (session is not null)
5858
{
59-
Log.Debug("Pool{0} found an existing session; checking it for validity", m_logArguments);
59+
Log.Trace("Pool{0} found an existing session; checking it for validity", m_logArguments);
6060
bool reuseSession;
6161

6262
if (session.PoolGeneration != m_generation)
6363
{
64-
Log.Debug("Pool{0} discarding session due to wrong generation", m_logArguments);
64+
Log.Trace("Pool{0} discarding session due to wrong generation", m_logArguments);
6565
reuseSession = false;
6666
}
6767
else
@@ -83,7 +83,7 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
8383
if (!reuseSession)
8484
{
8585
// session is either old or cannot communicate with the server
86-
Log.Warn("Pool{0} Session{1} is unusable; destroying it", m_logArguments[0], session.Id);
86+
Log.Info("Pool{0} Session{1} is unusable; destroying it", m_logArguments[0], session.Id);
8787
AdjustHostConnectionCount(session, -1);
8888
await session.DisposeAsync(ioBehavior, cancellationToken).ConfigureAwait(false);
8989
}
@@ -97,8 +97,8 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
9797
m_leasedSessions.Add(session.Id, session);
9898
leasedSessionsCountPooled = m_leasedSessions.Count;
9999
}
100-
if (Log.IsDebugEnabled())
101-
Log.Debug("Pool{0} returning pooled Session{1} to caller; LeasedSessionsCount={2}", m_logArguments[0], session.Id, leasedSessionsCountPooled);
100+
if (Log.IsTraceEnabled())
101+
Log.Trace("Pool{0} returning pooled Session{1} to caller; LeasedSessionsCount={2}", m_logArguments[0], session.Id, leasedSessionsCountPooled);
102102
return session;
103103
}
104104
}
@@ -113,8 +113,8 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
113113
m_leasedSessions.Add(session.Id, session);
114114
leasedSessionsCountNew = m_leasedSessions.Count;
115115
}
116-
if (Log.IsDebugEnabled())
117-
Log.Debug("Pool{0} returning new Session{1} to caller; LeasedSessionsCount={2}", m_logArguments[0], session.Id, leasedSessionsCountNew);
116+
if (Log.IsTraceEnabled())
117+
Log.Trace("Pool{0} returning new Session{1} to caller; LeasedSessionsCount={2}", m_logArguments[0], session.Id, leasedSessionsCountNew);
118118
return session;
119119
}
120120
catch (Exception ex)
@@ -129,7 +129,7 @@ public async ValueTask<ServerSession> GetSessionAsync(MySqlConnection connection
129129
}
130130
catch (Exception unexpectedException)
131131
{
132-
Log.Error(unexpectedException, "Pool{0} unexpected error in GetSessionAsync: {1}", m_logArguments[0], unexpectedException.Message);
132+
Log.Warn(unexpectedException, "Pool{0} unexpected error in GetSessionAsync: {1}", m_logArguments[0], unexpectedException.Message);
133133
}
134134
}
135135

@@ -164,8 +164,8 @@ public async ValueTask ReturnAsync(IOBehavior ioBehavior, ServerSession session)
164164
public async ValueTask<int> ReturnAsync(IOBehavior ioBehavior, ServerSession session)
165165
#endif
166166
{
167-
if (Log.IsDebugEnabled())
168-
Log.Debug("Pool{0} receiving Session{1} back", m_logArguments[0], session.Id);
167+
if (Log.IsTraceEnabled())
168+
Log.Trace("Pool{0} receiving Session{1} back", m_logArguments[0], session.Id);
169169

170170
try
171171
{
@@ -181,9 +181,9 @@ public async ValueTask<int> ReturnAsync(IOBehavior ioBehavior, ServerSession ses
181181
else
182182
{
183183
if (sessionHealth == 1)
184-
Log.Warn("Pool{0} received invalid Session{1}; destroying it", m_logArguments[0], session.Id);
184+
Log.Info("Pool{0} received invalid Session{1}; destroying it", m_logArguments[0], session.Id);
185185
else
186-
Log.Info("Pool{0} received expired Session{1}; destroying it", m_logArguments[0], session.Id);
186+
Log.Debug("Pool{0} received expired Session{1}; destroying it", m_logArguments[0], session.Id);
187187
AdjustHostConnectionCount(session, -1);
188188
await session.DisposeAsync(ioBehavior, CancellationToken.None).ConfigureAwait(false);
189189
}
@@ -210,7 +210,7 @@ public async Task ClearAsync(IOBehavior ioBehavior, CancellationToken cancellati
210210

211211
public async Task ReapAsync(IOBehavior ioBehavior, CancellationToken cancellationToken)
212212
{
213-
Log.Debug("Pool{0} reaping connection pool", m_logArguments);
213+
Log.Trace("Pool{0} reaping connection pool", m_logArguments);
214214
await RecoverLeakedSessionsAsync(ioBehavior).ConfigureAwait(false);
215215
await CleanPoolAsync(ioBehavior, session => (unchecked((uint) Environment.TickCount) - session.LastReturnedTicks) / 1000 >= ConnectionSettings.ConnectionIdleTimeout, true, cancellationToken).ConfigureAwait(false);
216216
}
@@ -250,7 +250,7 @@ private async Task RecoverLeakedSessionsAsync(IOBehavior ioBehavior)
250250
}
251251
}
252252
if (recoveredSessions.Count == 0)
253-
Log.Debug("Pool{0} recovered no sessions", m_logArguments);
253+
Log.Trace("Pool{0} recovered no sessions", m_logArguments);
254254
else
255255
Log.Warn("Pool{0}: RecoveredSessionCount={1}", m_logArguments[0], recoveredSessions.Count);
256256
foreach (var session in recoveredSessions)
@@ -306,7 +306,7 @@ private async Task CleanPoolAsync(IOBehavior ioBehavior, Func<ServerSession, boo
306306
if (shouldCleanFn(session))
307307
{
308308
// session should be cleaned; dispose it and keep iterating
309-
Log.Info("Pool{0} found Session{1} to clean up", m_logArguments[0], session.Id);
309+
Log.Debug("Pool{0} found Session{1} to clean up", m_logArguments[0], session.Id);
310310
await session.DisposeAsync(ioBehavior, cancellationToken).ConfigureAwait(false);
311311
}
312312
else
@@ -371,40 +371,40 @@ private async Task CreateMinimumPooledSessions(IOBehavior ioBehavior, Cancellati
371371
private async ValueTask<ServerSession> ConnectSessionAsync(string logMessage, int startTickCount, IOBehavior ioBehavior, CancellationToken cancellationToken)
372372
{
373373
var session = new ServerSession(this, m_generation, Interlocked.Increment(ref m_lastSessionId));
374-
if (Log.IsInfoEnabled())
375-
Log.Info(logMessage, m_logArguments[0], session.Id);
374+
if (Log.IsDebugEnabled())
375+
Log.Debug(logMessage, m_logArguments[0], session.Id);
376376
var statusInfo = await session.ConnectAsync(ConnectionSettings, startTickCount, m_loadBalancer, ioBehavior, cancellationToken).ConfigureAwait(false);
377377
Exception? redirectionException = null;
378378

379379
if (statusInfo is not null && statusInfo.StartsWith("Location: mysql://", StringComparison.Ordinal))
380380
{
381381
// server redirection string has the format "Location: mysql://{host}:{port}/user={userId}[&ttl={ttl}]"
382-
Log.Info("Session{0} has server redirection header {1}", session.Id, statusInfo);
382+
Log.Trace("Session{0} has server redirection header {1}", session.Id, statusInfo);
383383

384384
if (ConnectionSettings.ServerRedirectionMode == MySqlServerRedirectionMode.Disabled)
385385
{
386-
Log.Info("Pool{0} server redirection is disabled; ignoring redirection", m_logArguments);
386+
Log.Trace("Pool{0} server redirection is disabled; ignoring redirection", m_logArguments);
387387
}
388388
else if (Utility.TryParseRedirectionHeader(statusInfo, out var host, out var port, out var user))
389389
{
390390
if (host != ConnectionSettings.HostNames![0] || port != ConnectionSettings.Port || user != ConnectionSettings.UserID)
391391
{
392392
var redirectedSettings = ConnectionSettings.CloneWith(host, port, user);
393-
Log.Info("Pool{0} opening new connection to Host={1}; Port={2}; User={3}", m_logArguments[0], host, port, user);
393+
Log.Debug("Pool{0} opening new connection to Host={1}; Port={2}; User={3}", m_logArguments[0], host, port, user);
394394
var redirectedSession = new ServerSession(this, m_generation, Interlocked.Increment(ref m_lastSessionId));
395395
try
396396
{
397397
await redirectedSession.ConnectAsync(redirectedSettings, startTickCount, m_loadBalancer, ioBehavior, cancellationToken).ConfigureAwait(false);
398398
}
399399
catch (Exception ex)
400400
{
401-
Log.Warn(ex, "Pool{0} failed to connect redirected Session{1}", m_logArguments[0], redirectedSession.Id);
401+
Log.Info(ex, "Pool{0} failed to connect redirected Session{1}", m_logArguments[0], redirectedSession.Id);
402402
redirectionException = ex;
403403
}
404404

405405
if (redirectionException is null)
406406
{
407-
Log.Info("Pool{0} closing Session{1} to use redirected Session{2} instead", m_logArguments[0], session.Id, redirectedSession.Id);
407+
Log.Trace("Pool{0} closing Session{1} to use redirected Session{2} instead", m_logArguments[0], session.Id, redirectedSession.Id);
408408
await session.DisposeAsync(ioBehavior, cancellationToken).ConfigureAwait(false);
409409
return redirectedSession;
410410
}
@@ -421,7 +421,7 @@ private async ValueTask<ServerSession> ConnectSessionAsync(string logMessage, in
421421
}
422422
else
423423
{
424-
Log.Info("Session{0} is already connected to this server; ignoring redirection", session.Id);
424+
Log.Trace("Session{0} is already connected to this server; ignoring redirection", session.Id);
425425
}
426426
}
427427
}
@@ -486,9 +486,9 @@ private async ValueTask<ServerSession> ConnectSessionAsync(string logMessage, in
486486
if (connectionSettings.ConnectionReset)
487487
BackgroundConnectionResetHelper.Start();
488488
}
489-
else if (pool != newPool && Log.IsInfoEnabled())
489+
else if (pool != newPool && Log.IsDebugEnabled())
490490
{
491-
Log.Info("Pool{0} was created but will not be used (due to race)", newPool.m_logArguments);
491+
Log.Debug("Pool{0} was created but will not be used (due to race)", newPool.m_logArguments);
492492
}
493493

494494
return pool;

0 commit comments

Comments
 (0)