vdsm
vdsm copied to clipboard
Bogus warnings in deleteImage flow
If a volume was never activated on the SPM, deleting the image log bogus warnings about missing files and directories:
2022-05-18 22:30:04,981+0300 INFO (jsonrpc/1) [vdsm.api] START deleteImage(sdUUID='bafd0f16-9aba-4f9f-ba90-46d3b8a29157', spUUID='fa20ea36-c317-49a6-af6d-afaa5b1561df', imgUUID='e6d71bf6-80cf-407c-b7d0-2083a40e7584', postZero='false', force='false', dis
card=True) from=::ffff:192.168.122.10,53338, flow_id=e1f21682-ae34-4848-940c-bc917543118f, task_id=d3121fae-451a-443e-916d-b3803ce4bba2 (api:48)
2022-05-18 22:30:05,162+0300 INFO (jsonrpc/1) [storage.lvm] Change LVs tags (vg=bafd0f16-9aba-4f9f-ba90-46d3b8a29157, lvs={'e2115e7b-0d88-47df-a8ee-1acb7db6f1d9': ImgsPar(imgs=['e6d71bf6-80cf-407c-b7d0-2083a40e7584'], parent='00000000-0000-0000-0000-000
000000000')}, delTags=('IU_e6d71bf6-80cf-407c-b7d0-2083a40e7584',), addTags=('IU__remove_me_e6d71bf6-80cf-407c-b7d0-2083a40e7584',)) (lvm:1805)
2022-05-18 22:30:05,224+0300 INFO (jsonrpc/1) [IOProcessClient] (Global) Starting client (__init__:340)
2022-05-18 22:30:05,235+0300 INFO (ioprocess/134441) [IOProcess] (Global) Starting ioprocess (__init__:465)
2022-05-18 22:30:05,288+0300 INFO (jsonrpc/1) [vdsm.api] FINISH deleteImage return=None from=::ffff:192.168.122.10,53338, flow_id=e1f21682-ae34-4848-940c-bc917543118f, task_id=d3121fae-451a-443e-916d-b3803ce4bba2 (api:54)
2022-05-18 22:30:05,340+0300 INFO (tasks/6) [storage.threadpool.workerthread] START task d3121fae-451a-443e-916d-b3803ce4bba2 (cmd=<bound method Task.commit of <vdsm.storage.task.Task object at 0x7fd45122f128>>, args=None) (threadPool:146)
2022-05-18 22:30:05,369+0300 INFO (tmap-274/0) [storage.lvm] Activating lvs: vg=bafd0f16-9aba-4f9f-ba90-46d3b8a29157 lvs=['e2115e7b-0d88-47df-a8ee-1acb7db6f1d9'] (lvm:1758)
2022-05-18 22:30:05,456+0300 INFO (tmap-274/0) [storage.blockdev] Discarding device /dev/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/e2115e7b-0d88-47df-a8ee-1acb7db6f1d9 (blockdev:100)
2022-05-18 22:30:05,472+0300 INFO (tmap-274/0) [storage.blockdev] Discarded device /dev/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/e2115e7b-0d88-47df-a8ee-1acb7db6f1d9: 0.02 seconds (utils:390)
2022-05-18 22:30:05,472+0300 INFO (tmap-274/0) [storage.lvm] Deactivating lvs: vg=bafd0f16-9aba-4f9f-ba90-46d3b8a29157 lvs=['e2115e7b-0d88-47df-a8ee-1acb7db6f1d9'] (lvm:1769)
2022-05-18 22:30:05,542+0300 INFO (tmap-274/0) [storage.lvm] Removing LVs (vg=bafd0f16-9aba-4f9f-ba90-46d3b8a29157, lvs=('e2115e7b-0d88-47df-a8ee-1acb7db6f1d9',)) (lvm:1616)
2022-05-18 22:30:05,621+0300 INFO (tasks/6) [storage.storagedomainmanifest] Unlink volume symlink '/rhev/data-center/mnt/blockSD/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/images/e6d71bf6-80cf-407c-b7d0-2083a40e7584/e2115e7b-0d88-47df-a8ee-1acb7db6f1d9' (bloc
kSD:690)
2022-05-18 22:30:05,621+0300 WARN (tasks/6) [storage.storagedomainmanifest] Can't unlink /rhev/data-center/mnt/blockSD/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/images/e6d71bf6-80cf-407c-b7d0-2083a40e7584/e2115e7b-0d88-47df-a8ee-1acb7db6f1d9. [Errno 2] No su
ch file or directory: '/rhev/data-center/mnt/blockSD/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/images/e6d71bf6-80cf-407c-b7d0-2083a40e7584/e2115e7b-0d88-47df-a8ee-1acb7db6f1d9' (blockSD:694)
2022-05-18 22:30:05,621+0300 INFO (tasks/6) [storage.storagedomainmanifest] removed: [] (blockSD:697)
2022-05-18 22:30:05,621+0300 INFO (tasks/6) [storage.storagedomainmanifest] Removing image directory '/rhev/data-center/mnt/blockSD/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/images/e6d71bf6-80cf-407c-b7d0-2083a40e7584' (blockSD:703)
2022-05-18 22:30:05,621+0300 WARN (tasks/6) [storage.storagedomainmanifest] Can't rmdir /rhev/data-center/mnt/blockSD/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/images/e6d71bf6-80cf-407c-b7d0-2083a40e7584 (blockSD:707)
Traceback (most recent call last):
File "/usr/lib/python3.6/site-packages/vdsm/storage/blockSD.py", line 705, in rmDCImgDir
os.rmdir(imgPath)
FileNotFoundError: [Errno 2] No such file or directory: '/rhev/data-center/mnt/blockSD/bafd0f16-9aba-4f9f-ba90-46d3b8a29157/images/e6d71bf6-80cf-407c-b7d0-2083a40e7584'
2022-05-18 22:30:05,663+0300 INFO (tasks/6) [storage.threadpool.workerthread] FINISH task d3121fae-451a-443e-916d-b3803ce4bba2 (threadPool:148)
The issue is likey in the bad infrastructure warning about missing files and directories when removing them.
How to reproduce
- Create disk on block storage
- Delete the disk
- Check vdsm log on the SPM host
Actual results: Bogus warnings
Expected results: No warning about missing links and directories in the flow.
Fix
- Change code to use fixed infrastructure that does not log useless warnings for expected conditions
- Or fix the bad infrastructure to avoid the warnings and tracebacks.