--Apple-Mail=_B333446E-2E45-4D06-87D5-FAC3DE9E9DBC Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=us-ascii Hi, in logs engine.log=20 2014-02-22 23:02:17,446 ERROR = [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] = (ajp-/127.0.0.1:8702-8) Operation Failed: Entity not found: null vdsm log attached --Apple-Mail=_B333446E-2E45-4D06-87D5-FAC3DE9E9DBC Content-Disposition: attachment; filename=vdsm.log Content-Type: application/octet-stream; x-unix-mode=0644; name="vdsm.log" Content-Transfer-Encoding: quoted-printable Thread-600::DEBUG::2014-02-22=20= 23:04:56,814::resourceManager::648::ResourceManager::(releaseResource)=20= No=20one=20is=20waiting=20for=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20Clearing=20records.=0A= Thread-600::DEBUG::2014-02-22=20= 23:04:56,814::task::974::TaskManager.Task::(_decref)=20= Task=3D`d8ce5668-e14e-4d3d-bb9f-e231180079fd`::ref=200=20aborting=20= False=0AThread-601::DEBUG::2014-02-22=20= 23:04:57,467::task::579::TaskManager.Task::(_updateState)=20= Task=3D`13a65ab0-348d-4d14-bf18-eccbc9694a66`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-601::INFO::2014-02-22=20= 23:04:57,468::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= repoStats(options=3DNone)=0AThread-601::INFO::2014-02-22=20= 23:04:57,468::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= repoStats,=20Return=20response:=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000345636',=20'lastCheck':=20= '3.0',=20'valid':=20True},=20'5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20= {'code':=200,=20'version':=203,=20'acquired':=20True,=20'delay':=20= '0.000791732',=20'lastCheck':=20'2.4',=20'valid':=20True},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000183427',=20'lastCheck':=20= '3.9',=20'valid':=20True}}=0AThread-601::DEBUG::2014-02-22=20= 23:04:57,469::task::1168::TaskManager.Task::(prepare)=20= Task=3D`13a65ab0-348d-4d14-bf18-eccbc9694a66`::finished:=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000345636',=20'lastCheck':=20= '3.0',=20'valid':=20True},=20'5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20= {'code':=200,=20'version':=203,=20'acquired':=20True,=20'delay':=20= '0.000791732',=20'lastCheck':=20'2.4',=20'valid':=20True},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000183427',=20'lastCheck':=20= '3.9',=20'valid':=20True}}=0AThread-601::DEBUG::2014-02-22=20= 23:04:57,469::task::579::TaskManager.Task::(_updateState)=20= Task=3D`13a65ab0-348d-4d14-bf18-eccbc9694a66`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-601::DEBUG::2014-02-22=20= 23:04:57,469::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20{}=0A= Thread-601::DEBUG::2014-02-22=20= 23:04:57,470::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-601::DEBUG::2014-02-22=20= 23:04:57,470::task::974::TaskManager.Task::(_decref)=20= Task=3D`13a65ab0-348d-4d14-bf18-eccbc9694a66`::ref=200=20aborting=20= False=0AThread-26::DEBUG::2014-02-22=20= 23:05:03,614::domainMonitor::192::Storage.DomainMonitorThread::(_monitorDo= main)=20Refreshing=20domain=20ee57e3fd-ad08-4cd1-8396-d4d086ac0680=0A= Thread-26::DEBUG::2014-02-22=20= 23:05:03,647::fileSD::137::Storage.StorageDomain::(__init__)=20Reading=20= domain=20in=20path=20= /rhev/data-center/mnt/192.168.0.171:_srv_store_vm/ee57e3fd-ad08-4cd1-8396-= d4d086ac0680=0AThread-26::DEBUG::2014-02-22=20= 23:05:03,649::persistentDict::192::Storage.PersistentDict::(__init__)=20= Created=20a=20persistent=20dict=20with=20FileMetadataRW=20backend=0A= Thread-26::DEBUG::2014-02-22=20= 23:05:03,665::persistentDict::234::Storage.PersistentDict::(refresh)=20= read=20lines=20(FileMetadataRW)=3D['CLASS=3DData',=20= 'DESCRIPTION=3Dsstore',=20'IOOPTIMEOUTSEC=3D10',=20'LEASERETRIES=3D3',=20= 'LEASETIMESEC=3D60',=20'LOCKPOLICY=3D',=20'LOCKRENEWALINTERVALSEC=3D5',=20= 'MASTER_VERSION=3D2',=20'POOL_DESCRIPTION=3DDefault',=20= 'POOL_DOMAINS=3D73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-= 4b4d-83fe-78aba58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active'= ,=20'POOL_SPM_ID=3D1',=20'POOL_SPM_LVER=3D1',=20= 'POOL_UUID=3D5849b030-626e-47cb-ad90-3ce782d831b3',=20= 'REMOTE_PATH=3D192.168.0.171:/srv/store/vm',=20'ROLE=3DMaster',=20= 'SDUUID=3Dee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'TYPE=3DNFS',=20= 'VERSION=3D3',=20'_SHA_CKSUM=3Ded72997ee4e6040717765f6dbe967721a104f1fd']=0A= Thread-26::DEBUG::2014-02-22=20= 23:05:03,668::fileSD::558::Storage.StorageDomain::(imageGarbageCollector)=20= Removing=20remnants=20of=20deleted=20images=20[]=0A= Thread-26::INFO::2014-02-22=20= 23:05:03,669::sd::375::Storage.StorageDomain::(_registerResourceNamespaces= )=20Resource=20namespace=20ee57e3fd-ad08-4cd1-8396-d4d086ac0680_imageNS=20= already=20registered=0AThread-26::INFO::2014-02-22=20= 23:05:03,669::sd::383::Storage.StorageDomain::(_registerResourceNamespaces= )=20Resource=20namespace=20ee57e3fd-ad08-4cd1-8396-d4d086ac0680_volumeNS=20= already=20registered=0AThread-26::DEBUG::2014-02-22=20= 23:05:03,699::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/192.168.0.171:_srv_store_vm/ee57e3fd-ad08-4cd1-= 8396-d4d086ac0680/dom_md/metadata=20bs=3D4096=20count=3D1'=20(cwd=20= None)=0AThread-26::DEBUG::2014-02-22=20= 23:05:03,713::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n547=20= bytes=20(547=20B)=20copied,=200.000328811=20s,=201.7=20MB/s\n';=20<rc>=20= =3D=200=0AThread-21::DEBUG::2014-02-22=20= 23:05:04,503::domainMonitor::192::Storage.DomainMonitorThread::(_monitorDo= main)=20Refreshing=20domain=2073ea9031-8757-4df5-8c92-1836ac264042=0A= Thread-21::DEBUG::2014-02-22=20= 23:05:04,519::fileSD::137::Storage.StorageDomain::(__init__)=20Reading=20= domain=20in=20path=20= /rhev/data-center/mnt/192.168.0.171:_srv_bstore_vm/73ea9031-8757-4df5-8c92= -1836ac264042=0AThread-21::DEBUG::2014-02-22=20= 23:05:04,521::persistentDict::192::Storage.PersistentDict::(__init__)=20= Created=20a=20persistent=20dict=20with=20FileMetadataRW=20backend=0A= Thread-21::DEBUG::2014-02-22=20= 23:05:04,537::persistentDict::234::Storage.PersistentDict::(refresh)=20= read=20lines=20(FileMetadataRW)=3D['CLASS=3DData',=20= 'DESCRIPTION=3Dbstore',=20'IOOPTIMEOUTSEC=3D10',=20'LEASERETRIES=3D3',=20= 'LEASETIMESEC=3D60',=20'LOCKPOLICY=3D',=20'LOCKRENEWALINTERVALSEC=3D5',=20= 'MASTER_VERSION=3D0',=20= 'POOL_UUID=3D5849b030-626e-47cb-ad90-3ce782d831b3',=20= 'REMOTE_PATH=3D192.168.0.171:/srv/bstore/vm',=20'ROLE=3DRegular',=20= 'SDUUID=3D73ea9031-8757-4df5-8c92-1836ac264042',=20'TYPE=3DNFS',=20= 'VERSION=3D3',=20'_SHA_CKSUM=3Da12c6ef0e0ff1400ae80e055f130fd18caafe9fb']=0A= Thread-21::DEBUG::2014-02-22=20= 23:05:04,540::fileSD::558::Storage.StorageDomain::(imageGarbageCollector)=20= Removing=20remnants=20of=20deleted=20images=20[]=0A= Thread-21::INFO::2014-02-22=20= 23:05:04,541::sd::375::Storage.StorageDomain::(_registerResourceNamespaces= )=20Resource=20namespace=2073ea9031-8757-4df5-8c92-1836ac264042_imageNS=20= already=20registered=0AThread-21::INFO::2014-02-22=20= 23:05:04,541::sd::383::Storage.StorageDomain::(_registerResourceNamespaces= )=20Resource=20namespace=2073ea9031-8757-4df5-8c92-1836ac264042_volumeNS=20= already=20registered=0AThread-21::DEBUG::2014-02-22=20= 23:05:04,563::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/192.168.0.171:_srv_bstore_vm/73ea9031-8757-4df5= -8c92-1836ac264042/dom_md/metadata=20bs=3D4096=20count=3D1'=20(cwd=20= None)=0AThread-21::DEBUG::2014-02-22=20= 23:05:04,576::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n349=20= bytes=20(349=20B)=20copied,=200.000309329=20s,=201.1=20MB/s\n';=20<rc>=20= =3D=200=0AThread-23::DEBUG::2014-02-22=20= 23:05:05,080::domainMonitor::192::Storage.DomainMonitorThread::(_monitorDo= main)=20Refreshing=20domain=205cd522d0-bc23-4b4d-83fe-78aba58b47fc=0A= Thread-23::DEBUG::2014-02-22=20= 23:05:05,092::fileSD::137::Storage.StorageDomain::(__init__)=20Reading=20= domain=20in=20path=20= /rhev/data-center/mnt/rhevm.cebra.lab:_var_lib_exports_iso/5cd522d0-bc23-4= b4d-83fe-78aba58b47fc=0AThread-23::DEBUG::2014-02-22=20= 23:05:05,094::persistentDict::192::Storage.PersistentDict::(__init__)=20= Created=20a=20persistent=20dict=20with=20FileMetadataRW=20backend=0A= Thread-23::DEBUG::2014-02-22=20= 23:05:05,112::persistentDict::234::Storage.PersistentDict::(refresh)=20= read=20lines=20(FileMetadataRW)=3D['CLASS=3DData',=20'DESCRIPTION=3DISO',=20= 'IOOPTIMEOUTSEC=3D10',=20'LEASERETRIES=3D3',=20'LEASETIMESEC=3D60',=20= 'LOCKPOLICY=3D',=20'LOCKRENEWALINTERVALSEC=3D5',=20'MASTER_VERSION=3D1',=20= 'POOL_DESCRIPTION=3DDefault',=20= 'POOL_DOMAINS=3D73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-= 4b4d-83fe-78aba58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active'= ,=20'POOL_SPM_ID=3D1',=20'POOL_SPM_LVER=3D0',=20= 'POOL_UUID=3D5849b030-626e-47cb-ad90-3ce782d831b3',=20= 'REMOTE_PATH=3Drhevm.cebra.lab:/var/lib/exports/iso',=20'ROLE=3DMaster',=20= 'SDUUID=3D5cd522d0-bc23-4b4d-83fe-78aba58b47fc',=20'TYPE=3DNFS',=20= 'VERSION=3D3',=20'_SHA_CKSUM=3Dda95d1b98b5e92217949ec9416d1481cefe76ef0']=0A= Thread-23::DEBUG::2014-02-22=20= 23:05:05,116::fileSD::558::Storage.StorageDomain::(imageGarbageCollector)=20= Removing=20remnants=20of=20deleted=20images=20[]=0A= Thread-23::INFO::2014-02-22=20= 23:05:05,116::sd::375::Storage.StorageDomain::(_registerResourceNamespaces= )=20Resource=20namespace=205cd522d0-bc23-4b4d-83fe-78aba58b47fc_imageNS=20= already=20registered=0AThread-23::INFO::2014-02-22=20= 23:05:05,117::sd::383::Storage.StorageDomain::(_registerResourceNamespaces= )=20Resource=20namespace=205cd522d0-bc23-4b4d-83fe-78aba58b47fc_volumeNS=20= already=20registered=0AThread-23::DEBUG::2014-02-22=20= 23:05:05,135::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/rhevm.cebra.lab:_var_lib_exports_iso/5cd522d0-b= c23-4b4d-83fe-78aba58b47fc/dom_md/metadata=20bs=3D4096=20count=3D1'=20= (cwd=20None)=0AThread-23::DEBUG::2014-02-22=20= 23:05:05,149::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n553=20= bytes=20(553=20B)=20copied,=200.000811093=20s,=20682=20kB/s\n';=20<rc>=20= =3D=200=0AThread-615::DEBUG::2014-02-22=20= 23:05:06,926::BindingXMLRPC::177::vds::(wrapper)=20client=20= [192.168.0.170]=0AThread-615::DEBUG::2014-02-22=20= 23:05:06,927::task::579::TaskManager.Task::(_updateState)=20= Task=3D`d97ff9b7-17ce-44b8-829e-025245d4abde`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-615::INFO::2014-02-22=20= 23:05:06,928::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= getSpmStatus(spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3',=20= options=3DNone)=0AThread-615::INFO::2014-02-22=20= 23:05:06,928::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20= 'spmStatus':=20'SPM',=20'spmLver':=201}}=0AThread-615::DEBUG::2014-02-22=20= 23:05:06,929::task::1168::TaskManager.Task::(prepare)=20= Task=3D`d97ff9b7-17ce-44b8-829e-025245d4abde`::finished:=20{'spm_st':=20= {'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=201}}=0A= Thread-615::DEBUG::2014-02-22=20= 23:05:06,929::task::579::TaskManager.Task::(_updateState)=20= Task=3D`d97ff9b7-17ce-44b8-829e-025245d4abde`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-615::DEBUG::2014-02-22=20= 23:05:06,929::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20{}=0A= Thread-615::DEBUG::2014-02-22=20= 23:05:06,930::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-615::DEBUG::2014-02-22=20= 23:05:06,930::task::974::TaskManager.Task::(_decref)=20= Task=3D`d97ff9b7-17ce-44b8-829e-025245d4abde`::ref=200=20aborting=20= False=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,937::BindingXMLRPC::177::vds::(wrapper)=20client=20= [192.168.0.170]=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,938::task::579::TaskManager.Task::(_updateState)=20= Task=3D`005051ac-4b9d-4363-bbba-eefa54e86be2`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-616::INFO::2014-02-22=20= 23:05:06,939::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= getStoragePoolInfo(spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3',=20= options=3DNone)=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,940::resourceManager::197::ResourceManager.Request::(__init__)=20= ResName=3D`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=3D`e3678b4a-= e708-4a93-a8d0-123b0e0fb4fb`::Request=20was=20made=20in=20= '/usr/share/vdsm/storage/hsm.py'=20line=20'2562'=20at=20= 'getStoragePoolInfo'=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,940::resourceManager::541::ResourceManager::(registerResource)=20= Trying=20to=20register=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20for=20lock=20type=20= 'shared'=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,940::resourceManager::600::ResourceManager::(registerResource)=20= Resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20is=20free.=20= Now=20locking=20as=20'shared'=20(1=20active=20user)=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,941::resourceManager::237::ResourceManager.Request::(grant)=20= ResName=3D`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=3D`e3678b4a-= e708-4a93-a8d0-123b0e0fb4fb`::Granted=20request=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,942::task::811::TaskManager.Task::(resourceAcquired)=20= Task=3D`005051ac-4b9d-4363-bbba-eefa54e86be2`::_resourcesAcquired:=20= Storage.5849b030-626e-47cb-ad90-3ce782d831b3=20(shared)=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,942::task::974::TaskManager.Task::(_decref)=20= Task=3D`005051ac-4b9d-4363-bbba-eefa54e86be2`::ref=201=20aborting=20= False=0AThread-616::INFO::2014-02-22=20= 23:05:06,950::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20= 'master_uuid':=20'ee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'name':=20= 'Default',=20'version':=20'3',=20'domains':=20= '73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-4b4d-83fe-78aba= 58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active',=20= 'pool_status':=20'connected',=20'isoprefix':=20'',=20'type':=20'NFS',=20= 'master_ver':=202,=20'lver':=201},=20'dominfo':=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'status':=20'Active',=20= 'diskfree':=20'2197912813568',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'2197949513728',=20'version':=203},=20= '5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20{'status':=20'Active',=20= 'diskfree':=20'41649438720',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'47254077440',=20'version':=203},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'status':=20'Active',=20= 'diskfree':=20'249898729472',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'249934381056',=20'version':=203}}}=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,951::task::1168::TaskManager.Task::(prepare)=20= Task=3D`005051ac-4b9d-4363-bbba-eefa54e86be2`::finished:=20{'info':=20= {'spm_id':=201,=20'master_uuid':=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'name':=20'Default',=20= 'version':=20'3',=20'domains':=20= '73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-4b4d-83fe-78aba= 58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active',=20= 'pool_status':=20'connected',=20'isoprefix':=20'',=20'type':=20'NFS',=20= 'master_ver':=202,=20'lver':=201},=20'dominfo':=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'status':=20'Active',=20= 'diskfree':=20'2197912813568',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'2197949513728',=20'version':=203},=20= '5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20{'status':=20'Active',=20= 'diskfree':=20'41649438720',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'47254077440',=20'version':=203},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'status':=20'Active',=20= 'diskfree':=20'249898729472',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'249934381056',=20'version':=203}}}=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,951::task::579::TaskManager.Task::(_updateState)=20= Task=3D`005051ac-4b9d-4363-bbba-eefa54e86be2`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,951::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20= {'Storage.5849b030-626e-47cb-ad90-3ce782d831b3':=20<=20ResourceRef=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20isValid:=20'True'=20= obj:=20'None'>}=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,952::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,952::resourceManager::615::ResourceManager::(releaseResource)=20= Trying=20to=20release=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,953::resourceManager::634::ResourceManager::(releaseResource)=20= Released=20resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20= (0=20active=20users)=0AThread-616::DEBUG::2014-02-22=20= 23:05:06,953::resourceManager::640::ResourceManager::(releaseResource)=20= Resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20is=20free,=20= finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,953::resourceManager::648::ResourceManager::(releaseResource)=20= No=20one=20is=20waiting=20for=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20Clearing=20records.=0A= Thread-616::DEBUG::2014-02-22=20= 23:05:06,954::task::974::TaskManager.Task::(_decref)=20= Task=3D`005051ac-4b9d-4363-bbba-eefa54e86be2`::ref=200=20aborting=20= False=0AThread-618::DEBUG::2014-02-22=20= 23:05:12,740::task::579::TaskManager.Task::(_updateState)=20= Task=3D`1f9763c6-06f2-4684-a498-fb4f297b7b8d`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-618::INFO::2014-02-22=20= 23:05:12,740::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= repoStats(options=3DNone)=0AThread-618::INFO::2014-02-22=20= 23:05:12,741::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= repoStats,=20Return=20response:=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000309329',=20'lastCheck':=20= '8.2',=20'valid':=20True},=20'5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20= {'code':=200,=20'version':=203,=20'acquired':=20True,=20'delay':=20= '0.000811093',=20'lastCheck':=20'7.6',=20'valid':=20True},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000328811',=20'lastCheck':=20= '9.0',=20'valid':=20True}}=0AThread-618::DEBUG::2014-02-22=20= 23:05:12,741::task::1168::TaskManager.Task::(prepare)=20= Task=3D`1f9763c6-06f2-4684-a498-fb4f297b7b8d`::finished:=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000309329',=20'lastCheck':=20= '8.2',=20'valid':=20True},=20'5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20= {'code':=200,=20'version':=203,=20'acquired':=20True,=20'delay':=20= '0.000811093',=20'lastCheck':=20'7.6',=20'valid':=20True},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000328811',=20'lastCheck':=20= '9.0',=20'valid':=20True}}=0AThread-618::DEBUG::2014-02-22=20= 23:05:12,742::task::579::TaskManager.Task::(_updateState)=20= Task=3D`1f9763c6-06f2-4684-a498-fb4f297b7b8d`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-618::DEBUG::2014-02-22=20= 23:05:12,742::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20{}=0A= Thread-618::DEBUG::2014-02-22=20= 23:05:12,742::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-618::DEBUG::2014-02-22=20= 23:05:12,743::task::974::TaskManager.Task::(_decref)=20= Task=3D`1f9763c6-06f2-4684-a498-fb4f297b7b8d`::ref=200=20aborting=20= False=0AThread-26::DEBUG::2014-02-22=20= 23:05:13,742::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/192.168.0.171:_srv_store_vm/ee57e3fd-ad08-4cd1-= 8396-d4d086ac0680/dom_md/metadata=20bs=3D4096=20count=3D1'=20(cwd=20= None)=0AThread-26::DEBUG::2014-02-22=20= 23:05:13,756::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n547=20= bytes=20(547=20B)=20copied,=200.000327733=20s,=201.7=20MB/s\n';=20<rc>=20= =3D=200=0AThread-21::DEBUG::2014-02-22=20= 23:05:14,599::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/192.168.0.171:_srv_bstore_vm/73ea9031-8757-4df5= -8c92-1836ac264042/dom_md/metadata=20bs=3D4096=20count=3D1'=20(cwd=20= None)=0AThread-21::DEBUG::2014-02-22=20= 23:05:14,612::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n349=20= bytes=20(349=20B)=20copied,=200.000299729=20s,=201.2=20MB/s\n';=20<rc>=20= =3D=200=0AThread-23::DEBUG::2014-02-22=20= 23:05:15,180::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/rhevm.cebra.lab:_var_lib_exports_iso/5cd522d0-b= c23-4b4d-83fe-78aba58b47fc/dom_md/metadata=20bs=3D4096=20count=3D1'=20= (cwd=20None)=0AThread-23::DEBUG::2014-02-22=20= 23:05:15,195::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n553=20= bytes=20(553=20B)=20copied,=200.000818799=20s,=20675=20kB/s\n';=20<rc>=20= =3D=200=0AThread-621::DEBUG::2014-02-22=20= 23:05:17,042::BindingXMLRPC::177::vds::(wrapper)=20client=20= [192.168.0.170]=0AThread-621::DEBUG::2014-02-22=20= 23:05:17,043::task::579::TaskManager.Task::(_updateState)=20= Task=3D`d07202d3-e67f-42c4-9e88-cc5524acdfd2`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-621::INFO::2014-02-22=20= 23:05:17,043::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= getSpmStatus(spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3',=20= options=3DNone)=0AThread-621::INFO::2014-02-22=20= 23:05:17,044::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20= 'spmStatus':=20'SPM',=20'spmLver':=201}}=0AThread-621::DEBUG::2014-02-22=20= 23:05:17,044::task::1168::TaskManager.Task::(prepare)=20= Task=3D`d07202d3-e67f-42c4-9e88-cc5524acdfd2`::finished:=20{'spm_st':=20= {'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=201}}=0A= Thread-621::DEBUG::2014-02-22=20= 23:05:17,044::task::579::TaskManager.Task::(_updateState)=20= Task=3D`d07202d3-e67f-42c4-9e88-cc5524acdfd2`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-621::DEBUG::2014-02-22=20= 23:05:17,045::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20{}=0A= Thread-621::DEBUG::2014-02-22=20= 23:05:17,045::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-621::DEBUG::2014-02-22=20= 23:05:17,045::task::974::TaskManager.Task::(_decref)=20= Task=3D`d07202d3-e67f-42c4-9e88-cc5524acdfd2`::ref=200=20aborting=20= False=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,053::BindingXMLRPC::177::vds::(wrapper)=20client=20= [192.168.0.170]=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,054::task::579::TaskManager.Task::(_updateState)=20= Task=3D`26a5e591-f984-48b8-a183-4aa38539dffd`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-622::INFO::2014-02-22=20= 23:05:17,054::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= getStoragePoolInfo(spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3',=20= options=3DNone)=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,055::resourceManager::197::ResourceManager.Request::(__init__)=20= ResName=3D`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=3D`9f5b190d-= 4a75-406e-ae81-7b29bfb93c45`::Request=20was=20made=20in=20= '/usr/share/vdsm/storage/hsm.py'=20line=20'2562'=20at=20= 'getStoragePoolInfo'=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,055::resourceManager::541::ResourceManager::(registerResource)=20= Trying=20to=20register=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20for=20lock=20type=20= 'shared'=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,056::resourceManager::600::ResourceManager::(registerResource)=20= Resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20is=20free.=20= Now=20locking=20as=20'shared'=20(1=20active=20user)=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,056::resourceManager::237::ResourceManager.Request::(grant)=20= ResName=3D`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=3D`9f5b190d-= 4a75-406e-ae81-7b29bfb93c45`::Granted=20request=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,057::task::811::TaskManager.Task::(resourceAcquired)=20= Task=3D`26a5e591-f984-48b8-a183-4aa38539dffd`::_resourcesAcquired:=20= Storage.5849b030-626e-47cb-ad90-3ce782d831b3=20(shared)=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,057::task::974::TaskManager.Task::(_decref)=20= Task=3D`26a5e591-f984-48b8-a183-4aa38539dffd`::ref=201=20aborting=20= False=0AThread-622::INFO::2014-02-22=20= 23:05:17,064::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20= 'master_uuid':=20'ee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'name':=20= 'Default',=20'version':=20'3',=20'domains':=20= '73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-4b4d-83fe-78aba= 58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active',=20= 'pool_status':=20'connected',=20'isoprefix':=20'',=20'type':=20'NFS',=20= 'master_ver':=202,=20'lver':=201},=20'dominfo':=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'status':=20'Active',=20= 'diskfree':=20'2197912813568',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'2197949513728',=20'version':=203},=20= '5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20{'status':=20'Active',=20= 'diskfree':=20'41649438720',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'47254077440',=20'version':=203},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'status':=20'Active',=20= 'diskfree':=20'249898729472',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'249934381056',=20'version':=203}}}=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,064::task::1168::TaskManager.Task::(prepare)=20= Task=3D`26a5e591-f984-48b8-a183-4aa38539dffd`::finished:=20{'info':=20= {'spm_id':=201,=20'master_uuid':=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'name':=20'Default',=20= 'version':=20'3',=20'domains':=20= '73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-4b4d-83fe-78aba= 58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active',=20= 'pool_status':=20'connected',=20'isoprefix':=20'',=20'type':=20'NFS',=20= 'master_ver':=202,=20'lver':=201},=20'dominfo':=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'status':=20'Active',=20= 'diskfree':=20'2197912813568',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'2197949513728',=20'version':=203},=20= '5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20{'status':=20'Active',=20= 'diskfree':=20'41649438720',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'47254077440',=20'version':=203},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'status':=20'Active',=20= 'diskfree':=20'249898729472',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'249934381056',=20'version':=203}}}=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,065::task::579::TaskManager.Task::(_updateState)=20= Task=3D`26a5e591-f984-48b8-a183-4aa38539dffd`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,065::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20= {'Storage.5849b030-626e-47cb-ad90-3ce782d831b3':=20<=20ResourceRef=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20isValid:=20'True'=20= obj:=20'None'>}=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,065::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,066::resourceManager::615::ResourceManager::(releaseResource)=20= Trying=20to=20release=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,066::resourceManager::634::ResourceManager::(releaseResource)=20= Released=20resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20= (0=20active=20users)=0AThread-622::DEBUG::2014-02-22=20= 23:05:17,066::resourceManager::640::ResourceManager::(releaseResource)=20= Resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20is=20free,=20= finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,067::resourceManager::648::ResourceManager::(releaseResource)=20= No=20one=20is=20waiting=20for=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20Clearing=20records.=0A= Thread-622::DEBUG::2014-02-22=20= 23:05:17,067::task::974::TaskManager.Task::(_decref)=20= Task=3D`26a5e591-f984-48b8-a183-4aa38539dffd`::ref=200=20aborting=20= False=0AThread-26::DEBUG::2014-02-22=20= 23:05:23,781::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/192.168.0.171:_srv_store_vm/ee57e3fd-ad08-4cd1-= 8396-d4d086ac0680/dom_md/metadata=20bs=3D4096=20count=3D1'=20(cwd=20= None)=0AThread-26::DEBUG::2014-02-22=20= 23:05:23,921::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n547=20= bytes=20(547=20B)=20copied,=200.000509778=20s,=201.1=20MB/s\n';=20<rc>=20= =3D=200=0AThread-21::DEBUG::2014-02-22=20= 23:05:24,638::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/192.168.0.171:_srv_bstore_vm/73ea9031-8757-4df5= -8c92-1836ac264042/dom_md/metadata=20bs=3D4096=20count=3D1'=20(cwd=20= None)=0AThread-21::DEBUG::2014-02-22=20= 23:05:24,651::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n349=20= bytes=20(349=20B)=20copied,=200.000311853=20s,=201.1=20MB/s\n';=20<rc>=20= =3D=200=0AThread-23::DEBUG::2014-02-22=20= 23:05:25,224::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= '/bin/dd=20iflag=3Ddirect=20= if=3D/rhev/data-center/mnt/rhevm.cebra.lab:_var_lib_exports_iso/5cd522d0-b= c23-4b4d-83fe-78aba58b47fc/dom_md/metadata=20bs=3D4096=20count=3D1'=20= (cwd=20None)=0AThread-23::DEBUG::2014-02-22=20= 23:05:25,238::fileSD::222::Storage.Misc.excCmd::(getReadDelay)=20= SUCCESS:=20<err>=20=3D=20'0+1=20records=20in\n0+1=20records=20out\n553=20= bytes=20(553=20B)=20copied,=200.000794238=20s,=20696=20kB/s\n';=20<rc>=20= =3D=200=0AThread-626::DEBUG::2014-02-22=20= 23:05:27,281::BindingXMLRPC::177::vds::(wrapper)=20client=20= [192.168.0.170]=0AThread-626::DEBUG::2014-02-22=20= 23:05:27,282::task::579::TaskManager.Task::(_updateState)=20= Task=3D`765d9993-ad97-4093-8edd-2cb4887069ad`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-626::INFO::2014-02-22=20= 23:05:27,282::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= getSpmStatus(spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3',=20= options=3DNone)=0AThread-626::INFO::2014-02-22=20= 23:05:27,283::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= getSpmStatus,=20Return=20response:=20{'spm_st':=20{'spmId':=201,=20= 'spmStatus':=20'SPM',=20'spmLver':=201}}=0AThread-626::DEBUG::2014-02-22=20= 23:05:27,283::task::1168::TaskManager.Task::(prepare)=20= Task=3D`765d9993-ad97-4093-8edd-2cb4887069ad`::finished:=20{'spm_st':=20= {'spmId':=201,=20'spmStatus':=20'SPM',=20'spmLver':=201}}=0A= Thread-626::DEBUG::2014-02-22=20= 23:05:27,283::task::579::TaskManager.Task::(_updateState)=20= Task=3D`765d9993-ad97-4093-8edd-2cb4887069ad`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-626::DEBUG::2014-02-22=20= 23:05:27,284::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20{}=0A= Thread-626::DEBUG::2014-02-22=20= 23:05:27,284::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-626::DEBUG::2014-02-22=20= 23:05:27,284::task::974::TaskManager.Task::(_decref)=20= Task=3D`765d9993-ad97-4093-8edd-2cb4887069ad`::ref=200=20aborting=20= False=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,292::BindingXMLRPC::177::vds::(wrapper)=20client=20= [192.168.0.170]=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,292::task::579::TaskManager.Task::(_updateState)=20= Task=3D`fa20b6c3-e575-4721-8faa-7e7916ca4127`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-627::INFO::2014-02-22=20= 23:05:27,293::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= getStoragePoolInfo(spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3',=20= options=3DNone)=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,294::resourceManager::197::ResourceManager.Request::(__init__)=20= ResName=3D`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=3D`de253c34-= 66f7-4930-9341-04f6a48ef99e`::Request=20was=20made=20in=20= '/usr/share/vdsm/storage/hsm.py'=20line=20'2562'=20at=20= 'getStoragePoolInfo'=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,294::resourceManager::541::ResourceManager::(registerResource)=20= Trying=20to=20register=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20for=20lock=20type=20= 'shared'=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,294::resourceManager::600::ResourceManager::(registerResource)=20= Resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20is=20free.=20= Now=20locking=20as=20'shared'=20(1=20active=20user)=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,295::resourceManager::237::ResourceManager.Request::(grant)=20= ResName=3D`Storage.5849b030-626e-47cb-ad90-3ce782d831b3`ReqID=3D`de253c34-= 66f7-4930-9341-04f6a48ef99e`::Granted=20request=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,295::task::811::TaskManager.Task::(resourceAcquired)=20= Task=3D`fa20b6c3-e575-4721-8faa-7e7916ca4127`::_resourcesAcquired:=20= Storage.5849b030-626e-47cb-ad90-3ce782d831b3=20(shared)=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,295::task::974::TaskManager.Task::(_decref)=20= Task=3D`fa20b6c3-e575-4721-8faa-7e7916ca4127`::ref=201=20aborting=20= False=0AThread-627::INFO::2014-02-22=20= 23:05:27,302::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= getStoragePoolInfo,=20Return=20response:=20{'info':=20{'spm_id':=201,=20= 'master_uuid':=20'ee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'name':=20= 'Default',=20'version':=20'3',=20'domains':=20= '73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-4b4d-83fe-78aba= 58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active',=20= 'pool_status':=20'connected',=20'isoprefix':=20'',=20'type':=20'NFS',=20= 'master_ver':=202,=20'lver':=201},=20'dominfo':=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'status':=20'Active',=20= 'diskfree':=20'2197912813568',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'2197949513728',=20'version':=203},=20= '5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20{'status':=20'Active',=20= 'diskfree':=20'41649438720',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'47254077440',=20'version':=203},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'status':=20'Active',=20= 'diskfree':=20'249898729472',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'249934381056',=20'version':=203}}}=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,302::task::1168::TaskManager.Task::(prepare)=20= Task=3D`fa20b6c3-e575-4721-8faa-7e7916ca4127`::finished:=20{'info':=20= {'spm_id':=201,=20'master_uuid':=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680',=20'name':=20'Default',=20= 'version':=20'3',=20'domains':=20= '73ea9031-8757-4df5-8c92-1836ac264042:Active,5cd522d0-bc23-4b4d-83fe-78aba= 58b47fc:Active,ee57e3fd-ad08-4cd1-8396-d4d086ac0680:Active',=20= 'pool_status':=20'connected',=20'isoprefix':=20'',=20'type':=20'NFS',=20= 'master_ver':=202,=20'lver':=201},=20'dominfo':=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'status':=20'Active',=20= 'diskfree':=20'2197912813568',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'2197949513728',=20'version':=203},=20= '5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20{'status':=20'Active',=20= 'diskfree':=20'41649438720',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'47254077440',=20'version':=203},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'status':=20'Active',=20= 'diskfree':=20'249898729472',=20'isoprefix':=20'',=20'alerts':=20[],=20= 'disktotal':=20'249934381056',=20'version':=203}}}=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,303::task::579::TaskManager.Task::(_updateState)=20= Task=3D`fa20b6c3-e575-4721-8faa-7e7916ca4127`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,303::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20= {'Storage.5849b030-626e-47cb-ad90-3ce782d831b3':=20<=20ResourceRef=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20isValid:=20'True'=20= obj:=20'None'>}=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,303::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,304::resourceManager::615::ResourceManager::(releaseResource)=20= Trying=20to=20release=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,304::resourceManager::634::ResourceManager::(releaseResource)=20= Released=20resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20= (0=20active=20users)=0AThread-627::DEBUG::2014-02-22=20= 23:05:27,304::resourceManager::640::ResourceManager::(releaseResource)=20= Resource=20'Storage.5849b030-626e-47cb-ad90-3ce782d831b3'=20is=20free,=20= finding=20out=20if=20anyone=20is=20waiting=20for=20it.=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,305::resourceManager::648::ResourceManager::(releaseResource)=20= No=20one=20is=20waiting=20for=20resource=20= 'Storage.5849b030-626e-47cb-ad90-3ce782d831b3',=20Clearing=20records.=0A= Thread-627::DEBUG::2014-02-22=20= 23:05:27,305::task::974::TaskManager.Task::(_decref)=20= Task=3D`fa20b6c3-e575-4721-8faa-7e7916ca4127`::ref=200=20aborting=20= False=0AThread-628::DEBUG::2014-02-22=20= 23:05:27,959::task::579::TaskManager.Task::(_updateState)=20= Task=3D`907bfe0a-0dcf-4207-acb2-3c9c0671bda3`::moving=20from=20state=20= init=20->=20state=20preparing=0AThread-628::INFO::2014-02-22=20= 23:05:27,960::logUtils::44::dispatcher::(wrapper)=20Run=20and=20protect:=20= repoStats(options=3DNone)=0AThread-628::INFO::2014-02-22=20= 23:05:27,961::logUtils::47::dispatcher::(wrapper)=20Run=20and=20protect:=20= repoStats,=20Return=20response:=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000311853',=20'lastCheck':=20= '3.3',=20'valid':=20True},=20'5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20= {'code':=200,=20'version':=203,=20'acquired':=20True,=20'delay':=20= '0.000794238',=20'lastCheck':=20'2.7',=20'valid':=20True},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000509778',=20'lastCheck':=20= '4.0',=20'valid':=20True}}=0AThread-628::DEBUG::2014-02-22=20= 23:05:27,961::task::1168::TaskManager.Task::(prepare)=20= Task=3D`907bfe0a-0dcf-4207-acb2-3c9c0671bda3`::finished:=20= {'73ea9031-8757-4df5-8c92-1836ac264042':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000311853',=20'lastCheck':=20= '3.3',=20'valid':=20True},=20'5cd522d0-bc23-4b4d-83fe-78aba58b47fc':=20= {'code':=200,=20'version':=203,=20'acquired':=20True,=20'delay':=20= '0.000794238',=20'lastCheck':=20'2.7',=20'valid':=20True},=20= 'ee57e3fd-ad08-4cd1-8396-d4d086ac0680':=20{'code':=200,=20'version':=20= 3,=20'acquired':=20True,=20'delay':=20'0.000509778',=20'lastCheck':=20= '4.0',=20'valid':=20True}}=0AThread-628::DEBUG::2014-02-22=20= 23:05:27,961::task::579::TaskManager.Task::(_updateState)=20= Task=3D`907bfe0a-0dcf-4207-acb2-3c9c0671bda3`::moving=20from=20state=20= preparing=20->=20state=20finished=0AThread-628::DEBUG::2014-02-22=20= 23:05:27,962::resourceManager::939::ResourceManager.Owner::(releaseAll)=20= Owner.releaseAll=20requests=20{}=20resources=20{}=0A= Thread-628::DEBUG::2014-02-22=20= 23:05:27,962::resourceManager::976::ResourceManager.Owner::(cancelAll)=20= Owner.cancelAll=20requests=20{}=0AThread-628::DEBUG::2014-02-22=20= 23:05:27,962::task::974::TaskManager.Task::(_decref)=20= Task=3D`907bfe0a-0dcf-4207-acb2-3c9c0671bda3`::ref=200=20aborting=20= False=0A= --Apple-Mail=_B333446E-2E45-4D06-87D5-FAC3DE9E9DBC Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=windows-1251 Artem 22 =F4=E5=E2=F0. 2014 =E3., =E2 22:38, Meital Bourvine = <mbourvin@redhat.com> =ED=E0=EF=E8=F1=E0=EB(=E0):

Sounds like a bug to me. =20 Can you please attach engine.log and vdsm.log? =20 ----- Original Message -----

...

From: "sirin" <artem@e-inet.ru> To: users@ovirt.org Sent: Saturday, February 22, 2014 8:28:54 PM Subject: [Users] Cannot delete storage connection =20 Hi all, =20 i have next connection =20 <storage_connections> <storage_connection href=3D"/api/storageconnections/d94d9341-6116-4b1a-94c5-5c3327aa1b09" id=3D"d94d9341-6116-4b1a-94c5-5c3327aa1b09=BB> <address>192.168.0.171</address> <type>nfs</type> <path>/srv/lstore/vm</path> </storage_connection> =20 <storage_connection href=3D"/api/storageconnections/67539ba5-9b6d-46df-8c96-4acd3f212f4a" id=3D"67539ba5-9b6d-46df-8c96-4acd3f212f4a=BB> <address>rhevm.cebra.lab</address> <type>nfs</type> <path>/var/lib/exports/iso</path> </storage_connection> =20 <storage_connection href=3D"/api/storageconnections/fdc92419-b278-4b11-9eba-f68fd4914132" id=3D"fdc92419-b278-4b11-9eba-f68fd4914132=BB> <address>192.168.0.171</address> <type>nfs</type> <path>/srv/store/vm</path> </storage_connection> =20 <storage_connection href=3D"/api/storageconnections/92fc6cf3-17b1-4b69-af80-5782270137ed" id=3D"92fc6cf3-17b1-4b69-af80-5782270137ed=BB> <address>192.168.0.171</address> <type>nfs</type> <path>/srv/bstore/vm</path> </storage_connection> </storage_connections> =20 =20 I want to remove this connection = id=3D"d94d9341-6116-4b1a-94c5-5c3327aa1b09=BB but=85 fail =20 [RHEVM shell (connected)]# show storageconnection d94d9341-6116-4b1a-94c5-5c3327aa1b09 =20 id : d94d9341-6116-4b1a-94c5-5c3327aa1b09 address: 192.168.0.171 path : /srv/lstore/vm type : nfs =20 [RHEVM shell (connected)]# remove storageconnection d94d9341-6116-4b1a-94c5-5c3327aa1b09 =20 error: status: 404 reason: Not Found detail: Entity not found: null =20 [RHEVM shell (connected)]# show storageconnection d94d9341-6116-4b1a-94c5-5c3327aa1b09 =20 id : d94d9341-6116-4b1a-94c5-5c3327aa1b09 address: 192.168.0.171 path : /srv/lstore/vm type : nfs =20 okay=85 i use curl with DELETE =20 [root@rhevhst ~]# curl -X GET -H "Accept: application/xml" -u admin@internal:<pass> = https://192.168.0.170/api/storageconnections/d94d9341-6116-4b1a-94c5-5c332= 7aa1b09 --insecure <?xml version=3D"1.0" encoding=3D"UTF-8" standalone=3D"yes"?> <storage_connection href=3D"/api/storageconnections/d94d9341-6116-4b1a-94c5-5c3327aa1b09" id=3D"d94d9341-6116-4b1a-94c5-5c3327aa1b09"> <address>192.168.0.171</address> <type>nfs</type> <path>/srv/lstore/vm</path> </storage_connection> [root@rhevhst ~]# =20 [root@rhevhst ~]# curl -X DELETE -H "Accept: application/xml" -u admin@internal:<pass> = https://192.168.0.170/api/storageconnections/d94d9341-6116-4b1a-94c5-5c332= 7aa1b09 --insecure <?xml version=3D"1.0" encoding=3D"UTF-8" standalone=3D"yes"?><fault><reason>Operation = Failed</reason><detail>Entity not found: null</detail></fault> [root@rhevhst ~]# =20 how i can remove connection?! this is bug? =20 Artem =20 =20 _______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users =20

--Apple-Mail=_B333446E-2E45-4D06-87D5-FAC3DE9E9DBC--