Bug 2037057

If there are ongoing tasks on the host then it's ok to block switching it to maintenance
Or do you suspect there are no tasks actually running on that host?

Hello Arik,
There isn't any task and there isn't any vm on the host

Nir, how can we make sure that there is no image transfer task running on that host at this point? can vdsm-client be used for this?

Ah I see that we rely on the database rather than on reports from the hosts in this check but there's nothing much on those disks
Can you please upload a dump of the database so we'll see what went wrong with those transfer tasks?

Database dump was shared privately

Evelina brought to our attention that it sounds like bz 2008898
if "We can see that all the image transfers have phase '7' which is FINALIZING_SUCCESS." also holds in this case, maybe it's related to a stop-backup operation that switched it back?..

(In reply to Arik from comment #6)
> Evelina brought to our attention that it sounds like bz 2008898
> if "We can see that all the image transfers have phase '7' which is
> FINALIZING_SUCCESS." also holds in this case, maybe it's related to a
> stop-backup operation that switched it back?..

That's the "image_transfers" DB table content: a lot of "FINALIZING_SUCCESS" (7), a few "FINISHED_SUCCESS" (9)
56d943c2-2e7b-43ac-ab71-248c173dfff8	1024	7
e201c8c7-0d7d-45d0-a066-e2f42570a5e4	1024	7
3e1a8812-c49e-47eb-ac5a-10feaee90ae0	1024	7
b16a73c2-a380-471a-ab85-daadc8f4fd37	1024	7
b8ebe2a9-9751-4d39-bab8-be1bb0e641c5	1024	7
096d0d44-659e-410e-b5ae-cea407a01e00	1024	7
2cc48963-5258-45f3-ab12-42fe8ac9ec4e	1024	7
7571f69f-d705-4619-a2c9-03eb40c693e3	1024	9
c5b66396-c376-4d53-b4f4-7bdf02c481be	1024	7
f1d08ae1-775f-482d-ab42-08e72493f210	1024	7
66d6e2a8-228a-473e-b2c0-0c566ef2c80a	1024	7
2a2e24c0-ea95-4a5e-b71d-7a4c105620e7	1024	7
13fbc3a6-fe7f-4651-a617-576eec50d02d	1024	7
92b03ca9-4c23-4cc5-92d7-47ce61271f23	1024	9

(In reply to Arik from comment #6)
> also holds in this case, maybe it's related to a
> stop-backup operation that switched it back?..

Talked with Pavel offline - the above seems unrelated because we're talking here about the image transfer tasks and not the backup job

Hi Yuri,
From some investigation I understand the following:
1) The following error that you experienced:
"Cannot switch Host ${host} to Maintenance mode. Image transfer is in progress for the following (${disks_COUNTER}) disks: \n\n ${disks} \n\nPlease wait for the operations to complete and try again."
happens when there are some ongoing image transfers with disks related to the host that is being moved to maintenance.
I imported the DB that you sent and indeed there are 12 image transfers that are stuck in the "FINALIZING_SUCCESS" (7) state. As you can see from the below output ('last_updated' column) these image transfers are stuck for almost 1/2 a year (!!!): Aug 17th - Oct 8th.

pbar@engine2 ~/dev/Bug2037057 $ psql -U engine -d engine -c 'SELECT command_id, phase, disk_id, backup_id, last_updated FROM image_transfers ORDER BY last_updated'
              command_id              | phase |               disk_id                |              backup_id               |        last_updated        
--------------------------------------+-------+--------------------------------------+--------------------------------------+----------------------------
 b8ebe2a9-9751-4d39-bab8-be1bb0e641c5 |     7 | 9081b5ca-c835-457b-b4ef-3bbf9fd36e56 | b19422eb-bb09-4006-a4da-f13a4870a529 | 2021-08-17 20:38:33.985+03
 096d0d44-659e-410e-b5ae-cea407a01e00 |     7 | cd54a61f-ce6a-48ef-a34e-165e8890e382 | b19422eb-bb09-4006-a4da-f13a4870a529 | 2021-08-17 20:40:15.413+03
 2cc48963-5258-45f3-ab12-42fe8ac9ec4e |     7 | 6366d859-467a-450f-81f0-5b9330f5a2b9 | 81c7971f-7e6e-49d9-bd73-0f80faf8ff1e | 2021-08-17 20:41:56.828+03
 e201c8c7-0d7d-45d0-a066-e2f42570a5e4 |     7 | 34c5d5a4-bad7-4e06-b6fe-56963d86d1bc | 44b3f69a-9905-476a-acd1-8a50225f5aa1 | 2021-09-09 13:03:02.158+03
 56d943c2-2e7b-43ac-ab71-248c173dfff8 |     7 | 4c96fcdc-2c68-4e52-b747-6e1e4c958fb7 | 0d76d3f2-312f-4ffd-8d6e-21f73017c775 | 2021-09-20 21:20:40.622+03
 3e1a8812-c49e-47eb-ac5a-10feaee90ae0 |     7 | 16e8e0e8-e388-40f2-9dcc-29b3e9cc4bb8 | 0d76d3f2-312f-4ffd-8d6e-21f73017c775 | 2021-09-20 21:23:41.211+03
 b16a73c2-a380-471a-ab85-daadc8f4fd37 |     7 | fe8e5152-3466-496f-9e7e-00d30053a507 | 0d76d3f2-312f-4ffd-8d6e-21f73017c775 | 2021-09-20 21:26:41.794+03
 c5b66396-c376-4d53-b4f4-7bdf02c481be |     7 | 52edc5e1-0332-4738-b638-080ca928cb5f | d26dc7a5-0ff3-4dfe-9fe5-2ea210fba3db | 2021-10-04 20:37:11.54+03
 f1d08ae1-775f-482d-ab42-08e72493f210 |     7 | 48f218c8-f8d7-4cc7-b189-8bf31707f693 | 0022537c-c262-4f3b-a7f0-816f90aa3be5 | 2021-10-06 01:50:11.267+03
 66d6e2a8-228a-473e-b2c0-0c566ef2c80a |     7 | 2dd3f1a3-654e-41ad-b5e4-87c591b35dc9 | ddfaa089-ed90-4bf1-98e7-bf102a4ee4ba | 2021-10-06 01:50:21.54+03
 13fbc3a6-fe7f-4651-a617-576eec50d02d |     7 | ef3f99a4-40bf-4a6a-8f1a-218fad9660e7 | b9a71702-ac5f-48ac-b330-ab6ee1b614c4 | 2021-10-06 01:50:33.811+03
 2a2e24c0-ea95-4a5e-b71d-7a4c105620e7 |     7 | 33aa4da2-7a68-4022-953e-c4b8411d378a | d19d5aae-b9b3-462f-acfd-b4ab90834f94 | 2021-10-08 16:51:45.584+03
 7571f69f-d705-4619-a2c9-03eb40c693e3 |     9 | 8c8a58c7-4fa7-4320-ba1f-2bd7120ceb29 | 0258cd5b-db65-4780-ae10-efa935d1a78a | 2022-01-06 18:46:27.955+02
 92b03ca9-4c23-4cc5-92d7-47ce61271f23 |     9 | 8c8a58c7-4fa7-4320-ba1f-2bd7120ceb29 | 3a8ad644-31aa-4edb-bbdf-9b808aece6f9 | 2022-01-06 19:01:10.252+02
(14 rows)

I do see that there were newer backups that involved disk with UUID '8c8a58c7-4fa7-4320-ba1f-2bd7120ceb29' that did complete successfully - "FINISHED_SUCCESS" (9) - just lately (Jan 6th).
It's hard to tell what happened, especially that both the backups with that IDs and the disk with the IDs that the error talks about do not exist anymore:

pbar@engine2 ~/dev/Bug2037057 $ psql -U engine -d engine -c 'SELECT * FROM vm_backups'
 backup_id | from_checkpoint_id | to_checkpoint_id | vm_id | phase | _create_date | host_id | description | _update_date | is_live_backup 
-----------+--------------------+------------------+-------+-------+--------------+---------+-------------+--------------+----------------
(0 rows)

pbar@engine2 ~/dev/Bug2037057 $ psql -U engine -d engine -c "SELECT * FROM base_disks WHERE disk_id IN ('c9185fe8-a590-4721-be5d-4ad94bbcad4f', 'e9b437cc-46ef-4f94-9126-b0309c66682a', 'f9490edf-3d85-4eec-a5ea-dae3da909356', 'fe957159-5e0f-45a3-a28c-8fbbc9e1b9ee', '5fe650bb-7259-4e26-9c58-b53547a67020')"
 disk_id | wipe_after_delete | propagate_errors | disk_alias | disk_description | shareable | sgio | disk_storage_type | cinder_volume_type | disk_content_type | backup | backup_mode 
---------+-------------------+------------------+------------+------------------+-----------+------+-------------------+--------------------+-------------------+--------+-------------
(0 rows)

If you want to proceed with the investigation to understand why those image transfers got stuck and didn't finish as they were supposed to, I need older logs (engine log that you sent me is from Dec 19th). Of course better send me both VDSM and engine logs that contain the Aug 17th - Oct 8th 2021 time period. Still it might be not that trivial to investigate a 5 month's old failure.
If you just want to get the system back to normal it might be enough to clean the problematic entries.
Arik, Nir, Benny, what do you think?

Hello Pavel
I think this transfers can be related to some bugs with backup finalization.
So this situation can exist in some customers lab.
Can you create some watchdog to identify orphaned transfers and terminate them after some timeout?

Hi Yury,
Technically it is possible to add a watchdog that will:
1) Run every configurable period of time.
2) Delete all image transfers that are
  a) Running more than X (configurable) minutes
    and/or
  b) All/some disks that participate in the image transfers were already removed.
    and/or
  c) Maybe some other conditions.

