首页
学习
活动
专区
圈层
工具
发布
社区首页 >专栏 >xtrabackup prepare失败: innodb_init(): Error occured

xtrabackup prepare失败: innodb_init(): Error occured

原创
作者头像
大大刺猬
发布2026-05-14 17:45:10
发布2026-05-14 17:45:10
980
举报
文章被收录于专栏:大大刺猬大大刺猬

导读

在某环境使用xtrabackup做恢复的时候, prepare(命令参考:xtrabackup --prepare --target-dir=/data/backup/full_back/2026-05-11_14-34-12)报错如下: xtrabackup: innodb_init(): Error occured

代码语言:txt
复制
InnoDB: Completed initialization of buffer pool
InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
InnoDB: Log file ./ib_logfile1 is of different size 134217728 bytes than other log files 9437184 bytes!
InnoDB: Plugin initialization aborted with error Generic error
xtrabackup: innodb_init(): Error occured.

从报错来看就是ib_logfile1的大小和其它redo的大小不一样导致innodb初始化失败.

分析xtrabackup prepare过程

xtrabackup的输出日志非常的全面,所以分析起来比较方便. 当然我们还得和源码对比一下(稳一点).

日志分析

我们先来完整的看下xtrabackup preparer日志:

代码语言:txt
复制
xtrabackup: recognized client arguments: --prepare=1 --target-dir=/data/backup/full_back/2026-05-11_14-34-12 
xtrabackup version 2.4.27 based on MySQL server 5.7.40 Linux (x86_64) (revision id: aae8e82)
xtrabackup: cd to /data/backup/full_back/2026-05-11_14-34-12/
xtrabackup: This target seems to be not prepared yet.
InnoDB: Number of pools: 1
xtrabackup: xtrabackup_logfile detected: size=9437184, start_lsn=(748089915)
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup:   innodb_log_group_home_dir = .
xtrabackup:   innodb_log_files_in_group = 1
xtrabackup:   innodb_log_file_size = 9437184
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup:   innodb_log_group_home_dir = .
xtrabackup:   innodb_log_files_in_group = 1
xtrabackup:   innodb_log_file_size = 9437184
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: PUNCH HOLE support available
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Uses event mutexes
InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
InnoDB: Compressed tables use zlib 1.2.12
InnoDB: Number of pools: 1
InnoDB: Using CPU crc32 instructions
InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
InnoDB: Completed initialization of buffer pool
InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
InnoDB: Log file ./ib_logfile1 is of different size 134217728 bytes than other log files 9437184 bytes!
InnoDB: Plugin initialization aborted with error Generic error
xtrabackup: innodb_init(): Error occured.

从上述日志中我们得到xtrabackup prepare的流程为:

  1. 初始化环境redo相关变量(2次?)
  2. 初始化innodb buffer pool
  3. 设置page cleaner线程优先级失败(没权限).
  4. 发现ib_logfile1和其它redo日志大小不一样
  5. 插件(innodb)初始化失败
  6. innodb初始化失败,退出

从日志里面能分析出来的也就这样了, 基本上可以确定是redo log文件大小不统一导致的.

为啥redo log大小不一致呢?

我们查看备份目录下(已经做过prepare了)的文件:

代码语言:txt
复制
-rw-r----- 1 mysql mysql       496 May 11 14:34 backup-my.cnf
drwxr-x--- 2 mysql mysql      8192 May 11 14:34 db1
drwxr-x--- 2 mysql mysql       102 May 11 14:34 db2
drwxr-x--- 2 mysql mysql        82 May 11 14:34 db3
drwxr-x--- 2 mysql mysql      4096 May 11 14:34 db4
-rw-r----- 1 mysql mysql       985 May 11 14:34 ib_buffer_pool
-rw-r----- 1 mysql mysql 146800640 May 11 14:34 ibdata1
-rw-r----- 1 mysql mysql 134217728 May 13 18:05 ib_logfile1
drwxr-x--- 2 mysql mysql      4096 May 11 14:34 mysql
drwxr-x--- 2 mysql mysql      8192 May 11 14:34 performance_schema
drwxr-x--- 2 mysql mysql      8192 May 11 14:34 sys
drwxr-x--- 2 mysql mysql        20 May 11 14:34 test2
-rw-r----- 1 mysql mysql        64 May 11 14:34 xtrabackup_binlog_info
-rw-r----- 1 mysql mysql       141 May 11 14:34 xtrabackup_checkpoints
-rw-r----- 1 mysql mysql       652 May 11 14:34 xtrabackup_info
-rw-r----- 1 mysql mysql   9437184 May 14 13:19 xtrabackup_logfile

发现ib_logfile1的大小是134217728, xtrabackup_logfile的大小是9437184, 和报错中的描述(InnoDB: Log file ./ib_logfile1 is of different size 134217728 bytes than other log files 9437184 bytes)吻合.

