Backups fail after upgrading to 1.11.0

MySQL & MariaDB Percona Operator for MySQL
1

Since I upgraded the Percona Operator to version 1.11.0, all backups to S3 are failing. A similar issue was reported here in the past, but the issue remained unanswered.

Env specifics:
Operator: 1.11.0
MySQL: 8.0.27-18.1
Backup: 1.11.0-pxc8.0-backup
Kubernetes: v1.24.13

Pod view:

image
image641×666 101 KB

The backup seems to run successfully up until the following is seen:

2023-05-23 05:55:22.602  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/backup-my.cnf.00000000000000000000, size: 529

2023-05-23 05:55:23.693  INFO: 1.0 (pxc-muc2-pxc-2): State transfer to 0.0 (garb) complete.
2023-05-23 05:55:23.694  INFO: Member 1.0 (pxc-muc2-pxc-2) synced with group.
2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/xtrabackup_info.00000000000000000001, size: 29

2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/xtrabackup_tablespaces.00000000000000000001, size: 36

2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/xtrabackup_tablespaces.00000000000000000000, size: 95

2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/ib_buffer_pool.00000000000000000000, size: 10909

2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/xtrabackup_info.00000000000000000000, size: 904

2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:22 xbcloud: successfully uploaded chunk: pxc-muc2-2023-05-23-05:52:40-full/xtrabackup_logfile.00000000000000000000, size: 4911156

2023-05-23 05:55:23.975  INFO: [SST script] 230523 05:55:23 xbcloud: Upload failed: backup is incomplete.

2023-05-23 05:55:23.976  INFO: [SST script] + FIRST_RECEIVED=1

2023-05-23 05:55:23.976  INFO: [SST script] + echo 'Backup finished'

2023-05-23 05:55:23.976  INFO: [SST script] + mc -C /tmp/mc stat dest/nv-mysql-backups/pxc-muc2-2023-05-23-05:52:40-full.md5

2023-05-23 05:55:23.976  INFO: [SST script] Backup finished

2023-05-23 05:55:24.753  INFO: [SST script] mc: <ERROR> Unable to stat `dest/nv-mysql-backups/pxc-muc2-2023-05-23-05:52:40-full.md5`. Object does not exist.

2023-05-23 05:55:24.756  INFO: [SST script] ++ handle_sigint

2023-05-23 05:55:24.756  INFO: [SST script] ++ ((  1 == 0  ))

2023-05-23 05:55:24.756  INFO: SST script ended
2023-05-23 05:55:24.756  INFO: Closing send monitor...
2023-05-23 05:55:24.756  INFO: Closed send monitor.
2023-05-23 05:55:24.756  INFO: gcomm: terminating thread
2023-05-23 05:55:24.756  INFO: gcomm: joining thread
2023-05-23 05:55:24.756  INFO: gcomm: closing backend
2023-05-23 05:55:25.758  INFO: Current view of cluster as seen by this node
view (view_id(NON_PRIM,0cb17d93-a828,179)
memb {
	0cb17d93-a828,0
	}
joined {
	}
left {
	}
partitioned {
	49926b80-a215,0
	8af0e1f0-8418,0
	d1f05a9f-b180,0
	}
)
2023-05-23 05:55:25.758  INFO: PC protocol downgrade 1 -> 0
2023-05-23 05:55:25.758  INFO: Current view of cluster as seen by this node
view ((empty))
2023-05-23 05:55:25.758  INFO: gcomm: closed
2023-05-23 05:55:25.758  INFO: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2023-05-23 05:55:25.758  INFO: Flow-control interval: [0, 0]
2023-05-23 05:55:25.759  INFO: Received NON-PRIMARY.
2023-05-23 05:55:25.759  INFO: Shifting JOINER -> OPEN (TO: 4350176)
2023-05-23 05:55:25.759  INFO: New SELF-LEAVE.
2023-05-23 05:55:25.759  INFO: Flow-control interval: [0, 0]
2023-05-23 05:55:25.759  INFO: Received SELF-LEAVE. Closing connection.
2023-05-23 05:55:25.759  INFO: Shifting OPEN -> CLOSED (TO: 4350176)
2023-05-23 05:55:25.759  INFO: RECV thread exiting 0: Success
2023-05-23 05:55:25.759  INFO: Waiting for SST script to stop
2023-05-23 05:55:25.759  INFO: recv_thread() joined.
2023-05-23 05:55:25.759  INFO: Closing replication queue.
2023-05-23 05:55:25.759  INFO: Closing slave action queue.
2023-05-23 05:55:25.759  INFO: SST script stopped
2023-05-23 05:55:25.759  INFO: Exiting main loop
+ EXID_CODE=1
+ echo '[INFO] garbd was finished'
Process completed with error: /usr/bin/run_backup.sh: 1 (Operation not permitted)[INFO] garbd was finished
+ '[' -f /tmp/backup-is-completed ']'
+ exit 1

