[MDEV-8992] MariaDB crashes when accessing table with GIS features Created: 2015-10-22  Updated: 2016-09-22  Resolved: 2015-11-01

Status: Closed
Project: MariaDB Server
Component/s: GIS, Storage Engine - Aria
Affects Version/s: 10.1.8
Fix Version/s: 10.1.9

Type: Bug Priority: Blocker
Reporter: Willem van Pelt Assignee: Alexey Botchkov
Resolution: Fixed Votes: 1
Labels: crash, regression
Environment:

CentOS 6.6 with kernel 2.6.32-504.23.4.el6.x86_64


Attachments: File bad.frm    
Issue Links:
Relates
relates to MDEV-8163 Table causes maria to crash repeatedly. Closed
Sprint: 10.1.9-1

 Description   

After upgrading server from MariaDB 1.0.21 to 10.1.8, mysqld crashes when using a table that uses GIS features. As a result, it is not even possible to run mysql_upgrade. Because of the repeated crashing, the server becomes unusable for production purposes.

Selecting data from the affected tables is possible though, but operations such as 'show create table', 'show table status' or even 'use <database>' cause mysqld to restart.

Interestingly, after issuing the 'describe' command on a table, it is sometimes possible to (temporarily) perform these functions on that particular table without crashing mysqld.

After creating a new table using an identical table definition, followed by copying the new .frm file over the old .frm file, the table works smoothly.

This bug is similar (though in my opinion not identical) to bug MDEV-8163.



 Comments   
Comment by Willem van Pelt [ 2015-10-22 ]

Contents of mysqld.log:

Version: '10.1.8-MariaDB'  socket: '/serverdata/mysql/mysql.sock'  port: 3306  MariaDB Server
 
