aiomysql

Problem statement

Our company uses sqlalchemy + aiomysql, and sometimes we see blow error. Not sure what happens

aiomysql version is 0.2.0.

  File "sqlalchemy/pool/base.py", line 894, in _checkout
              fairy = _ConnectionRecord.checkout(pool)
  File "sqlalchemy/pool/base.py", line 497, in checkout
              with util.safe_reraise():
  File "sqlalchemy/util/langhelpers.py", line 70, in __exit__
                  compat.raise_(
  File "sqlalchemy/util/compat.py", line 211, in raise_
              raise exception
  File "sqlalchemy/pool/base.py", line 495, in checkout
              dbapi_connection = rec.get_connection()
  File "sqlalchemy/pool/base.py", line 659, in get_connection
              self.__connect()
  File "sqlalchemy/pool/base.py", line 690, in __connect
              with util.safe_reraise():
  File "sqlalchemy/util/langhelpers.py", line 70, in __exit__
                  compat.raise_(
  File "sqlalchemy/util/compat.py", line 211, in raise_
              raise exception
  File "sqlalchemy/pool/base.py", line 686, in __connect
              self.dbapi_connection = connection = pool._invoke_creator(self)
  File "sqlalchemy/engine/create.py", line 574, in connect
              return dialect.connect(*cargs, **cparams)
  File "sqlalchemy/engine/default.py", line 598, in connect
          return self.dbapi.connect(*cargs, **cparams)
  File "sqlalchemy/dialects/mysql/aiomysql.py", line 254, in connect
                  await_only(self.aiomysql.connect(*arg, **kw)),
  File "sqlalchemy/util/_concurrency_py3k.py", line 68, in await_only
      return current.driver.switch(awaitable)
  File "sqlalchemy/util/_concurrency_py3k.py", line 121, in greenlet_spawn
                  value = await result
  File "ddtrace/contrib/aiomysql/patch.py", line 41, in patched_connect
      conn = await connect_func(*args, **kwargs)
  File "aiomysql/connection.py", line 75, in _connect
      await conn._connect()
  File "aiomysql/connection.py", line 540, in _connect
              await self._request_authentication()
  File "aiomysql/connection.py", line 844, in _request_authentication
          auth_packet = await self._read_packet()
  File "aiomysql/connection.py", line 629, in _read_packet
                  raise InternalError(
sqlalchemy.exc.InternalError: (pymysql.err.InternalError) Packet sequence number wrong - got 1 expected 2

Mysql packet

https://dev.mysql.com/doc/dev/mysql-server/latest/page_protocol_basic_packets.html

Mysql protocol

The official doc describes the mysql client connection process. Before we try it out using wireshark, we mention a few gotchas. First, Mysql client uses Unix socket instead of TCP on localhost

On Unix, MySQL programs treat the host name localhost specially, in a way that is likely different from what you expect compared to other network-based programs: the client connects using a Unix socket file.

Therefore, wireshark cannot capture any traffic. To bypass this, we need to explicitly set the host to 127.0.0.1. Second, we should turn off TLS, otherwise, after the handshake, we cannot decipher anything from wireshark’s output.

So we run mysql client as blow.

mysql -u<...> -p<...> -h 127.0.0.1 --ssl-mode=DISABLED

The traffic captured is below:

First thing to note is packet number or sequence_id. For each new request, no matter whether it is from server or client, it has a starting sequence_id zero. Then this number increases until the request cycle ends. In the above screenshot, the first 5 packets belong to one request cycle, and the sequence_id is 0, 1, 2, 3, 4 respectively.

The first packet Server greeting corresponds to function _get_server_information

The second packet Login Request user=root corresponds to function _request_authentication

So in normal case, after Login Request, the server should send the client with a sequence_id 2, but the error message is Packet sequence number wrong - got 1 expected 2. The server sent a message with sequence_id 1, which means it is a response a message to request message from the client side. But this is the connection process, there shouldn’t be any attempt to send a different message. How could this be possible? A few hypotheses:

1. reconnect effect?
2. asyncio.gather?