[MDEV-15256] Crash in flush_cached_blocks Created: 2018-02-08  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Storage Engine - Aria
Affects Version/s: 5.5, 10.1, 10.1.22, 10.1.30, 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0
Fix Version/s: 10.4, 10.5, 10.6, 10.11

Type: Bug Priority: Major
Reporter: Frank Maas Assignee: Michael Widenius
Resolution: Unresolved Votes: 0
Labels: None
Environment:

CentOS Linux release 7.4.1708


Issue Links:
Relates
relates to MDEV-654 LP:1000495 - Assertion `share->now_tr... Closed
relates to MDEV-4312 aria: background thread crashes in ma... Closed
relates to MDEV-18947 my_pwrite / pagecache_fwrite: Syscall... Open

 Description   

We have copied part of our environment to a virtual server and since then we have experienced random crashes (4 times in a couple of weeks). As soon as the crash happens the dbms won't restart, since it crashes again while recovering. The latest crash, tonight, shows this stacktrace:

stack_bottom = 0x0 thread_stack 0x48400
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55d96d72cd0e]
/usr/sbin/mysqld(handle_fatal_signal+0x305)[0x55d96d24f925]
/lib64/libpthread.so.0(+0xf5e0)[0x7f759d8a15e0]
/usr/sbin/mysqld(+0x790bc7)[0x55d96d41ebc7]
/usr/sbin/mysqld(+0x791422)[0x55d96d41f422]
/usr/sbin/mysqld(+0x79568c)[0x55d96d42368c]
/usr/sbin/mysqld(+0x797108)[0x55d96d425108]
/lib64/libpthread.so.0(+0x7e25)[0x7f759d899e25]
/lib64/libc.so.6(clone+0x6d)[0x7f759bc3d34d]

Using 'addr2line' I deduced that the crash happens while doing a pagecache flush:

flush_cached_blocks .../mariadb-10.1.30/storage/maria/ma_pagecache.c:4431
flush_pagecache_blocks_int .../mariadb-10.1.30/storage/maria/ma_pagecache.c:4727
flush_pagecache_blocks_with_filter .../mariadb-10.1.30/storage/maria/ma_pagecache.c:4844
ma_checkpoint_background .../mariadb-10.1.30/storage/maria/ma_checkpoint.c:674

As said, when the dbms restarts, the recovery fails:

recovered pages: 0% 10% 20% 30% 40% 50%180208 21:55:00 [ERROR] mysqld got signal 11 ;

which happens here:

stack_bottom = 0x0 thread_stack 0x48400
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x5637695b7d0e]
/usr/sbin/mysqld(handle_fatal_signal+0x305)[0x5637690da925]
/lib64/libpthread.so.0(+0xf5e0)[0x7f041f2795e0]
/usr/sbin/mysqld(+0x799f6b)[0x5637692b2f6b]
/usr/sbin/mysqld(+0x7992f1)[0x5637692b22f1]
/usr/sbin/mysqld(+0x79df00)[0x5637692b6f00]
/usr/sbin/mysqld(+0x79e8ae)[0x5637692b78ae]
mysys/stacktrace.c:268(my_print_stacktrace)[0x5637692900bd]
maria/ma_recovery.c:2139(exec_REDO_LOGREC_CLR_END)[0x5637690dcbd4]
sql/handler.cc:521(ha_initialize_handlerton(st_plugin_int*))[0x563768f64730]
sql/sql_plugin.cc:1404(plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool))[0x563768f6601a]
/usr/sbin/mysqld(+0x3a1768)[0x563768eba768]
sql/mysqld.cc:5133(init_server_components())[0x563768ebe210]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f041d53ec05]
/usr/sbin/mysqld(+0x398ced)[0x563768eb1ced]

The four mysqld addresses translate to:

exec_REDO_LOGREC_CLR_END .../mariadb-10.1.30/storage/maria/ma_recovery.c:2139
display_and_apply_record .../mariadb-10.1.30/storage/maria/ma_recovery.c:588
run_redo_phase .../mariadb-10.1.30/storage/maria/ma_recovery.c:2730
maria_apply_log .../mariadb-10.1.30/storage/maria/ma_recovery.c:350
maria_recovery_from_log .../mariadb-10.1.30/storage/maria/ma_recovery.c:242

We can get the dbms running by removing a the table in which the redo log crashes (as determined by using aria_read_log) and moving the table back in after the restart.

Then everything runs fine, for a few days, for a week, even for two weeks and then it crashes again.

We haven't got the faintest idea of what goes wrong. I checked the open bugs and found some vague resemblance, but nothing that stood out. There is no oom-error or other malfunction visible on the system that can be pinpointed to the problem. I tried to investigate (at least) the aria_log file, but could not find tools to find out what is causing the crash in the restart. I know that the record which causes the crash is not the last record in the logfile, so it seems the two crashes are not related.

But we are a bit at a dead end. Any help is appreciated. We can enable logs (if someone tells us how), we can run a debug version, we can even try to update to 10.2 (but there are some issues in de Perl DBD::mysql module at the moment that keep us from doing so). Bear in mind that updating from 10.1.22 to 10.1.30 did not solve the issue. Help is appreciated...



 Comments   
Comment by Daniel Black [ 2018-02-09 ]

Bit sad that its crashing on a print https://github.com/MariaDB/server/blob/10.1/storage/maria/ma_recovery.c#L2139.

Was it functional and operational before it was copied to the VPS?

Obtaining a core dump and doing a backtrace (https://mariadb.com/kb/en/library/how-to-produce-a-full-stack-trace-for-mysqld/#using-the-core-file) would be useful.

If you are able to share the table before restoration can you upload it privately to our developers: https://mariadb.com/kb/en/meta/mariadb-ftp-server/ (and provide a SHOW CREATE TABLE for this table).

Have you tried to take a sql dump of the table and restore it that way rather than a hot copy?

I'm partially curious what DBD::mysql troubles you have as MariaDB's test suite uses those for testing.

Comment by Frank Maas [ 2018-02-10 ]

danblack: to answer your questions/observations:

  • the recovery seems to crash on a print, but the main issue (for us) is the "original crash". But since that crash looks like to be related to a checkpoint creation I am not sure there is no relation, so that's why I included it.
  • the database was and is functional before copying to the VPS. "Is" because the same database, tables and operations on the data are still also taking place on a non-virtual database server. However, that server runs 10.1.17 and the table uses MyISAM in stead of Aria. So quite a lot of differences there...
  • we'll look into creating the core-dump and will make a copy of the table when and if a crash happens and restore fails. It is not a very difficult table though:

CREATE TABLE `table` (
`a` VARCHAR(255) NOT NULL DEFAULT '' COLLATE 'latin1_general_ci',
`b` INT(11) NULL DEFAULT NULL,
`c` DATETIME NULL DEFAULT NULL,
PRIMARY KEY (`a`)
)
COLLATE='latin1_general_ci'
ENGINE=Aria;

  • Since the database server won't start with the table in place, I do not really see how I could try the SQL dump approach.
Comment by Elena Stepanova [ 2018-02-10 ]

The initial crash is a known problem, it's MDEV-4312. I've re-checked that it's still reproducible on current trees and added a note about that.

The second crash upon recovery hasn't been reported before.

10.1.30 debug

2018-02-10 19:11:12 139834242058112 [Note] mysqld: Aria engine: starting recovery
recovered pages: 0% 10% 20% 30% 29% 39% 49% 48% 58% 68% 67% 77% 87% 97% 96% 100% (3.3 seconds); transactions to roll back: 2mysqld: /data/src/10.1/storage/maria/ma_blockrec.c:2877: write_block_record: Assertion `undo_lsn == ((LSN)1) || head_length == row_pos->length' failed.
180210 19:11:15 [ERROR] mysqld got signal 6 ;
 