熟悉xbk工具的同学应该会疑惑为啥会有个ib_logfile1文件, 我们通常备份出来是没有这个文件的(redo是放在xtrabackup_logfile文件的).

那就是因为多了个ib_logfile1导致的? 且看后面的源码分析

源码分析

我们再从源码简单的看下prepare过程

代码语言:txt
复制
xtrabackup.cc:main
	if (xtrabackup_prepare) {
		xtrabackup_prepare_func(server_argc, server_defaults);
	}

main函数直接就调xtrabackup_prepare_func去做prepare.

代码语言:txt
复制
xtrabackup.cc:xtrabackup_prepare_func
    mysql_mutex_init()
    xtrabackup_read_metadata() # 读取元数据信息(主要是metadata_type,来源是xtrabackup_checkpoints(文本文件))
    
    /* Create logfiles for recovery from 'xtrabackup_logfile', before start InnoDB */
    os_event_global_init()
    sync_check_init()
    os_thread_init()
    trx_pool_init()
    ut_crc32_init()
    xb_filters_init()
    xtrabackup_init_temp_log() # 生成ib_logfile0的
    innodb_init_param()  # 初始化参数的(redo和ibdata1)
    xb_tablespace_keys_exist() # key相关的, 一般都没加密
    
	/* Expand compacted datafiles */
	xb_normalize_init_values()
	fil_close()
	trx_pool_close()
	os_thread_free()
	sync_check_close()
	innodb_free_param()
	innodb_init_param() # 没想到吧, 再来了一遍, 这也解释了为啥日志里面显示了两次信息
	innodb_init()  # 本次的报错就是这
	....

初始化了一堆, 也检查了一堆, 直到innodb_init函数就报错了(结合日志也能知道是这个函数)

代码语言:txt
复制
xtrabackup.cc:innodb_init
	os_event_global_init()
	if innobase_start_or_create_for_mysql(){
		msg("xtrabackup: innodb_init(): Error occured.\n")
	}

innodb的初始化是调用的innobase_start_or_create_for_mysql来实现的

代码语言:txt
复制
srv0start.cc:innobase_start_or_create_for_mysql
	for (i = 0; i < SRV_N_LOG_FILES_MAX; i++){
		size >>= UNIV_PAGE_SIZE_SHIFT (512)
		if (i == 0) {
			srv_log_file_size = size;
		} else if (size != srv_log_file_size) {
			ib::error() << "Log file " << logfilename
				<< " is of different size "
				<< (size << UNIV_PAGE_SIZE_SHIFT)
				<< " bytes than other log files "
				<< (srv_log_file_size
					<< UNIV_PAGE_SIZE_SHIFT)
				<< " bytes!";
			return(srv_init_abort(DB_ERROR));
		}
	}

如果i(redo文件号)不是第0个(ib_logfile0), 就判断其大小是否和xtrabackup_logfile(被当作了redo文件,虽然确实是记录的redo)相等, 若不相等就报错:Log file ./ib_logfile1 is of different size 134217728 bytes than other log files 9437184 bytes!

符合我们看到的日志信息, 也就是因为凭空多出来的ib_logfile1导致prepare失败.

设置线程优先级失败就会有如下提示(不影响后续操作):, mysql用户没有设置线程优先级的权限, 如果使用root则不会遇到这个提示.

代码语言:txt
复制
        /* linux might be able to set different setting for each thread.
        worth to try to set high priority for page cleaner threads */
        if (buf_flush_page_cleaner_set_priority(
                buf_flush_page_cleaner_priority)) {

                ib::info() << "page_cleaner coordinator priority: "
                        << buf_flush_page_cleaner_priority;
        } else {
                ib::info() << "If the mysqld execution user is authorized,"
                " page cleaner thread priority can be changed."
                " See the man page of setpriority().";
        }

prepare失败分析

通过日志和源码我们知道了prepare失败是因为多了个ib_logfile1导致的, 那么为啥有这个文件呢? 先来看下这次失败的恢复流程:

将备份恢复到NAS,将NAS挂载到目标环境,解压(qpress)并prepare,然后move/copy-back.

这个流程已经跑过很多次了, 所以流程是没有问题的. 那么就可能是人工拷贝ib_logfile1到xbk备份目录, 或者恢复到nas的时候由于网络之类的情况导致目标环境多了个文件. 由于整个过程都是自动化的,所以不存在人工干预的情况(理论上), 那就是文件传输的时候出的问题了.

总结

通过上述日志分析和源码得到本次prepare报错是因为文件传输的时候多了个ib_logfile1导致的, 重新传输备份文件到NAS并挂载到目标环境后,prepare正常.

至于为什么传输的时候会多一个文件,是否是人为操作的就不得而知了.

原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。

如有侵权,请联系 cloudcommunity@tencent.com 删除。

原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。

如有侵权,请联系 cloudcommunity@tencent.com 删除。

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
目录
  • 导读
  • 分析xtrabackup prepare过程
    • 日志分析
    • 源码分析
    • prepare失败分析
  • 总结
领券
问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档