[MDEV-32628] Cryptic ERROR message & inconsistent behavior on incorrect SHOW BINLOG EVENTS FROM ... - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.4(EOL), 10.5, 10.6, 10.9(EOL), 10.10(EOL), 10.11, 11.0(EOL), 11.1(EOL), 11.2(EOL), 11.3(EOL), 11.4
Fix Version/s: 10.4.33, 10.5.24, 10.6.17, 10.11.7, 11.0.5, 11.1.4, 11.2.3
Component/s: Binary Protocol
Labels:
- affects-tests
- sporadic

Description

# mysqld options required for replay: --log-bin

SHOW BINLOG EVENTS FROM 500;

Leads to, on the client:

11.3.0 126157061b4376496c034a809ea4943e863d1465 (Optimized)
11.3.0-opt>SHOW BINLOG EVENTS FROM 500;
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error

Which is easy to understand and correct. However the error log shows, on optimized builds:

11.3.0 126157061b4376496c034a809ea4943e863d1465 (Optimized)
2023-10-31 16:00:27 5 [ERROR] Error in Log_event::read_log_event(): 'Event too big', data_len: 117440512, event_type: 0

Here there is no correlation between what actually happened (a harmless SQL statement failure) and the error shown in the error log (which looks like an important binlog failure & possible corruption).
The debug log shows:

11.3.0 126157061b4376496c034a809ea4943e863d1465 (Debug)

2023-10-31 15:58:56 5 [ERROR] Replication event checksum verification failed while reading from a log file

2023-10-31 15:58:56 5 [ERROR] Error in Log_event::read_log_event(): 'Replication event checksum verification failed while reading from a log file', data_len: 41, event_type: 0

10.4 Optimized shows the same output as debug in later versions:

10.4.32 e52777f1a4df20ffd3ae743b7b64f5e645090cd8 (Optimized)

2023-10-31 16:06:21 10 [ERROR] Replication event checksum verification failed while reading from a log file

2023-10-31 16:06:21 10 [ERROR] Error in Log_event::read_log_event(): 'Replication event checksum verification failed while reading from a log file', data_len: 41, event_type: 0

Which again looks severe but is harmless. It would be good if we can improve the output to show it was a harmless issue.

Attachments

Issue Links

relates to

MDEV-21839 Handle crazy offset to SHOW BINLOG EVENTS

Closed

Activity

Ascending order - Click to sort in descending order

Roel Van de Paar added a comment - 2023-10-31 05:15 - edited

There are some additional incosistency issues. When using a MTR testcase as follows:

--source include/have_binlog_format_mixed.inc

--error ER_ERROR_WHEN_EXECUTING_COMMAND

SHOW BINLOG EVENTS FROM 500;

No error shows up in the mariadbd (as started by MTR) error log. Potentially this is due to some MTR internal check mechanism given the MTR output:

11.3.0 126157061b4376496c034a809ea4943e863d1465
ERROR HY000: Error when executing command SHOW BINLOG EVENTS: Invalid pos specified. Requested from pos:500 is greater than actual file size:329

However, when using mtr --start-and-exit we see the same error:

./mtr 1st --start-and-exit --mysqld=--log-bin && ../bin/mariadb -uroot -S./var/tmp/mysqld.1.sock test

11.3.0 126157061b4376496c034a809ea4943e863d1465
MariaDB [test]> SHOW BINLOG EVENTS FROM 500;
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Invalid pos specified. Requested from pos:500 is greater than actual file size:329

As this is the client being used directly, it is odd that the ERROR, whilst the same number is different from the

11.3.0 126157061b4376496c034a809ea4943e863d1465
11.3.0-opt>SHOW BINLOG EVENTS FROM 500;
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error

Seen when using the client directly (without MTR). This could be an additional shortcoming in MTR, especially as here too the error never makes it to the error log, which could mean some failures are being missed in MTR.

