Bug #2637

MySQL 5.5利用時にカラム名を変更しようとするとクラッシュする

Added by Kenji Maruyama about 3 years ago. Updated about 3 years ago.

Status:完了Start date:07/24/2014
Priority:NormalDue date:
Assignee:-% Done:

100%

Category:-
Target version:-

Description

MroongaのmasterでMySQL 5.5と一緒に使うとカラム名を変更した時にクラッシュする

バックトレース: https://travis-ci.org/mroonga/mroonga/jobs/30561802#L1546

再現方法

test/run-sql-test.sh mysql-test/mroonga/storage/alter_table/change_column/rename/t/no_order.test

ゴール

MySQL 5.5でカラム名を変更時にクラッシュしないようにする

History

#1 Updated by Kenji Maruyama about 3 years ago


[2014/07/23 14:58:23] すとう: バックトレースを見る感じだと、リネームできていないのに処理が進んじゃってリネーム語のカラムを参照してクラッシュみたいな流れだと思います。
[2014/07/23 14:59:17] すとう: できないのにinplace ALTER TABLEの処理に入っちゃっているんじゃないか疑惑を持っています。(MySQL 5.6ではできるようにしたけど5.5ではできない。)

手元のmysql5.5環境で

mysql-test/mroonga/storage/alter_table/change_column/rename/t/no_order.test の ALTER TABLEまでで実行してみた。

CREATE TABLE diaries (
  id INT PRIMARY KEY AUTO_INCREMENT,
  title TEXT,
  body TEXT
) DEFAULT CHARSET UTF8;
SHOW CREATE TABLE diaries;

ALTER TABLE diaries CHANGE body description TEXT;

結果としてすとうさんの予想通りリネーム時serverクラッシュした. クラッシュ時のログは以下となる

