Bug #96763 column type changed while OPTIMIZE TABLE
Submitted: 5 Sep 2019 3:33 Modified: 7 Oct 2019 11:49
Reporter: dave do Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server Severity:S6 (Debug Builds)
Version:8.0.16 OS:Any
Assigned to: CPU Architecture:Any

[5 Sep 2019 3:33] dave do
Description:
A dbug assert hitted while OPTIMIZE TABLE, the stack shown as below.(2 times hitted recently.)

------------------

(gdb) bt
#0  0x00007f67afd67417 in raise () from /lib64/libc.so.6
#1  0x00007f67afd68b08 in abort () from /lib64/libc.so.6
#2  0x0000000004b17888 in ut_dbg_assertion_failed (expr=0x681b1d3 "new_col->mtype == col->mtype", file=0x681a820 "/ci/src/sql/storage/innobase/row/row0log.cc", line=1405) at /ci/src/sql/storage/innobase/ut/ut0dbg.cc:92
#3  0x00000000049e2bfd in row_log_table_apply_convert_mrec (trx=0x7f677c3fcc40, mrec=0x7f678122b004 "\002", index=0x7f64cc1340f8, offsets=0x7f64ac023aa8, log=0x7f64ac0ab168, heap=0x7f64ac05dcf8, trx_id=7563, error=0x7f66d46d4194)
    at /ci/src/sql/storage/innobase/row/row0log.cc:1405
#4  0x00000000049e31a9 in row_log_table_apply_insert (thr=0x7f64ac031b00, mrec=0x7f678122b004 "\002", offsets=0x7f64ac023aa8, offsets_heap=0x7f64ac08c4b8, heap=0x7f64ac05dcf8, dup=0x7f66d46d4710, trx_id=7563)
    at /ci/src/sql/storage/innobase/row/row0log.cc:1525
#5  0x00000000049e51c9 in row_log_table_apply_op (thr=0x7f64ac031b00, trx_id_col=1, new_trx_id_col=1, dup=0x7f66d46d4710, error=0x7f66d46d434c, offsets_heap=0x7f64ac08c4b8, heap=0x7f64ac05dcf8, mrec=0x7f678122b004 "\002", mrec_end=0x7f678122b053 "", 
    offsets=0x7f64ac023aa8) at /ci/src/sql/storage/innobase/row/row0log.cc:2210
#6  0x00000000049e6d73 in row_log_table_apply_ops (thr=0x7f64ac031b00, dup=0x7f66d46d4710, stage=0x7f64ac00a298) at /ci/src/sql/storage/innobase/row/row0log.cc:2743
#7  0x00000000049e723d in row_log_table_apply (thr=0x7f64ac031b00, old_table=0x7f64cc1a9038, table=0x7f64ac080e80, stage=0x7f64ac00a298) at /ci/src/sql/storage/innobase/row/row0log.cc:2833
#8  0x00000000048632ec in commit_try_rebuild (ha_alter_info=0x7f66d46d6330, ctx=0x7f64ac055918, altered_table=0x7f64ac080e80, old_table=0x7f64ac00f5a0, trx=0x7f677c3fcc40, table_name=0x7f64b810518d "t3")
    at /ci/src/sql/storage/innobase/handler/handler0alter.cc:6695
#9  0x000000000486a052 in ha_innobase::commit_inplace_alter_table_impl<dd::Table> (this=0x7f64ac00b238, altered_table=0x7f64ac080e80, ha_alter_info=0x7f66d46d6330, commit=true, old_dd_tab=0x7f650c0eef50, new_dd_tab=0x7f64ac0190d0)
    at /ci/src/sql/storage/innobase/handler/handler0alter.cc:7343
#10 0x0000000004847f21 in ha_innobase::commit_inplace_alter_table (this=0x7f64ac00b238, altered_table=0x7f64ac080e80, ha_alter_info=0x7f66d46d6330, commit=true, old_dd_tab=0x7f650c0eef50, new_dd_tab=0x7f64ac0190d0)
    at /ci/src/sql/storage/innobase/handler/handler0alter.cc:1317
