[Users] I can't remove VM

Dafna Ron dron at redhat.com
Tue Feb 4 17:02:45 UTC 2014


Any time.
If you manage to reproduce please let us know.

Dafna

On 02/04/2014 05:00 PM, Eduardo Ramos wrote:
> Hi Dafna! Thanks for responding.
>
> In order to collect full logs, I migrated my 61 machines from 16 to 2 
> hosts. When I tried to remove, it worked without any problem. I did 
> not understand why. I'm investigating.
>
> Thanks again for your attention.
>
> On 02/03/2014 11:43 AM, Dafna Ron wrote:
>> please attach full vdsm and engine logs.
>>
>> Thanks,
>>
>> Dafna
>>
>>
>> On 02/03/2014 12:11 PM, Eduardo Ramos wrote:
>>> Hi all!
>>>
>>> I'm having trouble on removing virtual machines. My environment run 
>>> on a ISCSI domain storage. When I try remove, the SPM logs:
>>>
>>> # Start vdsm SPM log #
>>> Thread-6019517::INFO::2014-02-03 
>>> 09:58:09,293::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> deleteImage(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', 
>>> spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> imgUUID='57ba1906-2035-4503-acbc-5f6f077f75cc', postZero='false', 
>>> force='false')
>>> Thread-6019517::INFO::2014-02-03 
>>> 09:58:09,293::blockSD::816::Storage.StorageDomain::(validate) 
>>> sdUUID=c332da29-ba9f-4c94-8fa9-346bb8e04e2a
>>> Thread-6019517::ERROR::2014-02-03 
>>> 09:58:10,061::task::833::TaskManager.Task::(_setError) 
>>> Task=`8cbf9978-ed51-488a-af52-a3db030e44ff`::Unexpected error
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/storage/task.py", line 840, in _run
>>>     return fn(*args, **kargs)
>>>   File "/usr/share/vdsm/logUtils.py", line 42, in wrapper
>>>     res = f(*args, **kwargs)
>>>   File "/usr/share/vdsm/storage/hsm.py", line 1429, in deleteImage
>>>     allVols = dom.getAllVolumes()
>>>   File "/usr/share/vdsm/storage/blockSD.py", line 972, in getAllVolumes
>>>     return getAllVolumes(self.sdUUID)
>>>   File "/usr/share/vdsm/storage/blockSD.py", line 172, in getAllVolumes
>>>     vImg not in res[vPar]['imgs']):
>>> KeyError: '63650a24-7e83-4c0a-851d-0ce9869a294d'
>>> Thread-6019517::INFO::2014-02-03 
>>> 09:58:10,063::task::1134::TaskManager.Task::(prepare) 
>>> Task=`8cbf9978-ed51-488a-af52-a3db030e44ff`::aborting: Task is 
>>> aborted: u"'63650a24-7e83-4c0a-851d-0ce9869a294d'" - code 100
>>> Thread-6019517::ERROR::2014-02-03 
>>> 09:58:10,066::dispatcher::70::Storage.Dispatcher.Protect::(run) 
>>> '63650a24-7e83-4c0a-851d-0ce9869a294d'
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run
>>>     result = ctask.prepare(self.func, *args, **kwargs)
>>>   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare
>>>     raise self.error
>>> KeyError: '63650a24-7e83-4c0a-851d-0ce9869a294d'
>>> Thread-6019518::INFO::2014-02-03 
>>> 09:58:10,087::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getSpmStatus(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> options=None)
>>> Thread-6019518::INFO::2014-02-03 
>>> 09:58:10,088::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getSpmStatus, Return response: {'spm_st': {'spmId': 14, 'spmStatus': 
>>> 'SPM', 'spmLver': 64}}
>>> Thread-6019519::INFO::2014-02-03 
>>> 09:58:10,100::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getAllTasksStatuses(spUUID=None, options=None)
>>> Thread-6019519::INFO::2014-02-03 
>>> 09:58:10,101::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getAllTasksStatuses, Return response: {'allTasksStatus': {}}
>>> Thread-6019520::INFO::2014-02-03 
>>> 09:58:10,109::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None)
>>> Thread-6019520::INFO::2014-02-03 
>>> 09:58:10,681::clusterlock::121::SafeLease::(release) Releasing 
>>> cluster lock for domain c332da29-ba9f-4c94-8fa9-346bb8e04e2a
>>> Thread-6019521::INFO::2014-02-03 
>>> 09:58:11,054::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> repoStats(options=None)
>>> Thread-6019521::INFO::2014-02-03 
>>> 09:58:11,054::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> repoStats, Return response: 
>>> {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': 
>>> '0.00799298286438', 'lastCheck': '5.3', 'code': 0, 'valid': True}, 
>>> u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': 
>>> '0.0197920799255', 'lastCheck': '4.9', 'code': 0, 'valid': True}, 
>>> u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': 
>>> '0.00803208351135', 'lastCheck': '5.3', 'code': 0, 'valid': True}}
>>> Thread-6019520::INFO::2014-02-03 
>>> 09:58:11,732::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> spmStop, Return response: None
>>> Thread-6019523::INFO::2014-02-03 
>>> 09:58:11,835::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getAllTasksStatuses(spUUID=None, options=None)
>>> Thread-6019523::INFO::2014-02-03 
>>> 09:58:11,835::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getAllTasksStatuses, Return response: {'allTasksStatus': {}}
>>> Thread-6019524::INFO::2014-02-03 
>>> 09:58:11,844::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None)
>>> Thread-6019524::ERROR::2014-02-03 
>>> 09:58:11,846::task::833::TaskManager.Task::(_setError) 
>>> Task=`00df5ff7-bbf4-4a0e-b60b-1b06dcaa7683`::Unexpected error
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/storage/task.py", line 840, in _run
>>>     return fn(*args, **kargs)
>>>   File "/usr/share/vdsm/logUtils.py", line 42, in wrapper
>>>     res = f(*args, **kwargs)
>>>   File "/usr/share/vdsm/storage/hsm.py", line 601, in spmStop
>>>     pool.stopSpm()
>>>   File "/usr/share/vdsm/storage/securable.py", line 66, in wrapper
>>>     raise SecureError()
>>> SecureError
>>> Thread-6019524::INFO::2014-02-03 
>>> 09:58:11,855::task::1134::TaskManager.Task::(prepare) 
>>> Task=`00df5ff7-bbf4-4a0e-b60b-1b06dcaa7683`::aborting: Task is 
>>> aborted: u'' - code 100
>>> Thread-6019524::ERROR::2014-02-03 
>>> 09:58:11,857::dispatcher::70::Storage.Dispatcher.Protect::(run)
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run
>>>     result = ctask.prepare(self.func, *args, **kwargs)
>>>   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare
>>>     raise self.error
>>> SecureError
>>> Dummy-6018624::INFO::2014-02-03 
>>> 09:58:14,220::storage_mailbox::674::Storage.MailBox.SpmMailMonitor::(run) 
>>> SPM_MailMonitor - Incoming mail monitoring thread stopped
>>> Thread-34627::INFO::2014-02-03 
>>> 09:58:17,696::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', 
>>> spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> imgUUID='974d9602-8fbe-485b-a12d-59b6c34826b7', 
>>> volUUID='c1bcfe5c-20ab-4f50-a88b-e2e0e1184bf8', options=None)
>>> Thread-34757::INFO::2014-02-03 
>>> 09:58:17,696::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', 
>>> spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> imgUUID='49f65bfd-8592-42b9-9a31-91268402903f', 
>>> volUUID='511e6584-4f19-426d-9379-b223d0c2d9c6', options=None)
>>> Thread-34627::INFO::2014-02-03 
>>> 09:58:17,697::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize, Return response: {'truesize': '10737418240', 
>>> 'apparentsize': '10737418240'}
>>> Thread-34757::INFO::2014-02-03 
>>> 09:58:17,698::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize, Return response: {'truesize': '32212254720', 
>>> 'apparentsize': '32212254720'}
>>> Thread-6019529::INFO::2014-02-03 
>>> 09:58:21,672::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> repoStats(options=None)
>>> Thread-6019529::INFO::2014-02-03 
>>> 09:58:21,673::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> repoStats, Return response: 
>>> {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': 
>>> '0.00730204582214', 'lastCheck': '5.9', 'code': 0, 'valid': True}, 
>>> u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': 
>>> '0.0207469463348', 'lastCheck': '5.3', 'code': 0, 'valid': True}, 
>>> u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': 
>>> '0.00734615325928', 'lastCheck': '5.9', 'code': 0, 'valid': True}}
>>> Thread-243::INFO::2014-02-03 
>>> 09:58:27,800::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', 
>>> spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> imgUUID='50f2c3e9-aa94-4ad1-9c3f-91b452292374', 
>>> volUUID='d7cddb76-a5b7-49ed-9efe-44d92ec18d93', options=None)
>>> Thread-34590::INFO::2014-02-03 
>>> 09:58:27,801::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', 
>>> spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> imgUUID='c36bb1da-babd-47bd-a406-58f0cb529c00', 
>>> volUUID='6ea83f9e-c614-4e11-ab57-314ed4efeeaa', options=None)
>>> Thread-243::INFO::2014-02-03 
>>> 09:58:27,802::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize, Return response: {'truesize': '10737418240', 
>>> 'apparentsize': '10737418240'}
>>> Thread-34590::INFO::2014-02-03 
>>> 09:58:27,803::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize, Return response: {'truesize': '107374182400', 
>>> 'apparentsize': '107374182400'}
>>> Thread-6019535::INFO::2014-02-03 
>>> 09:58:32,337::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> repoStats(options=None)
>>> Thread-6019535::INFO::2014-02-03 
>>> 09:58:32,337::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> repoStats, Return response: 
>>> {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': 
>>> '0.0119340419769', 'lastCheck': '6.6', 'code': 0, 'valid': True}, 
>>> u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': 
>>> '0.0190720558167', 'lastCheck': '6.0', 'code': 0, 'valid': True}, 
>>> u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': 
>>> '0.00720596313477', 'lastCheck': '6.6', 'code': 0, 'valid': True}}
>>> Thread-2017487::INFO::2014-02-03 
>>> 09:58:37,692::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', 
>>> spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', 
>>> imgUUID='827f2d81-dc8c-414e-90d2-75e76b3250a0', 
>>> volUUID='f86ec330-0815-4361-8ce7-abf3318a8939', options=None)
>>> Thread-2017487::INFO::2014-02-03 
>>> 09:58:37,693::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getVolumeSize, Return response: {'truesize': '10737418240', 
>>> 'apparentsize': '10737418240'}
>>> Thread-6019540::INFO::2014-02-03 
>>> 09:58:39,118::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> getAllTasksStatuses(spUUID=None, options=None)
>>> Thread-6019540::INFO::2014-02-03 
>>> 09:58:39,118::logUtils::44::dispatcher::(wrapper) Run and protect: 
>>> getAllTasksStatuses, Return response: {'allTasksStatus': {}}
>>> Thread-6019541::INFO::2014-02-03 
>>> 09:58:39,126::logUtils::41::dispatcher::(wrapper) Run and protect: 
>>> spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None)
>>> Thread-6019541::ERROR::2014-02-03 
>>> 09:58:39,127::task::833::TaskManager.Task::(_setError) 
>>> Task=`1f478485-401b-4b9b-b58b-1e7973cf64a2`::Unexpected error
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/storage/task.py", line 840, in _run
>>>     return fn(*args, **kargs)
>>>   File "/usr/share/vdsm/logUtils.py", line 42, in wrapper
>>>     res = f(*args, **kwargs)
>>>   File "/usr/share/vdsm/storage/hsm.py", line 601, in spmStop
>>>     pool.stopSpm()
>>>   File "/usr/share/vdsm/storage/securable.py", line 66, in wrapper
>>>     raise SecureError()
>>> SecureError
>>> Thread-6019541::INFO::2014-02-03 
>>> 09:58:39,128::task::1134::TaskManager.Task::(prepare) 
>>> Task=`1f478485-401b-4b9b-b58b-1e7973cf64a2`::aborting: Task is 
>>> aborted: u'' - code 100
>>> Thread-6019541::ERROR::2014-02-03 
>>> 09:58:39,130::dispatcher::70::Storage.Dispatcher.Protect::(run)
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run
>>>     result = ctask.prepare(self.func, *args, **kwargs)
>>>   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare
>>>     raise self.error
>>> SecureError
>>> # End vdsm SPM log #
>>>
>>> And after, the cluster elects another SPM.
>>>
>>> The webgui shows on 'events' tab:
>>>
>>> # Start webgui events #
>>> Data Center is being initialized, please wait for initialization to 
>>> complete.
>>> Failed to remove VM _12.147_postgresql_default.sir.inpe.br_apagar 
>>> (User: eduardo.ramos).
>>> # End webgui events #
>>>
>>> Engine logs nothing but normal change of SPM.
>>>
>>> I would like to know how I can identify what is stuck, and if I can 
>>> delete by hand, deleting entry from DB and lvremove.
>>>
>>> Thanks!
>>>
>>>
>>> _______________________________________________
>>> Users mailing list
>>> Users at ovirt.org
>>> http://lists.ovirt.org/mailman/listinfo/users
>>
>>
>
>


-- 
Dafna Ron



More information about the Users mailing list