Roel Van de Paar added a comment - 2023-10-31 05:15 - edited There are some additional incosistency issues. When using a MTR testcase as follows: --source include/have_binlog_format_mixed.inc --error ER_ERROR_WHEN_EXECUTING_COMMAND SHOW BINLOG EVENTS FROM 500; No error shows up in the mariadbd (as started by MTR) error log. Potentially this is due to some MTR internal check mechanism given the MTR output: 11.3.0 126157061b4376496c034a809ea4943e863d1465 ERROR HY000: Error when executing command SHOW BINLOG EVENTS: Invalid pos specified. Requested from pos:500 is greater than actual file size:329 However, when using mtr --start-and-exit we see the same error: . /mtr 1st --start-and- exit --mysqld=--log-bin && .. /bin/mariadb -uroot -S. /var/tmp/mysqld .1.sock test 11.3.0 126157061b4376496c034a809ea4943e863d1465 MariaDB [test]> SHOW BINLOG EVENTS FROM 500; ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Invalid pos specified. Requested from pos:500 is greater than actual file size:329 As this is the client being used directly, it is odd that the ERROR, whilst the same number is different from the 11.3.0 126157061b4376496c034a809ea4943e863d1465 11.3.0-opt>SHOW BINLOG EVENTS FROM 500; ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error Seen when using the client directly (without MTR). This could be an additional shortcoming in MTR, especially as here too the error never makes it to the error log, which could mean some failures are being missed in MTR.

Roel Van de Paar added a comment - 2023-11-02 05:16

There is another error which can be reproduced with this testcase at the CLI:

# mysqld options required for replay: --log-bin

RESET MASTER;

DROP TABLE IF EXISTS t1;

CREATE TABLE t1 (c INT) ENGINE=MEMORY;

CREATE TABLE t2 (d INT) ENGINE=MyISAM;

SHOW BINLOG EVENTS FROM 504;

Leads to:

11.3.0 76e20f00772148fa928c6c6e42401f38ca89abf0 (Optimized or Debug)
11.3.0-opt>SHOW BINLOG EVENTS FROM 504;
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error

The error log in this case reads:

11.3.0 76e20f00772148fa928c6c6e42401f38ca89abf0 (Optimized or Debug)
2023-11-02 16:03:58 5 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 139008, event_type: 0

During testing there are also many of other event types that are seen, as can be seen from this non-exhaustive list sorted by event_type:

2023-10-29  1:55:38 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 10496, event_type: 0

2023-10-29  9:50:33 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 524288, event_type: 0

2023-10-28  4:06:03 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 655360, event_type: 0

2023-10-30 12:39:53 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 196608, event_type: 0

2023-10-27  6:26:11 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 262144, event_type: 0

2023-10-29 11:27:56 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 2

2023-10-28  5:48:07 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 4

2023-10-30 18:47:43 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 4

2023-10-26 23:16:55 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 6

2023-10-29  5:26:36 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 8

2023-10-28 22:19:31 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 11

2023-10-26 23:53:50 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 12

2023-10-28 10:59:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 12

2023-10-27 23:03:24 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 107077, event_type: 16

2023-10-27  6:34:39 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 16

2023-10-30  8:31:54 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 36

2023-10-27 10:06:02 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 38

2023-10-30 13:22:50 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 45

2023-10-30 13:22:37 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 45

2023-10-28  8:26:47 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 55

2023-10-28  2:44:12 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 61

2023-10-30  6:31:11 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 63

2023-10-27  8:49:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 66

2023-10-28 13:22:02 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 67

2023-10-30  2:58:10 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 77

2023-10-27 17:36:41 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 79

2023-10-27 19:07:00 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 80

2023-10-26 23:37:28 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 84

2023-10-28  8:24:48 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 85

2023-10-27  6:08:09 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 90

2023-10-27  6:23:49 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 93

2023-10-29 22:02:59 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 101

2023-10-27  8:00:49 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 110

2023-10-28 21:40:10 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 112

2023-10-30  5:36:38 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 116

2023-10-27 22:38:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 120

2023-10-30  7:15:34 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 122