#11 0x00000000035baab9 in handler::ha_commit_inplace_alter_table (this=0x7f64ac00b238, altered_table=0x7f64ac080e80, ha_alter_info=0x7f66d46d6330, commit=true, old_table_def=0x7f650c0eef50, new_table_def=0x7f64ac0190d0) at /ci/src/sql/sql/handler.cc:4748
#12 0x00000000033087f9 in mysql_inplace_alter_table (thd=0x7f64ac000d00, schema=..., new_schema=..., table_def=0x7f650c0eef50, altered_table_def=0x7f64ac0190d0, table_list=0x7f64ac051d10, table=0x7f64ac00f5a0, altered_table=0x7f64ac080e80, 
    ha_alter_info=0x7f66d46d6330, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, alter_ctx=0x7f66d46d68e0, columns=..., fk_key_info=0x7f64ac055130, fk_key_count=0, fk_invalidator=0x7f66d46d5ab0) at /ci/src/sql/sql/sql_table.cc:12603
#13 0x0000000003313ae0 in mysql_alter_table (thd=0x7f64ac000d00, new_db=0x0, new_name=0x0, create_info=0x7f66d46d7c50, table_list=0x7f64ac051d10, alter_info=0x7f66d46d7d50) at /ci/src/sql/sql/sql_table.cc:16151
#14 0x00000000033180d3 in mysql_recreate_table (thd=0x7f64ac000d00, table_list=0x7f64ac051d10, table_copy=false) at /ci/src/sql/sql/sql_table.cc:17365
#15 0x0000000003817d45 in mysql_admin_table (thd=0x7f64ac000d00, tables=0x7f64ac051d10, check_opt=0x7f64ac003fb8, operator_name=0x5d8bd58 "optimize", lock_type=TL_WRITE, open_for_modify=false, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, 
    operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x35ba64e <handler::ha_optimize(THD*, HA_CHECK_OPT*)>, check_view=0, alter_info=0x7f64ac051ba8, need_to_acquire_shared_backup_lock=true) at /ci/src/sql/sql/sql_admin.cc:1115
#16 0x00000000038196c3 in Sql_cmd_optimize_table::execute (this=0x7f64ac0522c8, thd=0x7f64ac000d00) at /ci/src/sql/sql/sql_admin.cc:1559
#17 0x000000000325635f in mysql_execute_command (thd=0x7f64ac000d00, first_level=true) at /ci/src/sql/sql/sql_parse.cc:4703
#18 0x0000000003258dbb in mysql_parse (thd=0x7f64ac000d00, parser_state=0x7f66d46da450) at /ci/src/sql/sql/sql_parse.cc:5581
#19 0x000000000324d9df in dispatch_command (thd=0x7f64ac000d00, com_data=0x7f66d46dae00, command=COM_QUERY) at /ci/src/sql/sql/sql_parse.cc:1808
#20 0x000000000324bf54 in do_command (thd=0x7f64ac000d00) at /ci/src/sql/sql/sql_parse.cc:1301
#21 0x000000000340a8cb in handle_connection (arg=0xa9d66b0) at /ci/src/sql/sql/conn_handler/connection_handler_per_thread.cc:302
#22 0x00000000051da911 in pfs_spawn_thread (arg=0xad6b820) at /ci/src/sql/storage/perfschema/pfs.cc:2836
#23 0x00007f67b7c53e45 in start_thread () from /lib64/libpthread.so.0
#24 0x00007f67afe2ab3d in clone () from /lib64/libc.so.6
(gdb) f 18
#18 0x0000000003258dbb in mysql_parse (thd=0x7f64ac000d00, parser_state=0x7f66d46da450) at /ci/src/sql/sql/sql_parse.cc:5581
5581  /ci/src/sql/sql/sql_parse.cc: No such file or directory.
(gdb) p thd->m_query_string
$1 = {str = 0x7f64ac0510e8 "OPTIMIZE NO_WRITE_TO_BINLOG TABLE t3", length = 36}
(gdb) f 3
#3  0x00000000049e2bfd in row_log_table_apply_convert_mrec (trx=0x7f677c3fcc40, mrec=0x7f678122b004 "\002", index=0x7f64cc1340f8, offsets=0x7f64ac023aa8, log=0x7f64ac0ab168, heap=0x7f64ac05dcf8, trx_id=7563, error=0x7f66d46d4194)
    at /ci/src/sql/storage/innobase/row/row0log.cc:1405
1405  /ci/src/sql/storage/innobase/row/row0log.cc: No such file or directory.
(gdb) p new_col->mtype
$2 = 4
(gdb) p col->mtype
$3 = 12

How to repeat:
There is no case to reproduce the issue currently.

It is a occasionally produced issue, maybe because of the concurrent between OPTIMIZE TABLE and ALTER TABLE (alter column type in the statement).

