[MDEV-27296] Assertion `((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && wsrep_emulate_bin_log) || mysql_bin_log.is_open()' failed Created: 2021-12-17  Updated: 2023-12-05

Status: Stalled
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Andrei Elkin
Resolution: Unresolved Votes: 0
Labels: debug

Attachments: File jan.cnf     File jan.test    

 Description   

# mysqld options required for replay: --log-bin --sql_mode= 
CREATE TABLE t (a DATE) ENGINE=MEMORY;
INSERT DELAYED INTO t VALUES (now());
RESET MASTER TO 2147483648;
INSERT DELAYED INTO t (a) VALUES (now());
SELECT 1;

10.8.0 1e8bcbd0a0bfa07052e9458830672ea215c8664a (Debug)

mysqld: /test/10.8_dbg/sql/log.cc:1627: void binlog_trans_log_savepos(THD*, my_off_t*): Assertion `((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && wsrep_emulate_bin_log) || mysql_bin_log.is_open()' failed.

10.8.0 1e8bcbd0a0bfa07052e9458830672ea215c8664a (Debug)

Core was generated by `/test/MD091221-mariadb-10.8.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x1538204a0700 (LWP 992309))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000153823104859 in __GI_abort () at abort.c:79
#2  0x0000153823104729 in __assert_fail_base (fmt=0x15382329a588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55a2a7647d88 "((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && wsrep_emulate_bin_log) || mysql_bin_log.is_open()", file=0x55a2a76465e4 "/test/10.8_dbg/sql/log.cc", line=1627, function=<optimized out>) at assert.c:92
#3  0x0000153823115f36 in __GI___assert_fail (assertion=assertion@entry=0x55a2a7647d88 "((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && wsrep_emulate_bin_log) || mysql_bin_log.is_open()", file=file@entry=0x55a2a76465e4 "/test/10.8_dbg/sql/log.cc", line=line@entry=1627, function=function@entry=0x55a2a7647d10 "void binlog_trans_log_savepos(THD*, my_off_t*)") at assert.c:101
#4  0x000055a2a6c14e6f in binlog_trans_log_savepos (thd=thd@entry=0x1537c8024758, pos=pos@entry=0x15382049f4e8) at /test/10.8_dbg/sql/log.h:324
#5  0x000055a2a6c1504c in THD::binlog_set_stmt_begin (this=this@entry=0x1537c8024758) at /test/10.8_dbg/sql/log.cc:5880
#6  0x000055a2a6c1514a in THD::binlog_start_trans_and_stmt (this=this@entry=0x1537c8024758) at /test/10.8_dbg/sql/log.cc:5795
#7  0x000055a2a6c33b9c in THD::binlog_write_table_maps (this=this@entry=0x1537c8024758) at /test/10.8_dbg/sql/log.cc:5966
#8  0x000055a2a6ac2e05 in handler::binlog_log_row (this=this@entry=0x1537cc0047c0, table=0x1537cc003ee8, before_record=before_record@entry=0x0, after_record=after_record@entry=0x1537cc004338 "\375\221\313\017", '\245' <repeats 12 times>, "XC", log_func=log_func@entry=0x55a2a6acb0d9 <Write_rows_log_event::binlog_row_logging_function(THD*, TABLE*, bool, unsigned char const*, unsigned char const*)>) at /test/10.8_dbg/sql/handler.cc:6994
#9  0x000055a2a6ac4cf8 in handler::ha_write_row (this=0x1537cc0047c0, buf=0x1537cc004338 "\375\221\313\017", '\245' <repeats 12 times>, "XC") at /test/10.8_dbg/sql/handler.cc:7526
#10 0x000055a2a6764c8f in write_record (thd=thd@entry=0x1537c8024758, table=0x1537cc003ee8, info=info@entry=0x1537c802b4f8, sink=sink@entry=0x0) at /test/10.8_dbg/sql/sql_insert.cc:2156
#11 0x000055a2a6767774 in Delayed_insert::handle_inserts (this=this@entry=0x1537c8024738) at /test/10.8_dbg/sql/sql_insert.cc:3597
#12 0x000055a2a67691ed in handle_delayed_insert (arg=arg@entry=0x1537c8024738) at /test/10.8_dbg/sql/sql_insert.cc:3337
#13 0x000055a2a6dafde6 in pfs_spawn_thread (arg=0x1537c8030c78) at /test/10.8_dbg/storage/perfschema/pfs.cc:2201
#14 0x0000153823612609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x0000153823201293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.2.41 (dbg), 10.3.32 (dbg), 10.4.22 (dbg), 10.5.13 (dbg), 10.6.5 (dbg), 10.7.1 (dbg), 10.8.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.41 (opt), 10.3.32 (opt), 10.4.22 (opt), 10.5.13 (opt), 10.6.5 (opt), 10.7.1 (opt), 10.8.0 (opt)



 Comments   
Comment by Jan Lindström [ 2023-04-14 ]

Elkin I can reproduce this using normal async replication. Some info from error log:

2023-04-14  8:58:44 9 [ERROR] Log filename extension number exhausted: 2147483647. Please fix this by archiving old logs and updating the index files.
2023-04-14  8:58:44 9 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
2023-04-14  8:58:44 9 [ERROR] MYSQL_BIN_LOG::open failed to generate new file name.
2023-04-14  8:58:44 9 [ERROR] Could not use master-bin for logging (error 11). Turning logging off for the whole duration of the MariaDB server process. To turn it on again: fix the cause, shutdown the MariaDB server and restart it.
mariadbd: /home/jan/work/mariadb/10.8/sql/log.cc:1743: void binlog_trans_log_savepos(THD*, my_off_t*): Assertion `((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && wsrep_emulate_bin_log) || mysql_bin_log.is_open()' failed.

Comment by Andrei Elkin [ 2023-04-18 ]

janlindstrom moi. I am at the critical bugs review/fixing phase for the next 3-4 days. Let me respond with analysis after that. Cheers!

Comment by Julien Fritsch [ 2023-12-05 ]

Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

Comment by JiraAutomate [ 2023-12-05 ]

Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

Generated at Thu Feb 08 09:51:50 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.