【 使用环境 】生产环境
【 OB or 其他组件 】OCP
【 使用版本 】4.3.1
【问题描述】
在OCP上创建了租户级的备份策略,每晚定时备份。在执行备份任务第一步是出现错误,提示Already in ARCHIVELOG MODE,任务执行失败。日志如下:
2024-09-13 03:00:01.144 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.o.c.t.e.runner.JavaSubtaskRunner : Run subtask, id=10000151, context=Context{parallelIdx=-1, stringMap={ob_tenant_id=1020, tenant_id=15, checkBeforeDataBackup=true, scheduleTime=03:00:00, tenant_name=ncms_xz, ob_version=4.3.2.1, startClusterCompact=true, task_instance_id=10000111, task_operation=execute, ob_cluster_id=1719885828, startLogBackup=true, backupDim=TENANT, cluster_id=3, tenantName=ncms_xz, backupMode=physical, scheduleDayMode={“1”:“FULL_BACKUP”,“2”:“INCREMENTAL_BACKUP”,“3”:“FULL_BACKUP”,“4”:“INCREMENTAL_BACKUP”,“5”:“FULL_BACKUP”,“6”:“INCREMENTAL_BACKUP”,“7”:“INCREMENTAL_BACKUP”}, scheduleMode=week, triggerType=SCHEDULED, latest_execution_start_time=2024-09-13T03:00:01.068+08:00, sub_task_instance_name=Start log backup if necessary, sub_task_instance_id=10000151, obClusterName=ob_pro}, listMap={}}, executor=10.252.158.68
2024-09-13 03:00:01.359 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:01.371 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: SHOW VARIABLES LIKE ‘system_time_zone’
2024-09-13 03:00:01.379 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.b.c.o.o.c.MysqlClusterOperator : get system time zone: +08:00
2024-09-13 03:00:01.395 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:01.414 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: SELECT value FROM CDB_OB_ARCHIVE_DEST WHERE tenant_id = ? AND name = ‘path’
2024-09-13 03:00:01.475 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.o.s.o.o.f.ConnectPropertiesBuilder : get credential from obsdk context, clusterName=ob_pro, tenantName=sys, dbUser=root
2024-09-13 03:00:01.487 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:01.494 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [300000000]
2024-09-13 03:00:01.507 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: alter system set log_archive_dest = ? tenant = ?, args: [LOCATION=file:///ob_backup/ncms_xz/ob_pro/1719885828/tenant_incarnation_1/1020/clog, ncms_xz]
2024-09-13 03:00:02.302 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:02.312 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] .o.b.i.o.PhysicalBackupOpsServiceFactory : set tenant:ncms_xz log archive dest done.
2024-09-13 03:00:02.378 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.o.s.o.o.f.ConnectPropertiesBuilder : get credential from obsdk context, clusterName=ob_pro, tenantName=sys, dbUser=root
2024-09-13 03:00:02.383 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:02.389 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: SHOW VARIABLES LIKE ‘system_time_zone’
2024-09-13 03:00:02.397 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.b.c.o.o.c.MysqlClusterOperator : get system time zone: +08:00
2024-09-13 03:00:02.403 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:02.408 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: SELECT value FROM CDB_OB_BACKUP_PARAMETER WHERE tenant_id = ? AND name = ‘data_backup_dest’
2024-09-13 03:00:02.421 WARN 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] queryForObject failed, sql:[SELECT value FROM CDB_OB_BACKUP_PARAMETER WHERE tenant_id = ? AND name = ‘data_backup_dest’], error message:[Incorrect result size: expected 1, actual 0]
2024-09-13 03:00:02.428 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : Last Trace Info:[YB420AFCD2A5-0006215B60CB964E-0-0]
2024-09-13 03:00:02.475 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.o.s.o.o.f.ConnectPropertiesBuilder : get credential from obsdk context, clusterName=ob_pro, tenantName=sys, dbUser=root
2024-09-13 03:00:02.484 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:02.490 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [300000000]
2024-09-13 03:00:02.495 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: alter system set data_backup_dest = ? tenant = ?, args: [file:///ob_backup/ncms_xz/ob_pro/1719885828/tenant_incarnation_1/1020/data, ncms_xz]
2024-09-13 03:00:02.831 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:02.838 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] .o.b.i.o.PhysicalBackupOpsServiceFactory : set tenant:ncms_xz data backup dest done.
2024-09-13 03:00:02.978 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.o.s.o.o.f.ConnectPropertiesBuilder : get credential from obsdk context, clusterName=ob_pro, tenantName=sys, dbUser=root
2024-09-13 03:00:03.008 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:03.020 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: SHOW VARIABLES LIKE ‘system_time_zone’
2024-09-13 03:00:03.026 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.b.c.o.o.c.MysqlClusterOperator : get system time zone: +08:00
2024-09-13 03:00:03.030 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:03.043 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: select * from (SELECT incarnation, round_id AS log_archive_round, tenant_id, path AS backup_dest, IF(start_scn_display != ‘’, start_scn_display, NULL) AS min_first_time, IF(checkpoint_scn_display != ‘’, checkpoint_scn_display, NULL) AS max_next_time, status, IF(checkpoint_scn != ‘’, truncate((time_to_usec(now()) - checkpoint_scn / 1000) / 1000000, 4), NULL) AS delay, now(6) AS check_time FROM CDB_OB_ARCHIVELOG_SUMMARY WHERE tenant_id = ? AND round_id = (SELECT MAX(round_id) FROM CDB_OB_ARCHIVELOG_SUMMARY WHERE tenant_id = ?)), args: [1020, 1020]
2024-09-13 03:00:03.055 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] .o.b.i.o.PhysicalBackupOpsServiceFactory : start tenant log backup, tenantId=15, tenantName=ncms_xz
2024-09-13 03:00:03.123 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: set ob_query_timeout = ?, args: [10000000]
2024-09-13 03:00:03.131 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] sql: ALTER SYSTEM ARCHIVELOG, args: []
2024-09-13 03:00:03.140 WARN 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : [obsdk] update failed, sql:[ALTER SYSTEM ARCHIVELOG], error message:[PreparedStatementCallback; SQL [ALTER SYSTEM ARCHIVELOG]; (conn=3222697677) Already in ARCHIVELOG mode; nested exception is java.sql.SQLTransientConnectionException: (conn=3222697677) Already in ARCHIVELOG mode]
2024-09-13 03:00:03.158 INFO 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.ocp.obsdk.connector.ConnectTemplate : Last Trace Info:[Y10B420AFCD2A4-000620BD02ACABCA-0-0]
2024-09-13 03:00:03.162 ERROR 3004741 — [subtask-executor27,ac1fba2107577703,91be66b91c977606] c.o.o.c.t.e.c.w.subtask.SubtaskExecutor : Already in ARCHIVELOG mode
java.sql.SQLException: Already in ARCHIVELOG mode
at com.oceanbase.jdbc.internal.protocol.AbstractQueryProtocol.readErrorPacket(AbstractQueryProtocol.java:2347)
at com.oceanbase.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:2210)
at com.oceanbase.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:2098)
at com.oceanbase.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:399)
at com.oceanbase.jdbc.JDBC4PreparedStatement.executeInternal(JDBC4PreparedStatement.java:247)
at com.oceanbase.jdbc.JDBC4PreparedStatement.execute(JDBC4PreparedStatement.java:170)
at com.oceanbase.jdbc.JDBC4PreparedStatement.executeUpdate(JDBC4PreparedStatement.java:204)
at com.alibaba.druid.pool.DruidPooledPreparedStatement.executeUpdate(DruidPooledPreparedStatement.java:255)
at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:967)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:650)
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:962)
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1017)
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:1027)
at com.oceanbase.ocp.obsdk.connector.ConnectTemplate.updateInner(ConnectTemplate.java:293)
at com.oceanbase.ocp.obsdk.connector.ConnectTemplate.update(ConnectTemplate.java:264)
at com.oceanbase.backup.core.obsdk.accessor.backup.AbstractBackupAccessor.startLogBackup(AbstractBackupAccessor.java:186)
at com.oceanbase.ocp.backup.internal.operation.PhysicalBackupObTenantOpsService.startLogBackup(PhysicalBackupObTenantOpsService.java:150)
at com.oceanbase.ocp.backup.internal.operation.PhysicalBackupOpsServiceFactory.startLogBackup(PhysicalBackupOpsServiceFactory.java:558)
at com.oceanbase.ocp.backup.internal.
operation.PhysicalBackupTaskService.startLogBackup(PhysicalBackupTaskService.java:77)
at com.oceanbase.ocp.backup.internal.task.schedule.StartLogBackupTask.run(StartLogBackupTask.java:46)
at com.oceanbase.ocp.core.task.engine.runner.JavaSubtaskRunner.execute(JavaSubtaskRunner.java:64)
at com.oceanbase.ocp.core.task.engine.runner.JavaSubtaskRunner.doRun(JavaSubtaskRunner.java:32)
at com.oceanbase.ocp.core.task.engine.runner.JavaSubtaskRunner.run(JavaSubtaskRunner.java:26)
at com.oceanbase.ocp.core.task.engine.runner.RunnerFactory.doRun(RunnerFactory.java:76)
at com.oceanbase.ocp.core.task.engine.coordinator.worker.subtask.SubtaskExecutor.doRun(SubtaskExecutor.java:206)
at com.oceanbase.ocp.core.task.engine.coordinator.worker.subtask.SubtaskExecutor.redirectConsoleOutput(SubtaskExecutor.java:200)
at com.oceanbase.ocp.core.task.engine.coordinator.worker.subtask.SubtaskExecutor.lambda$submit$2(SubtaskExecutor.java:137)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:750)
因为该租户使用OMS进行反向增量,设置过参数log_archive_dest并开了archivelog,时候跟这些设置有关关系。如果有关系,在保留OMS的反向增量的情况下,怎么处理才能保证其正常备份。
【复现路径】问题出现前后相关操作
【附件及日志】推荐使用OceanBase敏捷诊断工具obdiag收集诊断信息,详情参见链接(右键跳转查看):
【备注】基于 LLM 和开源文档 RAG 的论坛小助手已开放测试,在发帖时输入 [@论坛小助手] 即可召唤小助手,欢迎试用!