Suggested fix:
Is the debug assert necessary here? or there is something wrong while we do the concurrency control between table rebuild and table alter?
[5 Sep 2019 3:33] dave do
another core stack
-----------------------

(gdb) bt
#0  0x00007f6da9dba417 in raise () from /lib64/libc.so.6
#1  0x00007f6da9dbbb08 in abort () from /lib64/libc.so.6
#2  0x0000000004b2f448 in ut_dbg_assertion_failed (expr=0x6849270 "!((new_col->prtype ^ col->prtype) & ~256)", file=0x68488a0 "/ci/src/sql/storage/innobase/row/row0log.cc", line=1408) at /ci/src/sql/storage/innobase/ut/ut0dbg.cc:92
#3  0x00000000049f9e41 in row_log_table_apply_convert_mrec (trx=0x7f6c48c59c40, mrec=0x7f6ac40f9004 "", index=0x7f69640346c8, offsets=0x7f6a00019398, log=0x7f6a000c55d8, heap=0x7f6a0003ceb8, trx_id=6870, error=0x7f6c43e44194)
    at /ci/src/sql/storage/innobase/row/row0log.cc:1408
#4  0x00000000049fa3b5 in row_log_table_apply_insert (thr=0x7f6a0004c4a0, mrec=0x7f6ac40f9004 "", offsets=0x7f6a00019398, offsets_heap=0x7f6a00040f88, heap=0x7f6a0003ceb8, dup=0x7f6c43e44710, trx_id=6870) at /ci/src/sql/storage/innobase/row/row0log.cc:1525
#5  0x00000000049fc3d5 in row_log_table_apply_op (thr=0x7f6a0004c4a0, trx_id_col=1, new_trx_id_col=1, dup=0x7f6c43e44710, error=0x7f6c43e4434c, offsets_heap=0x7f6a00040f88, heap=0x7f6a0003ceb8, mrec=0x7f6ac40f9004 "", mrec_end=0x7f6ac40f906e "", offsets=0x7f6a00019398)
    at /ci/src/sql/storage/innobase/row/row0log.cc:2210
#6  0x00000000049fdf7f in row_log_table_apply_ops (thr=0x7f6a0004c4a0, dup=0x7f6c43e44710, stage=0x7f6a000196c8) at /ci/src/sql/storage/innobase/row/row0log.cc:2743
#7  0x00000000049fe449 in row_log_table_apply (thr=0x7f6a0004c4a0, old_table=0x7f6964038d68, table=0x7f6a000779f0, stage=0x7f6a000196c8) at /ci/src/sql/storage/innobase/row/row0log.cc:2833
#8  0x0000000004879cec in commit_try_rebuild (ha_alter_info=0x7f6c43e46330, ctx=0x7f6a000304b8, altered_table=0x7f6a000779f0, old_table=0x7f6a0000eaa0, trx=0x7f6c48c59c40, table_name=0x7f699c04bc3d "t17")
    at /ci/src/sql/storage/innobase/handler/handler0alter.cc:6695
#9  0x0000000004880a52 in ha_innobase::commit_inplace_alter_table_impl<dd::Table> (this=0x7f6a00094b18, altered_table=0x7f6a000779f0, ha_alter_info=0x7f6c43e46330, commit=true, old_dd_tab=0x7f699c08d200, new_dd_tab=0x7f6a000adbe0)
    at /ci/src/sql/storage/innobase/handler/handler0alter.cc:7343
#10 0x000000000485e921 in ha_innobase::commit_inplace_alter_table (this=0x7f6a00094b18, altered_table=0x7f6a000779f0, ha_alter_info=0x7f6c43e46330, commit=true, old_dd_tab=0x7f699c08d200, new_dd_tab=0x7f6a000adbe0)
    at /ci/src/sql/storage/innobase/handler/handler0alter.cc:1317
#11 0x00000000035d0765 in handler::ha_commit_inplace_alter_table (this=0x7f6a00094b18, altered_table=0x7f6a000779f0, ha_alter_info=0x7f6c43e46330, commit=true, old_table_def=0x7f699c08d200, new_table_def=0x7f6a000adbe0) at /ci/src/sql/sql/handler.cc:4748
#12 0x000000000331e419 in mysql_inplace_alter_table (thd=0x7f6a00000d00, schema=..., new_schema=..., table_def=0x7f699c08d200, altered_table_def=0x7f6a000adbe0, table_list=0x7f6a000888f0, table=0x7f6a0000eaa0, altered_table=0x7f6a000779f0, 
    ha_alter_info=0x7f6c43e46330, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, alter_ctx=0x7f6c43e468e0, columns=..., fk_key_info=0x7f6a0002fe08, fk_key_count=0, fk_invalidator=0x7f6c43e45ab0) at /ci/src/sql/sql/sql_table.cc:12603
