Bug 20024 - Angelegte Xen-Instanz war in UVMM nicht sichtbar, Neustart nötig
Angelegte Xen-Instanz war in UVMM nicht sichtbar, Neustart nötig
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: Virtualization - UVMM
UCS 2.3
Other Linux
: P5 normal (vote)
: UCS 2.4-2
Assigned To: Philipp Hahn
Tim Petersen
:
: 21832 (view as bug list)
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2010-09-16 11:06 CEST by Moritz Muehlenhoff
Modified: 2014-07-15 08:32 CEST (History)
3 users (show)

See Also:
What kind of report is it?: ---
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments
libvirt-0.8.7/src/xen/xen_hypervisor.c (108.68 KB, text/plain)
2011-03-08 11:46 CET, Philipp Hahn
Details
tracebacks in xend.log (451.60 KB, text/plain)
2011-03-25 11:16 CET, Tim Petersen
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Moritz Muehlenhoff univentionstaff 2010-09-16 11:06:17 CEST
Aufgetreten mit UCS 2.4-0 unter i386:

Mehrmals war eine angelegte Maschine im UVMM nicht sichtbar.

Mit "virsh -c xen://$(hostname -f)/" konnte die VM erreicht werden. 
Mit "uvmm nodes default ; uvmm query xen://$(hostname -f)/" war keine Verbindung möglich. Ich musste dann auf dem UVMM-Host den UVMM-daemon neu starten, danach funktionierte es wieder.

Folgende Tracebacks habe ich dabei in der Logdatei gesehen, ich kann sie aber nicht einzelnen Fehlerzuständen zuordnen:

2010-09-13 17:44:32,608 - uvmmd.command - DEBUG - NODE_REMOVE 
xen://bf001.budnikowsky.test/
2010-09-13 17:44:32,634 - uvmmd.unix - ERROR - [4] Exception: Traceback (most 
recent call last):
  File "/usr/lib/python2.4/site-packages/univention/uvmm/unix.py", line 144, 
in handle_command
    res = cmd(self, command)
  File "/usr/lib/python2.4/site-packages/univention/uvmm/commands.py", line 
75, in NODE_REMOVE
    node.node_remove(request.uri)
  File "/usr/lib/python2.4/site-packages/univention/uvmm/node.py", line 635, 
in node_remove
    del nodes[uri]
  File "/usr/lib/python2.4/site-packages/univention/uvmm/node.py", line 610, 
in __delitem__
    super(Node,self).__delitem__(uri)
TypeError: super(type, obj): obj must be an instance or subtype of type

.000. The specified session has been invalidated for some reason.
2010-09-13 17:13:15,959 - uvmmd.node - ERROR - Exception The specified session 
has been invalidated for some r
eason.: Traceback (most recent call last):
  File "/usr/lib/python2.4/site-packages/univention/uvmm/node.py", line 464, 
in update_autoreconnect
    self.conn.domainEventDeregister(self.domainCB)
  File "/usr/lib/python2.4/site-packages/libvirt.py", line 1923, in 
domainEventDeregister
    if ret == -1: raise libvirtError ('virConnectDomainEventDeregister() 
failed', conn=self)
libvirtError: The specified session has been invalidated for some reason.
Comment 1 Philipp Hahn univentionstaff 2010-10-18 20:12:01 CEST
Allgemeines libvirt-Debugging:
Aus bisher unbekanntem Grund befindet sich der libvirtd in folgendem Zustand:
  hypervisor_version = -1

Durch kann zur Laufzeit keine passende Implementierung mehr ausgewählt werden und eine Menge Aufrufe gehen ins Leere; hier einer davon:
#0  virXen_getdomaininfolist (handle=16, first_domain=0, maxids=1, dominfos=0xb5d8c090)
    at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:1080
#1  0xb77c70b0 in virXen_getdomaininfo (handle=-1, first_domain=-1216161636, dominfo=0xb5d8c0a8)
    at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:1112
#2  0xb77c7b88 in xenHypervisorHasDomain (conn=0xa13fc08, id=0)
    at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:2884
#3  0xb77e4ca4 in xenStoreNumOfDomains (conn=0xa13fc08) at /root/libvirt-0.8.3/src/xen/xs_internal.c:570
#4  0xb77ce7c0 in xenUnifiedNumOfDomains (conn=0xa13fc08) at /root/libvirt-0.8.3/src/xen/xen_driver.c:598
#5  0xb778c59f in virConnectNumOfDomains (conn=0xa13fc08) at /root/libvirt-0.8.3/src/libvirt.c:1904
#6  0x08067ff2 in remoteDispatchNumOfDomains (server=0xa108970, client=0xa279e20, conn=0xa13fc08, hdr=0xa2fe200, 
    rerr=0xb5d8c2b4, args=0xb5d8c27c, ret=0xb5d8c220) at /root/libvirt-0.8.3/daemon/remote.c:2921