#5  0x00007f2daefa2448 in __GI_abort () at abort.c:89
#6  0x00007f2daef9a266 in __assert_fail_base (fmt=0x7f2daf0d2f18 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f2db2054ae0 "undo_lsn == ((LSN)1) || head_length == row_pos->length", file=file@entry=0x7f2db2053fe0 "/data/src/10.1/storage/maria/ma_blockrec.c", line=line@entry=2877, function=function@entry=0x7f2db2055de0 <__PRETTY_FUNCTION__.16207> "write_block_record") at assert.c:92
#7  0x00007f2daef9a312 in __GI___assert_fail (assertion=0x7f2db2054ae0 "undo_lsn == ((LSN)1) || head_length == row_pos->length", file=0x7f2db2053fe0 "/data/src/10.1/storage/maria/ma_blockrec.c", line=2877, function=0x7f2db2055de0 <__PRETTY_FUNCTION__.16207> "write_block_record") at assert.c:101
#8  0x00007f2db1cc829d in write_block_record (info=0x7f2d9cbe9070, old_record=0x7f2dae709970 "\260(\336J-\343\363m  c\003s  \031\017", record=0x7f2dae709aa7 "\377\021\005\262 \266Km  c\003s  \031\017", row=0x7f2d9cbe9188, bitmap_blocks=0x7f2d9cbe90c8, head_block_is_read=1 '\001', row_pos=0x7fff5093e2c0, undo_lsn=0, old_record_checksum=0) at /data/src/10.1/storage/maria/ma_blockrec.c:2877
#9  0x00007f2db1ccb077 in _ma_update_at_original_place (info=0x7f2d9cbe9070, page=92, rownr=18, length_on_head_page=168, extent_count=0, extent_info=0x7f2d9c6aa083 "", oldrec=0x7f2dae709970 "\260(\336J-\343\363m  c\003s  \031\017", record=0x7f2dae709aa7 "\377\021\005\262 \266Km  c\003s  \031\017", undo_lsn=0) at /data/src/10.1/storage/maria/ma_blockrec.c:4000
#10 0x00007f2db1cd3d3a in _ma_apply_undo_row_update (info=0x7f2d9cbe9070, undo_lsn=0, header=0x7f2d9c6aa08b "\177\275", <incomplete sequence \366\200>, header_length=11) at /data/src/10.1/storage/maria/ma_blockrec.c:7439
#11 0x00007f2db1c9a9ab in exec_UNDO_LOGREC_UNDO_ROW_UPDATE (rec=0x7fff5093e4c0, trn=0x7f2dae5f58f0) at /data/src/10.1/storage/maria/ma_recovery.c:2371
#12 0x00007f2db1c9c229 in run_undo_phase (uncommitted=1) at /data/src/10.1/storage/maria/ma_recovery.c:2948
#13 0x00007f2db1c96082 in maria_apply_log (from_lsn=4589904097, end_lsn=0, apply=MARIA_LOG_APPLY, trace_file=0x0, should_run_undo_phase=1 '\001', skip_DDLs_arg=1 '\001', take_checkpoints=1 '\001', warnings_count=0x7fff5093e9d0) at /data/src/10.1/storage/maria/ma_recovery.c:422
#14 0x00007f2db1c95b9b in maria_recovery_from_log () at /data/src/10.1/storage/maria/ma_recovery.c:240
#15 0x00007f2db1c6be03 in ha_maria_init (p=0x7f2dae423670) at /data/src/10.1/storage/maria/ha_maria.cc:3591
#16 0x00007f2db1776b9a in ha_initialize_handlerton (plugin=0x7f2dae722c38) at /data/src/10.1/sql/handler.cc:521
#17 0x00007f2db1550aa9 in plugin_initialize (tmp_root=0x7fff5093ee00, plugin=0x7f2dae722c38, argc=0x7f2db28199f0 <remaining_argc>, argv=0x7f2dae421428, options_only=false) at /data/src/10.1/sql/sql_plugin.cc:1404
#18 0x00007f2db1551697 in plugin_init (argc=0x7f2db28199f0 <remaining_argc>, argv=0x7f2dae421428, flags=2) at /data/src/10.1/sql/sql_plugin.cc:1682
#19 0x00007f2db146f7a0 in init_server_components () at /data/src/10.1/sql/mysqld.cc:5135
#20 0x00007f2db147080b in mysqld_main (argc=11, argv=0x7f2dae421428) at /data/src/10.1/sql/mysqld.cc:5722
#21 0x00007f2db1465f50 in main (argc=11, argv=0x7fff5093fb98) at /data/src/10.1/sql/main.cc:25

