After i start the libvirt on node 1 , the node can set to maintaince status, then everything is ok now. Is there any guide about how to update Ovirt engine and Ovirt node ? (I install them by rpm and iso) Last time i update my Ovirt engine by 'rpm -Uvh ' , but Ofer Schreiber told me to upgrade rpms using the engine-upgrade utility So how can i upgrade/update the node ? On 28 May, 2012, at 2:04 PM, Haim Ateya wrote:
----- Original Message -----
From: "T-Sinjon" <tscbj1989@gmail.com> To: "Haim Ateya" <hateya@redhat.com> Cc: "Shu Ming" <shuming@linux.vnet.ibm.com>, users@ovirt.org Sent: Monday, May 28, 2012 7:52:22 AM Subject: Re: [Users] SPM host in unknown status
1,As my first mail said : maintenance action cannot been done: Error: Cannot switch Host to Maintenance mode. Host still has running VMs on it and is in Non-Responsive state. yea, it didn't work since manual fence failed.
2,vdsm version on engine and node1 [root@ovirt-engine ~]# rpm -qa | grep vdsm vdsm-4.9.3.3-0.fc16.x86_64 vdsm-reg-4.9.3.3-0.fc16.noarch vdsm-cli-4.9.3.3-0.fc16.noarch vdsm-bootstrap-4.9.3.3-0.fc16.noarch
those rpms are quit old and doesn't contain the patch for the issue described in BZ#787594. fix was committed in 70104b31b54d4a49d2f117139f1ae874addcc643.
[root@ovirt-node-1 ~]# rpm -qa | grep vdsm vdsm-cli-4.9.3.2-0.fc16.noarch vdsm-4.9.3.2-0.fc16.x86_64 vdsm-reg-4.9.3.2-0.fc16.noarch
3, node1's libvirtd is not running ;
please try to start it manually and see what happens, does it fail to start ? check /var/log/libvirtd.log
node1 has enough space on it; the list of /var/run/vdsm
[root@ovirt-node-1 ~]# ls -lR /var/run/vdsm/ /var/run/vdsm/: total 12 -rw-r--r--. 1 vdsm kvm 40 May 28 04:48 lvm.env drwxr-xr-x. 2 vdsm kvm 40 May 28 02:43 pools -rw-r--r--. 1 vdsm kvm 5 May 28 02:43 respawn.pid -rw-rw-r--. 1 vdsm kvm 6 May 28 04:48 vdsmd.pid
/var/run/vdsm/pools: total 0
On 28 May, 2012, at 12:20 PM, Haim Ateya wrote:
After you run the manual fence operation, maintenance is essential as well (right click on host, hit it). As for your logs on node2; it seems that manual fence command faild due to secure error (old bug of mine actually, we thought it was resolved - will search for bz later), what version are you working with (vdsm)?
As for logs on node1; as you can see vdsm fails to communicate with libvirt service; there are several reasons, please provide directory listing of /var/run/vdsm, is libvirt service is running? Do you have enough space on node?
Haim
On May 28, 2012, at 6:34, T-Sinjon < tscbj1989@gmail.com > wrote:
node1 vdsm.log:
MainThread::INFO::2012-05-28 03:14:55,836::vdsm::76::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2012-05-28 03:14:55,836::vdsm::79::vds::(run) <_MainThread(MainThread, started 140246996211456)> MainThread::INFO::2012-05-28 03:14:55,836::vdsm::79::vds::(run) <Thread(libvirtEventLoop, started daemon 140246779500288)> MainThread::INFO::2012-05-28 03:14:55,912::vdsm::71::vds::(run) I am the actual vdsm 4.9-0 MainThread::ERROR::2012-05-28 03:14:56,106::vdsm::74::vds::(run) Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 72, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 40, in serve_clients cif = clientIF.clientIF(log) File "/usr/share/vdsm/clientIF.py", line 114, in __init__ File "/usr/share/vdsm/libvirtconnection.py", line 111, in get File "/usr/lib64/python2.7/site-packages/libvirt.py", line 102, in openAuth libvirtError: Failed to connect socket to '/var/run/libvirt/libvirt-sock': No such file or directory
MainThread::INFO::2012-05-28 03:14:56,106::vdsm::76::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2012-05-28 03:14:56,106::vdsm::79::vds::(run) <_MainThread(MainThread, started 140708160984832)> MainThread::INFO::2012-05-28 03:14:56,106::vdsm::79::vds::(run) <Thread(libvirtEventLoop, started daemon 140707944273664)>
node2 vdsm.log: (sorry for the large log)
Thread-56734::DEBUG::2012-05-28 03:15:40,507::task::588::TaskManager.Task::(_updateState) Task=`5374a489-ad78-464c-93ce-3184d12fbe5b`::moving from state init -> state preparing Thread-56734::INFO::2012-05-28 03:15:40,508::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56734::INFO::2012-05-28 03:15:40,509::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.0014009475708', 'lastCheck': 1338174931.256155, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00122499465942', 'lastCheck': 1338174938.066188, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00152397155762', 'lastCheck': 1338174936.886322, 'code': 0, 'valid': True}} Thread-56734::DEBUG::2012-05-28 03:15:40,509::task::1174::TaskManager.Task::(prepare) Task=`5374a489-ad78-464c-93ce-3184d12fbe5b`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.0014009475708', 'lastCheck': 1338174931.256155, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00122499465942', 'lastCheck': 1338174938.066188, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00152397155762', 'lastCheck': 1338174936.886322, 'code': 0, 'valid': True}} Thread-56734::DEBUG::2012-05-28 03:15:40,510::task::588::TaskManager.Task::(_updateState) Task=`5374a489-ad78-464c-93ce-3184d12fbe5b`::moving from state preparing -> state finished Thread-56734::DEBUG::2012-05-28 03:15:40,511::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56734::DEBUG::2012-05-28 03:15:40,511::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56734::DEBUG::2012-05-28 03:15:40,512::task::980::TaskManager.Task::(_decref) Task=`5374a489-ad78-464c-93ce-3184d12fbe5b`::ref 0 aborting False Thread-56736::DEBUG::2012-05-28 03:15:41,332::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56736::DEBUG::2012-05-28 03:15:41,333::task::588::TaskManager.Task::(_updateState) Task=`39c4b239-4f85-4fae-b7b3-348650268585`::moving from state init -> state preparing Thread-56736::INFO::2012-05-28 03:15:41,334::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56736::INFO::2012-05-28 03:15:41,335::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56736::DEBUG::2012-05-28 03:15:41,335::task::1174::TaskManager.Task::(prepare) Task=`39c4b239-4f85-4fae-b7b3-348650268585`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56736::DEBUG::2012-05-28 03:15:41,336::task::588::TaskManager.Task::(_updateState) Task=`39c4b239-4f85-4fae-b7b3-348650268585`::moving from state preparing -> state finished Thread-56736::DEBUG::2012-05-28 03:15:41,337::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56736::DEBUG::2012-05-28 03:15:41,337::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56736::DEBUG::2012-05-28 03:15:41,338::task::980::TaskManager.Task::(_decref) Task=`39c4b239-4f85-4fae-b7b3-348650268585`::ref 0 aborting False Thread-56737::DEBUG::2012-05-28 03:15:41,825::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56737::DEBUG::2012-05-28 03:15:41,826::task::588::TaskManager.Task::(_updateState) Task=`4b92f7f8-94a6-426b-b626-65aa488e3bf8`::moving from state init -> state preparing Thread-56737::INFO::2012-05-28 03:15:41,827::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56737::INFO::2012-05-28 03:15:41,828::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56737::DEBUG::2012-05-28 03:15:41,828::task::1174::TaskManager.Task::(prepare) Task=`4b92f7f8-94a6-426b-b626-65aa488e3bf8`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56737::DEBUG::2012-05-28 03:15:41,829::task::588::TaskManager.Task::(_updateState) Task=`4b92f7f8-94a6-426b-b626-65aa488e3bf8`::moving from state preparing -> state finished Thread-56737::DEBUG::2012-05-28 03:15:41,830::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56737::DEBUG::2012-05-28 03:15:41,830::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56737::DEBUG::2012-05-28 03:15:41,831::task::980::TaskManager.Task::(_decref) Task=`4b92f7f8-94a6-426b-b626-65aa488e3bf8`::ref 0 aborting False Thread-56738::DEBUG::2012-05-28 03:15:41,865::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56738::DEBUG::2012-05-28 03:15:41,866::task::588::TaskManager.Task::(_updateState) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::moving from state init -> state preparing Thread-56738::INFO::2012-05-28 03:15:41,867::logUtils::37::dispatcher::(wrapper) Run and protect: fenceSpmStorage(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', lastOwner=1, lastLver='17', options=None) Thread-56738::DEBUG::2012-05-28 03:15:41,868::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef`ReqID=`8281ad30-ca07-4de6-8903-244ad562c05f`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2633' at 'fenceSpmStorage' Thread-56738::DEBUG::2012-05-28 03:15:41,869::resourceManager::483::ResourceManager::(registerResource) Trying to register resource 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef' for lock type 'exclusive' Thread-56738::DEBUG::2012-05-28 03:15:41,870::resourceManager::525::ResourceManager::(registerResource) Resource 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef' is free. Now locking as 'exclusive' (1 active user) Thread-56738::DEBUG::2012-05-28 03:15:41,871::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef`ReqID=`8281ad30-ca07-4de6-8903-244ad562c05f`::Granted request Thread-56738::DEBUG::2012-05-28 03:15:41,871::task::819::TaskManager.Task::(resourceAcquired) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::_resourcesAcquired: Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef (exclusive) Thread-56738::DEBUG::2012-05-28 03:15:41,871::task::980::TaskManager.Task::(_decref) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::ref 1 aborting False Thread-56738::ERROR::2012-05-28 03:15:41,872::task::855::TaskManager.Task::(_setError) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 863, in _run File "/usr/share/vdsm/logUtils.py", line 38, in wrapper File "/usr/share/vdsm/storage/hsm.py", line 2634, in fenceSpmStorage File "/usr/share/vdsm/storage/sp.py", line 150, in forceFreeSpm File "/usr/share/vdsm/storage/securable.py", line 78, in wrapper SecureError Thread-56738::DEBUG::2012-05-28 03:15:41,872::task::874::TaskManager.Task::(_run) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::Task._run: 8ee680b3-39b8-49ef-b756-8d374f34d97e ('524a7003-edec-4f52-a38e-b15cadfbe3ef', 1, '17') {} failed - stopping task Thread-56738::DEBUG::2012-05-28 03:15:41,872::task::1201::TaskManager.Task::(stop) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::stopping in state preparing (force False) Thread-56738::DEBUG::2012-05-28 03:15:41,872::task::980::TaskManager.Task::(_decref) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::ref 1 aborting True Thread-56738::INFO::2012-05-28 03:15:41,873::task::1159::TaskManager.Task::(prepare) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::aborting: Task is aborted: '' - code 100 Thread-56738::DEBUG::2012-05-28 03:15:41,873::task::1164::TaskManager.Task::(prepare) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::Prepare: aborted: Thread-56738::DEBUG::2012-05-28 03:15:41,873::task::980::TaskManager.Task::(_decref) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::ref 0 aborting True Thread-56738::DEBUG::2012-05-28 03:15:41,873::task::915::TaskManager.Task::(_doAbort) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::Task._doAbort: force False Thread-56738::DEBUG::2012-05-28 03:15:41,873::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56738::DEBUG::2012-05-28 03:15:41,874::task::588::TaskManager.Task::(_updateState) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::moving from state preparing -> state aborting Thread-56738::DEBUG::2012-05-28 03:15:41,874::task::537::TaskManager.Task::(__state_aborting) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::_aborting: recover policy none Thread-56738::DEBUG::2012-05-28 03:15:41,874::task::588::TaskManager.Task::(_updateState) Task=`8ee680b3-39b8-49ef-b756-8d374f34d97e`::moving from state aborting -> state failed Thread-56738::DEBUG::2012-05-28 03:15:41,874::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef': < ResourceRef 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef', isValid: 'True' obj: 'None'>} Thread-56738::DEBUG::2012-05-28 03:15:41,874::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56738::DEBUG::2012-05-28 03:15:41,875::resourceManager::535::ResourceManager::(releaseResource) Trying to release resource 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef' Thread-56738::DEBUG::2012-05-28 03:15:41,875::resourceManager::550::ResourceManager::(releaseResource) Released resource 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef' (0 active users) Thread-56738::DEBUG::2012-05-28 03:15:41,875::resourceManager::555::ResourceManager::(releaseResource) Resource 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef' is free, finding out if anyone is waiting for it. Thread-56738::DEBUG::2012-05-28 03:15:41,875::resourceManager::562::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.524a7003-edec-4f52-a38e-b15cadfbe3ef', Clearing records. Thread-56738::ERROR::2012-05-28 03:15:41,876::dispatcher::93::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 85, in run File "/usr/share/vdsm/storage/task.py", line 1166, in prepare SecureError Thread-26::DEBUG::2012-05-28 03:15:48,077::persistentDict::216::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=VMDomain', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1', 'POOL_DESCRIPTION=BLC', 'POOL_DOMAINS=fce72110-71ae-46be-8811-2fbeaa001ed2:Active,5e2ac537-6a73-4faf-8379-68f3ff26a75d:Active,6d931187-2c83-4c33-8693-ca2570f7c136:Active', 'POOL_SPM_ID=1', 'POOL_SPM_LVER=17', 'POOL_UUID=524a7003-edec-4f52-a38e-b15cadfbe3ef', 'REMOTE_PATH=xxx.xxx.xxx.xxx:/export/data/Ovirt-Domain/vmdomain', 'ROLE=Master', 'SDUUID=5e2ac537-6a73-4faf-8379-68f3ff26a75d', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=a17bf026e76daae1ff911bdbbcfa13b700c93d7e'] Thread-56743::DEBUG::2012-05-28 03:15:50,717::task::588::TaskManager.Task::(_updateState) Task=`e58fd0e1-d2ae-41ba-9906-473933b98bb5`::moving from state init -> state preparing Thread-56743::INFO::2012-05-28 03:15:50,718::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56743::INFO::2012-05-28 03:15:50,719::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00115013122559', 'lastCheck': 1338174941.265202, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00145602226257', 'lastCheck': 1338174948.079344, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00129413604736', 'lastCheck': 1338174946.895659, 'code': 0, 'valid': True}} Thread-56743::DEBUG::2012-05-28 03:15:50,720::task::1174::TaskManager.Task::(prepare) Task=`e58fd0e1-d2ae-41ba-9906-473933b98bb5`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00115013122559', 'lastCheck': 1338174941.265202, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00145602226257', 'lastCheck': 1338174948.079344, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00129413604736', 'lastCheck': 1338174946.895659, 'code': 0, 'valid': True}} Thread-56743::DEBUG::2012-05-28 03:15:50,721::task::588::TaskManager.Task::(_updateState) Task=`e58fd0e1-d2ae-41ba-9906-473933b98bb5`::moving from state preparing -> state finished Thread-56743::DEBUG::2012-05-28 03:15:50,722::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56743::DEBUG::2012-05-28 03:15:50,722::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56743::DEBUG::2012-05-28 03:15:50,723::task::980::TaskManager.Task::(_decref) Task=`e58fd0e1-d2ae-41ba-9906-473933b98bb5`::ref 0 aborting False Thread-56745::DEBUG::2012-05-28 03:15:51,379::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56745::DEBUG::2012-05-28 03:15:51,380::task::588::TaskManager.Task::(_updateState) Task=`38728832-84c0-45d6-9577-277bc00f4971`::moving from state init -> state preparing Thread-56745::INFO::2012-05-28 03:15:51,381::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56745::INFO::2012-05-28 03:15:51,382::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56745::DEBUG::2012-05-28 03:15:51,383::task::1174::TaskManager.Task::(prepare) Task=`38728832-84c0-45d6-9577-277bc00f4971`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56745::DEBUG::2012-05-28 03:15:51,383::task::588::TaskManager.Task::(_updateState) Task=`38728832-84c0-45d6-9577-277bc00f4971`::moving from state preparing -> state finished Thread-56745::DEBUG::2012-05-28 03:15:51,384::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56745::DEBUG::2012-05-28 03:15:51,385::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56745::DEBUG::2012-05-28 03:15:51,385::task::980::TaskManager.Task::(_decref) Task=`38728832-84c0-45d6-9577-277bc00f4971`::ref 0 aborting False Thread-56750::DEBUG::2012-05-28 03:16:00,916::task::588::TaskManager.Task::(_updateState) Task=`0b24e93f-a073-464b-968b-197658c4ca83`::moving from state init -> state preparing Thread-56750::INFO::2012-05-28 03:16:00,917::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56750::INFO::2012-05-28 03:16:00,918::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.0014750957489', 'lastCheck': 1338174951.276538, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00123810768127', 'lastCheck': 1338174958.08727, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00193691253662', 'lastCheck': 1338174956.908427, 'code': 0, 'valid': True}} Thread-56750::DEBUG::2012-05-28 03:16:00,919::task::1174::TaskManager.Task::(prepare) Task=`0b24e93f-a073-464b-968b-197658c4ca83`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.0014750957489', 'lastCheck': 1338174951.276538, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00123810768127', 'lastCheck': 1338174958.08727, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00193691253662', 'lastCheck': 1338174956.908427, 'code': 0, 'valid': True}} Thread-56750::DEBUG::2012-05-28 03:16:00,920::task::588::TaskManager.Task::(_updateState) Task=`0b24e93f-a073-464b-968b-197658c4ca83`::moving from state preparing -> state finished Thread-56750::DEBUG::2012-05-28 03:16:00,921::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56750::DEBUG::2012-05-28 03:16:00,921::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56750::DEBUG::2012-05-28 03:16:00,922::task::980::TaskManager.Task::(_decref) Task=`0b24e93f-a073-464b-968b-197658c4ca83`::ref 0 aborting False Thread-56752::DEBUG::2012-05-28 03:16:01,429::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56752::DEBUG::2012-05-28 03:16:01,430::task::588::TaskManager.Task::(_updateState) Task=`3fb01b85-0d37-4eea-935f-e82f1e2ff76b`::moving from state init -> state preparing Thread-56752::INFO::2012-05-28 03:16:01,431::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56752::INFO::2012-05-28 03:16:01,432::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56752::DEBUG::2012-05-28 03:16:01,433::task::1174::TaskManager.Task::(prepare) Task=`3fb01b85-0d37-4eea-935f-e82f1e2ff76b`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56752::DEBUG::2012-05-28 03:16:01,433::task::588::TaskManager.Task::(_updateState) Task=`3fb01b85-0d37-4eea-935f-e82f1e2ff76b`::moving from state preparing -> state finished Thread-56752::DEBUG::2012-05-28 03:16:01,434::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56752::DEBUG::2012-05-28 03:16:01,435::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56752::DEBUG::2012-05-28 03:16:01,435::task::980::TaskManager.Task::(_decref) Task=`3fb01b85-0d37-4eea-935f-e82f1e2ff76b`::ref 0 aborting False Thread-56757::DEBUG::2012-05-28 03:16:11,132::task::588::TaskManager.Task::(_updateState) Task=`f82a5430-0985-442f-8d58-c21bb1102190`::moving from state init -> state preparing Thread-56757::INFO::2012-05-28 03:16:11,133::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56757::INFO::2012-05-28 03:16:11,134::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00143098831177', 'lastCheck': 1338174961.286303, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00148105621338', 'lastCheck': 1338174968.096825, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00177407264709', 'lastCheck': 1338174966.91743, 'code': 0, 'valid': True}} Thread-56757::DEBUG::2012-05-28 03:16:11,134::task::1174::TaskManager.Task::(prepare) Task=`f82a5430-0985-442f-8d58-c21bb1102190`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00143098831177', 'lastCheck': 1338174961.286303, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00148105621338', 'lastCheck': 1338174968.096825, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00177407264709', 'lastCheck': 1338174966.91743, 'code': 0, 'valid': True}} Thread-56757::DEBUG::2012-05-28 03:16:11,135::task::588::TaskManager.Task::(_updateState) Task=`f82a5430-0985-442f-8d58-c21bb1102190`::moving from state preparing -> state finished Thread-56757::DEBUG::2012-05-28 03:16:11,136::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56757::DEBUG::2012-05-28 03:16:11,137::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56757::DEBUG::2012-05-28 03:16:11,137::task::980::TaskManager.Task::(_decref) Task=`f82a5430-0985-442f-8d58-c21bb1102190`::ref 0 aborting False Thread-56759::DEBUG::2012-05-28 03:16:11,493::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56759::DEBUG::2012-05-28 03:16:11,495::task::588::TaskManager.Task::(_updateState) Task=`b5efb22f-5d5c-4780-9090-1d220fc1842f`::moving from state init -> state preparing Thread-56759::INFO::2012-05-28 03:16:11,495::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56759::INFO::2012-05-28 03:16:11,496::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56759::DEBUG::2012-05-28 03:16:11,497::task::1174::TaskManager.Task::(prepare) Task=`b5efb22f-5d5c-4780-9090-1d220fc1842f`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56759::DEBUG::2012-05-28 03:16:11,498::task::588::TaskManager.Task::(_updateState) Task=`b5efb22f-5d5c-4780-9090-1d220fc1842f`::moving from state preparing -> state finished Thread-56759::DEBUG::2012-05-28 03:16:11,498::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56759::DEBUG::2012-05-28 03:16:11,499::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56759::DEBUG::2012-05-28 03:16:11,500::task::980::TaskManager.Task::(_decref) Task=`b5efb22f-5d5c-4780-9090-1d220fc1842f`::ref 0 aborting False Thread-56764::DEBUG::2012-05-28 03:16:21,323::task::588::TaskManager.Task::(_updateState) Task=`20c22deb-791f-4832-a37e-54a794d7f5eb`::moving from state init -> state preparing Thread-56764::INFO::2012-05-28 03:16:21,324::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56764::INFO::2012-05-28 03:16:21,325::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00120186805725', 'lastCheck': 1338174981.305562, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00149893760681', 'lastCheck': 1338174978.106855, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00185894966125', 'lastCheck': 1338174976.929951, 'code': 0, 'valid': True}} Thread-56764::DEBUG::2012-05-28 03:16:21,325::task::1174::TaskManager.Task::(prepare) Task=`20c22deb-791f-4832-a37e-54a794d7f5eb`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00120186805725', 'lastCheck': 1338174981.305562, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00149893760681', 'lastCheck': 1338174978.106855, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00185894966125', 'lastCheck': 1338174976.929951, 'code': 0, 'valid': True}} Thread-56764::DEBUG::2012-05-28 03:16:21,326::task::588::TaskManager.Task::(_updateState) Task=`20c22deb-791f-4832-a37e-54a794d7f5eb`::moving from state preparing -> state finished Thread-56764::DEBUG::2012-05-28 03:16:21,327::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56764::DEBUG::2012-05-28 03:16:21,328::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56764::DEBUG::2012-05-28 03:16:21,328::task::980::TaskManager.Task::(_decref) Task=`20c22deb-791f-4832-a37e-54a794d7f5eb`::ref 0 aborting False Thread-56766::DEBUG::2012-05-28 03:16:21,542::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56766::DEBUG::2012-05-28 03:16:21,543::task::588::TaskManager.Task::(_updateState) Task=`0586a277-8536-4e37-91ed-598b47286c2f`::moving from state init -> state preparing Thread-56766::INFO::2012-05-28 03:16:21,544::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56766::INFO::2012-05-28 03:16:21,545::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56766::DEBUG::2012-05-28 03:16:21,545::task::1174::TaskManager.Task::(prepare) Task=`0586a277-8536-4e37-91ed-598b47286c2f`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56766::DEBUG::2012-05-28 03:16:21,546::task::588::TaskManager.Task::(_updateState) Task=`0586a277-8536-4e37-91ed-598b47286c2f`::moving from state preparing -> state finished Thread-56766::DEBUG::2012-05-28 03:16:21,547::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56766::DEBUG::2012-05-28 03:16:21,547::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56766::DEBUG::2012-05-28 03:16:21,548::task::980::TaskManager.Task::(_decref) Task=`0586a277-8536-4e37-91ed-598b47286c2f`::ref 0 aborting False Thread-56771::DEBUG::2012-05-28 03:16:31,521::task::588::TaskManager.Task::(_updateState) Task=`5717ab22-77fc-4b9e-9ef1-fc37d9b23b60`::moving from state init -> state preparing Thread-56771::INFO::2012-05-28 03:16:31,522::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56771::INFO::2012-05-28 03:16:31,523::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00146007537842', 'lastCheck': 1338174991.315921, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00130796432495', 'lastCheck': 1338174988.116432, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00182700157166', 'lastCheck': 1338174986.942698, 'code': 0, 'valid': True}} Thread-56771::DEBUG::2012-05-28 03:16:31,524::task::1174::TaskManager.Task::(prepare) Task=`5717ab22-77fc-4b9e-9ef1-fc37d9b23b60`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00146007537842', 'lastCheck': 1338174991.315921, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00130796432495', 'lastCheck': 1338174988.116432, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00182700157166', 'lastCheck': 1338174986.942698, 'code': 0, 'valid': True}} Thread-56771::DEBUG::2012-05-28 03:16:31,524::task::588::TaskManager.Task::(_updateState) Task=`5717ab22-77fc-4b9e-9ef1-fc37d9b23b60`::moving from state preparing -> state finished Thread-56771::DEBUG::2012-05-28 03:16:31,525::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56771::DEBUG::2012-05-28 03:16:31,526::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56771::DEBUG::2012-05-28 03:16:31,526::task::980::TaskManager.Task::(_decref) Task=`5717ab22-77fc-4b9e-9ef1-fc37d9b23b60`::ref 0 aborting False Thread-56773::DEBUG::2012-05-28 03:16:31,592::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56773::DEBUG::2012-05-28 03:16:31,593::task::588::TaskManager.Task::(_updateState) Task=`752dbe30-c5e5-45a3-b7e0-81a19564ec4f`::moving from state init -> state preparing Thread-56773::INFO::2012-05-28 03:16:31,594::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56773::INFO::2012-05-28 03:16:31,595::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56773::DEBUG::2012-05-28 03:16:31,596::task::1174::TaskManager.Task::(prepare) Task=`752dbe30-c5e5-45a3-b7e0-81a19564ec4f`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56773::DEBUG::2012-05-28 03:16:31,596::task::588::TaskManager.Task::(_updateState) Task=`752dbe30-c5e5-45a3-b7e0-81a19564ec4f`::moving from state preparing -> state finished Thread-56773::DEBUG::2012-05-28 03:16:31,597::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56773::DEBUG::2012-05-28 03:16:31,598::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56773::DEBUG::2012-05-28 03:16:31,598::task::980::TaskManager.Task::(_decref) Task=`752dbe30-c5e5-45a3-b7e0-81a19564ec4f`::ref 0 aborting False Thread-56778::DEBUG::2012-05-28 03:16:41,641::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56778::DEBUG::2012-05-28 03:16:41,643::task::588::TaskManager.Task::(_updateState) Task=`5b9dcf88-4aaf-4649-8895-4c1d9bfcc2db`::moving from state init -> state preparing Thread-56778::INFO::2012-05-28 03:16:41,643::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56778::INFO::2012-05-28 03:16:41,644::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56778::DEBUG::2012-05-28 03:16:41,645::task::1174::TaskManager.Task::(prepare) Task=`5b9dcf88-4aaf-4649-8895-4c1d9bfcc2db`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56778::DEBUG::2012-05-28 03:16:41,646::task::588::TaskManager.Task::(_updateState) Task=`5b9dcf88-4aaf-4649-8895-4c1d9bfcc2db`::moving from state preparing -> state finished Thread-56778::DEBUG::2012-05-28 03:16:41,646::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56778::DEBUG::2012-05-28 03:16:41,647::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56778::DEBUG::2012-05-28 03:16:41,648::task::980::TaskManager.Task::(_decref) Task=`5b9dcf88-4aaf-4649-8895-4c1d9bfcc2db`::ref 0 aborting False Thread-56779::DEBUG::2012-05-28 03:16:41,731::task::588::TaskManager.Task::(_updateState) Task=`f3855ff9-49dc-4da1-ab42-3f717ca2242f`::moving from state init -> state preparing Thread-56779::INFO::2012-05-28 03:16:41,732::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56779::INFO::2012-05-28 03:16:41,733::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00130009651184', 'lastCheck': 1338175001.325553, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0015070438385', 'lastCheck': 1338174998.126787, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00195598602295', 'lastCheck': 1338174996.955508, 'code': 0, 'valid': True}} Thread-56779::DEBUG::2012-05-28 03:16:41,734::task::1174::TaskManager.Task::(prepare) Task=`f3855ff9-49dc-4da1-ab42-3f717ca2242f`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00130009651184', 'lastCheck': 1338175001.325553, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0015070438385', 'lastCheck': 1338174998.126787, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00195598602295', 'lastCheck': 1338174996.955508, 'code': 0, 'valid': True}} Thread-56779::DEBUG::2012-05-28 03:16:41,735::task::588::TaskManager.Task::(_updateState) Task=`f3855ff9-49dc-4da1-ab42-3f717ca2242f`::moving from state preparing -> state finished Thread-56779::DEBUG::2012-05-28 03:16:41,736::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56779::DEBUG::2012-05-28 03:16:41,736::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56779::DEBUG::2012-05-28 03:16:41,737::task::980::TaskManager.Task::(_decref) Task=`f3855ff9-49dc-4da1-ab42-3f717ca2242f`::ref 0 aborting False Thread-56785::DEBUG::2012-05-28 03:16:51,691::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56785::DEBUG::2012-05-28 03:16:51,693::task::588::TaskManager.Task::(_updateState) Task=`f7791e70-ed9d-438f-b90a-6de44ccc77df`::moving from state init -> state preparing Thread-56785::INFO::2012-05-28 03:16:51,693::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56785::INFO::2012-05-28 03:16:51,694::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56785::DEBUG::2012-05-28 03:16:51,695::task::1174::TaskManager.Task::(prepare) Task=`f7791e70-ed9d-438f-b90a-6de44ccc77df`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56785::DEBUG::2012-05-28 03:16:51,696::task::588::TaskManager.Task::(_updateState) Task=`f7791e70-ed9d-438f-b90a-6de44ccc77df`::moving from state preparing -> state finished Thread-56785::DEBUG::2012-05-28 03:16:51,696::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56785::DEBUG::2012-05-28 03:16:51,697::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56785::DEBUG::2012-05-28 03:16:51,698::task::980::TaskManager.Task::(_decref) Task=`f7791e70-ed9d-438f-b90a-6de44ccc77df`::ref 0 aborting False Thread-56786::DEBUG::2012-05-28 03:16:51,943::task::588::TaskManager.Task::(_updateState) Task=`ae37d8af-31d5-4248-8109-0c5edc0eeb72`::moving from state init -> state preparing Thread-56786::INFO::2012-05-28 03:16:51,943::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56786::INFO::2012-05-28 03:16:51,944::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00257992744446', 'lastCheck': 1338175011.337062, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00142002105713', 'lastCheck': 1338175008.138333, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0016028881073', 'lastCheck': 1338175006.965758, 'code': 0, 'valid': True}} Thread-56786::DEBUG::2012-05-28 03:16:51,945::task::1174::TaskManager.Task::(prepare) Task=`ae37d8af-31d5-4248-8109-0c5edc0eeb72`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00257992744446', 'lastCheck': 1338175011.337062, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00142002105713', 'lastCheck': 1338175008.138333, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0016028881073', 'lastCheck': 1338175006.965758, 'code': 0, 'valid': True}} Thread-56786::DEBUG::2012-05-28 03:16:51,946::task::588::TaskManager.Task::(_updateState) Task=`ae37d8af-31d5-4248-8109-0c5edc0eeb72`::moving from state preparing -> state finished Thread-56786::DEBUG::2012-05-28 03:16:51,947::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56786::DEBUG::2012-05-28 03:16:51,947::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56786::DEBUG::2012-05-28 03:16:51,948::task::980::TaskManager.Task::(_decref) Task=`ae37d8af-31d5-4248-8109-0c5edc0eeb72`::ref 0 aborting False Thread-56792::DEBUG::2012-05-28 03:17:01,741::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56792::DEBUG::2012-05-28 03:17:01,742::task::588::TaskManager.Task::(_updateState) Task=`2efcfeb7-a6c1-432f-b09e-3409520a5f89`::moving from state init -> state preparing Thread-56792::INFO::2012-05-28 03:17:01,743::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56792::INFO::2012-05-28 03:17:01,744::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56792::DEBUG::2012-05-28 03:17:01,744::task::1174::TaskManager.Task::(prepare) Task=`2efcfeb7-a6c1-432f-b09e-3409520a5f89`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56792::DEBUG::2012-05-28 03:17:01,745::task::588::TaskManager.Task::(_updateState) Task=`2efcfeb7-a6c1-432f-b09e-3409520a5f89`::moving from state preparing -> state finished Thread-56792::DEBUG::2012-05-28 03:17:01,746::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56792::DEBUG::2012-05-28 03:17:01,746::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56792::DEBUG::2012-05-28 03:17:01,747::task::980::TaskManager.Task::(_decref) Task=`2efcfeb7-a6c1-432f-b09e-3409520a5f89`::ref 0 aborting False Thread-56793::DEBUG::2012-05-28 03:17:02,137::task::588::TaskManager.Task::(_updateState) Task=`513c7e7e-7a78-4fc6-a497-d4810bd35c08`::moving from state init -> state preparing Thread-56793::INFO::2012-05-28 03:17:02,138::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56793::INFO::2012-05-28 03:17:02,139::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00146794319153', 'lastCheck': 1338175021.346104, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00128602981567', 'lastCheck': 1338175018.146864, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00149917602539', 'lastCheck': 1338175016.975937, 'code': 0, 'valid': True}} Thread-56793::DEBUG::2012-05-28 03:17:02,140::task::1174::TaskManager.Task::(prepare) Task=`513c7e7e-7a78-4fc6-a497-d4810bd35c08`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00146794319153', 'lastCheck': 1338175021.346104, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00128602981567', 'lastCheck': 1338175018.146864, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00149917602539', 'lastCheck': 1338175016.975937, 'code': 0, 'valid': True}} Thread-56793::DEBUG::2012-05-28 03:17:02,141::task::588::TaskManager.Task::(_updateState) Task=`513c7e7e-7a78-4fc6-a497-d4810bd35c08`::moving from state preparing -> state finished Thread-56793::DEBUG::2012-05-28 03:17:02,141::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56793::DEBUG::2012-05-28 03:17:02,142::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56793::DEBUG::2012-05-28 03:17:02,143::task::980::TaskManager.Task::(_decref) Task=`513c7e7e-7a78-4fc6-a497-d4810bd35c08`::ref 0 aborting False Thread-56799::DEBUG::2012-05-28 03:17:11,789::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56799::DEBUG::2012-05-28 03:17:11,790::task::588::TaskManager.Task::(_updateState) Task=`f4493a0e-87ed-49df-bb50-ff78c781c686`::moving from state init -> state preparing Thread-56799::INFO::2012-05-28 03:17:11,791::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56799::INFO::2012-05-28 03:17:11,792::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56799::DEBUG::2012-05-28 03:17:11,792::task::1174::TaskManager.Task::(prepare) Task=`f4493a0e-87ed-49df-bb50-ff78c781c686`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56799::DEBUG::2012-05-28 03:17:11,793::task::588::TaskManager.Task::(_updateState) Task=`f4493a0e-87ed-49df-bb50-ff78c781c686`::moving from state preparing -> state finished Thread-56799::DEBUG::2012-05-28 03:17:11,794::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56799::DEBUG::2012-05-28 03:17:11,794::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56799::DEBUG::2012-05-28 03:17:11,795::task::980::TaskManager.Task::(_decref) Task=`f4493a0e-87ed-49df-bb50-ff78c781c686`::ref 0 aborting False Thread-56800::DEBUG::2012-05-28 03:17:12,334::task::588::TaskManager.Task::(_updateState) Task=`1ea724d6-c05e-46f5-bd1c-dab69d7dd1dc`::moving from state init -> state preparing Thread-56800::INFO::2012-05-28 03:17:12,334::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56800::INFO::2012-05-28 03:17:12,335::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00105905532837', 'lastCheck': 1338175031.355215, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00141787528992', 'lastCheck': 1338175028.156488, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00145602226257', 'lastCheck': 1338175026.986184, 'code': 0, 'valid': True}} Thread-56800::DEBUG::2012-05-28 03:17:12,336::task::1174::TaskManager.Task::(prepare) Task=`1ea724d6-c05e-46f5-bd1c-dab69d7dd1dc`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00105905532837', 'lastCheck': 1338175031.355215, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00141787528992', 'lastCheck': 1338175028.156488, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00145602226257', 'lastCheck': 1338175026.986184, 'code': 0, 'valid': True}} Thread-56800::DEBUG::2012-05-28 03:17:12,337::task::588::TaskManager.Task::(_updateState) Task=`1ea724d6-c05e-46f5-bd1c-dab69d7dd1dc`::moving from state preparing -> state finished Thread-56800::DEBUG::2012-05-28 03:17:12,338::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56800::DEBUG::2012-05-28 03:17:12,338::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56800::DEBUG::2012-05-28 03:17:12,339::task::980::TaskManager.Task::(_decref) Task=`1ea724d6-c05e-46f5-bd1c-dab69d7dd1dc`::ref 0 aborting False Thread-56806::DEBUG::2012-05-28 03:17:21,831::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56806::DEBUG::2012-05-28 03:17:21,832::task::588::TaskManager.Task::(_updateState) Task=`06654530-d2e3-4dec-a811-10bd4b4e7c70`::moving from state init -> state preparing Thread-56806::INFO::2012-05-28 03:17:21,833::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56806::INFO::2012-05-28 03:17:21,834::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56806::DEBUG::2012-05-28 03:17:21,835::task::1174::TaskManager.Task::(prepare) Task=`06654530-d2e3-4dec-a811-10bd4b4e7c70`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56806::DEBUG::2012-05-28 03:17:21,835::task::588::TaskManager.Task::(_updateState) Task=`06654530-d2e3-4dec-a811-10bd4b4e7c70`::moving from state preparing -> state finished Thread-56806::DEBUG::2012-05-28 03:17:21,836::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56806::DEBUG::2012-05-28 03:17:21,836::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56806::DEBUG::2012-05-28 03:17:21,837::task::980::TaskManager.Task::(_decref) Task=`06654530-d2e3-4dec-a811-10bd4b4e7c70`::ref 0 aborting False Thread-56807::DEBUG::2012-05-28 03:17:22,541::task::588::TaskManager.Task::(_updateState) Task=`49132eb7-1f0c-4e1a-bb1a-719e8687e3e5`::moving from state init -> state preparing Thread-56807::INFO::2012-05-28 03:17:22,542::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56807::INFO::2012-05-28 03:17:22,543::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00123596191406', 'lastCheck': 1338175041.36586, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00138688087463', 'lastCheck': 1338175038.1667, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00125789642334', 'lastCheck': 1338175036.996167, 'code': 0, 'valid': True}} Thread-56807::DEBUG::2012-05-28 03:17:22,544::task::1174::TaskManager.Task::(prepare) Task=`49132eb7-1f0c-4e1a-bb1a-719e8687e3e5`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00123596191406', 'lastCheck': 1338175041.36586, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00138688087463', 'lastCheck': 1338175038.1667, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00125789642334', 'lastCheck': 1338175036.996167, 'code': 0, 'valid': True}} Thread-56807::DEBUG::2012-05-28 03:17:22,545::task::588::TaskManager.Task::(_updateState) Task=`49132eb7-1f0c-4e1a-bb1a-719e8687e3e5`::moving from state preparing -> state finished Thread-56807::DEBUG::2012-05-28 03:17:22,545::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56807::DEBUG::2012-05-28 03:17:22,546::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56807::DEBUG::2012-05-28 03:17:22,547::task::980::TaskManager.Task::(_decref) Task=`49132eb7-1f0c-4e1a-bb1a-719e8687e3e5`::ref 0 aborting False Thread-56813::DEBUG::2012-05-28 03:17:31,886::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56813::DEBUG::2012-05-28 03:17:31,887::task::588::TaskManager.Task::(_updateState) Task=`656dcbf2-61d2-41c8-b13b-246fc3f42320`::moving from state init -> state preparing Thread-56813::INFO::2012-05-28 03:17:31,888::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56813::INFO::2012-05-28 03:17:31,889::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56813::DEBUG::2012-05-28 03:17:31,889::task::1174::TaskManager.Task::(prepare) Task=`656dcbf2-61d2-41c8-b13b-246fc3f42320`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56813::DEBUG::2012-05-28 03:17:31,890::task::588::TaskManager.Task::(_updateState) Task=`656dcbf2-61d2-41c8-b13b-246fc3f42320`::moving from state preparing -> state finished Thread-56813::DEBUG::2012-05-28 03:17:31,891::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56813::DEBUG::2012-05-28 03:17:31,891::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56813::DEBUG::2012-05-28 03:17:31,892::task::980::TaskManager.Task::(_decref) Task=`656dcbf2-61d2-41c8-b13b-246fc3f42320`::ref 0 aborting False Thread-56814::DEBUG::2012-05-28 03:17:32,738::task::588::TaskManager.Task::(_updateState) Task=`53ace160-1b3c-4a73-9f0c-7f65e79b7956`::moving from state init -> state preparing Thread-56814::INFO::2012-05-28 03:17:32,739::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56814::INFO::2012-05-28 03:17:32,740::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141310691833', 'lastCheck': 1338175051.375892, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00151896476746', 'lastCheck': 1338175048.176782, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00130605697632', 'lastCheck': 1338175047.005668, 'code': 0, 'valid': True}} Thread-56814::DEBUG::2012-05-28 03:17:32,741::task::1174::TaskManager.Task::(prepare) Task=`53ace160-1b3c-4a73-9f0c-7f65e79b7956`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141310691833', 'lastCheck': 1338175051.375892, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00151896476746', 'lastCheck': 1338175048.176782, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00130605697632', 'lastCheck': 1338175047.005668, 'code': 0, 'valid': True}} Thread-56814::DEBUG::2012-05-28 03:17:32,742::task::588::TaskManager.Task::(_updateState) Task=`53ace160-1b3c-4a73-9f0c-7f65e79b7956`::moving from state preparing -> state finished Thread-56814::DEBUG::2012-05-28 03:17:32,742::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56814::DEBUG::2012-05-28 03:17:32,743::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56814::DEBUG::2012-05-28 03:17:32,743::task::980::TaskManager.Task::(_decref) Task=`53ace160-1b3c-4a73-9f0c-7f65e79b7956`::ref 0 aborting False Thread-56820::DEBUG::2012-05-28 03:17:41,934::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56820::DEBUG::2012-05-28 03:17:41,936::task::588::TaskManager.Task::(_updateState) Task=`f269aaa5-ae89-40f3-a3d9-6eeba3363fff`::moving from state init -> state preparing Thread-56820::INFO::2012-05-28 03:17:41,936::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56820::INFO::2012-05-28 03:17:41,937::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56820::DEBUG::2012-05-28 03:17:41,938::task::1174::TaskManager.Task::(prepare) Task=`f269aaa5-ae89-40f3-a3d9-6eeba3363fff`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56820::DEBUG::2012-05-28 03:17:41,939::task::588::TaskManager.Task::(_updateState) Task=`f269aaa5-ae89-40f3-a3d9-6eeba3363fff`::moving from state preparing -> state finished Thread-56820::DEBUG::2012-05-28 03:17:41,939::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56820::DEBUG::2012-05-28 03:17:41,940::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56820::DEBUG::2012-05-28 03:17:41,941::task::980::TaskManager.Task::(_decref) Task=`f269aaa5-ae89-40f3-a3d9-6eeba3363fff`::ref 0 aborting False Thread-56821::DEBUG::2012-05-28 03:17:42,936::task::588::TaskManager.Task::(_updateState) Task=`48656e47-318b-431c-9a65-3497cf116647`::moving from state init -> state preparing Thread-56821::INFO::2012-05-28 03:17:42,937::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56821::INFO::2012-05-28 03:17:42,938::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00127100944519', 'lastCheck': 1338175061.385365, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00120496749878', 'lastCheck': 1338175058.186244, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0014979839325', 'lastCheck': 1338175057.016019, 'code': 0, 'valid': True}} Thread-56821::DEBUG::2012-05-28 03:17:42,939::task::1174::TaskManager.Task::(prepare) Task=`48656e47-318b-431c-9a65-3497cf116647`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00127100944519', 'lastCheck': 1338175061.385365, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00120496749878', 'lastCheck': 1338175058.186244, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0014979839325', 'lastCheck': 1338175057.016019, 'code': 0, 'valid': True}} Thread-56821::DEBUG::2012-05-28 03:17:42,940::task::588::TaskManager.Task::(_updateState) Task=`48656e47-318b-431c-9a65-3497cf116647`::moving from state preparing -> state finished Thread-56821::DEBUG::2012-05-28 03:17:42,940::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56821::DEBUG::2012-05-28 03:17:42,941::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56821::DEBUG::2012-05-28 03:17:42,942::task::980::TaskManager.Task::(_decref) Task=`48656e47-318b-431c-9a65-3497cf116647`::ref 0 aborting False Thread-56827::DEBUG::2012-05-28 03:17:51,988::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56827::DEBUG::2012-05-28 03:17:51,989::task::588::TaskManager.Task::(_updateState) Task=`c7ebbcac-9438-40b0-997c-27bdbda50bdb`::moving from state init -> state preparing Thread-56827::INFO::2012-05-28 03:17:51,990::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56827::INFO::2012-05-28 03:17:51,991::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56827::DEBUG::2012-05-28 03:17:51,992::task::1174::TaskManager.Task::(prepare) Task=`c7ebbcac-9438-40b0-997c-27bdbda50bdb`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56827::DEBUG::2012-05-28 03:17:51,992::task::588::TaskManager.Task::(_updateState) Task=`c7ebbcac-9438-40b0-997c-27bdbda50bdb`::moving from state preparing -> state finished Thread-56827::DEBUG::2012-05-28 03:17:51,993::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56827::DEBUG::2012-05-28 03:17:51,994::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56827::DEBUG::2012-05-28 03:17:51,994::task::980::TaskManager.Task::(_decref) Task=`c7ebbcac-9438-40b0-997c-27bdbda50bdb`::ref 0 aborting False Thread-56828::DEBUG::2012-05-28 03:17:53,151::task::588::TaskManager.Task::(_updateState) Task=`23acd09a-65bb-4f83-b2b0-3676140b0cda`::moving from state init -> state preparing Thread-56828::INFO::2012-05-28 03:17:53,152::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56828::INFO::2012-05-28 03:17:53,153::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00128722190857', 'lastCheck': 1338175071.395135, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00151491165161', 'lastCheck': 1338175068.197441, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00175714492798', 'lastCheck': 1338175067.028897, 'code': 0, 'valid': True}} Thread-56828::DEBUG::2012-05-28 03:17:53,153::task::1174::TaskManager.Task::(prepare) Task=`23acd09a-65bb-4f83-b2b0-3676140b0cda`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00128722190857', 'lastCheck': 1338175071.395135, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00151491165161', 'lastCheck': 1338175068.197441, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00175714492798', 'lastCheck': 1338175067.028897, 'code': 0, 'valid': True}} Thread-56828::DEBUG::2012-05-28 03:17:53,154::task::588::TaskManager.Task::(_updateState) Task=`23acd09a-65bb-4f83-b2b0-3676140b0cda`::moving from state preparing -> state finished Thread-56828::DEBUG::2012-05-28 03:17:53,155::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56828::DEBUG::2012-05-28 03:17:53,155::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56828::DEBUG::2012-05-28 03:17:53,156::task::980::TaskManager.Task::(_decref) Task=`23acd09a-65bb-4f83-b2b0-3676140b0cda`::ref 0 aborting False Thread-56834::DEBUG::2012-05-28 03:18:02,038::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56834::DEBUG::2012-05-28 03:18:02,039::task::588::TaskManager.Task::(_updateState) Task=`a0f11dce-81fa-4be6-aa84-d0fdc9976be4`::moving from state init -> state preparing Thread-56834::INFO::2012-05-28 03:18:02,040::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56834::INFO::2012-05-28 03:18:02,041::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56834::DEBUG::2012-05-28 03:18:02,042::task::1174::TaskManager.Task::(prepare) Task=`a0f11dce-81fa-4be6-aa84-d0fdc9976be4`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56834::DEBUG::2012-05-28 03:18:02,042::task::588::TaskManager.Task::(_updateState) Task=`a0f11dce-81fa-4be6-aa84-d0fdc9976be4`::moving from state preparing -> state finished Thread-56834::DEBUG::2012-05-28 03:18:02,043::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56834::DEBUG::2012-05-28 03:18:02,044::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56834::DEBUG::2012-05-28 03:18:02,044::task::980::TaskManager.Task::(_decref) Task=`a0f11dce-81fa-4be6-aa84-d0fdc9976be4`::ref 0 aborting False Thread-56835::DEBUG::2012-05-28 03:18:03,344::task::588::TaskManager.Task::(_updateState) Task=`f4f68b23-3ccc-4435-acbe-d843ec15f315`::moving from state init -> state preparing Thread-56835::INFO::2012-05-28 03:18:03,345::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56835::INFO::2012-05-28 03:18:03,346::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142383575439', 'lastCheck': 1338175081.405448, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0016040802002', 'lastCheck': 1338175078.207242, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00149083137512', 'lastCheck': 1338175077.036792, 'code': 0, 'valid': True}} Thread-56835::DEBUG::2012-05-28 03:18:03,346::task::1174::TaskManager.Task::(prepare) Task=`f4f68b23-3ccc-4435-acbe-d843ec15f315`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142383575439', 'lastCheck': 1338175081.405448, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0016040802002', 'lastCheck': 1338175078.207242, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00149083137512', 'lastCheck': 1338175077.036792, 'code': 0, 'valid': True}} Thread-56835::DEBUG::2012-05-28 03:18:03,347::task::588::TaskManager.Task::(_updateState) Task=`f4f68b23-3ccc-4435-acbe-d843ec15f315`::moving from state preparing -> state finished Thread-56835::DEBUG::2012-05-28 03:18:03,348::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56835::DEBUG::2012-05-28 03:18:03,348::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56835::DEBUG::2012-05-28 03:18:03,349::task::980::TaskManager.Task::(_decref) Task=`f4f68b23-3ccc-4435-acbe-d843ec15f315`::ref 0 aborting False Thread-56841::DEBUG::2012-05-28 03:18:12,087::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56841::DEBUG::2012-05-28 03:18:12,088::task::588::TaskManager.Task::(_updateState) Task=`e2c3fe37-a5d1-4263-a2c1-d59301959374`::moving from state init -> state preparing Thread-56841::INFO::2012-05-28 03:18:12,089::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56841::INFO::2012-05-28 03:18:12,090::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56841::DEBUG::2012-05-28 03:18:12,090::task::1174::TaskManager.Task::(prepare) Task=`e2c3fe37-a5d1-4263-a2c1-d59301959374`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56841::DEBUG::2012-05-28 03:18:12,091::task::588::TaskManager.Task::(_updateState) Task=`e2c3fe37-a5d1-4263-a2c1-d59301959374`::moving from state preparing -> state finished Thread-56841::DEBUG::2012-05-28 03:18:12,092::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56841::DEBUG::2012-05-28 03:18:12,092::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56841::DEBUG::2012-05-28 03:18:12,093::task::980::TaskManager.Task::(_decref) Task=`e2c3fe37-a5d1-4263-a2c1-d59301959374`::ref 0 aborting False Thread-56842::DEBUG::2012-05-28 03:18:13,554::task::588::TaskManager.Task::(_updateState) Task=`c7a32a44-9030-4f03-aadf-267e368c6417`::moving from state init -> state preparing Thread-56842::INFO::2012-05-28 03:18:13,554::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56842::INFO::2012-05-28 03:18:13,556::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00156211853027', 'lastCheck': 1338175091.415912, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00146508216858', 'lastCheck': 1338175088.21675, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00190496444702', 'lastCheck': 1338175087.049977, 'code': 0, 'valid': True}} Thread-56842::DEBUG::2012-05-28 03:18:13,556::task::1174::TaskManager.Task::(prepare) Task=`c7a32a44-9030-4f03-aadf-267e368c6417`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00156211853027', 'lastCheck': 1338175091.415912, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00146508216858', 'lastCheck': 1338175088.21675, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00190496444702', 'lastCheck': 1338175087.049977, 'code': 0, 'valid': True}} Thread-56842::DEBUG::2012-05-28 03:18:13,557::task::588::TaskManager.Task::(_updateState) Task=`c7a32a44-9030-4f03-aadf-267e368c6417`::moving from state preparing -> state finished Thread-56842::DEBUG::2012-05-28 03:18:13,558::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56842::DEBUG::2012-05-28 03:18:13,558::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56842::DEBUG::2012-05-28 03:18:13,559::task::980::TaskManager.Task::(_decref) Task=`c7a32a44-9030-4f03-aadf-267e368c6417`::ref 0 aborting False Thread-56848::DEBUG::2012-05-28 03:18:22,136::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56848::DEBUG::2012-05-28 03:18:22,137::task::588::TaskManager.Task::(_updateState) Task=`f558b4e9-8c18-44eb-8690-ba0e44f2f667`::moving from state init -> state preparing Thread-56848::INFO::2012-05-28 03:18:22,138::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56848::INFO::2012-05-28 03:18:22,139::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56848::DEBUG::2012-05-28 03:18:22,139::task::1174::TaskManager.Task::(prepare) Task=`f558b4e9-8c18-44eb-8690-ba0e44f2f667`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56848::DEBUG::2012-05-28 03:18:22,140::task::588::TaskManager.Task::(_updateState) Task=`f558b4e9-8c18-44eb-8690-ba0e44f2f667`::moving from state preparing -> state finished Thread-56848::DEBUG::2012-05-28 03:18:22,141::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56848::DEBUG::2012-05-28 03:18:22,141::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56848::DEBUG::2012-05-28 03:18:22,142::task::980::TaskManager.Task::(_decref) Task=`f558b4e9-8c18-44eb-8690-ba0e44f2f667`::ref 0 aborting False Thread-56849::DEBUG::2012-05-28 03:18:23,747::task::588::TaskManager.Task::(_updateState) Task=`782848e8-5784-4eb6-a962-12a8ca573d8c`::moving from state init -> state preparing Thread-56849::INFO::2012-05-28 03:18:23,748::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56849::INFO::2012-05-28 03:18:23,749::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00139188766479', 'lastCheck': 1338175101.425565, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00169515609741', 'lastCheck': 1338175098.227214, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00200009346008', 'lastCheck': 1338175097.062642, 'code': 0, 'valid': True}} Thread-56849::DEBUG::2012-05-28 03:18:23,750::task::1174::TaskManager.Task::(prepare) Task=`782848e8-5784-4eb6-a962-12a8ca573d8c`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00139188766479', 'lastCheck': 1338175101.425565, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00169515609741', 'lastCheck': 1338175098.227214, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00200009346008', 'lastCheck': 1338175097.062642, 'code': 0, 'valid': True}} Thread-56849::DEBUG::2012-05-28 03:18:23,751::task::588::TaskManager.Task::(_updateState) Task=`782848e8-5784-4eb6-a962-12a8ca573d8c`::moving from state preparing -> state finished Thread-56849::DEBUG::2012-05-28 03:18:23,751::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56849::DEBUG::2012-05-28 03:18:23,752::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56849::DEBUG::2012-05-28 03:18:23,753::task::980::TaskManager.Task::(_decref) Task=`782848e8-5784-4eb6-a962-12a8ca573d8c`::ref 0 aborting False Thread-56855::DEBUG::2012-05-28 03:18:32,184::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56855::DEBUG::2012-05-28 03:18:32,185::task::588::TaskManager.Task::(_updateState) Task=`7995b9b1-34ec-4c00-bd20-5d522c60969d`::moving from state init -> state preparing Thread-56855::INFO::2012-05-28 03:18:32,186::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56855::INFO::2012-05-28 03:18:32,187::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56855::DEBUG::2012-05-28 03:18:32,188::task::1174::TaskManager.Task::(prepare) Task=`7995b9b1-34ec-4c00-bd20-5d522c60969d`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56855::DEBUG::2012-05-28 03:18:32,188::task::588::TaskManager.Task::(_updateState) Task=`7995b9b1-34ec-4c00-bd20-5d522c60969d`::moving from state preparing -> state finished Thread-56855::DEBUG::2012-05-28 03:18:32,189::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56855::DEBUG::2012-05-28 03:18:32,190::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56855::DEBUG::2012-05-28 03:18:32,190::task::980::TaskManager.Task::(_decref) Task=`7995b9b1-34ec-4c00-bd20-5d522c60969d`::ref 0 aborting False Thread-56856::DEBUG::2012-05-28 03:18:33,943::task::588::TaskManager.Task::(_updateState) Task=`6f40f32e-5510-4c96-9f45-40bd2f42c3d8`::moving from state init -> state preparing Thread-56856::INFO::2012-05-28 03:18:33,944::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56856::INFO::2012-05-28 03:18:33,945::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142502784729', 'lastCheck': 1338175111.435746, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00128602981567', 'lastCheck': 1338175108.236528, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00130701065063', 'lastCheck': 1338175107.074024, 'code': 0, 'valid': True}} Thread-56856::DEBUG::2012-05-28 03:18:33,946::task::1174::TaskManager.Task::(prepare) Task=`6f40f32e-5510-4c96-9f45-40bd2f42c3d8`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142502784729', 'lastCheck': 1338175111.435746, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00128602981567', 'lastCheck': 1338175108.236528, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00130701065063', 'lastCheck': 1338175107.074024, 'code': 0, 'valid': True}} Thread-56856::DEBUG::2012-05-28 03:18:33,947::task::588::TaskManager.Task::(_updateState) Task=`6f40f32e-5510-4c96-9f45-40bd2f42c3d8`::moving from state preparing -> state finished Thread-56856::DEBUG::2012-05-28 03:18:33,947::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56856::DEBUG::2012-05-28 03:18:33,948::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56856::DEBUG::2012-05-28 03:18:33,949::task::980::TaskManager.Task::(_decref) Task=`6f40f32e-5510-4c96-9f45-40bd2f42c3d8`::ref 0 aborting False Thread-56862::DEBUG::2012-05-28 03:18:42,266::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56862::DEBUG::2012-05-28 03:18:42,267::task::588::TaskManager.Task::(_updateState) Task=`662900fd-250b-4326-983d-e2a68f4953c3`::moving from state init -> state preparing Thread-56862::INFO::2012-05-28 03:18:42,268::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56862::INFO::2012-05-28 03:18:42,269::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56862::DEBUG::2012-05-28 03:18:42,270::task::1174::TaskManager.Task::(prepare) Task=`662900fd-250b-4326-983d-e2a68f4953c3`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56862::DEBUG::2012-05-28 03:18:42,271::task::588::TaskManager.Task::(_updateState) Task=`662900fd-250b-4326-983d-e2a68f4953c3`::moving from state preparing -> state finished Thread-56862::DEBUG::2012-05-28 03:18:42,271::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56862::DEBUG::2012-05-28 03:18:42,272::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56862::DEBUG::2012-05-28 03:18:42,273::task::980::TaskManager.Task::(_decref) Task=`662900fd-250b-4326-983d-e2a68f4953c3`::ref 0 aborting False Thread-56863::DEBUG::2012-05-28 03:18:44,136::task::588::TaskManager.Task::(_updateState) Task=`cdcef619-d7f2-4e60-a99a-97a30045738c`::moving from state init -> state preparing Thread-56863::INFO::2012-05-28 03:18:44,137::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56863::INFO::2012-05-28 03:18:44,138::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141000747681', 'lastCheck': 1338175121.445622, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0010199546814', 'lastCheck': 1338175118.245903, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00184297561646', 'lastCheck': 1338175117.086533, 'code': 0, 'valid': True}} Thread-56863::DEBUG::2012-05-28 03:18:44,138::task::1174::TaskManager.Task::(prepare) Task=`cdcef619-d7f2-4e60-a99a-97a30045738c`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141000747681', 'lastCheck': 1338175121.445622, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0010199546814', 'lastCheck': 1338175118.245903, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00184297561646', 'lastCheck': 1338175117.086533, 'code': 0, 'valid': True}} Thread-56863::DEBUG::2012-05-28 03:18:44,139::task::588::TaskManager.Task::(_updateState) Task=`cdcef619-d7f2-4e60-a99a-97a30045738c`::moving from state preparing -> state finished Thread-56863::DEBUG::2012-05-28 03:18:44,140::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56863::DEBUG::2012-05-28 03:18:44,140::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56863::DEBUG::2012-05-28 03:18:44,141::task::980::TaskManager.Task::(_decref) Task=`cdcef619-d7f2-4e60-a99a-97a30045738c`::ref 0 aborting False Thread-56869::DEBUG::2012-05-28 03:18:52,315::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56869::DEBUG::2012-05-28 03:18:52,316::task::588::TaskManager.Task::(_updateState) Task=`eb89f547-bb0d-482d-a2ac-fe19af1cc6bc`::moving from state init -> state preparing Thread-56869::INFO::2012-05-28 03:18:52,317::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56869::INFO::2012-05-28 03:18:52,318::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56869::DEBUG::2012-05-28 03:18:52,318::task::1174::TaskManager.Task::(prepare) Task=`eb89f547-bb0d-482d-a2ac-fe19af1cc6bc`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56869::DEBUG::2012-05-28 03:18:52,319::task::588::TaskManager.Task::(_updateState) Task=`eb89f547-bb0d-482d-a2ac-fe19af1cc6bc`::moving from state preparing -> state finished Thread-56869::DEBUG::2012-05-28 03:18:52,320::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56869::DEBUG::2012-05-28 03:18:52,320::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56869::DEBUG::2012-05-28 03:18:52,321::task::980::TaskManager.Task::(_decref) Task=`eb89f547-bb0d-482d-a2ac-fe19af1cc6bc`::ref 0 aborting False Thread-56870::DEBUG::2012-05-28 03:18:54,326::task::588::TaskManager.Task::(_updateState) Task=`aa4bc4bb-f9df-4691-93c1-2c79577b98bb`::moving from state init -> state preparing Thread-56870::INFO::2012-05-28 03:18:54,327::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56870::INFO::2012-05-28 03:18:54,328::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141406059265', 'lastCheck': 1338175131.455501, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00167608261108', 'lastCheck': 1338175128.25812, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00165891647339', 'lastCheck': 1338175127.096497, 'code': 0, 'valid': True}} Thread-56870::DEBUG::2012-05-28 03:18:54,329::task::1174::TaskManager.Task::(prepare) Task=`aa4bc4bb-f9df-4691-93c1-2c79577b98bb`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141406059265', 'lastCheck': 1338175131.455501, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00167608261108', 'lastCheck': 1338175128.25812, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00165891647339', 'lastCheck': 1338175127.096497, 'code': 0, 'valid': True}} Thread-56870::DEBUG::2012-05-28 03:18:54,330::task::588::TaskManager.Task::(_updateState) Task=`aa4bc4bb-f9df-4691-93c1-2c79577b98bb`::moving from state preparing -> state finished Thread-56870::DEBUG::2012-05-28 03:18:54,330::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56870::DEBUG::2012-05-28 03:18:54,331::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56870::DEBUG::2012-05-28 03:18:54,332::task::980::TaskManager.Task::(_decref) Task=`aa4bc4bb-f9df-4691-93c1-2c79577b98bb`::ref 0 aborting False Thread-56875::DEBUG::2012-05-28 03:19:02,361::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56875::DEBUG::2012-05-28 03:19:02,363::task::588::TaskManager.Task::(_updateState) Task=`f0eee7d7-5d12-452b-a148-88383240483b`::moving from state init -> state preparing Thread-56875::INFO::2012-05-28 03:19:02,364::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56875::INFO::2012-05-28 03:19:02,364::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56875::DEBUG::2012-05-28 03:19:02,365::task::1174::TaskManager.Task::(prepare) Task=`f0eee7d7-5d12-452b-a148-88383240483b`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56875::DEBUG::2012-05-28 03:19:02,366::task::588::TaskManager.Task::(_updateState) Task=`f0eee7d7-5d12-452b-a148-88383240483b`::moving from state preparing -> state finished Thread-56875::DEBUG::2012-05-28 03:19:02,366::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56875::DEBUG::2012-05-28 03:19:02,367::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56875::DEBUG::2012-05-28 03:19:02,368::task::980::TaskManager.Task::(_decref) Task=`f0eee7d7-5d12-452b-a148-88383240483b`::ref 0 aborting False Thread-56877::DEBUG::2012-05-28 03:19:04,518::task::588::TaskManager.Task::(_updateState) Task=`cc53854a-e65d-4a56-932e-c8b85ec73bb8`::moving from state init -> state preparing Thread-56877::INFO::2012-05-28 03:19:04,519::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56877::INFO::2012-05-28 03:19:04,520::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142812728882', 'lastCheck': 1338175141.465798, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00160598754883', 'lastCheck': 1338175138.267357, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00205516815186', 'lastCheck': 1338175137.107303, 'code': 0, 'valid': True}} Thread-56877::DEBUG::2012-05-28 03:19:04,520::task::1174::TaskManager.Task::(prepare) Task=`cc53854a-e65d-4a56-932e-c8b85ec73bb8`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142812728882', 'lastCheck': 1338175141.465798, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00160598754883', 'lastCheck': 1338175138.267357, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00205516815186', 'lastCheck': 1338175137.107303, 'code': 0, 'valid': True}} Thread-56877::DEBUG::2012-05-28 03:19:04,521::task::588::TaskManager.Task::(_updateState) Task=`cc53854a-e65d-4a56-932e-c8b85ec73bb8`::moving from state preparing -> state finished Thread-56877::DEBUG::2012-05-28 03:19:04,522::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56877::DEBUG::2012-05-28 03:19:04,522::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56877::DEBUG::2012-05-28 03:19:04,523::task::980::TaskManager.Task::(_decref) Task=`cc53854a-e65d-4a56-932e-c8b85ec73bb8`::ref 0 aborting False Thread-56882::DEBUG::2012-05-28 03:19:12,409::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56882::DEBUG::2012-05-28 03:19:12,410::task::588::TaskManager.Task::(_updateState) Task=`9f1329e9-8d29-46a6-9e08-dec6ba081463`::moving from state init -> state preparing Thread-56882::INFO::2012-05-28 03:19:12,411::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56882::INFO::2012-05-28 03:19:12,412::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56882::DEBUG::2012-05-28 03:19:12,413::task::1174::TaskManager.Task::(prepare) Task=`9f1329e9-8d29-46a6-9e08-dec6ba081463`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56882::DEBUG::2012-05-28 03:19:12,413::task::588::TaskManager.Task::(_updateState) Task=`9f1329e9-8d29-46a6-9e08-dec6ba081463`::moving from state preparing -> state finished Thread-56882::DEBUG::2012-05-28 03:19:12,414::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56882::DEBUG::2012-05-28 03:19:12,414::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56882::DEBUG::2012-05-28 03:19:12,415::task::980::TaskManager.Task::(_decref) Task=`9f1329e9-8d29-46a6-9e08-dec6ba081463`::ref 0 aborting False Thread-56884::DEBUG::2012-05-28 03:19:14,721::task::588::TaskManager.Task::(_updateState) Task=`0b93a2af-f1a7-4a47-86ee-524058784086`::moving from state init -> state preparing Thread-56884::INFO::2012-05-28 03:19:14,722::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56884::INFO::2012-05-28 03:19:14,723::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00129413604736', 'lastCheck': 1338175151.475591, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00171303749084', 'lastCheck': 1338175148.277164, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0018789768219', 'lastCheck': 1338175147.120321, 'code': 0, 'valid': True}} Thread-56884::DEBUG::2012-05-28 03:19:14,723::task::1174::TaskManager.Task::(prepare) Task=`0b93a2af-f1a7-4a47-86ee-524058784086`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00129413604736', 'lastCheck': 1338175151.475591, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00171303749084', 'lastCheck': 1338175148.277164, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0018789768219', 'lastCheck': 1338175147.120321, 'code': 0, 'valid': True}} Thread-56884::DEBUG::2012-05-28 03:19:14,724::task::588::TaskManager.Task::(_updateState) Task=`0b93a2af-f1a7-4a47-86ee-524058784086`::moving from state preparing -> state finished Thread-56884::DEBUG::2012-05-28 03:19:14,725::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56884::DEBUG::2012-05-28 03:19:14,725::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56884::DEBUG::2012-05-28 03:19:14,726::task::980::TaskManager.Task::(_decref) Task=`0b93a2af-f1a7-4a47-86ee-524058784086`::ref 0 aborting False Thread-56889::DEBUG::2012-05-28 03:19:22,458::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56889::DEBUG::2012-05-28 03:19:22,459::task::588::TaskManager.Task::(_updateState) Task=`2708c524-6c22-444d-b1b8-26bba6637f2b`::moving from state init -> state preparing Thread-56889::INFO::2012-05-28 03:19:22,460::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56889::INFO::2012-05-28 03:19:22,461::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56889::DEBUG::2012-05-28 03:19:22,462::task::1174::TaskManager.Task::(prepare) Task=`2708c524-6c22-444d-b1b8-26bba6637f2b`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56889::DEBUG::2012-05-28 03:19:22,463::task::588::TaskManager.Task::(_updateState) Task=`2708c524-6c22-444d-b1b8-26bba6637f2b`::moving from state preparing -> state finished Thread-56889::DEBUG::2012-05-28 03:19:22,463::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56889::DEBUG::2012-05-28 03:19:22,464::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56889::DEBUG::2012-05-28 03:19:22,465::task::980::TaskManager.Task::(_decref) Task=`2708c524-6c22-444d-b1b8-26bba6637f2b`::ref 0 aborting False Thread-56891::DEBUG::2012-05-28 03:19:24,908::task::588::TaskManager.Task::(_updateState) Task=`6a3d04d2-f4e6-4b7e-957f-2e83e0896f33`::moving from state init -> state preparing Thread-56891::INFO::2012-05-28 03:19:24,909::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56891::INFO::2012-05-28 03:19:24,910::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00108504295349', 'lastCheck': 1338175161.48503, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00139307975769', 'lastCheck': 1338175158.286835, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00184178352356', 'lastCheck': 1338175157.132717, 'code': 0, 'valid': True}} Thread-56891::DEBUG::2012-05-28 03:19:24,911::task::1174::TaskManager.Task::(prepare) Task=`6a3d04d2-f4e6-4b7e-957f-2e83e0896f33`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00108504295349', 'lastCheck': 1338175161.48503, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00139307975769', 'lastCheck': 1338175158.286835, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00184178352356', 'lastCheck': 1338175157.132717, 'code': 0, 'valid': True}} Thread-56891::DEBUG::2012-05-28 03:19:24,912::task::588::TaskManager.Task::(_updateState) Task=`6a3d04d2-f4e6-4b7e-957f-2e83e0896f33`::moving from state preparing -> state finished Thread-56891::DEBUG::2012-05-28 03:19:24,912::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56891::DEBUG::2012-05-28 03:19:24,913::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56891::DEBUG::2012-05-28 03:19:24,914::task::980::TaskManager.Task::(_decref) Task=`6a3d04d2-f4e6-4b7e-957f-2e83e0896f33`::ref 0 aborting False Thread-56896::DEBUG::2012-05-28 03:19:32,513::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56896::DEBUG::2012-05-28 03:19:32,514::task::588::TaskManager.Task::(_updateState) Task=`5263d438-5b32-4eb4-9d7c-64ab08594f33`::moving from state init -> state preparing Thread-56896::INFO::2012-05-28 03:19:32,515::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56896::INFO::2012-05-28 03:19:32,516::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56896::DEBUG::2012-05-28 03:19:32,517::task::1174::TaskManager.Task::(prepare) Task=`5263d438-5b32-4eb4-9d7c-64ab08594f33`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56896::DEBUG::2012-05-28 03:19:32,517::task::588::TaskManager.Task::(_updateState) Task=`5263d438-5b32-4eb4-9d7c-64ab08594f33`::moving from state preparing -> state finished Thread-56896::DEBUG::2012-05-28 03:19:32,518::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56896::DEBUG::2012-05-28 03:19:32,519::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56896::DEBUG::2012-05-28 03:19:32,519::task::980::TaskManager.Task::(_decref) Task=`5263d438-5b32-4eb4-9d7c-64ab08594f33`::ref 0 aborting False Thread-56898::DEBUG::2012-05-28 03:19:35,100::task::588::TaskManager.Task::(_updateState) Task=`f3d31ef6-d64f-4222-8582-3b93eee5910c`::moving from state init -> state preparing Thread-56898::INFO::2012-05-28 03:19:35,101::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56898::INFO::2012-05-28 03:19:35,102::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142216682434', 'lastCheck': 1338175171.495628, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00156998634338', 'lastCheck': 1338175168.296831, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00170207023621', 'lastCheck': 1338175167.144922, 'code': 0, 'valid': True}} Thread-56898::DEBUG::2012-05-28 03:19:35,103::task::1174::TaskManager.Task::(prepare) Task=`f3d31ef6-d64f-4222-8582-3b93eee5910c`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00142216682434', 'lastCheck': 1338175171.495628, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00156998634338', 'lastCheck': 1338175168.296831, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00170207023621', 'lastCheck': 1338175167.144922, 'code': 0, 'valid': True}} Thread-56898::DEBUG::2012-05-28 03:19:35,104::task::588::TaskManager.Task::(_updateState) Task=`f3d31ef6-d64f-4222-8582-3b93eee5910c`::moving from state preparing -> state finished Thread-56898::DEBUG::2012-05-28 03:19:35,104::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56898::DEBUG::2012-05-28 03:19:35,105::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56898::DEBUG::2012-05-28 03:19:35,106::task::980::TaskManager.Task::(_decref) Task=`f3d31ef6-d64f-4222-8582-3b93eee5910c`::ref 0 aborting False Thread-56903::DEBUG::2012-05-28 03:19:42,561::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56903::DEBUG::2012-05-28 03:19:42,563::task::588::TaskManager.Task::(_updateState) Task=`a87e820d-d8d1-48e8-9a13-7d5afb095f5b`::moving from state init -> state preparing Thread-56903::INFO::2012-05-28 03:19:42,563::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56903::INFO::2012-05-28 03:19:42,564::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56903::DEBUG::2012-05-28 03:19:42,565::task::1174::TaskManager.Task::(prepare) Task=`a87e820d-d8d1-48e8-9a13-7d5afb095f5b`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56903::DEBUG::2012-05-28 03:19:42,566::task::588::TaskManager.Task::(_updateState) Task=`a87e820d-d8d1-48e8-9a13-7d5afb095f5b`::moving from state preparing -> state finished Thread-56903::DEBUG::2012-05-28 03:19:42,566::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56903::DEBUG::2012-05-28 03:19:42,567::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56903::DEBUG::2012-05-28 03:19:42,568::task::980::TaskManager.Task::(_decref) Task=`a87e820d-d8d1-48e8-9a13-7d5afb095f5b`::ref 0 aborting False Thread-56905::DEBUG::2012-05-28 03:19:45,293::task::588::TaskManager.Task::(_updateState) Task=`8ef58f73-7dc4-43a0-a9cb-4c34541d1cbb`::moving from state init -> state preparing Thread-56905::INFO::2012-05-28 03:19:45,294::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56905::INFO::2012-05-28 03:19:45,295::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00112390518188', 'lastCheck': 1338175181.50506, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00104904174805', 'lastCheck': 1338175178.30603, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00154089927673', 'lastCheck': 1338175177.155919, 'code': 0, 'valid': True}} Thread-56905::DEBUG::2012-05-28 03:19:45,295::task::1174::TaskManager.Task::(prepare) Task=`8ef58f73-7dc4-43a0-a9cb-4c34541d1cbb`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00112390518188', 'lastCheck': 1338175181.50506, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00104904174805', 'lastCheck': 1338175178.30603, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00154089927673', 'lastCheck': 1338175177.155919, 'code': 0, 'valid': True}} Thread-56905::DEBUG::2012-05-28 03:19:45,296::task::588::TaskManager.Task::(_updateState) Task=`8ef58f73-7dc4-43a0-a9cb-4c34541d1cbb`::moving from state preparing -> state finished Thread-56905::DEBUG::2012-05-28 03:19:45,297::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56905::DEBUG::2012-05-28 03:19:45,297::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56905::DEBUG::2012-05-28 03:19:45,298::task::980::TaskManager.Task::(_decref) Task=`8ef58f73-7dc4-43a0-a9cb-4c34541d1cbb`::ref 0 aborting False Thread-56910::DEBUG::2012-05-28 03:19:52,610::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56910::DEBUG::2012-05-28 03:19:52,611::task::588::TaskManager.Task::(_updateState) Task=`548e82e4-17df-46f1-827a-27b136a58d93`::moving from state init -> state preparing Thread-56910::INFO::2012-05-28 03:19:52,612::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56910::INFO::2012-05-28 03:19:52,613::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56910::DEBUG::2012-05-28 03:19:52,614::task::1174::TaskManager.Task::(prepare) Task=`548e82e4-17df-46f1-827a-27b136a58d93`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56910::DEBUG::2012-05-28 03:19:52,615::task::588::TaskManager.Task::(_updateState) Task=`548e82e4-17df-46f1-827a-27b136a58d93`::moving from state preparing -> state finished Thread-56910::DEBUG::2012-05-28 03:19:52,615::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56910::DEBUG::2012-05-28 03:19:52,616::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56910::DEBUG::2012-05-28 03:19:52,616::task::980::TaskManager.Task::(_decref) Task=`548e82e4-17df-46f1-827a-27b136a58d93`::ref 0 aborting False Thread-56912::DEBUG::2012-05-28 03:19:55,489::task::588::TaskManager.Task::(_updateState) Task=`8528ed17-1773-4c6a-ae73-903e7506edc4`::moving from state init -> state preparing Thread-56912::INFO::2012-05-28 03:19:55,490::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56912::INFO::2012-05-28 03:19:55,491::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00149893760681', 'lastCheck': 1338175191.515354, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00145602226257', 'lastCheck': 1338175188.317232, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0016610622406', 'lastCheck': 1338175187.166205, 'code': 0, 'valid': True}} Thread-56912::DEBUG::2012-05-28 03:19:55,492::task::1174::TaskManager.Task::(prepare) Task=`8528ed17-1773-4c6a-ae73-903e7506edc4`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00149893760681', 'lastCheck': 1338175191.515354, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00145602226257', 'lastCheck': 1338175188.317232, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0016610622406', 'lastCheck': 1338175187.166205, 'code': 0, 'valid': True}} Thread-56912::DEBUG::2012-05-28 03:19:55,493::task::588::TaskManager.Task::(_updateState) Task=`8528ed17-1773-4c6a-ae73-903e7506edc4`::moving from state preparing -> state finished Thread-56912::DEBUG::2012-05-28 03:19:55,493::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56912::DEBUG::2012-05-28 03:19:55,494::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56912::DEBUG::2012-05-28 03:19:55,495::task::980::TaskManager.Task::(_decref) Task=`8528ed17-1773-4c6a-ae73-903e7506edc4`::ref 0 aborting False Thread-56917::DEBUG::2012-05-28 03:20:02,677::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56917::DEBUG::2012-05-28 03:20:02,678::task::588::TaskManager.Task::(_updateState) Task=`4bff1b0b-0fb7-43f3-a891-49c83a123977`::moving from state init -> state preparing Thread-56917::INFO::2012-05-28 03:20:02,679::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56917::INFO::2012-05-28 03:20:02,680::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56917::DEBUG::2012-05-28 03:20:02,681::task::1174::TaskManager.Task::(prepare) Task=`4bff1b0b-0fb7-43f3-a891-49c83a123977`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56917::DEBUG::2012-05-28 03:20:02,681::task::588::TaskManager.Task::(_updateState) Task=`4bff1b0b-0fb7-43f3-a891-49c83a123977`::moving from state preparing -> state finished Thread-56917::DEBUG::2012-05-28 03:20:02,682::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56917::DEBUG::2012-05-28 03:20:02,683::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56917::DEBUG::2012-05-28 03:20:02,683::task::980::TaskManager.Task::(_decref) Task=`4bff1b0b-0fb7-43f3-a891-49c83a123977`::ref 0 aborting False Thread-56919::DEBUG::2012-05-28 03:20:05,687::task::588::TaskManager.Task::(_updateState) Task=`369222f4-2262-496b-9893-238884727675`::moving from state init -> state preparing Thread-56919::INFO::2012-05-28 03:20:05,688::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56919::INFO::2012-05-28 03:20:05,689::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00213313102722', 'lastCheck': 1338175201.528354, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00161290168762', 'lastCheck': 1338175198.327144, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00187110900879', 'lastCheck': 1338175197.176457, 'code': 0, 'valid': True}} Thread-56919::DEBUG::2012-05-28 03:20:05,690::task::1174::TaskManager.Task::(prepare) Task=`369222f4-2262-496b-9893-238884727675`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00213313102722', 'lastCheck': 1338175201.528354, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00161290168762', 'lastCheck': 1338175198.327144, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00187110900879', 'lastCheck': 1338175197.176457, 'code': 0, 'valid': True}} Thread-56919::DEBUG::2012-05-28 03:20:05,691::task::588::TaskManager.Task::(_updateState) Task=`369222f4-2262-496b-9893-238884727675`::moving from state preparing -> state finished Thread-56919::DEBUG::2012-05-28 03:20:05,691::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56919::DEBUG::2012-05-28 03:20:05,692::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56919::DEBUG::2012-05-28 03:20:05,693::task::980::TaskManager.Task::(_decref) Task=`369222f4-2262-496b-9893-238884727675`::ref 0 aborting False Thread-56924::DEBUG::2012-05-28 03:20:12,726::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56924::DEBUG::2012-05-28 03:20:12,727::task::588::TaskManager.Task::(_updateState) Task=`0c42c194-9cc3-41ac-9648-a980ad788338`::moving from state init -> state preparing Thread-56924::INFO::2012-05-28 03:20:12,728::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56924::INFO::2012-05-28 03:20:12,729::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56924::DEBUG::2012-05-28 03:20:12,730::task::1174::TaskManager.Task::(prepare) Task=`0c42c194-9cc3-41ac-9648-a980ad788338`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56924::DEBUG::2012-05-28 03:20:12,731::task::588::TaskManager.Task::(_updateState) Task=`0c42c194-9cc3-41ac-9648-a980ad788338`::moving from state preparing -> state finished Thread-56924::DEBUG::2012-05-28 03:20:12,731::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56924::DEBUG::2012-05-28 03:20:12,732::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56924::DEBUG::2012-05-28 03:20:12,733::task::980::TaskManager.Task::(_decref) Task=`0c42c194-9cc3-41ac-9648-a980ad788338`::ref 0 aborting False Thread-56926::DEBUG::2012-05-28 03:20:15,884::task::588::TaskManager.Task::(_updateState) Task=`42db93af-35a1-44d2-8b1c-1056b094c515`::moving from state init -> state preparing Thread-56926::INFO::2012-05-28 03:20:15,885::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56926::INFO::2012-05-28 03:20:15,886::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00151801109314', 'lastCheck': 1338175211.536796, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0017991065979', 'lastCheck': 1338175208.337203, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00146102905273', 'lastCheck': 1338175207.186681, 'code': 0, 'valid': True}} Thread-56926::DEBUG::2012-05-28 03:20:15,886::task::1174::TaskManager.Task::(prepare) Task=`42db93af-35a1-44d2-8b1c-1056b094c515`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00151801109314', 'lastCheck': 1338175211.536796, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.0017991065979', 'lastCheck': 1338175208.337203, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00146102905273', 'lastCheck': 1338175207.186681, 'code': 0, 'valid': True}} Thread-56926::DEBUG::2012-05-28 03:20:15,887::task::588::TaskManager.Task::(_updateState) Task=`42db93af-35a1-44d2-8b1c-1056b094c515`::moving from state preparing -> state finished Thread-56926::DEBUG::2012-05-28 03:20:15,888::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56926::DEBUG::2012-05-28 03:20:15,888::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56926::DEBUG::2012-05-28 03:20:15,889::task::980::TaskManager.Task::(_decref) Task=`42db93af-35a1-44d2-8b1c-1056b094c515`::ref 0 aborting False Thread-56931::DEBUG::2012-05-28 03:20:22,774::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56931::DEBUG::2012-05-28 03:20:22,776::task::588::TaskManager.Task::(_updateState) Task=`458107ff-7945-41de-b4a8-75a79a8b0c3d`::moving from state init -> state preparing Thread-56931::INFO::2012-05-28 03:20:22,776::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56931::INFO::2012-05-28 03:20:22,777::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56931::DEBUG::2012-05-28 03:20:22,778::task::1174::TaskManager.Task::(prepare) Task=`458107ff-7945-41de-b4a8-75a79a8b0c3d`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56931::DEBUG::2012-05-28 03:20:22,779::task::588::TaskManager.Task::(_updateState) Task=`458107ff-7945-41de-b4a8-75a79a8b0c3d`::moving from state preparing -> state finished Thread-56931::DEBUG::2012-05-28 03:20:22,779::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56931::DEBUG::2012-05-28 03:20:22,780::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56931::DEBUG::2012-05-28 03:20:22,781::task::980::TaskManager.Task::(_decref) Task=`458107ff-7945-41de-b4a8-75a79a8b0c3d`::ref 0 aborting False Thread-56933::DEBUG::2012-05-28 03:20:26,076::task::588::TaskManager.Task::(_updateState) Task=`dd239c6d-9c7a-4884-845b-47815ca75c1d`::moving from state init -> state preparing Thread-56933::INFO::2012-05-28 03:20:26,077::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56933::INFO::2012-05-28 03:20:26,078::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00121998786926', 'lastCheck': 1338175221.545588, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00145983695984', 'lastCheck': 1338175218.346951, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00132298469543', 'lastCheck': 1338175217.198239, 'code': 0, 'valid': True}} Thread-56933::DEBUG::2012-05-28 03:20:26,079::task::1174::TaskManager.Task::(prepare) Task=`dd239c6d-9c7a-4884-845b-47815ca75c1d`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00121998786926', 'lastCheck': 1338175221.545588, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00145983695984', 'lastCheck': 1338175218.346951, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00132298469543', 'lastCheck': 1338175217.198239, 'code': 0, 'valid': True}} Thread-56933::DEBUG::2012-05-28 03:20:26,080::task::588::TaskManager.Task::(_updateState) Task=`dd239c6d-9c7a-4884-845b-47815ca75c1d`::moving from state preparing -> state finished Thread-56933::DEBUG::2012-05-28 03:20:26,080::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56933::DEBUG::2012-05-28 03:20:26,081::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56933::DEBUG::2012-05-28 03:20:26,082::task::980::TaskManager.Task::(_decref) Task=`dd239c6d-9c7a-4884-845b-47815ca75c1d`::ref 0 aborting False Thread-56938::DEBUG::2012-05-28 03:20:32,822::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56938::DEBUG::2012-05-28 03:20:32,823::task::588::TaskManager.Task::(_updateState) Task=`69cc05d9-7670-4029-9353-77c1e9682d2a`::moving from state init -> state preparing Thread-56938::INFO::2012-05-28 03:20:32,824::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56938::INFO::2012-05-28 03:20:32,825::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56938::DEBUG::2012-05-28 03:20:32,826::task::1174::TaskManager.Task::(prepare) Task=`69cc05d9-7670-4029-9353-77c1e9682d2a`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56938::DEBUG::2012-05-28 03:20:32,826::task::588::TaskManager.Task::(_updateState) Task=`69cc05d9-7670-4029-9353-77c1e9682d2a`::moving from state preparing -> state finished Thread-56938::DEBUG::2012-05-28 03:20:32,827::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56938::DEBUG::2012-05-28 03:20:32,828::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56938::DEBUG::2012-05-28 03:20:32,828::task::980::TaskManager.Task::(_decref) Task=`69cc05d9-7670-4029-9353-77c1e9682d2a`::ref 0 aborting False Thread-56940::DEBUG::2012-05-28 03:20:36,279::task::588::TaskManager.Task::(_updateState) Task=`90d564b4-e61a-45be-bfb6-8e01c461464c`::moving from state init -> state preparing Thread-56940::INFO::2012-05-28 03:20:36,280::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56940::INFO::2012-05-28 03:20:36,281::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00169110298157', 'lastCheck': 1338175231.556109, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00133609771729', 'lastCheck': 1338175228.356622, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0012149810791', 'lastCheck': 1338175227.244507, 'code': 0, 'valid': True}} Thread-56940::DEBUG::2012-05-28 03:20:36,282::task::1174::TaskManager.Task::(prepare) Task=`90d564b4-e61a-45be-bfb6-8e01c461464c`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00169110298157', 'lastCheck': 1338175231.556109, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00133609771729', 'lastCheck': 1338175228.356622, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0012149810791', 'lastCheck': 1338175227.244507, 'code': 0, 'valid': True}} Thread-56940::DEBUG::2012-05-28 03:20:36,282::task::588::TaskManager.Task::(_updateState) Task=`90d564b4-e61a-45be-bfb6-8e01c461464c`::moving from state preparing -> state finished Thread-56940::DEBUG::2012-05-28 03:20:36,283::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56940::DEBUG::2012-05-28 03:20:36,284::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56940::DEBUG::2012-05-28 03:20:36,284::task::980::TaskManager.Task::(_decref) Task=`90d564b4-e61a-45be-bfb6-8e01c461464c`::ref 0 aborting False Thread-56945::DEBUG::2012-05-28 03:20:42,871::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56945::DEBUG::2012-05-28 03:20:42,872::task::588::TaskManager.Task::(_updateState) Task=`388b6b84-7409-4f55-8f90-74c7aa9d1b01`::moving from state init -> state preparing Thread-56945::INFO::2012-05-28 03:20:42,873::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56945::INFO::2012-05-28 03:20:42,874::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56945::DEBUG::2012-05-28 03:20:42,875::task::1174::TaskManager.Task::(prepare) Task=`388b6b84-7409-4f55-8f90-74c7aa9d1b01`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56945::DEBUG::2012-05-28 03:20:42,875::task::588::TaskManager.Task::(_updateState) Task=`388b6b84-7409-4f55-8f90-74c7aa9d1b01`::moving from state preparing -> state finished Thread-56945::DEBUG::2012-05-28 03:20:42,876::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56945::DEBUG::2012-05-28 03:20:42,876::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56945::DEBUG::2012-05-28 03:20:42,877::task::980::TaskManager.Task::(_decref) Task=`388b6b84-7409-4f55-8f90-74c7aa9d1b01`::ref 0 aborting False Thread-56947::DEBUG::2012-05-28 03:20:46,472::task::588::TaskManager.Task::(_updateState) Task=`82d9ab88-ea59-413a-ab16-236604876de7`::moving from state init -> state preparing Thread-56947::INFO::2012-05-28 03:20:46,473::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56947::INFO::2012-05-28 03:20:46,474::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00122499465942', 'lastCheck': 1338175241.565494, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00244998931885', 'lastCheck': 1338175238.369767, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0427939891815', 'lastCheck': 1338175237.29732, 'code': 0, 'valid': True}} Thread-56947::DEBUG::2012-05-28 03:20:46,475::task::1174::TaskManager.Task::(prepare) Task=`82d9ab88-ea59-413a-ab16-236604876de7`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00122499465942', 'lastCheck': 1338175241.565494, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00244998931885', 'lastCheck': 1338175238.369767, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.0427939891815', 'lastCheck': 1338175237.29732, 'code': 0, 'valid': True}} Thread-56947::DEBUG::2012-05-28 03:20:46,475::task::588::TaskManager.Task::(_updateState) Task=`82d9ab88-ea59-413a-ab16-236604876de7`::moving from state preparing -> state finished Thread-56947::DEBUG::2012-05-28 03:20:46,476::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56947::DEBUG::2012-05-28 03:20:46,477::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56947::DEBUG::2012-05-28 03:20:46,477::task::980::TaskManager.Task::(_decref) Task=`82d9ab88-ea59-413a-ab16-236604876de7`::ref 0 aborting False Thread-56952::DEBUG::2012-05-28 03:20:52,921::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56952::DEBUG::2012-05-28 03:20:52,922::task::588::TaskManager.Task::(_updateState) Task=`10ec6d58-3495-4c0c-837e-869d547d3322`::moving from state init -> state preparing Thread-56952::INFO::2012-05-28 03:20:52,923::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56952::INFO::2012-05-28 03:20:52,924::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56952::DEBUG::2012-05-28 03:20:52,925::task::1174::TaskManager.Task::(prepare) Task=`10ec6d58-3495-4c0c-837e-869d547d3322`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56952::DEBUG::2012-05-28 03:20:52,926::task::588::TaskManager.Task::(_updateState) Task=`10ec6d58-3495-4c0c-837e-869d547d3322`::moving from state preparing -> state finished Thread-56952::DEBUG::2012-05-28 03:20:52,926::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56952::DEBUG::2012-05-28 03:20:52,927::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56952::DEBUG::2012-05-28 03:20:52,927::task::980::TaskManager.Task::(_decref) Task=`10ec6d58-3495-4c0c-837e-869d547d3322`::ref 0 aborting False Thread-56954::DEBUG::2012-05-28 03:20:56,684::task::588::TaskManager.Task::(_updateState) Task=`b5ece2e7-eae6-41cd-869c-880abe928f6e`::moving from state init -> state preparing Thread-56954::INFO::2012-05-28 03:20:56,685::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56954::INFO::2012-05-28 03:20:56,686::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141596794128', 'lastCheck': 1338175251.575526, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00190401077271', 'lastCheck': 1338175248.385359, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00176906585693', 'lastCheck': 1338175247.307218, 'code': 0, 'valid': True}} Thread-56954::DEBUG::2012-05-28 03:20:56,687::task::1174::TaskManager.Task::(prepare) Task=`b5ece2e7-eae6-41cd-869c-880abe928f6e`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00141596794128', 'lastCheck': 1338175251.575526, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00190401077271', 'lastCheck': 1338175248.385359, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00176906585693', 'lastCheck': 1338175247.307218, 'code': 0, 'valid': True}} Thread-56954::DEBUG::2012-05-28 03:20:56,688::task::588::TaskManager.Task::(_updateState) Task=`b5ece2e7-eae6-41cd-869c-880abe928f6e`::moving from state preparing -> state finished Thread-56954::DEBUG::2012-05-28 03:20:56,688::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56954::DEBUG::2012-05-28 03:20:56,689::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56954::DEBUG::2012-05-28 03:20:56,690::task::980::TaskManager.Task::(_decref) Task=`b5ece2e7-eae6-41cd-869c-880abe928f6e`::ref 0 aborting False Thread-56959::DEBUG::2012-05-28 03:21:02,969::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56959::DEBUG::2012-05-28 03:21:02,971::task::588::TaskManager.Task::(_updateState) Task=`48ad0981-11fb-4cf9-b954-cb7c301c0272`::moving from state init -> state preparing Thread-56959::INFO::2012-05-28 03:21:02,971::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56959::INFO::2012-05-28 03:21:02,972::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56959::DEBUG::2012-05-28 03:21:02,973::task::1174::TaskManager.Task::(prepare) Task=`48ad0981-11fb-4cf9-b954-cb7c301c0272`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56959::DEBUG::2012-05-28 03:21:02,974::task::588::TaskManager.Task::(_updateState) Task=`48ad0981-11fb-4cf9-b954-cb7c301c0272`::moving from state preparing -> state finished Thread-56959::DEBUG::2012-05-28 03:21:02,974::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56959::DEBUG::2012-05-28 03:21:02,975::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56959::DEBUG::2012-05-28 03:21:02,976::task::980::TaskManager.Task::(_decref) Task=`48ad0981-11fb-4cf9-b954-cb7c301c0272`::ref 0 aborting False Thread-56961::DEBUG::2012-05-28 03:21:06,878::task::588::TaskManager.Task::(_updateState) Task=`16065043-c96c-4865-acb9-b6bd7094aa17`::moving from state init -> state preparing Thread-56961::INFO::2012-05-28 03:21:06,879::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56961::INFO::2012-05-28 03:21:06,880::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00164604187012', 'lastCheck': 1338175261.586043, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00171995162964', 'lastCheck': 1338175258.399656, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00198912620544', 'lastCheck': 1338175257.317448, 'code': 0, 'valid': True}} Thread-56961::DEBUG::2012-05-28 03:21:06,880::task::1174::TaskManager.Task::(prepare) Task=`16065043-c96c-4865-acb9-b6bd7094aa17`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00164604187012', 'lastCheck': 1338175261.586043, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00171995162964', 'lastCheck': 1338175258.399656, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00198912620544', 'lastCheck': 1338175257.317448, 'code': 0, 'valid': True}} Thread-56961::DEBUG::2012-05-28 03:21:06,881::task::588::TaskManager.Task::(_updateState) Task=`16065043-c96c-4865-acb9-b6bd7094aa17`::moving from state preparing -> state finished Thread-56961::DEBUG::2012-05-28 03:21:06,882::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56961::DEBUG::2012-05-28 03:21:06,882::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56961::DEBUG::2012-05-28 03:21:06,883::task::980::TaskManager.Task::(_decref) Task=`16065043-c96c-4865-acb9-b6bd7094aa17`::ref 0 aborting False Thread-56965::DEBUG::2012-05-28 03:21:13,018::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [172.30.0.229] Thread-56965::DEBUG::2012-05-28 03:21:13,019::task::588::TaskManager.Task::(_updateState) Task=`a2b6f77b-c443-440c-80a0-c8afe27c6629`::moving from state init -> state preparing Thread-56965::INFO::2012-05-28 03:21:13,020::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='524a7003-edec-4f52-a38e-b15cadfbe3ef', options=None) Thread-56965::INFO::2012-05-28 03:21:13,021::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56965::DEBUG::2012-05-28 03:21:13,022::task::1174::TaskManager.Task::(prepare) Task=`a2b6f77b-c443-440c-80a0-c8afe27c6629`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'Free', 'spmLver': 17}} Thread-56965::DEBUG::2012-05-28 03:21:13,022::task::588::TaskManager.Task::(_updateState) Task=`a2b6f77b-c443-440c-80a0-c8afe27c6629`::moving from state preparing -> state finished Thread-56965::DEBUG::2012-05-28 03:21:13,023::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56965::DEBUG::2012-05-28 03:21:13,024::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56965::DEBUG::2012-05-28 03:21:13,024::task::980::TaskManager.Task::(_decref) Task=`a2b6f77b-c443-440c-80a0-c8afe27c6629`::ref 0 aborting False Thread-56968::DEBUG::2012-05-28 03:21:17,091::task::588::TaskManager.Task::(_updateState) Task=`8a53fed3-fa89-4317-86ab-96b029f52afc`::moving from state init -> state preparing Thread-56968::INFO::2012-05-28 03:21:17,092::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-56968::INFO::2012-05-28 03:21:17,093::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00132322311401', 'lastCheck': 1338175271.595521, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00182509422302', 'lastCheck': 1338175268.408193, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00145196914673', 'lastCheck': 1338175267.326476, 'code': 0, 'valid': True}} Thread-56968::DEBUG::2012-05-28 03:21:17,094::task::1174::TaskManager.Task::(prepare) Task=`8a53fed3-fa89-4317-86ab-96b029f52afc`::finished: {'fce72110-71ae-46be-8811-2fbeaa001ed2': {'delay': '0.00132322311401', 'lastCheck': 1338175271.595521, 'code': 0, 'valid': True}, '5e2ac537-6a73-4faf-8379-68f3ff26a75d': {'delay': '0.00182509422302', 'lastCheck': 1338175268.408193, 'code': 0, 'valid': True}, '6d931187-2c83-4c33-8693-ca2570f7c136': {'delay': '0.00145196914673', 'lastCheck': 1338175267.326476, 'code': 0, 'valid': True}} Thread-56968::DEBUG::2012-05-28 03:21:17,095::task::588::TaskManager.Task::(_updateState) Task=`8a53fed3-fa89-4317-86ab-96b029f52afc`::moving from state preparing -> state finished Thread-56968::DEBUG::2012-05-28 03:21:17,095::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-56968::DEBUG::2012-05-28 03:21:17,096::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-56968::DEBUG::2012-05-28 03:21:17,097::task::980::TaskManager.Task::(_decref) Task=`8a53fed3-fa89-4317-86ab-96b029f52afc`::ref 0 aborting False
On 28 May, 2012, at 11:09 AM, Shu Ming wrote:
How about your /var/log/vdsm.log in the two nodes? It seems that VDSM got some problems.
On 2012-5-28 11:04, T-Sinjon wrote:
1,on node1, vdsm seems strange , it's sleeping [root@ovirt-node-1 ~]# systemctl status vdsmd.service vdsmd.service - Virtual Desktop Server Manager Loaded: loaded (/lib/systemd/system/vdsmd.service; enabled) Active: active (running) since Mon, 28 May 2012 02:43:22 +0000; 9min ago Process: 1157 ExecStart=/lib/systemd/systemd-vdsmd start (code=exited, status=0/SUCCESS) Main PID: 2228 (respawn) CGroup: name=systemd:/system/vdsmd.service ├ 2228 /bin/bash -e /usr/share/vdsm/respawn --minlifetime... └ 3573 sleep 900 2,no firewall blocked 3,network is ok, i can ssh into node1 from engine
I have used the fence option (confirm host has been rebooted), but SPM did not changed to other node, below is the engine.log when i do this action:
2012-05-28 10:49:51,846 INFO [org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand] (pool-5-thread-49) [72d88732] Lock Acquired to object EngineLock [exclusiveLocks= key: org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand value: ae567034-5d8e-11e1-bdc9-a7168ad4d39f , sharedLocks= ] 2012-05-28 10:49:51,847 INFO [org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand] (pool-5-thread-49) [72d88732] Running command: FenceVdsManualyCommand internal: false. Entities affected : ID: ae567034-5d8e-11e1-bdc9-a7168ad4d39f Type: VDS 2012-05-28 10:49:51,927 INFO [org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand] (pool-5-thread-49) [72d88732] Trying to fence spm ovirt-node-1.local via vds ovirt-node-2.local 2012-05-28 10:49:51,933 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FenceSpmStorageVDSCommand] (pool-5-thread-49) [72d88732] START, FenceSpmStorageVDSCommand(vdsId = a522a6a6-a72e-11e1-baa3-bba876a88ef4, storagePoolId = 524a7003-edec-4f52-a38e-b15cadfbe3ef, prevId=1, prevLVER=17), log id: 530cb694 2012-05-28 10:49:51,965 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-5-thread-49) [72d88732] Command org.ovirt.engine.core.vdsbroker.vdsbroker.FenceSpmStorageVDSCommand return value Class Name: org.ovirt.engine.core.vdsbroker.vdsbroker.StatusOnlyReturnForXmlRpc mStatus Class Name: org.ovirt.engine.core.vdsbroker.vdsbroker.StatusForXmlRpc mCode 654 mMessage Not SPM
2012-05-28 10:49:51,966 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-5-thread-49) [72d88732] Vds: ovirt-node-2.local 2012-05-28 10:49:51,966
[org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-5-thread-49) [72d88732] Command FenceSpmStorageVDS execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM 2012-05-28 10:49:51,966 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FenceSpmStorageVDSCommand] (pool-5-thread-49) [72d88732] FINISH, FenceSpmStorageVDSCommand, log id: 530cb694 2012-05-28 10:49:51,967 WARN [org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand] (pool-5-thread-49) [72d88732] Could not fence spm on vds ovirt-node-2.local 2012-05-28 10:49:51,971 ERROR [org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand] (pool-5-thread-49) [72d88732] Transaction rolled-back for command: org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand. 2012-05-28 10:49:51,971 INFO [org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand] (pool-5-thread-49) [72d88732] Lock freed to object EngineLock [exclusiveLocks= key: org.ovirt.engine.core.bll.storage.FenceVdsManualyCommand value: ae567034-5d8e-11e1-bdc9-a7168ad4d39f , sharedLocks= ] 2012-05-28 10:49:57,457 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-79) hostFromVds::selectedVds - ovirt-node-2.local, spmStatus Free, storage pool BLC 2012-05-28 10:49:57,461 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-79) SPM Init: could not find reported vds or not up - pool:BLC vds_spm_id: 1 2012-05-28 10:49:57,466 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-79) SPM selection - vds seems as spm ovirt-node-1.local 2012-05-28 10:49:57,466 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-79) spm vds is non responsive, stopping spm selection. 2012-05-28 10:50:00,002 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-87) Checking autorecoverable hosts 2012-05-28 10:50:00,004 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-87) Checking autorecoverable hosts done 2012-05-28 10:50:00,004 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-87) Checking autorecoverable storage domains 2012-05-28 10:50:00,006 INFO [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-87) Checking autorecoverable storage domains done 2012-05-28 10:50:07,502 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-93) hostFromVds::selectedVds - ovirt-node-2.local, spmStatus Free, storage pool BLC 2012-05-28 10:50:07,505 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-93) SPM Init: could not find reported vds or not up - pool:BLC vds_spm_id: 1 2012-05-28 10:50:07,510 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-93) SPM selection - vds seems as spm ovirt-node-1.local 2012-05-28 10:50:07,510 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-93) spm vds is non responsive, stopping spm selection. 2012-05-28 10:50:17,551 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-34) hostFromVds::selectedVds - ovirt-node-2.local, spmStatus Free, storage pool BLC 2012-05-28 10:50:17,554 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-34) SPM Init: could not find reported vds or not up - pool:BLC vds_spm_id: 1 2012-05-28 10:50:17,559 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-34) SPM selection - vds seems as spm ovirt-node-1.local 2012-05-28 10:50:17,559 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-34) spm vds is non responsive, stopping spm selection. 2012-05-28 10:50:27,609 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-92) hostFromVds::selectedVds - ovirt-node-2.local, spmStatus Free, storage pool BLC 2012-05-28 10:50:27,612 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-92) SPM Init: could not find reported vds or not up - pool:BLC vds_spm_id: 1 2012-05-28 10:50:27,617 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-92) SPM selection - vds seems as spm ovirt-node-1.local 2012-05-28 10:50:27,618 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-92) spm vds is non responsive, stopping spm selection. 2012-05-28 10:50:37,652 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-67) hostFromVds::selectedVds - ovirt-node-2.local, spmStatus Free, storage pool BLC 2012-05-28 10:50:37,656 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-67) SPM Init: could not find reported vds or not up - pool:BLC vds_spm_id: 1 2012-05-28 10:50:37,661 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-67) SPM selection - vds seems as spm ovirt-node-1.local 2012-05-28 10:50:37,662 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-67) spm vds is non responsive, stopping spm selection. 2012-05-28 10:50:47,709 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-34) hostFromVds::selectedVds - ovirt-node-2.local, spmStatus Free, storage pool BLC 2012-05-28 10:50:47,712 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (QuartzScheduler_Worker-34) SPM Init: could not find reported vds or not up - pool:BLC vds_spm_id: 1
On 28 May, 2012, at 12:08 AM, Haim Ateya wrote:
Hi, first question that comes to mind is why host is in non-responsive state? Please check the following: 1. vdsmd service is running on host side 2. No firewall is blocking comm. in and out 3. No network issue between host and manager
Now, for your question, you can use the manual fence option (confirm host has been rebooted), which will free spm role for faulty host, and engine will elect new spm.
Haim
On May 27, 2012, at 18:32, T-Sinjon < tscbj1989@gmail.com > wrote:
Description of problem:
i have 2 nodes ovirt-node1.local Non Responsive SPM ovirt-node2.local Up None
The SPM node stuck in Non-responsive status, it can't be actived, all vms in the node went into Unknown status and the master vm domain became inactived
when i do "Maintenace" action to node1, it says: Error: Cannot switch Host to Maintenance mode. Host still has running VMs on it and is in Non-Responsive state.
but there has no vm running in node1 , it only has 2 vms in Unknown status
Because I can't active the SPM host , so i can't active the vm storage domain
1,How can i migrated the SPM role to other host in my data center , such us node2? 2,How can i send the node1 to UP status?(I have did 'confirm the host has been Rebooted' action , and rebooted the node1, but it did no sense)
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
-- Shu Ming <shuming@linux.vnet.ibm.com> IBM China Systems and Technology Laboratory