2023-10-29  9:50:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 135

2023-10-26 22:55:35 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 148

2023-10-30 20:08:40 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 162

2023-10-29 21:54:10 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 163

2023-10-26 22:51:52 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 164

2023-10-26 22:46:34 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 166

2023-10-28  3:33:43 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 177

2023-10-29 22:27:51 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 184

2023-10-30  9:08:39 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 186

2023-10-29 19:32:05 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 196

2023-10-29 18:14:05 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 215

2023-10-29  9:31:13 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 219

2023-10-29 22:57:07 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 226

2023-10-27  7:04:02 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 232

2023-10-27 14:51:53 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 173

2023-10-28 15:23:21 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 149

2023-10-27 14:33:26 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 196

2023-10-29 19:25:35 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 196

2023-10-27  9:49:58 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 215

2023-10-28  2:34:42 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 219

2023-10-30  5:30:14 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 221

2023-10-28 11:57:23 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 232

2023-10-29 10:20:23 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 244

2023-10-28  7:55:25 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 245

2023-10-28 15:25:28 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 254

Roel Van de Paar added a comment - 2023-11-02 05:16 There is another error which can be reproduced with this testcase at the CLI: # mysqld options required for replay: --log-bin RESET MASTER; DROP TABLE IF EXISTS t1; CREATE TABLE t1 (c INT ) ENGINE=MEMORY; CREATE TABLE t2 (d INT ) ENGINE=MyISAM; SHOW BINLOG EVENTS FROM 504; Leads to: 11.3.0 76e20f00772148fa928c6c6e42401f38ca89abf0 (Optimized or Debug) 11.3.0-opt>SHOW BINLOG EVENTS FROM 504; ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error The error log in this case reads: 11.3.0 76e20f00772148fa928c6c6e42401f38ca89abf0 (Optimized or Debug) 2023-11-02 16:03:58 5 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 139008, event_type: 0 During testing there are also many of other event types that are seen, as can be seen from this non-exhaustive list sorted by event_type: 2023-10-29 1:55:38 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 10496, event_type: 0 2023-10-29 9:50:33 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 524288, event_type: 0 2023-10-28 4:06:03 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 655360, event_type: 0 2023-10-30 12:39:53 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 196608, event_type: 0 2023-10-27 6:26:11 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 262144, event_type: 0 2023-10-29 11:27:56 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 2 2023-10-28 5:48:07 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 4 2023-10-30 18:47:43 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 4 2023-10-26 23:16:55 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 6 2023-10-29 5:26:36 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 8 2023-10-28 22:19:31 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 11 2023-10-26 23:53:50 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 12 2023-10-28 10:59:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 12 2023-10-27 23:03:24 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 107077, event_type: 16 2023-10-27 6:34:39 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 16 2023-10-30 8:31:54 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 36 2023-10-27 10:06:02 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 38 2023-10-30 13:22:50 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 45 2023-10-30 13:22:37 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 45 2023-10-28 8:26:47 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 55 2023-10-28 2:44:12 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 61 2023-10-30 6:31:11 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 63 2023-10-27 8:49:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 66 2023-10-28 13:22:02 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 67 2023-10-30 2:58:10 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 77 2023-10-27 17:36:41 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 79 2023-10-27 19:07:00 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 80 2023-10-26 23:37:28 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 84 2023-10-28 8:24:48 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 85 2023-10-27 6:08:09 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 90 2023-10-27 6:23:49 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 93 2023-10-29 22:02:59 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 101 2023-10-27 8:00:49 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 110 2023-10-28 21:40:10 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 112 2023-10-30 5:36:38 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 116 2023-10-27 22:38:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 120 2023-10-30 7:15:34 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 122 2023-10-29 9:50:01 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 135 2023-10-26 22:55:35 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 148 2023-10-30 20:08:40 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934207, event_type: 162 2023-10-29 21:54:10 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 163 2023-10-26 22:51:52 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 164 2023-10-26 22:46:34 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 166 2023-10-28 3:33:43 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 177 2023-10-29 22:27:51 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 184 2023-10-30 9:08:39 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 186 2023-10-29 19:32:05 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 196 2023-10-29 18:14:05 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 215 2023-10-29 9:31:13 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 219 2023-10-29 22:57:07 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 226 2023-10-27 7:04:02 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 232 2023-10-27 14:51:53 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 173 2023-10-28 15:23:21 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 149 2023-10-27 14:33:26 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 196 2023-10-29 19:25:35 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 196 2023-10-27 9:49:58 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934202, event_type: 215 2023-10-28 2:34:42 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934203, event_type: 219 2023-10-30 5:30:14 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934206, event_type: 221 2023-10-28 11:57:23 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 232 2023-10-29 10:20:23 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934205, event_type: 244 2023-10-28 7:55:25 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 245 2023-10-28 15:25:28 8 [ERROR] Error in Log_event::read_log_event(): 'Event truncated', data_len: 16934204, event_type: 254

