Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-11319

mysqlbinlog crashes or fails with out of memory while reading some encrypted binlogs

    XMLWordPrintable

    Details

      Description

      Attached are two seemingly identical (apart from timestamps) binary logs produced by consequent executions of the test below. However, mysqlbinlog works all right with binlog.good (of course, it cannot read it, but it produced the reasonable enough error messages

      # at 249
      # Encryption scheme: 1, key_version: 1, nonce: 7179d38d2d33034f33ac6998
      # The rest of the binlog is encrypted!
      # at 285
      #880514 17:47:03 server id 2601813764  end_log_pos 1816577002 	Ignorable
      # Ignorable event type 75 (Unknown)
      # at 310
      /*!50521 SET skip_replication=1*//*!*/;
      #871003  0:56:29 server id 1537441096  end_log_pos 3162602611 	Ignorable
      # Ignorable event type 94 (Unknown)
      # at 350
      #750404 23:13:24 server id 3367812640  end_log_pos 3306705717 	Ignorable
      # Ignorable event type 107 (Unknown)
      ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 172, event_type: 198
      ERROR: Could not read entry at offset 388: Error in log format or read error.
      

      while with binlog.bad, a a release mysqlbinlog fails with

      bin/mysqlbinlog: Out of memory (Needed 4294967272 bytes)
      ERROR: Error in Log_event::read_log_event(): 'Found invalid event in binary log', data_len: 25, event_type: 23
      ERROR: Could not read entry at offset 285: Error in log format or read error.
      

      and debug crashes:

      10.1 bccd0b5e0e debug

      #0  memset () at ../sysdeps/x86_64/memset.S:93
      #1  0x00007fed4410d4d2 in sf_malloc (size=18446744073709551592, my_flags=16) at /data/src/10.1/mysys/safemalloc.c:165
      #2  0x00007fed440fce9d in my_malloc (size=18446744073709551592, my_flags=16) at /data/src/10.1/mysys/my_malloc.c:100
      #3  0x00007fed4409b6ad in Rows_log_event::Rows_log_event (this=0x7fed4472c070, buf=0x7fed4472bf50 "kA\003\232\027\371\355\305\334\031", event_len=25, description_event=0x7fed4472c580) at /data/src/10.1/sql/log_event.cc:9525
      #4  0x00007fed4409ca60 in Write_rows_log_event::Write_rows_log_event (this=0x7fed4472c070, buf=0x7fed4472bf50 "kA\003\232\027\371\355\305\334\031", event_len=25, description_event=0x7fed4472c580) at /data/src/10.1/sql/log_event.cc:11295
      #5  0x00007fed440903eb in Log_event::read_log_event (buf=0x7fed4472bf50 "kA\003\232\027\371\355\305\334\031", event_len=25, error=0x7ffd96c75a50, fdle=0x7fed4472c580, crc_check=0 '\000') at /data/src/10.1/sql/log_event.cc:1726
      #6  0x00007fed4408faf3 in Log_event::read_log_event (file=0x7ffd96c75b10, log_lock=0x0, fdle=0x7fed4472c580, crc_check=0 '\000') at /data/src/10.1/sql/log_event.cc:1507
      #7  0x00007fed440874bb in dump_local_log_entries (print_event_info=0x7ffd96c76cd0, logname=0x7ffd96c795cc "/data/tmp/binlog.bad") at /data/src/10.1/client/mysqlbinlog.cc:2597
      #8  0x00007fed44085b47 in dump_log_entries (logname=0x7ffd96c795cc "/data/tmp/binlog.bad") at /data/src/10.1/client/mysqlbinlog.cc:1848
      #9  0x00007fed44087ac5 in main (argc=0, argv=0x7fed44725cd0) at /data/src/10.1/client/mysqlbinlog.cc:2780
      

      # ATTENTION:
      # To be run with --mysqld=--encrypt-binlog --mysqld=--plugin-load-add=file_key_management --mysqld=--file-key-management-filename=`pwd`/std_data/keys.txt --repeat=100
      #
       
      --source include/have_binlog_format_mixed.inc
       
      CREATE TABLE table1_to_encrypt (
        pk INT AUTO_INCREMENT PRIMARY KEY,
        ts TIMESTAMP NULL,
        b BLOB
      ) ENGINE=MyISAM; 
       
      INSERT INTO table1_to_encrypt VALUES (NULL,NOW(),'data_to_encrypt');
      INSERT INTO table1_to_encrypt SELECT NULL,NOW(),b FROM table1_to_encrypt;
      FLUSH BINARY LOGS;
      SET binlog_format=ROW;
      INSERT INTO table1_to_encrypt SELECT NULL,NOW(),b FROM table1_to_encrypt;
      INSERT INTO table1_to_encrypt SELECT NULL,NOW(),b FROM table1_to_encrypt;
       
      --let $datadir= `SELECT @@datadir`
       
      FLUSH BINARY LOGS;
      --error 1
      --exec $MYSQL_BINLOG $datadir/master-bin.000001
      

      NOTE: there is no special test for this in binlog_encryption yet, because the failure appears to be sporadic, and thus the test would be non-deterministic. When the root cause of the problem becomes known, hopefully it will be possible to create a proper test.

        Attachments

          Activity

            People

            Assignee:
            serg Sergei Golubchik
            Reporter:
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Git Integration