Bug #63942 Connections not closed properly when using pooling
Submitted: 6 Jan 2012 1:40 Modified: 29 Feb 2012 18:30
Reporter: Lars Oberg Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / NET Severity:S3 (Non-critical)
Version:6.4.4 OS:Windows
Assigned to: Fernando Gonzalez.Sanchez CPU Architecture:Any
Tags: aborted connection, clearallpools, close, pooling, reset, rst

[6 Jan 2012 1:40] Lars Oberg
Description:
When using connection pooling, the connections in the pool are not properly closed, which results in an "Aborted connection" error in the MySQL error log.  The error log gets so full of such messages that important messages easily get missed.

A workaround is to explicitly call MySql.Data.MySqlClient.MySqlConnection.ClearAllPools(); upon exiting the application.

With Wireshark, you can plainly see that an abrupt RST package is sent to the server upon application exit, causing the "Aborted connection" message.  If you were to send a "Request quit" package (which is what happens whenever you close a connection and have pooling turned off), everything works fine (and no warnings in the log file).  Calling ClearAllPools manually also results in a "Request quit" package.

How to repeat:
1) Open a connection
2) Close it
3) Exit app

Look at MySQL server error log (I have log-warnings=2, which might be needed for it to be logged).

using (var conn = new MySql.Data.MySqlClient.MySqlConnection("server=192.168.1.2; port=3306; user id=testuser; password='...'; database=Test; pooling=true"))
{
    conn.Open();
    conn.Close();
}

Suggested fix:
Call ClearAllPools automatically upon application exit (maybe add connection string option for this, such as AutoClearPools=true).
[9 Jan 2012 11:15] Bogdan Degtyariov
Lars,

I could not repeat the problem you reported. The application behaved as expected. Here is the process list (Id=14 is the mysql command line connection):

mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+
| Id | User | Host      | db   | Command | Time | State | Info             |
+----+------+-----------+------+---------+------+-------+------------------+
| 14 | root | i7w7:4859 | NULL | Query   |    0 | NULL  | show processlist |
+----+------+-----------+------+---------+------+-------+------------------+
1 row in set (0.00 sec)

Then I run the test application and opened a connection (Id=16) using Connector/NET 6.4.4:

mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+
| Id | User | Host      | db   | Command | Time | State | Info             |
+----+------+-----------+------+---------+------+-------+------------------+
| 14 | root | i7w7:4859 | NULL | Query   |    0 | NULL  | show processlist |
| 16 | root | i7w7:4963 | test | Sleep   |    4 |       | NULL             |
+----+------+-----------+------+---------+------+-------+------------------+
2 rows in set (0.00 sec)

Then the application has called connection.close() method moving the connection to the pool, so it remains in the list:

mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+
| Id | User | Host      | db   | Command | Time | State | Info             |
+----+------+-----------+------+---------+------+-------+------------------+
| 14 | root | i7w7:4859 | NULL | Query   |    0 | NULL  | show processlist |
| 16 | root | i7w7:4963 | test | Sleep   |    9 |       | NULL             |
+----+------+-----------+------+---------+------+-------+------------------+
2 rows in set (0.00 sec)

Then the application exited without explicit calling of ClearAllPools().

Please let me know if you can provide more clues on how to repeat the problem.
Perhaps the complete C# or VB project would help. Meanwhile I am setting "Cannot repeat" status.
Thanks.
[9 Jan 2012 11:16] Bogdan Degtyariov
Sorry, forgot to post the process list after the test application exited:

mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+
| Id | User | Host      | db   | Command | Time | State | Info             |
+----+------+-----------+------+---------+------+-------+------------------+
| 14 | root | i7w7:4859 | NULL | Query   |    0 | NULL  | show processlist |
+----+------+-----------+------+---------+------+-------+------------------+
1 row in set (0.00 sec)
[9 Jan 2012 17:18] Lars Oberg
Bogdan,

Thanks for looking into this.

I am sorry if I was not clear on one point:  You have to have "log-warnings=2" in my.cnf on the server.

I am uploading a full sample C# project (ConsoleApplication4.zip)

Please do this to reproduce the issue:
1) Set log-warnings=2 in /etc/my.cnf on the server and restart mysql
2) tail -f /path-to-mysql-server-dir/theserver.err | grep "Aborted"
3) Set the connection string in the sample code and run it.  
4) Look at the output from #2 above - you should see an "Aborted connection" message.

If you step through it, you will see the connection in the process list when you execute conn.Open() and it will remain after executing conn.Close(), which is all as it should.  When you run and the application exit, the connection disappears from the process list, but not gracefully, since it was tore down as an "Aborted connection" without being properly closed - just look at the error log to see the message.

Thanks.
[9 Jan 2012 17:23] Lars Oberg
Sample for reproducing

Attachment: ConsoleApplication4.zip (application/x-zip-compressed, text), 6.06 KiB.

[10 Jan 2012 3:40] Bogdan Degtyariov
Thank you Lars.
After closing the application I have got the following record in the server error log:

120110 14:38:26 [Warning] Aborted connection 20 to db: 'test9' user: 'root' host: 'localhost' (Got an error reading communication packets)

Setting the status to "Verified".
[10 Jan 2012 4:29] Bogdan Degtyariov
Same message appears when using 6.5.0
[10 Jan 2012 6:40] Bogdan Degtyariov
Also, tested with 6.3.8 and 6.2.5 with the same result.
[29 Feb 2012 18:30] John Russell
Added to changelog for 6.5.2: 

When using connection pooling, the connections in the pool were not
automatically closed upon application exit. With the setting
log-warnings=2, you could encounter Aborted connection errors in the
MySQL error log. The workaround was to explicitly call
MySql.Data.MySqlClient.MySqlConnection.ClearAllPools(); upon exiting
the application.
[12 Apr 2012 1:17] John Russell
Added to 6.3.9 changelog also.