mysqld-error.log:

2023-05-23T05:55:23.694228Z 2 [Note] [MY-000000] [WSREP] Synchronized with group, ready for connections
2023-05-23T05:55:23.694236Z 2 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2023-05-23T05:55:25.758561Z 0 [Note] [MY-000000] [Galera] declaring 8af0e1f0-8418 at ssl://172.20.6.47:4567 stable
2023-05-23T05:55:25.758631Z 0 [Note] [MY-000000] [Galera] declaring d1f05a9f-b180 at ssl://172.20.9.51:4567 stable
2023-05-23T05:55:25.758653Z 0 [Note] [MY-000000] [Galera] forgetting 0cb17d93-a828 (ssl://172.20.7.39:4567)
2023-05-23T05:55:25.760489Z 0 [Note] [MY-000000] [Galera] Node 49926b80-a215 state primary
2023-05-23T05:55:25.761608Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(PRIM,49926b80-a215,180)
memb {
	49926b80-a215,0
	8af0e1f0-8418,0
	d1f05a9f-b180,0
	}
joined {
	}
left {
	}
partitioned {
	0cb17d93-a828,0
	}
)
2023-05-23T05:55:25.761640Z 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
2023-05-23T05:55:25.764283Z 0 [Note] [MY-000000] [Galera] forgetting 0cb17d93-a828 (ssl://172.20.7.39:4567)
2023-05-23T05:55:25.764307Z 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
2023-05-23T05:55:25.764404Z 0 [Note] [MY-000000] [Galera] STATE_EXCHANGE: sent state UUID: 69d3a549-f92e-11ed-9881-821e9cef9179
2023-05-23T05:55:25.764988Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: 69d3a549-f92e-11ed-9881-821e9cef9179
2023-05-23T05:55:25.765522Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 69d3a549-f92e-11ed-9881-821e9cef9179 from 0 (pxc-muc2-pxc-2)
2023-05-23T05:55:25.765595Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 69d3a549-f92e-11ed-9881-821e9cef9179 from 1 (pxc-muc2-pxc-1)
2023-05-23T05:55:25.765608Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 69d3a549-f92e-11ed-9881-821e9cef9179 from 2 (pxc-muc2-pxc-0)
2023-05-23T05:55:25.765618Z 0 [Note] [MY-000000] [Galera] Quorum results:
	version    = 6,
	component  = PRIMARY,
	conf_id    = 175,
	members    = 3/3 (primary/total),
	act_id     = 4350176,
	last_appl. = 4350113,
	protocols  = 2/10/4 (gcs/repl/appl),
	vote policy= 0,
	group UUID = 9089a918-ba6b-11ec-b9cc-e37b9e1cccf9
2023-05-23T05:55:25.765656Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [173, 173]
2023-05-23T05:55:25.765744Z 2 [Note] [MY-000000] [Galera] ####### processing CC 4350177, local, ordered
2023-05-23T05:55:25.765782Z 2 [Note] [MY-000000] [Galera] Maybe drain monitors from 4350176 upto current CC event 4350177 upto:4350176
2023-05-23T05:55:25.765792Z 2 [Note] [MY-000000] [Galera] Drain monitors from 4350176 up to 4350176
2023-05-23T05:55:25.765803Z 2 [Note] [MY-000000] [Galera] ####### My UUID: 49926b80-f550-11ed-a215-73763e982c31
2023-05-23T05:55:25.765812Z 2 [Note] [MY-000000] [Galera] Skipping cert index reset
2023-05-23T05:55:25.765821Z 2 [Note] [MY-000000] [Galera] REPL Protocols: 10 (5)
2023-05-23T05:55:25.765834Z 2 [Note] [MY-000000] [Galera] ####### Adjusting cert position: 4350176 -> 4350177
2023-05-23T05:55:25.765905Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2023-05-23T05:55:25.767284Z 2 [Note] [MY-000000] [Galera] ================================================
View:
  id: 9089a918-ba6b-11ec-b9cc-e37b9e1cccf9:4350177
  status: primary
  protocol_version: 4
  capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
  final: no
  own_index: 0
  members(3):
	0: 49926b80-f550-11ed-a215-73763e982c31, pxc-muc2-pxc-2
	1: 8af0e1f0-f550-11ed-8418-f7d21bb22c41, pxc-muc2-pxc-1
	2: d1f05a9f-f550-11ed-b180-dff44cbef766, pxc-muc2-pxc-0
=================================================
2023-05-23T05:55:25.767321Z 2 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2023-05-23T05:55:25.769960Z 2 [Note] [MY-000000] [Galera] Recording CC from group: 4350177
2023-05-23T05:55:25.769994Z 2 [Note] [MY-000000] [Galera] Lowest cert index boundary for CC from group: 4350114
2023-05-23T05:55:25.770004Z 2 [Note] [MY-000000] [Galera] Min available from gcache for CC from group: 4153898
2023-05-23T05:55:31.001021Z 0 [Note] [MY-000000] [Galera]  cleaning up 0cb17d93-a828 (ssl://172.20.7.39:4567)

innobackup full:

pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821320.613904500, {"log":"230523 05:55:20 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.036350317, {"log":"230523 05:55:21 Starting to backup non-InnoDB tables and files\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.055994167, {"log":"230523 05:55:21 [02] Streaming mysql/slow_log_629.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.056012327, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.056014713, {"log":"230523 05:55:21 [04] Streaming mysql/slow_log.CSV to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.059209406, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.059231241, {"log":"230523 05:55:21 [03] Streaming mysql/slow_log.CSM to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.059235852, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.059239012, {"log":"230523 05:55:21 [02] Streaming mysql/general_log.CSM to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.062793799, {"log":"230523 05:55:21 [04] Streaming mysql/general_log.CSV to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.062808169, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.062810496, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.062812539, {"log":"230523 05:55:21 [01] Streaming mysql/general_log_627.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.063433046, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.084316526, {"log":"230523 05:55:21 [02] Streaming performance_schema/cond_instances_491.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.084339446, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090682098, {"log":"230523 05:55:21 [04] Streaming performance_schema/events_waits_cur_493.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090700717, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090886784, {"log":"230523 05:55:21 [02] Streaming performance_schema/events_waits_his_495.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090893954, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090897351, {"log":"230523 05:55:21 [04] Streaming performance_schema/events_waits_sum_496.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090904063, {"log":"230523 05:55:21 [03] Streaming performance_schema/error_log_492.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090909877, {"log":"230523 05:55:21 [02] Streaming performance_schema/events_waits_sum_497.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090916005, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.090919372, {"log":"230523 05:55:21 [01] Streaming performance_schema/events_waits_his_494.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.091983523, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.095881641, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.095898690, {"log":"230523 05:55:21 [04] Streaming performance_schema/events_waits_sum_498.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.095905854, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.097570785, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.098387974, {"log":"230523 05:55:21 [02] Streaming performance_schema/events_waits_sum_499.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.099728083, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.099743486, {"log":"230523 05:55:21 [01] Streaming performance_schema/events_waits_sum_500.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103442297, {"log":"230523 05:55:21 [03] Streaming performance_schema/events_waits_sum_501.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103468262, {"log":"230523 05:55:21 [04] Streaming performance_schema/file_instances_502.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103474431, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103477586, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103480739, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103483969, {"log":"230523 05:55:21 [02] Streaming performance_schema/file_summary_by__503.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.103490003, {"log":"230523 05:55:21 [01] Streaming performance_schema/file_summary_by__504.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.104394560, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.105566833, {"log":"230523 05:55:21 [04] Streaming performance_schema/host_cache_505.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.110841086, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.110861971, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.110865140, {"log":"230523 05:55:21 [02] Streaming performance_schema/objects_summary__507.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.112484279, {"log":"230523 05:55:21 [03] Streaming performance_schema/mutex_instances_506.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.112498097, {"log":"230523 05:55:21 [01] Streaming performance_schema/performance_time_508.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.112648143, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.113559150, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.113569473, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.113573095, {"log":"230523 05:55:21 [04] Streaming performance_schema/processlist_509.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.116804186, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.116821163, {"log":"230523 05:55:21 [02] Streaming performance_schema/rwlock_instances_510.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122285153, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122301589, {"log":"230523 05:55:21 [01] Streaming performance_schema/setup_actors_511.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122305515, {"log":"230523 05:55:21 [03] Streaming performance_schema/setup_consumers_512.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122309099, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122311073, {"log":"230523 05:55:21 [04] Streaming performance_schema/setup_instrument_513.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122314537, {"log":"230523 05:55:21 [02] Streaming performance_schema/setup_objects_514.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122317894, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122319779, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.122321686, {"log":"230523 05:55:21 [01] Streaming performance_schema/setup_threads_515.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.124128188, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.124141907, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.124144338, {"log":"230523 05:55:21 [04] Streaming performance_schema/table_io_waits_s_516.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.126259918, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.126283800, {"log":"230523 05:55:21 [02] Streaming performance_schema/table_io_waits_s_517.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.127677526, {"log":"230523 05:55:21 [01] Streaming performance_schema/threads_519.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.127695027, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.128937610, {"log":"230523 05:55:21 [03] Streaming performance_schema/table_lock_waits_518.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.128949683, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.130269296, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.131329355, {"log":"230523 05:55:21 [04] Streaming performance_schema/events_stages_cu_520.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.132055867, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.135710117, {"log":"230523 05:55:21 [02] Streaming performance_schema/events_stages_hi_521.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.135733215, {"log":"230523 05:55:21 [01] Streaming performance_schema/events_stages_hi_522.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.135740793, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.135744225, {"log":"230523 05:55:21 [03] Streaming performance_schema/events_stages_su_523.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.135750452, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.145685805, {"log":"230523 05:55:21 [03]        
----<<<SNIP>>>---
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.254575903, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.254595854, {"log":"230523 05:55:21 [02] Streaming performance_schema/user_defined_fun_597.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.254602926, {"log":"230523 05:55:21 [03] Streaming performance_schema/binary_log_trans_598.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.255325201, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.256038278, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.257281913, {"log":"230523 05:55:21 [01] Streaming performance_schema/tls_channel_stat_599.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.257364907, {"log":"230523 05:55:21 [04] Streaming performance_schema/malloc_stats_tot_600.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260132586, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260150202, {"log":"230523 05:55:21 [04]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260154194, {"log":"230523 05:55:21 [02] Streaming performance_schema/malloc_stats_601.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260160124, {"log":"230523 05:55:21 [03] Streaming performance_schema/keyring_componen_602.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260166403, {"log":"230523 05:55:21 [02]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260223516, {"log":"230523 05:55:21 [03]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.260225613, {"log":"230523 05:55:21 [01] Streaming performance_schema/pxc_cluster_view_603.sdi to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.261642462, {"log":"230523 05:55:21 [01]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.295732467, {"log":"230523 05:55:21 >> log scanned up to (21747982530)\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.398394801, {"log":"230523 05:55:21 Finished backing up non-InnoDB tables and files\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.398412577, {"log":"230523 05:55:21 Executing FLUSH NO_WRITE_TO_BINLOG BINARY LOGS\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.415459931, {"log":"230523 05:55:21 Selecting LSN and binary log position from p_s.log_status\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.419705634, {"log":"230523 05:55:21 [00] Streaming /var/lib/mysql/binlog.000367 to <STDOUT> up to position 236\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.419722734, {"log":"230523 05:55:21 [00]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.462605164, {"log":"230523 05:55:21 [00] Streaming <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.462621848, {"log":"230523 05:55:21 [00]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.462624143, {"log":"230523 05:55:21 [00] Streaming <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.462626190, {"log":"230523 05:55:21 [00]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.462628093, {"log":"230523 05:55:21 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...\nxtrabackup: The latest check point (for incremental): '21744491030'\nxtrabackup: Stopping log copying thread at LSN 21747987252.\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821321.462632044, {"log":"230523 05:55:21 >> log scanned up to (21747987262)\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462149833, {"log":"230523 05:55:22 Executing UNLOCK TABLES\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462165263, {"log":"230523 05:55:22 All tables unlocked\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462173676, {"log":"230523 05:55:22 [00] Streaming ib_buffer_pool to <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462177109, {"log":"230523 05:55:22 [00]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462179172, {"log":"230523 05:55:22 Backup created in directory '/tmp/pxc_sst_U0hq/donor_xb_Xh7q/'\nMySQL binlog position: filename 'binlog.000367', position '236', GTID of the last change '07f8fbf6-fc2a-11eb-8fd6-c3760dbd2b5d:1-5851,9089a918-ba6b-11ec-b9cc-e37b9e1cccf9:1-4334134'\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462183518, {"log":"230523 05:55:22 [00] Streaming <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.462186228, {"log":"230523 05:55:22 [00]        ...done\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.463565899, {"log":"230523 05:55:22 [00] Streaming <STDOUT>\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821322.463580423, {"log":"230523 05:55:22 [00]        ...done\nxtrabackup: Transaction log of lsn (21743087969) to (21747996548) was copied.\n","file":"/var/lib/mysql/innobackup.backup.log"}]
pxc.pxc-muc2-pxc-2.innobackup.backup.log: [1684821323.678681866, {"log":"230523 05:55:23 completed OK!\nxtrabackup: recognized server arguments: --datadir=/var/lib/mysql --server-id=38248282 --innodb_flush_log_at_trx_commit=0 --innodb_flush_method=O_DIRECT --innodb_file_per_table=1 --innodb_buffer_pool_size=500000000 --defaults_group=mysqld \nxtrabackup: recognized client arguments: --socket=/tmp/mysql.sock --no-version-check=1 --parallel=4 --user=mysql.pxc.sst.user --password=* --socket=/tmp/mysql.sock --lock-ddl=1 --backup=1 --galera-info=1 --stream=xbstream --xtrabackup-plugin-dir=/usr/bin/pxc_extra/pxb-8.0/lib/plugin --target-dir=/tmp/pxc_sst_a9zV/donor_xb_brtH \n/usr/bin/pxc_extra/pxb-8.0/bin/xtrabackup version 8.0.27-19 based on MySQL server 8.0.27 Linux (x86_64) (revision id: 50dbc8dadda)\n","file":"/var/lib/mysql/innobackup.backup.log"}]

I tried automatic and manual backups, with the same results. Any idea what could be the cause here?

2

I was able to overcome the issue by using percona/percona-xtradb-cluster-operator:1.12.0-pxc8.0-backup as a container image for the backup spec.

I assume there’s a bug in the 1.11.0 version, but I was not able to find it in the release notes.

3

Hi @nvuser, I have tried to reproduce your issue but without any results :frowning: I have checked all commits, and between 1.11.0 and 1.12.0 and I can’t find any fixes connected to this issue. It can be this commit K8SPXC-1062 change run_backup.sh for PXC 8.0 to handle SIGTERM instea… · percona/percona-docker@8dabbab · GitHub or just PXB version was updated, and your issue was fixed. As I can see from log the root of the issue was that md5 file was not pushed to s3.