[Thread debugging using libthread_db enabled]
Core was generated by `/home/vagrant/db_src/mysql-5.5.36/sql/mysqld --defaults-group-suffix=.1 --defau'.
Program terminated with signal 11, Segmentation fault.
#0  __pthread_kill (threadid=, signo=) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
63    val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
#0  __pthread_kill (threadid=, signo=) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
#1  0x00000000008d6e47 in my_write_core (sig=11) at /home/vagrant/db_src/mysql-5.5.36/mysys/stacktrace.c:433
#2  0x0000000000761cc7 in handle_fatal_signal (sig=11) at /home/vagrant/db_src/mysql-5.5.36/sql/signal_handler.cc:247
#3  
#4  0x00007f8c3172c86b in grn_obj_get_range_info (ctx=0x7f8c2c352a60, obj=0x0, range_id=0x7f8c3c75cde4, range_flags=0x7f8c3c75cde2) at db.c:4550
#5  0x00007f8c3172cacc in grn_obj_get_range (ctx=0x7f8c2c352a60, obj=0x0) at db.c:4591
#6  0x00007f8c3c14bdcb in ha_mroonga::storage_open_columns (this=0x7f8c2c351910) at ha_mroonga.cpp:4070
#7  0x00007f8c3c14b44c in ha_mroonga::storage_open (this=0x7f8c2c351910, name=0x7f8c2c3087b8 "./test/diaries", mode=2, test_if_locked=2) at ha_mroonga.cpp:3928
#8  0x00007f8c3c14c90e in ha_mroonga::open (this=0x7f8c2c351910, name=0x7f8c2c3087b8 "./test/diaries", mode=2, test_if_locked=2) at ha_mroonga.cpp:4218
#9  0x00000000007663b4 in handler::ha_open (this=0x7f8c2c351910, table_arg=0x7f8c2c351030, name=0x7f8c2c3087b8 "./test/diaries", mode=2, test_if_locked=2) at /home/vagrant/db_src/mysql-5.5.36/sql/handler.cc:2245
#10 0x00000000006a6a19 in open_table_from_share (thd=0x2181c20, share=0x7f8c2c308430, alias=0x7f8c2c004e00 "diaries", db_stat=39, prgflag=44, ha_open_flags=0, outparam=0x7f8c2c351030, is_create_table=false) at /home/vagrant/db_src/mysql-5.5.36/sql/table.cc:2064
#11 0x00000000005a533c in open_table (thd=0x2181c20, table_list=0x7f8c2c004e08, mem_root=0x2184828, ot_ctx=0x7f8c3c75e740) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_base.cc:3096
#12 0x0000000000684f97 in mysql_alter_table (thd=0x2181c20, new_db=0x7f8c2c005330 "test", new_name=0x7f8c2c004dd0 "diaries", create_info=0x7f8c3c75ff20, table_list=0x7f8c2c004e08, alter_info=0x7f8c3c760000, order_num=0, order=0x0, ignore=false) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_table.cc:6892
#13 0x00000000008acfe8 in Alter_table_statement::execute (this=0x7f8c2c005428, thd=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_alter.cc:106
#14 0x00000000005fde4a in mysql_execute_command (thd=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:4458
#15 0x00000000006009a3 in mysql_parse (thd=0x2181c20, rawbuf=0x7f8c2c004cf0 "ALTER TABLE diaries CHANGE body description TEXT", length=48, parser_state=0x7f8c3c7616a0) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:5664
#16 0x00000000005f486a in dispatch_command (command=COM_QUERY, thd=0x2181c20, packet=0x2206701 "ALTER TABLE diaries CHANGE body description TEXT", packet_length=48) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:1040
#17 0x00000000005f3b60 in do_command (thd=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:773
#18 0x00000000006da733 in do_handle_one_connection (thd_arg=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_connect.cc:862
#19 0x00000000006da26b in handle_one_connection (arg=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_connect.cc:781
#20 0x00000000009039d0 in pfs_spawn_thread (arg=0x21e2b90) at /home/vagrant/db_src/mysql-5.5.36/storage/perfschema/pfs.cc:1015
#21 0x00007f8c40efe9d1 in start_thread (arg=0x7f8c3c762700) at pthread_create.c:301
#22 0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 13 (Thread 0x7f8c3c7a3700 (LWP 6064)):
#0  do_sigwait (set=, sig=0x7f8c3c7a2e38) at ../sysdeps/unix/sysv/linux/sigwait.c:65
#1  __sigwait (set=, sig=0x7f8c3c7a2e38) at ../sysdeps/unix/sysv/linux/sigwait.c:100
#2  0x000000000055a0af in signal_hand (arg=0x0) at /home/vagrant/db_src/mysql-5.5.36/sql/mysqld.cc:2701
#3  0x00000000009039d0 in pfs_spawn_thread (arg=0x1b02b60) at /home/vagrant/db_src/mysql-5.5.36/storage/perfschema/pfs.cc:1015
#4  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c3c7a3700) at pthread_create.c:301
#5  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 12 (Thread 0x7f8c325f6700 (LWP 6063)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x1b11548, mp=0x1b114d0, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x1b11548, mutex=0x1b114d0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x1b114d0, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x00000000009cda8b in srv_master_thread (arg=0x0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0srv.c:3221
#5  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c325f6700) at pthread_create.c:301
#6  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 11 (Thread 0x7f8c32ff7700 (LWP 6062)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239
#1  0x00000000008ddf41 in safe_cond_timedwait (cond=0x1ebaec8, mp=0x1ebae50, abstime=0x7f8c32ff6dd0, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=171) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:278
#2  0x0000000000adadaf in os_cond_wait_timed (cond=0x1ebaec8, mutex=0x1ebae50, abstime=0x7f8c32ff6dd0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:171
#3  0x0000000000adb860 in os_event_wait_time_low (event=0x1ebae50, time_in_usec=5000000, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:716
#4  0x00000000009cbe77 in srv_monitor_thread (arg=0x0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0srv.c:2184
#5  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c32ff7700) at pthread_create.c:301
#6  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 10 (Thread 0x7f8c339f8700 (LWP 6061)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239
#1  0x00000000008ddf41 in safe_cond_timedwait (cond=0x1ebad48, mp=0x1ebacd0, abstime=0x7f8c339f7de0, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=171) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:278
#2  0x0000000000adadaf in os_cond_wait_timed (cond=0x1ebad48, mutex=0x1ebacd0, abstime=0x7f8c339f7de0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:171
#3  0x0000000000adb860 in os_event_wait_time_low (event=0x1ebacd0, time_in_usec=1000000, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:716
#4  0x00000000009cc652 in srv_error_monitor_thread (arg=0x0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0srv.c:2517
#5  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c339f8700) at pthread_create.c:301
#6  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 9 (Thread 0x7f8c343f9700 (LWP 6060)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239
#1  0x00000000008ddf41 in safe_cond_timedwait (cond=0x1ebae08, mp=0x1ebad90, abstime=0x7f8c343f8df0, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=171) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:278
#2  0x0000000000adadaf in os_cond_wait_timed (cond=0x1ebae08, mutex=0x1ebad90, abstime=0x7f8c343f8df0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:171
#3  0x0000000000adb860 in os_event_wait_time_low (event=0x1ebad90, time_in_usec=1000000, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:716
#4  0x00000000009cc26f in srv_lock_timeout_thread (arg=0x0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0srv.c:2334
#5  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c343f9700) at pthread_create.c:301
#6  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 8 (Thread 0x7f8c357fb700 (LWP 6058)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x20da378, mp=0x20da300, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x20da378, mutex=0x20da300) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x20da300, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x0000000000ad9c9d in os_aio_simulated_handle (global_segment=5, message1=0x7f8c357fae40, message2=0x7f8c357fae38, type=0x7f8c357fae30) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0file.c:5074
#5  0x0000000000a82862 in fil_aio_wait (segment=5) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/fil/fil0fil.c:4714
#6  0x00000000009cf368 in io_handler_thread (arg=0x12e80a8) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0start.c:482
#7  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c357fb700) at pthread_create.c:301
#8  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 7 (Thread 0x7f8c361fc700 (LWP 6057)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x20da2b8, mp=0x20da240, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x20da2b8, mutex=0x20da240) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x20da240, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x0000000000ad9c9d in os_aio_simulated_handle (global_segment=4, message1=0x7f8c361fbe40, message2=0x7f8c361fbe38, type=0x7f8c361fbe30) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0file.c:5074
#5  0x0000000000a82862 in fil_aio_wait (segment=4) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/fil/fil0fil.c:4714
#6  0x00000000009cf368 in io_handler_thread (arg=0x12e80a0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0start.c:482
#7  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c361fc700) at pthread_create.c:301
#8  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 6 (Thread 0x7f8c36bfd700 (LWP 6056)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x20da1f8, mp=0x20da180, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x20da1f8, mutex=0x20da180) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x20da180, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x0000000000ad9c9d in os_aio_simulated_handle (global_segment=3, message1=0x7f8c36bfce40, message2=0x7f8c36bfce38, type=0x7f8c36bfce30) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0file.c:5074
#5  0x0000000000a82862 in fil_aio_wait (segment=3) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/fil/fil0fil.c:4714
#6  0x00000000009cf368 in io_handler_thread (arg=0x12e8098) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0start.c:482
#7  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c36bfd700) at pthread_create.c:301
#8  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 5 (Thread 0x7f8c375fe700 (LWP 6055)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x20da138, mp=0x20da0c0, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x20da138, mutex=0x20da0c0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x20da0c0, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x0000000000ad9c9d in os_aio_simulated_handle (global_segment=2, message1=0x7f8c375fde40, message2=0x7f8c375fde38, type=0x7f8c375fde30) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0file.c:5074
#5  0x0000000000a82862 in fil_aio_wait (segment=2) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/fil/fil0fil.c:4714
#6  0x00000000009cf368 in io_handler_thread (arg=0x12e8090) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0start.c:482
#7  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c375fe700) at pthread_create.c:301
#8  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 4 (Thread 0x7f8c37fff700 (LWP 6054)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x20da078, mp=0x20da000, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x20da078, mutex=0x20da000) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x20da000, reset_sig_count=3) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x0000000000ad9c9d in os_aio_simulated_handle (global_segment=1, message1=0x7f8c37ffee40, message2=0x7f8c37ffee38, type=0x7f8c37ffee30) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0file.c:5074
#5  0x0000000000a82862 in fil_aio_wait (segment=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/fil/fil0fil.c:4714
#6  0x00000000009cf368 in io_handler_thread (arg=0x12e8088) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0start.c:482
#7  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c37fff700) at pthread_create.c:301
#8  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 3 (Thread 0x7f8c3f8f2700 (LWP 6053)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183
#1  0x00000000008ddd6f in safe_cond_wait (cond=0x20d9fb8, mp=0x20d9f40, file=0xca6470 "/home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c", line=207) at /home/vagrant/db_src/mysql-5.5.36/mysys/thr_mutex.c:240
#2  0x0000000000adaeb9 in os_cond_wait (cond=0x20d9fb8, mutex=0x20d9f40) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:207
#3  0x0000000000adb6aa in os_event_wait_low (event=0x20d9f40, reset_sig_count=1) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0sync.c:609
#4  0x0000000000ad9c9d in os_aio_simulated_handle (global_segment=0, message1=0x7f8c3f8f1e40, message2=0x7f8c3f8f1e38, type=0x7f8c3f8f1e30) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/os/os0file.c:5074
#5  0x0000000000a82862 in fil_aio_wait (segment=0) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/fil/fil0fil.c:4714
#6  0x00000000009cf368 in io_handler_thread (arg=0x12e8080) at /home/vagrant/db_src/mysql-5.5.36/storage/innobase/srv/srv0start.c:482
#7  0x00007f8c40efe9d1 in start_thread (arg=0x7f8c3f8f2700) at pthread_create.c:301
#8  0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 2 (Thread 0x7f8c41324720 (LWP 6051)):
#0  0x00007f8c3fc49343 in __poll (fds=, nfds=, timeout=) at ../sysdeps/unix/sysv/linux/poll.c:87
#1  0x000000000055dd72 in handle_connections_sockets () at /home/vagrant/db_src/mysql-5.5.36/sql/mysqld.cc:5232
#2  0x000000000055d19d in mysqld_main (argc=50, argv=0x1a929e8) at /home/vagrant/db_src/mysql-5.5.36/sql/mysqld.cc:4674
#3  0x0000000000555544 in main (argc=11, argv=0x7ffffdd94838) at /home/vagrant/db_src/mysql-5.5.36/sql/main.cc:25

Thread 1 (Thread 0x7f8c3c762700 (LWP 6068)):
#0  __pthread_kill (threadid=, signo=) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
#1  0x00000000008d6e47 in my_write_core (sig=11) at /home/vagrant/db_src/mysql-5.5.36/mysys/stacktrace.c:433
#2  0x0000000000761cc7 in handle_fatal_signal (sig=11) at /home/vagrant/db_src/mysql-5.5.36/sql/signal_handler.cc:247
#3  
#4  0x00007f8c3172c86b in grn_obj_get_range_info (ctx=0x7f8c2c352a60, obj=0x0, range_id=0x7f8c3c75cde4, range_flags=0x7f8c3c75cde2) at db.c:4550
#5  0x00007f8c3172cacc in grn_obj_get_range (ctx=0x7f8c2c352a60, obj=0x0) at db.c:4591
#6  0x00007f8c3c14bdcb in ha_mroonga::storage_open_columns (this=0x7f8c2c351910) at ha_mroonga.cpp:4070
#7  0x00007f8c3c14b44c in ha_mroonga::storage_open (this=0x7f8c2c351910, name=0x7f8c2c3087b8 "./test/diaries", mode=2, test_if_locked=2) at ha_mroonga.cpp:3928
#8  0x00007f8c3c14c90e in ha_mroonga::open (this=0x7f8c2c351910, name=0x7f8c2c3087b8 "./test/diaries", mode=2, test_if_locked=2) at ha_mroonga.cpp:4218
#9  0x00000000007663b4 in handler::ha_open (this=0x7f8c2c351910, table_arg=0x7f8c2c351030, name=0x7f8c2c3087b8 "./test/diaries", mode=2, test_if_locked=2) at /home/vagrant/db_src/mysql-5.5.36/sql/handler.cc:2245
#10 0x00000000006a6a19 in open_table_from_share (thd=0x2181c20, share=0x7f8c2c308430, alias=0x7f8c2c004e00 "diaries", db_stat=39, prgflag=44, ha_open_flags=0, outparam=0x7f8c2c351030, is_create_table=false) at /home/vagrant/db_src/mysql-5.5.36/sql/table.cc:2064
#11 0x00000000005a533c in open_table (thd=0x2181c20, table_list=0x7f8c2c004e08, mem_root=0x2184828, ot_ctx=0x7f8c3c75e740) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_base.cc:3096
#12 0x0000000000684f97 in mysql_alter_table (thd=0x2181c20, new_db=0x7f8c2c005330 "test", new_name=0x7f8c2c004dd0 "diaries", create_info=0x7f8c3c75ff20, table_list=0x7f8c2c004e08, alter_info=0x7f8c3c760000, order_num=0, order=0x0, ignore=false) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_table.cc:6892
#13 0x00000000008acfe8 in Alter_table_statement::execute (this=0x7f8c2c005428, thd=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_alter.cc:106
#14 0x00000000005fde4a in mysql_execute_command (thd=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:4458
#15 0x00000000006009a3 in mysql_parse (thd=0x2181c20, rawbuf=0x7f8c2c004cf0 "ALTER TABLE diaries CHANGE body description TEXT", length=48, parser_state=0x7f8c3c7616a0) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:5664
#16 0x00000000005f486a in dispatch_command (command=COM_QUERY, thd=0x2181c20, packet=0x2206701 "ALTER TABLE diaries CHANGE body description TEXT", packet_length=48) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:1040
#17 0x00000000005f3b60 in do_command (thd=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_parse.cc:773
#18 0x00000000006da733 in do_handle_one_connection (thd_arg=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_connect.cc:862
#19 0x00000000006da26b in handle_one_connection (arg=0x2181c20) at /home/vagrant/db_src/mysql-5.5.36/sql/sql_connect.cc:781
#20 0x00000000009039d0 in pfs_spawn_thread (arg=0x21e2b90) at /home/vagrant/db_src/mysql-5.5.36/storage/perfschema/pfs.cc:1015
#21 0x00007f8c40efe9d1 in start_thread (arg=0x7f8c3c762700) at pthread_create.c:301
#22 0x00007f8c3fc52b6d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Compressed file /home/vagrant/db_src/mysql-5.5.36/mysql-test/var/log/rename.no_order/mysqld.1/data/core.6051
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 8 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): mroonga/storage/alter_table/change_column/rename.no_order

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

#2 Updated by Naoya Murakami about 3 years ago

村上です。

すいません。最近少しだけソースが読めるようになって興味があったので少し追っかけました。

落ちている理由は、バックトレースみればわかると思いますが、以下のところです。

https://github.com/mroonga/mroonga/blob/master/ha_mroonga.cpp#L4068

Fieldの名前を見てみると、rename後の名前を取得しにいっています。 しかし、Groongaのカラムはrenameされていなく、grn_obj_columnでNULLが返っています。

MySQL5.5系でrenameのみでMroongaクラッシュするのは、今回の修正によるものじゃなくて以前の Mroongaのバージョンも同じでした。

テストケースが追加されて露見しただけだと思います。

alter table changeでrenameだけのときは、一時テーブルがつくられていません。

alter table changeで名前だけじゃなくてtypeも一緒に変更すると、一時テーブルが作成されてGroongaのカラムも新規作成されるのでクラッシュせずに正常にalter tableが成功します。

alter table changeで名前だけ変更のときは、一時テーブルが作られない仕様なのかinplaceの処理が 走るようなflag立てになっちゃっているのかはよくわかりませんでした。

私がわかったのはそれだけでした。。一応情報共有だけしておきます。

周知のことであれば、失礼しました。

#3 Updated by Kouhei Sutou about 3 years ago

  • Status changed from 新規 to 完了チェック待ち
  • % Done changed from 0 to 80

Applied in changeset commit:470865e2ad4281af04741b4614ece86b7b944ee1.

#4 Updated by Kenji Maruyama about 3 years ago

  • Status changed from 完了チェック待ち to 担当者作業中
  • % Done changed from 80 to 0

http://redmine.groonga.org/issues/2637#note-2

村上さん、ありがとうございます。

Fieldの名前を見てみると、rename後の名前を取得しにいっています。 しかし、Groongaのカラムはrenameされていなく、grn_obj_columnでNULLが返っています。

debugしてみると、column_nameは変更されていましたが、ご指摘のようにgrn_columns オブジェクトがnull になっています。

grn_columns[i] = grn_obj_column(ctx, grn_table, column_name, column_name_size);

alter table changeで名前だけ変更のときは、一時テーブルが作られない仕様なのかinplaceの処理が 走るようなflag立てになっちゃっているのかはよくわかりませんでした。

MySQL5.5のsql/handler.hをみるとinplace処理するのは、index系だけのようですので、それ以外のalter table(カラム名の変更)はすべて一時テーブル作られてコピーされる仕様なのではないかと思います。

ちなみにMySQL5.6とMySQL5.5にてtrace.logをみてみますと、以下のinplace ALTER TABLEの処理疑惑はありませんでした。

できないのにinplace ALTER TABLEの処理に入っちゃっているんじゃないか疑惑を持っています。


alter table changeで名前だけじゃなくてtypeも一緒に変更すると、一時テーブルが作成されてGroongaのカラムも新規作成されるのでクラッシュせずに正常にalter tableが成功します。

なるほどです。

http://redmine.groonga.org/issues/2637#note-3

須藤さん、ありがとうございます。手元の環境でおちないことを確認しました。

#5 Updated by Kenji Maruyama about 3 years ago

  • % Done changed from 0 to 80

#6 Updated by Kouhei Sutou about 3 years ago

  • Status changed from 担当者作業中 to 完了
  • % Done changed from 80 to 100

動作確認ありがとうございます!

村上さんも、調査してくれてありがとうございます!この問題が以前からあったのはその通りです!

Also available in: Atom PDF