MariaDB

Server started with skip-innodb crashes on SELECT * FROM INNODB_TABLE_STATS or INNODB_INDEX_STATS

Bug #896439 reported by Łukasz Muchlado
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
MariaDB
New
Undecided
Unassigned
5.1
New
Undecided
Unassigned
MariaDB 5.1
5.2
New
Undecided
Unassigned
MariaDB 5.2
5.3
New
Undecided
Unassigned
MariaDB 5.3
5.5
Fix Committed
Undecided
Unassigned
MariaDB 5.5
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
Low
Stewart Smith
Percona Server moved to https://jira.percona.com/projects/PS 5.5.25a-27.1
5.1
Fix Released
Low
Stewart Smith
Percona Server moved to https://jira.percona.com/projects/PS 5.1.65-14.0
5.5
Fix Released
Low
Stewart Smith
Percona Server moved to https://jira.percona.com/projects/PS 5.5.25a-27.1

Bug Description

System: Ubuntu 10.04 server with all updates running on Linode VPS
MariaDB Version: '5.2.9-MariaDB-mariadb105~lucid-log'

innodb is disabled (skip-innodb in config)
default_storage_engine is Maria

After installing automysqlbackup from repo and running it manualy, MariaDB crashes and is restarted while backing up information_schema.

Problem is repeatable.

Syslog fragment:

Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [ERROR] mysqld got signal 11 ;
Nov 25 22:52:26 s3 mysqld: This could be because you hit a bug. It is also possible that this binary
Nov 25 22:52:26 s3 mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Nov 25 22:52:26 s3 mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Nov 25 22:52:26 s3 mysqld: We will try our best to scrape up some info that will hopefully help diagnose
Nov 25 22:52:26 s3 mysqld: the problem, but since we have already crashed, something is definitely wrong
Nov 25 22:52:26 s3 mysqld: and this may fail.
Nov 25 22:52:26 s3 mysqld:
Nov 25 22:52:26 s3 mysqld: key_buffer_size=0
Nov 25 22:52:26 s3 mysqld: read_buffer_size=2097152
Nov 25 22:52:26 s3 mysqld: max_used_connections=1
Nov 25 22:52:26 s3 mysqld: max_threads=102
Nov 25 22:52:26 s3 mysqld: threads_connected=1
Nov 25 22:52:26 s3 mysqld: It is possible that mysqld could use up to
Nov 25 22:52:26 s3 mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 627451 K
Nov 25 22:52:26 s3 mysqld: bytes of memory
Nov 25 22:52:26 s3 mysqld: Hope that's ok; if not, decrease some variables in the equation.
Nov 25 22:52:26 s3 mysqld:
Nov 25 22:52:26 s3 mysqld: Thread pointer: 0xb86b8128
Nov 25 22:52:26 s3 mysqld: Attempting backtrace. You can use the following information to find out
Nov 25 22:52:26 s3 mysqld: where mysqld died. If you see no messages after this, something went
Nov 25 22:52:26 s3 mysqld: terribly wrong...
Nov 25 22:52:26 s3 mysqld: stack_bottom = 0xa8d6436c thread_stack 0x30000
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2d) [0xb75c131d]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(handle_segfault+0x4d4) [0xb71a9bd4]
Nov 25 22:52:26 s3 mysqld: [0xf57fe400]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(get_schema_tables_result(JOIN*, enum_schema_table_state)+0x1e3) [0xb72d68d3]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(JOIN::exec()+0x5d3) [0xb722fae3]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*,
Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x102) [0xb7231b12]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x164) [0xb7232544]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(+0x25618c) [0xb71b618c]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(mysql_execute_command(THD*)+0xfe7) [0xb71b98c7]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(mysql_parse(THD*, char*, unsigned int, char const**)+0x2bf) [0xb71c0e9f]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x101d) [0xb71c239d]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(do_command(THD*)+0x10b) [0xb71c2f7b]
Nov 25 22:52:26 s3 mysqld: /usr/sbin/mysqld(handle_one_connection+0x168) [0xb71b1758]
Nov 25 22:52:26 s3 mysqld: /lib/tls/i686/cmov/libpthread.so.0(+0x596e) [0xb6d0996e]
Nov 25 22:52:26 s3 mysqld: /lib/tls/i686/cmov/libc.so.6(clone+0x5e) [0xb6b52a4e]
Nov 25 22:52:26 s3 mysqld:
Nov 25 22:52:26 s3 mysqld: Trying to get some variables.
Nov 25 22:52:26 s3 mysqld: Some pointers may be invalid and cause the dump to abort.
Nov 25 22:52:26 s3 mysqld: Query (0xb880eba0): SELECT /*!40001 SQL_NO_CACHE */ * FROM `INNODB_TABLE_STATS`
Nov 25 22:52:26 s3 mysqld: Connection ID (thread ID): 2
Nov 25 22:52:26 s3 mysqld: Status: NOT_KILLED
Nov 25 22:52:26 s3 mysqld:
Nov 25 22:52:26 s3 mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Nov 25 22:52:26 s3 mysqld: information that should help you find out what is causing the crash.
Nov 25 22:52:26 s3 mysqld_safe: Number of processes running now: 0
Nov 25 22:52:26 s3 mysqld_safe: mysqld restarted
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] PrimeBase XT (PBXT) Engine 1.0.11-7 Pre-GA loaded...
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] Paul McCullagh, PrimeBase Technologies GmbH, http://www.primebase.org
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] The server was not shutdown correctly, recovery required
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] Plugin 'InnoDB' is disabled.
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] Recovering after a crash using /var/log/mysql/mariadb-bin
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] Starting crash recovery...
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] Crash recovery finished.
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] Event Scheduler: Loaded 0 events
Nov 25 22:52:26 s3 mysqld: 111125 22:52:26 [Note] /usr/sbin/mysqld: ready for connections.
Nov 25 22:52:26 s3 mysqld: Version: '5.2.9-MariaDB-mariadb105~lucid-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (MariaDB - http://mariadb.com/)

