pymysql - executemany test failing - lock timeout - insert wait on non-indexed table

_________________________ CursorTest.test_executemany __________________________

self = <pymysql.tests.test_cursor.CursorTest testMethod=test_executemany>

    def test_executemany(self):

        conn = self.test_connection

        cursor = conn.cursor(pymysql.cursors.Cursor)

        m = pymysql.cursors.RE_INSERT_VALUES.match(

            "INSERT INTO TEST (ID, NAME) VALUES (%s, %s)"

        )

        self.assertIsNotNone(m, "error parse %s")

        self.assertEqual(m.group(3), "", "group 3 not blank, bug in RE_INSERT_VALUES?")

        m = pymysql.cursors.RE_INSERT_VALUES.match(

            "INSERT INTO TEST (ID, NAME) VALUES (%(id)s, %(name)s)"

        )

        self.assertIsNotNone(m, "error parse %(name)s")

        self.assertEqual(m.group(3), "", "group 3 not blank, bug in RE_INSERT_VALUES?")

        m = pymysql.cursors.RE_INSERT_VALUES.match(

            "INSERT INTO TEST (ID, NAME) VALUES (%(id_name)s, %(name)s)"

        )

        self.assertIsNotNone(m, "error parse %(id_name)s")

        self.assertEqual(m.group(3), "", "group 3 not blank, bug in RE_INSERT_VALUES?")

        m = pymysql.cursors.RE_INSERT_VALUES.match(

            "INSERT INTO TEST (ID, NAME) VALUES (%(id_name)s, %(name)s) ON duplicate update"

        )

        self.assertIsNotNone(m, "error parse %(id_name)s")

        self.assertEqual(

            m.group(3),

            " ON duplicate update",

            "group 3 not ON duplicate update, bug in RE_INSERT_VALUES?",

        )

        # https://github.com/PyMySQL/PyMySQL/pull/597

        m = pymysql.cursors.RE_INSERT_VALUES.match(

            "INSERT INTO bloup(foo, bar)VALUES(%s, %s)"

        )

        assert m is not None

        # cursor._executed must bee "insert into test (data) values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9)"

        # list args

        data = range(10)

>       cursor.executemany("insert into test (data) values (%s)", data)

pymysql/tests/test_cursor.py:101: 

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

