Infinite waiting on closing connection using ClearDB on Azure

[ktos]

Hi, I have a problem using ClearDB on Azure with Pomelo.EntityFrameworkCore (PomeloFoundation/Pomelo.EntityFrameworkCore.MySql#384), and I debugged it more thoroughly, and unfortunately it seems it's MySqlConnector problem so I am bringing it here.

Too long, don't want to read? See lower ;)

I've debugged it in Pomelo.EntityFrameworkCore that it starts in getting server version, actually in line 42, which is closing the connection. So I've replicated it into a small .NET Core 2.0 console app:

public class Program
{
    public const string ConnectionString = @"Database=tempdata;Data Source=eu-cdbr-azure-north-e.cloudapp.net;User Id=bef044c47f5218;Password=REDACTED;Ssl Mode=none;Connection Reset=false;Pooling=false"

    private static MySqlConnectionStringBuilder _settingsCsb(MySqlConnectionStringBuilder csb)
    {
        return new MySqlConnectionStringBuilder
        {
            Server = csb.Server,
            Port = csb.Port,
            OldGuids = csb.OldGuids,
            TreatTinyAsBoolean = csb.TreatTinyAsBoolean,
        };
    }

    public static void Main()
    {
        var csb = new MySqlConnectionStringBuilder(Program.ConnectionString);

        var settingsCsb = _settingsCsb(csb);
        csb.Database = "";
        csb.Pooling = false;
        string serverVersion;
        using (var schemalessConnection = new MySqlConnection(csb.ConnectionString))
        {
            schemalessConnection.Open();
            serverVersion = schemalessConnection.ServerVersion;
            schemalessConnection.Close();
        }

        Console.Read();
    }
}

So you see it's just connecting, reading server version and disconnecting. And it does not work with ClearDB and MySqlConnector freshly downloaded from GitHub. I've tried two ClearDB regions (West Europe and North Europe) and two plans (free and the cheapest one). Same issue.

In closing the connection (used here explicitely for debugging) I have a situation that there is an infinite wait (I have waited over 3 minutes) for closing the connection. It seems that the problem is here: https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/MySqlClient/MySqlConnection.cs#L392 - this line waits.

Going inside we are in https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Serialization/MySqlSession.cs#L171-L173 and the problem is in ReadPayloadAsync. The quit command seems to be sent correctly - I have wireshark dumps in the previous issue attached.

Let's look at the stacktrace:

>	MySqlConnector.dll!MySql.Data.Protocol.Serialization.BufferedByteReader.ReadBytesAsync(MySql.Data.Protocol.Serialization.IByteHandler byteHandler, int count, MySql.Data.Protocol.Serialization.IOBehavior ioBehavior) Line 14	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.Protocol.Serialization.ProtocolUtility.ReadPacketAsync(MySql.Data.Protocol.Serialization.BufferedByteReader bufferedByteReader, MySql.Data.Protocol.Serialization.IByteHandler byteHandler, System.Func<int> getNextSequenceNumber, MySql.Data.Protocol.Serialization.ProtocolErrorBehavior protocolErrorBehavior, MySql.Data.Protocol.Serialization.IOBehavior ioBehavior) Line 14	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.Protocol.Serialization.ProtocolUtility.DoReadPayloadAsync(MySql.Data.Protocol.Serialization.BufferedByteReader bufferedByteReader, MySql.Data.Protocol.Serialization.IByteHandler byteHandler, System.Func<int> getNextSequenceNumber, MySql.Data.Protocol.Serialization.ArraySegmentHolder<byte> previousPayloads, MySql.Data.Protocol.Serialization.ProtocolErrorBehavior protocolErrorBehavior, MySql.Data.Protocol.Serialization.IOBehavior ioBehavior) Line 69	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.Protocol.Serialization.ProtocolUtility.ReadPayloadAsync(MySql.Data.Protocol.Serialization.BufferedByteReader bufferedByteReader, MySql.Data.Protocol.Serialization.IByteHandler byteHandler, System.Func<int> getNextSequenceNumber, MySql.Data.Protocol.Serialization.ArraySegmentHolder<byte> cache, MySql.Data.Protocol.Serialization.ProtocolErrorBehavior protocolErrorBehavior, MySql.Data.Protocol.Serialization.IOBehavior ioBehavior) Line 64	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.Protocol.Serialization.StandardPayloadHandler.ReadPayloadAsync(MySql.Data.Protocol.Serialization.ArraySegmentHolder<byte> cache, MySql.Data.Protocol.Serialization.ProtocolErrorBehavior protocolErrorBehavior, MySql.Data.Protocol.Serialization.IOBehavior ioBehavior) Line 36	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.Serialization.MySqlSession.DisposeAsync(MySql.Data.Protocol.Serialization.IOBehavior ioBehavior, System.Threading.CancellationToken cancellationToken) Line 173	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.MySqlClient.MySqlConnection.DoClose() Line 392	C#	Symbols loaded.
 	MySqlConnector.dll!MySql.Data.MySqlClient.MySqlConnection.Close() Line 113	C#	Symbols loaded.
 	ConsoleApp8.dll!MySqlTest.Program.Main() Line 90	C#	Symbols loaded.

So we're at https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Protocol/Serialization/BufferedByteReader.cs#L16 and m_remainingdata.Count is 0 while count is 4. This of course goes to https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Protocol/Serialization/BufferedByteReader.cs#L37 and then to https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Protocol/Serialization/SocketByteHandler.cs#L22 because ioBehavior is Synchronous.

And this m_stream.Read() stays here forever.

I've searched the web and think that maybe the problem is similar to npgsql/npgsql#265 - I think ClearDB's MySQL is just closing the connection after quit command (see again how does it look like in wireshark) and there is no data to be received.

To solve this we could possibly use ReadTimeout?

ReadTimeout property for m_stream in https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Protocol/Serialization/StreamByteHandler.cs#L18 is -1 (indefinite), so I've changed it into 100 ms for test. That causes IOException, which is being caught in https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Serialization/MySqlSession.cs#L175 (and nothing happens).

I've changed that to be more polite and disconnect the socket on IOException:

catch (IOException)
{
	ShutdownSocket();
	lock (m_lock)
		m_state = State.Closed;
}

And run my app again. It throws IOException and it works! Then, I've started the actual app using EF and it also works now! Both on Azure's ClearDB and on my local MySQL server.

But it does not work when I had Ssl Mode=none in my ConnectionString.

So I've removed ReadTimeout in StreamByteHandler and I've added in https://github.com/mysql-net/MySqlConnector/blob/master/src/MySqlConnector/Protocol/Serialization/SocketByteHandler.cs#L11 m_socket.ReceiveTimeout = 500;. And it works now for both SSL and non-SSL connection!

TL;DR: It seems ClearDB is closing the connection just after quit command while MySqlConnector is still waiting for something. Adding ReceiveTimeout for socket seems to fix it.

I would be happy to prepare a PR for this, but:

• is it a good solution?
• what the default timeout should be, should it be configurable? I used 500 ms as a test after 100 ms caused another problems;
• if it's solving only a problem for one specific vendor I've encountered, should it be solved in upstream?

[bgrainger]

I think ReadTimeout or ReceiveTimeout will be part of the solution. The default timeout would probably be CommandTimeout (which is not currently implemented: #67); implementing that correctly might have the side-effect of fixing this problem.

That's on my list for 1.0 but I'm not sure when I'll get to it.

Ideally, we would simulate the different server behaviours with a "fake" server (#271) to have a high degree of confidence that the client behaves correctly in different scenarios.

[bgrainger]

@ktos, regarding this specific problem, do you think it would be fixed by removing the single line that waits for a response after sending a QUIT payload?

MySqlConnector/src/MySqlConnector/Serialization/MySqlSession.cs

Line 173 in 7eebecc

await m_payloadHandler.ReadPayloadAsync(m_payloadCache, ProtocolErrorBehavior.Ignore, ioBehavior).ConfigureAwait(false);

MySQL Server 5.7 doesn't actually send an OK payload in response, but simply closes the TCP connection with a FIN packet. So in practice the ReadPayloadAsync call is unnecessary and throws an IOException (IIRC) anyway. If the client sends a QUIT packet then closes the connection without waiting for a response, we should avoid a hang with ClearDB but still allow all server resources to be cleaned up.

[ktos]

Yes, it is also solving my issue. I've prepared a beautiful one-line PR #335 for this (if really just removing this one line is everything) :-)

[bgrainger]

Fixed in 0.26.5.