Bug 832796 - ConnectStorageServerVDSCommand fails, but engine continues the process (with CreateStorageDomainVDSCommand)
Summary: ConnectStorageServerVDSCommand fails, but engine continues the process (with ...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 3.1.0
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
: 3.1.0
Assignee: Tal Nisan
QA Contact: vvyazmin@redhat.com
URL:
Whiteboard: storage
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-06-17 13:24 UTC by Yaniv Kaul
Modified: 2016-02-10 17:07 UTC (History)
11 users (show)

Fixed In Version: si11
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:
oVirt Team: Storage
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Yaniv Kaul 2012-06-17 13:24:25 UTC
Description of problem:
I've tried to create a local storage domain, which failed due to error 100. This did not seem to be caught well in engine which continued needlessly the process of the creating the storage domain. See log in additional information. Not sure why error code 100 is interpreted as 'general exception', will look into VDSM side to find out (but it's irrelevant right now, I suspect).

It caused the UI to get stuck (https://bugzilla.redhat.com/show_bug.cgi?id=832794) - but I'm not sure it's related, as engine did catch the later exception by VDSM. It's just that it shouldn't have continued the process, AFAIK.

Version-Release number of selected component (if applicable):
rhevm-backend-3.1.0_0001-14.el6ev.noarch

How reproducible:


Steps to Reproduce:
1. Create a local storage domain that fails on error 100 (not sure how that happened - permissions? lack of mount?
2.
3.
  
Actual results:


Expected results:


Additional info:

engine.log:

2012-06-17 16:09:27,934 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (ajp--0.0.0.0-8009-4) [4c00fdbe] START, ValidateStorageServerConnectionVDSCommand(vdsId = 892891e2-b87a-11e1-9ebc-001a4a16976a, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = LOCALFS, connectionList = [{ id: be21f7a6-cc8b-47d4-8295-107e6ed76988, connection: /storage };]), log id: 35cbf519
2012-06-17 16:09:27,951 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (ajp--0.0.0.0-8009-4) [4c00fdbe] FINISH, ValidateStorageServerConnectionVDSCommand, return: {be21f7a6-cc8b-47d4-8295-107e6ed76988=0}, log id: 35cbf519
2012-06-17 16:09:27,974 INFO  [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--0.0.0.0-8009-4) [4c00fdbe] Running command: AddStorageServerConnectionCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-06-17 16:09:27,977 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--0.0.0.0-8009-4) [4c00fdbe] START, ConnectStorageServerVDSCommand(vdsId = 892891e2-b87a-11e1-9ebc-001a4a16976a, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = LOCALFS, connectionList = [{ id: be21f7a6-cc8b-47d4-8295-107e6ed76988, connection: /storage };]), log id: 9976adf
2012-06-17 16:09:28,009 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--0.0.0.0-8009-4) [4c00fdbe] FINISH, ConnectStorageServerVDSCommand, return: {be21f7a6-cc8b-47d4-8295-107e6ed76988=100}, log id: 9976adf
2012-06-17 16:09:28,012 ERROR [org.ovirt.engine.core.bll.storage.LOCALFSStorageHelper] (ajp--0.0.0.0-8009-4) [4c00fdbe] The connection with details /storage failed because of error code 100 and error message is: general exception
2012-06-17 16:09:28,161 INFO  [org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand] (ajp--0.0.0.0-8009-11) [6de45c34] Running command: AddLocalStorageDomainCommand internal: false. Entities affected :  ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-06-17 16:09:28,193 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStorageDomainVDSCommand] (ajp--0.0.0.0-8009-11) [6de45c34] START, CreateStorageDomainVDSCommand(vdsId = 892891e2-b87a-11e1-9ebc-001a4a16976a, storageDomain=org.ovirt.engine.core.common.businessentities.storage_domain_static@c565e91a, args=/storage), log id: 6828efa6
2012-06-17 16:09:28,864 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (ajp--0.0.0.0-8009-11) [6de45c34] Failed in CreateStorageDomainVDS method
2012-06-17 16:09:28,865 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (ajp--0.0.0.0-8009-11) [6de45c34] Error code StorageServerAccessPermissionError and error message VDSGenericException: VDSErrorException: Failed to CreateStorageDomainVDS, error = Permission settings on the specified path do not allow access to the storage. Verify permission settings on the specified storage path.: 'path = /rhev/data-center/mnt/_storage'
2012-06-17 16:09:28,869 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (ajp--0.0.0.0-8009-11) [6de45c34] Command org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStorageDomainVDSCommand return value 
 Class Name: org.ovirt.engine.core.vdsbroker.vdsbroker.StatusOnlyReturnForXmlRpc
