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

Assertion `(&(&pagecache->cache_lock)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&pagecache->cache_lock)->m_mutex)->thread)' failed in dec_counter_for_resize_op

    XMLWordPrintable

    Details

      Description

      Note: The test case is for reproducing purposes only, please don't put it into the regression suite!

      The anonymous compound statement is unimportant for the test flow, it is there just to provide parallelism in MTR.

      The test runs backup stages in a loop in one thread, and INSERTs into two Aria tables in several other threads.
      The number of INSERT threads is controlled by $n variable. The bigger the value, the faster the failure seems to happen. Increase if you want a quicker end, decrease if you want less threads for debugging.
      The duration of the test is controlled by $run variable, which defines the number of loops for BACKUP stages. It is set to 100000, because currently for me it fails approximately after 10K/20K iterations on a rotating disk and after 50K iterations in memory. In absolute time it's fast, all happens within a minute or less. Increase the value if your machine is too fast and the test ends before it fails.

      # Number of parallel threads to run DML
      --let $n= 20
      # Number of loops for BACKUP STAGE
      --let $run= 100000
       
      CREATE TABLE t1 (a VARCHAR(1), KEY(a)) ENGINE=Aria;
      CREATE TABLE t2 (b VARCHAR(1), KEY(b)) ENGINE=Aria;
       
      while ($n)
      {
      --delimiter $
      --connect (con$n,localhost,root,,)
          --send 
          LOOP
              INSERT INTO t1 () VALUES (),(),(),(),(),(),(),();
              INSERT INTO t2 () VALUES (),(),(),(),(),(),(),();
          END LOOP $
          --dec $n
      --delimiter ;
      }
       
      --connection default
       
      --disable_query_log
      while ($run)
      {
        --echo Backup loops left: $run 
        BACKUP STAGE START;
        BACKUP STAGE BLOCK_COMMIT;
        BACKUP STAGE END;
        --dec $run
      }
      --enable_query_log
       
      DROP TABLE t1, t2;
      

      10.5 c2a92918

      mariadbd: /data/src/10.5/storage/maria/ma_pagecache.c:1098: dec_counter_for_resize_op: Assertion `(&(&pagecache->cache_lock)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&pagecache->cache_lock)->m_mutex)->thread)' failed.
      200528 19:41:02 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007f99e95c2f12 in __GI___assert_fail (assertion=0x564a8fade810 "(&(&pagecache->cache_lock)->m_mutex)->count > 0 && pthread_equal(pthread_self(), (&(&pagecache->cache_lock)->m_mutex)->thread)", file=0x564a8fade5b8 "/data/src/10.5/storage/maria/ma_pagecache.c", line=1098, function=0x564a8fae0cd0 <__PRETTY_FUNCTION__.16314> "dec_counter_for_resize_op") at assert.c:101
      #8  0x0000564a8f0c8a0b in dec_counter_for_resize_op (pagecache=0x564a90f198c0 <maria_pagecache_var>) at /data/src/10.5/storage/maria/ma_pagecache.c:1098
      #9  0x0000564a8f0d0dff in pagecache_read (pagecache=0x564a90f198c0 <maria_pagecache_var>, file=0x7f99c802bcc0, pageno=15, level=3, buff=0x7f99d83b96c0 "\001", type=PAGECACHE_LSN_PAGE, lock=PAGECACHE_LOCK_WRITE, page_link=0x7f99d83b9650) at /data/src/10.5/storage/maria/ma_pagecache.c:3758
      #10 0x0000564a8f0f94e1 in _ma_fetch_keypage (page=0x7f99d83bb840, info=0x7f997c02d358, keyinfo=0x7f99c802c368, pos=122880, lock=PAGECACHE_LOCK_WRITE, level=3, buff=0x7f99d83b96c0 "\001", return_buffer=0 '\000') at /data/src/10.5/storage/maria/ma_page.c:110
      #11 0x0000564a8f124de0 in w_search (info=0x7f997c02d358, comp_flag=131076, key=0x7f99d83be5f0, page_pos=122880, father_page=0x7f99d83bda30, father_keypos=0x7f99d83bb955 "", insert_last=1 '\001') at /data/src/10.5/storage/maria/ma_write.c:639
      #12 0x0000564a8f125382 in w_search (info=0x7f997c02d358, comp_flag=131076, key=0x7f99d83be5f0, page_pos=24576, father_page=0x0, father_keypos=0x0, insert_last=1 '\001') at /data/src/10.5/storage/maria/ma_write.c:735
      #13 0x0000564a8f12472d in _ma_ck_real_write_btree (info=0x7f997c02d358, key=0x7f99d83be5f0, root=0x7f99d83bdb40, comp_flag=131076) at /data/src/10.5/storage/maria/ma_write.c:528
      #14 0x0000564a8f1245a7 in _ma_ck_write_btree_with_log (info=0x7f997c02d358, key=0x7f99d83be5f0, root=0x7f99c802c548, comp_flag=131076) at /data/src/10.5/storage/maria/ma_write.c:495
      #15 0x0000564a8f1243f8 in _ma_ck_write_btree (info=0x7f997c02d358, key=0x7f99d83be5f0) at /data/src/10.5/storage/maria/ma_write.c:453
      #16 0x0000564a8f12435b in _ma_ck_write (info=0x7f997c02d358, key=0x7f99d83be5f0) at /data/src/10.5/storage/maria/ma_write.c:438
      #17 0x0000564a8f123ace in maria_write (info=0x7f997c02d358, record=0x7f997c02c688 "\377") at /data/src/10.5/storage/maria/ma_write.c:189
      #18 0x0000564a8f09decd in ha_maria::write_row (this=0x7f997c02caf0, buf=0x7f997c02c688 "\377") at /data/src/10.5/storage/maria/ha_maria.cc:1256
      #19 0x0000564a8ee26b55 in handler::ha_write_row (this=0x7f997c02caf0, buf=0x7f997c02c688 "\377") at /data/src/10.5/sql/handler.cc:6986
      #20 0x0000564a8ea71d83 in write_record (thd=0x7f997c000b18, table=0x7f997c02b808, info=0x7f99d83be930, sink=0x0) at /data/src/10.5/sql/sql_insert.cc:2091
      #21 0x0000564a8ea6ec2c in mysql_insert (thd=0x7f997c000b18, table_list=0x7f997c01a430, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false, result=0x0) at /data/src/10.5/sql/sql_insert.cc:1088
      #22 0x0000564a8eac0568 in mysql_execute_command (thd=0x7f997c000b18) at /data/src/10.5/sql/sql_parse.cc:4553
      #23 0x0000564a8e9c94ba in sp_instr_stmt::exec_core (this=0x7f997c01b120, thd=0x7f997c000b18, nextp=0x7f99d83bf2f4) at /data/src/10.5/sql/sp_head.cc:3761
      #24 0x0000564a8e9c8859 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7f997c01b168, thd=0x7f997c000b18, nextp=0x7f99d83bf2f4, open_tables=false, instr=0x7f997c01b120) at /data/src/10.5/sql/sp_head.cc:3488
      #25 0x0000564a8e9c907f in sp_instr_stmt::execute (this=0x7f997c01b120, thd=0x7f997c000b18, nextp=0x7f99d83bf2f4) at /data/src/10.5/sql/sp_head.cc:3667
      #26 0x0000564a8e9c2776 in sp_head::execute (this=0x7f997c019650, thd=0x7f997c000b18, merge_da_on_success=true) at /data/src/10.5/sql/sp_head.cc:1432
      #27 0x0000564a8e9c554e in sp_head::execute_procedure (this=0x7f997c019650, thd=0x7f997c000b18, args=0x7f997c0059f8) at /data/src/10.5/sql/sp_head.cc:2442
      #28 0x0000564a8eabb91d in do_execute_sp (thd=0x7f997c000b18, sp=0x7f997c019650) at /data/src/10.5/sql/sql_parse.cc:3050
      #29 0x0000564a8eac4da0 in mysql_execute_command (thd=0x7f997c000b18) at /data/src/10.5/sql/sql_parse.cc:5681
      #30 0x0000564a8eacbfb9 in mysql_parse (thd=0x7f997c000b18, rawbuf=0x7f997c0124f0 "LOOP\nINSERT INTO t1 () VALUES (),(),(),(),(),(),(),();\nINSERT INTO t2 () VALUES (),(),(),(),(),(),(),();\nEND LOOP", length=113, parser_state=0x7f99d83c0520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7991
      #31 0x0000564a8eab8365 in dispatch_command (command=COM_QUERY, thd=0x7f997c000b18, packet=0x7f997c008939 "LOOP\nINSERT INTO t1 () VALUES (),(),(),(),(),(),(),();\nINSERT INTO t2 () VALUES (),(),(),(),(),(),(),();\nEND LOOP ", packet_length=114, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1875
      #32 0x0000564a8eab6a9d in do_command (thd=0x7f997c000b18) at /data/src/10.5/sql/sql_parse.cc:1356
      #33 0x0000564a8ec5a561 in do_handle_one_connection (connect=0x564a9230d658, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1411
      #34 0x0000564a8ec5a2c9 in handle_one_connection (arg=0x564a9230d658) at /data/src/10.5/sql/sql_connect.cc:1313
      #35 0x0000564a8f190fd8 in pfs_spawn_thread (arg=0x564a92226ea8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
      #36 0x00007f99eb54b4a4 in start_thread (arg=0x7f99d83c1700) at pthread_create.c:456
      #37 0x00007f99e967fd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

      All threads' stack trace is attached: all_threads

      Here is an RQG grammar if you prefer it to the MTR test. Most 10.5-friendly RQG branches will probably do, but for certainty please take the master:

      git clone https://github.com/MariaDB/randgen rqg-master
      cd rqg-master
      perl runall-new.pl --basedir=<your basedir> --grammar=./mdev22746.yy --vardir=/dev/shm/var_mdev22746  --threads=10 --skip-gendata
      

      mdev22746.yy

      query_init:
          CREATE TABLE IF NOT EXISTS t1 (a VARCHAR(1), KEY(a)) ENGINE=Aria
          ; CREATE TABLE IF NOT EXISTS t2 (a VARCHAR(1), KEY(a)) ENGINE=Aria; 
       
      query:
          INSERT INTO t1 () VALUES (),(),(),(),(),()
        | INSERT INTO t2 () VALUES (),(),(),(),(),()
      ;
       
      thread1:
        BACKUP STAGE START; BACKUP STAGE BLOCK_COMMIT; BACKUP STAGE END;
      

      I think the failure started happening after the recent Aria changes in 10.5, although I didn't bisect for the exact commit.
      Not reproducible on 10.4.
      So far I didn't observe any obvious problem on a non-debug build, but there is no guarantee that there are no hidden ones.

        Attachments

          Activity

            People

            Assignee:
            sanja Oleksandr Byelkin
            Reporter:
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: