Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-24993

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

    XMLWordPrintable

    Details

      Description

      pymysql tests - as tested by https://buildbot.mariadb.org/#/builders/158 have been failing on 10.6 branch for a while.

      This test is stable on all other branches.

      Example failure: https://buildbot.mariadb.org/#/builders/158/builds/149

      pymysql executemany test failure

      _________________________ 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
      

      https://github.com/PyMySQL/PyMySQL/blob/master/pymysql/tests/test_cursor.py#L101

      git bisect log

      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
      

      innodb processlist during test

      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)
      
      

      From: https://github.com/MariaDB/mariadb.org-tools/blob/master/buildbot.mariadb.org/dockerfiles/ecofiles/test-pymysql.sh

      Create this test environment:

      https://github.com/MariaDB/mariadb.org-tools/blob/master/buildbot.mariadb.org/dockerfiles/ecofiles/test-pymysql.sh#L21-L39

      + `set password for root@localhost = password('');`

      +
      https://github.com/MariaDB/mariadb.org-tools/blob/master/buildbot.mariadb.org/dockerfiles/ecofiles/test-pymysql.sh#L47-L52

      runtest

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

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              danblack Daniel Black
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.