Created attachment 1806592 [details] vdsm.log Description of problem: When using a block-based SD and one host is put into maintenance mode, the storage domain is disconnected from the host, causing that the ovirt-ha-broker service cannot update the status because the he_metadata LV has been deactivated. This causes that both the ovirt-ha-agent and ovirt-ha-broker services restart to try to recover the storage. After the ovirt-ha-broker service is started the needed LVs are activated, but vdsm deactivates them again short after. This causes a restart loop on the ovirt-ha-* services and notifications emails are sent to the administrator every few minutes. Version-Release number of selected component (if applicable): vdsm-4.40.70.6-1.el8ev.x86_64 ovirt-hosted-engine-ha-2.4.7-1.el8ev.noarch ovirt-engine-4.4.7.6-0.11.el8ev.noarch How reproducible: Happens on customer environment using FC storage and reproduced locally with an iSCSI SD. Steps to Reproduce: 1. Deploy HE on a 2 nodes cluster with iSCSI storage. 2. Put one node into maintenance mode. Actual results: Relevant UUIDs: image_guid 'df774f3a-09ba-44ac-a537-856a016e1316' -> he_metadata SD '18389231-4400-44d8-8d65-61ba71ae5511' -> hosted_storage ## When entering the maintenance mode, vdsm tears down the SD, deactivating the LVs: 2021-07-27 14:30:04,547+0000 INFO (jsonrpc/5) [vds] Setting Hosted Engine HA local maintenance to True (API:1702) 2021-07-27 14:30:06,683+0000 INFO (jsonrpc/2) [vdsm.api] START stopMonitoringDomain(sdUUID='18389231-4400-44d8-8d65-61ba71ae5511', options=None) from=::1,57834, task_id=0cf0b147-7044-4c1e-9bf5-03a55ffa82e7 (api:48) 2021-07-27 14:30:10,217+0000 INFO (monitor/1838923) [storage.BlockSD] Tearing down domain 18389231-4400-44d8-8d65-61ba71ae5511 (blockSD:995) ## In supervdsm.log, we see that the he_metadata disk is deactivated: MainProcess|monitor/1838923::INFO::2021-07-27 14:30:15,148::devicemapper::138::storage.devicemapper::(removeMapping) Removing device mapping 18389231--4400--44d8--8d65--61ba71ae5511-df774f3a--09ba--44ac--a537--856a016e1316 ## In broker.log, the ovirt-ha-broker service fails to update the metadata, as the symlink of the he_metadata disk points to a non-existing device: StatusStorageThread::ERROR::2021-07-27 14:30:15,282::storage_broker::223::ovirt_hosted_engine_ha.broker.storage_broker.StorageBroker::(put_stats) Failed to write metadata for host 2 to /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316 Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ovirt_hosted_engine_ha/broker/storage_broker.py", line 215, in put_stats f = os.open(path, direct_flag | os.O_WRONLY | os.O_SYNC) FileNotFoundError: [Errno 2] No such file or directory: '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316' StatusStorageThread::ERROR::2021-07-27 14:30:15,297::status_broker::90::ovirt_hosted_engine_ha.broker.status_broker.StatusBroker.Update::(run) Failed to update state. Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ovirt_hosted_engine_ha/broker/storage_broker.py", line 215, in put_stats f = os.open(path, direct_flag | os.O_WRONLY | os.O_SYNC) FileNotFoundError: [Errno 2] No such file or directory: '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316' ## The broker restarts: StatusStorageThread::ERROR::2021-07-27 14:30:15,305::status_broker::70::ovirt_hosted_engine_ha.broker.status_broker.StatusBroker.Update::(trigger_restart) Trying to restart the broker MainThread::INFO::2021-07-27 14:30:47,718::broker::47::ovirt_hosted_engine_ha.broker.broker.Broker::(run) ovirt-hosted-engine-ha broker 2.4.7 started ## vdsm activates the LVs: 2021-07-27 14:30:47,810+0000 INFO (Reactor thread) [Broker.StompAdapter] Processing CONNECT request (stompserver:95) 2021-07-27 14:30:47,811+0000 INFO (JsonRpc (StompReactor)) [Broker.StompAdapter] Subscribe command received (stompserver:124) 2021-07-27 14:30:49,822+0000 INFO (jsonrpc/4) [vdsm.api] START connectStorageServer(domType=3, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '10.37.201.136', 'iqn': 'iqn.2003-01.org.linux-iscsi.jorti-nfs.x8664:sn.a4d3ba1f2da2', 'tpgt': '1', 'user': '', 'password': '********', 'id': 'c930a7ee-498c-4a3b-9610-b4731d799f01', 'port': '3260'}], options=None) from=::1,57862, task_id=94085357-ee74-4e17-8f96-0ea0bb21ae02 (api:48) 2021-07-27 14:30:55,854+0000 INFO (jsonrpc/0) [storage.LVM] Activating lvs: vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['ids'] (lvm:1755) 2021-07-27 14:30:56,013+0000 INFO (jsonrpc/0) [storage.LVM] Activating lvs: vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['leases'] (lvm:1755) 2021-07-27 14:30:56,146+0000 INFO (jsonrpc/0) [storage.LVM] Activating lvs: vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['metadata', 'inbox', 'outbox', 'xleases', 'master'] (lvm:1755) 2021-07-27 14:30:56,912+0000 INFO (jsonrpc/1) [vdsm.api] START prepareImage(sdUUID='18389231-4400-44d8-8d65-61ba71ae5511', spUUID='00000000-0000-0000-0000-000000000000', imgUUID='4b152815-0797-4854-8797-aa8e12a02814', leafUUID='df774f3a-09ba-44ac-a537-856a016e1316', allowIllegal=False) from=::1,57862, task_id=1b1e5cba-b29e-4788-99ec-848e0185e3cf (api:48) 2021-07-27 14:30:57,050+0000 INFO (jsonrpc/1) [storage.LVM] Activating lvs: vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['df774f3a-09ba-44ac-a537-856a016e1316'] (lvm:1755) 2021-07-27 14:30:57,193+0000 INFO (jsonrpc/1) [storage.StorageDomain] Creating image run directory '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814' (blockSD:1363) 2021-07-27 14:30:57,193+0000 INFO (jsonrpc/1) [storage.fileUtils] Creating directory: /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814 mode: None (fileUtils:201) 2021-07-27 14:30:57,193+0000 INFO (jsonrpc/1) [storage.StorageDomain] Creating symlink from /dev/18389231-4400-44d8-8d65-61ba71ae5511/df774f3a-09ba-44ac-a537-856a016e1316 to /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316 (blockSD:1368) 2021-07-27 14:30:57,385+0000 INFO (jsonrpc/1) [vdsm.api] FINISH prepareImage return={'path': '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316', 'info': {'type': 'block', 'path': '/rhev/data-center/mnt/blockSD/18389231-4400-44d8-8d65-61ba71ae5511/images/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316'}, 'imgVolumesInfo': [{'domainID': '18389231-4400-44d8-8d65-61ba71ae5511', 'imageID': '4b152815-0797-4854-8797-aa8e12a02814', 'volumeID': 'df774f3a-09ba-44ac-a537-856a016e1316', 'path': '/rhev/data-center/mnt/blockSD/18389231-4400-44d8-8d65-61ba71ae5511/images/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316', 'leasePath': '/dev/18389231-4400-44d8-8d65-61ba71ae5511/leases', 'leaseOffset': 111149056}]} from=::1,57862, task_id=1b1e5cba-b29e-4788-99ec-848e0185e3cf (api:54) 2021-07-27 14:30:57,390+0000 INFO (jsonrpc/3) [vdsm.api] START prepareImage(sdUUID='18389231-4400-44d8-8d65-61ba71ae5511', spUUID='00000000-0000-0000-0000-000000000000', imgUUID='3e99f583-3dd6-467f-a465-515ddd333198', leafUUID='477324a2-b98e-44b6-a8f3-d9ab7a6ccc48', allowIllegal=False) from=::1,57862, task_id=c30bdd08-af90-4e5f-a806-7e20a4d52963 (api:48) ## But short after, vdsm tears down the SD again: 2021-07-27 14:31:35,589+0000 INFO (jsonrpc/1) [storage.Monitor] Stop monitoring 18389231-4400-44d8-8d65-61ba71ae5511 (shutdown=False) (monitor:268) 2021-07-27 14:31:35,589+0000 INFO (monitor/1838923) [storage.check] Stop checking '/dev/18389231-4400-44d8-8d65-61ba71ae5511/metadata' (check:135) 2021-07-27 14:31:35,589+0000 INFO (monitor/1838923) [storage.SANLock] Releasing host id for domain 18389231-4400-44d8-8d65-61ba71ae5511 (id: 2) (clusterlock:447) 2021-07-27 14:31:37,590+0000 INFO (monitor/1838923) [storage.SANLock] Host id for domain 18389231-4400-44d8-8d65-61ba71ae5511 released successfully (id: 2) (clusterlock:462) 2021-07-27 14:31:37,590+0000 INFO (monitor/1838923) [storage.BlockSD] Tearing down domain 18389231-4400-44d8-8d65-61ba71ae5511 (blockSD:995) supervdsm.log: MainProcess|monitor/1838923::INFO::2021-07-27 14:31:42,512::devicemapper::138::storage.devicemapper::(removeMapping) Removing device mapping 18389231--4400--44d8--8d65--61ba71ae5511-df774f3a--09ba--44ac--a537--856a016e1316 ## This causes that the broker fails to update the metadata again, and attempts to restart in an endless loop: StatusStorageThread::ERROR::2021-07-27 14:31:42,665::storage_broker::223::ovirt_hosted_engine_ha.broker.storage_broker.StorageBroker::(put_stats) Failed to write metadata for host 2 to /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316 Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ovirt_hosted_engine_ha/broker/storage_broker.py", line 215, in put_stats f = os.open(path, direct_flag | os.O_WRONLY | os.O_SYNC) FileNotFoundError: [Errno 2] No such file or directory: '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316' StatusStorageThread::ERROR::2021-07-27 14:31:42,666::status_broker::90::ovirt_hosted_engine_ha.broker.status_broker.StatusBroker.Update::(run) Failed to update state. Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ovirt_hosted_engine_ha/broker/storage_broker.py", line 215, in put_stats f = os.open(path, direct_flag | os.O_WRONLY | os.O_SYNC) FileNotFoundError: [Errno 2] No such file or directory: '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316' StatusStorageThread::ERROR::2021-07-27 14:31:42,668::status_broker::70::ovirt_hosted_engine_ha.broker.status_broker.StatusBroker.Update::(trigger_restart) Trying to restart the broker MainThread::INFO::2021-07-27 14:32:17,217::broker::47::ovirt_hosted_engine_ha.broker.broker.Broker::(run) ovirt-hosted-engine-ha broker 2.4.7 started Expected results: Some kind of coordination between the HA services and vdsm should exist so the HA metadata can be updated in the storage. Additional info:
Created attachment 1806593 [details] broker.log
Created attachment 1806595 [details] engine.log
Can Eyal or Martin please explain why this bug is moved around without any explanation? I do not know the relevant code well, but can't believe this is an old bug. Since -ha didn't change recently around this functionality and this is a new report of this issue, I suppose this is due to a change in the engine or vdsm. So: 1. Did we start disconnecting shared storage during maintenance recently? 2. -HA does require access to at least some shared storage, as detailed in comment 0. What are Storage/Infra teams' thoughts about this? Thanks!
(In reply to Yedidyah Bar David from comment #3) > Can Eyal or Martin please explain why this bug is moved around without any > explanation? > > I do not know the relevant code well, but can't believe this is an old bug. > Since -ha didn't change recently around this functionality and this is a new > report of this issue, I suppose this is due to a change in the engine or > vdsm. So: > > 1. Did we start disconnecting shared storage during maintenance recently? > > 2. -HA does require access to at least some shared storage, as detailed in > comment 0. What are Storage/Infra teams' thoughts about this? When setting the host to maintenance, the storage domain is disconnected from the host and the ovirt-ha-broker service cannot access the storage. In the past, vdsm was buggy and did not deactivate the storage LVs properly, but now it is fixed. The ha code is wrong and should be fixed accordingly.
(In reply to Juan Orti from comment #0) > Created attachment 1806592 [details] > vdsm.log > > Description of problem: > When using a block-based SD and one host is put into maintenance mode, the > storage domain is disconnected from the host, causing that the > ovirt-ha-broker service cannot update the status because the he_metadata LV > has been deactivated. This is expected behavior and correct. > This causes that both the ovirt-ha-agent and > ovirt-ha-broker services restart to try to recover the storage. This is wrong, ovirt-ha-* cannot access storage when host is in maintainance, and should not try. > After the ovirt-ha-broker service is started the needed LVs are activated, How the lvs are activated? > but vdsm deactivates them again short after. This causes a restart loop on > the ovirt-ha-* services and notifications emails are sent to the > administrator every few minutes. If vdsm is not connected to storage, it is expected that the lvs will be deactivated when vsdm does periodic cleanup. > Relevant UUIDs: > image_guid 'df774f3a-09ba-44ac-a537-856a016e1316' -> he_metadata > SD '18389231-4400-44d8-8d65-61ba71ae5511' -> hosted_storage > > ## When entering the maintenance mode, vdsm tears down the SD, deactivating > the LVs: > > 2021-07-27 14:30:04,547+0000 INFO (jsonrpc/5) [vds] Setting Hosted Engine > HA local maintenance to True (API:1702) > 2021-07-27 14:30:06,683+0000 INFO (jsonrpc/2) [vdsm.api] START > stopMonitoringDomain(sdUUID='18389231-4400-44d8-8d65-61ba71ae5511', > options=None) from=::1,57834, task_id=0cf0b147-7044-4c1e-9bf5-03a55ffa82e7 > (api:48) > 2021-07-27 14:30:10,217+0000 INFO (monitor/1838923) [storage.BlockSD] > Tearing down domain 18389231-4400-44d8-8d65-61ba71ae5511 (blockSD:995) Good > ## In supervdsm.log, we see that the he_metadata disk is deactivated: > > MainProcess|monitor/1838923::INFO::2021-07-27 > 14:30:15,148::devicemapper::138::storage.devicemapper::(removeMapping) > Removing device mapping > 18389231--4400--44d8--8d65--61ba71ae5511-df774f3a--09ba--44ac--a537-- > 856a016e1316 > > > ## In broker.log, the ovirt-ha-broker service fails to update the metadata, > as the symlink of the he_metadata disk points to a non-existing device: > > StatusStorageThread::ERROR::2021-07-27 > 14:30:15,282::storage_broker::223::ovirt_hosted_engine_ha.broker. > storage_broker.StorageBroker::(put_stats) Failed to write metadata for host > 2 to > /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316 > Traceback (most recent call last): > File > "/usr/lib/python3.6/site-packages/ovirt_hosted_engine_ha/broker/ > storage_broker.py", line 215, in put_stats > f = os.open(path, direct_flag | os.O_WRONLY | os.O_SYNC) > FileNotFoundError: [Errno 2] No such file or directory: > '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316' > StatusStorageThread::ERROR::2021-07-27 > 14:30:15,297::status_broker::90::ovirt_hosted_engine_ha.broker.status_broker. > StatusBroker.Update::(run) Failed to update state. > Traceback (most recent call last): > File > "/usr/lib/python3.6/site-packages/ovirt_hosted_engine_ha/broker/ > storage_broker.py", line 215, in put_stats > f = os.open(path, direct_flag | os.O_WRONLY | os.O_SYNC) > FileNotFoundError: [Errno 2] No such file or directory: > '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316' I think the bug is that the broker was not stopped, or maybe not moved to local-maintenance mode. > ## The broker restarts: > > StatusStorageThread::ERROR::2021-07-27 > 14:30:15,305::status_broker::70::ovirt_hosted_engine_ha.broker.status_broker. > StatusBroker.Update::(trigger_restart) Trying to restart the broker > MainThread::INFO::2021-07-27 > 14:30:47,718::broker::47::ovirt_hosted_engine_ha.broker.broker.Broker::(run) > ovirt-hosted-engine-ha broker 2.4.7 started > > > ## vdsm activates the LVs: > > 2021-07-27 14:30:47,810+0000 INFO (Reactor thread) [Broker.StompAdapter] > Processing CONNECT request (stompserver:95) > 2021-07-27 14:30:47,811+0000 INFO (JsonRpc (StompReactor)) > [Broker.StompAdapter] Subscribe command received (stompserver:124) > 2021-07-27 14:30:49,822+0000 INFO (jsonrpc/4) [vdsm.api] START > connectStorageServer(domType=3, > spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': > '10.37.201.136', 'iqn': > 'iqn.2003-01.org.linux-iscsi.jorti-nfs.x8664:sn.a4d3ba1f2da2', 'tpgt': '1', > 'user': '', 'password': '********', 'id': > 'c930a7ee-498c-4a3b-9610-b4731d799f01', 'port': '3260'}], options=None) > from=::1,57862, task_id=94085357-ee74-4e17-8f96-0ea0bb21ae02 (api:48) > 2021-07-27 14:30:55,854+0000 INFO (jsonrpc/0) [storage.LVM] Activating lvs: > vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['ids'] (lvm:1755) > 2021-07-27 14:30:56,013+0000 INFO (jsonrpc/0) [storage.LVM] Activating lvs: > vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['leases'] (lvm:1755) > 2021-07-27 14:30:56,146+0000 INFO (jsonrpc/0) [storage.LVM] Activating lvs: > vg=18389231-4400-44d8-8d65-61ba71ae5511 lvs=['metadata', 'inbox', 'outbox', > 'xleases', 'master'] (lvm:1755) > 2021-07-27 14:30:56,912+0000 INFO (jsonrpc/1) [vdsm.api] START > prepareImage(sdUUID='18389231-4400-44d8-8d65-61ba71ae5511', > spUUID='00000000-0000-0000-0000-000000000000', > imgUUID='4b152815-0797-4854-8797-aa8e12a02814', > leafUUID='df774f3a-09ba-44ac-a537-856a016e1316', allowIllegal=False) > from=::1,57862, task_id=1b1e5cba-b29e-4788-99ec-848e0185e3cf (api:48) > 2021-07-27 14:30:57,050+0000 INFO (jsonrpc/1) [storage.LVM] Activating lvs: > vg=18389231-4400-44d8-8d65-61ba71ae5511 > lvs=['df774f3a-09ba-44ac-a537-856a016e1316'] (lvm:1755) > 2021-07-27 14:30:57,193+0000 INFO (jsonrpc/1) [storage.StorageDomain] > Creating image run directory > '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814' (blockSD:1363) > 2021-07-27 14:30:57,193+0000 INFO (jsonrpc/1) [storage.fileUtils] Creating > directory: > /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814 mode: None (fileUtils:201) > 2021-07-27 14:30:57,193+0000 INFO (jsonrpc/1) [storage.StorageDomain] > Creating symlink from > /dev/18389231-4400-44d8-8d65-61ba71ae5511/df774f3a-09ba-44ac-a537- > 856a016e1316 to > /run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316 (blockSD:1368) > 2021-07-27 14:30:57,385+0000 INFO (jsonrpc/1) [vdsm.api] FINISH > prepareImage return={'path': > '/run/vdsm/storage/18389231-4400-44d8-8d65-61ba71ae5511/4b152815-0797-4854- > 8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316', 'info': {'type': > 'block', 'path': > '/rhev/data-center/mnt/blockSD/18389231-4400-44d8-8d65-61ba71ae5511/images/ > 4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316'}, > 'imgVolumesInfo': [{'domainID': '18389231-4400-44d8-8d65-61ba71ae5511', > 'imageID': '4b152815-0797-4854-8797-aa8e12a02814', 'volumeID': > 'df774f3a-09ba-44ac-a537-856a016e1316', 'path': > '/rhev/data-center/mnt/blockSD/18389231-4400-44d8-8d65-61ba71ae5511/images/ > 4b152815-0797-4854-8797-aa8e12a02814/df774f3a-09ba-44ac-a537-856a016e1316', > 'leasePath': '/dev/18389231-4400-44d8-8d65-61ba71ae5511/leases', > 'leaseOffset': 111149056}]} from=::1,57862, > task_id=1b1e5cba-b29e-4788-99ec-848e0185e3cf (api:54) > 2021-07-27 14:30:57,390+0000 INFO (jsonrpc/3) [vdsm.api] START > prepareImage(sdUUID='18389231-4400-44d8-8d65-61ba71ae5511', > spUUID='00000000-0000-0000-0000-000000000000', > imgUUID='3e99f583-3dd6-467f-a465-515ddd333198', > leafUUID='477324a2-b98e-44b6-a8f3-d9ab7a6ccc48', allowIllegal=False) > from=::1,57862, task_id=c30bdd08-af90-4e5f-a806-7e20a4d52963 (api:48) Looks like the ha agent connected vdsm to storage - this is very wrong as the host was put to maintenance. This may lead to data corruption if the admin that put the host to maintenance assumes that the host will not connect to storage. > ## But short after, vdsm tears down the SD again: > > 2021-07-27 14:31:35,589+0000 INFO (jsonrpc/1) [storage.Monitor] Stop > monitoring 18389231-4400-44d8-8d65-61ba71ae5511 (shutdown=False) > (monitor:268) Someone asked to stop monitoring... > 2021-07-27 14:31:35,589+0000 INFO (monitor/1838923) [storage.check] Stop > checking '/dev/18389231-4400-44d8-8d65-61ba71ae5511/metadata' (check:135) > 2021-07-27 14:31:35,589+0000 INFO (monitor/1838923) [storage.SANLock] > Releasing host id for domain 18389231-4400-44d8-8d65-61ba71ae5511 (id: 2) > (clusterlock:447) > 2021-07-27 14:31:37,590+0000 INFO (monitor/1838923) [storage.SANLock] Host > id for domain 18389231-4400-44d8-8d65-61ba71ae5511 released successfully > (id: 2) (clusterlock:462) > 2021-07-27 14:31:37,590+0000 INFO (monitor/1838923) [storage.BlockSD] > Tearing down domain 18389231-4400-44d8-8d65-61ba71ae5511 (blockSD:995) > > supervdsm.log: > MainProcess|monitor/1838923::INFO::2021-07-27 > 14:31:42,512::devicemapper::138::storage.devicemapper::(removeMapping) > Removing device mapping > 18389231--4400--44d8--8d65--61ba71ae5511-df774f3a--09ba--44ac--a537-- > 856a016e1316 And when we stop monitoring, we must deactivate the storage domain. > ## This causes that the broker fails to update the metadata again, and > attempts to restart in an endless loop: HA services should stop doing this.
Didi, can you move this bug to ovirt-ha component? vdsm behavior is correct.
As far as I remember, moving a host to maintenance when the host is also an hosted engine host meant: - Put the host in Hosted Engine Local maintenance (so HA Agent won't try to do anything) - Put the host in Host Maintenance (do whatever you need to do on the host) and I may be wrong but this also implied stopping HA services All this was handled by ovirt-host-deploy if I remember correctly. Didi can you check and keep me honest on this?
(In reply to Eyal Shenitzky from comment #4) > When setting the host to maintenance, the storage domain is disconnected > from the host and the ovirt-ha-broker service cannot access the storage. > In the past, vdsm was buggy and did not deactivate the storage LVs properly, > but now it is fixed. OK. > > The ha code is wrong and should be fixed accordingly. Understood. But: The fix to vdsm caused a regression - the current bug. If our testing would have covered also the current bug flow, you wouldn't have merged the vdsm fix - you'd first made sure to not introduce the regression. But our testing didn't, so the patch was merged, and now we have a customer running into this bug and reporting it. So now, IMHO, what we should do is: 1. Revert the vdsm fix 2. Make sure to cover the current bug flow in future testing 3. Open one or more bugs as needed on relevant components to make sure the fix to vdsm does not introduce this regression, probably including ovirt-hosted-engine-ha, perhaps with the design you suggest 4. Reopen/clone the original vdsm bug and make it depend on these bugs. I still didn't see a reference to the vdsm bug that was fixed. If you feel like completely reverting the fix to it is too risky, please prepare a smaller-scale partial revert, such as perhaps an exception for hosted-engine metadata storage domains or something similar. Thanks.
*** Bug 1997609 has been marked as a duplicate of this bug. ***
I now finished an "exercise" [1] to prevent the broker restart loop and disconnect/reconnect storage loop in vdsm. With this, I can move a host to maintenance and then activate it, back and forth, and get no repeating errors in any log. When it's in maintenance, though, 'hosted-engine --vm-status' on any host returns stale data or none. If we do want the original request in this bug: (In reply to Juan Orti from comment #0) > Expected results: > Some kind of coordination between the HA services and vdsm should exist so > the HA metadata can be updated in the storage. then we do want something like comment 8. Thus, not proposing [1] for merging, for now. That said: Is the current situation causing real problems? Or just noise in logs etc.? [1] https://github.com/didib/ovirt-hosted-engine-ha/commits/maintenance-no-storage-stuff
(In reply to Yedidyah Bar David from comment #8) > (In reply to Eyal Shenitzky from comment #4) > > When setting the host to maintenance, the storage domain is disconnected > > from the host and the ovirt-ha-broker service cannot access the storage. > > In the past, vdsm was buggy and did not deactivate the storage LVs properly, > > but now it is fixed. > > OK. > > > > > The ha code is wrong and should be fixed accordingly. > > Understood. > > But: > > The fix to vdsm caused a regression - the current bug. If our testing would > have covered also the current bug flow, you wouldn't have merged the vdsm > fix - you'd first made sure to not introduce the regression. But our testing > didn't, so the patch was merged, and now we have a customer running into > this bug and reporting it. > > So now, IMHO, what we should do is: > > 1. Revert the vdsm fix The vdsm fix includes multiple changes in multiple releases. I think the last issue was fixed in 4.4.6 (Vojta can add more details on that). We cannot revert vdsm to brocken behavior at this point, even if it breaks code assuming the broken behavior. Code should assume only documented behavior - anything else is not supported and may change between minor releases. > 2. Make sure to cover the current bug flow in future testing This is the most important thing. vdsm developers do not understand or test hosted engine flows. If the flows are not tested by QE or automated tests they will continue to fail in the future. > I still didn't see a reference to the vdsm bug that was fixed. If you feel > like completely reverting the fix to it is too risky, please prepare a > smaller-scale partial revert, such as perhaps an exception for hosted-engine > metadata storage domains or something similar. There is no way to make an exception for things like this. When you deactivate a storage domain it MUST deactivate all logical volumes. Vojta, can you add more info on the relevant fixes related to deactivating logical volumes when storage domain is deactivated, and when they were released?
(In reply to Yedidyah Bar David from comment #12) > If we do want the original request in this bug: > > (In reply to Juan Orti from comment #0) > > Expected results: > > Some kind of coordination between the HA services and vdsm should exist so > > the HA metadata can be updated in the storage. When host is deactivated in engine, it cannot access storage, and it cannot participate in hosted engine cluster. Engine assumes that the host does not access storage, and we should not do thins behind engine back. Connecting inactive host to storage should be done only for debugging purpose by support. When a host is active, it can participate in hosted engine cluster. So maybe the fix is to make sure that a host is active in the relevant flow. Hosted engine supports connecting a host to the hosted engine storage domain during bootstrap, I think via calls to connectStorageServer, and startMonitoringStorageDomain. Theoretically this can be used to connect host only to the hosted engine storage domain. If we have a need to have a state when host is unused by engine, but is connected the hosted engine cluster, this should be done on engine side by introducing a new host state.
(In reply to Nir Soffer from comment #14) > (In reply to Yedidyah Bar David from comment #12) > > If we do want the original request in this bug: > > > > (In reply to Juan Orti from comment #0) > > > Expected results: > > > Some kind of coordination between the HA services and vdsm should exist so > > > the HA metadata can be updated in the storage. > > When host is deactivated in engine, it cannot access storage, and it cannot > participate in hosted engine cluster. Engine assumes that the host does not > access storage, and we should not do thins behind engine back. Not questioning your statement for the current case, but in general, HA does have to sometimes do things "behind the engine's back", by definition. If e.g. the engine VM dies unexpectedly and HA starts it on some other host, the engine does not know that until it scans all hosts (well, at least the old and new). Juan didn't clarify what other things he wants, but in principle, I can expect people wanting to use a host that's in maintenance for starting the engine VM. Consider e.g. this flow: 1. Have hosted-engine with two active hosts. 2. Put host-0 to maintenance for some reason (e.g. upgrade or whatever). 3. Get into a problem that kills the engine VM on host-1 and leaves it unstartable there for some reason. 4. Try to use host-0 for starting the engine VM, so that you can use the engine to try and fix the problem on host-1. Not saying I think it's mandatory to handle this flow. But I can see value in allowing it, even if only for support cases. > Connecting > inactive host to storage should be done only for debugging purpose by > support. AFAIU, right now, even this is not possible. If you manually connect storage, VDSM will shortly thereafter disconnect it. No? > > When a host is active, it can participate in hosted engine cluster. So maybe > the fix is to make sure that a host is active in the relevant flow. Well, the flow is "Move a host to maintenance" :-). > > Hosted engine supports connecting a host to the hosted engine storage domain > during bootstrap, I think via calls to connectStorageServer, and > startMonitoringStorageDomain. Theoretically this can be used to connect host > only to the hosted engine storage domain. But then VDSM will disconnect it, no? That's your point. > > If we have a need to have a state when host is unused by engine, but is > connected the hosted engine cluster, this should be done on engine side by > introducing a new host state. Perhaps. Keeping needinfo's on Juan and Krist, for clarifying the actual need. As I wrote before, I consider the report in comment 0 to be an annoyance, not more. I might be missing something. In addition: If the request here is/was to make sure that the move to LocalMaintenance is reported correctly so that the other hosts will see it, but then it's ok to have the storage disconnected (so that later changes to it by other hosts are not seen by the host that's in maintenance), that's doable - we should change HA's set_maintenance_mode method to be sync, or make VDSM's code in setHaMaintenanceMode wait until the status is written to the storage (a much simpler change, but will cause the move to maintenance to take longer) (and then probably use something like my patch from comment 12).
(In reply to Yedidyah Bar David from comment #12) > That said: Is the current situation causing real problems? Or just noise in > logs etc.? The original issue was about the noise in the logs and the host constantly flapping between HA states and thus sending emails every few minutes. No other problem was detected. My main concern about this is the constant connection and disconnection of the storage causing the activation of some LVs while in maintenance mode. If this is fixed and the only downside is that the host is reported as stale-data in the HA status, I guess it's fine. Can you confirm me that this won't send any email notification? Thanks.
> Vojta, can you add more info on the relevant fixes related to deactivating > logical volumes when storage domain is deactivated, and when they were > released? This was implemented as fix for BZ #1928041 and all relevant patches are linked under this BZ. Main patch, which fixed the issue and caused this bug to pop-up is https://gerrit.ovirt.org/c/vdsm/+/113712 It was released in vdsm 4.40.50.7. Besides the issue described in BZ #1928041, the main issue is that leaving SD activated on a host which is maintenance is in principle wrong and can lead to other issues, in worst case into data corruption, as already mentioned by Nir. Therefore IMHO we definitely shouldn't revert this patch.
it should disconnect everything in case of HE global maintenance, not local maintenance. HE agent is managing HE SD
targeting as discussed in office hours.
Dropping the target as it moved to different team and need to be reviewed.
With linked change 117565, I verified that moving to maintenance does not repeatedly try to reconnect to storage, nor notify, so it might be good enough. More details follow: Design criteria: 1. Should be simple to understand and review, for both developers and users. 2. Should introduce no new risks, including no subtle changes in functionality. 3. Should make the product better :-), compared to doing nothing or to only ask users (via doc) to manually do things/workaround. In particular, we probably want this flow: I. Move a host to maintenance II. Do stuff III. Activate the host to emit a constant (low) number of notifications, irrespective of the time that (II.) takes. My previous patchset (linked in comment 12) was probably slightly nicer (judging by number of notifications and log noise), but considerably more complex (at least IMO, at least considering I do not know this code very well). How does it work? 1. A user puts the host to maintenance. 2. agent and broker continue doing what they did so far, as the patch changes their behavior only during their start. 3. vdsm (eventually?) disconnects the storage, and also locally marks for HA that the host is in local maintenance. 4. Through various existing functionality, both agent and broker restart themselves, due to the missing storage. During this, they do emit a few notifications. 5. On agent restart, the patch just makes it wait until local maintenance is cleared. agent logs every 30 seconds 'Local maintenance set' and broker logs nothing. 6. User activates the host. This makes the agent exit the new loop added in the patch, (eventually) fail and restart due to existing functionality, along the way emitting a few notifications, and eventually reaching a stable state. One more flow I tested, to see that it's possible to get out of problematic situations only using documented means: 1. Put host-0 to maintenance via the engine UI (as above). 2. On host-1, set global maintenance, then shutdown the engine VM, and stopped ha-agent. 3. On host-0, 'hosted-engine --set-maintenance --mode=none'. This emitted an error "Cannot connect to the HA daemon, please check the logs." (because the loop added in [1] runs before the agent listens to commands), but did exit _local_ maintenance (and eventually caused the agent to restart itself). It still didn't clean the _global_ maintenance (as set on the shared storage from host-1 in step 2). This was clearly visible with 'hosted-engine --vm-status'. 4. After a few seconds, after the agent was up, ran again on host-0 'hosted-engine --set-maintenance --mode=none'. This made it exit global maintenance and successfully start the engine VM. In a private discussion with the storage team, they described a more elaborate solution, which would allow keeping the metadata storage connected during local maintenance, so that other hosts can know/update the status, but this would require a lot of work, thus not considered right now. If this is required, please create a new bug. Juan - is this good enough for you? Thanks!
QE: Please see comment 25 for details. Basically the flow is: Put a HA host to (local) maintenance, and make sure you get (a few) notifications only upon moving to/from maintenance, with no notifications during the maintenance window. Please note that the patch deliberately adds a different text in the new loop: "Local maintenance set". This is the one you'll see if on agent start the host is already on local maintenance. The existing message, "Local maintenance detected", which you might have been used to so far, will likely be logged now at most a few times upon entering local maintenance. To get the notifications, you should point HA to a working mail server. The default, during HE deploy, is to send to localhost, so if you keep this, you should configure a local mail server.
Another clarification: If HA managed to update the state on the shared storage prior to vdsm disconnecting it, it might remain in its main loop and keep logging "Local maintenance detected".
I see that no loop occurs anymore and being simply stopped: alma03 ~]# systemctl status ovirt-ha-broker ● ovirt-ha-broker.service - oVirt Hosted Engine High Availability Communications Broker Loaded: loaded (/usr/lib/systemd/system/ovirt-ha-broker.service; enabled; vendor preset: disabled) Active: inactive (dead) since Tue 2022-03-15 13:57:01 IST; 16min ago Process: 819 ExecStart=/usr/libexec/ovirt-hosted-engine-ha/ovirt-ha-broker (code=exited, status=0/SUCCESS) Main PID: 819 (code=exited, status=0/SUCCESS) Mar 15 13:56:41 Broker log reports as its last message on host under local maintenance: StatusStorageThread::ERROR::2022-03-15 13:57:01,593::status_broker::70::ovirt_hosted_engine_ha.broker.status_broker.StatusBroker.Update::(trigger_restart) Trying to restart the broker ovirt-ha-broker service is stopped and the agent is still running: alma03 ~]# systemctl status ovirt-ha-agent ● ovirt-ha-agent.service - oVirt Hosted Engine High Availability Monitoring Agent Loaded: loaded (/usr/lib/systemd/system/ovirt-ha-agent.service; enabled; vendor preset: disabled) Active: active (running) since Tue 2022-03-15 13:56:42 IST; 30min ago Main PID: 40074 (ovirt-ha-agent) Tasks: 1 (limit: 177745) Memory: 21.5M CGroup: /system.slice/ovirt-ha-agent.service └─40074 /usr/libexec/platform-python /usr/libexec/ovirt-hosted-engine-ha/ovirt-ha-agent Mar 15 13:56:42 Moving to verified as the storage restore loop has been eliminated and agent and broker does not cause for the loop anymore. Tested on: ovirt-hosted-engine-setup-2.6.1-1.el8ev.noarch ovirt-hosted-engine-ha-2.5.0-1.el8ev.noarch Linux 4.18.0-372.el8.x86_64 #1 SMP Wed Mar 9 11:41:34 EST 2022 x86_64 x86_64 x86_64 GNU/Linux Red Hat Enterprise Linux release 8.6 Beta (Ootpa)
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Low: RHV RHEL Host (ovirt-host) [ovirt-4.5.0] security update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2022:4764