See original description
Tags: xtradb crash

Related branches

lp://staging/~stewart/percona-server/bug896439
Alexey Kopytov (community): Approve
Diff: 616 lines (+140/-230)
11 files modified
Percona-Server/mysql-test/r/information_schema.result (+7/-11)
Percona-Server/mysql-test/r/information_schema_db.result (+1/-2)
Percona-Server/mysql-test/r/mysqlshow.result (+2/-4)
Percona-Server/mysql-test/suite/innodb_plugin/r/percona_skip_innodb_i_s.result (+93/-0)
Percona-Server/mysql-test/suite/innodb_plugin/t/percona_skip_innodb_i_s-master.opt (+1/-0)
Percona-Server/mysql-test/suite/innodb_plugin/t/percona_skip_innodb_i_s.test (+21/-0)
Percona-Server/storage/innodb_plugin/Makefile.am (+0/-1)
Percona-Server/storage/innodb_plugin/handler/ha_innodb.cc (+1/-2)
Percona-Server/storage/innodb_plugin/handler/i_s.cc (+14/-158)
Percona-Server/storage/innodb_plugin/handler/i_s.h (+0/-1)
Percona-Server/storage/innodb_plugin/handler/innodb_patch_info.h (+0/-51)
lp://staging/~stewart/percona-server/5.5-bug896439
Alexey Kopytov (community): Approve
Diff: 257 lines (+162/-0)
4 files modified
Percona-Server/mysql-test/suite/innodb/r/percona_skip_innodb_i_s.result (+114/-0)
Percona-Server/mysql-test/suite/innodb/t/percona_skip_innodb_i_s-master.opt (+1/-0)
Percona-Server/mysql-test/suite/innodb/t/percona_skip_innodb_i_s.test (+25/-0)
Percona-Server/storage/innobase/handler/i_s.cc (+22/-0)
Revision history for this message
Vladislav Vaintroub (wlad-montyprogram) wrote :

What is the point of disabling innodb *and* running SELECT * FROM `INNODB_TABLE_STATS` ?

check what plugins you use with "show plugins", you probably did not disabled everything. there are ~10 information schema for innodb plugins (among them | INNODB_TABLE_STATS) that not likely to function, or just useless if you disable the storage engine. You can see them with 'show plugins'. I guess everything will be back to normal if you disable the rest of INNODB_XXX plugins as well.

