14.02.2019 19:45, Jiří Sléžka пишет:
Hello,
we are using ovirt 4.2.8.2-1.el7.
One our user probably tried to preview taken snapshot but the task is
stucked and never finished. Also disk is locked.
I'm also have this problem.
I try to use openbaccus project for backup VMs, and all was good (manual
started backup, for example, did his job: take snapshot, copy VM, etc.)
But when I configure a task at night (Sheduled backup VM), It was some
sort of disaster :)
It try to snapshot/copy VM in infinite loop and create dozens images,
all of that tasks have "failed" result.
I was forced to delete it in ovirtengine by hand, but last created task
are stuck. I switch off baccus, because it send queries to snapshots via
API indefinitely, In engine log:
-------------------------------
2019-02-12 03:17:00,659+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-2941) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
2019-02-12 03:17:00,697+04 INFO
[org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default
task-2941) [7feb4bfd] Running command: CreateUserSessionCommand
internal: false.
2019-02-12 03:17:00,704+04 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(default task-2941) [7feb4bfd] EVENT_ID: USER_VDC_LOGIN(30), User
admin@internal-authz connecting from '172.16.10.41' using session 'K
tVU5wRCDZn2ZrPIE4rengdlpt+GdIfjTD6KpPIW45oY4XUfpcUCJH9ry4gRbsO98lQawu8LdMdRZ0zxqUcJKA=='
logged in.
2019-02-12 03:17:00,804+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-2941) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
2019-02-12 03:17:00,863+04 INFO
[org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default
task-2941) [34e0ac0] Running command: CreateUserSessionCommand internal:
false.
2019-02-12 03:17:00,984+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-2941) [2f595966-44e8-4a67-8f55-a3d09836fc4d] Lock Acquired
to object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebe
cf860776f=VM]', sharedLocks=''}'
2019-02-12 03:17:00,985+04 WARN
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-2941) [2f595966-44e8-4a67-8f55-a3d09836fc4d] Validation of
action 'CreateSnapshotForVm' failed for user admin@internal-authz.
Reasons:
VAR__ACTION__CREATE,VAR__TYPE__SNAPSHOT,ACTION_TYPE_FAILED_VM_IS_DURING_SNAPSHOT
2019-02-12 03:17:00,985+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-2941) [2f595966-44e8-4a67-8f55-a3d09836fc4d] Lock freed to
object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebecf8
60776f=VM]', sharedLocks=''}'
2019-02-12 03:17:00,990+04 ERROR
[org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default
task-2941) [] Operation Failed: [Cannot create Snapshot. The VM is
performing an operation on a Snapshot. Please wait for the operat
ion to finish, and try again.]
2019-02-12 03:17:01,033+04 INFO
[org.ovirt.engine.core.sso.servlets.OAuthRevokeServlet] (default
task-2958) [] User admin@internal successfully logged out
2019-02-12 03:17:01,040+04 INFO
[org.ovirt.engine.core.bll.aaa.TerminateSessionsForTokenCommand]
(default task-2955) [6310d15d] Running command:
TerminateSessionsForTokenCommand internal: true.
2019-02-12 03:17:01,231+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-2941) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
2019-02-12 03:17:01,255+04 INFO
[org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default
task-2941) [584a33cc] Running command: CreateUserSessionCommand
internal: false.
2019-02-12 03:17:01,390+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-2941) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
2019-02-12 03:17:01,414+04 INFO
[org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default
task-2941) [4adc6455] Running command: CreateUserSessionCommand
internal: false.
2019-02-12 03:17:01,587+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-2941) [8b27b7bc-a7d1-4d9a-94f0-fbcad58691d0] Lock Acquired
to object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebe
cf860776f=VM]', sharedLocks=''}'
2019-02-12 03:17:01,587+04 WARN
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-2941) [8b27b7bc-a7d1-4d9a-94f0-fbcad58691d0] Validation of
action 'CreateSnapshotForVm' failed for user admin@internal-authz.
Reasons:
VAR__ACTION__CREATE,VAR__TYPE__SNAPSHOT,ACTION_TYPE_FAILED_VM_IS_DURING_SNAPSHOT
2019-02-12 03:17:01,588+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-2941) [8b27b7bc-a7d1-4d9a-94f0-fbcad58691d0] Lock freed to
object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebecf8
60776f=VM]', sharedLocks=''}'
2019-02-12 03:17:01,622+04 ERROR
[org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default
task-2941) [] Operation Failed: [Cannot create Snapshot. The VM is
performing an operation on a Snapshot. Please wait for the operat
ion to finish, and try again.]
2019-02-12 03:17:01,679+04 INFO
[org.ovirt.engine.core.sso.servlets.OAuthRevokeServlet] (default
task-2958) [] User admin@internal successfully logged out
-----------------------------------------------------------------------
Then in log I see some xml dump (134 nested records):
......
<backingStore type='file' index='133'>
<format type='qcow2'/>
<source
file='/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-486e-b1f2-95810cd93468/2a50a181-d8c9-4012-965c-3f2dea021b70'/>
<backingStore type='file' index='134'>
<format type='raw'/>
<source
file='/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-486e-b1f2-95810cd93468/07d862cd-406d-455b-be64-529d5edd7fc2'/>
<backingStore/>
Also in log:
---------------------------
2019-02-12 14:25:37,955+04 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(default task-4082) [906e6cae-f040-4ada-9646-e9c2c213c254] EVENT_ID:
USER_ADD_VM_STARTED(37), VM bacchus_cryptopro.miac_20190212_14281
0 creation was initiated by admin@internal-authz.
2019-02-12 14:25:37,955+04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-4082)
[906e6cae-f040-4ada-9646-e9c2c213c254] BaseAsyncTask::startPollingTask:
Starting to poll task '2b58becd-e7d2-4a70-955c-0aa153a024e2'.
2019-02-12 14:25:37,955+04 INFO
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-4082)
[906e6cae-f040-4ada-9646-e9c2c213c254] BaseAsyncTask::startPollingTask:
Starting to poll task '5f6627b7-71aa-4167-9d9a-94a8642cfa8e'.
2019-02-12 14:25:37,963+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-4074) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
2019-02-12 14:25:37,966+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-4028) [ed551253-1a6f-489e-8d8c-2fde63a3ada4] Lock Acquired
to object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebe
cf860776f=VM]', sharedLocks=''}'
2019-02-12 14:25:37,966+04 WARN
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-4028) [ed551253-1a6f-489e-8d8c-2fde63a3ada4] Validation of
action 'CreateSnapshotForVm' failed for user admin@internal-authz.
Reasons:
VAR__ACTION__CREATE,VAR__TYPE__SNAPSHOT,ACTION_TYPE_FAILED_VM_STATUS_ILLEGAL,VAR__VM_STATUS__NOT_RESPONDING
2019-02-12 14:25:37,967+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-4028) [ed551253-1a6f-489e-8d8c-2fde63a3ada4] Lock freed to
object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebecf8
60776f=VM]', sharedLocks=''}'
2019-02-12 14:25:37,972+04 ERROR
[org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default
task-4028) [] Operation Failed: [Cannot create Snapshot because the VM
is in Not Responding status.]
2019-02-12 14:25:37,989+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-4080) [7d19cf2a-6e06-4b90-a445-1d047b11529b] Lock Acquired
to object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebe
cf860776f=VM]', sharedLocks=''}'
2019-02-12 14:25:37,989+04 WARN
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-4080) [7d19cf2a-6e06-4b90-a445-1d047b11529b] Validation of
action 'CreateSnapshotForVm' failed for user admin@internal-authz.
Reasons:
VAR__ACTION__CREATE,VAR__TYPE__SNAPSHOT,ACTION_TYPE_FAILED_VM_STATUS_ILLEGAL,VAR__VM_STATUS__NOT_RESPONDING
2019-02-12 14:25:37,989+04 INFO
[org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand]
(default task-4080) [7d19cf2a-6e06-4b90-a445-1d047b11529b] Lock freed to
object 'EngineLock:{exclusiveLocks='[f1029df3-36f3-4746-8c58-ebecf8
60776f=VM]', sharedLocks=''}'
2019-02-12 14:25:37,994+04 ERROR
[org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default
task-4080) [] Operation Failed: [Cannot create Snapshot because the VM
is in Not Responding status.]
2019-02-12 14:25:38,012+04 INFO
[org.ovirt.engine.core.sso.servlets.OAuthRevokeServlet] (default
task-4028) [] User admin@internal successfully logged out
.....
2019-02-12 14:25:47,814+04 INFO
[org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer]
(EE-ManagedThreadFactory-engineScheduled-Thread-98) [] VM
'f1029df3-36f3-4746-8c58-ebecf860776f'(cryptopro.miac) moved from
'NotResponding' --> 'Up'
2019-02-12 14:25:48,150+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-4070) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
2019-02-12 14:25:48,172+04 INFO
[org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default
task-4070) [720e0bca] Running command: CreateUserSessionCommand
internal: false.
2019-02-12 14:25:48,178+04 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) [] Failed in
'HSMGetAllTasksStatusesVDS' method
2019-02-12 14:25:48,184+04 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) [] EVENT_ID:
VDS_BROKER_COMMAND_FAILURE(10,802), VDSM ovirtnode6.miac command HSMG
etAllTasksStatusesVDS failed: low level Image copy failed: ('Command
[\'/usr/bin/taskset\', \'--cpu-list\', \'0-31\', \'/usr/bin/nice\',
\'-n\', \'19\', \'/usr/bin/ionice\', \'-c\', \'3\',
\'/usr/bin/qemu-img\', \'convert\', \'-p\', \'-t\
', \'none\', \'-T\', \'none\', \'-f\', \'qcow2\',
u\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-486e-b1f2-95810cd93468/069dc3e6-a925-4fda-a740-b40a81e5e561\',
\'-O\',
\'raw\',
u\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/fd352508-942f-4882-bda4-293aba7616a7/0ba12329-6b6e-4d58-a9fa-f91cf1cf9555\']
failed with rc=1 out=\'\' err=bytearray(b\'qemu
-img: Could not open
\\\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-486e-b1f2-95810cd93468/069dc3e6-a925-4fda-a740-b40a81e5e561\\\':
Failed to get shared "write" lock
\\nIs another process using the image?\\n\')',)
...2019-02-12 14:25:48,189+04 ERROR
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) []
BaseAsyncTask::logEndTaskFailure: Task
'5f6627b7-71aa-4167-9d9a-94a8642cfa8e' (Parent Command 'AddVmFro
mSnapshot', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended
with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to
HSMGetAllTasksStatusesVDS, error = low level Image copy failed:
('Command [\'/usr/bin/taskset\', \'--cpu-list\', \'0-31\',
\'/usr/bin/nice\', \'-n\', \'19\', \'/usr/bin/ionice
\', \'-c\', \'3\', \'/usr/bin/qemu-img\', \'convert\', \'-p\', \'-t\',
\'none\', \'-T\', \'none\', \'-f\', \'qcow2\',
u\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-48
6e-b1f2-95810cd93468/069dc3e6-a925-4fda-a740-b40a81e5e561\', \'-O\',
\'raw\',
u\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/fd352508-942f-4882-bda4-293aba7616a7/0ba12329-6b6e-4d58-
a9fa-f91cf1cf9555\'] failed with rc=1 out=\'\'
err=bytearray(b\'qemu-img: Could not open
\\\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-486e-b1f2-95810cd93468/069dc3e
6-a925-4fda-a740-b40a81e5e561\\\': Failed to get shared "write"
lock\\nIs another process using the image?\\n\')',), code = 261',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to
HSMGetAllTasksStatusesVDS, error = low level Image copy failed:
('Command [\'/usr/bin/taskset\', \'--cpu-list\', \'0-31\',
\'/usr/bin/nice\', \'-n\', \'19\', \'/usr/bin/ioni
ce\', \'-c\', \'3\', \'/usr/bin/qemu-img\', \'convert\', \'-p\', \'-t\',
\'none\', \'-T\', \'none\', \'-f\', \'qcow2\',
u\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-
486e-b1f2-95810cd93468/069dc3e6-a925-4fda-a740-b40a81e5e561\', \'-O\',
\'raw\',
u\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/fd352508-942f-4882-bda4-293aba7616a7/0ba12329-6b6e-4d5
8-a9fa-f91cf1cf9555\'] failed with rc=1 out=\'\'
err=bytearray(b\'qemu-img: Could not open
\\\'/rhev/data-center/mnt/glusterSD/ovirtnode1.miac:_vmstore/01f6fd06-9ad1-4957-bcda-df24dc4cc4f5/images/f195597c-d243-486e-b1f2-95810cd93468/069dc
3e6-a925-4fda-a740-b40a81e5e561\\\': Failed to get shared "write"
lock\\nIs another process using the image?\\n\')',), code = 261'
2019-02-12 14:25:48,190+04 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) []
CommandAsyncTask::endActionIfNecessary: All tasks of command
'9bfb0439-89b4-4e2f-be60-0011c43b098f'
has ended -> executing 'endAction'
2019-02-12 14:25:48,190+04 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) []
CommandAsyncTask::endAction: Ending action for '2' tasks (command ID:
'9bfb0439-89b4-4e2f-be60-0011
c43b098f'): calling endAction '.
2019-02-12 14:25:48,191+04 INFO
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-2242806) []
CommandAsyncTask::endCommandAction [within thread] context: Attempting
to endAction 'AddVmFromSnapshot'
,
2019-02-12 14:25:48,241+04 INFO
[org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default
task-4070) [] User admin@internal successfully logged in with scopes:
ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:pub
lic-authz-search ovirt-ext=token-info:validate
ovirt-ext=token:password-access
...
2019-02-12 14:25:48,665+04 ERROR
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-2242806) [] [within thread]:
endAction for action type AddVmFromSnapshot threw an exception.:
java.lang.ClassCastEx
ception: org.ovirt.engine.core.common.action.VmLeaseParameters cannot be
cast to org.ovirt.engine.core.common.action.MoveOrCopyImageGroupParameters
at
org.ovirt.engine.core.bll.AddVmAndCloneImageCommand.removeVmImages(AddVmAndCloneImageCommand.java:123)
[bll.jar:]
at
org.ovirt.engine.core.bll.AddVmAndCloneImageCommand.removeVmRelatedEntitiesFromDb(AddVmAndCloneImageCommand.java:115)
[bll.jar:]
at
org.ovirt.engine.core.bll.AddVmCommand.endWithFailure(AddVmCommand.java:1413)
[bll.jar:]
at
org.ovirt.engine.core.bll.AddVmFromSnapshotCommand.endWithFailure(AddVmFromSnapshotCommand.java:304)
[bll.jar:]
------------------------------------------------------------------------
Here is a full log:
https://yadi.sk/d/eCIoFBnhZZgYRQ
Task list in ovirtengine webui
Creating VM bacchus_cryptopro.miac_20190212_142810 from Snapshot
bacchus_cryptopro.miac_20190212_142810 in Cluster Default
Started: Feb 12, 2019, 2:25:35 PM
Validating
Completed: Feb 12, 2019, 2:25:35 PM
Executing
Completed: Feb 12, 2019, 2:25:48 PM
Adding VM lease
Completed: Feb 12, 2019, 2:25:38 PM
Copying Image (stuck here)
Started: Feb 12, 2019, 2:25:37 PM
Finalizing
I try to use taskcleaner.sh, and I clean 1 task, but that lines in UI
are not disappear.
Also I would like to unlock disk and clean this task. I can see locked
snapshot and disk
[root@ovirt dbutils]# ./unlock_entity.sh -q -t snapshot -c
Locked snapshots
vm_id | snapshot_id
--------------------------------------+--------------------------------------
f1029df3-36f3-4746-8c58-ebecf860776f |
d95ab426-3fea-4521-b415-284abfbd8d8d
[root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
Locked disks
vm_id | disk_id
--------------------------------------+--------------------------------------
f1029df3-36f3-4746-8c58-ebecf860776f |
f195597c-d243-486e-b1f2-95810cd93468
but no runnig tasks
[root@ovirt dbutils]# ./taskcleaner.sh -o
t
[root@ovirtengine dbutils]# ./taskcleaner.sh -T
t
(-o has a tasks ...)
what is best approach to unlock and clean this?
Also interested in it.
--
Mike
_______________________________________________
Users mailing list -- users@ovirt.org
To unsubscribe send an email to users-le...@ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/W6XDSEN7DJSMDS5ADQWYVORYBPFQ4TR4/
