Connection from python 2.7 with PyMySQL to ProxySQL admin interface sometimes fails

[rsab]

Tested on:

Centos 7
ProxySQL version 2.0.2-1-g533442f, codename Truls
python 2.7.5
python2-PyMySQL: 0.9.2

Sometimes this code fails:

import pymysql.cursors

connection = pymysql.connect(user='admin', password='<edited>', unix_socket='/var/lib/proxysql/proxysql_admin.sock',  cursorclass=pymysql.cursors.DictCursor)

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib/python2.7/site-packages/pymysql/__init__.py", line 94, in Connect
    return Connection(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 327, in __init__
    self.connect()
  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 598, in connect
    self._request_authentication()
  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 862, in _request_authentication
    auth_packet = self._process_auth(plugin_name, auth_packet)
  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 933, in _process_auth
    pkt = self._read_packet()
  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 683, in _read_packet
    packet.check_error()
  File "/usr/lib/python2.7/site-packages/pymysql/protocol.py", line 220, in check_error
    err.raise_mysql_exception(self._data)
  File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 109, in raise_mysql_exception
    raise errorclass(errno, errval)
pymysql.err.OperationalError: (1045, u"ProxySQL Error: Access denied for user 'admin'@'' (using password: YES)")

Logs in ProxySQL server:

2019-03-01 10:04:42 MySQL_Session.cpp:3966:handler___status_CONNECTING_CLIENT___STATE_SERVER_HANDSHAKE(): [ERROR] ProxySQL Error: Access denied for user 'admin'@'' (using password: YES)

Running test multiple times:

import pymysql.cursors

def testconnp():
   try:
     connection = pymysql.connect(user='admin', password='<edited>', unix_socket='/var/lib/proxysql/proxysql_admin.sock',  cursorclass=pymysql.cursors.DictCursor)
     connection.close()
   except:
     return 0
   return 1 
 
sum([testconnp() for i in range(1000)])

#Returns around 930

Same python and library tested on MariaDB with no connection errors, also connection to proxysql admin interface from mysql client works fine.

[rsab]

Have dumped two session:
Successful:

< 2019/03/01 12:07:01.884654  length=78 from=0 to=77
 4a 00 00 00 0a 35 2e 35 2e 33 30 00 3a 1e 00 00 76 66 5e 5b 78 2c 1b 39 00 2f f2 21 02 00 0f 80 15 00 00 00 00 00 00 00 00 00 00 1c 68 75 47 3d 6d 47 40 37 42 47 5f 00 6d 79 73 71 6c 5f 6e 61 74 69 76 65 5f 70 61 73 73 77 6f 72 64 00
> 2019/03/01 12:07:01.885221  length=64 from=0 to=63
 3c 00 00 01 05 a2 3a 00 ff ff ff 00 2d 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 61 64 6d 69 6e 00 14 4b 61 e5 9e 78 6a 82 d9 aa aa 9b c3 a4 3a 0b 84 b4 27 e0 9c 00
< 2019/03/01 12:07:01.885498  length=48 from=78 to=125
 2c 00 00 02 fe 6d 79 73 71 6c 5f 6e 61 74 69 76 65 5f 70 61 73 73 77 6f 72 64 00 76 66 5e 5b 78 2c 1b 39 1c 68 75 47 3d 6d 47 40 37 42 47 5f 00
> 2019/03/01 12:07:01.885778  length=24 from=64 to=87
 14 00 00 03 4b 61 e5 9e 78 6a 82 d9 aa aa 9b c3 a4 3a 0b 84 b4 27 e0 9c
< 2019/03/01 12:07:01.885930  length=11 from=126 to=136
 07 00 00 04 00 00 00 00 02 00 00
> 2019/03/01 12:07:01.886127  length=23 from=88 to=110
 13 00 00 00 03 53 45 54 20 41 55 54 4f 43 4f 4d 4d 49 54 20 3d 20 30
< 2019/03/01 12:07:01.886274  length=11 from=137 to=147
 07 00 00 01 00 00 00 02 02 00 00
> 2019/03/01 12:07:01.886727  length=5 from=111 to=115
 01 00 00 00 01

Failed:

< 2019/03/01 12:07:02.715940  length=78 from=0 to=77
 4a 00 00 00 0a 35 2e 35 2e 33 30 00 3b 1e 00 00 05 41 0e 0d 57 56 58 3a 00 2f f2 21 02 00 0f 80 15 00 00 00 00 00 00 00 00 00 00 18 5f 62 62 36 0f 10 32 05 69 54 7f 00 6d 79 73 71 6c 5f 6e 61 74 69 76 65 5f 70 61 73 73 77 6f 72 64 00
> 2019/03/01 12:07:02.716616  length=64 from=0 to=63
 3c 00 00 01 05 a2 3a 00 ff ff ff 00 2d 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 61 64 6d 69 6e 00 14 6e 00 8b ab c6 6a c9 45 61 3c 2c 56 fb 9b 6d 98 49 87 fc 43 00
< 2019/03/01 12:07:02.716811  length=48 from=78 to=125
 2c 00 00 02 fe 6d 79 73 71 6c 5f 6e 61 74 69 76 65 5f 70 61 73 73 77 6f 72 64 00 05 41 0e 0d 57 56 58 3a 18 5f 62 62 36 0f 10 32 05 69 54 7f 00
> 2019/03/01 12:07:02.717111  length=24 from=64 to=87
 14 00 00 03 6e 00 8b ab c6 6a c9 45 61 3c 2c 56 fb 9b 6d 98 49 87 fc 43
< 2019/03/01 12:07:02.717423  length=84 from=126 to=209
 50 00 00 04 ff 15 04 23 32 38 30 30 30 50 72 6f 78 79 53 51 4c 20 45 72 72 6f 72 3a 20 41 63 63 65 73 73 20 64 65 6e 69 65 64 20 66 6f 72 20 75 73 65 72 20 27 61 64 6d 69 6e 27 40 27 27 20 28 75 73 69 6e 67 20 70 61 73 73 77 6f 72 64 3a 20 59 45 53 29

My test password SHA1:

c4 c5 24 2b d9 e8 e5 33 9f ae a7 d2 7a 05 5a 00 e8 31 b7 7c

To test on python mysql authentication I have created a function:

import hashlib

# SHA1( password ) XOR SHA1( "20-bytes random data from server" <concat> SHA1( SHA1( password ) ) )
def response(pwh, rdata):
  m = hashlib.sha1()
  m.update(pwh)
  pwhh = m.digest()
  m = hashlib.sha1()
  m.update(rdata)
  m.update(pwhh)
  concath = m.digest()
  return ''.join(chr(ord(a) ^ ord(b)) for a,b in zip(pwh,concath))

For first session:

server challenge (from dump):
76 66 5e 5b 78 2c 1b 39 1c 68 75 47 3d 6d 47 40 37 42 47 5f
client response (from dump):
4b 61 e5 9e 78 6a 82 d9 aa aa 9b c3 a4 3a 0b 84 b4 27 e0 9c
calculated response:
>>> binascii.hexlify(response(PW,SK))
'4b61e59e786a82d9aaaa9bc3a43a0b84b427e09c'

For second session:

server challenge (from dump):
05 41 0e 0d 57 56 58 3a 18 5f 62 62 36 0f 10 32 05 69 54 7f
client response (from dump):
6e 00 8b ab c6 6a c9 45 61 3c 2c 56 fb 9b 6d 98 49 87 fc 43
calculated response:
>>> binascii.hexlify(response(PW,SF))
'6e008babc66ac945613c2c56fb9b6d984987fc43'

So the password authentication step seems ok from the perspective of the client in both cases.

[Seitanas]

This appears to be a bug in pymysql version 0.9.2:
pip install pymysql==0.9.2

python test.py
923

pip install pymysql==0.9.3

python test.py
1000

[renecannao]

I tested with pymysql 0.8.0 (what is installed by default on my system) and I couldn't reproduce it.
Once upgraded to 0.9.2 , it started failing with a failure ratio of ~7% .
Once upgraded to pymysql 0.9.3 , errors went away.

Thank you @Seitanas for pointing it appears to be a bug in pymysql, this saved us a lot of time!

Closing