[MDEV-6943] Assertion `(uint)v->offset <= vars->dynamic_variables_head' failure and further refusal to start Created: 2014-10-25  Updated: 2015-02-28  Resolved: 2015-02-28

Status: Closed
Project: MariaDB Server
Component/s: Plugins
Affects Version/s: 10.1.1
Fix Version/s: 10.1.3

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergey Vojtovich
Resolution: Fixed Votes: 0
Labels: None


 Description   

The problem appeared in 10.1 tree with this revision:

commit 28ebc2a72485c4b2956531010bd3ee247ae91df2
Author: Sergei Golubchik <serg@mariadb.org>
Date:   Wed Aug 27 20:32:32 2014 +0200
 
    cleanup: sysvar, only one common check_update_type()

Test case

--source include/have_innodb.inc
 
--connect (con1,localhost,root,,)
create table t1 (i int) engine=InnoDB;
install soname 'ha_tokudb';
--disconnect
 
--connection default
select "Still here?";

Version: '10.1.1-MariaDB-wsrep-debug'  socket: '/home/elenst/git/10.1/data/tmp/mysql.sock'  port: 3306  Source distribution, wsrep_25.10.r4123
mysqld: /home/elenst/git/10.1/sql/sql_plugin.cc:3111: void cleanup_variables(THD*, system_variables*): Assertion `(uint)v->offset <= vars->dynamic_variables_head' failed.
141025 11:50:37 [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 http://kb.askmonty.org/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.1-MariaDB-wsrep-debug
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467303 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0x7f3a7df44070
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 = 0x7f3a99e47e30 thread_stack 0x48000
Fatal signal 11 while backtracing

Stack trace from

commit 0a16fe4ec9add45532b6fd36a1059c33bac14f05
Author: Alexey Botchkov <holyfoot@montyprogram.com>
Date:   Fri Oct 24 17:12:03 2014 +0500
 
    GIS-related test results updated.

An attempt to start server again fails:

141025 11:51:29 [ERROR] mysqld: Table './mysql/plugin' is marked as crashed and should be repaired
141025 11:51:29 [Warning] Checking table:   './mysql/plugin'
141025 11:51:29 [ERROR] mysql.plugin: 1 client is using or hasn't closed the table properly
Sat Oct 25 11:51:29 2014 TokuFT recovery starting in env /home/elenst/git/10.1/data/
Sat Oct 25 11:51:29 2014 TokuFT recovery scanning backward from 12
Sat Oct 25 11:51:29 2014 TokuFT recovery bw_end_checkpoint at 12 timestamp 1414223435280149 xid 8 (bw_newer)
Sat Oct 25 11:51:29 2014 TokuFT recovery bw_begin_checkpoint at 8 timestamp 1414223434743935 (bw_between)
Sat Oct 25 11:51:29 2014 TokuFT recovery turning around at begin checkpoint 8 time 536214
Sat Oct 25 11:51:29 2014 TokuFT recovery starts scanning forward to 12 from 8 left 4 (fw_between)
Sat Oct 25 11:51:29 2014 TokuFT recovery closing 2 dictionaries
Sat Oct 25 11:51:29 2014 TokuFT recovery making a checkpoint
Sat Oct 25 11:51:29 2014 TokuFT recovery done
141025 11:51:29 [Note] Recovering after a crash using tc.log
141025 11:51:29 [ERROR] Recovery failed! You must enable exactly 2 storage engines that support two-phase commit protocol
141025 11:51:29 [ERROR] Crash recovery failed. Either correct the problem (if it's, for example, out of memory error) and restart, or delete tc log and start mysqld with --tc-heuristic-recover={commit|rollback}
141025 11:51:29 [ERROR] Can't init tc log
141025 11:51:29 [ERROR] Aborting
 
141025 11:51:31 [Note] InnoDB: FTS optimize thread exiting.
141025 11:51:31 [Note] InnoDB: Starting shutdown...



 Comments   
Comment by Elena Stepanova [ 2014-10-28 ]

Same assertion with QUERY_RESPONSE_TIME, only here I can get the stack trace, and no disaster on further startup:

create table t1 (i int) engine=InnoDB;
install soname 'query_response_time.so';

#6  0x00007f079bbbb6f1 in *__GI___assert_fail (assertion=0x7f079ede77e0 "(uint)v->offset <= vars->dynamic_variables_head", file=<optimized out>, line=3111, function=0x7f079ede87e0 "void cleanup_variables(THD*, system_variables*)") at assert.c:81
#7  0x00007f079e4eaec8 in cleanup_variables (thd=0x7f07945c8070, vars=0x7f07945c8730) at 10.1/sql/sql_plugin.cc:3111
#8  0x00007f079e4eb053 in plugin_thdvar_cleanup (thd=0x7f07945c8070) at 10.1/sql/sql_plugin.cc:3142
#9  0x00007f079e5f8385 in end_connection (thd=0x7f07945c8070) at 10.1/sql/sql_connect.cc:1144
#10 0x00007f079e5f8b0d in do_handle_one_connection (thd_arg=0x7f07945c8070) at 10.1/sql/sql_connect.cc:1354
#11 0x00007f079e5f882c in handle_one_connection (arg=0x7f07945c8070) at 10.1/sql/sql_connect.cc:1262
#12 0x00007f079eb89f6e in pfs_spawn_thread (arg=0x7f0794640770) at 10.1/storage/perfschema/pfs.cc:1860
#13 0x00007f079dbd5b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
#14 0x00007f079bc6c20d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Stack trace from 10.1 tree

commit 9646f946e912db02fb75493b48db188476860c8e
Author: Jan Lindström <jan.lindstrom@skysql.com>
Date:   Mon Oct 27 16:34:53 2014 +0200
 
    MDEV-6759: innodb valgrind failures
    
    Fix failure seen on dict_foreign_remove_partial.

Comment by Sergei Golubchik [ 2015-02-27 ]

I cannot repeat it in the latest 10.1

Comment by Elena Stepanova [ 2015-02-28 ]

The problem disappeared from 10.1 tree after the following commit:

commit db89dd3a8f7b0d868946d25ba98c6f88612d309a ae09895c9136ef6455d3bac3f25070a90e1df9c2
Author: Sergey Vojtovich <svoj@mariadb.org>
Date:   Fri Dec 26 13:07:43 2014 +0400
 
    MDEV-7364 - mysqld --help --verbose prints random values for "debug"
    
    getopt value pointer of "debug" variable was pointing to incorrect address:
    &global_system_variables. Runtime statements like SHOW VARIABLES materialize
    value from DBUG structures on demand, so they never access getopt value pointer.
    But mysqld --help --verbose loaded this value from &global_system_variables.
    
    Remove "debug" variable from mysqld --help --verbose output by setting value
    pointer to NULL.

(I don't know why, but it did).

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