Description:
When the MySQL server is down, the MySQL Connector NET fills up the connection pool, and does not recover, even when the server is back up.
There seems to be two issues - one is a logging issue, which then causes the pool to fill up.
Long description:
When the MySQL server is down, the MySQL Connector NET (run on .NET Framework 4.6.1, tried on both Server 2016 and Windows 10) throws the following error message:
System.ArgumentException: Source property was not set before writing to the event log.
Stack Trace:
at System.Diagnostics.EventLogInternal.WriteEvent(EventInstance instance, Byte[] data, Object[] values)
at System.Diagnostics.EventLog.WriteEvent(EventInstance instance, Object[] values)
at System.Diagnostics.EventLogTraceListener.TraceEvent(TraceEventCache eventCache, String source, TraceEventType severity, Int32 id, String message)
at System.Diagnostics.TraceInternal.TraceEvent(TraceEventType eventType, Int32 id, String format, Object[] args)
at MySql.Data.MySqlClient.MySqlTrace.LogError(Int32 id, String msg)
at MySql.Data.MySqlClient.MySqlPool.TryToGetDriver()
at MySql.Data.MySqlClient.MySqlPool.GetConnection()
at MySql.Data.MySqlClient.MySqlConnection.Open()
It does not appear to be able to write to the event error log. Setting 'Logging=false' does not prevent this error, and neither does turning off logging in the config file:
<system.diagnostics>
<sources>
<source name="mysql" switchValue="Off">
<listeners>
<clear />
</listeners>
</source>
</sources>
</system.diagnostics>
More importantly, when this error occurs it does not mark the connection spot as 'available' again. So the connection pool runs out of available connection slots if the server is down for enough time to hit the MaxPoolSize.
Initially I was using 8.0.12, so I upgraded to 8.0.17, but the same problem still exists.
How to repeat:
Create a .NET Framework 4.6.1 C# project, add MySQL Connector NET via NuGet Packages.
Create a connection string to a test server that you can turn on and off. Set MaxPoolSize=2, ConnectionTimeout=5
Write C# code to create 3 connections one after the other without closing the previous, and put a try catch around each separately.
Put a breakpoint after the first connection.
Turn your MySQL server on, then run the code in debug mode.
After the 1st one connects successfully and you've hit your breakpoint, hover over the 1st connection in Visual Studio to see the 'driver.Pool' properties: NumConnections=1, _maxSize=2, _inUsePool=1, available=1
This is expected.
Turn your MySQL server off, then continue debugging.
The 2nd will throw the 'Source property was not set before writing to the event log.'.
Hover over the 1st connection in Visual Studio again to see 'driver.Pool' values: NumConnections=1, _maxSize=2, _inUsePool=1, available=0
Note that the available has gone to 0 but the connection hasn't been made.
The 3rd connection (and any subsequent) will throw 'Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.'
Suggested fix:
I am not sure how to fix the logging issue. However I suggest that the connection pool issue (which is the main problem) could be fixed by changing the following block:
From line 228 of https://github.com/mysql/mysql-connector-net/blob/8.0/MySQL.Data/src/MySqlPool.cs:
catch (Exception ex)
{
MySqlTrace.LogError(-1, ex.Message);
Interlocked.Increment(ref _available);
throw;
}
Change to put the connection slot back to available first, before trying to log the error:
catch (Exception ex)
{
Interlocked.Increment(ref _available);
MySqlTrace.LogError(-1, ex.Message);
throw;
}
Description: When the MySQL server is down, the MySQL Connector NET fills up the connection pool, and does not recover, even when the server is back up. There seems to be two issues - one is a logging issue, which then causes the pool to fill up. Long description: When the MySQL server is down, the MySQL Connector NET (run on .NET Framework 4.6.1, tried on both Server 2016 and Windows 10) throws the following error message: System.ArgumentException: Source property was not set before writing to the event log. Stack Trace: at System.Diagnostics.EventLogInternal.WriteEvent(EventInstance instance, Byte[] data, Object[] values) at System.Diagnostics.EventLog.WriteEvent(EventInstance instance, Object[] values) at System.Diagnostics.EventLogTraceListener.TraceEvent(TraceEventCache eventCache, String source, TraceEventType severity, Int32 id, String message) at System.Diagnostics.TraceInternal.TraceEvent(TraceEventType eventType, Int32 id, String format, Object[] args) at MySql.Data.MySqlClient.MySqlTrace.LogError(Int32 id, String msg) at MySql.Data.MySqlClient.MySqlPool.TryToGetDriver() at MySql.Data.MySqlClient.MySqlPool.GetConnection() at MySql.Data.MySqlClient.MySqlConnection.Open() It does not appear to be able to write to the event error log. Setting 'Logging=false' does not prevent this error, and neither does turning off logging in the config file: <system.diagnostics> <sources> <source name="mysql" switchValue="Off"> <listeners> <clear /> </listeners> </source> </sources> </system.diagnostics> More importantly, when this error occurs it does not mark the connection spot as 'available' again. So the connection pool runs out of available connection slots if the server is down for enough time to hit the MaxPoolSize. Initially I was using 8.0.12, so I upgraded to 8.0.17, but the same problem still exists. How to repeat: Create a .NET Framework 4.6.1 C# project, add MySQL Connector NET via NuGet Packages. Create a connection string to a test server that you can turn on and off. Set MaxPoolSize=2, ConnectionTimeout=5 Write C# code to create 3 connections one after the other without closing the previous, and put a try catch around each separately. Put a breakpoint after the first connection. Turn your MySQL server on, then run the code in debug mode. After the 1st one connects successfully and you've hit your breakpoint, hover over the 1st connection in Visual Studio to see the 'driver.Pool' properties: NumConnections=1, _maxSize=2, _inUsePool=1, available=1 This is expected. Turn your MySQL server off, then continue debugging. The 2nd will throw the 'Source property was not set before writing to the event log.'. Hover over the 1st connection in Visual Studio again to see 'driver.Pool' values: NumConnections=1, _maxSize=2, _inUsePool=1, available=0 Note that the available has gone to 0 but the connection hasn't been made. The 3rd connection (and any subsequent) will throw 'Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.' Suggested fix: I am not sure how to fix the logging issue. However I suggest that the connection pool issue (which is the main problem) could be fixed by changing the following block: From line 228 of https://github.com/mysql/mysql-connector-net/blob/8.0/MySQL.Data/src/MySqlPool.cs: catch (Exception ex) { MySqlTrace.LogError(-1, ex.Message); Interlocked.Increment(ref _available); throw; } Change to put the connection slot back to available first, before trying to log the error: catch (Exception ex) { Interlocked.Increment(ref _available); MySqlTrace.LogError(-1, ex.Message); throw; }