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

Assertion `log_descriptor.bc.buffer->prev_last_lsn == ((LSN)0)' failed in translog_flush_buffers

    Details

      Description

      10.3 c5a9a63293

      mysqld: /data/src/10.3/storage/maria/ma_loghandler.c:7966: translog_flush_buffers: Assertion `log_descriptor.bc.buffer->prev_last_lsn == ((LSN)0)' failed.
      180918 15:03:22 [ERROR] mysqld got signal 6 ;
       
      #5  0x00007fd2cf54b3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
      13186", create_info=0x7fd2cc16c4d0, frm=0x7fd2cc16bee0) at /data/src/10.3/sql/handler.cc:4966
      #14 0x00005610844f78c2 in rea_create_table (thd=0x7fd25c000b00, frm=0x7fd2cc16bee0, path=0x7fd2cc16bef0 "./transforms/delete_returning_13186", db=0x7fd25c031af0 "transforms", table_name=0x7fd25c031b00 "delete_returning_13186", create_info=0x7fd2cc16c4d0, file=0x7fd25c02a4e0, no_ha_create_table=false) at /data/src/10.3/sql/unireg.cc:514
      #15 0x000056108449a36e in create_table_impl (thd=0x7fd25c000b00, orig_db=0x7fd25c031b70, orig_table_name=0x7fd25c031b80, db=0x7fd25c031b70, table_name=0x7fd25c031b80, path=0x7fd2cc16bef0 "./transforms/delete_returning_13186", options=..., create_info=0x7fd2cc16c4d0, alter_info=0x7fd2cc16c410, create_table_mode=0, is_trans=0x7fd2cc16c14e, key_info=0x7fd2cc16bed0, key_count=0x7fd2cc16bec4, frm=0x7fd2cc16bee0) at /data/src/10.3/sql/sql_table.cc:4974
      #16 0x000056108449a987 in mysql_create_table_no_lock (thd=0x7fd25c000b00, db=0x7fd25c031b70, table_name=0x7fd25c031b80, create_info=0x7fd2cc16c4d0, alter_info=0x7fd2cc16c410, is_trans=0x7fd2cc16c14e, create_table_mode=0, table_list=0x7fd25c031b58) at /data/src/10.3/sql/sql_table.cc:5095
      #17 0x000056108449ad26 in mysql_create_table (thd=0x7fd25c000b00, create_table=0x7fd25c031b58, create_info=0x7fd2cc16c4d0, alter_info=0x7fd2cc16c410) at /data/src/10.3/sql/sql_table.cc:5188
      #18 0x00005610843c99d6 in mysql_execute_command (thd=0x7fd25c000b00) at /data/src/10.3/sql/sql_parse.cc:4280
      #19 0x00005610843f3916 in Prepared_statement::execute (this=0x7fd25c014310, expanded_query=0x7fd2cc16d3c0, open_cursor=false) at /data/src/10.3/sql/sql_prepare.cc:4764
      #20 0x00005610843f1d08 in Prepared_statement::execute_loop (this=0x7fd25c014310, expanded_query=0x7fd2cc16d3c0, open_cursor=false, packet=0x7fd25c00b22a "", packet_end=0x7fd25c00b22a "") at /data/src/10.3/sql/sql_prepare.cc:4192
      #21 0x00005610843ef52b in mysql_stmt_execute_common (thd=0x7fd25c000b00, stmt_id=2, packet=0x7fd25c00b22a "", packet_end=0x7fd25c00b22a "", cursor_flags=0, bulk_op=false, read_types=false) at /data/src/10.3/sql/sql_prepare.cc:3192
      #22 0x00005610843ef0c4 in mysqld_stmt_execute (thd=0x7fd25c000b00, packet_arg=0x7fd25c00b221 "\002", packet_length=9) at /data/src/10.3/sql/sql_prepare.cc:3090
      #23 0x00005610843c2bcd in dispatch_command (command=COM_STMT_EXECUTE, thd=0x7fd25c000b00, packet=0x7fd25c00b221 "\002", packet_length=9, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1792
      #24 0x00005610843c19a2 in do_command (thd=0x7fd25c000b00) at /data/src/10.3/sql/sql_parse.cc:1395
      #25 0x000056108452883b in do_handle_one_connection (connect=0x5610874dd1a0) at /data/src/10.3/sql/sql_connect.cc:1402
      #26 0x00005610845285bf in handle_one_connection (arg=0x5610874dd1a0) at /data/src/10.3/sql/sql_connect.cc:1308
      #27 0x00007fd2d1219494 in start_thread (arg=0x7fd2cc16e700) at pthread_create.c:333
      #28 0x00007fd2cf5ff93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
      

      The best test case that I currently have is attached. It's an extremely ugly test case, most of its contents should have nothing to do with the problem, but I can't remove anything else without reducing the probability of reproducing to almost none. It already requires on average a hundred repetitions, but it's totally unpredictable – sometimes it happens in first 10 attempts, sometimes after 400.

      Run as

       perl ./mtr bug.lsn8 --repeat=500 --ps-protocol --mem
      

      ps-protocol is not necessary, the test might still fail without it, but it seems to make the failure more probable.
      mem is not necessary, but it makes things faster.
      repeat=500 is arbitrary if not a guarantee. If you can, set even a higher number, or run several times if it doesn't happen right away.

      No visible effect on a non-debug build.

      10.3 and 10.4 are affected. It might well be that 10.2 and earlier versions are also affected, but the test contains some 10.3-specific stuff, and since I can't change anything there, I can't check if the problem exists in earlier versions.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                vlad.lesin Vladislav Lesin
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated: