Beim Starten einer VM bricht mit Fehler OVMAPI_5001E ab

Beim Versuch eine Oracle VM (Version 3.2.x) zu starten, bricht dies immer innerhalb von 1-2 Sekunden mit dem Fehler OVMAPI_5001E ab.

Folgende Fehlermeldungen stehen in /var/log/ovs-agent.log:

[2013-12-11 13:53:13 23831] DEBUG (service:76) call complete: discover_network

	[2013-12-11 13:53:14 23836] ERROR (base:259) async call exception

	Traceback (most recent call last):

	File "/usr/lib64/python2.4/site-packages/agent/api/host/base.py", line 257, in ovs_async_proc

	output = function(*args)

	File "/usr/lib64/python2.4/site-packages/agent/lib/service.py", line 109, in wrapper

	return func(*args)

	File "/usr/lib64/python2.4/site-packages/agent/api/hypervisor/xenxm.py", line 120, in start_vm

	create_vm(path)

	File "/usr/lib64/python2.4/site-packages/agent/lib/xenxm.py", line 148, in create_vm

	run_cmd(['xm', 'create', path])

	File "/usr/lib64/python2.4/site-packages/agent/lib/linux.py", line 49, in run_cmd

	raise RuntimeError('Command: %s failed (%s): stderr: %s stdout: %s'

	RuntimeError: Command: ['xm', 'create', '/OVS/Repositories/0004fb0000030000c99bf484486dfb82/VirtualMachines/0004fb0000060000f3bd399daea9c244/vm.cfg'] failed (1): stderr: Error: Acquire running lock failed: 512 stdout: Using config file "/OVS/Repositories/0004fb0000030000c99bf484486dfb82/VirtualMachines/0004fb0000060000f3bd399daea9c244/vm.cfg".

	

	[2013-12-11 13:53:14 23836] DEBUG (base:269) async call complete: func: start_vm pid: 23836 status: 1 output: Command: ['xm', 'create', '/OVS/Repositories/0004fb0000030000c99bf484486dfb82/VirtualMachines/0004fb0000060000f3bd399daea9c244/vm.cfg'] failed (1): stderr: Error: Acquire running lock failed: 512 stdout: Using config file "/OVS/Repositories/0004fb0000030000c99bf484486dfb82/VirtualMachines/0004fb0000060000f3bd399daea9c244/vm.cfg".

	

	[2013-12-11 13:53:14 23836] INFO (notification:47) Notification sent: {ASYNC_PROC} exit PID 23836

	[2013-12-11 13:53:14 8961] INFO (notificationserver:139) Sending notification: {ASYNC_PROC} exit PID 23836

	[2013-12-11 13:53:15 23845] WARNING (base:323) PID 23836 does not exist in DB.

	[2013-12-11 13:53:15 23845] DEBUG (service:76) call complete: ovs_async_proc_stop

	[2013-12-11 13:53:20 23858] DEBUG (service:76) call complete: discover_network

	[2013-12-11 13:53:26 23873] INFO (xenxm:135) Destroy VM 0004fb0000060000f3bd399daea9c244 failed: Command: ['xm', 'destroy', '0004fb0000060000f3bd399daea9c244'] failed (3): stderr: Error: Domain '0004fb0000060000f3bd399daea9c244' does not exist.

	stdout:

	[2013-12-11 13:53:26 23873] INFO (xenxm:140) Destroy VM migrating-0004fb0000060000f3bd399daea9c244 failed: Command: ['xm', 'destroy', 'migrating-0004fb0000060000f3bd399daea9c244'] failed (3): stderr: Error: Domain 'migrating-0004fb0000060000f3bd399daea9c244' does not exist.

	stdout:

	[2013-12-11 13:53:26 23873] DEBUG (service:76) call complete: stop_vm

Analyse des Problems

Die Analyse ergab, dass beim letzten Stoppen der VM das LOCK File nicht gelöscht wurde.

rm /var/run/ovs-agent/vm-0004fb0000060000f3bd399daea9c244.lock

Es handelt sich um einen Oracle Bug

In der Oracle BUG Database findet man einen immer noch offenen "BUG 16922439 : XENDERROR: ACQUIRE RUNNING LOCK FAILED: 512 STILL SEEN ON OVM 3.2", obwohl die Lösung simpel wäre - man bräuchte nur einen zusätzlichen Check, ob die XEN DOM wirklich noch läuft - einbauen.