Comment by Elena Stepanova [ 2018-02-11 ]

Frank_VID,
There is a chance that upgrade to 10.1.31 can help with the second part of the problem (crash upon recovery). It's not a certainty, because I'm not getting it on a release build of 10.1.30, but the debug assertion above is reliably reproducible on 10.1.30 and appears to be gone on 10.1.31, possibly together with MDEV-14690.

If you are willing to try it, it could be informative.

It's not a fix, of course. The initial crash will still be reproducible; also, if the initial crash happened on 10.1.30, upgrade to 10.1.31 won't help the recovery; but the initial crash on the new server wouldn't be fatal for further recovery on the new server. All of this, of course, assumes that the recovery problem is the same as the debug assertion above.

Comment by Frank Maas [ 2018-02-11 ]

elenst

  • I found https://jira.mariadb.org/browse/MDEV-4312 while searching for this problem, but that seems to describe a crash one step further (in make_lock_and_pin), wherease "we" crash just before that. However, I do agree that they might be related.
  • We updated to 10.1.31 to seen if this at least solves the recovery problem. It will already help a lot if the db is able to restart itself when and if the original crash happens. Will keep you posted on this.
Comment by Frank Maas [ 2018-02-15 ]

Update: version 10.1.31 still shows the "initial crash", but the problem with the recovery seems to be solved in this version.

Comment by Elena Stepanova [ 2018-06-12 ]

Please try 10.1.34 when it is out; MDEV-4312 appears to be fixed in it along with MDEV-654.

Comment by Elena Stepanova [ 2018-07-13 ]

Have you had a chance to try the new version? Did the problem go away?

Comment by Frank Maas [ 2018-07-13 ]

It took a bit of time before we could install, but unfortunately the problem still seems to exist:

10.1.34 crash

180709 19:23:25 [ERROR] mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
 
Server version: 10.1.34-MariaDB
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=188
max_threads=1002
thread_count=102
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2332265 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x48400
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55c6edb43fbe]
mysys/stacktrace.c:268(my_print_stacktrace)[0x55c6ed667875]
sigaction.c:0(__restore_rt)[0x7f60650ea6d0]
maria/ma_pagecache.c:4431(flush_cached_blocks)[0x55c6ed837cf7]
maria/ma_pagecache.c:4727(flush_pagecache_blocks_int)[0x55c6ed838552]
maria/ma_pagecache.c:4844(flush_pagecache_blocks_with_filter)[0x55c6ed83c09c]
maria/ma_checkpoint.c:674(ma_checkpoint_background)[0x55c6ed83da80]
pthread_create.c:0(start_thread)[0x7f60650e2e25]
/lib64/libc.so.6(clone+0x6d)[0x7f6063252bad]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
2018-07-09 19:23:31 140142618450176 [Note] CONNECT: Version 1.06.0007 March 11, 2018
2018-07-09 19:23:31 140142618450176 [Note] mysqld: Aria engine: starting recovery
recovered pages: 0% 10% 20% 30% 40% 50% 60% 70% 80% 90% 100% (0.1 seconds); tables to flush: 28 27 26 25 24 23 22 21 20 19 18 17 16 15 14 13 12 11 10 9 8 7 6 5 4 3 2 1 0 (0.0 seconds);
2018-07-09 19:23:31 140142618450176 [Note] mysqld: Aria engine: recovery done
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: The InnoDB memory heap is disabled
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Compressed tables use zlib 1.2.7
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Using Linux native AIO
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Using SSE crc32 instructions
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Initializing buffer pool, size = 256.0M
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Completed initialization of buffer pool
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Highest supported file format is Barracuda.
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: The log sequence number 37237605 in ibdata file do not match the log sequence number 37237655 in the ib_logfiles!
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: 128 rollback segment(s) are active.
2018-07-09 19:23:31 140142618450176 [Note] InnoDB: Waiting for purge to start
2018-07-09 19:23:31 140142618450176 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.39-83.1 started; log sequence number 37237655
2018-07-09 19:23:31 140141658109696 [Note] InnoDB: Dumping buffer pool(s) not yet started
2018-07-09 19:23:31 140142618450176 [Note] Plugin 'FEEDBACK' is disabled.
2018-07-09 19:23:31 140142618450176 [Note] Recovering after a crash using tc.log
2018-07-09 19:23:31 140142618450176 [Note] Starting crash recovery...
2018-07-09 19:23:31 140142618450176 [Note] Crash recovery finished.
2018-07-09 19:23:31 140142618450176 [Note] Server socket created on IP: '::'.
2018-07-09 19:23:31 140142618450176 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.1.34-MariaDB'  socket: '/serverdata/mysql/mysql.sock'  port: 3306  MariaDB Server

