9:45 a.m.
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.
Here is engine.log
https://pastebin.com/izBJ1BUg
I am not sure what went wrong except one java.lang.NullPointerException
error... Could it be some bug?
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
--------------------------------------+--------------------------------------
df27ee13-9961-41d5-a4eb-bbb0aadf9086 | 58998020-08cb-4c84-8847-0cb6790724ba
[root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
Locked disks
vm_id | disk_id
--------------------------------------+--------------------------------------
df27ee13-9961-41d5-a4eb-bbb0aadf9086 | f6405448-baf8-4cc2-8ee7-798ca11cad10
but no runnig tasks
[root@ovirt dbutils]# ./taskcleaner.sh -o
t
but in ovirt-manager I see this stucked task...
Preview VM Snapshot predsysprep of VM install_10_64bit_LTSB_UK_ucebny -
Started: Feb 12, 2019, 11:28:04 AM
Validating - Completed: Feb 12, 2019, 11:28:04 AM
Executing - Completed: Feb 12, 2019, 11:28:15 AM
Creating Volume - Completed: Feb 12, 2019, 11:28:15 AM
Finalizing - Started: Feb 12, 2019, 11:28:15 AM
what is best approach to unlock and clean this?
Thanks in advance,
Cheers, Jiri
1:31 p.m.
On Thu, Feb 14, 2019 at 11:37 AM Jiří Sléžka <jiri.slezka(a)slu.cz> wrote:
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.
Here is engine.log
https://pastebin.com/izBJ1BUg
I am not sure what went wrong except one java.lang.NullPointerException
error... Could it be some bug?
Indeed, it looks like a bug. Can you open one:
https://bugzilla.redhat.com/enter_bug.cgi?product=ovirt-engine
component = BLL.Virt, team = Virt
please attach your logs too.
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
--------------------------------------+--------------------------------------
df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
58998020-08cb-4c84-8847-0cb6790724ba
[root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
Locked disks
vm_id | disk_id
--------------------------------------+--------------------------------------
df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
f6405448-baf8-4cc2-8ee7-798ca11cad10
but no runnig tasks
[root@ovirt dbutils]# ./taskcleaner.sh -o
t
but in ovirt-manager I see this stucked task...
Preview VM Snapshot predsysprep of VM install_10_64bit_LTSB_UK_ucebny -
Started: Feb 12, 2019, 11:28:04 AM
Validating - Completed: Feb 12, 2019, 11:28:04 AM
Executing - Completed: Feb 12, 2019, 11:28:15 AM
Creating Volume - Completed: Feb 12, 2019, 11:28:15 AM
Finalizing - Started: Feb 12, 2019, 11:28:15 AM
what is best approach to unlock and clean this?
I'm not sure -- hopefully someone else can assist :)
Thanks in advance,
Cheers, Jiri
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)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/FVJTQ25MGI2...
--
GREG SHEREMETA
SENIOR SOFTWARE ENGINEER - TEAM LEAD - RHV UX
Red Hat NA
<https://www.redhat.com/>
gshereme(a)redhat.com IRC: gshereme
<https://red.ht/sig>
2:05 p.m.
Isn’t the code wrong? Seems the function checks for disks or unmanaged
device, and if it is unmanaged non-disk device it still kind of
assumes it’s a disk at line 475?
It’s not common, but any device can be unmanaged
> On 14 Feb 2019, at 16:45, Jiří Sléžka <jiri.slezka(a)slu.cz> wrote:
>
> 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.
>
> Here is engine.log
>
> https://pastebin.com/izBJ1BUg
>
> I am not sure what went wrong except one java.lang.NullPointerException
> error... Could it be some bug?
>
> 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
>
> --------------------------------------+--------------------------------------
> df27ee13-9961-41d5-a4eb-bbb0aadf9086 | 58998020-08cb-4c84-8847-0cb6790724ba
>
> [root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
>
> Locked disks
>
> vm_id | disk_id
>
> --------------------------------------+--------------------------------------
> df27ee13-9961-41d5-a4eb-bbb0aadf9086 | f6405448-baf8-4cc2-8ee7-798ca11cad10
>
> but no runnig tasks
>
> [root@ovirt dbutils]# ./taskcleaner.sh -o
> t
>
> but in ovirt-manager I see this stucked task...
>
> Preview VM Snapshot predsysprep of VM install_10_64bit_LTSB_UK_ucebny -
> Started: Feb 12, 2019, 11:28:04 AM
> Validating - Completed: Feb 12, 2019, 11:28:04 AM
> Executing - Completed: Feb 12, 2019, 11:28:15 AM
> Creating Volume - Completed: Feb 12, 2019, 11:28:15 AM
> Finalizing - Started: Feb 12, 2019, 11:28:15 AM
>
> what is best approach to unlock and clean this?
>
> Thanks in advance,
>
> Cheers, Jiri
>
> _______________________________________________
> Users mailing list -- users(a)ovirt.org
> To unsubscribe send an email to users-leave(a)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/FVJTQ25MGI2...
3:01 p.m.
IIUC it shouldn't get to 475 since it would short-circuit if it isn't a disk
Jiří, can you attach the full engine logs so we can retrace everything that
happened?
On Fri, Feb 15, 2019 at 10:06 PM Michal Skrivanek <
michal.skrivanek(a)redhat.com> wrote:
Isn’t the code wrong? Seems the function checks for disks or
unmanaged
device, and if it is unmanaged non-disk device it still kind of
assumes it’s a disk at line 475?
It’s not common, but any device can be unmanaged
> On 14 Feb 2019, at 16:45, Jiří Sléžka <jiri.slezka(a)slu.cz> wrote:
>
> 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.
>
> Here is engine.log
>
> https://pastebin.com/izBJ1BUg
>
> I am not sure what went wrong except one java.lang.NullPointerException
> error... Could it be some bug?
>
> 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
>
>
--------------------------------------+--------------------------------------
> df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
58998020-08cb-4c84-8847-0cb6790724ba
>
> [root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
>
> Locked disks
>
> vm_id | disk_id
>
>
--------------------------------------+--------------------------------------
> df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
f6405448-baf8-4cc2-8ee7-798ca11cad10
>
> but no runnig tasks
>
> [root@ovirt dbutils]# ./taskcleaner.sh -o
> t
>
> but in ovirt-manager I see this stucked task...
>
> Preview VM Snapshot predsysprep of VM install_10_64bit_LTSB_UK_ucebny -
> Started: Feb 12, 2019, 11:28:04 AM
> Validating - Completed: Feb 12, 2019, 11:28:04 AM
> Executing - Completed: Feb 12, 2019, 11:28:15 AM
> Creating Volume - Completed: Feb 12, 2019, 11:28:15 AM
> Finalizing - Started: Feb 12, 2019, 11:28:15 AM
>
> what is best approach to unlock and clean this?
>
> Thanks in advance,
>
> Cheers, Jiri
>
> _______________________________________________
> Users mailing list -- users(a)ovirt.org
> To unsubscribe send an email to users-leave(a)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/FVJTQ25MGI2...
4:32 a.m.
Hi,
On 2/15/19 10:01 PM, Benny Zlotnik wrote:
IIUC it shouldn't get to 475 since it would short-circuit if it
isn't a disk
Jiří, can you attach the full engine logs so we can retrace everything
that happened?
sure,
https://filesender.cesnet.cz/?s=download&token=a67b3f78-8f65-f559-6a9...
Cheers,
Jiri
On Fri, Feb 15, 2019 at 10:06 PM Michal Skrivanek
<michal.skrivanek(a)redhat.com <mailto:michal.skrivanek@redhat.com>> wrote:
Isn’t the code wrong? Seems the function checks for disks or unmanaged
device, and if it is unmanaged non-disk device it still kind of
assumes it’s a disk at line 475?
It’s not common, but any device can be unmanaged
> On 14 Feb 2019, at 16:45, Jiří Sléžka <jiri.slezka(a)slu.cz
<mailto:jiri.slezka@slu.cz>> wrote:
>
> 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.
>
> Here is engine.log
>
> https://pastebin.com/izBJ1BUg
>
> I am not sure what went wrong except one
java.lang.NullPointerException
> error... Could it be some bug?
>
> 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
>
>
--------------------------------------+--------------------------------------
> df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
58998020-08cb-4c84-8847-0cb6790724ba
>
> [root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
>
> Locked disks
>
> vm_id | disk_id
>
>
--------------------------------------+--------------------------------------
> df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
f6405448-baf8-4cc2-8ee7-798ca11cad10
>
> but no runnig tasks
>
> [root@ovirt dbutils]# ./taskcleaner.sh -o
> t
>
> but in ovirt-manager I see this stucked task...
>
> Preview VM Snapshot predsysprep of VM
install_10_64bit_LTSB_UK_ucebny -
> Started: Feb 12, 2019, 11:28:04 AM
> Validating - Completed: Feb 12, 2019, 11:28:04 AM
> Executing - Completed: Feb 12, 2019, 11:28:15 AM
> Creating Volume - Completed: Feb 12, 2019, 11:28:15 AM
> Finalizing - Started: Feb 12, 2019, 11:28:15 AM
>
> what is best approach to unlock and clean this?
>
> Thanks in advance,
>
> Cheers, Jiri
>
> _______________________________________________
> Users mailing list -- users(a)ovirt.org <mailto:users@ovirt.org>
> To unsubscribe send an email to users-leave(a)ovirt.org
<mailto:users-leave@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/FVJTQ25MGI2...
4:58 a.m.
Hi,
On Thu, Feb 14, 2019 at 11:37 AM Jiří Sléžka <jiri.slezka(a)slu.cz
<mailto:jiri.slezka@slu.cz>> wrote:
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.
Here is engine.log
https://pastebin.com/izBJ1BUg
I am not sure what went wrong except one java.lang.NullPointerException
error... Could it be some bug?
Indeed, it looks like a bug. Can you open one:
https://bugzilla.redhat.com/enter_bug.cgi?product=ovirt-engine
component = BLL.Virt, team = Virt
please attach your logs too.
here it is
https://bugzilla.redhat.com/show_bug.cgi?id=1678234
Cheers,
Jiri
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
--------------------------------------+--------------------------------------
df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
58998020-08cb-4c84-8847-0cb6790724ba
[root@ovirt dbutils]# ./unlock_entity.sh -q -t disk -c
Locked disks
vm_id | disk_id
--------------------------------------+--------------------------------------
df27ee13-9961-41d5-a4eb-bbb0aadf9086 |
f6405448-baf8-4cc2-8ee7-798ca11cad10
but no runnig tasks
[root@ovirt dbutils]# ./taskcleaner.sh -o
t
but in ovirt-manager I see this stucked task...
Preview VM Snapshot predsysprep of VM install_10_64bit_LTSB_UK_ucebny -
Started: Feb 12, 2019, 11:28:04 AM
Validating - Completed: Feb 12, 2019, 11:28:04 AM
Executing - Completed: Feb 12, 2019, 11:28:15 AM
Creating Volume - Completed: Feb 12, 2019, 11:28:15 AM
Finalizing - Started: Feb 12, 2019, 11:28:15 AM
what is best approach to unlock and clean this?
I'm not sure -- hopefully someone else can assist :)
Thanks in advance,
Cheers, Jiri
_______________________________________________
Users mailing list -- users(a)ovirt.org <mailto:users@ovirt.org>
To unsubscribe send an email to users-leave(a)ovirt.org
<mailto:users-leave@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/FVJTQ25MGI2...
--
GREG SHEREMETA
SENIOR SOFTWARE ENGINEER - TEAM LEAD - RHV UX
Red Hat NA
<https://www.redhat.com/>
gshereme(a)redhat.com <mailto:gshereme@redhat.com> IRC: gshereme
<https://red.ht/sig>
7:13 a.m.
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
8:09 a.m.
Hi,
In order to delete all jobs (aka tasks on the UI), I'm using:
truncate table job cascade;
Which is also mentioned here:
https://github.com/oVirt/ovirt-engine/blob/master/packaging/setup/dbutils...
Hope it helps
*Regards,*
*Shani Leviim*
On Mon, Feb 18, 2019 at 3:52 PM Mike Lykov <combr(a)ya.ru> wrote:
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(a)ovirt.org
To unsubscribe send an email to users-leave(a)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/W6XDSEN7DJS...
1899
days inactive
1904
days old
7 comments
6 participants
participants (6)
-
Benny Zlotnik -
Greg Sheremeta -
Jiří Sléžka -
Michal Skrivanek -
Mike Lykov -
Shani Leviim