151022 17:04:12 [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 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.8-MariaDB
key_buffer_size=4294967296
read_buffer_size=2097152
max_used_connections=1
max_threads=1002
thread_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 10371034 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0x7f2537bd0008
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 = 0x7f253b62dd40 thread_stack 0x48000
mysys/stacktrace.c:247(my_print_stacktrace)[0x7f253c0ea6cb]
sql/signal_handler.cc:160(handle_fatal_signal)[0x7f253bc4c0d5]
/lib64/libpthread.so.0(+0xf790)[0x7f253b265790]
sql/field.cc:8337(gis_field_options_read(unsigned char const*, unsigned int, Field_geom::storage_type*, unsigned int*, unsigned int*, unsigned int*))[0x7f253bc3a800]
sql/table.cc:1501(TABLE_SHARE::init_from_binary_frm_image(THD*, bool, unsigned char const*, unsigned long))[0x7f253bb7a84c]
sql/table.cc:652(open_table_def(THD*, TABLE_SHARE*, unsigned int))[0x7f253bb7c5b2]
sql/table_cache.cc:641(tdc_acquire_share(THD*, char const*, char const*, char const*, unsigned int, unsigned int, unsigned int, TABLE**))[0x7f253bbff14a]
sql/sql_base.cc:2421(open_table(THD*, TABLE_LIST*, Open_table_context*))[0x7f253ba9ac5c]
sql/sql_base.cc:4068(open_and_process_table)[0x7f253ba9f27a]
sql/sql_show.cc:1137(mysqld_show_create(THD*, TABLE_LIST*))[0x7f253bb3a4dc]
sql/sql_parse.cc:3701(mysql_execute_command(THD*))[0x7f253badf5c4]
sql/sql_parse.cc:7265(mysql_parse)[0x7f253bae4c0d]
sql/sql_parse.cc:1488(dispatch_command(enum_server_command, THD*, char*, unsigned int))[0x7f253bae7853]
sql/sql_parse.cc:1112(do_command(THD*))[0x7f253bae7dfb]
sql/sql_connect.cc:1350(do_handle_one_connection(THD*))[0x7f253bba262f]
sql/sql_connect.cc:1264(handle_one_connection)[0x7f253bba2787]
/lib64/libpthread.so.0(+0x7a51)[0x7f253b25da51]
/lib64/libc.so.6(clone+0x6d)[0x7f253974393d]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f1ea70aa020): is an invalid pointer
Connection ID (thread ID): 2
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
 
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.
151022 17:04:13 mysqld_safe Number of processes running now: 0
151022 17:04:13 mysqld_safe mysqld restarted
2015-10-22 17:04:13 140096469264416 [Note] /usr/sbin/mysqld (mysqld 10.1.8-MariaDB) starting as process 51151 ...
2015-10-22 17:04:13 140096469264416 [Note] CONNECT: Version 1.03.0007 July 05, 2015
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Memory barrier is not used
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Using Linux native AIO
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Using CPU crc32 instructions
2015-10-22 17:04:14 140096469264416 [Note] InnoDB: Initializing buffer pool, size = 20.0G
2015-10-22 17:04:15 140096469264416 [Note] InnoDB: Completed initialization of buffer pool
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: Highest supported file format is Barracuda.
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: The log sequence numbers 1475580279756 and 1475580279756 in ibdata files do not match the log sequence number 1475580280052 in the ib_logfiles!
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: Database was not shutdown normally!
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: Starting crash recovery.
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: Reading tablespace information from the .ibd files...
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: Restoring possible half-written data pages
2015-10-22 17:04:16 140096469264416 [Note] InnoDB: from the doublewrite buffer...
2015-10-22 17:04:17 140096469264416 [Note] InnoDB: 128 rollback segment(s) are active.
2015-10-22 17:04:17 140096469264416 [Note] InnoDB: Waiting for purge to start
2015-10-22 17:04:17 140096469264416 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 1475580280052
2015-10-22 17:04:17 140068018689792 [Note] InnoDB: Dumping buffer pool(s) not yet started
2015-10-22 17:04:17 140096469264416 [Note] Plugin 'FEEDBACK' is disabled.
2015-10-22 17:04:17 140096469264416 [Note] Recovering after a crash using tc.log
2015-10-22 17:04:17 140096469264416 [Note] Starting crash recovery...
2015-10-22 17:04:17 140096469264416 [Note] Crash recovery finished.
2015-10-22 17:04:17 140096469264416 [Note] Server socket created on IP: '::'.
2015-10-22 17:04:17 140096469264416 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.1.8-MariaDB'  socket: '/serverdata/mysql/mysql.sock'  port: 3306  MariaDB Server

Comment by Elena Stepanova [ 2015-10-24 ]

wvp, thanks for the report!


MTR test case, assuming that you have downloaded the attached frm file to <basedir>/mysql-test:

create table bad (i int) engine=Aria;
flush tables;
--let $datadir=`SELECT @@datadir`
--remove_file $datadir/test/bad.frm
--copy_file bad.frm $datadir/test/bad.frm
flush tables;
show create table bad;

The same can be done manually.

Apparently the problem was introduced by the following commit:

commit c4cb15e87ba8cf4f1e7fd8e7cda5c88098ecd515
Author: Alexey Botchkov <holyfoot@askmonty.org>
Date:   Wed Dec 3 14:07:43 2014 +0400
 
    MDEV-60 Support for Spatial Reference systems for the GIS data.
            The GEOMETRY field metadata is stored in the FRM file.
            SRID for a spatial column now can be stored, it was added to the CREATE TABLE syntax,
            so the AddGeometryData() stored procedure is now possible. Script adding the required Add/DropGeometryColumn sp-s added.

Stack trace from 10.1 commit 7e29f2d64fb463559a7c9c178ffe899b9bcab113