(and then a few crashed tables are reported)

Comment by Elena Stepanova [ 2019-01-11 ]

I've just had the same crash in my regular tests on 10.4:

#3  <signal handler called>
#4  0x0000556512183d08 in make_lock_and_pin (pagecache=0x556513868920 <maria_pagecache_var>, block=0x7f31a01f9b60, lock=PAGECACHE_LOCK_READ, pin=PAGECACHE_PIN, any=0 '\000') at /data/src/10.4/storage/maria/ma_pagecache.c:2595
#5  0x0000556512188594 in flush_cached_blocks (pagecache=0x556513868920 <maria_pagecache_var>, file=0x7f31880130e8, cache=0x7f318dcd8f88, end=0x7f318dcd8fc8, type=FLUSH_KEEP_LAZY, first_errno=0x7f318dcd8ec4) at /data/src/10.4/storage/maria/ma_pagecache.c:4398
#6  0x0000556512189196 in flush_pagecache_blocks_int (pagecache=0x556513868920 <maria_pagecache_var>, file=0x7f31880130e8, type=FLUSH_KEEP_LAZY, filter=0x55651218b03d <filter_flush_file_evenly>, filter_arg=0x7f318dcdcee0) at /data/src/10.4/storage/maria/ma_pagecache.c:4716
#7  0x00005565121895c6 in flush_pagecache_blocks_with_filter (pagecache=0x556513868920 <maria_pagecache_var>, file=0x7f31880130e8, type=FLUSH_KEEP_LAZY, filter=0x55651218b03d <filter_flush_file_evenly>, filter_arg=0x7f318dcdcee0) at /data/src/10.4/storage/maria/ma_pagecache.c:4831
#8  0x000055651218b305 in ma_checkpoint_background (arg=0x1e) at /data/src/10.4/storage/maria/ma_checkpoint.c:668
#9  0x00007f31a340b6db in start_thread (arg=0x7f318dcdd700) at pthread_create.c:463
#10 0x00007f31a27f588f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Given that it's a single occurrence in tests which run dozens times a day every day, it appears to be a very rare event, and creating a reproducible test case is going to be difficult. However, it proves that the problem definitely still exists in apparently all versions.

Comment by Elena Stepanova [ 2019-10-15 ]

I have finally got what can count as a reproducer. It is not a very good one, as it takes long time, but it currently triggers the failure on all of 5.5-10.5 branches, debug, ASAN, non-debug. Examples of stack traces are below, they can vary a bit.

To reproduce:

git clone https://github.com/MariaDB/randgen --branch mdev15256 rqg-mdev15256
cd rqg-mdev15256
perl runall-trials.pl --basedir=<your basedir> --output="flush_cached_blocks" --trials=5 --grammar=./mdev15256.yy --duration=1200 --threads=1 --seed=1 --engine=Aria --skip-gendata --gendata-advanced --mysqld=--aria-checkpoint-interval=5 --vardir=/dev/shm/vardir_mdev15256

Remember to set the correct basedir and adjust vardir if necessary.
Expect the test to take a long time. The command line above runs 5 attempts (set in trials option), 20 min long each (set in duration option). It usually fails for me within 1-3 attempts, but it can vary on different machines and builds.

Stack traces (all from Debian 9 with gcc 6.3.0-18+deb9u1):

10.2 debug+ASAN 13535b27

