vdsm icon indicating copy to clipboard operation
vdsm copied to clipboard

Bogus warnings in deleteImage flow

Open nirs opened this issue 2 years ago • 0 comments

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

  1. Create disk on block storage
  2. Delete the disk
  3. 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.

nirs avatar May 18 '22 19:05 nirs