Revision history for this message
Łukasz Muchlado (lukasz-muchlado) wrote :

Thanks for fast and helpful response.

> What is the point of disabling innodb *and* running SELECT * FROM `INNODB_TABLE_STATS` ?

That query was run by backup application, not strictly by user

Workaround for my automysqlbackup problem is to exclude "information_schema" from autogenerated list of databases to backup. (Everything else is backed up without crashing mysqld).

But for me it don't feel right that simply querying:
SELECT * FROM information_schema.innodb_table_stats;
can CRASH whole mariadb server (if innodb storage engine is disabled).

Can I put in mariadb config something like "skip-innodb-table-stats" to feel safe from such crashing queries? (Or only method would be manualy disabling plugins by querying mariadb)?

> check what plugins you use with "show plugins", you probably did not disabled everything

I didn't disabled any plugins except disabling innodb storage engine by puting in config
skip-innodb

"show plugins" shows that everything (except disabled InnoDB STORAGE ENGINE) is enabled.

Revision history for this message
Vladislav Vaintroub (wlad-montyprogram) wrote :

The backup program should not backup INFORMATION_SCHEMA at all (it is mostly statistics that not stored persistently anyway, no need to backup/restore it, restore of it does not make sense)

>But for me it don't feel right that simply querying:
> SELECT * FROM information_schema.innodb_table_stats;
> can CRASH whole mariadb server (if innodb storage engine is disabled).

I agree it does not feel right, and needs to be fixed. By also take into account that disabling innodb is not something people do often, in contrary overwhelming majority runs innodb all the time.

If you would like to remove all trace of Innodb/XtraDB, and do not like to switch off all information schema plugins individually, use "ignore-builtin-innodb". The documentation of this variable here http://dev.mysql.com/doc/refman/5.1/en/innodb-parameters.html is rather sparse, but it does disable all of innodb.

Elena Stepanova (elenst)
summary: - Crash and restart of MariaDB 5.2.9 after running automysqlbackup on
- ubuntu 10.04
+ Server started with skip-innodb crashes in mutex_test_and_set on SELECT
+ * FROM INNODB_TABLE_STATS or INNODB_INDEX_STATS
Changed in maria:
milestone: none → 5.1
Revision history for this message
Elena Stepanova (elenst) wrote :
Download full text (3.4 KiB)

Stack trace from Percona Server 5.5.21:

#4 <signal handler called>
#5 0xb76f121d in pthread_mutex_trylock () from /lib/libpthread.so.0
#6 0x084accba in pfs_mutex_enter_func (thd=0x8a6a978, tables=0x8ae9f68, cond=0x0)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/storage/innobase/include/os0sync.ic:54
#7 i_s_innodb_table_stats_fill (thd=0x8a6a978, tables=0x8ae9f68, cond=0x0)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/storage/innobase/handler/i_s.cc:4038
#8 0x081f277e in get_schema_tables_result (join=0x8aea858,
    executed_place=PROCESSED_BY_JOIN_EXEC)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_show.cc:7420
#9 0x081ecf79 in JOIN::exec (this=0x8aea858)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_select.cc:1926
#10 0x081ef8ee in mysql_select (thd=0x8a6a978, rref_pointer_array=0x8a6c0a8, tables=0x8ae9f68,
    wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0,
    proc_param=0x0, select_options=2684619520, result=0x8aea848, unit=0x8a6bb74,
    select_lex=0x8a6bfb0)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_select.cc:2600
#11 0x081f0274 in handle_select (thd=0x8a6a978, lex=0x8a6bb10, result=0x8aea848,
    setup_tables_done_option=0)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_select.cc:312
#12 0x081a4748 in execute_sqlcom_select (thd=0x8a6a978, all_tables=0x8ae9f68)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_parse.cc:4734
#13 0x081a6ebf in mysql_execute_command (thd=0x8a6a978)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_parse.cc:2278
#14 0x081ae0b8 in mysql_parse (thd=0x8a6a978,
    rawbuf=0x8ae9de8 "select * from INNODB_TABLE_STATS", length=32, parser_state=0xb6493ddc)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_parse.cc:5804