ASAN:DEADLYSIGNAL
=================================================================
==7478==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000050 (pc 0x55676af01fed bp 0x7f0497379750 sp 0x7f0497379740 T28)
    #0 0x55676af01fec in cmp_sec_link /data/src/10.2/storage/maria/ma_pagecache.c:4321
    #1 0x7f04c302dd20  (/lib/x86_64-linux-gnu/libc.so.6+0x34d20)
    #2 0x7f04c302da97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #3 0x7f04c302da81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #4 0x7f04c302da81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #5 0x7f04c302da97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #6 0x7f04c302da97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #7 0x7f04c302da97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #8 0x7f04c302da97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #9 0x7f04c302dfde in qsort_r (/lib/x86_64-linux-gnu/libc.so.6+0x34fde)
    #10 0x55676af0222c in flush_cached_blocks /data/src/10.2/storage/maria/ma_pagecache.c:4364
    #11 0x55676af0439c in flush_pagecache_blocks_int /data/src/10.2/storage/maria/ma_pagecache.c:4715
    #12 0x55676af04b9b in flush_pagecache_blocks_with_filter /data/src/10.2/storage/maria/ma_pagecache.c:4832
    #13 0x55676af08b6c in ma_checkpoint_background /data/src/10.2/storage/maria/ma_checkpoint.c:670
    #14 0x7f04c4b9a4a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
    #15 0x7f04c30e1d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /data/src/10.2/storage/maria/ma_pagecache.c:4321 in cmp_sec_link
Thread T28 created by T0 here:
    #0 0x7f04c4de0f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
    #1 0x55676b33d177 in spawn_thread_noop /data/src/10.2/mysys/psi_noop.c:187
    #2 0x55676af06e35 in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1239
    #3 0x55676af07e97 in ma_checkpoint_init /data/src/10.2/storage/maria/ma_checkpoint.c:337
    #4 0x55676aeac042 in ha_maria_init /data/src/10.2/storage/maria/ha_maria.cc:3619
    #5 0x55676a28db72 in ha_initialize_handlerton(st_plugin_int*) /data/src/10.2/sql/handler.cc:555
    #6 0x556769ce3cbc in plugin_initialize /data/src/10.2/sql/sql_plugin.cc:1417
    #7 0x556769ce540f in plugin_init(int*, char**, int) /data/src/10.2/sql/sql_plugin.cc:1698
    #8 0x556769abc27c in init_server_components /data/src/10.2/sql/mysqld.cc:5333
    #9 0x556769abdfc1 in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:5929
    #10 0x556769aa97df in main /data/src/10.2/sql/main.cc:25
    #11 0x7f04c30192e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
 
==7478==ABORTING

10.1 debug+ASAN adefaeff

ASAN:DEADLYSIGNAL
=================================================================
==20598==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000010 (pc 0x5586fd9390b0 bp 0x7fc9bd27a990 sp 0x7fc9bd27a810 T2)
    #0 0x5586fd9390af in make_lock_and_pin /data/src/10.1/storage/maria/ma_pagecache.c:2599
    #1 0x5586fd93cee8 in flush_cached_blocks /data/src/10.1/storage/maria/ma_pagecache.c:4409
    #2 0x5586fd93e5ca in flush_pagecache_blocks_int /data/src/10.1/storage/maria/ma_pagecache.c:4727
    #3 0x5586fd949853 in flush_pagecache_blocks_with_filter /data/src/10.1/storage/maria/ma_pagecache.c:4844
    #4 0x5586fd94ee4e in ma_checkpoint_background /data/src/10.1/storage/maria/ma_checkpoint.c:669
    #5 0x7fc9d23534a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
    #6 0x7fc9d0d69d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /data/src/10.1/storage/maria/ma_pagecache.c:2599 in make_lock_and_pin
Thread T2 created by T0 here:
    #0 0x7fc9d2599f59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
    #1 0x5586fe256285 in spawn_thread_noop /data/src/10.1/mysys/psi_noop.c:187
 
==20598==ABORTING

5.5. debug+ASAN db9a4d92

SAN:DEADLYSIGNAL
=================================================================
==4728==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000048 (pc 0x558e6f238a12 bp 0x000000000001 sp 0x7f92de7fa4f0 T2)
    #0 0x558e6f238a11 in cmp_sec_link /data/src/5.5/storage/maria/ma_pagecache.c:4303
    #1 0x7f92e1589d20  (/lib/x86_64-linux-gnu/libc.so.6+0x34d20)
    #2 0x7f92e1589a97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #3 0x7f92e1589a97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #4 0x7f92e1589a97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #5 0x7f92e1589a81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #6 0x7f92e1589a81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #7 0x7f92e1589a97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #8 0x7f92e1589a97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #9 0x7f92e1589a81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #10 0x7f92e1589fde in qsort_r (/lib/x86_64-linux-gnu/libc.so.6+0x34fde)
    #11 0x558e6f24673a in flush_cached_blocks /data/src/5.5/storage/maria/ma_pagecache.c:4346
    #12 0x558e6f24837a in flush_pagecache_blocks_int /data/src/5.5/storage/maria/ma_pagecache.c:4690
    #13 0x558e6f254241 in flush_pagecache_blocks_with_filter /data/src/5.5/storage/maria/ma_pagecache.c:4806
    #14 0x558e6f25a1d4 in ma_checkpoint_background /data/src/5.5/storage/maria/ma_checkpoint.c:665
    #15 0x7f92e2c274a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
    #16 0x7f92e163dd0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /data/src/5.5/storage/maria/ma_pagecache.c:4303 in cmp_sec_link
