Skip to content

Commit

Permalink
SNOW-834781: Remove log4net and delegate logging to consumers
Browse files Browse the repository at this point in the history
  • Loading branch information
sfc-gh-ext-simba-lf committed Nov 9, 2024
1 parent 717a804 commit 650bb43
Show file tree
Hide file tree
Showing 52 changed files with 464 additions and 1,200 deletions.
35 changes: 18 additions & 17 deletions Snowflake.Data/Client/SnowflakeDbCommand.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
/*
/*
* Copyright (c) 2012-2019 Snowflake Computing Inc. All rights reserved.
*/

Expand All @@ -10,6 +10,7 @@
using System.Threading;
using System.Threading.Tasks;
using Snowflake.Data.Log;
using Microsoft.Extensions.Logging;

namespace Snowflake.Data.Client
{
Expand All @@ -22,13 +23,13 @@ public class SnowflakeDbCommand : DbCommand

private SnowflakeDbParameterCollection parameterCollection;

private SFLogger logger = SFLoggerFactory.GetLogger<SnowflakeDbCommand>();
private ILogger logger = SFLoggerFactory.GetLogger<SnowflakeDbCommand>();

private readonly QueryResultsAwaiter _queryResultsAwaiter = QueryResultsAwaiter.Instance;

public SnowflakeDbCommand()
{
logger.Debug("Constructing SnowflakeDbCommand class");
logger.LogDebug("Constructing SnowflakeDbCommand class");
// by default, no query timeout
this.CommandTimeout = 0;
parameterCollection = new SnowflakeDbParameterCollection();
Expand Down Expand Up @@ -165,7 +166,7 @@ public override void Cancel()

public override int ExecuteNonQuery()
{
logger.Debug($"ExecuteNonQuery");
logger.LogDebug($"ExecuteNonQuery");
SFBaseResultSet resultSet = ExecuteInternal();
long total = 0;
do
Expand All @@ -190,7 +191,7 @@ public override int ExecuteNonQuery()

public override async Task<int> ExecuteNonQueryAsync(CancellationToken cancellationToken)
{
logger.Debug($"ExecuteNonQueryAsync");
logger.LogDebug($"ExecuteNonQueryAsync");
cancellationToken.ThrowIfCancellationRequested();

var resultSet = await ExecuteInternalAsync(cancellationToken).ConfigureAwait(false);
Expand All @@ -217,7 +218,7 @@ public override async Task<int> ExecuteNonQueryAsync(CancellationToken cancellat

public override object ExecuteScalar()
{
logger.Debug($"ExecuteScalar");
logger.LogDebug($"ExecuteScalar");
SFBaseResultSet resultSet = ExecuteInternal();

if(resultSet.Next())
Expand All @@ -228,7 +229,7 @@ public override object ExecuteScalar()

public override async Task<object> ExecuteScalarAsync(CancellationToken cancellationToken)
{
logger.Debug($"ExecuteScalarAsync");
logger.LogDebug($"ExecuteScalarAsync");
cancellationToken.ThrowIfCancellationRequested();

var result = await ExecuteInternalAsync(cancellationToken).ConfigureAwait(false);
Expand Down Expand Up @@ -263,22 +264,22 @@ protected override DbParameter CreateDbParameter()

protected override DbDataReader ExecuteDbDataReader(CommandBehavior behavior)
{
logger.Debug($"ExecuteDbDataReader");
logger.LogDebug($"ExecuteDbDataReader");
SFBaseResultSet resultSet = ExecuteInternal();
return new SnowflakeDbDataReader(this, resultSet);
}

protected override async Task<DbDataReader> ExecuteDbDataReaderAsync(CommandBehavior behavior, CancellationToken cancellationToken)
{
logger.Debug($"ExecuteDbDataReaderAsync");
logger.LogDebug($"ExecuteDbDataReaderAsync");
try
{
var result = await ExecuteInternalAsync(cancellationToken).ConfigureAwait(false);
return new SnowflakeDbDataReader(this, result);
}
catch (Exception ex)
{
logger.Error("The command failed to execute.", ex);
logger.LogError("The command failed to execute.", ex);
throw;
}
}
Expand All @@ -290,7 +291,7 @@ protected override async Task<DbDataReader> ExecuteDbDataReaderAsync(CommandBeha
/// <returns>The query id.</returns>
public string ExecuteInAsyncMode()
{
logger.Debug($"ExecuteInAsyncMode");
logger.LogDebug($"ExecuteInAsyncMode");
SFBaseResultSet resultSet = ExecuteInternal(asyncExec: true);
return resultSet.queryId;
}
Expand All @@ -303,7 +304,7 @@ public string ExecuteInAsyncMode()
/// <returns>The query id.</returns>
public async Task<string> ExecuteAsyncInAsyncMode(CancellationToken cancellationToken)
{
logger.Debug($"ExecuteAsyncInAsyncMode");
logger.LogDebug($"ExecuteAsyncInAsyncMode");
var resultSet = await ExecuteInternalAsync(cancellationToken, asyncExec: true).ConfigureAwait(false);
return resultSet.queryId;
}
Expand All @@ -315,7 +316,7 @@ public async Task<string> ExecuteAsyncInAsyncMode(CancellationToken cancellation
/// <returns>The query status.</returns>
public QueryStatus GetQueryStatus(string queryId)
{
logger.Debug($"GetQueryStatus");
logger.LogDebug($"GetQueryStatus");
return _queryResultsAwaiter.GetQueryStatus(connection, queryId);
}

Expand All @@ -327,7 +328,7 @@ public QueryStatus GetQueryStatus(string queryId)
/// <returns>The query status.</returns>
public async Task<QueryStatus> GetQueryStatusAsync(string queryId, CancellationToken cancellationToken)
{
logger.Debug($"GetQueryStatusAsync");
logger.LogDebug($"GetQueryStatusAsync");
return await _queryResultsAwaiter.GetQueryStatusAsync(connection, queryId, cancellationToken);
}

Expand All @@ -338,7 +339,7 @@ public async Task<QueryStatus> GetQueryStatusAsync(string queryId, CancellationT
/// <returns>The query results.</returns>
public DbDataReader GetResultsFromQueryId(string queryId)
{
logger.Debug($"GetResultsFromQueryId");
logger.LogDebug($"GetResultsFromQueryId");

Task task = _queryResultsAwaiter.RetryUntilQueryResultIsAvailable(connection, queryId, CancellationToken.None, false);
task.Wait();
Expand All @@ -356,7 +357,7 @@ public DbDataReader GetResultsFromQueryId(string queryId)
/// <returns>The query results.</returns>
public async Task<DbDataReader> GetResultsFromQueryIdAsync(string queryId, CancellationToken cancellationToken)
{
logger.Debug($"GetResultsFromQueryIdAsync");
logger.LogDebug($"GetResultsFromQueryIdAsync");

await _queryResultsAwaiter.RetryUntilQueryResultIsAvailable(connection, queryId, cancellationToken, true);

Expand Down Expand Up @@ -464,7 +465,7 @@ private void CheckIfCommandTextIsSet()
if (string.IsNullOrEmpty(CommandText))
{
var errorMessage = "Unable to execute command due to command text not being set";
logger.Error(errorMessage);
logger.LogError(errorMessage);
throw new Exception(errorMessage);
}
}
Expand Down
49 changes: 25 additions & 24 deletions Snowflake.Data/Client/SnowflakeDbConnection.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
/*
/*
* Copyright (c) 2012-2021 Snowflake Computing Inc. All rights reserved.
*/

Expand All @@ -10,13 +10,14 @@
using System.Data;
using System.Threading;
using Snowflake.Data.Log;
using Microsoft.Extensions.Logging;

namespace Snowflake.Data.Client
{
[System.ComponentModel.DesignerCategory("Code")]
public class SnowflakeDbConnection : DbConnection
{
private SFLogger logger = SFLoggerFactory.GetLogger<SnowflakeDbConnection>();
private ILogger logger = SFLoggerFactory.GetLogger<SnowflakeDbConnection>();

internal SFSession SfSession { get; set; }

Expand Down Expand Up @@ -113,7 +114,7 @@ public void PreventPooling()
throw new Exception("Session not yet created for this connection. Unable to prevent the session from pooling");
}
SfSession.SetPooling(false);
logger.Debug($"Session {SfSession.sessionId} marked not to be pooled any more");
logger.LogDebug($"Session {SfSession.sessionId} marked not to be pooled any more");
}

internal bool HasActiveExplicitTransaction() => ExplicitTransaction != null && ExplicitTransaction.IsActive;
Expand All @@ -131,7 +132,7 @@ private bool TryToReturnSessionToPool()
var sessionReturnedToPool = SnowflakeDbConnectionPool.AddSession(SfSession);
if (sessionReturnedToPool)
{
logger.Debug($"Session pooled: {SfSession.sessionId}");
logger.LogDebug($"Session pooled: {SfSession.sessionId}");
}
return sessionReturnedToPool;
}
Expand All @@ -142,28 +143,28 @@ private TransactionRollbackStatus TerminateTransactionForDirtyConnectionReturnin
return TransactionRollbackStatus.Success;
try
{
logger.Debug("Closing dirty connection: an active transaction exists in session: " + SfSession.sessionId);
logger.LogDebug("Closing dirty connection: an active transaction exists in session: " + SfSession.sessionId);
using (IDbCommand command = CreateCommand())
{
command.CommandText = "ROLLBACK";
command.ExecuteNonQuery();
// error to indicate a problem within application code that a connection was closed while still having a pending transaction
logger.Error("Closing dirty connection: rollback transaction in session " + SfSession.sessionId + " succeeded.");
logger.LogError("Closing dirty connection: rollback transaction in session " + SfSession.sessionId + " succeeded.");
ExplicitTransaction = null;
return TransactionRollbackStatus.Success;
}
}
catch (Exception exception)
{
// error to indicate a problem with rollback of an active transaction and inability to return dirty connection to the pool
logger.Error("Closing dirty connection: rollback transaction in session: " + SfSession.sessionId + " failed, exception: " + exception.Message);
logger.LogError("Closing dirty connection: rollback transaction in session: " + SfSession.sessionId + " failed, exception: " + exception.Message);
return TransactionRollbackStatus.Failure; // connection won't be pooled
}
}

public override void ChangeDatabase(string databaseName)
{
logger.Debug($"ChangeDatabase to:{databaseName}");
logger.LogDebug($"ChangeDatabase to:{databaseName}");

string alterDbCommand = $"use database {databaseName}";

Expand All @@ -176,7 +177,7 @@ public override void ChangeDatabase(string databaseName)

public override void Close()
{
logger.Debug("Close Connection.");
logger.LogDebug("Close Connection.");
if (IsNonClosedWithSession())
{
var returnedToPool = TryToReturnSessionToPool();
Expand All @@ -200,7 +201,7 @@ public override async Task CloseAsync()

public virtual async Task CloseAsync(CancellationToken cancellationToken)
{
logger.Debug("Close Connection.");
logger.LogDebug("Close Connection.");
TaskCompletionSource<object> taskCompletionSource = new TaskCompletionSource<object>();

if (cancellationToken.IsCancellationRequested)
Expand All @@ -225,18 +226,18 @@ await SfSession.CloseAsync(cancellationToken).ContinueWith(
if (previousTask.IsFaulted)
{
// Exception from SfSession.CloseAsync
logger.Error("Error closing the session", previousTask.Exception);
logger.LogError("Error closing the session", previousTask.Exception);
taskCompletionSource.SetException(previousTask.Exception);
}
else if (previousTask.IsCanceled)
{
_connectionState = ConnectionState.Closed;
logger.Debug("Session close canceled");
logger.LogDebug("Session close canceled");
taskCompletionSource.SetCanceled();
}
else
{
logger.Debug("Session closed successfully");
logger.LogDebug("Session closed successfully");
_connectionState = ConnectionState.Closed;
taskCompletionSource.SetResult(null);
}
Expand All @@ -245,7 +246,7 @@ await SfSession.CloseAsync(cancellationToken).ContinueWith(
}
else
{
logger.Debug("Session not opened. Nothing to do.");
logger.LogDebug("Session not opened. Nothing to do.");
taskCompletionSource.SetResult(null);
}
}
Expand All @@ -260,10 +261,10 @@ protected virtual bool CanReuseSession(TransactionRollbackStatus transactionRoll

public override void Open()
{
logger.Debug("Open Connection.");
logger.LogDebug("Open Connection.");
if (_connectionState != ConnectionState.Closed)
{
logger.Debug($"Open with a connection already opened: {_connectionState}");
logger.LogDebug($"Open with a connection already opened: {_connectionState}");
return;
}
try
Expand All @@ -272,14 +273,14 @@ public override void Open()
SfSession = SnowflakeDbConnectionPool.GetSession(ConnectionString, Password);
if (SfSession == null)
throw new SnowflakeDbException(SFError.INTERNAL_ERROR, "Could not open session");
logger.Debug($"Connection open with pooled session: {SfSession.sessionId}");
logger.LogDebug($"Connection open with pooled session: {SfSession.sessionId}");
OnSessionEstablished();
}
catch (Exception e)
{
// Otherwise when Dispose() is called, the close request would timeout.
_connectionState = ConnectionState.Closed;
logger.Error("Unable to connect: ", e);
logger.LogError("Unable to connect: ", e);
if (e is SnowflakeDbException)
{
throw;
Expand All @@ -294,10 +295,10 @@ public override void Open()

public override Task OpenAsync(CancellationToken cancellationToken)
{
logger.Debug("Open Connection Async.");
logger.LogDebug("Open Connection Async.");
if (_connectionState != ConnectionState.Closed)
{
logger.Debug($"Open with a connection already opened: {_connectionState}");
logger.LogDebug($"Open with a connection already opened: {_connectionState}");
return Task.CompletedTask;
}
registerConnectionCancellationCallback(cancellationToken);
Expand All @@ -311,7 +312,7 @@ public override Task OpenAsync(CancellationToken cancellationToken)
// Exception from SfSession.OpenAsync
Exception sfSessionEx = previousTask.Exception;
_connectionState = ConnectionState.Closed;
logger.Error("Unable to connect", sfSessionEx);
logger.LogError("Unable to connect", sfSessionEx);
throw new SnowflakeDbException(
sfSessionEx,
SnowflakeDbException.CONNECTION_FAILURE_SSTATE,
Expand All @@ -321,14 +322,14 @@ public override Task OpenAsync(CancellationToken cancellationToken)
else if (previousTask.IsCanceled)
{
_connectionState = ConnectionState.Closed;
logger.Debug("Connection canceled");
logger.LogDebug("Connection canceled");
throw new TaskCanceledException("Connecting was cancelled");
}
else
{
// Only continue if the session was opened successfully
SfSession = previousTask.Result;
logger.Debug($"Connection open with pooled session: {SfSession.sessionId}");
logger.LogDebug($"Connection open with pooled session: {SfSession.sessionId}");
OnSessionEstablished();
}
}, TaskContinuationOptions.None); // this continuation should be executed always (even if the whole operation was canceled) because it sets the proper state of the connection
Expand Down Expand Up @@ -392,7 +393,7 @@ protected override void Dispose(bool disposing)
catch (Exception ex)
{
// Prevent an exception from being thrown when disposing of this object
logger.Error("Unable to close connection", ex);
logger.LogError("Unable to close connection", ex);
}
}
else
Expand Down
Loading

0 comments on commit 650bb43

Please sign in to comment.