mysql-net / MySqlConnector

MySQL Connector for .NET
https://mysqlconnector.net
MIT License
1.4k stars 335 forks source link

If a query result has multiple rows, timeouts aren't always triggered properly #1501

Open karlra opened 4 months ago

karlra commented 4 months ago

Software versions MySqlConnector version: 2.3.7 Server type (MySQL, MariaDB, Aurora, etc.) and version: Mysql 8.0 .NET version: 6.0

Describe the bug I can't tell if this is a bug or not but it feels like one. If you execute a query that has multiple rows where one row seems to be "ready" already, the .CommandTimeout property doesn't work as you would expect. CancellationToken query cancellation displays the same behaviour.

The query below is attempting to select 3 rows, with the values {1,0,2}. A timeout of 10 seconds is specified, but if you don't Read() the row that would've triggered the timeout on the command there is no exception being generated and it appears as if the query worked as expected.

The server thread is still cancelled after 1 second as expected, but there is no timeout exception triggered.

Code sample


            MySqlConnection conn = new MySqlConnection("...");
            await conn.OpenAsync();
            using(var cmd = conn.CreateCommand())
            {
                cmd.CommandText = "select 1 union all select sleep(10) union all select 2";
                cmd.CommandTimeout = 1;
                using(var reader = await cmd.ExecuteReaderAsync())
                {
                    await reader.ReadAsync();
                    var i = reader.GetInt32(0);
                    Console.WriteLine(i); //Prints 1

                    /* Uncomment to trigger the timeout exception
                    await reader.ReadAsync();
                    i = reader.GetInt32(0);
                    Console.WriteLine(i);
                    */
                }

            }

Inserts are even weirder:


            MySqlConnection conn = new MySqlConnection("...");
            await conn.OpenAsync();
            using(var cmd = conn.CreateCommand())
            {
                cmd.CommandText = @"
                    drop table if exists test;
                    create table test
                        ( `a` int NOT NULL, PRIMARY KEY (`a`) USING BTREE) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
                ";
                await cmd.ExecuteNonQueryAsync();

                cmd.CommandText = "insert into test set a = 1; select sleep(10); insert into test set a = 2;";
                cmd.CommandTimeout = 1;
                using(var reader = await cmd.ExecuteReaderAsync())
                {
                    await reader.ReadAsync();
                    var i = reader.GetInt32(0);
                    Console.WriteLine(i);
                }

            }

The second example triggers no exception, and if you check the database afterwards it contains two rows with values 1,2.

Expected behavior We would expect an exception to be triggered after 1 seconds no matter what the server thread was doing, no?

bgrainger commented 1 month ago

I haven't dug into this deeply, but any repro with SLEEP isn't really valid for testing timeouts. The reason is that SLEEP(n) is intentionally designed to be an interruptible command that doesn't cause an error when it's cancelled (by KILL QUERY). https://github.com/mysql-net/MySqlConnector/issues/1496#issuecomment-2235251186

Do you have a repro (or a production scenario) that doesn't use SLEEP?

karlra commented 1 month ago

It does the same if you replace SLEEP with BENCHMARK(9999999, md5('hmmmm')), but maybe this also qualifies as an interruptable query?

bgrainger commented 1 month ago

I don't think the BENCHMARK function can be used, either. It's not documented as doing this, but experimentally one can observe that SELECT BENCHMARK returns a valid result when it's cancelled via KILL QUERY. Thus, from MySqlConnector's perspective, no error occurred.

bgrainger commented 1 month ago

A timeout of 10 seconds is specified, but if you don't Read() the row that would've triggered the timeout on the command there is no exception being generated and it appears as if the query worked as expected.

If you don't Read the row, then the code exits the using block and Disposes the MySqlDataReader. This will read the result set, because MySqlConnector needs to consume all incoming data before the connection is ready to reuse again (e.g., for the next command).

While this is happening, the query is cancelled because of the CommandTimeout. An error payload is received by MySqlConnector and converted to an exception. Although it is allowable for Dispose to throw exceptions, I have found that, in practice, this leads to very confusing errors because the exception thrown from Dispose will often mask a different exception that is causing the stack to be unwound.

So, since it was first implemented, cancellation in MySqlConnector swallows this exception in Dispose: https://github.com/mysql-net/MySqlConnector/commit/3e4d8f5148c2ffb7810eeeea7bc555b3d4cb4861#diff-a8b0743221709c433a3aec2081e850eb5f55a97f7705eb3312ff2c44305b38c9. If you have logging enabled, you will see this exception in your logs (at a "Warning" level).

To observe the exception, you need to read all rows of the MySqlDataReader. The standard pattern for doing this is (sync example given):

using (var reader = command.ExecuteReader())
{
    do
    {
        while (reader.Read())
        {
            // ...
        }
    }
    while (reader.NextResult());
}

Any decent ORM (like EFCore or Dapper) should do this for you automatically. If you have to use plain ADO.NET, you should always use a while (reader.Read()) loop to consume all data. If you're not going to read it all, add a LIMIT n clause to your query to avoid sending the data to your client in the first place. (Or perhaps you could add an explicit command.Cancel(); at the end of the using block to eagerly cancel the command because you know you don't want any more results from it.