Thread T2 created by T0 here:
    #0 0x7f92e2e6df59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
    #1 0x558e6f25a539 in inline_mysql_thread_create /data/src/5.5/include/mysql/psi/mysql_thread.h:1063
    #2 0x558e6f25a539 in ma_checkpoint_init /data/src/5.5/storage/maria/ma_checkpoint.c:336

10.5 debug+ASAN fa843790

ASAN:DEADLYSIGNAL
=================================================================
==24067==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000060 (pc 0x5597336b3a36 bp 0x7fdb1c1fa6e0 sp 0x7fdb1c1fa6d0 T2)
    #0 0x5597336b3a35 in cmp_sec_link /data/src/10.5/storage/maria/ma_pagecache.c:4641
    #1 0x7fdb2f95ad20  (/lib/x86_64-linux-gnu/libc.so.6+0x34d20)
    #2 0x7fdb2f95aa81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #3 0x7fdb2f95aa81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #4 0x7fdb2f95aa97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #5 0x7fdb2f95aa81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #6 0x7fdb2f95aa81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #7 0x7fdb2f95aa97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #8 0x7fdb2f95aa81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #9 0x7fdb2f95aa97  (/lib/x86_64-linux-gnu/libc.so.6+0x34a97)
    #10 0x7fdb2f95afde in qsort_r (/lib/x86_64-linux-gnu/libc.so.6+0x34fde)
    #11 0x5597336b3ce7 in flush_cached_blocks /data/src/10.5/storage/maria/ma_pagecache.c:4684
    #12 0x5597336b60a6 in flush_pagecache_blocks_int /data/src/10.5/storage/maria/ma_pagecache.c:5035
    #13 0x5597336b68de in flush_pagecache_blocks_with_filter /data/src/10.5/storage/maria/ma_pagecache.c:5150
    #14 0x5597336bac93 in ma_checkpoint_background /data/src/10.5/storage/maria/ma_checkpoint.c:668
    #15 0x7fdb314c74a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
    #16 0x7fdb2fa0ed0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /data/src/10.5/storage/maria/ma_pagecache.c:4641 in cmp_sec_link
Thread T2 created by T0 here:
    #0 0x7fdb3170df59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
    #1 0x559734335e25 in spawn_thread_noop /data/src/10.5/mysys/psi_noop.c:187
    #2 0x5597336b8e8f in inline_mysql_thread_create /data/src/10.5/include/mysql/psi/mysql_thread.h:1268
    #3 0x5597336b9f67 in ma_checkpoint_init /data/src/10.5/storage/maria/ma_checkpoint.c:337
    #4 0x55973364edb5 in ha_maria_init /data/src/10.5/storage/maria/ha_maria.cc:3652
    #5 0x55973309b58a in ha_initialize_handlerton(st_plugin_int*) /data/src/10.5/sql/handler.cc:550
    #6 0x55973299fab6 in plugin_initialize /data/src/10.5/sql/sql_plugin.cc:1450
    #7 0x5597329a13ec in plugin_init(int*, char**, int) /data/src/10.5/sql/sql_plugin.cc:1732
    #8 0x5597326c8200 in init_server_components /data/src/10.5/sql/mysqld.cc:5027
    #9 0x5597326ca173 in mysqld_main(int, char**) /data/src/10.5/sql/mysqld.cc:5556
    #10 0x5597326b54ef in main /data/src/10.5/sql/main.cc:25
    #11 0x7fdb2f9462e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
 
==24067==ABORTING

10.4 debug+ASAN 899c843f

ASAN:DEADLYSIGNAL
=================================================================
==25387==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000050 (pc 0x5601ee946611 bp 0x7fb2326f9910 sp 0x7fb2326f9900 T2)
    #0 0x5601ee946610 in cmp_sec_link /data/src/10.4/storage/maria/ma_pagecache.c:4321
    #1 0x7fb245eccd20  (/lib/x86_64-linux-gnu/libc.so.6+0x34d20)
    #2 0x7fb245ecca81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #3 0x7fb245ecca81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #4 0x7fb245ecca81  (/lib/x86_64-linux-gnu/libc.so.6+0x34a81)
    #5 0x7fb245eccfde in qsort_r (/lib/x86_64-linux-gnu/libc.so.6+0x34fde)
    #6 0x5601ee9468c2 in flush_cached_blocks /data/src/10.4/storage/maria/ma_pagecache.c:4364
    #7 0x5601ee948c49 in flush_pagecache_blocks_int /data/src/10.4/storage/maria/ma_pagecache.c:4715
    #8 0x5601ee949477 in flush_pagecache_blocks_with_filter /data/src/10.4/storage/maria/ma_pagecache.c:4830
    #9 0x5601ee94d7bb in ma_checkpoint_background /data/src/10.4/storage/maria/ma_checkpoint.c:668
    #10 0x7fb247a394a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
    #11 0x7fb245f80d0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
 
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV /data/src/10.4/storage/maria/ma_pagecache.c:4321 in cmp_sec_link
Thread T2 created by T0 here:
    #0 0x7fb247c7ff59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
    #1 0x5601eedcc406 in spawn_thread_noop /data/src/10.4/mysys/psi_noop.c:187
    #2 0x5601ee94b9b7 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
    #3 0x5601ee94ca8f in ma_checkpoint_init /data/src/10.4/storage/maria/ma_checkpoint.c:337
    #4 0x5601ee8e4f3f in ha_maria_init /data/src/10.4/storage/maria/ha_maria.cc:3627
    #5 0x5601edbfe875 in ha_initialize_handlerton(st_plugin_int*) /data/src/10.4/sql/handler.cc:557
    #6 0x5601ed4d31b0 in plugin_initialize /data/src/10.4/sql/sql_plugin.cc:1438
    #7 0x5601ed4d4ae6 in plugin_init(int*, char**, int) /data/src/10.4/sql/sql_plugin.cc:1720
    #8 0x5601ed1fc024 in init_server_components /data/src/10.4/sql/mysqld.cc:5198
    #9 0x5601ed1fde6a in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:5721
    #10 0x5601ed1e88ef in main /data/src/10.4/sql/main.cc:25
    #11 0x7fb245eb82e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
 
