Understanding and investigating CommitFailedException on MySQL

Question

I have an Entity Framework-based application running in production.

Since a couple of days some customers are calling for random Internal Server Errors. Log files show that a simple transaction, with a single INSERT statement, is failing to commit, and that transaction is related to logging.

Let me explain better....

I have inherited a database logging feature that thanks to a controller method attribute will log every HTTP request to database to make a navigation log. Last year I have refactored the whole application from plain old multi-dialect SQL/ADO (because app runs on both MySQL and SQL Server) to Entity Framework. The application went in production and only little maintenance was required, up to major release 3.0 which is in prod for more than a month.

From yesterday, we received multiple complaints that I found related to the following exception

System.Data.Entity.Infrastructure.CommitFailedException: [non-English description] http://go.microsoft.com/fwlink/?LinkId=313468. ---> MySql.Data.MySqlClient.MySqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.TimeoutException: Timeout in IO operation
   in MySql.Data.MySqlClient.TimedStream.StopTimer()
   in MySql.Data.MySqlClient.TimedStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   in System.IO.BufferedStream.Read(Byte[] array, Int32 offset, Int32 count)
   in MySql.Data.MySqlClient.MySqlStream.ReadFully(Stream stream, Byte[] buffer, Int32 offset, Int32 count)
   in MySql.Data.MySqlClient.MySqlStream.LoadPacket()
   in MySql.Data.MySqlClient.MySqlStream.ReadPacket()
   in MySql.Data.MySqlClient.NativeDriver.GetResult(Int32& affectedRow, Int64& insertedId)
   in MySql.Data.MySqlClient.Driver.NextResult(Int32 statementId, Boolean force)
   in MySql.Data.MySqlClient.MySqlDataReader.NextResult()
   in MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   --- Fine della traccia dello stack dell'eccezione interna ---
   in MySql.Data.MySqlClient.ExceptionInterceptor.Throw(Exception exception)
   in MySql.Data.MySqlClient.MySqlConnection.HandleTimeoutOrThreadAbort(Exception ex)
   in MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   in MySql.Data.MySqlClient.MySqlCommand.ExecuteNonQuery()
   in MySql.Data.MySqlClient.MySqlTransaction.Commit()
   in System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action`2 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   --- Fine della traccia dello stack dell'eccezione interna ---
   in System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action`2 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   in System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.Commit(DbTransaction transaction, DbInterceptionContext interceptionContext)
   in System.Data.Entity.Core.EntityClient.EntityTransaction.Commit()
   in System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess)
   in System.Data.Entity.Core.Objects.ObjectContext.SaveChangesToStore(SaveOptions options, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction)
   in System.Data.Entity.Core.Objects.ObjectContext.SaveChangesInternal(SaveOptions options, Boolean executeInExistingTransaction)
   in System.Data.Entity.Internal.InternalContext.SaveChanges()
   in DiagnosticoSite.Data.Managers.Spring.NavigationLogManagerImpl.Insert(String aUserId, DateTime aRequestDate, String aPath, String aQuery, String aHost, String aBrowser, String aExecutionTime)

The code

Code that runs the query is extremely simple

    public void Insert(string aUserId, DateTime aRequestDate, string aPath, string aQuery, string aHost, string aBrowser, string aExecutionTime)
    {
        using (MyContext dataContext = GetDataContext())
        {
            LogNavigation log = new LogNavigation
            {
                LN_RequestDate = aRequestDate,
                LN_Path = aPath,
                LN_Query = aQuery,
                LN_Host = aHost,
                LN_Browser = aBrowser,
                LN_ExecutionTime = aExecutionTime,
                LN_FK_Utenti = aUserId
            };

            dataContext.log_navigation.Add(log);
            dataContext.SaveChanges();
        }
    }

GetDataContext() is a Spring lookup method that returns new MyDataContext() as a Spring prototype object.

The application is DB-heavy, in the sense that it normally runs queries that take up to minutes to complete, but those readonly queries and the log navigation queries reasonably run on different connections/transactions.

What I have tried

Currently DB timeout is very high. Following is Spring XML configuration

<object id="DataContext" singleton="false" type="MyPackage.MyDataContext, MyAssembly" >
    <property name="Database.CommandTimeout" value="3600" />
    <property name="Configuration.UseDatabaseNullSemantics" value="true" />
</object>

I have also tried to investigate slow-query-log without finding any INSERT

Workaround

Currently the workaround to this issue was to try-catch the logging facility and log possible exception to log4net's system log. But that is a workaround. Like when you take a painkiller instead of properly treating an inflammation I mean.

The question is

How do I investigate the root cause of such timeouts during the execution of a single-statement transaction?