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

Server crash or assertion `file != ((void *)0)' failure in translog_sync_files

    XMLWordPrintable

Details

    Description

      I get these failures on all versions and different builds, although some versions and builds are more willing to reproduce it than others.
      However, so far I can't come up with a general test which would work (fail) on all versions. There are some unreliable version-specific variants which employ backup stages (the failure on 10.2 below shows that it's not limited to backup stages).

      10.2 bf1e09e0 debug,

      		 
      mysqld: /home/elenst/src/10.2/storage/maria/ma_loghandler.c:7882: translog_sync_files: Assertion `file != ((void *)0)' failed.
      		 
      210411 11:36:59 [ERROR] mysqld got signal 6 ;
      		 
       
      		 
      #7  0x00007f5267aa20d2 in __assert_fail () from /lib64/libc.so.6
      		 
      #8  0x000055b391b84445 in translog_sync_files (min=1, max=2619214, sync_dir=0 '\000') at /home/elenst/src/10.2/storage/maria/ma_loghandler.c:7882
      		 
      #9  0x000055b391b850dd in translog_flush (lsn=11249439983363622) at /home/elenst/src/10.2/storage/maria/ma_loghandler.c:8199
      		 
      #10 0x000055b391b9ecef in maria_flush_log_for_page (args=0x7f525009b4d0) at /home/elenst/src/10.2/storage/maria/ma_pagecrc.c:376
      		 
      #11 0x000055b391b87e76 in pagecache_fwrite (pagecache=0x55b393136a60 <maria_pagecache_var>, filedesc=0x7f5251a23418, buffer=0x7f52529d0080 "N\367'&f!Z", pageno=2, type=PAGECACHE_LSN_PAGE, flags=36) at /home/elenst/src/10.2/storage/maria/ma_pagecache.c:660
      		 
      #12 0x000055b391b9193c in flush_cached_blocks (pagecache=0x55b393136a60 <maria_pagecache_var>, file=0x7f51b01ebce0, cache=0x7f525009b6e0, end=0x7f525009b710, type=FLUSH_RELEASE, first_errno=0x7f525009b644) at /home/elenst/src/10.2/storage/maria/ma_pagecache.c:4419
      		 
      #13 0x000055b391b922e6 in flush_pagecache_blocks_int (pagecache=0x55b393136a60 <maria_pagecache_var>, file=0x7f51b01ebce0, type=FLUSH_RELEASE, filter=0x0, filter_arg=0x0) at /home/elenst/src/10.2/storage/maria/ma_pagecache.c:4715
      		 
      #14 0x000055b391b92705 in flush_pagecache_blocks_with_filter (pagecache=0x55b393136a60 <maria_pagecache_var>, file=0x7f51b01ebce0, type=FLUSH_RELEASE, filter=0x0, filter_arg=0x0) at /home/elenst/src/10.2/storage/maria/ma_pagecache.c:4832
      		 
      #15 0x000055b391be8d2e in maria_close (info=0x7f51b07fc840) at /home/elenst/src/10.2/storage/maria/ma_close.c:49
      		 
      #16 0x000055b391b64aba in ha_maria::close (this=0x7f51b01e9328) at /home/elenst/src/10.2/storage/maria/ha_maria.cc:1277
      		 
      #17 0x000055b3915965f1 in handler::ha_close (this=0x7f51b01e9328) at /home/elenst/src/10.2/sql/handler.cc:2657
      		 
      #18 0x000055b391417bfa in closefrm (table=0x7f51b01e8720) at /home/elenst/src/10.2/sql/table.cc:3525
      		 
      #19 0x000055b391506f01 in intern_close_table (table=0x7f51b01e8720) at /home/elenst/src/10.2/sql/table_cache.cc:222
      		 
      #20 0x000055b391507308 in tc_purge (mark_flushed=true) at /home/elenst/src/10.2/sql/table_cache.cc:335
      		 
      #21 0x000055b3912963de in close_cached_tables (thd=0x7f51c4000af0, tables=0x0, wait_for_refresh=true, timeout=10) at /home/elenst/src/10.2/sql/sql_base.cc:374
      		 
      #22 0x000055b39149afa9 in reload_acl_and_cache (thd=0x7f51c4000af0, options=4, tables=0x0, write_to_binlog=0x7f525009fc10) at /home/elenst/src/10.2/sql/sql_reload.cc:344
      		 
      #23 0x000055b391312061 in mysql_execute_command (thd=0x7f51c4000af0) at /home/elenst/src/10.2/sql/sql_parse.cc:5201
      		 
      #24 0x000055b391319775 in mysql_parse (thd=0x7f51c4000af0, rawbuf=0x7f51c40132e8 "FLUSH /* QNO 1291 CON_ID 25 */ TABLES", length=37, parser_state=0x7f52500a0520, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.2/sql/sql_parse.cc:7794
      		 
      #25 0x000055b391307a5e in dispatch_command (command=COM_QUERY, thd=0x7f51c4000af0, packet=0x7f51c40088b1 "FLUSH /* QNO 1291 CON_ID 25 */ TABLES", packet_length=37, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.2/sql/sql_parse.cc:1828
      		 
      #26 0x000055b391306404 in do_command (thd=0x7f51c4000af0) at /home/elenst/src/10.2/sql/sql_parse.cc:1382
      		 
      #27 0x000055b39145fef6 in do_handle_one_connection (connect=0x55b394272580) at /home/elenst/src/10.2/sql/sql_connect.cc:1336
      		 
      #28 0x000055b39145fc41 in handle_one_connection (arg=0x55b394272580) at /home/elenst/src/10.2/sql/sql_connect.cc:1241
      		 
      #29 0x00007f52697b4dd5 in start_thread () from /lib64/libpthread.so.0
      		 
      #30 0x00007f5267b70ead in clone () from /lib64/libc.so.6

      all threads for the above: threads_full_10_2_debug

      10.5 2e67b9f6 debug

      		 
      mysqld: /home/elenst/src/10.5/storage/maria/ma_loghandler.c:7888: translog_sync_files: Assertion `file != ((void *)0)' failed.
      		 
      210327  1:58:59 [ERROR] mysqld got signal 6 ;
      		 
       
      		 
      #7  0x00007fa224c30252 in __assert_fail () from /lib64/libc.so.6
      		 
      #8  0x00005559cb342389 in translog_sync_files (min=1, max=4161181, sync_dir=0 '\000') at /home/elenst/src/10.5/storage/maria/ma_loghandler.c:7888
      		 
      #9  0x00005559cb343265 in translog_flush (lsn=17872137156560647) at /home/elenst/src/10.5/storage/maria/ma_loghandler.c:8233
      		 
      #10 0x00005559cb3621fe in maria_flush_log_for_page (args=0x7fa20c0662c0) at /home/elenst/src/10.5/storage/maria/ma_pagecrc.c:375
      		 
      #11 0x00005559cb346746 in pagecache_fwrite (pagecache=0x5559cd1ca940 <maria_pagecache_var>, filedesc=0x7fa22194c670, buffer=0x7fa20ec45000 "\235~?\a\a\230\062", pageno=1, type=PAGECACHE_LSN_PAGE, flags=36) at /home/elenst/src/10.5/storage/maria/ma_pagecache.c:675
      		 
      #12 0x00005559cb353d47 in flush_cached_blocks (pagecache=0x5559cd1ca940 <maria_pagecache_var>, file=0x7fa1a053f760, cache=0x7fa20c0664d0, end=0x7fa20c066558, type=FLUSH_RELEASE, first_errno=0x7fa20c066434) at /home/elenst/src/10.5/storage/maria/ma_pagecache.c:4815
      		 
      #13 0x00005559cb35485b in flush_pagecache_blocks_int (pagecache=0x5559cd1ca940 <maria_pagecache_var>, file=0x7fa1a053f760, type=FLUSH_RELEASE, filter=0x0, filter_arg=0x0) at /home/elenst/src/10.5/storage/maria/ma_pagecache.c:5111
      		 
      #14 0x00005559cb354cab in flush_pagecache_blocks_with_filter (pagecache=0x5559cd1ca940 <maria_pagecache_var>, file=0x7fa1a053f760, type=FLUSH_RELEASE, filter=0x0, filter_arg=0x0) at /home/elenst/src/10.5/storage/maria/ma_pagecache.c:5226
      		 
      #15 0x00005559cb312b95 in maria_close (info=0x7fa1a00fb4e8) at /home/elenst/src/10.5/storage/maria/ma_close.c:52
      		 
      #16 0x00005559cb31cb2f in ha_maria::close (this=0x7fa1a05edd70) at /home/elenst/src/10.5/storage/maria/ha_maria.cc:1243
      		 
      #17 0x00005559cb08c5a7 in handler::ha_close (this=0x7fa1a05edd70) at /home/elenst/src/10.5/sql/handler.cc:3053
      		 
      #18 0x00005559cae63750 in closefrm (table=0x7fa1a06db698) at /home/elenst/src/10.5/sql/table.cc:4322
      		 
      #19 0x00005559cafadd55 in intern_close_table (table=0x7fa1a06db698) at /home/elenst/src/10.5/sql/table_cache.cc:220
      		 
      #20 0x00005559cafae17c in tc_purge () at /home/elenst/src/10.5/sql/table_cache.cc:312
      		 
      #21 0x00005559cac6c6d1 in purge_tables () at /home/elenst/src/10.5/sql/sql_base.cc:327
      		 
      #22 0x00005559cac6c85c in close_cached_tables (thd=0x7fa1b0000b18, tables=0x0, wait_for_refresh=true, timeout=10) at /home/elenst/src/10.5/sql/sql_base.cc:356
      		 
      #23 0x00005559caf0b56b in reload_acl_and_cache (thd=0x7fa1b0000b18, options=4, tables=0x0, write_to_binlog=0x7fa20c06a9e0) at /home/elenst/src/10.5/sql/sql_reload.cc:336
      		 
      #24 0x00005559cad2278d in mysql_execute_command (thd=0x7fa1b0000b18) at /home/elenst/src/10.5/sql/sql_parse.cc:5515
      		 
      #25 0x00005559cac23a49 in sp_instr_stmt::exec_core (this=0x7fa1b00c1cd8, thd=0x7fa1b0000b18, nextp=0x7fa20c06af4c) at /home/elenst/src/10.5/sql/sp_head.cc:3768
      		 
      #26 0x00005559cac22d99 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7fa1b00c1d20, thd=0x7fa1b0000b18, nextp=0x7fa20c06af4c, open_tables=false, instr=0x7fa1b00c1cd8) at /home/elenst/src/10.5/sql/sp_head.cc:3495
      		 
      #27 0x00005559cac235c1 in sp_instr_stmt::execute (this=0x7fa1b00c1cd8, thd=0x7fa1b0000b18, nextp=0x7fa20c06af4c) at /home/elenst/src/10.5/sql/sp_head.cc:3674
      		 
      #28 0x00005559cac1ccda in sp_head::execute (this=0x7fa1b00c1080, thd=0x7fa1b0000b18, merge_da_on_success=true) at /home/elenst/src/10.5/sql/sp_head.cc:1437
      		 
      #29 0x00005559cac1fac5 in sp_head::execute_procedure (this=0x7fa1b00c1080, thd=0x7fa1b0000b18, args=0x7fa1b0005ba8) at /home/elenst/src/10.5/sql/sp_head.cc:2449
      		 
      #30 0x00005559cad19e5a in do_execute_sp (thd=0x7fa1b0000b18, sp=0x7fa1b00c1080) at /home/elenst/src/10.5/sql/sql_parse.cc:3088
      		 
      #31 0x00005559cad1aa84 in Sql_cmd_call::execute (this=0x7fa1b0013b48, thd=0x7fa1b0000b18) at /home/elenst/src/10.5/sql/sql_parse.cc:3334
      		 
      #32 0x00005559cad24818 in mysql_execute_command (thd=0x7fa1b0000b18) at /home/elenst/src/10.5/sql/sql_parse.cc:6049
      		 
      #33 0x00005559cad2a6ff in mysql_parse (thd=0x7fa1b0000b18, rawbuf=0x7fa1b0013a70 "CALL /* QNO 2511 CON_ID 18 */ sp4", length=33, parser_state=0x7fa20c06c3e0, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.5/sql/sql_parse.cc:8093
      		 
      #34 0x00005559cad16737 in dispatch_command (command=COM_QUERY, thd=0x7fa1b0000b18, packet=0x7fa1b000b179 "CALL /* QNO 2511 CON_ID 18 */ sp4", packet_length=33, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.5/sql/sql_parse.cc:1890
      		 
      #35 0x00005559cad14dab in do_command (thd=0x7fa1b0000b18) at /home/elenst/src/10.5/sql/sql_parse.cc:1371
      		 
      #36 0x00005559caec1453 in do_handle_one_connection (connect=0x5559ce9fa248, put_in_cache=true) at /home/elenst/src/10.5/sql/sql_connect.cc:1410
      		 
      #37 0x00005559caec1197 in handle_one_connection (arg=0x5559ce9fa248) at /home/elenst/src/10.5/sql/sql_connect.cc:1312
      		 
      #38 0x00005559cb411846 in pfs_spawn_thread (arg=0x5559ce8f49f8) at /home/elenst/src/10.5/storage/perfschema/pfs.cc:2201
      		 
      #39 0x00007fa226b49ea5 in start_thread () from /lib64/libpthread.so.0
      		 
      #40 0x00007fa224cff8dd in clone () from /lib64/libc.so.6

      all threads for the above: threads_full_10_5_debug

      Couldn't reproduce with rr or with debug trace.

      A coredump (from a different occasion) is available.

      Attachments

        1. threads_full_10_5_debug
          351 kB
        2. threads_full_10_2_debug
          189 kB
        3. threads_10_5e_rel
          63 kB
        4. threads_10_5e_debug
          69 kB

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-17225 Assertion `log_descriptor.bc.buffer->prev_last_lsn == ((LSN)0)' failed in translog_flush_buffers

          • Major - Major loss of function.
          • Open

          Activity

            People

              monty Michael Widenius
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

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