mStatus                       Class Name: org.ovirt.engine.core.vdsbroker.vdsbroker.StatusForXmlRpc
mCode                         469
mMessage                      Permission settings on the specified path do not allow access to the storage. Verify permission settings on the specified storage path.: 'path = /rhev/data-center/mnt/_storage'


2012-06-17 16:09:28,871 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (ajp--0.0.0.0-8009-11) [6de45c34] Vds: gold-vdsc
2012-06-17 16:09:28,871 ERROR [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (ajp--0.0.0.0-8009-11) [6de45c34] Command CreateStorageDomainVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to CreateStorageDomainVDS, error = Permission settings on the specified path do not allow access to the storage. Verify permission settings on the specified storage path.: 'path = /rhev/data-center/mnt/_storage'
2012-06-17 16:09:28,873 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateStorageDomainVDSCommand] (ajp--0.0.0.0-8009-11) [6de45c34] FINISH, CreateStorageDomainVDSCommand, log id: 6828efa6
2012-06-17 16:09:28,873 ERROR [org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand] (ajp--0.0.0.0-8009-11) [6de45c34] Command org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to CreateStorageDomainVDS, error = Permission settings on the specified path do not allow access to the storage. Verify permission settings on the specified storage path.: 'path = /rhev/data-center/mnt/_storage'
2012-06-17 16:09:28,900 INFO  [org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand] (ajp--0.0.0.0-8009-11) [6de45c34] Command [id=74521896-af9f-4c42-bfb0-9896ef1ebe71]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage_domain_dynamic; snapshot: 0e1b644f-88b0-4c4f-a323-c580c32cafb0.
2012-06-17 16:09:28,906 INFO  [org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand] (ajp--0.0.0.0-8009-11) [6de45c34] Command [id=74521896-af9f-4c42-bfb0-9896ef1ebe71]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage_domain_static; snapshot: 0e1b644f-88b0-4c4f-a323-c580c32cafb0.
2012-06-17 16:09:28,926 ERROR [org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand] (ajp--0.0.0.0-8009-11) [6de45c34] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddLocalStorageDomainCommand.

vdsm.log:

Thread-529::INFO::2012-06-17 16:07:30,842::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=4, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '/storage', 
'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'be21f7a6-cc8b-47d4-8295-107e6ed76988', 'port': ''}], options=None)
Thread-529::ERROR::2012-06-17 16:07:30,843::hsm::1906::Storage.HSM::(connectStorageServer) Could not connect to storageServer
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/hsm.py", line 1903, in connectStorageServer
    conObj.connect()
  File "/usr/share/vdsm/storage/storageServer.py", line 415, in connect
    raise Exception("Could not like to directory. Path does not exist "
Exception: Could not like to directory. Path does not exist or isn't a directory
Thread-529::DEBUG::2012-06-17 16:07:30,860::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-529::DEBUG::2012-06-17 16:07:30,860::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-529::DEBUG::2012-06-17 16:07:30,860::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-529::DEBUG::2012-06-17 16:07:30,861::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-529::DEBUG::2012-06-17 16:07:30,861::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-529::DEBUG::2012-06-17 16:07:30,862::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-529::INFO::2012-06-17 16:07:30,862::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 100, 'id': 'be21f7a6-cc8b-47d4-8295-107e6ed76988'}]}
Thread-529::DEBUG::2012-06-17 16:07:30,862::task::1172::TaskManager.Task::(prepare) Task=`25f7bade-111e-4aa0-b1b1-fe9a35e3f405`::finished: {'statuslist': [{'status': 100, 'id': 'be21f7a6-cc8b-47d4-8295-107e6ed76988'}]}

Comment 1 Tal Nisan 2012-07-22 09:08:39 UTC
This happens when the given directory does not exist on the target host, does not stuck and gives the message "Error while executing action New Local Storage Domain: Error creating a storage domain"

Comment 2 vvyazmin@redhat.com 2012-07-26 09:04:59 UTC
If you create “New Local Storage Domain”, and give wrong  directory path, you get an error: “Error while executing action New Local Storage Domain: Error creating a storage domain”

If you give right path but with wrong owner permission (not owner is vdsm:kvm (36:36)), you get same error.

Only if you give right path and right owner permission, it works OK.






Verified on RHEVM 3.1 - SI11

RHEVM: rhevm-3.1.0-7.el6ev.noarch.rpm
VDSM: vdsm-4.9.6-23.0.el6.x86_64
LIBVIRT: libvirt-0.9.10-21.el6.x86_64
QEMU & KVM: qemu-kvm-rhev-0.12.1.2-2.295.el6.x86_64
SANLOCK: sanlock-2.3-2.1.el6.x86_64


Note You need to log in before you can comment on or make changes to this bug.