Roel Van de Paar added a comment - 2023-11-02 05:18

Some of these are confirmed sporadic, or are hard to reproduce, or require a specific setup (for example client with direct copy/paste versus any other automated method), etc.

Roel Van de Paar added a comment - 2023-11-02 05:18 Some of these are confirmed sporadic, or are hard to reproduce, or require a specific setup (for example client with direct copy/paste versus any other automated method), etc.

Andrei Elkin added a comment - 2023-11-02 08:35 - edited

roel, the matter of the report belongs to ~~MDEV-21839~~. That fixes idea is still to treat the provided offset as the beginning of an event, try to
find its checksum and verify the event against it. Yet when offset is "super- crazy" so that its checksum field can't be reached, Event too big is un-avoidable.
The error message of course can be improved to suggest about a possibly incorrect offset.

Andrei Elkin added a comment - 2023-11-02 08:35 - edited roel , the matter of the report belongs to MDEV-21839 . That fixes idea is still to treat the provided offset as the beginning of an event, try to find its checksum and verify the event against it. Yet when offset is "super- crazy" so that its checksum field can't be reached, Event too big is un-avoidable. The error message of course can be improved to suggest about a possibly incorrect offset.

Kristian Nielsen added a comment - 2023-11-15 16:29

Note: Now that gtid indexes (~~MDEV-4991~~) will be in 11.4, it is possible to fix this better.
The user-specified offset can be looked up in the index to check that it refers to the start of an event; and a specific error can be given for offsets that are invalid (point into the middle of an event).

Kristian Nielsen added a comment - 2023-11-15 16:29 Note: Now that gtid indexes ( MDEV-4991 ) will be in 11.4, it is possible to fix this better. The user-specified offset can be looked up in the index to check that it refers to the start of an event; and a specific error can be given for offsets that are invalid (point into the middle of an event).

Brandon Nesterenko added a comment - 2023-11-15 16:30

Hi Andrei,

This is ready for review: PR-2844

Brandon Nesterenko added a comment - 2023-11-15 16:30 Hi Andrei, This is ready for review: PR-2844

Andrei Elkin added a comment - 2023-11-16 17:42

Approved on GH.

Andrei Elkin added a comment - 2023-11-16 17:42 Approved on GH.

Brandon Nesterenko added a comment - 2023-11-17 19:15

Pushed into 10.4 as c42aadc3.

Merge conflicts observed in 10.6, 11.0, and 11.2 with resolutions in the respective branches:

Brandon Nesterenko added a comment - 2023-11-17 19:15 Pushed into 10.4 as c42aadc3 . Merge conflicts observed in 10.6, 11.0, and 11.2 with resolutions in the respective branches: bb-10.6-MDEV-32628-mergefix bb-11.0-MDEV-32628-mergefix bb-11.2-MDEV-32628-mergefix

People

Assignee:: Brandon Nesterenko

Reporter:: Roel Van de Paar

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2023-10-31 05:08

Updated:: 2023-12-15 19:59

Resolved:: 2023-11-17 19:15

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server