[MDEV-12679] purge_sys_t::~purge_sys_t(): Assertion `latch.magic_n == 0' failed on --bootstrap (CMAKE_BUILD_TYPE=Debug) Created: 2017-05-04  Updated: 2017-05-16  Resolved: 2017-05-10

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.5
Fix Version/s: 10.2.6

Type: Bug Priority: Major
Reporter: Daniel Black Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: debug, powerpc
Environment:

Ubuntu-16.04, Power8, TYPE=Debug



 Description   

10.2 at commit ce8ee7d90b4f7dd784e1d7587093e671b35303f0

When compiled on Power with CMAKE_BUILD_TYPE=Debug, this fails on all test instigations.

 cmake ../mariadb-10.2 -DCMAKE_BUILD_TYPE=Debug  -DCMAKE_C_COMPILER=/opt/at10.0/bin/gcc -DCMAKE_CXX_COMPILER=/opt/at10.0/bin/g++ '-DCMAKE_C_FLAGS_RELWITHDEBINFO=-m64 -O3 -g -mtune=native' '-DCMAKE_CXX_FLAGS_RELWITHDEBINFO=-m64 -O3 -g -mtune=native' '-DCMAKE_C_FLAGS=-m64 -O3 -g -mtune=native' '-DCMAKE_CXX_FLAGS=-m64 -O3 -g -mtune=native' -DWITH_SSL=system -DCMAKE_INSTALL_PREFIX=/mysql/mariadb-upstream-Debug-10.0-at10.0-rc1  -DCMAKE_C_COMPILER_LAUNCHER=ccache -DCMAKE_CXX_COMPILER_LAUNCHER=ccache -DWITHOUT_FEDERATED_STORAGE_ENGINE=1 -DWITHOUT_FEDERATEDX_STORAGE_ENGINE=1 -DWITHOUT_TOKUDB_STORAGE_ENGINE=1

Same assertion fail with gcc-5 and gcc-6

$ gcc-5 --version
gcc-5 (Ubuntu/IBM 5.4.0-6ubuntu1~16.04.4) 5.4.0 20160609
$ gcc-6 --version
gcc-6 (Ubuntu 6.3.0-12ubuntu1.1) 6.3.0 20170406

(cd mysql-test/; ./mtr )
 
2017-05-04 12:44:40 70367348770832 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2017-05-04 12:44:40 70367348770832 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
mysqld: /home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc:235: purge_sys_t::~purge_sys_t(): Assertion `latch.magic_n == 0' failed.
170504 12:44:42 [ERROR] mysqld got signal 6 ;
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.2.6-MariaDB-debug
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467287 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 0x49000
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(my_print_stacktrace+0x60)[0x457f4f60]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(handle_fatal_signal+0x440)[0x44fc76e0]
[0x3fffaccc04d8]
/lib/powerpc64le-linux-gnu/libc.so.6(gsignal+0x40)[0x3fffac19edb0]
/lib/powerpc64le-linux-gnu/libc.so.6(abort+0x2b4)[0x3fffac1a1314]
/lib/powerpc64le-linux-gnu/libc.so.6(+0x34290)[0x3fffac194290]
/lib/powerpc64le-linux-gnu/libc.so.6(__assert_fail+0x64)[0x3fffac194384]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(+0xbb9d64)[0x453f9d64]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(+0xb90318)[0x453d0318]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(+0x9cb8ec)[0x4520b8ec]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(_Z22ha_finalize_handlertonP13st_plugin_int+0x8c)[0x44fcb61c]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(+0x54c4cc)[0x44d8c4cc]
mysys/stacktrace.c:267(my_print_stacktrace)[0x44d94728]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(_Z15plugin_shutdownv+0x5b4)[0x44d95de4]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(+0x45fb60)[0x44c9fb60]
trx/trx0purge.cc:235(purge_sys_t::~purge_sys_t())[0x44ca3890]
/home/danielgb/build-mariadb-10.2-gcc/sql/mysqld(_Z11mysqld_mainiPPc+0x10b8)[0x44cadb58]
srv/srv0start.cc:2834(innodb_shutdown())[0x44c827e8]
/lib/powerpc64le-linux-gnu/libc.so.6(+0x2309c)[0x3fffac18309c]
/lib/powerpc64le-linux-gnu/libc.so.6(__libc_start_main+0xb8)[0x3fffac183298]
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.
Writing a core file

