hey
am facing following problem while creating new storage domain in ovirt.
PFA screenshot and log file details
On 01/25/2014 12:17 PM, aditya mamidwar wrote:
hey
am facing following problem while creating new storage domain in ovirt.
PFA screenshot and log file details
-- -Aditya Mamidwar
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"?
"The connection with details 192.168.0.110:/var/lib/exports/data failed because of error code 477 and error message is: problem while trying to mount target"
the engine.log was :
2014-01-26 17:22:33,038 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ] 2014-01-26 17:22:33,066 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:22:33,069 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5907fb7a 2014-01-26 17:22:33,276 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 5907fb7a 2014-01-26 17:22:33,282 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-2) [6ac5d5df] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 returned by VDSM was: Problem while trying to mount target 2014-01-26 17:22:33,283 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-2) [6ac5d5df] The connection with details localhost.localdomain:/192.168.0.108 failed because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:22:33,285 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:22:33,310 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ] 2014-01-26 17:23:44,807 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ] 2014-01-26 17:23:44,827 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:23:44,831 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 48a8b870 2014-01-26 17:23:44,927 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 48a8b870 2014-01-26 17:23:44,930 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [574043f9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 returned by VDSM was: Problem while trying to mount target 2014-01-26 17:23:44,931 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-3) [574043f9] The connection with details localhost.localdomain:/192.168.0.108 failed because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:23:44,935 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:23:44,949 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ]
the vdsm log was: Thread-17::DEBUG::2014-01-26 17:17:41,579::BindingXMLRPC::974::vds::(wrapper) client [192.168.0.108]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-01-26 17:17:41,614::BindingXMLRPC::981::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'HP Pavilion g4 Notebook PC', 'systemSerialNumber': '5CD2418N50', 'systemFamily': '103C_5335KV G=N L=CON B=HP S=PAV X=Null', 'systemVersion': '0796100000005610000600000', 'systemUUID': '32444335-3134-4E38-3530-843497791B18', 'systemManufacturer': 'Hewlett-Packard'}} Thread-19::DEBUG::2014-01-26 17:18:27,079::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state init -> state preparing Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::1168::TaskManager.Task::(prepare) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::finished: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state preparing -> state finished Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::974::TaskManager.Task::(_decref) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::ref 0 aborting False
On Sun, Jan 26, 2014 at 3:08 PM, Itamar Heim iheim@redhat.com wrote:
On 01/25/2014 12:17 PM, aditya mamidwar wrote:
hey
am facing following problem while creating new storage domain in ovirt.
PFA screenshot and log file details
-- -Aditya Mamidwar
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"?
"The connection with details 192.168.0.110:/var/lib/exports/data failed because of error code 477 and error message is: problem while trying to mount target"
On 01/26/2014 01:57 PM, aditya mamidwar wrote:
the engine.log was :
2014-01-26 17:22:33,038 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ] 2014-01-26 17:22:33,066 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:22:33,069 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5907fb7a 2014-01-26 17:22:33,276 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 5907fb7a 2014-01-26 17:22:33,282 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-2) [6ac5d5df] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by VDSM was: Problem while trying to mount target 2014-01-26 17:22:33,283 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-2) [6ac5d5df] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:22:33,285 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:22:33,310 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ] 2014-01-26 17:23:44,807 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ] 2014-01-26 17:23:44,827 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:23:44,831 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 48a8b870 2014-01-26 17:23:44,927 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 48a8b870 2014-01-26 17:23:44,930 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [574043f9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by VDSM was: Problem while trying to mount target 2014-01-26 17:23:44,931 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-3) [574043f9] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:23:44,935 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:23:44,949 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION , sharedLocks= ]
the vdsm log was: Thread-17::DEBUG::2014-01-26 17:17:41,579::BindingXMLRPC::974::vds::(wrapper) client [192.168.0.108]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-01-26 17:17:41,614::BindingXMLRPC::981::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'HP Pavilion g4 Notebook PC', 'systemSerialNumber': '5CD2418N50', 'systemFamily': '103C_5335KV G=N L=CON B=HP S=PAV X=Null', 'systemVersion': '0796100000005610000600000', 'systemUUID': '32444335-3134-4E38-3530-843497791B18', 'systemManufacturer': 'Hewlett-Packard'}} Thread-19::DEBUG::2014-01-26 17:18:27,079::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state init -> state preparing Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::1168::TaskManager.Task::(prepare) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::finished: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state preparing -> state finished Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::974::TaskManager.Task::(_decref) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::ref 0 aborting False
On Sun, Jan 26, 2014 at 3:08 PM, Itamar Heim <iheim@redhat.com mailto:iheim@redhat.com> wrote:
On 01/25/2014 12:17 PM, aditya mamidwar wrote: hey am facing following problem while creating new storage domain in ovirt. PFA screenshot and log file details -- -Aditya Mamidwar _________________________________________________ vdsm-devel mailing list vdsm-devel@lists.fedorahosted.__org <mailto:vdsm-devel@lists.fedorahosted.org> https://lists.fedorahosted.__org/mailman/listinfo/vdsm-__devel <https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel> please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"? "The connection with details 192.168.0.110:/var/lib/__exports/data failed because of error code 477 and error message is: problem while trying to mount target"-- -Aditya Mamidwar
please try to locate the relevant part in the vdsm log, it isn't the one you attached
I am seeing similar problem with latest vdsm master. I can see that SP.connect command has changed and corresponding engine change is not merged yet http://gerrit.ovirt.org/#/c/22712
The next step fails as well:
2014-01-31 10:29:40,346 INFO [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (http--0.0.0.0-8080-1) Message sent: {"jsonrpc":"2.0","method":"StoragePool.getSpmStatus","params":{"storagepoolID":"00000002-0002-0002-0002-000000000002"},"id":"4f7c8960-8c9c-4129-8ca8-89d601619a0b"} 2014-01-31 10:29:40,357 INFO [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) Message received :{"jsonrpc": "2.0", "id": "4f7c8960-8c9c-4129-8ca8-89d601619a0b", "error": {"message": "", "code": 100}}
Here is what I see in vdsm logs:
JsonRpc (AsyncoreReactor)::DEBUG::2014-01-31 10:31:13,727::asyncoreReactor::130::jsonrpc.AsyncoreClient::(_handleMessage) Queueing incoming message Thread-132::DEBUG::2014-01-31 10:31:13,728::__init__::474::jsonrpc.JsonRpcServer::(_serveRequest) Looking for method 'StoragePool_getSpmStatus' in bridge Thread-132::INFO::2014-01-31 10:31:13,728::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID=u'00000002-0002-0002-0002-000000000002', options=None) Thread-132::ERROR::2014-01-31 10:31:13,729::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1159, in prepare raise self.error InquireNotSupportedError
Piotr
On Sun, Jan 26, 2014 at 1:50 PM, Itamar Heim iheim@redhat.com wrote:
On 01/26/2014 01:57 PM, aditya mamidwar wrote:
the engine.log was :
2014-01-26 17:22:33,038 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:22:33,066 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:22:33,069 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5907fb7a 2014-01-26 17:22:33,276 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 5907fb7a 2014-01-26 17:22:33,282 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-2) [6ac5d5df] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:22:33,283 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-2) [6ac5d5df] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:22:33,285 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:22:33,310 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,807 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,827 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:23:44,831 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 48a8b870 2014-01-26 17:23:44,927 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 48a8b870 2014-01-26 17:23:44,930 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [574043f9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:23:44,931 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-3) [574043f9] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:23:44,935 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:23:44,949 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ]
the vdsm log was: Thread-17::DEBUG::2014-01-26 17:17:41,579::BindingXMLRPC::974::vds::(wrapper) client [192.168.0.108]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-01-26 17:17:41,614::BindingXMLRPC::981::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'HP Pavilion g4 Notebook PC', 'systemSerialNumber': '5CD2418N50', 'systemFamily': '103C_5335KV G=N L=CON B=HP S=PAV X=Null', 'systemVersion': '0796100000005610000600000', 'systemUUID': '32444335-3134-4E38-3530-843497791B18', 'systemManufacturer': 'Hewlett-Packard'}} Thread-19::DEBUG::2014-01-26 17:18:27,079::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state init -> state preparing Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::1168::TaskManager.Task::(prepare) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::finished: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state preparing -> state finished Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::974::TaskManager.Task::(_decref) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::ref 0 aborting False
On Sun, Jan 26, 2014 at 3:08 PM, Itamar Heim <iheim@redhat.com mailto:iheim@redhat.com> wrote:
On 01/25/2014 12:17 PM, aditya mamidwar wrote: hey am facing following problem while creating new storage domain in ovirt. PFA screenshot and log file details -- -Aditya Mamidwar _________________________________________________ vdsm-devel mailing list vdsm-devel@lists.fedorahosted.__org <mailto:vdsm-devel@lists.fedorahosted.org> https://lists.fedorahosted.__org/mailman/listinfo/vdsm-__devel <https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel> please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"? "The connection with details 192.168.0.110:/var/lib/__exports/data failed because of error code 477 and error message is: problem while trying to mount target"-- -Aditya Mamidwar
please try to locate the relevant part in the vdsm log, it isn't the one you attached
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
----- Original Message -----
From: "Piotr Kliczewski" piotr.kliczewski@gmail.com To: "Itamar Heim" iheim@redhat.com Cc: "aditya mamidwar" aditya.mamidwar@gmail.com, vdsm-devel@lists.fedorahosted.org Sent: Friday, January 31, 2014 11:40:22 AM Subject: Re: [vdsm] ovirt storage creation problems
I am seeing similar problem with latest vdsm master. I can see that SP.connect command has changed and corresponding engine change is not merged yet http://gerrit.ovirt.org/#/c/22712
The next step fails as well:
2014-01-31 10:29:40,346 INFO [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (http--0.0.0.0-8080-1) Message sent: {"jsonrpc":"2.0","method":"StoragePool.getSpmStatus","params":{"storagepoolID":"00000002-0002-0002-0002-000000000002"},"id":"4f7c8960-8c9c-4129-8ca8-89d601619a0b"} 2014-01-31 10:29:40,357 INFO [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) Message received :{"jsonrpc": "2.0", "id": "4f7c8960-8c9c-4129-8ca8-89d601619a0b", "error": {"message": "", "code": 100}}
Here is what I see in vdsm logs:
JsonRpc (AsyncoreReactor)::DEBUG::2014-01-31 10:31:13,727::asyncoreReactor::130::jsonrpc.AsyncoreClient::(_handleMessage) Queueing incoming message Thread-132::DEBUG::2014-01-31 10:31:13,728::__init__::474::jsonrpc.JsonRpcServer::(_serveRequest) Looking for method 'StoragePool_getSpmStatus' in bridge Thread-132::INFO::2014-01-31 10:31:13,728::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID=u'00000002-0002-0002-0002-000000000002', options=None) Thread-132::ERROR::2014-01-31 10:31:13,729::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1159, in prepare raise self.error InquireNotSupportedError
This means you are using a cluster lock which does not support the new inquire method. This is internal error that should *not* bubble up to the engine, so we don't need a user visible error message in this case.
Can you describe your setup? which storage do you use?
Piotr
On Sun, Jan 26, 2014 at 1:50 PM, Itamar Heim iheim@redhat.com wrote:
On 01/26/2014 01:57 PM, aditya mamidwar wrote:
the engine.log was :
2014-01-26 17:22:33,038 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:22:33,066 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:22:33,069 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5907fb7a 2014-01-26 17:22:33,276 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 5907fb7a 2014-01-26 17:22:33,282 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-2) [6ac5d5df] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:22:33,283 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-2) [6ac5d5df] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:22:33,285 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:22:33,310 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,807 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,827 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:23:44,831 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 48a8b870 2014-01-26 17:23:44,927 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 48a8b870 2014-01-26 17:23:44,930 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [574043f9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:23:44,931 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-3) [574043f9] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:23:44,935 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:23:44,949 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ]
the vdsm log was: Thread-17::DEBUG::2014-01-26 17:17:41,579::BindingXMLRPC::974::vds::(wrapper) client [192.168.0.108]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-01-26 17:17:41,614::BindingXMLRPC::981::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'HP Pavilion g4 Notebook PC', 'systemSerialNumber': '5CD2418N50', 'systemFamily': '103C_5335KV G=N L=CON B=HP S=PAV X=Null', 'systemVersion': '0796100000005610000600000', 'systemUUID': '32444335-3134-4E38-3530-843497791B18', 'systemManufacturer': 'Hewlett-Packard'}} Thread-19::DEBUG::2014-01-26 17:18:27,079::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state init -> state preparing Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::1168::TaskManager.Task::(prepare) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::finished: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state preparing -> state finished Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::974::TaskManager.Task::(_decref) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::ref 0 aborting False
On Sun, Jan 26, 2014 at 3:08 PM, Itamar Heim <iheim@redhat.com mailto:iheim@redhat.com> wrote:
On 01/25/2014 12:17 PM, aditya mamidwar wrote: hey am facing following problem while creating new storage domain in ovirt. PFA screenshot and log file details -- -Aditya Mamidwar _________________________________________________ vdsm-devel mailing list vdsm-devel@lists.fedorahosted.__org <mailto:vdsm-devel@lists.fedorahosted.org> https://lists.fedorahosted.__org/mailman/listinfo/vdsm-__devel <https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel> please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"? "The connection with details 192.168.0.110:/var/lib/__exports/data failed because of error code 477 and error message is: problem while trying to mount target"-- -Aditya Mamidwar
please try to locate the relevant part in the vdsm log, it isn't the one you attached
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
On Fri, Jan 31, 2014 at 3:37 PM, Nir Soffer nsoffer@redhat.com wrote:
----- Original Message -----
From: "Piotr Kliczewski" piotr.kliczewski@gmail.com To: "Itamar Heim" iheim@redhat.com Cc: "aditya mamidwar" aditya.mamidwar@gmail.com, vdsm-devel@lists.fedorahosted.org Sent: Friday, January 31, 2014 11:40:22 AM Subject: Re: [vdsm] ovirt storage creation problems
I am seeing similar problem with latest vdsm master. I can see that SP.connect command has changed and corresponding engine change is not merged yet http://gerrit.ovirt.org/#/c/22712
The next step fails as well:
2014-01-31 10:29:40,346 INFO [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (http--0.0.0.0-8080-1) Message sent: {"jsonrpc":"2.0","method":"StoragePool.getSpmStatus","params":{"storagepoolID":"00000002-0002-0002-0002-000000000002"},"id":"4f7c8960-8c9c-4129-8ca8-89d601619a0b"} 2014-01-31 10:29:40,357 INFO [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) Message received :{"jsonrpc": "2.0", "id": "4f7c8960-8c9c-4129-8ca8-89d601619a0b", "error": {"message": "", "code": 100}}
Here is what I see in vdsm logs:
JsonRpc (AsyncoreReactor)::DEBUG::2014-01-31 10:31:13,727::asyncoreReactor::130::jsonrpc.AsyncoreClient::(_handleMessage) Queueing incoming message Thread-132::DEBUG::2014-01-31 10:31:13,728::__init__::474::jsonrpc.JsonRpcServer::(_serveRequest) Looking for method 'StoragePool_getSpmStatus' in bridge Thread-132::INFO::2014-01-31 10:31:13,728::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID=u'00000002-0002-0002-0002-000000000002', options=None) Thread-132::ERROR::2014-01-31 10:31:13,729::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1159, in prepare raise self.error InquireNotSupportedError
This means you are using a cluster lock which does not support the new inquire method. This is internal error that should *not* bubble up to the engine, so we don't need a user visible error message in this case.
Can you describe your setup? which storage do you use?
I have freshly compiled engine with clean DB and single instance of vdsm (built from master) using NFS on f20.
I wanted to test vm provisioning so configured everything from scratch.
Piotr
On Sun, Jan 26, 2014 at 1:50 PM, Itamar Heim iheim@redhat.com wrote:
On 01/26/2014 01:57 PM, aditya mamidwar wrote:
the engine.log was :
2014-01-26 17:22:33,038 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:22:33,066 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:22:33,069 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5907fb7a 2014-01-26 17:22:33,276 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 5907fb7a 2014-01-26 17:22:33,282 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-2) [6ac5d5df] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:22:33,283 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-2) [6ac5d5df] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:22:33,285 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:22:33,310 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,807 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,827 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:23:44,831 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 48a8b870 2014-01-26 17:23:44,927 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 48a8b870 2014-01-26 17:23:44,930 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [574043f9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:23:44,931 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-3) [574043f9] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:23:44,935 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:23:44,949 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ]
the vdsm log was: Thread-17::DEBUG::2014-01-26 17:17:41,579::BindingXMLRPC::974::vds::(wrapper) client [192.168.0.108]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-01-26 17:17:41,614::BindingXMLRPC::981::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'HP Pavilion g4 Notebook PC', 'systemSerialNumber': '5CD2418N50', 'systemFamily': '103C_5335KV G=N L=CON B=HP S=PAV X=Null', 'systemVersion': '0796100000005610000600000', 'systemUUID': '32444335-3134-4E38-3530-843497791B18', 'systemManufacturer': 'Hewlett-Packard'}} Thread-19::DEBUG::2014-01-26 17:18:27,079::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state init -> state preparing Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::1168::TaskManager.Task::(prepare) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::finished: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state preparing -> state finished Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::974::TaskManager.Task::(_decref) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::ref 0 aborting False
On Sun, Jan 26, 2014 at 3:08 PM, Itamar Heim <iheim@redhat.com mailto:iheim@redhat.com> wrote:
On 01/25/2014 12:17 PM, aditya mamidwar wrote: hey am facing following problem while creating new storage domain in ovirt. PFA screenshot and log file details -- -Aditya Mamidwar _________________________________________________ vdsm-devel mailing list vdsm-devel@lists.fedorahosted.__org <mailto:vdsm-devel@lists.fedorahosted.org> https://lists.fedorahosted.__org/mailman/listinfo/vdsm-__devel <https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel> please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"? "The connection with details 192.168.0.110:/var/lib/__exports/data failed because of error code 477 and error message is: problem while trying to mount target"-- -Aditya Mamidwar
please try to locate the relevant part in the vdsm log, it isn't the one you attached
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
After the conversation with Nir we agreed that vdsm schema needs to be updated (rename domainsDict to domainsMap and make it optional).
Thanks, Piotr
On Fri, Jan 31, 2014 at 3:58 PM, Piotr Kliczewski piotr.kliczewski@gmail.com wrote:
On Fri, Jan 31, 2014 at 3:37 PM, Nir Soffer nsoffer@redhat.com wrote:
----- Original Message -----
From: "Piotr Kliczewski" piotr.kliczewski@gmail.com To: "Itamar Heim" iheim@redhat.com Cc: "aditya mamidwar" aditya.mamidwar@gmail.com, vdsm-devel@lists.fedorahosted.org Sent: Friday, January 31, 2014 11:40:22 AM Subject: Re: [vdsm] ovirt storage creation problems
I am seeing similar problem with latest vdsm master. I can see that SP.connect command has changed and corresponding engine change is not merged yet http://gerrit.ovirt.org/#/c/22712
The next step fails as well:
2014-01-31 10:29:40,346 INFO [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (http--0.0.0.0-8080-1) Message sent: {"jsonrpc":"2.0","method":"StoragePool.getSpmStatus","params":{"storagepoolID":"00000002-0002-0002-0002-000000000002"},"id":"4f7c8960-8c9c-4129-8ca8-89d601619a0b"} 2014-01-31 10:29:40,357 INFO [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) Message received :{"jsonrpc": "2.0", "id": "4f7c8960-8c9c-4129-8ca8-89d601619a0b", "error": {"message": "", "code": 100}}
Here is what I see in vdsm logs:
JsonRpc (AsyncoreReactor)::DEBUG::2014-01-31 10:31:13,727::asyncoreReactor::130::jsonrpc.AsyncoreClient::(_handleMessage) Queueing incoming message Thread-132::DEBUG::2014-01-31 10:31:13,728::__init__::474::jsonrpc.JsonRpcServer::(_serveRequest) Looking for method 'StoragePool_getSpmStatus' in bridge Thread-132::INFO::2014-01-31 10:31:13,728::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID=u'00000002-0002-0002-0002-000000000002', options=None) Thread-132::ERROR::2014-01-31 10:31:13,729::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1159, in prepare raise self.error InquireNotSupportedError
This means you are using a cluster lock which does not support the new inquire method. This is internal error that should *not* bubble up to the engine, so we don't need a user visible error message in this case.
Can you describe your setup? which storage do you use?
I have freshly compiled engine with clean DB and single instance of vdsm (built from master) using NFS on f20.
I wanted to test vm provisioning so configured everything from scratch.
Piotr
On Sun, Jan 26, 2014 at 1:50 PM, Itamar Heim iheim@redhat.com wrote:
On 01/26/2014 01:57 PM, aditya mamidwar wrote:
the engine.log was :
2014-01-26 17:22:33,038 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:22:33,066 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:22:33,069 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 5907fb7a 2014-01-26 17:22:33,276 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 5907fb7a 2014-01-26 17:22:33,282 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-2) [6ac5d5df] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:22:33,283 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-2) [6ac5d5df] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:22:33,285 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:22:33,310 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-2) [6ac5d5df] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,807 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock Acquired to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ] 2014-01-26 17:23:44,827 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Running command: AddStorageServerConnectionCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System 2014-01-26 17:23:44,831 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] START, ConnectStorageServerVDSCommand(HostName = TL-WR740N, HostId = be488cfd-f00e-4a05-82be-6ec142b6cc20, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: null, connection: localhost.localdomain:/192.168.0.108 http://192.168.0.108, iqn: null, vfsType: null, mountOptions: null,
nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 48a8b870 2014-01-26 17:23:44,927 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (ajp--127.0.0.1-8702-3) [574043f9] FINISH, ConnectStorageServerVDSCommand, return: {00000000-0000-0000-0000-000000000000=477}, log id: 48a8b870 2014-01-26 17:23:44,930 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [574043f9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The error message for connection localhost.localdomain:/192.168.0.108 http://192.168.0.108 returned by
VDSM was: Problem while trying to mount target 2014-01-26 17:23:44,931 ERROR [org.ovirt.engine.core.bll.storage.NFSStorageHelper] (ajp--127.0.0.1-8702-3) [574043f9] The connection with details localhost.localdomain:/192.168.0.108 http://192.168.0.108 failed
because of error code 477 and error message is: problem while trying to mount target 2014-01-26 17:23:44,935 ERROR [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand. 2014-01-26 17:23:44,949 INFO [org.ovirt.engine.core.bll.storage.AddStorageServerConnectionCommand] (ajp--127.0.0.1-8702-3) [574043f9] Lock freed to object EngineLock [exclusiveLocks= key: localhost.localdomain:/192.168.0.108 http://192.168.0.108 value: STORAGE_CONNECTION
, sharedLocks= ]
the vdsm log was: Thread-17::DEBUG::2014-01-26 17:17:41,579::BindingXMLRPC::974::vds::(wrapper) client [192.168.0.108]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-01-26 17:17:41,614::BindingXMLRPC::981::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'HP Pavilion g4 Notebook PC', 'systemSerialNumber': '5CD2418N50', 'systemFamily': '103C_5335KV G=N L=CON B=HP S=PAV X=Null', 'systemVersion': '0796100000005610000600000', 'systemUUID': '32444335-3134-4E38-3530-843497791B18', 'systemManufacturer': 'Hewlett-Packard'}} Thread-19::DEBUG::2014-01-26 17:18:27,079::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state init -> state preparing Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-19::INFO::2014-01-26 17:18:27,079::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::1168::TaskManager.Task::(prepare) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::finished: {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::579::TaskManager.Task::(_updateState) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::moving from state preparing -> state finished Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-19::DEBUG::2014-01-26 17:18:27,080::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-19::DEBUG::2014-01-26 17:18:27,080::task::974::TaskManager.Task::(_decref) Task=`0649dc45-6e00-468c-8a60-94680cabb980`::ref 0 aborting False
On Sun, Jan 26, 2014 at 3:08 PM, Itamar Heim <iheim@redhat.com mailto:iheim@redhat.com> wrote:
On 01/25/2014 12:17 PM, aditya mamidwar wrote: hey am facing following problem while creating new storage domain in ovirt. PFA screenshot and log file details -- -Aditya Mamidwar _________________________________________________ vdsm-devel mailing list vdsm-devel@lists.fedorahosted.__org <mailto:vdsm-devel@lists.fedorahosted.org> https://lists.fedorahosted.__org/mailman/listinfo/vdsm-__devel <https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel> please attach vdsm log. storage folks - can we get something more tangible to show in the ui to user? hopefully based on the engine log has a "477 error"? "The connection with details 192.168.0.110:/var/lib/__exports/data failed because of error code 477 and error message is: problem while trying to mount target"-- -Aditya Mamidwar
please try to locate the relevant part in the vdsm log, it isn't the one you attached
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
vdsm-devel mailing list vdsm-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/vdsm-devel
vdsm-devel@lists.stg.fedorahosted.org
-
aditya mamidwar -
iheim＠redhat.com -
Nir Soffer -
Piotr Kliczewski