+ exec cinder-backup --config-file /etc/cinder/cinder.conf
simplejson unavailable, fall-back to standard python json
2026-07-29 08:29:22.542 1 INFO cinder.cmd.backup [-] Backup running in single process mode.
2026-07-29 08:29:22.820 1 INFO cinder.rpc [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Automatically selected cinder-backup objects version 1.39 as minimum service version.
2026-07-29 08:29:22.822 1 INFO cinder.rpc [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Automatically selected cinder-backup RPC version 2.4 as minimum service version.
2026-07-29 08:29:22.824 1 INFO cinder.rpc [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Automatically selected cinder-volume objects version 1.39 as minimum service version.
2026-07-29 08:29:22.826 1 INFO cinder.rpc [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Automatically selected cinder-volume RPC version 3.20 as minimum service version.
2026-07-29 08:29:22.829 1 INFO cinder.rpc [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Automatically selected cinder-scheduler objects version 1.39 as minimum service version.
2026-07-29 08:29:22.831 1 INFO cinder.rpc [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Automatically selected cinder-scheduler RPC version 3.12 as minimum service version.
2026-07-29 08:29:22.922 1 WARNING oslo_config.cfg [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Deprecated: Option "auth_uri" from group "keystone_authtoken" is deprecated for removal (The auth_uri option is deprecated in favor of www_authenticate_uri and will be removed in the S  release.).  Its value may be silently ignored in the future.
2026-07-29 08:29:22.923 1 WARNING oslo_config.cfg [None req-8b289a60-ee67-4351-803a-b6a153f6343d - - - - - -] Deprecated: Option "auth_uri" from group "keystone_authtoken" is deprecated. Use option "www_authenticate_uri" from group "keystone_authtoken".
2026-07-29 08:29:22.935 1 INFO cinder.service [-] Starting cinder-backup node (version 27.1.0)
2026-07-29 08:29:22.959 1 INFO cinder.backup.manager [None req-61bd39b2-0935-4c7d-8ef0-b8f44542a010 - - - - - -] Cleaning up incomplete backup operations.
2026-07-29 08:29:23.018 1 INFO cinder.keymgr.migration [None req-58165d3f-9755-4624-872b-db4003f462c8 - - - - - -] Not migrating encryption keys because the ConfKeyManager's fixed_key is not in use.
2026-07-29 08:38:37.086 1 INFO cinder.backup.manager [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Create backup started, backup: fd42091e-2258-4a53-91d9-665a2ce31e59 volume: 553ae691-7645-475b-8b09-8ed908f5104a.
2026-07-29 08:38:37.131 1 INFO cinder.backup.manager [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Call Volume Manager to get_backup_device for Backup(availability_zone='nova',container=None,created_at=2026-07-29T08:38:36Z,data_timestamp=2026-07-29T08:38:36Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-VolumesBackupsAdminTest-Backup-1021801470',encryption_key_id=None,fail_reason=None,host='cinder-volume-worker',id=fd42091e-2258-4a53-91d9-665a2ce31e59,metadata={},num_dependent_backups=0,object_count=0,parent=None,parent_id=None,project_id='03c80cc2c80c4654bf7ea1dedec0ef58',restore_volume_id=None,service='cinder.backup.drivers.ceph.CephBackupDriver',service_metadata=None,size=1,snapshot_id=None,status='creating',temp_snapshot_id=None,temp_volume_id=None,updated_at=None,user_id='37919cc1b53d47cda4f5e98dd3557f16',volume_id=553ae691-7645-475b-8b09-8ed908f5104a)
2026-07-29 08:38:37.204 1 INFO oslo.privsep.daemon [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Running privsep helper: ['sudo', 'cinder-rootwrap', '/etc/cinder/rootwrap.conf', 'privsep-helper', '--config-file', '/etc/cinder/cinder.conf', '--privsep_context', 'os_brick.privileged.default', '--privsep_sock_path', '/tmp/tmpf0rdek2b/privsep.sock']
2026-07-29 08:38:38.868 1 WARNING oslo.privsep.daemon [-] privsep log: [Errno 1] Operation not permitted
2026-07-29 08:38:39.036 1 INFO oslo.privsep.daemon [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Spawned new privsep daemon via rootwrap
2026-07-29 08:38:38.859 86 INFO oslo.privsep.daemon [-] privsep daemon starting
2026-07-29 08:38:38.863 86 INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0
2026-07-29 08:38:38.866 86 ERROR oslo.privsep.daemon [-] [Errno 1] Operation not permitted
Traceback (most recent call last):
  File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 600, in helper_main
    Daemon(channel, context).run()
  File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 409, in run
    self._drop_privs()
  File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 443, in _drop_privs
    capabilities.drop_all_caps_except(self.caps, self.caps, [])
  File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/capabilities.py", line 159, in drop_all_caps_except
    raise OSError(errno, os.strerror(errno))
PermissionError: [Errno 1] Operation not permitted
2026-07-29 08:38:39.040 1 WARNING oslo_privsep.comm [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Unexpected error: <class 'BrokenPipeError'>: BrokenPipeError: [Errno 32] Broken pipe
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Error while sending initial PING to privsep: [Errno 32] Broken pipe: BrokenPipeError: [Errno 32] Broken pipe
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged Traceback (most recent call last):
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 201, in exchange_ping
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged     reply = self.send_recv((comm.Message.PING.value,))
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/comm.py", line 192, in send_recv
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged     self.writer.send((myid, msg))
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/comm.py", line 60, in send
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged     self.writesock.sendall(buf)
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged   File "/var/lib/openstack/lib/python3.12/site-packages/eventlet/greenio/base.py", line 389, in sendall
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged     tail = self.send(data, flags)
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged            ^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged   File "/var/lib/openstack/lib/python3.12/site-packages/eventlet/greenio/base.py", line 383, in send
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged     return self._send_loop(self.fd.send, data, flags)
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged   File "/var/lib/openstack/lib/python3.12/site-packages/eventlet/greenio/base.py", line 370, in _send_loop
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged     return send_method(data, *args)
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged            ^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged BrokenPipeError: [Errno 32] Broken pipe
2026-07-29 08:38:39.041 1 ERROR os_brick.privileged 
2026-07-29 08:38:39.043 1 CRITICAL os_brick.privileged [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Privsep daemon failed to start
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server [None req-deb04709-26dc-4447-befe-81696e3d30cb 37919cc1b53d47cda4f5e98dd3557f16 03c80cc2c80c4654bf7ea1dedec0ef58 - - - -] Exception during message handling: oslo_privsep.daemon.FailedToDropPrivileges: Privsep daemon failed to start
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_messaging/rpc/server.py", line 174, in _process_incoming
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_messaging/rpc/dispatcher.py", line 309, in dispatch
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_messaging/rpc/dispatcher.py", line 229, in _do_dispatch
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server              ^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/cinder/backup/manager.py", line 497, in continue_backup
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     properties = volume_utils.brick_get_connector_properties(
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/cinder/volume/volume_utils.py", line 1395, in brick_get_connector_properties
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     return connector.get_connector_properties(root_helper,
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/os_brick/utils.py", line 174, in trace_logging_wrapper
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server            ^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/os_brick/initiator/connector.py", line 232, in get_connector_properties
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     connector.get_connector_properties(
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/os_brick/initiator/connectors/iscsi.py", line 78, in get_connector_properties
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     initiator = iscsi.get_initiator()
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server                 ^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/os_brick/initiator/connectors/iscsi.py", line 1035, in get_initiator
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     lines, _err = self._execute('cat', file_path, run_as_root=True,
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/os_brick/executor.py", line 55, in _execute
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     result = self.__execute(*args, **kwargs)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/os_brick/privileged/rootwrap.py", line 173, in execute
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     return execute_root(*cmd, **kwargs)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/priv_context.py", line 265, in _wrap
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     self.start()
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/priv_context.py", line 279, in start
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     channel = daemon.RootwrapClientChannel(context=self)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 389, in __init__
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     super().__init__(sock, context)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 196, in __init__
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     self.exchange_ping()
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server   File "/var/lib/openstack/lib/python3.12/site-packages/oslo_privsep/daemon.py", line 210, in exchange_ping
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server     raise FailedToDropPrivileges(msg)
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server oslo_privsep.daemon.FailedToDropPrivileges: Privsep daemon failed to start
2026-07-29 08:38:39.044 1 ERROR oslo_messaging.rpc.server 
2026-07-29 08:48:23.729 1 WARNING oslo.service.backend._common.loopingcall [None req-e93ca070-cf73-4632-966b-c8cc7a208b6d - - - - - -] Function 'cinder.service.Service.report_state' run outlasted interval by 0.59 sec
2026-07-29 08:48:36.494 1 WARNING oslo.service.backend._common.loopingcall [None req-e93ca070-cf73-4632-966b-c8cc7a208b6d - - - - - -] Function 'cinder.service.Service.report_state' run outlasted interval by 2.76 sec
2026-07-29 08:48:57.522 1 WARNING oslo.service.backend._common.loopingcall [None req-e93ca070-cf73-4632-966b-c8cc7a208b6d - - - - - -] Function 'cinder.service.Service.report_state' run outlasted interval by 11.03 sec
2026-07-29 08:49:47.698 1 WARNING oslo.service.backend._common.loopingcall [None req-e93ca070-cf73-4632-966b-c8cc7a208b6d - - - - - -] Function 'cinder.service.Service.report_state' run outlasted interval by 40.18 sec
2026-07-29 08:50:18.949 1 WARNING oslo.service.backend._common.loopingcall [None req-e93ca070-cf73-4632-966b-c8cc7a208b6d - - - - - -] Function 'cinder.service.Service.report_state' run outlasted interval by 21.25 sec