==25387==ABORTING

10.4 debug 899c843f

#3  <signal handler called>
#4  0x0000558dd836a0e3 in cmp_sec_link (a=0x7f134c015d00, b=0x7f134c015d08) at /data/src/10.4/storage/maria/ma_pagecache.c:4321
#5  0x00007f13657c9d21 in msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015d00, n=2) at msort.c:83
#6  0x00007f13657c9a82 in msort_with_tmp (n=2, b=0x7f134c015d00, p=0x7f1364821da0) at msort.c:45
#7  msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015d00, n=5) at msort.c:53
#8  0x00007f13657c9a82 in msort_with_tmp (n=5, b=0x7f134c015d00, p=0x7f1364821da0) at msort.c:45
#9  msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015d00, n=10) at msort.c:53
#10 0x00007f13657c9a98 in msort_with_tmp (n=10, b=0x7f134c015d00, p=0x7f1364821da0) at msort.c:45
#11 msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015cb0, n=20) at msort.c:54
#12 0x00007f13657c9a98 in msort_with_tmp (n=20, b=0x7f134c015cb0, p=0x7f1364821da0) at msort.c:45
#13 msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015c18, n=39) at msort.c:54
#14 0x00007f13657c9a82 in msort_with_tmp (n=39, b=0x7f134c015c18, p=0x7f1364821da0) at msort.c:45
#15 msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015c18, n=79) at msort.c:53
#16 0x00007f13657c9a82 in msort_with_tmp (n=79, b=0x7f134c015c18, p=0x7f1364821da0) at msort.c:45
#17 msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015c18, n=158) at msort.c:53
#18 0x00007f13657c9a98 in msort_with_tmp (n=158, b=0x7f134c015c18, p=0x7f1364821da0) at msort.c:45
#19 msort_with_tmp (p=0x7f1364821da0, b=0x7f134c015730, n=315) at msort.c:54
#20 0x00007f13657c9a98 in msort_with_tmp (n=315, b=0x7f134c015730, p=0x7f1364821da0) at msort.c:45
#21 msort_with_tmp (p=0x7f1364821da0, b=0x7f134c014d60, n=629) at msort.c:54
#22 0x00007f13657c9fdf in msort_with_tmp (n=629, b=0x7f134c014d60, p=0x7f1364821da0) at msort.c:45
#23 __GI___qsort_r (b=0x7f134c014d60, n=629, s=8, cmp=0x558dd836a0cc <cmp_sec_link>, arg=0x0) at msort.c:297
#24 0x0000558dd836a1d7 in flush_cached_blocks (pagecache=0x558dd9b40a00 <maria_pagecache_var>, file=0x7f134c014730, cache=0x7f134c014d60, end=0x7f134c016108, type=FLUSH_KEEP_LAZY, first_errno=0x7f1364821ee4) at /data/src/10.4/storage/maria/ma_pagecache.c:4364
#25 0x0000558dd836b1a3 in flush_pagecache_blocks_int (pagecache=0x558dd9b40a00 <maria_pagecache_var>, file=0x7f134c014730, type=FLUSH_KEEP_LAZY, filter=0x558dd836d16a <filter_flush_file_evenly>, filter_arg=0x7f1364825f00) at /data/src/10.4/storage/maria/ma_pagecache.c:4715
#26 0x0000558dd836b5f3 in flush_pagecache_blocks_with_filter (pagecache=0x558dd9b40a00 <maria_pagecache_var>, file=0x7f134c014730, type=FLUSH_KEEP_LAZY, filter=0x558dd836d16a <filter_flush_file_evenly>, filter_arg=0x7f1364825f00) at /data/src/10.4/storage/maria/ma_pagecache.c:4830
#27 0x0000558dd836d452 in ma_checkpoint_background (arg=0x5) at /data/src/10.4/storage/maria/ma_checkpoint.c:668
#28 0x00007f13673364a4 in start_thread (arg=0x7f1364826700) at pthread_create.c:456
#29 0x00007f136587dd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

10.4 release 899c843f