mysqld: /home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc:235: purge_sys_t::~purge_sys_t(): Assertion `latch.magic_n == 0' failed.
 
Thread 1 "mysqld" received signal SIGABRT, Aborted.
0x00003fffb745edb0 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:54
54      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  0x00003fffb745edb0 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00003fffb7461270 in __GI_abort () at abort.c:89
#2  0x00003fffb7454290 in __assert_fail_base (fmt=<optimized out>, assertion=0x211bb570 "latch.magic_n == 0", 
    file=0x211bb500 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", line=<optimized out>, function=<optimized out>) at assert.c:92
#3  0x00003fffb7454384 in __GI___assert_fail (assertion=0x211bb570 "latch.magic_n == 0", file=0x211bb500 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", 
    line=<optimized out>, function=0x211bab40 <purge_sys_t::~purge_sys_t()::__PRETTY_FUNCTION__> "purge_sys_t::~purge_sys_t()") at assert.c:101
#4  0x0000000020bb9d64 in purge_sys_t::~purge_sys_t (this=<optimized out>, __in_chrg=<optimized out>) at /home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc:235
#5  0x0000000020b90318 in innodb_shutdown () at /home/danielgb/mariadb-10.2/storage/innobase/srv/srv0start.cc:2834
#6  0x00000000209cb8ec in innobase_end (hton=<optimized out>, type=<optimized out>) at /home/danielgb/mariadb-10.2/storage/innobase/handler/ha_innodb.cc:4593
#7  0x000000002078b61c in ha_finalize_handlerton (plugin=0x22103328) at /home/danielgb/mariadb-10.2/sql/handler.cc:451
#8  0x000000002054c4cc in plugin_deinitialize (plugin=0x22103328, ref_check=true) at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1209
#9  0x0000000020554728 in reap_plugins () at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1286
#10 0x0000000020555de4 in plugin_shutdown () at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1938
#11 0x000000002045fb60 in clean_up (print_message=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:2201
#12 0x0000000020463890 in unireg_abort (exit_code=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:2120
#13 0x000000002046db58 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:5947
#14 0x00000000204427e8 in main (argc=<optimized out>, argv=<optimized out>) at /home/danielgb/mariadb-10.2/sql/main.cc:25



 Comments   
Comment by Marko Mäkelä [ 2017-05-05 ]

This could be related to a WITH_ASAN failure that I am now seeing in 10.2 after merging MDEV-12253 from 10.1:

==5226==ERROR: AddressSanitizer: attempting free on address which was not malloc()-ed: 0x612000018588 in thread T0
    #0 0x736750 in operator delete(void*) (/mariadb/server/build/sql/mysqld+0x736750)
    #1 0x1e4833f in LatchCounter::~LatchCounter() /mariadb/server/storage/innobase/include/sync0types.h:599:4
    #2 0x1e480b8 in LatchMeta<LatchCounter>::~LatchMeta() /mariadb/server/storage/innobase/include/sync0types.h:786:17
    #3 0x1e35509 in sync_latch_meta_destroy() /mariadb/server/storage/innobase/sync/sync0debug.cc:1622:3
    #4 0x1e35314 in sync_check_close() /mariadb/server/storage/innobase/sync/sync0debug.cc:1839:2
    #5 0x1dfdc18 in innodb_shutdown() /mariadb/server/storage/innobase/srv/srv0start.cc:2888:2
    #6 0x197e5e6 in innobase_init(void*) /mariadb/server/storage/innobase/handler/ha_innodb.cc:4475:3

Comment by Marko Mäkelä [ 2017-05-09 ]

I fixed the WITH_ASAN failure mentioned above. It should not be related to this one.

Comment by Marko Mäkelä [ 2017-05-09 ]

danblack, can you please show the output of the following GDB commands:

print *purge_sys
thread apply all backtrace

The assertion is not expected to fail. It is trying to make the code compatible with the (in my opinion) clumsy design of rw_lock_free():

	rw_lock_free(&latch);
	/* rw_lock_free() already called latch.~rw_lock_t(); tame the
	debug assertions when the destructor will be called once more. */
	ut_ad(latch.magic_n == 0);
	ut_d(latch.magic_n = RW_LOCK_MAGIC_N);

Comment by Daniel Black [ 2017-05-10 ]

10.2 at 2980b0c348b1964b6efcadeba1082e02c2f5b45b

Starting program: /home/danielgb/build-mariadb-10.2-gcc/sql/mysqld --no-defaults --bootstrap --basedir=/home/danielgb/mariadb-10.2 --datadir=/home/danielgb/build-mariadb-10.2-gcc/mysql-test/var/install.db --default-storage-engine=myisam --skip-plugin-aria --skip-plugin-feedback --skip-plugin-innodb --skip-plugin-innodb-buffer-page --skip-plugin-innodb-buffer-page-lru --skip-plugin-innodb-buffer-pool-stats --skip-plugin-innodb-cmp --skip-plugin-innodb-cmp-per-index --skip-plugin-innodb-cmp-per-index-reset --skip-plugin-innodb-cmp-reset --skip-plugin-innodb-cmpmem --skip-plugin-innodb-cmpmem-reset --skip-plugin-innodb-ft-being-deleted --skip-plugin-innodb-ft-config --skip-plugin-innodb-ft-default-stopword --skip-plugin-innodb-ft-deleted --skip-plugin-innodb-ft-index-cache --skip-plugin-innodb-ft-index-table --skip-plugin-innodb-lock-waits --skip-plugin-innodb-locks --skip-plugin-innodb-metrics --skip-plugin-innodb-mutexes --skip-plugin-innodb-sys-columns --skip-plugin-innodb-sys-datafiles --skip-plugin-innodb-sys-fields --skip-plugin-innodb-sys-foreign --skip-plugin-innodb-sys-foreign-cols --skip-plugin-innodb-sys-indexes --skip-plugin-innodb-sys-semaphore-waits --skip-plugin-innodb-sys-tables --skip-plugin-innodb-sys-tablespaces --skip-plugin-innodb-sys-tablestats --skip-plugin-innodb-sys-virtual --skip-plugin-innodb-tablespaces-encryption --skip-plugin-innodb-tablespaces-scrubbing --skip-plugin-innodb-trx --skip-plugin-partition --skip-plugin-sequence --loose-innodb --loose-innodb-log-file-size=5M --disable-sync-frm --tmpdir=/home/danielgb/build-mariadb-10.2-gcc/mysql-test/var/tmp/ --core-file --lc-messages-dir=/home/danielgb/build-mariadb-10.2-gcc/sql/share/ --character-sets-dir=/home/danielgb/mariadb-10.2/sql/share/charsets < /home/danielgb/build-mariadb-10.2-gcc/mysql-test/var/tmp/bootstrap.sql
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/powerpc64le-linux-gnu/libthread_db.so.1".
warning: File "/usr/share/gdb/auto-load/usr/lib/powerpc64le-linux-gnu/libstdc++.so.6.0.23-gdb.py" auto-loading has been declined by your `auto-load safe-path' set to "/opt/*".
To enable execution of this file add
        add-auto-load-safe-path /usr/share/gdb/auto-load/usr/lib/powerpc64le-linux-gnu/libstdc++.so.6.0.23-gdb.py