#7  0x0806bef8 in remoteDispatchClientRequest (server=0xa108970, client=0xa279e20, msg=0xa2be1f0)
    at /root/libvirt-0.8.3/daemon/dispatch.c:527
#8  0x0805d72b in qemudWorker (data=0xa12dd94) at /root/libvirt-0.8.3/daemon/libvirtd.c:1570
#9  0xb76f3506 in start_thread () from /lib/i686/nosegneg/libpthread.so.0
#10 0xb73b56fe in clone () from /lib/i686/nosegneg/libc.so.6


Gesetzt wird dieser Wert an drei Stellen:
# gfind -n 'hypervisor_version *= *-1'
./src/xen/xen_hypervisor.c:1993:        hypervisor_version = -1;
./src/xen/xen_hypervisor.c:2038:    hypervisor_version = -1;
./src/xen/xen_hypervisor.c:2124:    hypervisor_version = -1;
Comment 2 Stefan Gohmann univentionstaff 2010-10-22 19:43:33 CEST
Ich konnte das Problem nur halb reproduzieren. Es sollte eine Instanz gestartet werden, allerdings war kein Speicher mehr verfügbar:
[2010-10-22 19:34:40 17897] ERROR (XendDomainInfo:2217) Device model destroy failed X86_HVM_ImageHandler instance has no attribute 'sentinel_lock'
Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/xen/xend/XendDomainInfo.py", line 2215, in _releaseDevices
    self.image.destroyDeviceModel()
  File "/usr/lib/python2.5/site-packages/xen/xend/image.py", line 562, in destroyDeviceModel
    self.sentinel_lock.acquire()
AttributeError: X86_HVM_ImageHandler instance has no attribute 'sentinel_lock'
[2010-10-22 19:34:40 17897] DEBUG (XendDomainInfo:2221) Releasing devices
[2010-10-22 19:34:40 17897] ERROR (SrvBase:88) Request start failed.
Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/xen/web/SrvBase.py", line 85, in perform
    return op_method(op, req)
  File "/usr/lib/python2.5/site-packages/xen/xend/server/SrvDomain.py", line 77, in op_start
    return self.xd.domain_start(self.dom.getName(), paused)
  File "/usr/lib/python2.5/site-packages/xen/xend/XendDomain.py", line 1041, in domain_start
    dominfo.start(is_managed = True)
  File "/usr/lib/python2.5/site-packages/xen/xend/XendDomainInfo.py", line 456, in start
    XendTask.log_progress(31, 60, self._initDomain)
  File "/usr/lib/python2.5/site-packages/xen/xend/XendTask.py", line 209, in log_progress
    retval = func(*args, **kwds)
  File "/usr/lib/python2.5/site-packages/xen/xend/XendDomainInfo.py", line 2592, in _initDomain
    raise exn
VmError: I need 535552 KiB, but dom0_min_mem is 200704 and shrinking to 200704 KiB would leave only 468012 KiB free.

Kann es sein, dass auf den Systemen, auf denen das Problem aufgetreten ist, der Dom0-Speicher nicht begrenzt ist (grub/xenhopt)?
Comment 3 Arvid Requate univentionstaff 2010-10-25 09:38:36 CEST
Ein analoges Verhalten trat in einer DVS-Testumgebung auch nochmal auf, und liess sich dort durch das Setzen von grub/xenhopt entsprechend Bug #20013 zuverlässig beheben. Bug 20307 Comment 12 weist darauf hin, dass das CPU-Pinning nich unbedingt notwendig ist, die Speicherreservierung per dom0_mem scheint also den Deadlock zu beheben.