#13 0x0000000003329700 in mysql_alter_table (thd=0x7f6a00000d00, new_db=0x0, new_name=0x0, create_info=0x7f6c43e47c50, table_list=0x7f6a000888f0, alter_info=0x7f6c43e47d50) at /ci/src/sql/sql/sql_table.cc:16151
#14 0x000000000332dcf3 in mysql_recreate_table (thd=0x7f6a00000d00, table_list=0x7f6a000888f0, table_copy=false) at /ci/src/sql/sql/sql_table.cc:17365
#15 0x000000000382e611 in mysql_admin_table (thd=0x7f6a00000d00, tables=0x7f6a000888f0, check_opt=0x7f6a00003fb8, operator_name=0x5db97d8 "optimize", lock_type=TL_WRITE, open_for_modify=false, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, 
    operator_func=(int (handler::*)(handler * const, THD *, HA_CHECK_OPT *)) 0x35d02fa <handler::ha_optimize(THD*, HA_CHECK_OPT*)>, check_view=0, alter_info=0x7f6a00088788, need_to_acquire_shared_backup_lock=true) at /ci/src/sql/sql/sql_admin.cc:1115
#16 0x000000000382ff8f in Sql_cmd_optimize_table::execute (this=0x7f6a00088ea8, thd=0x7f6a00000d00) at /ci/src/sql/sql/sql_admin.cc:1559
#17 0x000000000326bf7f in mysql_execute_command (thd=0x7f6a00000d00, first_level=true) at /ci/src/sql/sql/sql_parse.cc:4703
#18 0x000000000326e9db in mysql_parse (thd=0x7f6a00000d00, parser_state=0x7f6c43e4a450) at /ci/src/sql/sql/sql_parse.cc:5581
#19 0x00000000032635ff in dispatch_command (thd=0x7f6a00000d00, com_data=0x7f6c43e4ae00, command=COM_QUERY) at /ci/src/sql/sql/sql_parse.cc:1808
#20 0x0000000003261b74 in do_command (thd=0x7f6a00000d00) at /ci/src/sql/sql/sql_parse.cc:1301
#21 0x0000000003420577 in handle_connection (arg=0xa0c4b30) at /ci/src/sql/sql/conn_handler/connection_handler_per_thread.cc:302
#22 0x0000000005207721 in pfs_spawn_thread (arg=0xa03c2b0) at /ci/src/sql/storage/perfschema/pfs.cc:2836
#23 0x00007f6db1ca5e45 in start_thread () from /lib64/libpthread.so.0
#24 0x00007f6da9e7db3d in clone () from /lib64/libc.so.6
(gdb) f 18
#18 0x000000000326e9db in mysql_parse (thd=0x7f6a00000d00, parser_state=0x7f6c43e4a450) at /ci/src/sql/sql/sql_parse.cc:5581
5581  /ci/src/sql/sql/sql_parse.cc: No such file or directory.
(gdb) p thd->m_query_string
$1 = {str = 0x7f6a00087cd8 "OPTIMIZE LOCAL TABLE t17", length = 24}
(gdb) f 3
#3  0x00000000049f9e41 in row_log_table_apply_convert_mrec (trx=0x7f6c48c59c40, mrec=0x7f6ac40f9004 "", index=0x7f69640346c8, offsets=0x7f6a00019398, log=0x7f6a000c55d8, heap=0x7f6a0003ceb8, trx_id=6870, error=0x7f6c43e44194)
    at /ci/src/sql/storage/innobase/row/row0log.cc:1408
1408  /ci/src/sql/storage/innobase/row/row0log.cc: No such file or directory.
(gdb) p new_col->prtype 
$2 = 16715791
(gdb) p col->prtype
$3 = 5443599
(gdb)
[5 Sep 2019 12:44] MySQL Verification Team
Hi Mr. do,

Thank you for your bug report.

I have analysed your stacktraces and concluded that you are using a debug build. So, why are you using a debug build and not a binary package from our site. You can download it from dev.mysql.com.

Next, we can not do anything without a repeatable test case. Hence, if you get a crash from a production binary every time you OPTIMIZE that table, then we need full contents of that table in the form of the mysqldump output.

Thanks in advance.
[6 Oct 2019 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".