Bug 769001

Summary:

Adding a virtual disk to a VM causes an Exception which keeps the image in state locked

Product:

[Retired] oVirt

Reporter:

Matthias H <redhat>

Component:

ovirt-engine-core

Assignee:

lpeer <lpeer>

Status:

CLOSED WONTFIX

QA Contact:

Severity:

unspecified

Docs Contact:

Priority:

unspecified

Version:

unspecified

CC:

abaron, acathrow, amureini, iheim, michal.skrivanek, ykaul

Target Milestone:

---

Target Release:

3.3.4

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

storage

Fixed In Version:

Doc Type:

Bug Fix

Doc Text:

Story Points:

---

Clone Of:

Environment:

Last Closed:

2012-12-12 12:25:20 UTC

Type:

---

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

Storage

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Attachments:

Description	Flags
Engine log of adding storage to the VM	none
vdsm log of creating a new virtual disk for a VM	none

Description Matthias H 2011-12-19 16:13:07 UTC

Whenever I try to add a Virtual Disk to a VM ovirt throws an exception and the status of the image stays "Image locked".

In the Alerts row it says "Operation Add-Disk failed to complete on VM test."

The LVM volume gets created, but not activated. Activating it manually doesn't change the state in the webadmin. There's no error in the vdsm.log.

I've attached the relevant part from the log.

Comment 1 Matthias H 2011-12-19 16:13:48 UTC

Created attachment 548632 [details]
Engine log of adding storage to the VM

Comment 2 Itamar Heim 2011-12-19 21:01:48 UTC

per your comments on bug 768919 - can you please verify vdsm can launch qemu-img?
in any case, relevant vdsm log will help.

Comment 3 Matthias H 2011-12-20 14:18:06 UTC

