IDbCommand にログ出力を追加

DbLoggingWrapper.vb

Imports System.Data
Imports System.Runtime.CompilerServices
Imports Common.Logging

Public Class DbLoggingWrapper

    Private Shared _logger As ILog
    Public Shared Property Logger As ILog
        Get
            If _logger Is Nothing Then
                _logger = LogManager.GetLogger(Of DbLoggingWrapper)()
            End If
            Return _logger
        End Get
        Set(value As ILog)
            _logger = value
        End Set
    End Property

    Private Shared _loggingTimeout As TimeSpan = TimeSpan.FromSeconds(3)
    Public Shared Property LoggingTimeout As TimeSpan
        Get
            Return _loggingTimeout
        End Get
        Set(value As TimeSpan)
            _loggingTimeout = value
        End Set
    End Property

End Class

Public Module DbLoggingWrapperExtensions

    <Extension>
    Public Function BaseConnection(connection As IDbConnection) As IDbConnection
        Dim wrapper = TryCast(connection, DbConnectionLoggingWrapper)
        Return If(wrapper Is Nothing, connection, wrapper.BaseConnection)
    End Function

    <Extension>
    Public Function BaseConnection(Of TConnection As {IDbConnection, Class})(connection As IDbConnection) As TConnection
        Return DirectCast(BaseConnection(connection), TConnection)
    End Function

    <Extension>
    Public Function BaseCommand(command As IDbCommand) As IDbCommand
        Dim wrapper = TryCast(command, DbCommandLoggingWrapper)
        Return If(wrapper Is Nothing, command, wrapper.BaseCommand)
    End Function

    <Extension>
    Public Function BaseCommand(Of TCommand As {IDbCommand, Class})(command As IDbCommand) As TCommand
        Return DirectCast(BaseCommand(command), TCommand)
    End Function

    <Extension>
    Public Function BaseTransaction(transaction As IDbTransaction) As IDbTransaction
        Dim wrapper = TryCast(transaction, DbTransactionLoggingWrapper)
        Return If(wrapper Is Nothing, transaction, wrapper.BaseTransaction)
    End Function

    <Extension>
    Public Function BaseTransaction(Of TTransaction As {IDbTransaction, Class})(transaction As IDbTransaction) As TTransaction
        Return DirectCast(BaseTransaction(transaction), TTransaction)
    End Function
End Module

