Description of problem: When engine start the NBD server in vdsm during upload (e.g. restore) or download (e.g. offline backup) it uses the image transfer ticket id as the server id. This id is used to create a socket at /run/vdsm/nbd/{id} and for stopping the server. We have 2 UUIDs for an image tranfer: - The transfer id - used as the engine command id. - The ticket id - used for authenticating the client with imageio server. The ticket id is sensitive information that should not be logged while the transfer is active. The transfer id is public information that may be logged everywhere, and we want all events related to image transfer to have this id. Here are example logs in vdsm that should use the transfer id instead of the ticket id: # grep e285c666-fde0-431b-a993-36315d651e42 /var/log/vdsm/vdsm.log 2022-01-21 00:53:06,843+0200 INFO (jsonrpc/4) [vdsm.api] START start_nbd_server(server_id='e285c666-fde0-431b-a993-36315d651e42', config={'detect_zeroes': True, 'discard': False, 'readonly': True, 'bitmap': None, 'sd_id': 'aecec81f-d464-4a35-9a91-6acf2ca4938c', 'img_id': '69015aa7-b4c5-4bd7-b1d3-c183494975e0', 'vol_id': '37ca5b02-e993-4cfe-b337-1f5f4b70a883', 'backing_chain': True}) from=::ffff:192.168.122.10,58050, flow_id=5b7bb8a1-632f-47a5-a29b-d6966a1943fd, task_id=28c288d3-b4c6-4bcf-ad1a-ecef08aebc4c (api:48) 2022-01-21 00:53:06,856+0200 INFO (jsonrpc/4) [storage.nbd] Starting transient service vdsm-nbd-e285c666-fde0-431b-a993-36315d651e42.service, serving /rhev/data-center/mnt/blockSD/aecec81f-d464-4a35-9a91-6acf2ca4938c/images/69015aa7-b4c5-4bd7-b1d3-c183494975e0/37ca5b02-e993-4cfe-b337-1f5f4b70a883 via unix socket /run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock (nbd:142) 2022-01-21 00:53:06,892+0200 INFO (jsonrpc/4) [vdsm.api] FINISH start_nbd_server return={'result': 'nbd:unix:/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock'} from=::ffff:192.168.122.10,58050, flow_id=5b7bb8a1-632f-47a5-a29b-d6966a1943fd, task_id=28c288d3-b4c6-4bcf-ad1a-ecef08aebc4c (api:54) 2022-01-21 00:53:13,059+0200 INFO (jsonrpc/6) [vdsm.api] START stop_nbd_server(server_id='e285c666-fde0-431b-a993-36315d651e42') from=::ffff:192.168.122.10,58050, flow_id=5b7bb8a1-632f-47a5-a29b-d6966a1943fd, task_id=47a33712-39aa-4015-a604-553d8549db86 (api:48) 2022-01-21 00:53:13,073+0200 INFO (jsonrpc/6) [storage.nbd] Stopping transient service vdsm-nbd-e285c666-fde0-431b-a993-36315d651e42.service (nbd:184) Here are example logs in imageio that should use the transfer id instead of the ticket id: # grep e285c666-fde0-431b-a993-36315d651e42 /var/log/ovirt-imageio/daemon.log 2022-01-21 00:53:07,988 INFO (Thread-11) [images] [::ffff:192.168.122.1] OPTIONS ticket=e285c666-fde0-431b-a993-36315d651e42 2022-01-21 00:53:07,988 INFO (Thread-11) [backends.nbd] Open backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' export_name='' sparse=False max_connections=8 2022-01-21 00:53:07,989 INFO (Thread-11) [extents] [::ffff:192.168.122.1] EXTENTS ticket=e285c666-fde0-431b-a993-36315d651e42 context=zero 2022-01-21 00:53:08,043 INFO (Thread-12) [backends.nbd] Open backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' export_name='' sparse=False max_connections=8 2022-01-21 00:53:08,047 INFO (Thread-13) [backends.nbd] Open backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' export_name='' sparse=False max_connections=8 2022-01-21 00:53:08,050 INFO (Thread-14) [backends.nbd] Open backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' export_name='' sparse=False max_connections=8 2022-01-21 00:53:08,052 INFO (Thread-15) [backends.nbd] Open backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' export_name='' sparse=False max_connections=8 2022-01-21 00:53:10,519 INFO (Thread-13) [backends.nbd] Close backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' 2022-01-21 00:53:10,552 INFO (Thread-15) [backends.nbd] Close backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' 2022-01-21 00:53:10,569 INFO (Thread-12) [backends.nbd] Close backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' 2022-01-21 00:53:10,672 INFO (Thread-14) [backends.nbd] Close backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' 2022-01-21 00:53:10,674 INFO (Thread-11) [backends.nbd] Close backend address='/run/vdsm/nbd/e285c666-fde0-431b-a993-36315d651e42.sock' Fixing all these logs is very easy - when engine starts the nbd server, it should use the transfer id instead of the ticket id. Version-Release number of selected component (if applicable): Any How reproducible: Always Steps to Reproduce: 1. Perform upload or download using the example sdk scripts 2. Grep vdsm and imageio logs with the ticket id Actual results: Ticket id used for nbd server id and socket Expected results: Should use the transfer id This should be trivial change in engine, vdsm and imageio do not need to change.
I forgot to mention that the ticket id is also used as the name of the nbd servive during the transfer: vdsm-nbd-{id}.service This name should use the transfer id as well.
Posted fix to github since gerrit is offline now.
This bugzilla is included in oVirt 4.5.0 release, published on April 20th 2022. Since the problem described in this bug report should be resolved in oVirt 4.5.0 release, it has been closed with a resolution of CURRENT RELEASE. If the solution does not work for you, please open a new bug report.