#3  <signal handler called>
#4  0x000055cb95801652 in cmp_sec_link (a=0x7f109c0026c0, b=0x7f109c0026c8) at /data/src/10.4/storage/maria/ma_pagecache.c:4321
#5  0x00007f10b6fc6d21 in msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c0026c0, n=2) at msort.c:83
#6  0x00007f10b6fc6a82 in msort_with_tmp (n=2, b=0x7f109c0026c0, p=0x7f10b48fcd70) at msort.c:45
#7  msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c0026c0, n=5) at msort.c:53
#8  0x00007f10b6fc6a98 in msort_with_tmp (n=5, b=0x7f109c0026c0, p=0x7f10b48fcd70) at msort.c:45
#9  msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c002698, n=10) at msort.c:54
#10 0x00007f10b6fc6a82 in msort_with_tmp (n=10, b=0x7f109c002698, p=0x7f10b48fcd70) at msort.c:45
#11 msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c002698, n=20) at msort.c:53
#12 0x00007f10b6fc6a82 in msort_with_tmp (n=20, b=0x7f109c002698, p=0x7f10b48fcd70) at msort.c:45
#13 msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c002698, n=40) at msort.c:53
#14 0x00007f10b6fc6a98 in msort_with_tmp (n=40, b=0x7f109c002698, p=0x7f10b48fcd70) at msort.c:45
#15 msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c002560, n=79) at msort.c:54
#16 0x00007f10b6fc6a98 in msort_with_tmp (n=79, b=0x7f109c002560, p=0x7f10b48fcd70) at msort.c:45
#17 msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c0022f0, n=157) at msort.c:54
#18 0x00007f10b6fc6a82 in msort_with_tmp (n=157, b=0x7f109c0022f0, p=0x7f10b48fcd70) at msort.c:45
#19 msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c0022f0, n=315) at msort.c:53
#20 0x00007f10b6fc6a98 in msort_with_tmp (n=315, b=0x7f109c0022f0, p=0x7f10b48fcd70) at msort.c:45
#21 msort_with_tmp (p=0x7f10b48fcd70, b=0x7f109c001918, n=630) at msort.c:54
#22 0x00007f10b6fc6fdf in msort_with_tmp (n=630, b=0x7f109c001918, p=0x7f10b48fcd70) at msort.c:45
#23 __GI___qsort_r (b=b@entry=0x7f109c001918, n=n@entry=630, s=s@entry=8, cmp=cmp@entry=0x55cb95801640 <cmp_sec_link>, arg=arg@entry=0x0) at msort.c:297
#24 0x00007f10b6fc7088 in __GI_qsort (b=b@entry=0x7f109c001918, n=n@entry=630, s=s@entry=8, cmp=cmp@entry=0x55cb95801640 <cmp_sec_link>) at msort.c:308
#25 0x000055cb9580267f in flush_cached_blocks (pagecache=pagecache@entry=0x55cb96bb82a0 <maria_pagecache_var>, file=file@entry=0x7f109c000d98, cache=cache@entry=0x7f109c001918, end=end@entry=0x7f109c002cc8, type=type@entry=FLUSH_KEEP_LAZY, first_errno=first_errno@entry=0x7f10b48fcef4) at /data/src/10.4/storage/maria/ma_pagecache.c:4364
#26 0x000055cb95802e05 in flush_pagecache_blocks_int (pagecache=pagecache@entry=0x55cb96bb82a0 <maria_pagecache_var>, file=file@entry=0x7f109c000d98, type=type@entry=FLUSH_KEEP_LAZY, filter=filter@entry=0x55cb95806900 <filter_flush_file_evenly>, filter_arg=filter_arg@entry=0x7f10b4900ed0) at /data/src/10.4/storage/maria/ma_pagecache.c:4715
#27 0x000055cb958063df in flush_pagecache_blocks_with_filter (pagecache=0x55cb96bb82a0 <maria_pagecache_var>, file=file@entry=0x7f109c000d98, type=type@entry=FLUSH_KEEP_LAZY, filter=filter@entry=0x55cb95806900 <filter_flush_file_evenly>, filter_arg=filter_arg@entry=0x7f10b4900ed0) at /data/src/10.4/storage/maria/ma_pagecache.c:4830
#28 0x000055cb95807c94 in ma_checkpoint_background (arg=0x5) at /data/src/10.4/storage/maria/ma_checkpoint.c:668
#29 0x00007f10b8b334a4 in start_thread (arg=0x7f10b4901700) at pthread_create.c:456
#30 0x00007f10b707ad0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Comment by Alice Sherepa [ 2022-01-25 ]

still reproducible

230321 10:56:51 [ERROR] mysqld got signal 11 ;
 
Server version: 11.0.1-MariaDB-debug-log source revision: f9b33ac570337be320f718d52fd88d301a2bc1e7
 
sql/signal_handler.cc:238(handle_fatal_signal)[0x55c15e8985bc]
??:0(__restore_rt)[0x7fc4ff831730]
maria/ma_pagecache.c:2665(make_lock_and_pin)[0x55c15eedad80]
maria/ma_pagecache.c:4803(flush_cached_blocks)[0x55c15eee7ad0]
maria/ma_pagecache.c:5121(flush_pagecache_blocks_int)[0x55c15eee9921]
maria/ma_pagecache.c:5236(flush_pagecache_blocks_with_filter)[0x55c15eeea33a]
maria/ma_checkpoint.c:687(ma_checkpoint_background)[0x55c15eeee889]
nptl/pthread_create.c:487(start_thread)[0x7fc4ff826fa3]
x86_64/clone.S:97(clone)[0x7fc4ff43006f]

Generated at Thu Feb 08 08:19:53 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.