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

The table mysql.general_log is not protected during backup

    XMLWordPrintable

Details

    Description

      The table mysql.general_log may easily become corrupted during a backup, because writes to the table are not blocked by the very statements that are supposed to make the server safe to back up.

      Here is a test case with the BACKUP STAGE block_commit of MDEV-5336:

      SET GLOBAL log_output='TABLE',general_log=1;
      BACKUP STAGE start;
      BACKUP STAGE block_commit;
      --connect con1, localhost, root
      SET GLOBAL general_log=0;
      --disconnect con1
      --connection default
      UNLOCK TABLES;
      

      I was expecting the SET GLOBAL statement of con1 to mark the mysql.general_log table as dirty. But in fact it already was the client connection that caused it:

      10.11 fe5829a1214bcb2e4323d3fb826bf607e1059ef5

      (rr) bt
      #0  write_meta_file (meta_file=22, rows=2, dirty=dirty@entry=true) at /mariadb/10.11/storage/csv/ha_tina.cc:364
      #1  0x000056513596c463 in ha_tina::init_tina_writer (this=this@entry=0x7fb8c801d520) at /mariadb/10.11/storage/csv/ha_tina.cc:414
      #2  0x000056513596d424 in ha_tina::write_row (this=0x7fb8c801d520, buf=<optimized out>) at /mariadb/10.11/storage/csv/ha_tina.cc:1036
      #3  0x000056513576d161 in handler::ha_write_row (this=0x7fb8c801d520, buf=0x7fb8c801d0a0 "f\331c\223\b-\034\025") at /mariadb/10.11/sql/handler.cc:7751
      #4  0x00005651358441e2 in Log_to_csv_event_handler::log_general (this=<optimized out>, thd=0x7fb8c8002758, event_time=..., user_host=0x7fb8e7ffd9c0 "[root] @ localhost []", user_host_len=21, thread_id_arg=5, command_type=0x565135f2f826 "Connect", command_type_len=7, sql_text=0x7fb8e7ffdc10 "root@localhost on  using Socket", sql_text_len=31, client_cs=0x56513678c200 <my_charset_latin1>) at /mariadb/10.11/sql/log.cc:921
      #5  0x0000565135845ff7 in LOGGER::general_log_write (this=this@entry=0x56513685d420 <logger>, thd=thd@entry=0x7fb8c8002758, command=command@entry=COM_CONNECT, query=query@entry=0x7fb8e7ffdc10 "root@localhost on  using Socket", query_length=31) at /mariadb/10.11/sql/log.cc:1507
      #6  0x000056513584606b in LOGGER::general_log_print (this=this@entry=0x56513685d420 <logger>, thd=thd@entry=0x7fb8c8002758, command=command@entry=COM_CONNECT, format=format@entry=0x565135edb762 "%s@%s on %s using %s", args=args@entry=0x7fb8e7ffe048) at /mariadb/10.11/sql/log.cc:1532
      #7  0x0000565135846161 in general_log_print (thd=thd@entry=0x7fb8c8002758, command=command@entry=COM_CONNECT, format=format@entry=0x565135edb762 "%s@%s on %s using %s") at /mariadb/10.11/sql/log.cc:7141
      #8  0x00005651354835ca in acl_authenticate (thd=thd@entry=0x7fb8c8002758, com_change_user_pkt_len=com_change_user_pkt_len@entry=0) at /mariadb/10.11/sql/sql_acl.cc:14603
      #9  0x0000565135628959 in check_connection (thd=thd@entry=0x7fb8c8002758) at /mariadb/10.11/sql/sql_connect.cc:1083
      #10 0x0000565135628c55 in login_connection (thd=thd@entry=0x7fb8c8002758) at /mariadb/10.11/sql/sql_connect.cc:1149
      #11 0x0000565135628ffe in thd_prepare_connection (thd=0x7fb8c8002758) at /mariadb/10.11/sql/sql_connect.cc:1333
      #12 0x0000565135629464 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5651528e8d08, put_in_cache=put_in_cache@entry=true) at /mariadb/10.11/sql/sql_connect.cc:1407
      #13 0x0000565135629571 in handle_one_connection (arg=0x5651528e8d08) at /mariadb/10.11/sql/sql_connect.cc:1319
      #14 0x00007fb8edea1732 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:447
      #15 0x00007fb8edf1c100 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100
      

      Here is the contents of mysql/general_log.CSV after running the test:

      "2024-09-05 10:53:55.505128","root[root] @ localhost []",4,1,"Query","BACKUP STAGE start"
      "2024-09-05 10:53:55.508824","root[root] @ localhost []",4,1,"Query","BACKUP STAGE block_commit"
      "2024-09-05 10:53:55.535836","[root] @ localhost []",5,1,"Connect","root@localhost on  using Socket"
      "2024-09-05 10:53:55.540602","root[root] @ localhost []",5,1,"Init DB","test"
      "2024-09-05 10:53:55.541475","root[root] @ localhost []",5,1,"Query","SET GLOBAL general_log=0"
      

      If I replace the two BACKUP STAGE statements with just FLUSH TABLES WITH READ LOCK, it is similar:

      "2024-09-05 11:18:47.963999","root[root] @ localhost []",4,1,"Query","FLUSH TABLES WITH READ LOCK"
      "2024-09-05 11:18:47.976701","[root] @ localhost []",5,1,"Connect","root@localhost on  using Socket"
      "2024-09-05 11:18:47.979514","root[root] @ localhost []",5,1,"Init DB","test"
      "2024-09-05 11:18:47.979960","root[root] @ localhost []",5,1,"Query","SET GLOBAL general_log=0"
      

      Put in practical terms: If general_log was enabled and log_output='TABLE' during the final stages of a backup, it may be necessary for the user to execute

      REPAIR TABLE mysql.general_log;
      

      after restoring a backup. This would seem to be necessary if any user connected to the server or issued any SQL statements during the critical time while the log tables were being copied.

      Attachments

        Issue Links

          Activity

            People

              monty Michael Widenius
              marko Marko Mäkelä
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

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