(In reply to comment #2)
> per your comments on bug 768919 - can you please verify vdsm can launch
> qemu-img?

# ls -la /usr/bin/qemu-img 
-rwxr-xr-x 1 root root 351520 Jul 23 10:55 /usr/bin/qemu-img

Tried is as user vdsm, yes it should be able to launch it.


> in any case, relevant vdsm log will help.

will follow soon.

Comment 4 Matthias H 2011-12-20 14:23:08 UTC

Created attachment 548844 [details]
vdsm log of creating a new virtual disk for a VM

The logical volume that gets created is:

--- Logical volume ---
LV Name                /dev/834c8c61-a12a-4eb9-a717-e4c3af55c434/9100bb4c-cd4e-44a6-aac8-134ce04be0e2
VG Name                834c8c61-a12a-4eb9-a717-e4c3af55c434
LV UUID                CG2XWL-yKat-b5s0-pLmm-yNKi-PqO3-sAPIpP
LV Write Access        read/write
LV Status              NOT available
LV Size                1.00 GiB
Current LE             8
Segments               1
Allocation             inherit
Read ahead sectors     auto

Comment 5 Matthias H 2011-12-20 16:03:09 UTC

A few more informations: After rebooting the host (don't ask me what changes here) the image is no longer locked.

But I'm unable to add another image, the webadmin says:
Error: Cannot add Virtual Machine Disk. There are already asynchronous running tasks, please retry later.

the ovirt log says:
2011-12-20 16:01:27,849 WARN  [org.ovirt.engine.core.bll.AddDiskToVmCommand] (http-0.0.0.0-8080-3) CanDoAction of action AddDiskToVm failed. Reasons:ACTION_TYPE_FAILED_VM_TASKS_ARE_ALREADY_RUNNING,VAR__ACTION__ADD,VAR__TYPE__VM_DISK

Comment 6 Matthias H 2012-01-09 13:44:34 UTC

This problem still remains.

But I've got some different error messages.

From ovirt.log:

13:41:42,346 ERROR [TxPolicy] javax.ejb.EJBTransactionRolledbackException: CallableStatementCallback; uncategorized SQLException for SQL [{call delete_entity_snapshot_by_command_id(?)}]; SQL state [25P02]; error code [0]; ERROR: current transaction is aborted, commands ignored until end of transaction block; nested exception is org.postgresql.util.PSQLException: ERROR: current transaction is aborted, commands ignored until end of transaction block


from postgressql log:
2012-01-09 13:41:42 UTC ERROR:  structure of query does not match function result type
2012-01-09 13:41:42 UTC DETAIL:  Number of returned columns (7) does not match expected column count (9).
2012-01-09 13:41:42 UTC CONTEXT:  PL/pgSQL function "getdisk_image_dynamicbyimage_id" line 2 at RETURN QUERY
2012-01-09 13:41:42 UTC STATEMENT:  select * from  getdisk_image_dynamicbyimage_id($1)
2012-01-09 13:41:42 UTC ERROR:  current transaction is aborted, commands ignored until end of transaction block
2012-01-09 13:41:42 UTC STATEMENT:  select * from delete_entity_snapshot_by_command_id($1) as result
2012-01-09 13:41:52 UTC ERROR:  structure of query does not match function result type
2012-01-09 13:41:52 UTC DETAIL:  Number of returned columns (7) does not match expected column count (9).
2012-01-09 13:41:52 UTC CONTEXT:  PL/pgSQL function "getdisk_image_dynamicbyimage_id" line 2 at RETURN QUERY
2012-01-09 13:41:52 UTC STATEMENT:  select * from  getdisk_image_dynamicbyimage_id($1)
2012-01-09 13:41:52 UTC ERROR:  current transaction is aborted, commands ignored until end of transaction block
2012-01-09 13:41:52 UTC STATEMENT:  select * from delete_entity_snapshot_by_command_id($1) as result
2012-01-09 13:42:02 UTC ERROR:  structure of query does not match function result type
2012-01-09 13:42:02 UTC DETAIL:  Number of returned columns (7) does not match expected column count (9).
2012-01-09 13:42:02 UTC CONTEXT:  PL/pgSQL function "getdisk_image_dynamicbyimage_id" line 2 at RETURN QUERY
2012-01-09 13:42:02 UTC STATEMENT:  select * from  getdisk_image_dynamicbyimage_id($1)
2012-01-09 13:42:02 UTC ERROR:  current transaction is aborted, commands ignored until end of transaction block
2012-01-09 13:42:02 UTC STATEMENT:  select * from delete_entity_snapshot_by_command_id($1) as result
2012-01-09 13:42:13 UTC ERROR:  structure of query does not match function result type
2012-01-09 13:42:13 UTC DETAIL:  Number of returned columns (7) does not match expected column count (9).
2012-01-09 13:42:13 UTC CONTEXT:  PL/pgSQL function "getdisk_image_dynamicbyimage_id" line 2 at RETURN QUERY
2012-01-09 13:42:13 UTC STATEMENT:  select * from  getdisk_image_dynamicbyimage_id($1)
(and so on)

Comment 7 Matthias H 2012-01-10 15:50:56 UTC

A bit more verbose output from the postgresql log. Hopefully this helps. If you need more, just ask.


2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: select * from  getimagebyimageguid($1)
2012-01-10 15:43:48 UTC DETAIL:  parameters: $1 = 'afa5add2-8a2d-48f7-8fda-664d68710035'
2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: SELECT NULL AS PROCEDURE_CAT, n.nspname AS PROCEDURE_SCHEM, p.proname AS PROCEDURE_NAME, NULL, NULL, NULL, d.description AS REMARKS, 2 AS PROCEDURE_TYPE  FROM pg_catalog.pg_namespace n, pg
_catalog.pg_proc p  LEFT JOIN pg_catalog.pg_description d ON (p.oid=d.objoid)  LEFT JOIN pg_catalog.pg_class c ON (d.classoid=c.oid AND c.relname='pg_proc')  LEFT JOIN pg_catalog.pg_namespace pn ON (c.relnamespace=pn.oid AND pn.nspname='
pg_catalog')  WHERE p.pronamespace=n.oid  AND n.nspname LIKE 'public'  AND p.proname LIKE 'getdisk_image_dynamicbyimage_id'  ORDER BY PROCEDURE_SCHEM, PROCEDURE_NAME 
2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: SELECT n.nspname,p.proname,p.prorettype,p.proargtypes, t.typtype,t.typrelid , p.proargnames, p.proargmodes, p.proallargtypes   FROM pg_catalog.pg_proc p, pg_catalog.pg_namespace n, pg_cata
log.pg_type t  WHERE p.pronamespace=n.oid AND p.prorettype=t.oid  AND n.nspname LIKE 'public'  AND p.proname LIKE 'getdisk_image_dynamicbyimage_id'  ORDER BY n.nspname, p.proname 
2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: SELECT e.typdelim FROM pg_catalog.pg_type t, pg_catalog.pg_type e WHERE t.oid = $1 and t.typelem = e.oid
2012-01-10 15:43:48 UTC DETAIL:  parameters: $1 = '1009'
2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: SELECT a.attname,a.atttypid FROM pg_catalog.pg_attribute a WHERE a.attrelid = 2595442 AND a.attnum > 0 ORDER BY a.attnum 
2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: SELECT 1 FROM pg_catalog.pg_type WHERE typname = $1 AND typinput='array_in'::regproc
2012-01-10 15:43:48 UTC DETAIL:  parameters: $1 = NULL
2012-01-10 15:43:48 UTC LOG:  execute <unnamed>: select * from  getdisk_image_dynamicbyimage_id($1)
2012-01-10 15:43:48 UTC DETAIL:  parameters: $1 = 'afa5add2-8a2d-48f7-8fda-664d68710035'
2012-01-10 15:43:48 UTC ERROR:  structure of query does not match function result type
2012-01-10 15:43:48 UTC DETAIL:  Number of returned columns (7) does not match expected column count (9).
2012-01-10 15:43:48 UTC CONTEXT:  PL/pgSQL function "getdisk_image_dynamicbyimage_id" line 2 at RETURN QUERY
2012-01-10 15:43:48 UTC STATEMENT:  select * from  getdisk_image_dynamicbyimage_id($1)
2012-01-10 15:43:48 UTC ERROR:  current transaction is aborted, commands ignored until end of transaction block

Comment 8 Matthias H 2012-01-13 12:17:46 UTC

This looks like a problem with my database version. I just upgraded from 8.4.9 to 9.1.2 and the problem is gone. Though 8.4.9 should be new enough (with regard to the spec file).

Comment 9 Itamar Heim 2012-12-12 12:25:20 UTC

Closing old bugs. If this issue is still relevant/important in current version, please re-open the bug.