#3  <signal handler called>
#4  0x00007fe9f7fd4ed2 in gis_field_options_read (buf=0x0, buf_len=3960754304, st_type=0x7fe9f7833e38, precision=0x7fe9f7833e2c, scale=0x7fe9f7833e30, srid=0x7fe9f7833e34) at 10.1/sql/field.cc:8331
#5  0x00007fe9f7e9c04a in TABLE_SHARE::init_from_binary_frm_image (this=0x7fe9ec06f688, thd=0x7fe9ee176070, write=false, frm_image=0x7fe9ec0cd870 "\376\001\n*\022", frm_length=1991) at 10.1/sql/table.cc:1503
#6  0x00007fe9f7e996d7 in open_table_def (thd=0x7fe9ee176070, share=0x7fe9ec06f688, flags=11) at 10.1/sql/table.cc:650
#7  0x00007fe9f7f74f9b in tdc_acquire_share (thd=0x7fe9ee176070, db=0x7fe9ec267740 "test", table_name=0x7fe9ec267128 "bad", key=0x7fe9ec2675a1 "test", key_length=9, hash_value=2226402630, flags=3, out_table=0x7fe9f7834568) at 10.1/sql/table_cache.cc:639
#8  0x00007fe9f7d49c61 in open_table (thd=0x7fe9ee176070, table_list=0x7fe9ec267160, ot_ctx=0x7fe9f7834990) at 10.1/sql/sql_base.cc:2419
#9  0x00007fe9f7d4c9e5 in open_and_process_table (thd=0x7fe9ee176070, lex=0x7fe9ee1799a8, tables=0x7fe9ec267160, counter=0x7fe9f7834a6c, flags=1024, prelocking_strategy=0x7fe9f7834a10, has_prelocking_list=false, ot_ctx=0x7fe9f7834990) at 10.1/sql/sql_base.cc:4068
#10 0x00007fe9f7d4dad4 in open_tables (thd=0x7fe9ee176070, options=..., start=0x7fe9f7834a50, counter=0x7fe9f7834a6c, flags=1024, prelocking_strategy=0x7fe9f7834a10) at 10.1/sql/sql_base.cc:4579
#11 0x00007fe9f7d8db79 in open_tables (thd=0x7fe9ee176070, tables=0x7fe9f7834a50, counter=0x7fe9f7834a6c, flags=1024) at 10.1/sql/sql_base.h:499
#12 0x00007fe9f7e38442 in mysqld_show_create (thd=0x7fe9ee176070, table_list=0x7fe9ec267160) at 10.1/sql/sql_show.cc:1136
#13 0x00007fe9f7db360e in mysql_execute_command (thd=0x7fe9ee176070) at 10.1/sql/sql_parse.cc:3701
#14 0x00007fe9f7dbec4f in mysql_parse (thd=0x7fe9ee176070, rawbuf=0x7fe9ec267088 "show create table bad", length=21, parser_state=0x7fe9f78361a0) at 10.1/sql/sql_parse.cc:7265
#15 0x00007fe9f7dad7b6 in dispatch_command (command=COM_QUERY, thd=0x7fe9ee176070, packet=0x7fe9efd35071 "show create table bad", packet_length=21) at 10.1/sql/sql_parse.cc:1488
#16 0x00007fe9f7dac4dc in do_command (thd=0x7fe9ee176070) at 10.1/sql/sql_parse.cc:1110
#17 0x00007fe9f7ee2a5d in do_handle_one_connection (thd_arg=0x7fe9ee176070) at 10.1/sql/sql_connect.cc:1350
#18 0x00007fe9f7ee27ae in handle_one_connection (arg=0x7fe9ee176070) at 10.1/sql/sql_connect.cc:1262
#19 0x00007fe9f84b0193 in pfs_spawn_thread (arg=0x7fe9f4825170) at 10.1/storage/perfschema/pfs.cc:1860
#20 0x00007fe9f7471b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
#21 0x00007fe9f52fd95d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Comment by Alexey Botchkov [ 2015-11-01 ]

Fixing patch: http://lists.askmonty.org/pipermail/commits/2015-November/008567.html

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