Public Class DbConnectionLoggingWrapper
    Implements IDbConnection

    Private _logger As ILog
    Private _connection As IDbConnection

    Public Sub New(connection As IDbConnection)
        _connection = connection
        _logger = DbLoggingWrapper.Logger
    End Sub

    Public Property BaseConnection As IDbConnection

    Public Function BeginTransaction() As IDbTransaction Implements IDbConnection.BeginTransaction
        Try
            Dim trans = _connection.BeginTransaction()
            Dim result = New DbTransactionLoggingWrapper(trans)
            _logger.Debug(Sub(f) f("トランザクションを開始しました。。アイソレーションレベル:{0}", result.IsolationLevel))
            Return result
        Catch ex As Exception
            _logger.Error(Sub(f) f("トランザクションの開始に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Function

    Public Function BeginTransaction(il As IsolationLevel) As IDbTransaction Implements IDbConnection.BeginTransaction
        Try
            Dim result = New DbTransactionLoggingWrapper(_connection.BeginTransaction(il))
            _logger.Debug(Sub(f) f("トランザクションを開始しました。アイソレーションレベル:{0}", result.IsolationLevel))
            Return result
        Catch ex As Exception
            _logger.Error(Sub(f) f("トランザクションの開始に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Function

    Public Sub ChangeDatabase(databaseName As String) Implements IDbConnection.ChangeDatabase
        _connection.ChangeDatabase(databaseName)
    End Sub

    Public Sub Close() Implements IDbConnection.Close
        Try
            _connection.Close()
            _logger.Trace("コネクションを切断しました。")
        Catch ex As Exception
            _logger.Error(Sub(f) f("コネクションの切断に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Sub

    Public Property ConnectionString As String Implements IDbConnection.ConnectionString
        Get
            Return _connection.ConnectionString
        End Get
        Set(value As String)
            _connection.ConnectionString = value
        End Set
    End Property

    Public ReadOnly Property ConnectionTimeout As Integer Implements IDbConnection.ConnectionTimeout
        Get
            Return _connection.ConnectionTimeout
        End Get
    End Property

    Public Function CreateCommand() As IDbCommand Implements IDbConnection.CreateCommand
        Return New DbCommandLoggingWrapper(_connection.CreateCommand())
    End Function

    Public ReadOnly Property Database As String Implements IDbConnection.Database
        Get
            Return _connection.Database
        End Get
    End Property

    Public Sub Open() Implements IDbConnection.Open
        Try
            Dim stopwatch = System.Diagnostics.Stopwatch.StartNew()
            _connection.Open()
            _logger.Trace(Sub(f) f("コネクションを接続しました。実行時間:{0}", stopwatch.Elapsed))
        Catch ex As Exception
            _logger.Error(Sub(f) f("コネクションの接続に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Sub

    Public ReadOnly Property State As ConnectionState Implements IDbConnection.State
        Get
            Return _connection.State
        End Get
    End Property

#Region "IDisposable Support"
    Private disposedValue As Boolean ' 重複する呼び出しを検出するには

    Protected Overridable Sub Dispose(disposing As Boolean)
        If Not Me.disposedValue Then
            If disposing Then
                _logger.Trace("コネクションを破棄しました。")
                _connection.Dispose()
            End If
        End If
        Me.disposedValue = True
    End Sub

    Protected Overrides Sub Finalize()
        Dispose(False)
        MyBase.Finalize()
    End Sub

    Public Sub Dispose() Implements IDisposable.Dispose
        Dispose(True)
        GC.SuppressFinalize(Me)
    End Sub
#End Region

    Private Function Dums() As String
        Dim sb = New System.Text.StringBuilder()
        sb.AppendLine()
        sb.Append("----- ").Append(_connection.GetType().Name).AppendLine(" -----")
        sb.Append(" ConnectionString:").Append(_connection.ConnectionString).AppendLine()
        sb.Append("ConnectionTimeout:").Append(_connection.ConnectionTimeout).AppendLine()
        sb.Append("         Database:").Append(_connection.Database).AppendLine()
        sb.Append("            State:").Append(_connection.State.ToString()).AppendLine()
        Return sb.ToString()
    End Function
End Class

Public Class DbTransactionLoggingWrapper
    Implements IDbTransaction

    Private _logger As ILog
    Private _transaction As IDbTransaction

    Public Sub New(transaction As IDbTransaction)
        _transaction = transaction
        _logger = DbLoggingWrapper.Logger
    End Sub

    Public ReadOnly Property BaseTransaction As IDbTransaction
        Get
            Return _transaction
        End Get
    End Property

    Public Sub Commit() Implements IDbTransaction.Commit
        Try
            _transaction.Commit()
            _logger.Trace("トランザクションをコミットしました。")
        Catch ex As Exception
            _logger.Error(Sub(f) f("トランザクションのコミットに失敗しました。アイソレーションレベル:{0}", _transaction.IsolationLevel), ex)
            Throw
        End Try
    End Sub

    Public ReadOnly Property Connection As IDbConnection Implements IDbTransaction.Connection
        Get
            Return _transaction.Connection
        End Get
    End Property

    Public ReadOnly Property IsolationLevel As IsolationLevel Implements IDbTransaction.IsolationLevel
        Get
            Return _transaction.IsolationLevel
        End Get
    End Property

    Public Sub Rollback() Implements IDbTransaction.Rollback
        Try
            _transaction.Rollback()
            _logger.Trace("トランザクションをロールバックしました。")
        Catch ex As Exception
            _logger.Error(Sub(f) f("トランザクションのロールバックに失敗しました。アイソレーションレベル:{0}", _transaction.IsolationLevel), ex)
            Throw
        End Try
    End Sub

#Region "IDisposable Support"
    Private disposedValue As Boolean ' 重複する呼び出しを検出するには

    ' IDisposable
    Protected Overridable Sub Dispose(disposing As Boolean)
        If Not Me.disposedValue Then
            If disposing Then
                _transaction.Dispose()
                _logger.Trace("トランザクションを破棄しました。")
            End If
        End If
        Me.disposedValue = True
    End Sub

    Protected Overrides Sub Finalize()
        Dispose(False)
        MyBase.Finalize()
    End Sub

    Public Sub Dispose() Implements IDisposable.Dispose
        Dispose(True)
        GC.SuppressFinalize(Me)
    End Sub
#End Region

End Class

Public Class DbCommandLoggingWrapper
    Implements IDbCommand

    Private _logger As ILog
    Private _command As IDbCommand
    Public Sub New(command As IDbCommand)
        _command = command
        _logger = DbLoggingWrapper.Logger
        Dim bindByName = _command.GetType().GetProperties().Where(Function(p) p.Name = "BindByName" And p.CanWrite And p.PropertyType = GetType(Boolean)).FirstOrDefault()
        If bindByName IsNot Nothing Then
            bindByName.SetValue(_command, True)
        End If
    End Sub

    Public ReadOnly Property BaseCommand As IDbCommand
        Get
            Return _command
        End Get
    End Property

    Public Sub Cancel() Implements IDbCommand.Cancel
        Try
            _command.Cancel()
            _logger.Trace("コマンドの実行をキャンセルしました。")
        Catch ex As Exception
            _logger.Error("コマンドのキャンセルに失敗しました。", ex)
            Throw
        End Try
    End Sub

    Public Property CommandText As String Implements IDbCommand.CommandText
        Get
            Return _command.CommandText
        End Get
        Set(value As String)
            _command.CommandText = value
        End Set
    End Property

    Public Property CommandTimeout As Integer Implements IDbCommand.CommandTimeout
        Get
            Return _command.CommandTimeout
        End Get
        Set(value As Integer)
            _command.CommandTimeout = value
        End Set
    End Property

    Public Property CommandType As CommandType Implements IDbCommand.CommandType
        Get
            Return _command.CommandType
        End Get
        Set(value As CommandType)
            _command.CommandType = value
        End Set
    End Property

    Public Property Connection As IDbConnection Implements IDbCommand.Connection
        Get
            Return _command.Connection
        End Get
        Set(value As IDbConnection)
            _command.Connection = value.BaseConnection()
        End Set
    End Property

    Public Function CreateParameter() As IDbDataParameter Implements IDbCommand.CreateParameter
        Return _command.CreateParameter()
    End Function

    Public Function ExecuteNonQuery() As Integer Implements IDbCommand.ExecuteNonQuery
        Try
            Dim stopwatch = System.Diagnostics.Stopwatch.StartNew()
            Dim result = _command.ExecuteNonQuery()
            stopwatch.Stop()
            If stopwatch.Elapsed > DbLoggingWrapper.LoggingTimeout Then
                _logger.Warn(Sub(f) f("コマンドの実行に規定時間以上を要しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            Else
                _logger.Trace(Sub(f) f("コマンドを実行しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            End If
            Return result
        Catch ex As Exception
            _logger.Error(Sub(f) f("コマンドの実行に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Function

    Public Function ExecuteReader() As IDataReader Implements IDbCommand.ExecuteReader
        Try
            Dim stopwatch = System.Diagnostics.Stopwatch.StartNew()
            Dim result = _command.ExecuteReader()
            stopwatch.Stop()
            If stopwatch.Elapsed > DbLoggingWrapper.LoggingTimeout Then
                _logger.Warn(Sub(f) f("コマンドの実行に規定時間以上を要しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            Else
                _logger.Trace(Sub(f) f("コマンドを実行しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            End If
            Return result
        Catch ex As Exception
            _logger.Error(Sub(f) f("コマンドの実行に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Function

    Public Function ExecuteReader(behavior As CommandBehavior) As IDataReader Implements IDbCommand.ExecuteReader
        Try
            Dim stopwatch = System.Diagnostics.Stopwatch.StartNew()
            Dim result = _command.ExecuteReader(behavior)
            stopwatch.Stop()
            If stopwatch.Elapsed > DbLoggingWrapper.LoggingTimeout Then
                _logger.Warn(Sub(f) f("コマンドの実行に規定時間以上を要しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            Else
                _logger.Trace(Sub(f) f("コマンドを実行しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            End If
            Return result
        Catch ex As Exception
            _logger.Error(Sub(f) f("コマンドの実行に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Function

    Public Function ExecuteScalar() As Object Implements IDbCommand.ExecuteScalar
        Try
            Dim stopwatch = System.Diagnostics.Stopwatch.StartNew()
            Dim result = _command.ExecuteScalar()
            stopwatch.Stop()
            If stopwatch.Elapsed > DbLoggingWrapper.LoggingTimeout Then
                _logger.Warn(Sub(f) f("コマンドの実行に規定時間以上を要しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            Else
                _logger.Trace(Sub(f) f("コマンドを実行しました。実行時間:{0}{1}", stopwatch.Elapsed, Dums()))
            End If
            Return result
        Catch ex As Exception
            _logger.Error(Sub(f) f("コマンドの実行に失敗しました。{0}", Dums()), ex)
            Throw
        End Try
    End Function

    Public ReadOnly Property Parameters As IDataParameterCollection Implements IDbCommand.Parameters
        Get
            Return _command.Parameters
        End Get
    End Property

    Public Sub Prepare() Implements IDbCommand.Prepare
        _command.Prepare()
    End Sub

    Public Property Transaction As IDbTransaction Implements IDbCommand.Transaction
        Get
            Return _command.Transaction
        End Get
        Set(value As IDbTransaction)
            _command.Transaction = value.BaseTransaction()
        End Set
    End Property

    Public Property UpdatedRowSource As UpdateRowSource Implements IDbCommand.UpdatedRowSource
        Get
            Return _command.UpdatedRowSource
        End Get
        Set(value As UpdateRowSource)
            _command.UpdatedRowSource = value
        End Set
    End Property

#Region "IDisposable Support"
    Private disposedValue As Boolean ' 重複する呼び出しを検出するには

    Protected Overridable Sub Dispose(disposing As Boolean)
        If Not Me.disposedValue Then
            If disposing Then
                _command.Dispose()
                _logger.Trace("コマンドを破棄しました。")
            End If
        End If
        Me.disposedValue = True
    End Sub

    Protected Overrides Sub Finalize()
        Dispose(False)
        MyBase.Finalize()
    End Sub

    Public Sub Dispose() Implements IDisposable.Dispose
        Dispose(True)
        GC.SuppressFinalize(Me)
    End Sub
#End Region

    Private Function Dums()
        Dim sb = New System.Text.StringBuilder()
        sb.AppendLine()
        sb.AppendFormat("----- {0} -----", _command.GetType().Name)
        sb.AppendLine()
        sb.Append("   CommandType:").Append(_command.CommandType.ToString()).AppendLine()
        sb.Append("CommandTimeout:").Append(_command.CommandTimeout).AppendLine()
        If _command.Connection Is Nothing Then
            sb.Append("    Connection:<NULL>").AppendLine()
        Else
            sb.Append("    Connection:").Append(_command.Connection.State.ToString()).AppendLine()
        End If
        If _command.Transaction Is Nothing Then
            sb.Append("   Transaction:<NULL>").AppendLine()
        Else
            sb.Append("   Transaction:").Append(_command.Transaction.IsolationLevel.ToString()).AppendLine()
        End If
        sb.AppendLine("----- CommandText -----")
        sb.AppendLine(_command.CommandText)
        sb.AppendLine("----- Parameters -----")
        For Each p As IDataParameter In _command.Parameters
            sb.Append(p.ParameterName).Append("(").Append(p.DbType.ToString()).Append(")=").Append(p.Value).AppendLine()
        Next
        Return sb.ToString()
    End Function
End Class