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

Last binlog file and position are "empty" in mariabackup --prepare output

    XMLWordPrintable

    Details

      Description

      Normally (till 10.5.x) mariabackup prepare stage reports last binlog file and position at the end, for example:

      openxs@ao756:~/dbs/maria10.4$  bin/mariabackup --no-defaults --binlog-info=on --prepare --target-dir=/tmp/backup
      bin/mariabackup based on MariaDB server 10.4.22-MariaDB Linux (x86_64)
      [00] 2021-08-08 16:46:12 cd to /tmp/backup/
      [00] 2021-08-08 16:46:12 open files limit requested 0, set to 1024
      [00] 2021-08-08 16:46:12 This target seems to be not prepared yet.
      [00] 2021-08-08 16:46:12 mariabackup: using the following InnoDB configuration for recovery:
      [00] 2021-08-08 16:46:12 innodb_data_home_dir = .
      [00] 2021-08-08 16:46:12 innodb_data_file_path = ibdata1:10M:autoextend
      [00] 2021-08-08 16:46:12 innodb_log_group_home_dir = .
      [00] 2021-08-08 16:46:12 InnoDB: Using Linux native AIO
      [00] 2021-08-08 16:46:12 Starting InnoDB instance for recovery.
      [00] 2021-08-08 16:46:12 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
      2021-08-08 16:46:12 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
      2021-08-08 16:46:12 0 [Note] InnoDB: Uses event mutexes
      2021-08-08 16:46:12 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2021-08-08 16:46:12 0 [Note] InnoDB: Number of pools: 1
      2021-08-08 16:46:12 0 [Note] InnoDB: Using SSE2 crc32 instructions
      2021-08-08 16:46:12 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
      2021-08-08 16:46:13 0 [Note] InnoDB: Completed initialization of buffer pool
      2021-08-08 16:46:13 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2021-08-08 16:46:13 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=651139114
      2021-08-08 16:46:15 0 [Note] InnoDB: Starting a batch to recover 291 pages from redo log.
      2021-08-08 16:46:17 0 [Note] InnoDB: Starting final batch to recover 167 pages from redo log.
      2021-08-08 16:46:17 0 [Note] InnoDB: Last binlog file './ao756-bin.000002', position 31344186
      [00] 2021-08-08 16:46:18 Last binlog file ./ao756-bin.000002, position 31344186
      [00] 2021-08-08 16:46:18 completed OK!
      

      But in 10.5.x it's reported as "empty":

      openxs@ao756:~/dbs/maria10.5$ bin/mariabackup --no-defaults --binlog-info=on --prepare --target-dir=/tmp/backup
      bin/mariabackup based on MariaDB server 10.5.13-MariaDB Linux (x86_64)
      [00] 2021-08-08 14:58:54 cd to /tmp/backup/
      [00] 2021-08-08 14:58:54 open files limit requested 0, set to 1024
      [00] 2021-08-08 14:58:54 This target seems to be not prepared yet.
      [00] 2021-08-08 14:58:54 mariabackup: using the following InnoDB configuration for recovery:
      [00] 2021-08-08 14:58:54 innodb_data_home_dir = .
      [00] 2021-08-08 14:58:54 innodb_data_file_path = ibdata1:10M:autoextend
      [00] 2021-08-08 14:58:54 innodb_log_group_home_dir = .
      [00] 2021-08-08 14:58:54 InnoDB: Using Linux native AIO
      [00] 2021-08-08 14:58:54 Starting InnoDB instance for recovery.
      [00] 2021-08-08 14:58:54 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
      2021-08-08 14:58:54 0 [Note] InnoDB: Uses event mutexes
      2021-08-08 14:58:54 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2021-08-08 14:58:54 0 [Note] InnoDB: Number of pools: 1
      2021-08-08 14:58:54 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
      2021-08-08 14:58:54 0 [Note] InnoDB: Using Linux native AIO
      2021-08-08 14:58:54 0 [Note] InnoDB: Initializing buffer pool, total size = 104857600, chunk size = 104857600
      2021-08-08 14:58:54 0 [Note] InnoDB: Completed initialization of buffer pool
      2021-08-08 14:58:55 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1050962794,1120684838
      2021-08-08 14:59:00 0 [Note] InnoDB: Starting a batch to recover 155 pages from redo log.
      2021-08-08 14:59:02 0 [Note] InnoDB: Starting a batch to recover 155 pages from redo log.
      2021-08-08 14:59:04 0 [Note] InnoDB: Starting a batch to recover 157 pages from redo log.
      2021-08-08 14:59:06 0 [Note] InnoDB: Starting a batch to recover 162 pages from redo log.
      2021-08-08 14:59:07 0 [Note] InnoDB: Starting final batch to recover 358 pages from redo log.
      [00] 2021-08-08 14:59:08 Last binlog file , position 0
      [00] 2021-08-08 14:59:08 completed OK!
      

      It looks like a regression bug, but maybe there is a good reason NOT to report it (where is it documented then?) In the latter case why this output appears at the log at all? It adds no value, just a confusion.

      See also MDEV-21611 and related bugs there. Cross checking vs the information reported at --backup stage and xtrabackup_binlog_info is important for troubleshooting in some cases.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              vlad.lesin Vladislav Lesin
              Reporter:
              valerii Valerii Kravchuk
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration

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