Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1(EOL)
-
None
-
10.1.12
Description
|
Stack trace from 498a264d19f041c36d71e41a32c16ac40a014a3e |
10.1/sql/field.cc:4615: int Field_timestamp::store_TIME_with_warning(THD*, MYSQL_TIME*, const ErrConv*, int, bool): Assertion `is_stat_field || !table || (!table->write_set || bitmap_is_set(table->write_set, field_index) || bitmap_is_set(table->vcol_set, field_index))' failed.
|
150702 17:46:52 [ERROR] mysqld got signal 6 ;
|
|
|
#6 0x00007f23dc77f311 in *__GI___assert_fail (assertion=0x7f23dfaf0a30 "is_stat_field || !table || (!table->write_set || bitmap_is_set(table->write_set, field_index) || bitmap_is_set(table->vcol_set, field_index))", file=<optimized out>, line=4615, function=0x7f23dfaf45e0 "int Field_timestamp::store_TIME_with_warning(THD*, MYSQL_TIME*, const ErrConv*, int, bool)") at assert.c:81
|
#7 0x00007f23df304ffc in Field_timestamp::store_TIME_with_warning (this=0x7f23b6276b58, thd=0x7f23b604c070, l_time=0x7f23deacce30, str=0x7f23deacce60, was_cut=0, have_smth_to_conv=true) at 10.1/sql/field.cc:4615
|
#8 0x00007f23df3052c6 in Field_timestamp::store_time_dec (this=0x7f23b6276b58, ltime=0x7f23deacd0b0, dec=0) at 10.1/sql/field.cc:4676
|
#9 0x00007f23df31f86a in do_field_temporal (copy=0x7f23deacd280) at 10.1/sql/field_conv.cc:424
|
#10 0x00007f23df31eee0 in do_copy_null (copy=0x7f23deacd280) at 10.1/sql/field_conv.cc:243
|
#11 0x00007f23df43382c in unpack_row (rgi=0x7f23b6023800, table=0x7f23dbd8e470, colcnt=9, row_data=0x7f23b62d5df0 "r\376\001", cols=0x7f23b629d1e8, current_row_end=0x7f23b629d288, master_reclength=0x7f23b629d230, row_end=0x7f23b62d5ec6 "\245\245h4z\025") at 10.1/sql/rpl_record.cc:375
|
#12 0x00007f23df432587 in Rows_log_event::unpack_current_row (this=0x7f23b629d170, rgi=0x7f23b6023800) at 10.1/sql/log_event.h:4430
|
#13 0x00007f23df42f287 in Rows_log_event::find_row (this=0x7f23b629d170, rgi=0x7f23b6023800) at 10.1/sql/log_event.cc:11889
|
#14 0x00007f23df4304ec in Update_rows_log_event::do_exec_row (this=0x7f23b629d170, rgi=0x7f23b6023800) at 10.1/sql/log_event.cc:12386
|
#15 0x00007f23df42a8da in Rows_log_event::do_apply_event (this=0x7f23b629d170, rgi=0x7f23b6023800) at 10.1/sql/log_event.cc:9917
|
#16 0x00007f23df05030d in Log_event::apply_event (this=0x7f23b629d170, rgi=0x7f23b6023800) at 10.1/sql/log_event.h:1347
|
#17 0x00007f23df045cf6 in apply_event_and_update_pos (ev=0x7f23b629d170, thd=0x7f23b604c070, rgi=0x7f23b6023800, rpt=0x0) at 10.1/sql/slave.cc:3269
|
#18 0x00007f23df0465a3 in exec_relay_log_event (thd=0x7f23b604c070, rli=0x7f23ca088c20, serial_rgi=0x7f23b6023800) at 10.1/sql/slave.cc:3587
|
#19 0x00007f23df04988a in handle_slave_sql (arg=0x7f23ca087000) at 10.1/sql/slave.cc:4687
|
#20 0x00007f23de79ab50 in start_thread (arg=<optimized out>) at pthread_create.c:304
|
#21 0x00007f23dc82f95d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
|
To reproduce,
- bootstrap server 1 and server 2;
- unpack the attached binlog.tar.gz and put all mysql-bin.* files into the datadir for server 1;
- start server 1 with --log-bin=mysql-bin --server-id=1;
- start server 2 with --server-id=2;
- set up and start standard replication from server 1 to server 2;
- wait.
When slave SQL thread reaches mysql-bin.000237 pos 866, the slave crashes as above.
I have also attached mysql.log from the master in case you want to match the binlog with the general log.
Attachments
Activity
Similar crash with a testcase:
|
Stack trace from 10.1 commit d58a770201acae10bdae7e840db043368cb48ba0 |
#7 0x00007f052bbb5192 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x00007f052e35910b in Field_long::store (this=0x7f0515445280, nr=1000, unsigned_val=false) at 10.1/sql/field.cc:4058
|
#9 0x00007f052e3a18f6 in save_int_value_in_field (field=0x7f0515445280, nr=1000, null_value=false, unsigned_flag=false) at 10.1/sql/item.cc:5945
|
#10 0x00007f052e3a1954 in Item_int::save_in_field (this=0x7f05154ed4c8, field=0x7f0515445280, no_conversions=false) at 10.1/sql/item.cc:5951
|
#11 0x00007f052e3a84de in Item_trigger_field::set_value (this=0x7f05154ed550, thd=0x7f051543f070, it=0x7f05154ed6c0) at 10.1/sql/item.cc:8389
|
#12 0x00007f052e4cfb66 in Item_trigger_field::set_value (this=0x7f05154ed550, thd=0x7f051543f070, it=0x7f05154ed6c0) at 10.1/sql/item.h:4931
|
#13 0x00007f052e4cd567 in sp_instr_set_trigger_field::exec_core (this=0x7f05154ed688, thd=0x7f051543f070, nextp=0x7f052dacc1f0) at 10.1/sql/sp_head.cc:3234
|
#14 0x00007f052e4cc924 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7f05154ed6c8, thd=0x7f051543f070, nextp=0x7f052dacc1f0, open_tables=true, instr=0x7f05154ed688) at 10.1/sql/sp_head.cc:2916
|
#15 0x00007f052e4cd4d3 in sp_instr_set_trigger_field::execute (this=0x7f05154ed688, thd=0x7f051543f070, nextp=0x7f052dacc1f0) at 10.1/sql/sp_head.cc:3225
|
#16 0x00007f052e4c8ae9 in sp_head::execute (this=0x7f05154a3088, thd=0x7f051543f070, merge_da_on_success=false) at 10.1/sql/sp_head.cc:1317
|
#17 0x00007f052e4c962f in sp_head::execute_trigger (this=0x7f05154a3088, thd=0x7f051543f070, db_name=0x7f05154b97b8, table_name=0x7f05154b97c8, grant_info=0x7f05154b9bd8) at 10.1/sql/sp_head.cc:1646
|
#18 0x00007f052e2161a0 in Table_triggers_list::process_triggers (this=0x7f05154b9a88, thd=0x7f051543f070, event=TRG_EVENT_UPDATE, time_type=TRG_ACTION_BEFORE, old_row_is_record1=true) at 10.1/sql/sql_trigger.cc:2151
|
#19 0x00007f052e4855fe in Rows_log_event::process_triggers (this=0x7f05154a6230, event=TRG_EVENT_UPDATE, time_type=TRG_ACTION_BEFORE, old_row_is_record1=true) at 10.1/sql/log_event.cc:11357
|
#20 0x00007f052e488143 in Update_rows_log_event::do_exec_row (this=0x7f05154a6230, rgi=0x7f0515416800) at 10.1/sql/log_event.cc:12517
|
#21 0x00007f052e4822e6 in Rows_log_event::do_apply_event (this=0x7f05154a6230, rgi=0x7f0515416800) at 10.1/sql/log_event.cc:9987
|
#22 0x00007f052e0b4759 in Log_event::apply_event (this=0x7f05154a6230, rgi=0x7f0515416800) at 10.1/sql/log_event.h:1343
|
#23 0x00007f052e0aa512 in apply_event_and_update_pos (ev=0x7f05154a6230, thd=0x7f051543f070, rgi=0x7f0515416800, rpt=0x0) at 10.1/sql/slave.cc:3375
|
#24 0x00007f052e0aaf97 in exec_relay_log_event (thd=0x7f051543f070, rli=0x7f05267c9c20, serial_rgi=0x7f0515416800) at 10.1/sql/slave.cc:3705
|
#25 0x00007f052e0ae0bc in handle_slave_sql (arg=0x7f05267c8000) at 10.1/sql/slave.cc:4784
|
#26 0x00007f052e9737b0 in pfs_spawn_thread (arg=0x7f05161650f0) at 10.1/storage/perfschema/pfs.cc:1860
|
#27 0x00007f052c54ce9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
|
#28 0x00007f052bc79cbd in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
|
Test case |
--source include/master-slave.inc
|
--source include/have_binlog_format_row.inc
|
|
|
set binlog_row_image = MINIMAL;
|
create table t1 (pk int primary key, f int);
|
|
|
--sync_slave_with_master
|
create trigger tr before update on t1 for each row set new.f = 1000;
|
set global slave_run_triggers_for_rbr = YES;
|
|
|
--connection master
|
insert into t1 values (1,1),(2,2);
|
update t1 set pk=pk+10;
|
|
|
--sync_slave_with_master
|
The reason for the assertion failure is that the update statement for the minimal row image sets only the PK column in the write_set of the table to true. On the other hand, the trigger aims to update a different column. We must find a way to signal the store procedure that if we are during a trigger update, that the write set must not be taken into account.
Can you please review:
https://github.com/MariaDB/server/commit/de1fa4527663ffde05b43bbc2acd5ce0398f483a
For the record, buildbot tests pass.
https://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-vicentiu
cvicentiu, I'm not quite sure it's related to
MDEV-6877, but I can't check it because the binary log was created with binlog-row-image=minimal, so it does not work on a pre-MDEV-6877build.If it turns out it's unrelated, please reassign to Kristian or to me.