*** This bug has been marked as a duplicate of bug 20013 ***
Comment 4 Arvid Requate univentionstaff 2010-10-25 10:00:44 CEST
Bug 20307 Comment 12 hatte ich falsch verstanden, CPU-Pinning scheint doch notwendig. Es sollte daher z.B.
 ucr set grub/xenhopt="dom0_mem=1024M dom0_max_vcpus=1 dom0_vcpus_pin"
gesetzt werden.
Comment 5 Stefan Gohmann univentionstaff 2010-10-25 14:26:27 CEST
Ich habe nochmal weiter versucht das Problem zu reproduzieren. Es ist weder auf i386, noch auf amd64 Systemen aufgetreten. Auch nachdem ich mehrere UVMM's in der Umgebung installiert habe, war es nicht reproduzierbar.

Auf xen4 konnte ich noch die folgende Logmeldung beim Aufruf von 'virsh -c xen+unix:/// list' sehen:
07:54:25.633: error : qemudDispatchServer:1320 : Too many active clients (20), dropping connection

Ich glaube xen4 ist aber wenig aussagekräftig, da dort auch schon KVM installiert war und das System relativ alt ist.


Ggf. sollten die maximal zulässigen Verbindungen für libvirt erhöht werden.

Falls das Problem erneut auftritt sollte libvirt und Xen Debug aktiviert werden. Danach sollte erneut versucht werden das Problem zu reproduzieren.
Comment 6 Philipp Hahn univentionstaff 2010-10-26 12:01:39 CEST
(In reply to comment #5)
> Auf xen4 konnte ich noch die folgende Logmeldung beim Aufruf von 'virsh -c
> xen+unix:/// list' sehen:
> 07:54:25.633: error : qemudDispatchServer:1320 : Too many active clients (20),
> dropping connection

Das sollte eigentlich nicht auftreten, da die virsh-Verbindungen von der Kommandozeile aus nur sehr kurz bestehen. Interaktive-virsh-Sitzungen bzw. jeder UVMM zählt als eine Verbindung. Bei erneutem Auftreten wäre ein 'lsof -p `pidof libvirtd`' bzw. 'netstat -tapn' interessant.

> Ggf. sollten die maximal zulässigen Verbindungen für libvirt erhöht werden.

/etc/libvirt/libvirtd.conf:251
  max_clients = 20

> Falls das Problem erneut auftritt sollte libvirt und Xen Debug aktiviert
> werden. Danach sollte erneut versucht werden das Problem zu reproduzieren.

Für libvirtd kann das (hier: xen)-Debugging über /etc/libvirt/libvirtd.conf konfiguriert werden:
  log_filters="1:xen"
  log_outputs="1:file:/var/log/libvirt/libvirtd.log"

Für libvirt-Clients wie "virsh" und "uvmmd":
  export LIBVIRT_LOG_FILTERS="1:xen"
  export LIBVIRT_LOG_OUTPUTS="1:file:/var/log/libvirt/uvmm.log"

'xen' wird hier als Filter verwendet und bezieht sich auf alle Log-Meldungen, deren Kategorie(=Pfadname) das Wort 'xen' enthält. Über log_level=1 bzw. LIBVIRT_DEBUG=1 kann der Loglevel auch global auf den Debug-Level gesenkt werden. Allerdings loggt libvirt sehr viel...
Comment 7 Philipp Hahn univentionstaff 2010-10-27 14:10:59 CEST
Zum automatisieren eines libvirtd-Restarts kann man folgendes Kommando benutzen:
  diff <(virsh -c xen+unix:/// list --all) <(virsh -c xen:/// list --all) || \
    /etc/init.d/univention-virtual-machine-manager-node-common restart

Zu beachten ist allerdings, daß das durchaus auch einige normale Zustände als Fehler erkennen kann, da sich zwischen den beiden virsh-Aufrufen der Zustand bereits wieder geändert haben kann. Dort dann ggf. sowas:
  #!/bin/bash
  #
  # Restart libvirtd when its output is different from direct xen communication 3 times in a row.
  #
  while true
  do
    sleep 1m
    for ((i=0; i<3; i++))
    do
      if diff <(virsh -c xen+unix:/// list --all) <(virsh -c xen:/// list --all)
      then
        continue 2
      fi
      sleep 1
    done
    /etc/init.d/univention-virtual-machine-manager-node-common restart
  done
Comment 8 Stefan Gohmann univentionstaff 2010-10-27 14:20:28 CEST
Ich hatte gerade bei den Prototypen Tests gesehen, dass die Zustände sich sehr massiv ändern, gerade wenn mehrere Systeme gleichzeitig gestartet werden und das System unter Last ist.
Comment 9 Philipp Hahn univentionstaff 2010-11-04 10:39:12 CET
Bei einem weiteren Debug-versuch mit gdb ist folgendes aufgefallen:

(gdb) bt
#0  xenHypervisorDoV2Sys (handle=17, op=0xb5e1afa0) at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:964
#1  0xb7855dff in virXen_getdomaininfolist (handle=17, first_domain=<value optimized out>, maxids=1, dominfos=0xb5e1b060)
    at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:1062
#2  0xb78560e9 in virXen_getdomaininfo (handle=-1243497620, first_domain=22, dominfo=0xb5e1b078)
    at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:1115
#3  0xb7856bc8 in xenHypervisorHasDomain (conn=0x8a66c80, id=0) at /root/libvirt-0.8.3/src/xen/xen_hypervisor.c:2900
#4  0xb7873d2e in xenStoreDoListDomains (conn=0x8a66c80, priv=<value optimized out>, ids=0x8b612f8, maxids=500)
    at /root/libvirt-0.8.3/src/xen/xs_internal.c:613
#5  0xb7873db9 in xenStoreListDomains (conn=0x8a66c80, ids=0x8b612f8, maxids=500) at /root/libvirt-0.8.3/src/xen/xs_internal.c:646
#6  0xb785dace in xenUnifiedListDomains (conn=0x8a66c80, ids=0x8b612f8, maxids=500) at /root/libvirt-0.8.3/src/xen/xen_driver.c:566
#7  0xb781b6ad in virConnectListDomains (conn=0x8a66c80, ids=0x8b612f8, maxids=500) at /root/libvirt-0.8.3/src/libvirt.c:1870
#8  0x08068721 in remoteDispatchListDomains (server=0x8a32970, client=0x8a89720, conn=0x8a66c80, hdr=0x8b5f030, rerr=0xb5e1b2b4,
    args=0xb5e1b27c, ret=0xb5e1b220) at /root/libvirt-0.8.3/daemon/remote.c:2494
#9  0x0806bef8 in remoteDispatchClientCall (server=0x8a32970, client=0x8a89720, msg=0x8b1f020)
    at /root/libvirt-0.8.3/daemon/dispatch.c:527
#10 remoteDispatchClientRequest (server=0x8a32970, client=0x8a89720, msg=0x8b1f020) at /root/libvirt-0.8.3/daemon/dispatch.c:405
#11 0x0805d72b in qemudWorker (data=0x8a57d3c) at /root/libvirt-0.8.3/daemon/libvirtd.c:1570
#12 0xb7782506 in start_thread () from /lib/i686/nosegneg/libpthread.so.0
#13 0xb74446fe in clone () from /lib/i686/nosegneg/libc.so.6


libvirt-0.8.3/src/xen/xen_hypervisor.c:947
  static int xenHypervisorDoV2Sys(int handle, xen_op_v2_sys* op) {   
  ...
  ret = ioctl(handle, xen_ioctl_hypercall_cmd, (unsigned long) &hc);

Dieser Aufruf liefert ab einem bestimmten Zeitpunkt immer ret=-1 zurück; errno=22=EINVAL

Warum das Handle zum XenHypervisor (/proc/xen/privcmd) plötzlich nicht mehr funktioniert, ist unbekannt. Ggf. hilft hier als Work-Around das Neuöffnen des Handles.

FYI: Der xenUnified-Treiber besteht aus mehreren Einzeltreibern: direkt Kommunikation zum Hypervisor bzw. einem ro-Proxy, Verbindung zum XenD, Verbindung zum XenStore, Parsen der Dateien unter /etc/xen/ mit ggf. Inotify-Überbachung. Ein "virsh list" wendet sich zunächst an den XenStore, dessen Ausgabe aber dann nochmals über den Hypervisor auf Aktualität überprüft wird; das geht dann schief.
Comment 10 Stefan Gohmann univentionstaff 2011-02-28 20:01:55 CET
(In reply to comment #9)
> Dieser Aufruf liefert ab einem bestimmten Zeitpunkt immer ret=-1 zurück;
> errno=22=EINVAL
> 
> Warum das Handle zum XenHypervisor (/proc/xen/privcmd) plötzlich nicht mehr
> funktioniert, ist unbekannt. Ggf. hilft hier als Work-Around das Neuöffnen des
> Handles.

Kannst du das versuchen umzusetzen?
Comment 11 Philipp Hahn univentionstaff 2011-03-04 16:04:41 CET
Heute wieder auf xen15 passiert:
(gdb) break xenHypervisorHasDomain
(gdb) continue
(gdb) set scheduler-locking on
(gdb) print hypervisor_version
$2 = -1
(gdb) print dom_interface_version
$3 = -1
(gdb) print priv->handle
$4 = 16

Dann den Verbindung geschlossen, neu initialisiert und neu aufgebaut:
(gdb) call xenHypervisorClose(conn)
(gdb) set initialized=0
(gdb) call xenHypervisorInit()
(gdb) call xenHypervisorOpen(conn, 0, 0)

(gdb) print hypervisor_version
$8 = 2
(gdb) print dom_interface_version
$9 = 5
(gdb) print priv->handle
$10 = 16

(gdb) set scheduler-locking on
(gdb) detach
Comment 12 Philipp Hahn univentionstaff 2011-03-08 11:46:19 CET
Created attachment 3093 [details]
libvirt-0.8.7/src/xen/xen_hypervisor.c

Gepatchter Version für die Kommunikation mit dem Hypervisor, die <http://code.google.com/p/google-coredumper/> nutzt, um im Fehlerfall einen live-Coredump zu erzeugen, die Verbindung zum Hypervisor schließt und neu öffnet, und ggf. die API-Versionsnummers neu bestimmt.

coredumper:
sed -i -e '/include/s!linux/dirent.h!dirent.h!' src/linuxthreads.c src/linux_syscall_support_unittest.cc

libvirt:
sed -i -e '/^XEN_LIBS/s/$/ -lcoredumper' src/Makefile*
Comment 13 Stefan Gohmann univentionstaff 2011-03-15 07:08:02 CET
*** Bug 21832 has been marked as a duplicate of this bug. ***
Comment 14 Philipp Hahn univentionstaff 2011-03-15 13:24:35 CET
er Patch wurde in überarbeiteter Form eingespielt und libvirt im Scope
ucs-2.4-2 neu gebaut.

svn8946, svn8957, libvirt_0.8.7-1.59.201103151115

Im Fehlerfall sollte eine Meldung geloggt werden. Dazu in
{/etc/univention/templates/files,}/etc/libvirt/libvirtd.conf folgendes
hinzufügen:
  log_filters="1:xen_hypervisor"
  log_outputs="1:file:/var/log/libvirtd.log 1:stderr"

Mir ist derzeit keine Möglichkeit bekannt, die Ursache für den Fehler gezielt
zu reproduzieren. Gefühlt trat der Fehler vorallem dann auf, wenn eine neue
Domain gestartet wurde und das Hostsystem erst einmal freien Speicherplatz
schaffen musste, um diesen der VM zur Verfügung zu stellen.

ChangeLog:
\item In \ucsName{libvirt} wurde eine Änderung vorgenommen, die bei einem 
Verbindungsabbruch zwischen \ucsName{libvirtd} und \ucsName{xend} automatisch
versucht, die Verbindung neu aufzubauen (\ucsBug{20024}).
Comment 15 Philipp Hahn univentionstaff 2011-03-16 15:44:35 CET
Heute Morgen nach dem Hochfahren von xen5 zeigte "virsh list" keine Domänen an. Ein "gdb -p `pidof libvirtd`" hat folgendes gezeigt:
 in_init == 1 <<<<<<<<<<<<<<<<<<<<<
 hypervisor_version == -1
 sys_interface_version == -1
 dom_interface_version == -1

Ein "thread apply all bt" hat allerdings gezeigt, daß keiner der Threads tatsächlich in xenHypervisorInit() mehr war. Das hat verhindert, daß die Verbindung zum Hypervisor nicht neu aufgebaut wurde.

In der Funktion gab es 2 Code-Pfade, bei denen es zu diesem Zustand kommen konnte, was ich jetzt auch noch behoben habe. Genaue Beschreibung siehe <http://www.redhat.com/archives/libvir-list/2011-March/msg00757.html>.

svn8964, libvirt_0.8.7-1.60.201103161541
Comment 16 Philipp Hahn univentionstaff 2011-03-16 16:51:39 CET
Das ist noch die alte Version:
# dpkg-query -W libvirt0 libvirt0-dbg libvirt-bin python-libvirt
libvirt-bin     0.8.7-1.59.201103151115
libvirt0        0.8.7-1.59.201103151115
libvirt0-dbg    0.8.7-1.59.201103151115
python-libvirt  0.8.7-1.59.201103151115

(gdb) print in_init 
$1 = 1
(gdb) print hypervisor_version 
$2 = -1
(gdb) print sys_interface_version 
$3 = -1
(gdb) print dom_interface_version 
$4 = -1
(gdb) thread apply all bt

Thread 8 (Thread 0x40d9c950 (LWP 4664)):
#0  0x00007fa3ef7ffbd6 in poll () from /lib/libc.so.6
#1  0x0000000000418048 in virEventRunOnce () at /tmp/buildd/libvirt-0.8.7/daemon/event.c:589
#2  0x000000000041a9e6 in qemudOneLoop () at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:2244
#3  0x000000000041aeba in qemudRunLoop (opaque=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:2354
#4  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#5  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#6  0x0000000000000000 in ?? ()

Thread 7 (Thread 0x4159d950 (LWP 4665)):
#0  0x00007fa3efa96d29 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1  0x00007fa3f19f2216 in virCondWait (c=0x14ba73c, m=0x80) at /tmp/buildd/libvirt-0.8.7/src/util/threads-pthread.c:108
#2  0x000000000041c31d in qemudWorker (data=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:1566
#3  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#4  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()

Thread 6 (Thread 0x41d9e950 (LWP 4666)):
#0  0x00007fa3efa96d29 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1  0x00007fa3f19f2216 in virCondWait (c=0x14ba73c, m=0x80) at /tmp/buildd/libvirt-0.8.7/src/util/threads-pthread.c:108
#2  0x000000000041c31d in qemudWorker (data=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:1566
#3  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#4  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()

Thread 5 (Thread 0x4259f950 (LWP 4667)):
#0  0x00007fa3efa96d29 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1  0x00007fa3f19f2216 in virCondWait (c=0x14ba73c, m=0x80) at /tmp/buildd/libvirt-0.8.7/src/util/threads-pthread.c:108
#2  0x000000000041c31d in qemudWorker (data=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:1566
#3  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#4  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()

Thread 4 (Thread 0x42da0950 (LWP 4668)):
#0  0x00007fa3efa96d29 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1  0x00007fa3f19f2216 in virCondWait (c=0x14ba73c, m=0x80) at /tmp/buildd/libvirt-0.8.7/src/util/threads-pthread.c:108
#2  0x000000000041c31d in qemudWorker (data=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:1566
#3  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#4  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()

Thread 3 (Thread 0x435a1950 (LWP 4669)):
#0  0x00007fa3efa96d29 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1  0x00007fa3f19f2216 in virCondWait (c=0x14ba73c, m=0x80) at /tmp/buildd/libvirt-0.8.7/src/util/threads-pthread.c:108
---Type <return> to continue, or q <return> to quit---
#2  0x000000000041c31d in qemudWorker (data=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:1566
#3  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#4  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()

Thread 2 (Thread 0x43da2950 (LWP 5333)):
#0  0x00007fa3efa997db in read () from /lib/libpthread.so.0
#1  0x00007fa3f0422f1d in ?? () from /usr/lib/libxenstore.so.3.0
#2  0x00007fa3f0422fd4 in ?? () from /usr/lib/libxenstore.so.3.0
#3  0x00007fa3f04232f8 in ?? () from /usr/lib/libxenstore.so.3.0
#4  0x00007fa3efa92fc7 in start_thread () from /lib/libpthread.so.0
#5  0x00007fa3ef80864d in clone () from /lib/libc.so.6
#6  0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fa3f20fc770 (LWP 4603)):
#0  0x00007fa3efa93715 in pthread_join () from /lib/libpthread.so.0
#1  0x000000000041ec7b in main (argc=<value optimized out>, argv=<value optimized out>) at /tmp/buildd/libvirt-0.8.7/daemon/libvirtd.c:3334
#0  0x00007fa3efa93715 in pthread_join () from /lib/libpthread.so.0
Comment 17 Tim Petersen univentionstaff 2011-03-25 11:16:58 CET
Created attachment 3143 [details]
tracebacks in xend.log

Ich konnte das Problem nicht bewusst reproduzieren, allerdings sind mir beschriebene Tracebacks in der Log auf Xen15 aufgefallen.

Es gab auf xen15 diverse Momente in denen UVMM den Server kurzzeitig nicht fand, in einer Warteschleife hing, etc. - es konnte allerdings scheinbar alles immer mit einem reload und abwarten gelöst werden - zumindest ist mir _bewusst kein Fehler aufgefallen.

Siehe Anhang, ab 2011-03-25 09:50:49


Sollte noch einmal angeschaut werden.
Comment 18 Philipp Hahn univentionstaff 2011-03-25 11:47:30 CET
(In reply to comment #17)
> Created an attachment (id=3143) [details]
> tracebacks in xend.log
> 
> Ich konnte das Problem nicht bewusst reproduzieren, allerdings sind mir
> beschriebene Tracebacks in der Log auf Xen15 aufgefallen.

Folgende Fehlermeldungen sind "normal":
> VmError: Not enough free memory and enable-dom0-ballooning is False, so I cannot release any more.  I need 535552 KiB but only have 350760.

Hier wurde versucht, eine weitere VM zu starten, obwohl auf dem Rechner nicht mehr genügend freier Speicher vorhanden ist. Hier wurde noch probiert, die bereits laufenden VMs duch sog. Ballooning zu verkleinern: in den VMs wird durch einen einen speziellen Ballon-Treiber Speicher alloziert, der dann nach außen durchgereicht und dem Hypervisor zur Verfügung gestellt wird). Für die dom0 ist in /etc/xen/xend.sxp eine Untergrenze definiert (Bug #20013), damit die Prozesse darin nicht den OOM-Killer-Tod sterben.

Durch den Balloon kommt es in dem VMs dazu, daß diese Speicher freiräumen müssen, was ggf. dann zu Swapping führt. Dadurch werden die Maschinen (kurzzeitig) sehr träge und reagieren verzögert. Das passier vermutlich auch auf dem dom0, so daß dadurch dann vermutlich der libvirtd/UVMMd nicht mehr schnell genug mit dem Hypervisor kommunizieren kann, wodurch die Verbindung vermutlich abbricht.

> Es gab auf xen15 diverse Momente in denen UVMM den Server kurzzeitig nicht
> fand, in einer Warteschleife hing, etc. - es konnte allerdings scheinbar alles
> immer mit einem reload und abwarten gelöst werden - zumindest ist mir _bewusst
> kein Fehler aufgefallen.

Das ist dann schon mal deutlich besser als vorher. Mehr ist hier vermutlich nicht mit vertretbaren Aufwand zu erreichen bzw. zu erwarten.
Comment 19 Tim Petersen univentionstaff 2011-03-28 09:19:35 CEST
(In reply to comment #18)
> Das ist dann schon mal deutlich besser als vorher. Mehr ist hier vermutlich
> nicht mit vertretbaren Aufwand zu erreichen bzw. zu erwarten.

Ok, da mir keine groben Fehler mehr aufgefallen sind und sich alles ohne manuelles Eingreifen "von selbst" behoben hat/behebt - setzte ich hier verified!
Comment 20 Sönke Schwardt-Krummrich univentionstaff 2011-04-04 15:47:28 CEST
UCS 2.4-2 wurde veröffentlicht. Sollte der hier beschriebene Bug mit einer
neueren Version von UCS erneut auftreten, so sollte der Bug dupliziert werden:
"Clone This Bug".