pymysql/cursors.py:187: in executemany

    return self._do_execute_many(

pymysql/cursors.py:225: in _do_execute_many

    rows += self.execute(sql + postfix)

pymysql/cursors.py:158: in execute

    result = self._query(query)

pymysql/cursors.py:325: in _query

    conn.query(q)

pymysql/connections.py:546: in query

    self._affected_rows = self._read_query_result(unbuffered=unbuffered)

pymysql/connections.py:775: in _read_query_result

    result.read()

pymysql/connections.py:1156: in read

    first_packet = self.connection._read_packet()

pymysql/connections.py:725: in _read_packet

    packet.raise_for_error()

pymysql/protocol.py:221: in raise_for_error

    err.raise_mysql_exception(self._data)

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

data = b'\xff\xb5\x04#HY000Lock wait timeout exceeded; try restarting transaction'

    def raise_mysql_exception(data):

        errno = struct.unpack("<h", data[1:3])[0]

        errval = data[9:].decode("utf-8", "replace")

        errorclass = error_map.get(errno)

        if errorclass is None:

            errorclass = InternalError if errno < 1000 else OperationalError

>       raise errorclass(errno, errval)

E       pymysql.err.OperationalError: (1205, 'Lock wait timeout exceeded; try restarting transaction')

pymysql/err.py:143: OperationalError

git bisect start 'fail'

# good: [b76e5c66107d75d0161d8f8ab3cf05fc360c831e] MDEV-24765 fseg_free_extent fails to call buf_page_free() for the whole segment

git bisect good b76e5c66107d75d0161d8f8ab3cf05fc360c831e

# good: [b76e5c66107d75d0161d8f8ab3cf05fc360c831e] MDEV-24765 fseg_free_extent fails to call buf_page_free() for the whole segment

git bisect good b76e5c66107d75d0161d8f8ab3cf05fc360c831e

# bad: [786bc312b85e58857cb26a24ab6e997ba0fdfc32] Cleanup: Replace mysql_cond_t with pthread_cond_t

git bisect bad 786bc312b85e58857cb26a24ab6e997ba0fdfc32

# good: [260161fc9fb5b4885013d550e606681769b52019] MDEV-24167 fixup: Avoid hangs in SRW_LOCK_DUMMY

git bisect good 260161fc9fb5b4885013d550e606681769b52019

# good: [394fc71f4fa8f8b1b6d24adfead0ec45121d271e] MDEV-24569: Merge 10.5 into 10.6

git bisect good 394fc71f4fa8f8b1b6d24adfead0ec45121d271e

# bad: [3329f0ed0c3acdd47dedfa54aefadb1852eb7454] Cleanup: Remove LOCK_REC (which was mutually exclusive with LOCK_TABLE)

git bisect bad 3329f0ed0c3acdd47dedfa54aefadb1852eb7454

# bad: [3f871b339429441ad907ecf7dfabdc414797e664] MDEV-515 fixup: Cover dict_table_t::clear() during ADD INDEX

git bisect bad 3f871b339429441ad907ecf7dfabdc414797e664

# good: [0d7380fdac1add2be3fdb57519ccd8ac9c8e12bc] MDEV-24637 fts_slots is being accessed after it gets freed

git bisect good 0d7380fdac1add2be3fdb57519ccd8ac9c8e12bc

# good: [e9fc61053d64ee829e26ecf3bb1c521938e20543] Merge 10.5 into 10.6

git bisect good e9fc61053d64ee829e26ecf3bb1c521938e20543

# bad: [3cef4f8f0fc88ae5bfae4603d8d600ec84cc70a9] MDEV-515 Reduce InnoDB undo logging for insert into empty table

git bisect bad 3cef4f8f0fc88ae5bfae4603d8d600ec84cc70a9

# good: [7aed5eb76ffdec91637cb7a48bff89e4b4315f82] MDEV-24642 Assertion r->emplace... failed in sux_lock::s_lock_register()

git bisect good 7aed5eb76ffdec91637cb7a48bff89e4b4315f82

# first bad commit: [3cef4f8f0fc88ae5bfae4603d8d600ec84cc70a9] MDEV-515 Reduce InnoDB undo logging for insert into empty table

MariaDB [(none)]> show processlist; show engine innodb status\G

Connection id:    6

Current database: *** NONE ***

+----+------+-----------+-------+---------+------+----------+------------------------------------------------------------------------+----------+

| Id | User | Host      | db    | Command | Time | State    | Info                                                                   | Progress |

+----+------+-----------+-------+---------+------+----------+------------------------------------------------------------------------+----------+

|  3 | root | localhost | test1 | Sleep   |    4 |          | NULL                                                                   |    0.000 |

|  4 | root | localhost | test1 | Sleep   |    4 |          | NULL                                                                   |    0.000 |

|  5 | root | localhost | test1 | Query   |    4 | Update   | insert into test (data) values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9) |    0.000 |

|  6 | dan  | localhost | NULL  | Query   |    0 | starting | show processlist                                                       |    0.000 |

+----+------+-----------+-------+---------+------+----------+------------------------------------------------------------------------+----------+

4 rows in set (0.003 sec)

*************************** 1. row ***************************

  Type: InnoDB

  Name: 

Status: 

=====================================

2021-02-26 17:36:22 0x7fd420d1a640 INNODB MONITOR OUTPUT

=====================================

Per second averages calculated from the last 7 seconds

-----------------

BACKGROUND THREAD

-----------------

srv_master_thread loops: 1 srv_active, 0 srv_shutdown, 7 srv_idle

srv_master_thread log flush and writes: 8

----------

SEMAPHORES

----------

------------

TRANSACTIONS

------------

Trx id counter 488

Purge done for trx's n:o < 487 undo n:o < 0 state: running

History list length 215

LIST OF TRANSACTIONS FOR EACH SESSION:

---TRANSACTION 487, ACTIVE 5 sec inserting

mysql tables in use 1, locked 1

LOCK WAIT 1 lock struct(s), heap size 1128, 0 row lock(s)

MySQL thread id 5, OS thread handle 140549382817344, query id 8 localhost root Update

insert into test (data) values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9)

------- TRX HAS BEEN WAITING 5 SEC FOR THIS LOCK TO BE GRANTED:

TABLE LOCK table `test1`.`test` trx id 487 lock mode IX waiting

------------------

---TRANSACTION 482, ACTIVE 5 sec

2 lock struct(s), heap size 1128, 0 row lock(s), undo log entries 1

MySQL thread id 4, OS thread handle 140549383124544, query id 6 localhost root 

---TRANSACTION 422024369524888, not started

0 lock struct(s), heap size 1128, 0 row lock(s)

 pytest -v pymysql/tests/test_cursor.py  -k  test_executemany