Created attachment 1632855 [details] engine and vdsm logs Description of problem: Via webadmin/RESTAPI add a new ISCSI storage doamin and see it fail with the following errors: Engine: 2019-11-05 09:22:03,233+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand] (default task-114) [635a0212] START, CreateVGVDSCommand(HostName = host_mixed_2, CreateVGVDSCommandParameters:{hos tId='2cddb970-871b-42d9-bdd2-026621118c48', storageDomainId='5ef4a19a-be98-44d3-b1dc-d929b10f4a8d', deviceList='[360002ac0000000000000001a00021f6b]', force='true'}), log id: 1b4530cd 2019-11-05 09:22:03,274+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand] (default task-114) [635a0212] Failed in 'CreateVGVDS' method 2019-11-05 09:22:03,283+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-114) [635a0212] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_2 command Crea teVGVDS failed: Cannot create Volume Group: "vgname=5ef4a19a-be98-44d3-b1dc-d929b10f4a8d, devname=['360002ac0000000000000001a00021f6b']" 2019-11-05 09:22:03,283+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand] (default task-114) [635a0212] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand' return value 'OneUuidReturn:{status='Status [code=502, message=Cannot create Volume Group: "vgname=5ef4a19a-be98-44d3-b1dc-d929b10f4a8d, devname=['360002ac0000000000000001a00021f6b']"]'}' 2019-11-05 09:22:03,283+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand] (default task-114) [635a0212] HostName = host_mixed_2 2019-11-05 09:22:03,284+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand] (default task-114) [635a0212] Command 'CreateVGVDSCommand(HostName = host_mixed_2, CreateVGVDSCommandParameters:{h ostId='2cddb970-871b-42d9-bdd2-026621118c48', storageDomainId='5ef4a19a-be98-44d3-b1dc-d929b10f4a8d', deviceList='[360002ac0000000000000001a00021f6b]', force='true'})' execution failed: VDSGenericException: VDSErrorException: Failed to CreateVGVDS, error = Cannot create Volume Group: "vgname=5ef4a19a-be98-44d3-b1dc-d929b10f4a8d, devname=['360002ac0000000000000001a00021f6b']", code = 502 2019-11-05 09:22:03,284+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVGVDSCommand] (default task-114) [635a0212] FINISH, CreateVGVDSCommand, return: , log id: 1b4530cd 2019-11-05 09:22:03,284+02 ERROR [org.ovirt.engine.core.bll.storage.domain.AddSANStorageDomainCommand] (default task-114) [635a0212] Command 'org.ovirt.engine.core.bll.storage.domain.AddSANStorageDomainCommand' failed: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to CreateVGVDS, error = Cannot create Volume Group: "vgname=5ef4a19a-be98-44d3-b1dc-d929b10f4a8d, devname=['360002ac0000000000000001a00021f6b']", code = 502 (Failed with error VolumeGroupCreateError and code 502) 2019-11-05 09:22:03,288+02 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default task-114) [635a0212] Command [id=5f47acfb-beec-4f43-a3eb-23612354891d]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.profiles.DiskProfile; snapshot: dfb11d4b-05bb-4324-baf2-325e2da64419. 2019-11-05 09:22:03,294+02 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default task-114) [635a0212] Command [id=5f47acfb-beec-4f43-a3eb-23612354891d]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.StorageDomainDynamic; snapshot: 5ef4a19a-be98-44d3-b1dc-d929b10f4a8d. 2019-11-05 09:22:03,296+02 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default task-114) [635a0212] Command [id=5f47acfb-beec-4f43-a3eb-23612354891d]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.StorageDomainStatic; snapshot: 5ef4a19a-be98-44d3-b1dc-d929b10f4a8d. 2019-11-05 09:22:03,321+02 ERROR [org.ovirt.engine.core.bll.storage.domain.AddSANStorageDomainCommand] (default task-114) [635a0212] Transaction rolled-back for command 'org.ovirt.engine.core.bll.storage.domain.AddSANStorageDomainCommand'. 2019-11-05 09:22:03,331+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-114) [635a0212] EVENT_ID: USER_ADD_STORAGE_DOMAIN_FAILED(957), Failed to add Storage Domain sd_test1. (User: admin@internal-authz) 2019-11-05 09:22:03,338+02 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-114) [] Operation Failed: [Cannot create Volume Group] 2019-11-05 09:22:03,346+02 INFO [org.ovirt.engine.core.bll.aaa.LogoutSessionCommand] (default task-114) [534abd2c] Running command: LogoutSessionCommand internal: false. In VDSM log I see: 2019-11-05 09:22:03,237+0200 INFO (jsonrpc/1) [vdsm.api] START createVG(vgname='5ef4a19a-be98-44d3-b1dc-d929b10f4a8d', devlist=['360002ac0000000000000001a00021f6b'], force=True, options=None) from=::ffff:10.35 .161.118,37586, flow_id=635a0212, task_id=5f40a8ad-200f-4581-9dbc-b203563f9778 (api:48) 2019-11-05 09:22:03,263+0200 INFO (jsonrpc/1) [vdsm.api] FINISH createVG error=devicemapper_removeMapping() missing 1 required positional argument: 'deviceName' from=::ffff:10.35.161.118,37586, flow_id=635a021 2, task_id=5f40a8ad-200f-4581-9dbc-b203563f9778 (api:52) 2019-11-05 09:22:03,265+0200 ERROR (jsonrpc/1) [storage.TaskManager.Task] (Task='5f40a8ad-200f-4581-9dbc-b203563f9778') Unexpected error (task:889) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 896, in _run return fn(*args, **kargs) File "<decorator-gen-95>", line 2, in createVG File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method ret = func(*args, **kwargs) File "/usr/lib/python3.6/site-packages/vdsm/storage/hsm.py", line 2147, in createVG force=force) File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 1143, in createVG _initpvs(pvs, metadataSize, force) File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 881, in _initpvs _initpvs_removeHolders() File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 871, in _initpvs_removeHolders os.path.basename(device)) File "/usr/lib/python3.6/site-packages/vdsm/storage/devicemapper.py", line 163, in removeMappingsHoldingDevice removeMapping(getDevName(holder)) File "/usr/lib/python3.6/site-packages/vdsm/storage/devicemapper.py", line 135, in removeMapping return supervdsm.getProxy().devicemapper_removeMapping() File "/usr/lib/python3.6/site-packages/vdsm/common/supervdsm.py", line 56, in __call__ return callMethod() File "/usr/lib/python3.6/site-packages/vdsm/common/supervdsm.py", line 54, in <lambda> **kwargs) File "<string>", line 2, in devicemapper_removeMapping File "/usr/lib64/python3.6/multiprocessing/managers.py", line 772, in _callmethod raise convert_to_error(kind, result) TypeError: devicemapper_removeMapping() missing 1 required positional argument: 'deviceName' 2019-11-05 09:22:03,265+0200 ERROR (jsonrpc/1) [storage.Dispatcher] FINISH createVG error=devicemapper_removeMapping() missing 1 required positional argument: 'deviceName' (dispatcher:87) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/vdsm/storage/dispatcher.py", line 74, in wrapper result = ctask.prepare(func, *args, **kwargs) File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 110, in wrapper return m(self, *a, **kw) File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 1208, in prepare raise self.error File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 896, in _run return fn(*args, **kargs) File "<decorator-gen-95>", line 2, in createVG File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method ret = func(*args, **kwargs) File "/usr/lib/python3.6/site-packages/vdsm/storage/hsm.py", line 2147, in createVG force=force) File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 1143, in createVG _initpvs(pvs, metadataSize, force) File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 881, in _initpvs _initpvs_removeHolders() File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 871, in _initpvs_removeHolders os.path.basename(device)) File "/usr/lib/python3.6/site-packages/vdsm/storage/devicemapper.py", line 163, in removeMappingsHoldingDevice removeMapping(getDevName(holder)) File "/usr/lib/python3.6/site-packages/vdsm/storage/devicemapper.py", line 135, in removeMapping return supervdsm.getProxy().devicemapper_removeMapping() File "/usr/lib/python3.6/site-packages/vdsm/common/supervdsm.py", line 56, in __call__ return callMethod() File "/usr/lib/python3.6/site-packages/vdsm/common/supervdsm.py", line 54, in <lambda> **kwargs) File "<string>", line 2, in devicemapper_removeMapping File "/usr/lib64/python3.6/multiprocessing/managers.py", line 772, in _callmethod raise convert_to_error(kind, result) TypeError: devicemapper_removeMapping() missing 1 required positional argument: 'deviceName' supervdsm log: MainProcess|jsonrpc/1::ERROR::2019-11-05 09:22:03,262::supervdsm_server::96::SuperVdsm.ServerCallback::(wrapper) Error in devicemapper_removeMapping Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/vdsm/supervdsm_server.py", line 94, in wrapper res = func(*args, **kwargs) TypeError: devicemapper_removeMapping() missing 1 required positional argument: 'deviceName' Version-Release number of selected component (if applicable): rhv-4.4.0-4 (http://bob.eng.lab.tlv.redhat.com/builds/4.4/rhv-4.4.0-4/) ovirt-engine-4.4.0-0.4.master.el7.noarch vdsm-4.40.0-127.gitc628cce.el8ev.x86_64 python3-libvirt-5.0.0-5.module+el8.0.1+3755+6782b0ed.x86_64 qemu-kvm-3.1.0-30.module+el8.0.1+3755+6782b0ed.x86_64 How reproducible: 100% Steps to Reproduce: 1.Create ISCSI storage domain via webadmin Actual results: Adding storage domain fails Expected results: Additional info: REST request: Method: POST URL: https://storage-ge-04.scl.lab.tlv.redhat.com/ovirt-engine/api/storagedomains Headers: Content-Type - application/xml Body: <storage_domain> <name>sd_test1</name> <storage> <logical_units> <logical_unit id="360002ac0000000000000001a00021f6b"> <address>10.35.146.1</address> <port>3260</port> <target>iqn.2000-05.com.3pardata:20210002ac021f6b</target> </logical_unit> </logical_units> <override_luns>true</override_luns> <type>iscsi</type> </storage> <storage_format>v5</storage_format> <type>data</type> <host> <name>host_mixed_1</name> </host> </storage_domain>
requested LUN is in use and DM probably failed to remove mapping to this LUN: 360002ac0000000000000001a00021f6b 253:4 0 50G 0 mpath ├─a52c5f80--536c--4d3f--a581--682038fd80ed-metadata 253:14 0 128M 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-outbox 253:19 0 128M 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-xleases 253:23 0 1G 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-leases 253:27 0 2G 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-ids 253:31 0 128M 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-inbox 253:35 0 128M 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-master 253:39 0 1G 0 lvm ├─a52c5f80--536c--4d3f--a581--682038fd80ed-4dfea443--be0e--4760--8671--d3d27a319a16 253:43 0 128M 0 lvm └─a52c5f80--536c--4d3f--a581--682038fd80ed-a93ae40a--78fe--418f--bab1--601079bf1b5c 253:47 0 128M 0 lvm will need to reproduce it to debug further.
I can confirm it's vdsm bug. After fix seems to be working: curl --insecure --request POST --header "Accept: application/xml" --header "Content-Type: application/xml" --user "***" https://storage-ge-04.scl.lab.tlv.redhat.com/ovirt-engine/api/storagedomains --data '<storage_domain> > <name>sd_test1</name> > <storage> > <logical_units> > <logical_unit id="360002ac0000000000000001a00021f6b"> > <address>10.35.146.1</address> > <port>3260</port> > <target>iqn.2000-05.com.3pardata:20210002ac021f6b</target> > </logical_unit> > </logical_units> > <override_luns>true</override_luns> > <type>iscsi</type> > </storage> > <storage_format>v5</storage_format> > <type>data</type> > <host> > <name>host_mixed_1</name> > </host> > </storage_domain>' <?xml version="1.0" encoding="UTF-8" standalone="yes"?> <storage_domain href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d" id="e9e2fa04-c08f-4cc9-9074-0b52b834554d"> <actions> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/isattached" rel="isattached"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/refreshluns" rel="refreshluns"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/reduceluns" rel="reduceluns"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/updateovfstore" rel="updateovfstore"/> </actions> <name>sd_test1</name> <description></description> <comment></comment> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/diskprofiles" rel="diskprofiles"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/disks" rel="disks"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/templates" rel="templates"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/vms" rel="vms"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/disksnapshots" rel="disksnapshots"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/storageconnections" rel="storageconnections"/> <link href="/ovirt-engine/api/storagedomains/e9e2fa04-c08f-4cc9-9074-0b52b834554d/permissions" rel="permissions"/> <available>48318382080</available> <backup>false</backup> <block_size>512</block_size> <committed>0</committed> <critical_space_action_blocker>5</critical_space_action_blocker> <discard_after_delete>false</discard_after_delete> <external_status>ok</external_status> <master>false</master> <status>unknown</status> <storage> <type>iscsi</type> <volume_group id="XFVexi-8xqt-lWqs-uOn5-ippb-Nmr4-if7uAv"> <logical_units> <logical_unit id="360002ac0000000000000001a00021f6b"> <address>10.35.146.1</address> <discard_max_size>33554432</discard_max_size> <discard_zeroes_data>false</discard_zeroes_data> <lun_mapping>4</lun_mapping> <paths>0</paths> <port>3260</port> <portal>10.35.146.1:3260,21</portal> <product_id>VV</product_id> <serial>S3PARdataVV_CZ3836C3RB</serial> <size>53687091200</size> <storage_domain_id>e9e2fa04-c08f-4cc9-9074-0b52b834554d</storage_domain_id> <target>iqn.2000-05.com.3pardata:20210002ac021f6b</target> <vendor_id>3PARdata</vendor_id> <volume_group_id>XFVexi-8xqt-lWqs-uOn5-ippb-Nmr4-if7uAv</volume_group_id> </logical_unit> </logical_units> </volume_group> </storage> <storage_format>v5</storage_format> <supports_discard>true</supports_discard> <supports_discard_zeroes_data>false</supports_discard_zeroes_data> <type>data</type> <used>4294967296</used> <warning_low_space_indicator>10</warning_low_space_indicator> <wipe_after_delete>false</wipe_after_delete> </storage_domain>
Verified on: 4.4.0-0.13.master.el7
This bugzilla is included in oVirt 4.4.0 release, published on May 20th 2020. Since the problem described in this bug report should be resolved in oVirt 4.4.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.