[MDEV-29078] For old binary logs explicit_defaults_for_timestamp presumed to be OFF, server value ignored Created: 2022-07-10  Updated: 2022-09-07  Resolved: 2022-08-02

Status: Closed
Project: MariaDB Server
Component/s: Replication, Variables
Affects Version/s: 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.5.17, 10.6.9, 10.7.5, 10.8.4, 10.9.2

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: None

Attachments: File old-master-bin.000001    
Issue Links:
Problem/Incident
is caused by MDEV-28632 Change default of explicit_defaults_f... Closed

 Description   

Before MDEV-28632, the server uses its own value of explicit_defaults_for_timestamp while replaying/replicating binary logs.

Now it expects to find explicit_defaults_for_timestamp in the binary log, which is good; but when it's not there (the log is created by a server which doesn't yet have this functionality), it apparently falls back to "always OFF".

While it will work for the vast majority of old masters (those which have the default explicit_defaults_for_timestamp=off), it will make OM => NS replication impossible for those remaining ones which have non-default explicit_defaults_for_timestamp=on already.

The other option would be to fall back to the value configured on the slave instead. It will require an additional action from users with the default OFF on the old master, but it will keep the replication configurable for those who have ON on the master.

So, it is a judgement call which needs to be thought through and at least documented explicitly.

MySQL seems to use the server value in such case.

An example of the old log is attached for convenience (naturally it is easy to create by any existing server). It was produced on a 10.6.8 server started with explicit_defaults_for_timestamp=on and binlog_format=row. A table with two timestamps was created

#220710 21:26:03 server id 101  end_log_pos 534 CRC32 0x742afba6 	GTID 0-101-2 ddl
/*!100001 SET @@session.gtid_seq_no=2*//*!*/;
# at 534
#220710 21:26:03 server id 101  end_log_pos 653 CRC32 0x766a78ae 	Query	thread_id=6	exec_time=0	error_code=0	xid=6
use `test`/*!*/;
SET TIMESTAMP=1657477563/*!*/;
create table t (t1 timestamp, t2 timestamp)
/*!*/;
# at 653

and a (NULL,NULL) row was inserted.

#220710 21:26:10 server id 101  end_log_pos 750 CRC32 0xba62832c 	Annotate_rows:
#Q> insert into t values (null,null)
#220710 21:26:10 server id 101  end_log_pos 797 CRC32 0x5258822f 	Table_map: `test`.`t` mapped to number 18
# at 797
#220710 21:26:10 server id 101  end_log_pos 831 CRC32 0x957e2b6f 	Write_rows: table id 18 flags: STMT_END_F
### INSERT INTO `test`.`t`
### SET
###   @1=NULL
###   @2=NULL
# Number of rows: 1

On the original server the result is a table with nullable columns and NULL values (as the row event also demonstrates),

10.6.8

MariaDB [test]> show create table t \G
*************************** 1. row ***************************
       Table: t
Create Table: CREATE TABLE `t` (
  `t1` timestamp NULL DEFAULT NULL,
  `t2` timestamp NULL DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=latin1
1 row in set (0.000 sec)
 
MariaDB [test]> select * from t;
+------+------+
| t1   | t2   |
+------+------+
| NULL | NULL |
+------+------+
1 row in set (0.001 sec)

while on the preview server started with the new default explicit_defaults_for_timestamp=on, after replaying the log it is

bb-10.10-MDEV-28632 c4407143a2

MariaDB [test]> show create table t \G
*************************** 1. row ***************************
       Table: t
Create Table: CREATE TABLE `t` (
  `t1` timestamp NOT NULL DEFAULT current_timestamp() ON UPDATE current_timestamp(),
  `t2` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00'
) ENGINE=InnoDB DEFAULT CHARSET=latin1
1 row in set (0.000 sec)
 
MariaDB [test]> select * from t;
+---------------------+---------------------+
| t1                  | t2                  |
+---------------------+---------------------+
| 2022-07-10 21:26:10 | 0000-00-00 00:00:00 |
+---------------------+---------------------+
1 row in set (0.001 sec)



 Comments   
Comment by Sergei Golubchik [ 2022-07-23 ]

Elkin, please, take a look at commits https://github.com/MariaDB/server/commit/e19254ef90f and https://github.com/MariaDB/server/commit/f852b1b153a

Comment by Andrei Elkin [ 2022-07-26 ]

I pushed a "review" commit into bb-10.10-MDEV-28632-review that covers two findings.

Comment by Sergei Golubchik [ 2022-07-27 ]

Applied, slightly modified. Added a test case.
New commit: 65df4654d7b

Comment by Andrei Elkin [ 2022-07-28 ]

That's

modified   sql/log_event_client.cc
@@ -1887,6 +1887,7 @@ bool Query_log_event::print_query_header(IO_CACHE* file,
     if (unlikely(tmp)) /* some bits have changed */
     {
       bool need_comma= 0;
+      ulonglong mask= glob_description_event->options_written_to_bin_log;
       if (my_b_write_string(file, "SET ") ||
           print_set_option(file, tmp, OPTION_NO_FOREIGN_KEY_CHECKS, ~flags2,
                            "@@session.foreign_key_checks", &need_comma)||
@@ -1898,10 +1899,11 @@ bool Query_log_event::print_query_header(IO_CACHE* file,
                            "@@session.autocommit", &need_comma) ||
           print_set_option(file, tmp, OPTION_NO_CHECK_CONSTRAINT_CHECKS, ~flags2,
                            "@@session.check_constraint_checks", &need_comma) ||
-          print_set_option(file, tmp, OPTION_IF_EXISTS, flags2,
-                           "@@session.sql_if_exists", &need_comma)||
-          print_set_option(file, tmp, OPTION_EXPLICIT_DEF_TIMESTAMP, flags2,
-                           "@@session.explicit_defaults_for_timestamp", &need_comma)||
+          print_set_option(file, tmp, mask & OPTION_IF_EXISTS, flags2,

even nicer! Thanks for the replication contribution

Generated at Thu Feb 08 10:05:43 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.