Page MenuHomePhabricator

Openstack cinder volumes backups are broken
Closed, ResolvedPublic

Description

As part of a planned audit/analysis of the existing backups for WMCS resources, Riccardo discovered that the backups of cinder volumes (Openstack additional disks attached to VMs, not the root disks of the VMs) were failing to be backed up since March, due to a change in firewall rules that required to use the HTTP proxies to connect to the Openstack APIs, used by the backup jobs. Those are cross-site backups.

Incident doc: https://docs.google.com/document/d/17h-QBQ74bjIJkRsdayveG5PiTBVTnxFR3KY13fHSwsY/edit?usp=drive_link


While working on my backup audit/analysis, I've discovered that the cinder volume backups taken on cloudbackup2* hosts are broken (backup_cinder_volumes unit):

Jun 11 07:00:06 cloudbackup2004 systemd[1]: Starting backup_cinder_volumes.service - backup cinder volumes...
Jun 11 07:04:36 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:04:36,369] Retrying mwopenstackclients.Clients.allvolumes in 13.062859424353473 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:09:18 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:09:18,993] Retrying mwopenstackclients.Clients.allvolumes in 11.129678384689344 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:13:59 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:13:59,569] Retrying mwopenstackclients.Clients.allvolumes in 8.372975600660839 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:18:38 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:18:38,097] Retrying mwopenstackclients.Clients.allvolumes in 11.525299719816571 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:23:18 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:23:18,673] Retrying mwopenstackclients.Clients.allvolumes in 6.168648336640929 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:27:55 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:27:55,153] Retrying mwopenstackclients.Clients.allvolumes in 5.576154738960626 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:32:29 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:32:29,585] Retrying mwopenstackclients.Clients.allvolumes in 12.37777738170948 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:37:12 cloudbackup2004 wmcs-backup[182725]: WARNING:[2026-06-11 07:37:12,209] Retrying mwopenstackclients.Clients.allvolumes in 7.052115883403381 seconds as it raised ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out.
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: Traceback (most recent call last):
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 198, in _new_conn
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     sock = connection.create_connection(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         (self._dns_host, self.port),
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ...<2 lines>...
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         socket_options=self.socket_options,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     )
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/util/connection.py", line 85, in create_connection
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise err
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/util/connection.py", line 73, in create_connection
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     sock.connect(sa)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ~~~~~~~~~~~~^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: TimeoutError: [Errno 110] Connection timed out
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: The above exception was the direct cause of the following exception:
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: Traceback (most recent call last):
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 787, in urlopen
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     response = self._make_request(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         conn,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ...<10 lines>...
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         **response_kw,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     )
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 488, in _make_request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise new_e
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 464, in _make_request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     self._validate_conn(conn)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ~~~~~~~~~~~~~~~~~~~^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 1093, in _validate_conn
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     conn.connect()
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ~~~~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 704, in connect
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     self.sock = sock = self._new_conn()
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                        ~~~~~~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 207, in _new_conn
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise ConnectTimeoutError(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ...<2 lines>...
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ) from e
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: urllib3.exceptions.ConnectTimeoutError: (<urllib3.connection.HTTPSConnection object at 0x7f4e456b82d0>, 'Connection to openstack.eqiad1.wikimediacloud.org timed out. (connect timeout=None)')
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: The above exception was the direct cause of the following exception:
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: Traceback (most recent call last):
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/requests/adapters.py", line 667, in send
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp = conn.urlopen(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         method=request.method,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ...<9 lines>...
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         chunked=chunked,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     )
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 841, in urlopen
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     retries = retries.increment(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         method, url, error=new_e, _pool=self, _stacktrace=sys.exc_info()[2]
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     )
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/urllib3/util/retry.py", line 519, in increment
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise MaxRetryError(_pool, url, reason) from reason  # type: ignore[arg-type]
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='openstack.eqiad1.wikimediacloud.org', port=25357): Max retries exceeded with url: /v3/auth/tokens (Caused by ConnectTimeoutError(<urllib3.connection.HTTPSConnection object at 0x7f4e456b82d0>, 'Connection to openstack.eqiad1.wikimediacloud.org timed out. (connect timeout=None)'))
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: During handling of the above exception, another exception occurred:
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: Traceback (most recent call last):
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/session.py", line 1169, in _send_request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp = self.session.request(method, url, **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/requests/sessions.py", line 589, in request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp = self.send(prep, **send_kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/requests/sessions.py", line 703, in send
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     r = adapter.send(request, **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/requests/adapters.py", line 688, in send
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise ConnectTimeout(e, request=request)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: requests.exceptions.ConnectTimeout: HTTPSConnectionPool(host='openstack.eqiad1.wikimediacloud.org', port=25357): Max retries exceeded with url: /v3/auth/tokens (Caused by ConnectTimeoutError(<urllib3.connection.HTTPSConnection object at 0x7f4e456b82d0>, 'Connection to openstack.eqiad1.wikimediacloud.org timed out. (connect timeout=None)'))
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: During handling of the above exception, another exception occurred:
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: Traceback (most recent call last):
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/local/sbin/wmcs-backup", line 2190, in <module>
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     args.func()
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/local/sbin/wmcs-backup", line 2041, in <lambda>
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     func=lambda: get_current_volumes_state(from_cache=args.from_cache).delete_expired(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                  ~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/local/sbin/wmcs-backup", line 1647, in get_current_volumes_state
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     volume_id_to_volume_dict = get_volumes_info(from_cache)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/local/sbin/wmcs-backup", line 1623, in get_volumes_info
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     volume_id_to_volume_info = {volume.id: volume.to_dict() for volume in clients.allvolumes()}
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                                                                           ~~~~~~~~~~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 332, in wrapped_f
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self(f, *args, **kw)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 469, in __call__
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     do = self.iter(retry_state=retry_state)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 370, in iter
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     result = action(retry_state)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 412, in exc_check
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise retry_exc.reraise()
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:           ~~~~~~~~~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 185, in reraise
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise self.last_attempt.result()
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:           ~~~~~~~~~~~~~~~~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3.13/concurrent/futures/_base.py", line 449, in result
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self.__get_result()
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~~~~~~^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3.13/concurrent/futures/_base.py", line 401, in __get_result
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise self._exception
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 472, in __call__
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     result = fn(*args, **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/mwopenstackclients.py", line 410, in allvolumes
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self.cinderclient(projectid).volumes.list(search_opts=search_params)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/cinderclient/v3/volumes_base.py", line 222, in list
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self._list(url, resource_type, limit=limit)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/cinderclient/base.py", line 78, in _list
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp, body = self.api.client.get(url)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                  ~~~~~~~~~~~~~~~~~~~^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/cinderclient/client.py", line 220, in get
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self._cs_request(url, 'GET', **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/cinderclient/client.py", line 211, in _cs_request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self.request(url, method, **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/cinderclient/client.py", line 192, in request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp, body = super(SessionClient, self).request(*args,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                                                     raise_exc=False,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                                                     ^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                                                     **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                                                     ^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/adapter.py", line 657, in request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp = self._request(url, method, **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/adapter.py", line 294, in _request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self.session.request(url, method, **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/session.py", line 901, in request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     auth_headers = self.get_auth_headers(auth)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/session.py", line 1387, in get_auth_headers
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return auth.get_headers(self)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~~~~~^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/plugin.py", line 124, in get_headers
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     token = self.get_token(session)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/identity/base.py", line 91, in get_token
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self.get_access(session).auth_token
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~~~~^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/identity/base.py", line 139, in get_access
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     self.auth_ref = self.get_auth_ref(session)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:                     ~~~~~~~~~~~~~~~~~^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/identity/v3/base.py", line 240, in get_auth_ref
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp = session.post(
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         token_url,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     ...<4 lines>...
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:         **rkwargs,
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     )
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/session.py", line 1334, in post
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     return self.request(url, 'POST', **kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:            ~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/session.py", line 1057, in request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     resp = send(**kwargs)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:   File "/usr/lib/python3/dist-packages/keystoneauth1/session.py", line 1175, in _send_request
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]:     raise exceptions.ConnectTimeout(msg)
Jun 11 07:41:48 cloudbackup2004 wmcs-backup[182725]: keystoneauth1.exceptions.connection.ConnectTimeout: Request to https://openstack.eqiad1.wikimediacloud.org:25357/v3/auth/tokens timed out
Jun 11 07:41:48 cloudbackup2004 systemd[1]: backup_cinder_volumes.service: Control process exited, code=exited, status=1/FAILURE
Jun 11 07:41:48 cloudbackup2004 systemd[1]: backup_cinder_volumes.service: Failed with result 'exit-code'.
Jun 11 07:41:48 cloudbackup2004 systemd[1]: Failed to start backup_cinder_volumes.service - backup cinder volumes.

This is probably the same issue we got with T419996 for cumin. I would have expected also the other openstack backups to fail (root disks and glance images) but the root ones are unclear (see T428865 ) while the glance images seems to be backing up correctly.

I'm working to add support for http proxies to mwopenstackclients that is the one used by wmcs-backup.py to connect to openstack.

Event Timeline

Volans triaged this task as Unbreak Now! priority.
Restricted Application added a subscriber: Aklapper. · View Herald Transcript

Do we have any concern that after fixing the issue the next round of backups might cause harm to the infrastructure because of the backlog?

cloudbackup1* hosts doesn't seem to be affected just because they have a leg into the cloud-private vlan:

$ ip route get 185.15.56.161
185.15.56.161 via 172.20.1.1 dev vlan1151 src 172.20.1.6 uid 14150
    cache
$ ip -6 route get 2a02:ec80:a000:4000::1
2a02:ec80:a000:4000::1 from :: via 2a02:ec80:a000:201::1 dev vlan1151 src 2a02:ec80:a000:201::6 metric 1024 pref medium

The systemd unit is clearly failed:

● backup_cinder_volumes.service                                                                    loaded failed failed    backup cinder volumes
● remove_dangling_cinder_snapshots.service                                                         loaded failed failed    backup cinder volumes

As for why it didn't alert I think it might be related to team-wmcs/general_systemd_unit_down.yaml

# deploy-tag: ops
# deploy-site: eqiad

Change #1300730 had a related patch set uploaded (by Volans; author: Volans):

[operations/puppet@production] wmcs-backups: fix openstack access

https://gerrit.wikimedia.org/r/1300730

The systemd unit is clearly failed:

● backup_cinder_volumes.service                                                                    loaded failed failed    backup cinder volumes
● remove_dangling_cinder_snapshots.service                                                         loaded failed failed    backup cinder volumes

As for why it didn't alert I think it might be related to team-wmcs/general_systemd_unit_down.yaml

# deploy-tag: ops
# deploy-site: eqiad

that's correct, I have opened T428873 to rectify the situation

Change #1300730 merged by Volans:

[operations/puppet@production] wmcs-backups: fix openstack access

https://gerrit.wikimedia.org/r/1300730

Change #1300758 had a related patch set uploaded (by Volans; author: Volans):

[operations/puppet@production] mwopenstackclients.py: fix proxy_url

https://gerrit.wikimedia.org/r/1300758

Change #1300758 merged by Volans:

[operations/puppet@production] mwopenstackclients.py: fix proxy_url

https://gerrit.wikimedia.org/r/1300758

Volans lowered the priority of this task from Unbreak Now! to Medium.EditedJun 11 2026, 12:12 PM

With the above patches merged the remote backups are now working again. I've manually triggered the ones from cloudbackup2004 that are currently running. The ones from cloudbackup2003 will trigger automatically at 19UTC tonight, I'll check later on that they will start properly.

I'll keep an eye on the process and I've verified that it will not overlap (type oneshot) so we don't have to worry about that.

Lowering priority, I'll keep the task open until we have a full run of backups.

Change #1300802 had a related patch set uploaded (by Volans; author: Volans):

[operations/puppet@production] wmcs cinder backups: set temporary retention

https://gerrit.wikimedia.org/r/1300802

Change #1300802 merged by Volans:

[operations/puppet@production] wmcs cinder backups: set temporary retention

https://gerrit.wikimedia.org/r/1300802

The cleanup (that unfortunately was setup to run before the backup and not after) has completed a while ago and the actual backups are running fine so far. Keep monitoring and leaving the task open until successful completion.

Backups on cloudbackup2003 have started and old backups were kept as expected. New ones so far have been all full backups.

cloudbackup2004 backups are still going, currently backing up the tool-nfs volume (17.9% 160.0MB/sØ ETA 14h53m). I'll keep an eye that the 07:00 UTC timer doesn't overlap.

cloudbackup2003 backups failed when they failed to create the backup for a specific volume:

Jun 12 01:16:34 cloudbackup2003 wmcs-backup[270700]: INFO:[2026-06-12 01:16:34,291] Backing up image 48552d6d-6b85-467f-bb99-a3100502aff2
Jun 12 01:16:37 cloudbackup2003 wmcs-backup[270700]: INFO:[2026-06-12 01:16:37,920] Creating differential backup of pool:eqiad1-cinder image_name:volume-48552d6d-6b85-467f-bb99-a3100502aff2 from rbd snapshot eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-03-03T20:48:07_cloudbackup2003 and backy2 version 89ee2efa-1731-11f1-8000-84160cded950
Jun 12 01:16:40 cloudbackup2003 wmcs-backup[330018]: [68B blob data]
Jun 12 01:16:45 cloudbackup2003 wmcs-backup[330056]:    ERROR: [backy2.logging] Sample larger than population or is negative
Jun 12 01:16:46 cloudbackup2003 wmcs-backup[330056]:    ERROR: [backy2.logging] Backy failed.
Jun 12 01:16:46 cloudbackup2003 wmcs-backup[270700]: WARNING:[2026-06-12 01:16:46,105] Got an error trying to backup trove-3ab770f7-554b-47d9-9d16-4ed9f800a483, try n#0 of 3: Command '['/usr/bin/backy2', 'backup', '--snapshot-name', '2026-06-12T01:16:36_cloudbackup2003', '--rbd', '/tmp/tmp6ueedvq1', '--from-version', '89ee2efa-1731-11f1-8000-84160cded950', 'rbd://eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-06-12T01:16:36_cloudbackup2003', 'volume-48552d6d-6b85-467f-bb99-a3100502aff2', '--expire', '2026-12-29 01:16:36', '--tag', 'differential_backup']' returned non-zero exit status 100.
Jun 12 01:16:46 cloudbackup2003 wmcs-backup[270700]: INFO:[2026-06-12 01:16:46,105] Backing up image 48552d6d-6b85-467f-bb99-a3100502aff2
Jun 12 01:16:49 cloudbackup2003 wmcs-backup[270700]: INFO:[2026-06-12 01:16:49,703] Creating differential backup of pool:eqiad1-cinder image_name:volume-48552d6d-6b85-467f-bb99-a3100502aff2 from rbd snapshot eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-03-03T20:48:07_cloudbackup2003 and backy2 version 89ee2efa-1731-11f1-8000-84160cded950
Jun 12 01:16:52 cloudbackup2003 wmcs-backup[330136]: [68B blob data]
Jun 12 01:16:57 cloudbackup2003 wmcs-backup[330176]:    ERROR: [backy2.logging] Sample larger than population or is negative
Jun 12 01:16:57 cloudbackup2003 wmcs-backup[330176]:    ERROR: [backy2.logging] Backy failed.
Jun 12 01:16:58 cloudbackup2003 wmcs-backup[270700]: WARNING:[2026-06-12 01:16:58,021] Got an error trying to backup trove-3ab770f7-554b-47d9-9d16-4ed9f800a483, try n#1 of 3: Command '['/usr/bin/backy2', 'backup', '--snapshot-name', '2026-06-12T01:16:47_cloudbackup2003', '--rbd', '/tmp/tmp_hio8i3b', '--from-version', '89ee2efa-1731-11f1-8000-84160cded950', 'rbd://eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-06-12T01:16:47_cloudbackup2003', 'volume-48552d6d-6b85-467f-bb99-a3100502aff2', '--expire', '2026-12-29 01:16:47', '--tag', 'differential_backup']' returned non-zero exit status 100.
Jun 12 01:16:58 cloudbackup2003 wmcs-backup[270700]: INFO:[2026-06-12 01:16:58,021] Backing up image 48552d6d-6b85-467f-bb99-a3100502aff2
Jun 12 01:17:01 cloudbackup2003 wmcs-backup[270700]: INFO:[2026-06-12 01:17:01,766] Creating differential backup of pool:eqiad1-cinder image_name:volume-48552d6d-6b85-467f-bb99-a3100502aff2 from rbd snapshot eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-03-03T20:48:07_cloudbackup2003 and backy2 version 89ee2efa-1731-11f1-8000-84160cded950
Jun 12 01:17:04 cloudbackup2003 wmcs-backup[330280]: [68B blob data]
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[330319]:    ERROR: [backy2.logging] Sample larger than population or is negative
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[330319]:    ERROR: [backy2.logging] Backy failed.
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]: WARNING:[2026-06-12 01:17:10,510] Got an error trying to backup trove-3ab770f7-554b-47d9-9d16-4ed9f800a483, try n#2 of 3: Command '['/usr/bin/backy2', 'backup', '--snapshot-name', '2026-06-12T01:16:59_cloudbackup2003', '--rbd', '/tmp/tmpn1c6sux1', '--from-version', '89ee2efa-1731-11f1-8000-84160cded950', 'rbd://eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-06-12T01:16:59_cloudbackup2003', 'volume-48552d6d-6b85-467f-bb99-a3100502aff2', '--expire', '2026-12-29 01:16:59', '--tag', 'differential_backup']' returned non-zero exit status 100.
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]: Traceback (most recent call last):
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/local/sbin/wmcs-backup", line 2190, in <module>
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     args.func()
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ~~~~~~~~~^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/local/sbin/wmcs-backup", line 2116, in <lambda>
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     func=lambda: get_current_volumes_state(from_cache=args.from_cache).backup_assigned_images(
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:                  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         noop=args.noop
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         ^^^^^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     )
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/local/sbin/wmcs-backup", line 1514, in backup_assigned_images
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     self.create_image_backup(
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ~~~~~~~~~~~~~~~~~~~~~~~~^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         image_info=image_info,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         ^^^^^^^^^^^^^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         project_name=project_id,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         ^^^^^^^^^^^^^^^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         noop=noop,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         ^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     )
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/local/sbin/wmcs-backup", line 1455, in create_image_backup
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     self.image_backups[image_id].create_next_backup(noop=noop)
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/local/sbin/wmcs-backup", line 425, in create_next_backup
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     new_backup = ImageBackup.create_diff_backup(
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         pool=self.config.ceph_pool,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ...<5 lines>...
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         noop=noop,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     )
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/local/sbin/wmcs-backup", line 199, in create_diff_backup
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     new_entry = BackupEntry.create_diff_backup(
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         image_name=ceph_id,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ...<5 lines>...
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         noop=noop,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     )
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/lib/python3/dist-packages/rbd2backy2.py", line 402, in create_diff_backup
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     run_command(
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ~~~~~~~~~~~^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         [
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         ^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ...<17 lines>...
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         noop=noop,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:         ^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     )
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     ^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/lib/python3/dist-packages/rbd2backy2.py", line 29, in run_command
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     output = subprocess.check_output(args).decode("utf8")
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:              ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/lib/python3.13/subprocess.py", line 472, in check_output
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:            ~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:                **kwargs).stdout
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:                ^^^^^^^^^
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:   File "/usr/lib/python3.13/subprocess.py", line 577, in run
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:     raise CalledProcessError(retcode, process.args,
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]:                              output=stdout, stderr=stderr)
Jun 12 01:17:10 cloudbackup2003 wmcs-backup[270700]: subprocess.CalledProcessError: Command '['/usr/bin/backy2', 'backup', '--snapshot-name', '2026-06-12T01:16:59_cloudbackup2003', '--rbd', '/tmp/tmpn1c6sux1', '--from-version', '89ee2efa-1731-11f1-8000-84160cded950', 'rbd://eqiad1-cinder/volume-48552d6d-6b85-467f-bb99-a3100502aff2@2026-06-12T01:16:59_cloudbackup2003', 'volume-48552d6d-6b85-467f-bb99-a3100502aff2', '--expire', '2026-12-29 01:16:59', '--tag', 'differential_backup']' returned non-zero exit status 100.
Jun 12 01:17:10 cloudbackup2003 systemd[1]: backup_cinder_volumes.service: Main process exited, code=exited, status=1/FAILURE
Jun 12 01:17:10 cloudbackup2003 systemd[1]: backup_cinder_volumes.service: Failed with result 'exit-code'.
Jun 12 01:17:10 cloudbackup2003 systemd[1]: Failed to start backup_cinder_volumes.service - backup cinder volumes.
Jun 12 01:17:10 cloudbackup2003 systemd[1]: backup_cinder_volumes.service: Consumed 7h 54min 26.299s CPU time, 488.8G memory peak.

I've manually removed the snapshot for the failed volume so that it should force it to make a full backup and restarted the process on backup2003.

The full run on cloudbackup2003 failed again for volume-9ec2e481-26dd-41d1-81bf-24b43abcee12, due to T428995. I've manually cleaned snapshots for that volume. But I'm not sure what's the best action here. We depend on an unmaintained software that has bugs.

I've extracted the list of volumes from backy2 ls for which the last backup is from march, and I passed that to rbd to list the snapshots. What I can do is pre-emptively delete all the snapshots associated so to probably force a full backup in all cases and get out of this empasse. Thoughts?

Agreed on irc to clear the unprotected snapshots created by cloudbackup in 2026. Extracted the list with:

$ while read -r vol; do
    sudo rbd --pool eqiad1-cinder snap ls "$vol" \
        | grep -v " yes " | grep _cloudbackup | grep 2026 \
        | awk -v vol="$vol" '{print "sudo rbd --pool eqiad1-cinder snap remove --snap-id " $1 " " vol}'
done < volumes_to_clear.txt

Running now on tmux with: while read line; do echo $line; $line; sleep 60; done < volumes_to_clear.sh

Cleanup completed, the next backup run will start in less than 2h, hopefully will run all the way.

cloudbackup2004 round of backups completed successfully tonight after running for ~2 days (started on 2026-06-11 11:25:52m not too bad), the next run will start at 07 UTC.

Jun 13 02:19:53 cloudbackup2004 systemd[1]: backup_cinder_volumes.service: Consumed 2d 59min 968ms CPU time, 463.9G memory peak.

cloudbackup2003 round is still running (good that it hasn't failed, hopefully the cleanup of old ceph snapshot helped here) and has backed up 491 volumes so far.

Finally a full round of backups from cloudbackup2003 has completed:

Jun 13 17:09:35 cloudbackup2003 systemd[1]: backup_cinder_volumes.service: Consumed 22h 21min 17.189s CPU time, 467.8G memory peak.

On cloudbackup2004 the new run lasted ~7h from 07UTC:

Jun 13 14:17:51 cloudbackup2004 systemd[1]: backup_cinder_volumes.service: Consumed 9h 26min 43.636s CPU time, 464.8G memory peak.

Leaving the task open for final checks on monday and to restore the retention to a sane value.

Change #1303487 had a related patch set uploaded (by Volans; author: Volans):

[operations/puppet@production] WMCS cinder backups: adjust retention

https://gerrit.wikimedia.org/r/1303487

Change #1303487 merged by Volans:

[operations/puppet@production] WMCS cinder backups: adjust retention

https://gerrit.wikimedia.org/r/1303487

Change #1304865 had a related patch set uploaded (by Volans; author: Volans):

[operations/puppet@production] WMCS backups: set retention back to sane value

https://gerrit.wikimedia.org/r/1304865

Change #1304865 merged by Volans:

[operations/puppet@production] WMCS backups: set retention back to sane value

https://gerrit.wikimedia.org/r/1304865

All cinder backups are now working fine, the retention period has been restored to a sane value (10 days, was 8 before). All the old backups have been automatically cleaned up.

Resolving.