To me it looks like something that might actually hide real existing/future bugs, while ideally those situations (with zombie image transfers) shouldn't happen.
We can hear more opinions here (Arik, Benny, Nir) or you might open a new bugzilla request that will be prioritized.

(In reply to Pavel Bar from comment #16)
> To me it looks like something that might actually hide real existing/future
> bugs, while ideally those situations (with zombie image transfers) shouldn't
> happen.

+1
We have a mechanism like this that clears zombie tasks on the engine side so there's some sense in having something similar also for image transfer tasks but it's really more for scenarios in which we can't tell whether the task is running or not. I'd like to know first why the task(s) ended up in this state in order to see if there's an issue we should rather fix than introducing a mechanism that compensates for the issue

We already have mechanism for cleaning up image tranfers, its is called
the TransferDiskImageCommand. This is a task that watches the image
transfer through the various phases, and ensure that the image transfer
is finalized and cleaned up properly.

I think the symptoms reported here are bugs in this mechanism. There
is no point in adding a new mechanism to clean up after the first one.
Who can promise that the next mechanism will not be buggy as the first
one?

The way to fix his is to fix the transfer command bugs so it never
leaves stale image transfers.

Hello there,
> We already have mechanism for cleaning up image tranfers, its is called
> the TransferDiskImageCommand
I don't mind about new one, if you already have solution for the problem.


> I think the symptoms reported here are bugs in this mechanism. There
> is no point in adding a new mechanism to clean up after the first one.
I agree with that, let's fix it.

> I'd like to know first why the task(s) ended up in this state in order to see if there's an issue we should rather fix than introducing a mechanism that compensates for the issue
There was a bug: backup finalization sometimes leave in finalization stage. It was fixed it the same timeframe, so I think it's a source of the problem.

(In reply to Yury.Panchenko from comment #19)
> > I'd like to know first why the task(s) ended up in this state in order to see if there's an issue we should rather fix than introducing a mechanism that compensates for the issue
> There was a bug: backup finalization sometimes leave in finalization stage.
> It was fixed it the same timeframe, so I think it's a source of the problem.

OK, there are few fixes in this area also in 4.4.10 (bz 1985746, bz 1854038)
I'm closing this with reason = insufficient data because without full logs we can't pinpoint the source of why the tasks are stuck but it seems we are all in consensus here about avoiding a new mechanism for zombie image transfer tasks and that there's a good chance the issue is solved in 4.4.10 - I'd suggest trying to reproduce it on 4.4.10 or reopen this bz if this happens again