8:07 a.m.
Hi, trying to attach an iso domain to engine master:
2016-03-08 15:04:28,386 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(default task-50) [477da39f] Lock Acquired to object
'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf
6-08c0e96d70dc=<STORAGE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]',
sharedLocks='null'}'
2016-03-08 15:04:28,433 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Running command:
AttachStorageDomainToPoolCommand interna
l: false. Entities affected : ID: bd9860d2-756b-42bd-9cf6-08c0e96d70dc
Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type ADMIN,
ID: 07b2decc-9d40-4df6-bfa1-0da26f95df53 Type: StoragePoolAction
group MANIPULATE_STORAGE_DOMAIN with role type ADMIN
2016-03-08 15:04:28,445 INFO
[org.ovirt.engine.core.bll.storage.connection.ConnectStorageToVdsCommand]
(org.ovirt.thread.pool-10-thread-43) [72ff69e2] Running command:
ConnectStorageToVdsCommand internal: true.
Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type:
SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN
2016-03-08 15:04:28,447 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
(org.ovirt.thread.pool-10-thread-43) [72ff69e2] START,
ConnectStorageServerVDSCommand(HostName = local_hos
t, StorageServerConnectionManagementVDSParameters:{runAsync='true',
hostId='384c1ab4-e03b-46ff-8e32-8a8b3650235b',
storagePoolId='00000000-0000-0000-0000-000000000000', storageType='NFS',
connectionList='[Storag
eServerConnections:{id='51ffb87c-c595-4792-b915-50af506dbf67',
connection='mididell.home:/var/lib/exports/iso-20160308130525',
iqn='null',
vfsType='null', mountOptions='null', nfsVersion='null',
nfsRetrans='null
', nfsTimeo='null', iface='null',
netIfaceName='null'}]'}), log id: 2e547cc1
2016-03-08 15:04:29,454 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
(org.ovirt.thread.pool-10-thread-43) [72ff69e2] FINISH,
ConnectStorageServerVDSCommand, return: {51ffb87c-
c595-4792-b915-50af506dbf67=0}, log id: 2e547cc1
2016-03-08 15:04:29,455 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] START,
AttachStorageDomainVDSCommand( AttachStorageDomainVD
SCommandParameters:{runAsync='true',
storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
ignoreFailoverLimit='false',
storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}), log id: 5bc96473
2016-03-08 15:04:30,549 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Failed in
'AttachStorageDomainVDS' method
2016-03-08 15:04:30,558 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: null, Call
Stack: null, Custom Event ID: -1, M
essage: VDSM command failed: Error in storage domain action:
(u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',)
2016-03-08 15:04:30,558 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Command
'AttachStorageDomainVDSCommand( AttachStorageDomain
VDSCommandParameters:{runAsync='true',
storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
ignoreFailoverLimit='false',
storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'})' execution failed:
IRSGenericExc
eption: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error
in storage domain action: (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350
2016-03-08 15:04:30,558 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] FINISH,
AttachStorageDomainVDSCommand, log id: 5bc96473
2016-03-08 15:04:30,558 ERROR
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Command
'org.ovirt.engine.core.bll.storage.domain.AttachS
torageDomainToPoolCommand' failed: EngineException:
org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS,
erro
r = Error in storage domain action:
(u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350 (Failed with
error StorageDomainActionError and code 350)
2016-03-08 15:04:30,559 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Command
[id=6426d8ba-223f-401d-8fed-c537620bd4c3]: Compensating NEW_ENTITY_ID of
org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot:
StoragePoolIsoMapId:{storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
storageId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}.
2016-03-08 15:04:30,575 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: 477da39f,
Job ID: 13fbe031-0c58-4fff-bc38-324cce2e4c3f, Call Stack: null, Custom
Event ID: -1, Message: Failed to attach Storage Domain ISO_DOMAIN to Data
Center local_datacenter. (User: admin@internal)
2016-03-08 15:04:30,584 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Lock freed to object
'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf6-08c0e96d70dc=<STORAGE,
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
Any hint on what can be the reason?
# rpm -qv ovirt-engine
ovirt-engine-4.0.0-0.0.master.20160307171512.git398703d.el7.centos.noarch
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
8:12 a.m.
Please attach vdsm logs showing this flow.
On Tue, Mar 8, 2016 at 4:07 PM, Sandro Bonazzola <sbonazzo(a)redhat.com> wrote:
Hi, trying to attach an iso domain to engine master:
2016-03-08 15:04:28,386 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(default task-50) [477da39f] Lock Acquired to object
'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf
6-08c0e96d70dc=<STORAGE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]',
sharedLocks='null'}'
2016-03-08 15:04:28,433 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Running command:
AttachStorageDomainToPoolCommand interna
l: false. Entities affected : ID: bd9860d2-756b-42bd-9cf6-08c0e96d70dc
Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type ADMIN,
ID: 07b2decc-9d40-4df6-bfa1-0da26f95df53 Type: StoragePoolAction
group MANIPULATE_STORAGE_DOMAIN with role type ADMIN
2016-03-08 15:04:28,445 INFO
[org.ovirt.engine.core.bll.storage.connection.ConnectStorageToVdsCommand]
(org.ovirt.thread.pool-10-thread-43) [72ff69e2] Running command:
ConnectStorageToVdsCommand internal: true.
Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type:
SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN
2016-03-08 15:04:28,447 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
(org.ovirt.thread.pool-10-thread-43) [72ff69e2] START,
ConnectStorageServerVDSCommand(HostName = local_hos
t, StorageServerConnectionManagementVDSParameters:{runAsync='true',
hostId='384c1ab4-e03b-46ff-8e32-8a8b3650235b',
storagePoolId='00000000-0000-0000-0000-000000000000', storageType='NFS',
connectionList='[Storag
eServerConnections:{id='51ffb87c-c595-4792-b915-50af506dbf67',
connection='mididell.home:/var/lib/exports/iso-20160308130525',
iqn='null',
vfsType='null', mountOptions='null', nfsVersion='null',
nfsRetrans='null
', nfsTimeo='null', iface='null',
netIfaceName='null'}]'}), log id: 2e547cc1
2016-03-08 15:04:29,454 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
(org.ovirt.thread.pool-10-thread-43) [72ff69e2] FINISH,
ConnectStorageServerVDSCommand, return: {51ffb87c-
c595-4792-b915-50af506dbf67=0}, log id: 2e547cc1
2016-03-08 15:04:29,455 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] START,
AttachStorageDomainVDSCommand( AttachStorageDomainVD
SCommandParameters:{runAsync='true',
storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
ignoreFailoverLimit='false',
storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}), log id: 5bc96473
2016-03-08 15:04:30,549 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Failed in
'AttachStorageDomainVDS' method
2016-03-08 15:04:30,558 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: null, Call
Stack: null, Custom Event ID: -1, M
essage: VDSM command failed: Error in storage domain action:
(u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',)
2016-03-08 15:04:30,558 ERROR
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Command
'AttachStorageDomainVDSCommand( AttachStorageDomain
VDSCommandParameters:{runAsync='true',
storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
ignoreFailoverLimit='false',
storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'})' execution failed:
IRSGenericExc
eption: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error
in storage domain action: (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350
2016-03-08 15:04:30,558 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] FINISH,
AttachStorageDomainVDSCommand, log id: 5bc96473
2016-03-08 15:04:30,558 ERROR
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Command
'org.ovirt.engine.core.bll.storage.domain.AttachS
torageDomainToPoolCommand' failed: EngineException:
org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS,
erro
r = Error in storage domain action:
(u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350 (Failed with
error StorageDomainActionError and code 350)
2016-03-08 15:04:30,559 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Command
[id=6426d8ba-223f-401d-8fed-c537620bd4c3]: Compensating NEW_ENTITY_ID of
org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot:
StoragePoolIsoMapId:{storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
storageId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}.
2016-03-08 15:04:30,575 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: 477da39f,
Job ID: 13fbe031-0c58-4fff-bc38-324cce2e4c3f, Call Stack: null, Custom Event
ID: -1, Message: Failed to attach Storage Domain ISO_DOMAIN to Data Center
local_datacenter. (User: admin@internal)
2016-03-08 15:04:30,584 INFO
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
(org.ovirt.thread.pool-10-thread-42) [477da39f] Lock freed to object
'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf6-08c0e96d70dc=<STORAGE,
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
Any hint on what can be the reason?
# rpm -qv ovirt-engine
ovirt-engine-4.0.0-0.0.master.20160307171512.git398703d.el7.centos.noarch
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
_______________________________________________
Devel mailing list
Devel(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/devel
8:18 a.m.
On Tue, Mar 8, 2016 at 3:12 PM, Nir Soffer <nsoffer(a)redhat.com> wrote:
Please attach vdsm logs showing this flow.
corresponding vdsm log:
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,449::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'StoragePool.connectStorageServer' in bridge with {u'connectionParams':
[{u'id': u'51ffb87c-c595-4792-b915-50af506dbf67', u'connection':
u'mididell.home:/var/lib/exports/iso-20160308130525', u'iqn': u'',
u'user':
u'', u'password': '********', u'port': u''}],
u'storagepoolID':
u'00000000-0000-0000-0000-000000000000', u'domainType': 1}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,449::task::596::Storage.TaskManager.Task::(_updateState)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::moving from state init ->
state preparing
jsonrpc.Executor/3::INFO::2016-03-08
15:04:28,449::logUtils::49::dispatcher::(wrapper) Run and protect:
connectStorageServer(domType=1,
spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id':
u'51ffb87c-c595-4792-b915-50af506dbf67', u'connection':
u'mididell.home:/var/lib/exports/iso-20160308130525', u'iqn': u'',
u'user':
u'', u'password': '********', u'port': u''}],
options=None)
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,451::hsm::2412::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/mididell.home:_var_lib_exports_iso-20160308130525
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,451::hsm::2436::Storage.HSM::(__prefetchDomains) Found SD uuids:
(u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',)
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,451::hsm::2496::Storage.HSM::(connectStorageServer) knownSDs:
{bd9860d2-756b-42bd-9cf6-08c0e96d70dc: storage.nfsSD.findDomain,
8dc79844-210c-4bb1-acae-3c3e55d4fa3c: storage.localFsSD.findDomain}
jsonrpc.Executor/3::INFO::2016-03-08
15:04:28,451::logUtils::52::dispatcher::(wrapper) Run and protect:
connectStorageServer, Return response: {'statuslist': [{'status': 0,
'id':
u'51ffb87c-c595-4792-b915-50af506dbf67'}]}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::task::1192::Storage.TaskManager.Task::(prepare)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::finished: {'statuslist':
[{'status': 0, 'id': u'51ffb87c-c595-4792-b915-50af506dbf67'}]}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::task::596::Storage.TaskManager.Task::(_updateState)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::moving from state preparing ->
state finished
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::resourceManager::951::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::task::994::Storage.TaskManager.Task::(_decref)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::ref 0 aborting False
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::__init__::539::jsonrpc.JsonRpcServer::(_serveRequest) Return
'StoragePool.connectStorageServer' in bridge with [{'status': 0,
'id':
u'51ffb87c-c595-4792-b915-50af506dbf67'}]
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,456::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'StorageDomain.attach' in bridge with {u'storagepoolID':
u'07b2decc-9d40-4df6-bfa1-0da26f95df53', u'storagedomainID':
u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,456::task::596::Storage.TaskManager.Task::(_updateState)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state init ->
state preparing
jsonrpc.Executor/4::INFO::2016-03-08
15:04:29,456::logUtils::49::dispatcher::(wrapper) Run and protect:
attachStorageDomain(sdUUID=u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',
spUUID=u'07b2decc-9d40-4df6-bfa1-0da26f95df53', options=None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::200::Storage.ResourceManager.Request::(__init__)
ResName=`Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53`ReqID=`0c01819d-8d3f-400b-a798-660babb497df`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1208' at
'attachStorageDomain'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::553::Storage.ResourceManager::(registerResource)
Trying to register resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53'
for lock type 'exclusive'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::612::Storage.ResourceManager::(registerResource)
Resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' is free. Now
locking as 'exclusive' (1 active user)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::240::Storage.ResourceManager.Request::(grant)
ResName=`Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53`ReqID=`0c01819d-8d3f-400b-a798-660babb497df`::Granted
request
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::task::828::Storage.TaskManager.Task::(resourceAcquired)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_resourcesAcquired:
Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53 (exclusive)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting False
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::200::Storage.ResourceManager.Request::(__init__)
ResName=`Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc`ReqID=`46ee6ea9-6dd4-4823-b894-dfd971c748ce`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1209' at
'attachStorageDomain'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::553::Storage.ResourceManager::(registerResource)
Trying to register resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc'
for lock type 'exclusive'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::612::Storage.ResourceManager::(registerResource)
Resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' is free. Now
locking as 'exclusive' (1 active user)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::240::Storage.ResourceManager.Request::(grant)
ResName=`Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc`ReqID=`46ee6ea9-6dd4-4823-b894-dfd971c748ce`::Granted
request
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::task::828::Storage.TaskManager.Task::(resourceAcquired)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_resourcesAcquired:
Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc (exclusive)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting False
jsonrpc.Executor/4::INFO::2016-03-08
15:04:29,458::sp::921::Storage.StoragePool::(attachSD)
sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::700::Storage.SamplingMethod::(__call__) Trying to enter
sampling method (storage.sdc.refreshStorage)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::703::Storage.SamplingMethod::(__call__) Got in to
sampling method
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::700::Storage.SamplingMethod::(__call__) Trying to enter
sampling method (storage.iscsi.rescan)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::703::Storage.SamplingMethod::(__call__) Got in to
sampling method
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::iscsi::434::Storage.ISCSI::(rescan) Performing SCSI scan,
this will take up to 30 seconds
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::iscsiadm::97::Storage.Misc.excCmd::(_runCmd) /usr/bin/taskset
--cpu-list 0-7 /usr/bin/sudo -n /usr/sbin/iscsiadm -m session -R (cwd None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::misc::710::Storage.SamplingMethod::(__call__) Returning last
result
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::misc::700::Storage.SamplingMethod::(__call__) Trying to enter
sampling method (storage.hba.rescan)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::misc::703::Storage.SamplingMethod::(__call__) Got in to
sampling method
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::hba::56::Storage.HBA::(rescan) Starting scan
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,493::hba::62::Storage.HBA::(rescan) Scan finished
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,493::misc::710::Storage.SamplingMethod::(__call__) Returning last
result
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,493::multipath::78::Storage.Misc.excCmd::(rescan) /usr/bin/taskset
--cpu-list 0-7 /usr/bin/sudo -n /usr/sbin/multipath (cwd None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,532::multipath::78::Storage.Misc.excCmd::(rescan) SUCCESS: <err> =
''; <rc> = 0
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,532::commands::70::root::(execCmd) /usr/bin/taskset --cpu-list 0-7
/sbin/udevadm settle --timeout=5 (cwd None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,540::commands::88::root::(execCmd) SUCCESS: <err> = ''; <rc>
= 0
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::497::Storage.OperationMutex::(_invalidateAllPvs)
Operation 'lvm invalidate operation' got the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::499::Storage.OperationMutex::(_invalidateAllPvs)
Operation 'lvm invalidate operation' released the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::508::Storage.OperationMutex::(_invalidateAllVgs)
Operation 'lvm invalidate operation' got the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::510::Storage.OperationMutex::(_invalidateAllVgs)
Operation 'lvm invalidate operation' released the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::528::Storage.OperationMutex::(_invalidateAllLvs)
Operation 'lvm invalidate operation' got the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::530::Storage.OperationMutex::(_invalidateAllLvs)
Operation 'lvm invalidate operation' released the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::misc::710::Storage.SamplingMethod::(__call__) Returning last
result
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,544::fileSD::159::Storage.StorageDomainManifest::(__init__)
Reading domain in path
/rhev/data-center/mnt/mididell.home:_var_lib_exports_iso-20160308130525/bd9860d2-756b-42bd-9cf6-08c0e96d70dc
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,544::persistentDict::192::Storage.PersistentDict::(__init__)
Created a persistent dict with FileMetadataRW backend
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::persistentDict::234::Storage.PersistentDict::(refresh) read
lines (FileMetadataRW)=[]
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::persistentDict::252::Storage.PersistentDict::(refresh) Empty
metadata
jsonrpc.Executor/4::ERROR::2016-03-08
15:04:29,545::task::867::Storage.TaskManager.Task::(_setError)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 874, in _run
return fn(*args, **kargs)
File "/usr/lib/python2.7/site-packages/vdsm/logUtils.py", line 50, in
wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 1211, in attachStorageDomain
pool.attachSD(sdUUID)
File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper
return method(self, *args, **kwargs)
File "/usr/share/vdsm/storage/sp.py", line 928, in attachSD
dom = sdCache.produce(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 100, in produce
domain.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 124, in _realProduce
domain = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 143, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/nfsSD.py", line 122, in findDomain
return NfsStorageDomain(NfsStorageDomain.findDomainPath(sdUUID))
File "/usr/share/vdsm/storage/fileSD.py", line 330, in __init__
manifest = self.manifestClass(domainPath)
File "/usr/share/vdsm/storage/fileSD.py", line 168, in __init__
sd.StorageDomainManifest.__init__(self, sdUUID, domaindir, metadata)
File "/usr/share/vdsm/storage/sd.py", line 310, in __init__
self._domainLock = self._makeDomainLock()
File "/usr/share/vdsm/storage/sd.py", line 439, in _makeDomainLock
domVersion = self.getVersion()
File "/usr/share/vdsm/storage/sd.py", line 359, in getVersion
return self.getMetaParam(DMDK_VERSION)
File "/usr/share/vdsm/storage/sd.py", line 356, in getMetaParam
return self._metadata[key]
File "/usr/share/vdsm/storage/persistentDict.py", line 89, in __getitem__
return dec(self._dict[key])
File "/usr/share/vdsm/storage/persistentDict.py", line 201, in __getitem__
raise KeyError(key)
KeyError: 'VERSION'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::886::Storage.TaskManager.Task::(_run)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Task._run:
c24beaf3-733e-45b2-9c0b-31dce0e7d4a8
(u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',
u'07b2decc-9d40-4df6-bfa1-0da26f95df53') {} failed - stopping task
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::1247::Storage.TaskManager.Task::(stop)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::stopping in state preparing
(force False)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting True
jsonrpc.Executor/4::INFO::2016-03-08
15:04:29,545::task::1172::Storage.TaskManager.Task::(prepare)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::aborting: Task is aborted:
u"'VERSION'" - code 100
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::1177::Storage.TaskManager.Task::(prepare)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Prepare: aborted: 'VERSION'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 0 aborting True
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::929::Storage.TaskManager.Task::(_doAbort)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Task._doAbort: force False
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::596::Storage.TaskManager.Task::(_updateState)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state preparing ->
state aborting
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::551::Storage.TaskManager.Task::(__state_aborting)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_aborting: recover policy none
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::596::Storage.TaskManager.Task::(_updateState)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state aborting ->
state failed
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::951::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources
{u'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53': < ResourceRef
'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53', isValid: 'True' obj:
'None'>, u'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc': <
ResourceRef
'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc', isValid: 'True' obj:
'None'>}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::627::Storage.ResourceManager::(releaseResource)
Trying to release resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::646::Storage.ResourceManager::(releaseResource)
Released resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' (0 active
users)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::652::Storage.ResourceManager::(releaseResource)
Resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' is free, finding
out if anyone is waiting for it.
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::660::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53', Clearing records.
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::627::Storage.ResourceManager::(releaseResource)
Trying to release resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::646::Storage.ResourceManager::(releaseResource)
Released resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' (0 active
users)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::652::Storage.ResourceManager::(releaseResource)
Resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' is free, finding
out if anyone is waiting for it.
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::660::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc', Clearing records.
jsonrpc.Executor/4::ERROR::2016-03-08
15:04:29,547::dispatcher::79::Storage.Dispatcher::(wrapper) 'VERSION'
Traceback (most recent call last):
File "/usr/share/vdsm/storage/dispatcher.py", line 71, in wrapper
result = ctask.prepare(func, *args, **kwargs)
File "/usr/share/vdsm/storage/task.py", line 105, in wrapper
return m(self, *a, **kw)
File "/usr/share/vdsm/storage/task.py", line 1180, in prepare
raise self.error
KeyError: 'VERSION'
Thread-41::DEBUG::2016-03-08
15:04:30,110::fileSD::174::Storage.Misc.excCmd::(getReadDelay)
/usr/bin/taskset --cpu-list 0-7 /usr/bin/dd
if=/rhev/data-center/mnt/_var_lib_images-20160308135819/8dc79844-210c-4bb1-acae-3c3e55d4fa3c/dom_md/metadata
iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-41::DEBUG::2016-03-08
15:04:30,114::fileSD::174::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n484 bytes (484 B) copied,
0.000216157 s, 2.2 MB/s\n'; <rc> = 0
jsonrpc.Executor/6::DEBUG::2016-03-08
15:04:37,311::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'StoragePool.getSpmStatus' in bridge with {u'storagepoolID':
u'07b2decc-9d40-4df6-bfa1-0da26f95df53'}
On Tue, Mar 8, 2016 at 4:07 PM, Sandro Bonazzola
<sbonazzo(a)redhat.com>
wrote:
> Hi, trying to attach an iso domain to engine master:
>
> 2016-03-08 15:04:28,386 INFO
>
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> (default task-50) [477da39f] Lock Acquired to object
> 'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf
> 6-08c0e96d70dc=<STORAGE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]',
> sharedLocks='null'}'
> 2016-03-08 15:04:28,433 INFO
>
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Running command:
> AttachStorageDomainToPoolCommand interna
> l: false. Entities affected : ID: bd9860d2-756b-42bd-9cf6-08c0e96d70dc
> Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type ADMIN,
> ID: 07b2decc-9d40-4df6-bfa1-0da26f95df53 Type: StoragePoolAction
> group MANIPULATE_STORAGE_DOMAIN with role type ADMIN
> 2016-03-08 15:04:28,445 INFO
> [org.ovirt.engine.core.bll.storage.connection.ConnectStorageToVdsCommand]
> (org.ovirt.thread.pool-10-thread-43) [72ff69e2] Running command:
> ConnectStorageToVdsCommand internal: true.
> Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type:
> SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN
> 2016-03-08 15:04:28,447 INFO
>
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
> (org.ovirt.thread.pool-10-thread-43) [72ff69e2] START,
> ConnectStorageServerVDSCommand(HostName = local_hos
> t, StorageServerConnectionManagementVDSParameters:{runAsync='true',
> hostId='384c1ab4-e03b-46ff-8e32-8a8b3650235b',
> storagePoolId='00000000-0000-0000-0000-000000000000',
storageType='NFS',
> connectionList='[Storag
> eServerConnections:{id='51ffb87c-c595-4792-b915-50af506dbf67',
> connection='mididell.home:/var/lib/exports/iso-20160308130525',
iqn='null',
> vfsType='null', mountOptions='null', nfsVersion='null',
nfsRetrans='null
> ', nfsTimeo='null', iface='null',
netIfaceName='null'}]'}), log id:
2e547cc1
> 2016-03-08 15:04:29,454 INFO
>
[org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
> (org.ovirt.thread.pool-10-thread-43) [72ff69e2] FINISH,
> ConnectStorageServerVDSCommand, return: {51ffb87c-
> c595-4792-b915-50af506dbf67=0}, log id: 2e547cc1
> 2016-03-08 15:04:29,455 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] START,
> AttachStorageDomainVDSCommand( AttachStorageDomainVD
> SCommandParameters:{runAsync='true',
> storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
> ignoreFailoverLimit='false',
> storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}), log id:
5bc96473
> 2016-03-08 15:04:30,549 ERROR
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Failed in
> 'AttachStorageDomainVDS' method
> 2016-03-08 15:04:30,558 ERROR
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: null,
Call
> Stack: null, Custom Event ID: -1, M
> essage: VDSM command failed: Error in storage domain action:
> (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
> spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',)
> 2016-03-08 15:04:30,558 ERROR
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Command
> 'AttachStorageDomainVDSCommand( AttachStorageDomain
> VDSCommandParameters:{runAsync='true',
> storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
> ignoreFailoverLimit='false',
> storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'})' execution
failed:
> IRSGenericExc
> eption: IRSErrorException: Failed to AttachStorageDomainVDS, error =
Error
> in storage domain action: (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
> spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350
> 2016-03-08 15:04:30,558 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] FINISH,
> AttachStorageDomainVDSCommand, log id: 5bc96473
> 2016-03-08 15:04:30,558 ERROR
>
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Command
> 'org.ovirt.engine.core.bll.storage.domain.AttachS
> torageDomainToPoolCommand' failed: EngineException:
>
org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
> IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS,
> erro
> r = Error in storage domain action:
> (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
> spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350 (Failed with
> error StorageDomainActionError and code 350)
> 2016-03-08 15:04:30,559 INFO
>
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Command
> [id=6426d8ba-223f-401d-8fed-c537620bd4c3]: Compensating NEW_ENTITY_ID of
> org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap;
snapshot:
>
StoragePoolIsoMapId:{storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
> storageId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}.
> 2016-03-08 15:04:30,575 ERROR
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: 477da39f,
> Job ID: 13fbe031-0c58-4fff-bc38-324cce2e4c3f, Call Stack: null, Custom
Event
> ID: -1, Message: Failed to attach Storage Domain ISO_DOMAIN to Data
Center
> local_datacenter. (User: admin@internal)
> 2016-03-08 15:04:30,584 INFO
>
[org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Lock freed to object
>
'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf6-08c0e96d70dc=<STORAGE,
> ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
>
> Any hint on what can be the reason?
>
> # rpm -qv ovirt-engine
> ovirt-engine-4.0.0-0.0.master.20160307171512.git398703d.el7.centos.noarch
>
> --
> Sandro Bonazzola
> Better technology. Faster innovation. Powered by community collaboration.
> See how it works at redhat.com
>
> _______________________________________________
> Devel mailing list
> Devel(a)ovirt.org
> http://lists.ovirt.org/mailman/listinfo/devel
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
7:38 a.m.
Whatever it was, today it's working with ovirt-engine and vdsm from master.
On Tue, Mar 8, 2016 at 3:18 PM, Sandro Bonazzola <sbonazzo(a)redhat.com>
wrote:
On Tue, Mar 8, 2016 at 3:12 PM, Nir Soffer <nsoffer(a)redhat.com> wrote:
> Please attach vdsm logs showing this flow.
>
>
corresponding vdsm log:
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,449::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'StoragePool.connectStorageServer' in bridge with {u'connectionParams':
[{u'id': u'51ffb87c-c595-4792-b915-50af506dbf67', u'connection':
u'mididell.home:/var/lib/exports/iso-20160308130525', u'iqn':
u'', u'user':
u'', u'password': '********', u'port': u''}],
u'storagepoolID':
u'00000000-0000-0000-0000-000000000000', u'domainType': 1}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,449::task::596::Storage.TaskManager.Task::(_updateState)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::moving from state init ->
state preparing
jsonrpc.Executor/3::INFO::2016-03-08
15:04:28,449::logUtils::49::dispatcher::(wrapper) Run and protect:
connectStorageServer(domType=1,
spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id':
u'51ffb87c-c595-4792-b915-50af506dbf67', u'connection':
u'mididell.home:/var/lib/exports/iso-20160308130525', u'iqn':
u'', u'user':
u'', u'password': '********', u'port': u''}],
options=None)
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,451::hsm::2412::Storage.HSM::(__prefetchDomains) nfs local path:
/rhev/data-center/mnt/mididell.home:_var_lib_exports_iso-20160308130525
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,451::hsm::2436::Storage.HSM::(__prefetchDomains) Found SD uuids:
(u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',)
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,451::hsm::2496::Storage.HSM::(connectStorageServer) knownSDs:
{bd9860d2-756b-42bd-9cf6-08c0e96d70dc: storage.nfsSD.findDomain,
8dc79844-210c-4bb1-acae-3c3e55d4fa3c: storage.localFsSD.findDomain}
jsonrpc.Executor/3::INFO::2016-03-08
15:04:28,451::logUtils::52::dispatcher::(wrapper) Run and protect:
connectStorageServer, Return response: {'statuslist': [{'status': 0,
'id':
u'51ffb87c-c595-4792-b915-50af506dbf67'}]}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::task::1192::Storage.TaskManager.Task::(prepare)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::finished: {'statuslist':
[{'status': 0, 'id': u'51ffb87c-c595-4792-b915-50af506dbf67'}]}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::task::596::Storage.TaskManager.Task::(_updateState)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::moving from state preparing ->
state finished
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::resourceManager::951::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::task::994::Storage.TaskManager.Task::(_decref)
Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::ref 0 aborting False
jsonrpc.Executor/3::DEBUG::2016-03-08
15:04:28,452::__init__::539::jsonrpc.JsonRpcServer::(_serveRequest) Return
'StoragePool.connectStorageServer' in bridge with [{'status': 0,
'id':
u'51ffb87c-c595-4792-b915-50af506dbf67'}]
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,456::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'StorageDomain.attach' in bridge with {u'storagepoolID':
u'07b2decc-9d40-4df6-bfa1-0da26f95df53', u'storagedomainID':
u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,456::task::596::Storage.TaskManager.Task::(_updateState)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state init ->
state preparing
jsonrpc.Executor/4::INFO::2016-03-08
15:04:29,456::logUtils::49::dispatcher::(wrapper) Run and protect:
attachStorageDomain(sdUUID=u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',
spUUID=u'07b2decc-9d40-4df6-bfa1-0da26f95df53', options=None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::200::Storage.ResourceManager.Request::(__init__)
ResName=`Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53`ReqID=`0c01819d-8d3f-400b-a798-660babb497df`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1208' at
'attachStorageDomain'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::553::Storage.ResourceManager::(registerResource)
Trying to register resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53'
for lock type 'exclusive'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::612::Storage.ResourceManager::(registerResource)
Resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' is free. Now
locking as 'exclusive' (1 active user)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::240::Storage.ResourceManager.Request::(grant)
ResName=`Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53`ReqID=`0c01819d-8d3f-400b-a798-660babb497df`::Granted
request
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::task::828::Storage.TaskManager.Task::(resourceAcquired)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_resourcesAcquired:
Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53 (exclusive)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting False
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::200::Storage.ResourceManager.Request::(__init__)
ResName=`Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc`ReqID=`46ee6ea9-6dd4-4823-b894-dfd971c748ce`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '1209' at
'attachStorageDomain'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::553::Storage.ResourceManager::(registerResource)
Trying to register resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc'
for lock type 'exclusive'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::612::Storage.ResourceManager::(registerResource)
Resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' is free. Now
locking as 'exclusive' (1 active user)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::resourceManager::240::Storage.ResourceManager.Request::(grant)
ResName=`Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc`ReqID=`46ee6ea9-6dd4-4823-b894-dfd971c748ce`::Granted
request
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,457::task::828::Storage.TaskManager.Task::(resourceAcquired)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_resourcesAcquired:
Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc (exclusive)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting False
jsonrpc.Executor/4::INFO::2016-03-08
15:04:29,458::sp::921::Storage.StoragePool::(attachSD)
sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc
spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::700::Storage.SamplingMethod::(__call__) Trying to enter
sampling method (storage.sdc.refreshStorage)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::703::Storage.SamplingMethod::(__call__) Got in to
sampling method
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::700::Storage.SamplingMethod::(__call__) Trying to enter
sampling method (storage.iscsi.rescan)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::misc::703::Storage.SamplingMethod::(__call__) Got in to
sampling method
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::iscsi::434::Storage.ISCSI::(rescan) Performing SCSI scan,
this will take up to 30 seconds
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,458::iscsiadm::97::Storage.Misc.excCmd::(_runCmd) /usr/bin/taskset
--cpu-list 0-7 /usr/bin/sudo -n /usr/sbin/iscsiadm -m session -R (cwd None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::misc::710::Storage.SamplingMethod::(__call__) Returning last
result
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::misc::700::Storage.SamplingMethod::(__call__) Trying to enter
sampling method (storage.hba.rescan)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::misc::703::Storage.SamplingMethod::(__call__) Got in to
sampling method
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,467::hba::56::Storage.HBA::(rescan) Starting scan
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,493::hba::62::Storage.HBA::(rescan) Scan finished
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,493::misc::710::Storage.SamplingMethod::(__call__) Returning last
result
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,493::multipath::78::Storage.Misc.excCmd::(rescan) /usr/bin/taskset
--cpu-list 0-7 /usr/bin/sudo -n /usr/sbin/multipath (cwd None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,532::multipath::78::Storage.Misc.excCmd::(rescan) SUCCESS: <err> =
''; <rc> = 0
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,532::commands::70::root::(execCmd) /usr/bin/taskset --cpu-list 0-7
/sbin/udevadm settle --timeout=5 (cwd None)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,540::commands::88::root::(execCmd) SUCCESS: <err> = ''; <rc>
= 0
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::497::Storage.OperationMutex::(_invalidateAllPvs)
Operation 'lvm invalidate operation' got the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::499::Storage.OperationMutex::(_invalidateAllPvs)
Operation 'lvm invalidate operation' released the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::508::Storage.OperationMutex::(_invalidateAllVgs)
Operation 'lvm invalidate operation' got the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::510::Storage.OperationMutex::(_invalidateAllVgs)
Operation 'lvm invalidate operation' released the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::528::Storage.OperationMutex::(_invalidateAllLvs)
Operation 'lvm invalidate operation' got the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::lvm::530::Storage.OperationMutex::(_invalidateAllLvs)
Operation 'lvm invalidate operation' released the operation mutex
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,541::misc::710::Storage.SamplingMethod::(__call__) Returning last
result
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,544::fileSD::159::Storage.StorageDomainManifest::(__init__)
Reading domain in path
/rhev/data-center/mnt/mididell.home:_var_lib_exports_iso-20160308130525/bd9860d2-756b-42bd-9cf6-08c0e96d70dc
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,544::persistentDict::192::Storage.PersistentDict::(__init__)
Created a persistent dict with FileMetadataRW backend
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::persistentDict::234::Storage.PersistentDict::(refresh) read
lines (FileMetadataRW)=[]
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::persistentDict::252::Storage.PersistentDict::(refresh) Empty
metadata
jsonrpc.Executor/4::ERROR::2016-03-08
15:04:29,545::task::867::Storage.TaskManager.Task::(_setError)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 874, in _run
return fn(*args, **kargs)
File "/usr/lib/python2.7/site-packages/vdsm/logUtils.py", line 50, in
wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 1211, in attachStorageDomain
pool.attachSD(sdUUID)
File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper
return method(self, *args, **kwargs)
File "/usr/share/vdsm/storage/sp.py", line 928, in attachSD
dom = sdCache.produce(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 100, in produce
domain.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 124, in _realProduce
domain = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 143, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/nfsSD.py", line 122, in findDomain
return NfsStorageDomain(NfsStorageDomain.findDomainPath(sdUUID))
File "/usr/share/vdsm/storage/fileSD.py", line 330, in __init__
manifest = self.manifestClass(domainPath)
File "/usr/share/vdsm/storage/fileSD.py", line 168, in __init__
sd.StorageDomainManifest.__init__(self, sdUUID, domaindir, metadata)
File "/usr/share/vdsm/storage/sd.py", line 310, in __init__
self._domainLock = self._makeDomainLock()
File "/usr/share/vdsm/storage/sd.py", line 439, in _makeDomainLock
domVersion = self.getVersion()
File "/usr/share/vdsm/storage/sd.py", line 359, in getVersion
return self.getMetaParam(DMDK_VERSION)
File "/usr/share/vdsm/storage/sd.py", line 356, in getMetaParam
return self._metadata[key]
File "/usr/share/vdsm/storage/persistentDict.py", line 89, in __getitem__
return dec(self._dict[key])
File "/usr/share/vdsm/storage/persistentDict.py", line 201, in
__getitem__
raise KeyError(key)
KeyError: 'VERSION'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::886::Storage.TaskManager.Task::(_run)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Task._run:
c24beaf3-733e-45b2-9c0b-31dce0e7d4a8
(u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',
u'07b2decc-9d40-4df6-bfa1-0da26f95df53') {} failed - stopping task
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::1247::Storage.TaskManager.Task::(stop)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::stopping in state preparing
(force False)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting True
jsonrpc.Executor/4::INFO::2016-03-08
15:04:29,545::task::1172::Storage.TaskManager.Task::(prepare)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::aborting: Task is aborted:
u"'VERSION'" - code 100
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,545::task::1177::Storage.TaskManager.Task::(prepare)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Prepare: aborted: 'VERSION'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::994::Storage.TaskManager.Task::(_decref)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 0 aborting True
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::929::Storage.TaskManager.Task::(_doAbort)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Task._doAbort: force False
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::596::Storage.TaskManager.Task::(_updateState)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state preparing ->
state aborting
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::551::Storage.TaskManager.Task::(__state_aborting)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_aborting: recover policy none
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::task::596::Storage.TaskManager.Task::(_updateState)
Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state aborting ->
state failed
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::951::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources
{u'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53': < ResourceRef
'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53', isValid: 'True' obj:
'None'>, u'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc': <
ResourceRef
'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc', isValid: 'True' obj:
'None'>}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::627::Storage.ResourceManager::(releaseResource)
Trying to release resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::646::Storage.ResourceManager::(releaseResource)
Released resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' (0 active
users)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::652::Storage.ResourceManager::(releaseResource)
Resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' is free, finding
out if anyone is waiting for it.
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::660::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53', Clearing records.
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::627::Storage.ResourceManager::(releaseResource)
Trying to release resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc'
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::646::Storage.ResourceManager::(releaseResource)
Released resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' (0 active
users)
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::652::Storage.ResourceManager::(releaseResource)
Resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' is free, finding
out if anyone is waiting for it.
jsonrpc.Executor/4::DEBUG::2016-03-08
15:04:29,546::resourceManager::660::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc', Clearing records.
jsonrpc.Executor/4::ERROR::2016-03-08
15:04:29,547::dispatcher::79::Storage.Dispatcher::(wrapper) 'VERSION'
Traceback (most recent call last):
File "/usr/share/vdsm/storage/dispatcher.py", line 71, in wrapper
result = ctask.prepare(func, *args, **kwargs)
File "/usr/share/vdsm/storage/task.py", line 105, in wrapper
return m(self, *a, **kw)
File "/usr/share/vdsm/storage/task.py", line 1180, in prepare
raise self.error
KeyError: 'VERSION'
Thread-41::DEBUG::2016-03-08
15:04:30,110::fileSD::174::Storage.Misc.excCmd::(getReadDelay)
/usr/bin/taskset --cpu-list 0-7 /usr/bin/dd
if=/rhev/data-center/mnt/_var_lib_images-20160308135819/8dc79844-210c-4bb1-acae-3c3e55d4fa3c/dom_md/metadata
iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-41::DEBUG::2016-03-08
15:04:30,114::fileSD::174::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n484 bytes (484 B) copied,
0.000216157 s, 2.2 MB/s\n'; <rc> = 0
jsonrpc.Executor/6::DEBUG::2016-03-08
15:04:37,311::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling
'StoragePool.getSpmStatus' in bridge with {u'storagepoolID':
u'07b2decc-9d40-4df6-bfa1-0da26f95df53'}
> On Tue, Mar 8, 2016 at 4:07 PM, Sandro Bonazzola <sbonazzo(a)redhat.com>
> wrote:
> > Hi, trying to attach an iso domain to engine master:
> >
> > 2016-03-08 15:04:28,386 INFO
> >
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> > (default task-50) [477da39f] Lock Acquired to object
> > 'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf
> > 6-08c0e96d70dc=<STORAGE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]',
> > sharedLocks='null'}'
> > 2016-03-08 15:04:28,433 INFO
> >
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Running command:
> > AttachStorageDomainToPoolCommand interna
> > l: false. Entities affected : ID: bd9860d2-756b-42bd-9cf6-08c0e96d70dc
> > Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type
> ADMIN,
> > ID: 07b2decc-9d40-4df6-bfa1-0da26f95df53 Type: StoragePoolAction
> > group MANIPULATE_STORAGE_DOMAIN with role type ADMIN
> > 2016-03-08 15:04:28,445 INFO
> >
> [org.ovirt.engine.core.bll.storage.connection.ConnectStorageToVdsCommand]
> > (org.ovirt.thread.pool-10-thread-43) [72ff69e2] Running command:
> > ConnectStorageToVdsCommand internal: true.
> > Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type:
> > SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN
> > 2016-03-08 15:04:28,447 INFO
> >
> [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
> > (org.ovirt.thread.pool-10-thread-43) [72ff69e2] START,
> > ConnectStorageServerVDSCommand(HostName = local_hos
> > t, StorageServerConnectionManagementVDSParameters:{runAsync='true',
> > hostId='384c1ab4-e03b-46ff-8e32-8a8b3650235b',
> > storagePoolId='00000000-0000-0000-0000-000000000000',
storageType='NFS',
> > connectionList='[Storag
> > eServerConnections:{id='51ffb87c-c595-4792-b915-50af506dbf67',
> > connection='mididell.home:/var/lib/exports/iso-20160308130525',
> iqn='null',
> > vfsType='null', mountOptions='null', nfsVersion='null',
nfsRetrans='null
> > ', nfsTimeo='null', iface='null',
netIfaceName='null'}]'}), log id:
> 2e547cc1
> > 2016-03-08 15:04:29,454 INFO
> >
> [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]
> > (org.ovirt.thread.pool-10-thread-43) [72ff69e2] FINISH,
> > ConnectStorageServerVDSCommand, return: {51ffb87c-
> > c595-4792-b915-50af506dbf67=0}, log id: 2e547cc1
> > 2016-03-08 15:04:29,455 INFO
> >
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] START,
> > AttachStorageDomainVDSCommand( AttachStorageDomainVD
> > SCommandParameters:{runAsync='true',
> > storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
> > ignoreFailoverLimit='false',
> > storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}), log id:
> 5bc96473
> > 2016-03-08 15:04:30,549 ERROR
> >
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Failed in
> > 'AttachStorageDomainVDS' method
> > 2016-03-08 15:04:30,558 ERROR
> > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: null,
> Call
> > Stack: null, Custom Event ID: -1, M
> > essage: VDSM command failed: Error in storage domain action:
> > (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
> > spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',)
> > 2016-03-08 15:04:30,558 ERROR
> >
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Command
> > 'AttachStorageDomainVDSCommand( AttachStorageDomain
> > VDSCommandParameters:{runAsync='true',
> > storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
> > ignoreFailoverLimit='false',
> > storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'})' execution
> failed:
> > IRSGenericExc
> > eption: IRSErrorException: Failed to AttachStorageDomainVDS, error =
> Error
> > in storage domain action:
> (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
> > spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350
> > 2016-03-08 15:04:30,558 INFO
> >
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] FINISH,
> > AttachStorageDomainVDSCommand, log id: 5bc96473
> > 2016-03-08 15:04:30,558 ERROR
> >
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Command
> > 'org.ovirt.engine.core.bll.storage.domain.AttachS
> > torageDomainToPoolCommand' failed: EngineException:
> >
> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
> > IRSGenericException: IRSErrorException: Failed to
> AttachStorageDomainVDS,
> > erro
> > r = Error in storage domain action:
> > (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,
> > spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350 (Failed with
> > error StorageDomainActionError and code 350)
> > 2016-03-08 15:04:30,559 INFO
> >
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Command
> > [id=6426d8ba-223f-401d-8fed-c537620bd4c3]: Compensating NEW_ENTITY_ID of
> > org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap;
> snapshot:
> >
> StoragePoolIsoMapId:{storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',
> > storageId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}.
> > 2016-03-08 15:04:30,575 ERROR
> > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID:
> 477da39f,
> > Job ID: 13fbe031-0c58-4fff-bc38-324cce2e4c3f, Call Stack: null, Custom
> Event
> > ID: -1, Message: Failed to attach Storage Domain ISO_DOMAIN to Data
> Center
> > local_datacenter. (User: admin@internal)
> > 2016-03-08 15:04:30,584 INFO
> >
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]
> > (org.ovirt.thread.pool-10-thread-42) [477da39f] Lock freed to object
> >
>
'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf6-08c0e96d70dc=<STORAGE,
> > ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
> >
> > Any hint on what can be the reason?
> >
> > # rpm -qv ovirt-engine
> >
> ovirt-engine-4.0.0-0.0.master.20160307171512.git398703d.el7.centos.noarch
> >
> > --
> > Sandro Bonazzola
> > Better technology. Faster innovation. Powered by community
> collaboration.
> > See how it works at redhat.com
> >
> > _______________________________________________
> > Devel mailing list
> > Devel(a)ovirt.org
> > http://lists.ovirt.org/mailman/listinfo/devel
>
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
2976
days inactive
2977
days old
3 comments
2 participants
participants (2)
-
Nir Soffer -
Sandro Bonazzola