#15 0x081af93f in dispatch_command (command=COM_QUERY, thd=0x8a6a978,
    packet=0x8ae1c19 "select * from INNODB_TABLE_STATS", packet_length=32)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_parse.cc:1060
#16 0x081afe36 in do_command (thd=0x8a6a978)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_parse.cc:788
#17 0x082594d5 in do_handle_one_connection (thd_arg=0x8a6a978)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_connect.cc:1433
#18 0x082595bf in handle_one_connection (arg=0x8a6a978)
    at /home/jenkins/workspace/percona-server-5.5-binaries/label_exp/centos5-32/Percona-Server-5.5.21-rel25.1/sql/sql_connect.cc:1340
#19 0xb76eeb25...

Read more...

summary: - Server started with skip-innodb crashes in mutex_test_and_set on SELECT
- * FROM INNODB_TABLE_STATS or INNODB_INDEX_STATS
+ Server started with skip-innodb crashes on SELECT * FROM
+ INNODB_TABLE_STATS or INNODB_INDEX_STATS
tags: added: xtradb
Łukasz Muchlado (lukasz-muchlado)
description: updated
Revision history for this message
Elena Stepanova (elenst) wrote :

The fix made it to maria/5.5 and will be released with 5.5.27, but it's not yet in 5.1-5.3 trees.

Changed in maria:
milestone: 5.1 → none
Revision history for this message
Eric H (eric-hardway) wrote :
Download full text (3.5 KiB)

I just had an instance crash with a similar query.

select /*! SQL_NO_CACHE */ @a:='2013-01-14 14:57:00', @b:='(none)', @c:='10.20.36.131', @d:='3307', X.* from information_schema.INNODB_BUFFER_POOL_STATS as X

The instance is MyISAM only and I run it with skip-innodb.

Version: '5.1.66rel14.1' socket: '/san/mainolpanalytics/mainolpanalytics.sock' port: 3307 Percona Server with XtraDB (GPL), Release rel14.1, Revision 495
121230 9:23:43 [Note] Event Scheduler: scheduler thread started with id 1
22:57:35 UTC - 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.
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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=1073741824
read_buffer_size=131072
max_used_connections=14
max_threads=50
thread_count=10
connection_count=9
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1157930 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f568800f550
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 = 7f568ee8de98 thread_stack 0x40000
/usr/local/mainolpanalytics/libexec/mysqld(my_print_stacktrace+0x35)[0x8ab885]
/usr/local/mainolpanalytics/libexec/mysqld(handle_fatal_signal+0x378)[0x6ae2f8]
/lib/libpthread.so.0(+0xef60)[0x7f56d154df60]
/usr/local/mainolpanalytics/libexec/mysqld[0x800cb6]
/usr/local/mainolpanalytics/libexec/mysqld[0x74e365]
/usr/local/mainolpanalytics/libexec/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x1d1)[0x6c5271]
/usr/local/mainolpanalytics/libexec/mysqld(_ZN4JOIN4execEv+0x3ff)[0x63a7ff]
/usr/local/mainolpanalytics/libexec/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x199)[0x63c8d9]
/usr/local/mainolpanalytics/libexec/mysqld(_Z13handle_selectP3THDP6st_lexP13select_resultm+0x1c5)[0x63d225]
/usr/local/mainolpanalytics/libexec/mysqld[0x5c7ef1]
/usr/local/mainolpanalytics/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x3b6)[0x5cad16]
/usr/local/mainolpanalytics/libexec/mysqld(_Z11mysql_parseP3THDPcjPPKc+0x51b)[0x5d0f8b]
/usr/local/mainolpanalytics/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x46e)[0x5d13fe]
/usr/local/mainolpanalytics/libexec/mysqld(_Z10do_commandP3THD+0x129)[0x5d2699]
/usr/local/mainolpanalytics/libexec/mysqld(handle_one_connection+0x9cd)[0x5c45cd]
/lib/libpthread.so.0(+0x68ba)[0x7f56d15458ba]
/lib/libc.so.6(clone+0x6d)[0x7f56d05b902d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (29015d0): select /*! SQL_NO_CACHE */ @a:='2013-01-14 14:57:00', @b:='(none)', @c:='10.20.36.13...

Read more...

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1897

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.