line to your configuration file "/home/danielgb/.gdbinit".
To completely disable this security protection add
        set auto-load safe-path /
line to your configuration file "/home/danielgb/.gdbinit".
For more information about this security protection see the
"Auto-loading safe path" section in the GDB manual.  E.g., run from the shell:
        info "(gdb)Auto-loading safe path"
2017-05-10 12:56:56 70367536203824 [Note] /home/danielgb/build-mariadb-10.2-gcc/sql/mysqld (mysqld 10.2.6-MariaDB-debug) starting as process 76388 ...
2017-05-10 12:56:56 70367536203824 [Warning] Changed limits: max_open_files: 1024  max_connections: 151  table_cache: 431
[New Thread 0x3fffb714f000 (LWP 76391)]
2017-05-10 12:56:56 70367536203824 [Note] Plugin 'SEQUENCE' is disabled.
2017-05-10 12:56:56 70367536203824 [Note] Plugin 'partition' is disabled.
2017-05-10 12:56:56 70367536203824 [Note] Using unique option prefix 'plugin-innodb-cmp' is error-prone and can break in the future. Please use the full name 'plugin-innodb-cmp-per-index-enabled' instead.
2017-05-10 12:56:56 70367536203824 [Note] Using unique option prefix 'plugin-innodb-cmp-per-index' is error-prone and can break in the future. Please use the full name 'plugin-innodb-cmp-per-index-enabled' instead.
2017-05-10 12:56:56 70367536203824 [Note] Using unique option prefix 'plugin-innodb-locks' is error-prone and can break in the future. Please use the full name 'plugin-innodb-locks-unsafe-for-binlog' instead.
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Uses event mutexes
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Using Linux native AIO
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Number of pools: 1
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Using POWER8 crc32 instructions
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Completed initialization of buffer pool
[New Thread 0x3fff9f0df000 (LWP 76392)]
[New Thread 0x3fff9e8df000 (LWP 76393)]
[New Thread 0x3fff9e0df000 (LWP 76394)]
[New Thread 0x3fff9d8df000 (LWP 76395)]
[New Thread 0x3fff9d0df000 (LWP 76396)]
[New Thread 0x3fff9c8df000 (LWP 76397)]
[New Thread 0x3fff9c0df000 (LWP 76398)]
[New Thread 0x3fff9b8df000 (LWP 76399)]
[New Thread 0x3fff9b0df000 (LWP 76400)]
[New Thread 0x3fff9a8df000 (LWP 76401)]
[New Thread 0x3fff9a0df000 (LWP 76402)]
2017-05-10 12:56:56 70367033815040 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: The first innodb_system data file 'ibdata1' did not exist. A new tablespace will be created!
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Setting file './ibdata1' size to 12 MB. Physically writing the file full; Please wait ...
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: File './ibdata1' size is now 12 MB.
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Setting log file ./ib_logfile101 size to 5 MB
2017-05-10 12:56:56 70367536203824 [Note] InnoDB: Setting log file ./ib_logfile1 size to 5 MB
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: New log files created, LSN=45892
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Doublewrite buffer not found: creating new
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Doublewrite buffer created
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: 128 out of 128 rollback segments are active.
[New Thread 0x3fff998df000 (LWP 76403)]
[New Thread 0x3fff990df000 (LWP 76404)]
[New Thread 0x3fff988df000 (LWP 76405)]
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Creating foreign key constraint system tables.
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Creating tablespace and datafile system tables.
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: Creating sys_virtual system tables.
[New Thread 0x3fff93fff000 (LWP 76406)]
[New Thread 0x3fff937ff000 (LWP 76407)]
[New Thread 0x3fff92fff000 (LWP 76408)]
[New Thread 0x3fff927ff000 (LWP 76409)]
[New Thread 0x3fff91fff000 (LWP 76410)]
2017-05-10 12:56:57 70367536203824 [Note] InnoDB: 5.7.14 started; log sequence number 0
[New Thread 0x3fff917ff000 (LWP 76411)]
[New Thread 0x3fff90fff000 (LWP 76412)]
[New Thread 0x3fff907ff000 (LWP 76413)]
[New Thread 0x3fff73fff000 (LWP 76414)]
[New Thread 0x3fff737ff000 (LWP 76415)]
[New Thread 0x3fff72fff000 (LWP 76416)]
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'Aria' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Using unique option prefix 'plugin-innodb-sys-tables' is error-prone and can break in the future. Please use the full name 'plugin-innodb-sys-tablestats' instead.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Using unique option prefix 'plugin-innodb-buffer-page' is error-prone and can break in the future. Please use the full name 'plugin-innodb-buffer-page-lru' instead.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'FEEDBACK' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Using unique option prefix 'plugin-innodb-sys-foreign' is error-prone and can break in the future. Please use the full name 'plugin-innodb-sys-foreign-cols' instead.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_TRX' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_METRICS' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2017-05-10 12:56:57 70367536203824 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
[New Thread 0x3fffb4818000 (LWP 76417)]
[New Thread 0x3fffb47b8000 (LWP 76418)]
[Thread 0x3fffb47b8000 (LWP 76418) exited]
[Thread 0x3fff72fff000 (LWP 76416) exited]
[Thread 0x3fff907ff000 (LWP 76413) exited]
[Thread 0x3fff90fff000 (LWP 76412) exited]
[Thread 0x3fff988df000 (LWP 76405) exited]
[Thread 0x3fff737ff000 (LWP 76415) exited]
[Thread 0x3fff990df000 (LWP 76404) exited]
[Thread 0x3fff998df000 (LWP 76403) exited]
[Thread 0x3fff917ff000 (LWP 76411) exited]
[Thread 0x3fff927ff000 (LWP 76409) exited]
[Thread 0x3fff91fff000 (LWP 76410) exited]
[Thread 0x3fff92fff000 (LWP 76408) exited]
[Thread 0x3fff937ff000 (LWP 76407) exited]
[Thread 0x3fff73fff000 (LWP 76414) exited]
[Thread 0x3fff9a0df000 (LWP 76402) exited]
[Thread 0x3fff93fff000 (LWP 76406) exited]
[Thread 0x3fff9f0df000 (LWP 76392) exited]
[Thread 0x3fff9e0df000 (LWP 76394) exited]
[Thread 0x3fff9d8df000 (LWP 76395) exited]
[Thread 0x3fff9d0df000 (LWP 76396) exited]
[Thread 0x3fff9c8df000 (LWP 76397) exited]
[Thread 0x3fff9a8df000 (LWP 76401) exited]
[Thread 0x3fff9b8df000 (LWP 76399) exited]
[Thread 0x3fff9c0df000 (LWP 76398) exited]
[Thread 0x3fff9b0df000 (LWP 76400) exited]
[Thread 0x3fff9e8df000 (LWP 76393) exited]
mysqld: /home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc:235: purge_sys_t::~purge_sys_t(): Assertion `latch.magic_n == 0' failed.

(gdb) print *purge_sys
$1 = {sess = 0x22727620, latch = {<latch_t> = {_vptr.latch_t = 0x21662f18 <vtable for rw_lock_t+16>, m_id = LATCH_ID_TRX_PURGE, m_rw_lock = true, m_temp_fsp = false}, lock_word = 536870912, waiters = 0, 
    sx_recursive = 0, writer_is_wait_ex = false, writer_thread = 0, event = 0x0, wait_ex_event = 0x0, cfile_name = 0x211c19f0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", 
    last_s_file_name = 0x211c3eb0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0rec.cc", last_x_file_name = 0x211c19f0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", cline = 218, 
    is_block_lock = 0, last_s_line = 2118, last_x_line = 1739, count_os_wait = 0, list = {prev = 0x0, next = 0x0}, pfs_psi = 0x0, magic_n = 22643, debug_list = {count = 0, start = 0x0, end = 0x0, 
      node = &rw_lock_debug_t::list, init = 51966}, level = SYNC_PURGE_LATCH}, event = 0x22727c40, n_stop = 0, running = false, state = PURGE_STATE_EXIT, query = 0x22727f18, view = {m_low_limit_id = 797, 
    m_up_limit_id = 797, m_creator_trx_id = 18446744073709551615, m_ids = {m_ptr = 0x3fff84008830, m_size = 0, m_reserved = 32}, m_low_limit_no = 797, m_closed = false, pad1 = '\377' <repeats 48 times>, m_view_list = {
      prev = 0x0, next = 0x0}}, n_submitted = 19, n_completed = 19, iter = {trx_no = 797, undo_no = 0, undo_rseg_space = 18446744073709551615}, limit = {trx_no = 797, undo_no = 0, 
    undo_rseg_space = 18446744073709551615}, done = {trx_no = 797, undo_no = 0, undo_rseg_space = 18446744073709551615}, next_stored = false, rseg = 0x0, page_no = 325, offset = 758, hdr_page_no = 325, 
  hdr_offset = 86, rseg_iter = {m_trx_undo_rsegs = {m_trx_no = 18446744073709551615, m_rsegs = {<std::_Vector_base<trx_rseg_t*, ut_allocator<trx_rseg_t*> >> = {_M_impl = {<ut_allocator<trx_rseg_t*>> = {
              m_oom_fatal = true}, _M_start = 0x3fff84008940, _M_finish = 0x3fff84008940, _M_end_of_storage = 0x3fff84008948}}, <No data fields>}}, m_iter = {_M_current = 0x3fff84008940}, static NullElement = {
      m_trx_no = 18446744073709551615, m_rsegs = {<std::_Vector_base<trx_rseg_t*, ut_allocator<trx_rseg_t*> >> = {_M_impl = {<ut_allocator<trx_rseg_t*>> = {m_oom_fatal = true}, _M_start = 0x0, _M_finish = 0x0, 
            _M_end_of_storage = 0x0}}, <No data fields>}}}, purge_queue = {c = {<std::_Vector_base<TrxUndoRsegs, ut_allocator<TrxUndoRsegs> >> = {_M_impl = {<ut_allocator<TrxUndoRsegs>> = {m_oom_fatal = true}, 
          _M_start = 0x3fff5804cef0, _M_finish = 0x3fff5804cef0, _M_end_of_storage = 0x3fff5804cf90}}, <No data fields>}, comp = {m_trx_no = 0, 
      m_rsegs = {<std::_Vector_base<trx_rseg_t*, ut_allocator<trx_rseg_t*> >> = {_M_impl = {<ut_allocator<trx_rseg_t*>> = {m_oom_fatal = true}, _M_start = 0x0, _M_finish = 0x0, 
            _M_end_of_storage = 0x0}}, <No data fields>}}}, pq_mutex = {m_impl = {m_lock_word = 0, m_event = 0x22729380, m_policy = {<MutexDebug<TTASEventMutex<GenericPolicy> >> = {
          _vptr.MutexDebug = 0x21662b48 <vtable for GenericPolicy<TTASEventMutex<GenericPolicy> >+16>, m_magic_n = 979585, m_context = {<latch_t> = {
              _vptr.latch_t = 0x21662a80 <vtable for MutexDebug<TTASEventMutex<GenericPolicy> >::Context+16>, m_id = LATCH_ID_PURGE_SYS_PQ, m_rw_lock = false, m_temp_fsp = false}, m_mutex = 0x0, m_filename = 0x0, 
            m_line = 0, m_thread_id = 18446744073709551615}}, m_count = {m_spins = 0, m_waits = 0, m_calls = 0, m_enabled = false}, m_id = LATCH_ID_PURGE_SYS_PQ}}, m_ptr = 0x0}, undo_trunc = {
    m_undo_for_trunc = 18446744073709551615, m_rseg_for_trunc = {<std::_Vector_base<trx_rseg_t*, std::allocator<trx_rseg_t*> >> = {
        _M_impl = {<std::allocator<trx_rseg_t*>> = {<__gnu_cxx::new_allocator<trx_rseg_t*>> = {<No data fields>}, <No data fields>}, _M_start = 0x0, _M_finish = 0x0, _M_end_of_storage = 0x0}}, <No data fields>}, 
    m_scan_start = 1, m_purge_rseg_truncate_frequency = 128, static s_spaces_to_truncate = {<std::_Vector_base<unsigned long, std::allocator<unsigned long> >> = {
        _M_impl = {<std::allocator<unsigned long>> = {<__gnu_cxx::new_allocator<unsigned long>> = {<No data fields>}, <No data fields>}, _M_start = 0x0, _M_finish = 0x0, _M_end_of_storage = 0x0}}, <No data fields>}, 
    static s_fix_up_spaces = {<std::_Vector_base<unsigned long, std::allocator<unsigned long> >> = {
        _M_impl = {<std::allocator<unsigned long>> = {<__gnu_cxx::new_allocator<unsigned long>> = {<No data fields>}, <No data fields>}, _M_start = 0x0, _M_finish = 0x0, _M_end_of_storage = 0x0}}, <No data fields>}}}

Thread 28 (Thread 0x3fffb4818000 (LWP 76417)):
#0  0x00003fffb7966774 in do_sigwait (sig=0x3fffb48173fc, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:61
#1  __sigwait (set=<optimized out>, sig=0x3fffb48173fc) at ../sysdeps/unix/sysv/linux/sigwait.c:96
#2  0x0000000020460c1c in signal_hand (arg=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:3492
#3  0x00003fffb7958070 in start_thread (arg=0x3fffb4818000) at pthread_create.c:335
#4  0x00003fffb7543230 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
 
Thread 2 (Thread 0x3fffb714f000 (LWP 76391)):
#0  0x00003fffb7960614 in __pthread_cond_timedwait (cond=0x22091870 <COND_timer>, mutex=0x220917b0 <LOCK_timer+40>, abstime=0x3fffb714e568) at pthread_cond_timedwait.c:198
#1  0x0000000020fc07b0 in safe_cond_timedwait (cond=0x22091870 <COND_timer>, mp=0x22091788 <LOCK_timer>, abstime=0x3fffb714e568, file=0x21042da0 "/home/danielgb/mariadb-10.2/include/mysql/psi/mysql_thread.h", 
    line=<optimized out>) at /home/danielgb/mariadb-10.2/mysys/thr_mutex.c:545
#2  0x0000000020fc1318 in inline_mysql_cond_timedwait (that=0x22091870 <COND_timer>, mutex=0x22091788 <LOCK_timer>, src_file=0x2125fa40 "/home/danielgb/mariadb-10.2/mysys/thr_timer.c", src_line=292, 
    abstime=0x3fffb714e568) at /home/danielgb/mariadb-10.2/include/mysql/psi/mysql_thread.h:1186
#3  timer_handler (arg=<optimized out>) at /home/danielgb/mariadb-10.2/mysys/thr_timer.c:292
#4  0x00003fffb7958070 in start_thread (arg=0x3fffb714f000) at pthread_create.c:335
#5  0x00003fffb7543230 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
 
Thread 1 (Thread 0x3fffb7ffc830 (LWP 76388)):
#0  0x00003fffb745edb0 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00003fffb7461270 in __GI_abort () at abort.c:89
#2  0x00003fffb7454290 in __assert_fail_base (fmt=<optimized out>, assertion=0x211c1a60 "latch.magic_n == 0", file=0x211c19f0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", line=<optimized out>, 
    function=<optimized out>) at assert.c:92
#3  0x00003fffb7454384 in __GI___assert_fail (assertion=0x211c1a60 "latch.magic_n == 0", file=0x211c19f0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", line=<optimized out>, 
    function=0x211c1030 <purge_sys_t::~purge_sys_t()::__PRETTY_FUNCTION__> "purge_sys_t::~purge_sys_t()") at assert.c:101
#4  0x0000000020bbd504 in purge_sys_t::~purge_sys_t (this=<optimized out>, __in_chrg=<optimized out>) at /home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc:235
#5  0x0000000020b93a98 in innodb_shutdown () at /home/danielgb/mariadb-10.2/storage/innobase/srv/srv0start.cc:2839
#6  0x00000000209cdebc in innobase_end (hton=<optimized out>, type=<optimized out>) at /home/danielgb/mariadb-10.2/storage/innobase/handler/ha_innodb.cc:4626
#7  0x000000002078cdbc in ha_finalize_handlerton (plugin=0x22113328) at /home/danielgb/mariadb-10.2/sql/handler.cc:451
#8  0x000000002054dd0c in plugin_deinitialize (plugin=0x22113328, ref_check=true) at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1209
#9  0x0000000020555f68 in reap_plugins () at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1286
#10 0x0000000020557624 in plugin_shutdown () at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1944
#11 0x0000000020461400 in clean_up (print_message=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:2206
#12 0x0000000020465550 in unireg_abort (exit_code=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:2125
#13 0x000000002046f4e8 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:5959
#14 0x0000000020444098 in main (argc=<optimized out>, argv=<optimized out>) at /home/danielgb/mariadb-10.2/sql/main.cc:25

(gdb)  thread apply all backtrace full
 
Thread 28 (Thread 0x3fffb4818000 (LWP 76417)):
#0  0x00003fffb7966774 in do_sigwait (sig=0x3fffb48173fc, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:61
        r4 = 0
        r7 = 2
        arg2 = 0
        r5 = 0
        r8 = 2
        arg3 = 0
        r0 = 176
        r3 = 4
        r6 = 8
        arg4 = 8
        ret = <optimized out>
        tmpset = {__val = {0, 561937624, 70367477592976, 0, 553386552, 561210624, 0, 70367477598048, 0, 561933376, 70367477596352, 70367477593096, 70367477592976, 0, 70367529419680, 553920656}}
        err = <optimized out>
#1  __sigwait (set=<optimized out>, sig=0x3fffb48173fc) at ../sysdeps/unix/sysv/linux/sigwait.c:96
        oldtype = 0
        result = -1266584580
        sig = 0x3fffb48173fc
        set = <optimized out>
#2  0x0000000020460c1c in signal_hand (arg=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:3492
        error = <optimized out>
        set = {__val = {548869, 0 <repeats 15 times>}}
        sig = 0
        _db_stack_frame_ = {func = 0x21262188 "?func", file = 0x21262190 "?file", level = 2147483649, line = -1, prev = 0x0}
#3  0x00003fffb7958070 in start_thread (arg=0x3fffb4818000) at pthread_create.c:335
        pd = 0x3fffb4818000
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {935777734000739322, 70367529434880, 935777733949093350, 0, 561933084, 70367477235712, 364544, 70367529419664, 70367477598048, 0, 561933376, 70367477596352, 
                541460112, 70368744161048, 0, 70367529419680, 70368744161048, 70368744160424, 4001536, 70367529238400, 70367477593648, 2450033122994028543, 0 <repeats 42 times>}, mask_was_saved = 0}}, priv = {pad = {
              0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#4  0x00003fffb7543230 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
No locals.
 
Thread 2 (Thread 0x3fffb714f000 (LWP 76391)):
#0  0x00003fffb7960614 in __pthread_cond_timedwait (cond=0x22091870 <COND_timer>, mutex=0x220917b0 <LOCK_timer+40>, abstime=0x3fffb714e568) at pthread_cond_timedwait.c:198
        r4 = 393
        r7 = 0
        arg5 = 0
        arg2 = 137
        r5 = 1
        r8 = 4294967295
        arg6 = 4294967295
        arg3 = 1
        r0 = 221
        r3 = 516
        r6 = 70367520810344
        arg1 = 571021428
        __err = <optimized out>
        __ret = <optimized out>
        futex_val = 1
        buffer = {__routine = 0x3fffb795fd40 <__condvar_cleanup>, __arg = 0x3fffb714e380, __canceltype = -1223364416, __prev = 0x0}
        cbuffer = {oldtype = 0, cond = 0x22091870 <COND_timer>, mutex = 0x220917b0 <LOCK_timer+40>, bc_seq = 0}
        result = 0
        pshared = 0
        pi_flag = 0
        err = <optimized out>
        val = <optimized out>
        seq = 0
#1  0x0000000020fc07b0 in safe_cond_timedwait (cond=0x22091870 <COND_timer>, mp=0x22091788 <LOCK_timer>, abstime=0x3fffb714e568, file=0x21042da0 "/home/danielgb/mariadb-10.2/include/mysql/psi/mysql_thread.h", 
    line=<optimized out>) at /home/danielgb/mariadb-10.2/mysys/thr_mutex.c:545
        error = <optimized out>
#2  0x0000000020fc1318 in inline_mysql_cond_timedwait (that=0x22091870 <COND_timer>, mutex=0x22091788 <LOCK_timer>, src_file=0x2125fa40 "/home/danielgb/mariadb-10.2/mysys/thr_timer.c", src_line=292, 
    abstime=0x3fffb714e568) at /home/danielgb/mariadb-10.2/include/mysql/psi/mysql_thread.h:1186
        result = <optimized out>
#3  timer_handler (arg=<optimized out>) at /home/danielgb/mariadb-10.2/mysys/thr_timer.c:292
        top_time = <optimized out>
        abstime = {tv_sec = 2147483647, tv_nsec = 0}
#4  0x00003fffb7958070 in start_thread (arg=0x3fffb714f000) at pthread_create.c:335
        pd = 0x3fffb714f000
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {935777733940614138, 70367529434880, 935777733949093350, 0, 561933084, 70367512428544, 8388608, 70367529419664, 70367520814944, 0, 571035872, 70367520813248, 
                553389968, 70368744157936, 0, 70367529419680, 70368744157936, 70368744157656, 4001536, 70367529238400, 70367520810544, 2450033140173897727, 0 <repeats 42 times>}, mask_was_saved = 0}}, priv = {pad = {
              0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#5  0x00003fffb7543230 in clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
No locals.
 
Thread 1 (Thread 0x3fffb7ffc830 (LWP 76388)):
#0  0x00003fffb745edb0 in __GI_raise (sig=<optimized out>) at ../sysdeps/unix/sysv/linux/raise.c:54
        r4 = 76388
        r7 = 70367524024504
        arg2 = 76388
        r5 = 6
        r8 = 0
        arg3 = 6
        r0 = 250
        r3 = 0
        r6 = 16384
        arg1 = 0
        sc_err = <optimized out>
        sc_ret = <optimized out>
        pd = 0x3fffb7ffc830
        pid = 0
        selftid = 76388
#1  0x00003fffb7461270 in __GI_abort () at abort.c:89
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {561933084, 561933376, 561947296, 561933384, 553921952, 561921160, 70368744160888, 555968680, 561955992, 561957496, 
              562541144, 577927216, 562246112, 555487280, 555489888, 555489776}}, sa_flags = -1222377472, sa_restorer = 0x3fffffffaf30}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00003fffb7454290 in __assert_fail_base (fmt=<optimized out>, assertion=0x211c1a60 "latch.magic_n == 0", file=0x211c19f0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", line=<optimized out>, 
    function=<optimized out>) at assert.c:92
        str = 0x220e2910 ""
        total = 65536
#3  0x00003fffb7454384 in __GI___assert_fail (assertion=0x211c1a60 "latch.magic_n == 0", file=0x211c19f0 "/home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc", line=<optimized out>, 
    function=0x211c1030 <purge_sys_t::~purge_sys_t()::__PRETTY_FUNCTION__> "purge_sys_t::~purge_sys_t()") at assert.c:101
No locals.
#4  0x0000000020bbd504 in purge_sys_t::~purge_sys_t (this=<optimized out>, __in_chrg=<optimized out>) at /home/danielgb/mariadb-10.2/storage/innobase/trx/trx0purge.cc:235
No locals.
#5  0x0000000020b93a98 in innodb_shutdown () at /home/danielgb/mariadb-10.2/storage/innobase/srv/srv0start.cc:2839
        __PRETTY_FUNCTION__ = "void innodb_shutdown()"
#6  0x00000000209cdebc in innobase_end (hton=<optimized out>, type=<optimized out>) at /home/danielgb/mariadb-10.2/storage/innobase/handler/ha_innodb.cc:4626
        err = 0
        _db_stack_frame_ = {func = 0x21116c70 "ha_finalize_handlerton", file = 0x211167d0 "/home/danielgb/mariadb-10.2/sql/handler.cc", level = 2147483652, line = -1, prev = 0x3fffffffb340}
        __PRETTY_FUNCTION__ = "int innobase_end(handlerton*, ha_panic_function)"
#7  0x000000002078cdbc in ha_finalize_handlerton (plugin=0x22113328) at /home/danielgb/mariadb-10.2/sql/handler.cc:451
        hton = 0x2213f000
        _db_stack_frame_ = {func = 0x2106b638 "plugin_shutdown", file = 0x2106ac60 "/home/danielgb/mariadb-10.2/sql/sql_plugin.cc", level = 2147483651, line = -1, prev = 0x3fffffffb6f8}
        __PRETTY_FUNCTION__ = "int ha_finalize_handlerton(st_plugin_int*)"
---Type <return> to continue, or q <return> to quit---
#8  0x000000002054dd0c in plugin_deinitialize (plugin=0x22113328, ref_check=true) at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1209
        __PRETTY_FUNCTION__ = "void plugin_deinitialize(st_plugin_int*, bool)"
#9  0x0000000020555f68 in reap_plugins () at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1286
        count = <optimized out>
        plugin = <optimized out>
        reap = 0x3fffffffb4f0
        list = 0x3fffffffb480
        __PRETTY_FUNCTION__ = "void reap_plugins()"
#10 0x0000000020557624 in plugin_shutdown () at /home/danielgb/mariadb-10.2/sql/sql_plugin.cc:1944
        i = <optimized out>
        count = 51
        plugins = <optimized out>
        plugin = <optimized out>
        dl = <optimized out>
        _db_stack_frame_ = {func = 0x21043458 "unireg_abort", file = 0x21042890 "/home/danielgb/mariadb-10.2/sql/mysqld.cc", level = 2147483650, line = -1, prev = 0x3fffffffb8c0}
#11 0x0000000020461400 in clean_up (print_message=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:2206
        print_message = false
#12 0x0000000020465550 in unireg_abort (exit_code=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:2125
        _db_stack_frame_ = {func = 0x21262188 "?func", file = 0x21262190 "?file", level = 2147483649, line = -1, prev = 0x0}
#13 0x000000002046f4e8 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at /home/danielgb/mariadb-10.2/sql/mysqld.cc:5959
        ho_error = <optimized out>
#14 0x0000000020444098 in main (argc=<optimized out>, argv=<optimized out>) at /home/danielgb/mariadb-10.2/sql/main.cc:25
No locals.

Comment by Marko Mäkelä [ 2017-05-10 ]

Thanks, danblack!
Is it possible that your build is defining neither UNIV_DEBUG nor DBUG_OFF? In that case, the ut_d() would have no effect, but ut_ad() would map to assert(). In that case, this should fail every time. The problem would appear to be that rw_lock_free_func() is not calling the destructor (in the dump, magic_n is at RW_LOCK_MAGIC_N, which rw_lock_t::rw_lock_t() assigned it to) but the ut_ad() assertion in purge_sys_t::~purge_sys_t() expected that to happen.

If the above guess is correct, then this should be a regression caused by MDEV-12269 (making UNIV_DEBUG depend on DBUG_OFF).

Comment by Marko Mäkelä [ 2017-05-10 ]

I can reproduce this locally on a Debian GNU/Linux AMD64 system with the following CMake invocation:

cmake .. -DCMAKE_BUILD_TYPE=Debug  -DCMAKE_C_COMPILER=gcc -DCMAKE_CXX_COMPILER=g++ '-DCMAKE_C_FLAGS_RELWITHDEBINFO=-m64 -O3 -g -mtune=native' '-DCMAKE_CXX_FLAGS_RELWITHDEBINFO=-m64 -O3 -g -mtune=native' '-DCMAKE_C_FLAGS=-m64 -O3 -g -mtune=native' '-DCMAKE_CXX_FLAGS=-m64 -O3 -g -mtune=native' -DWITH_SSL=system -DWITHOUT_FEDERATED_STORAGE_ENGINE=1 -DWITHOUT_FEDERATEDX_STORAGE_ENGINE=1 -DWITHOUT_TOKUDB_STORAGE_ENGINE=1

When using make VERBOSE=1, I see that the flags -DUNIV_DEBUG -DUNIV_SYNC_DEBUG are being defined and DBUG_OFF is not being defined.
At the machine code level, I see that rw_lock_t::~rw_lock_t() is being invoked (it is inlined in rw_lock_free_func()) and that the assignment in the destructor is apparently being optimized away:

	virtual ~rw_lock_t()
	{
		ut_ad(magic_n == RW_LOCK_MAGIC_N);
		magic_n = 0;
	}

It looks like the correct action (for now) is to relax the debug assertion in purge_sys_t::~purge_sys_t():

diff --git a/storage/innobase/trx/trx0purge.cc b/storage/innobase/trx/trx0purge.cc
index b21ec75c3a6..38ffe0cfe7e 100644
--- a/storage/innobase/trx/trx0purge.cc
+++ b/storage/innobase/trx/trx0purge.cc
@@ -231,8 +231,10 @@ purge_sys_t::~purge_sys_t()
 	view.close();
 	rw_lock_free(&latch);
 	/* rw_lock_free() already called latch.~rw_lock_t(); tame the
-	debug assertions when the destructor will be called once more. */
-	ut_ad(latch.magic_n == 0);
+	debug assertions when the destructor will be called once more.
+	Sometimes (maybe when compiled with -O3) rw_lock_t::~rw_lock_t()
+	will not assign the magic_n=0; we tolerate either value here. */
+	ut_ad(latch.magic_n == 0 || latch.magic_n == RW_LOCK_MAGIC_N);
 	ut_d(latch.magic_n = RW_LOCK_MAGIC_N);
 	mutex_free(&pq_mutex);
 	os_event_destroy(event);

I do not know if this is a compiler bug or if C++ allows the assignment to be optimized away.

Comment by Marko Mäkelä [ 2017-05-10 ]

In my final patch, I decided to duplicate the assignment magic_n=0 in rw_lock_free_func() instead.

Comment by Daniel Black [ 2017-05-11 ]

Well done marko and thanks. Accessing a objects members after an explicit destructor call does sound a bit suspicious.
http://www.open-std.org/jtc1/sc22/wg21/docs/papers/2014/n4296.pdf 3.8 talks about an object lifetime ending on destructor and there after properties aren't valid.

Comment by Marko Mäkelä [ 2017-05-16 ]

danblack, thanks for reporting this!
Ultimately, we should make rw_lock_t use proper constructors and destructors, instead of splitting some of the work to rw_lock_create_func() and rw_lock_free_func().

Generated at Thu Feb 08 07:59:36 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.