Bug 29375 - /umcp/command/uvmm/profile/query liefert keine Daten / Error 502
/umcp/command/uvmm/profile/query liefert keine Daten / Error 502
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UMC - Virtual machines (UVMM)
UCS 3.1
All Linux
: P5 critical (vote)
: UCS 3.1
Assigned To: Philipp Hahn
Lukas Walter
: interim-4
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2012-11-23 13:48 CET by Philipp Hahn
Modified: 2012-12-12 21:09 CET (History)
2 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): Troubleshooting
Max CVSS v3 score:
hahn: Patch_Available+


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Philipp Hahn univentionstaff 2012-11-23 13:48:42 CET
Auf einem frisch installierten System liefert das UMC-Commando zum Abfragen der UVMM Profile keine Daten mehr; es erscheint nach einiger Zeit folgende Meldung:
> An unknown error with status code 502 occurred while connecting to the server, please try again later.
Dadruch lassen sich keine neuen Instanzen mehr anlegen.

/var/log/apache/access.log:
> 192.168.0.191 - - [23/Nov/2012:12:49:55 +0100] "POST /umcp/command/uvmm/profile/query HTTP/1.1" 502 596 "http://xen11.knut.univention.de/univention-management-console/?lang=en-US"

univention-management-console-server -d 99 -n
> 12:49:55.601  RESOURCES   ( INFO    ) : Searching for module providing command uvmm/profile/query
> 12:49:55.601  RESOURCES   ( INFO    ) : Found module uvmm
> 12:49:55.602  MAIN        ( INFO    ) : Passing new request to running module uvmm
> 12:49:55.602  PROTOCOL    ( INFO    ) : Sending UMCP COMMAND REQUEST 135367139552674-65
> 12:49:55.705  MAIN        ( WARN    ) : Socket died (module=uvmm)
> 12:49:55.706  MAIN        ( WARN    ) : Module process uvmm died (pid: 10315, exit status: -1, signal: -1)
> 12:49:55.706  MAIN        ( INFO    ) : Checking for kill timer ()
> 12:49:55.706  MAIN        ( WARN    ) : Cleaning up requests
> 12:49:55.706  MAIN        ( WARN    ) : Invalidating all pending requests 135367139552674-65
> 12:49:55.706  MAIN        ( WARN    ) : Remove inactivity timer
> 12:49:55.717  MAIN        ( PROCESS ) : ModuleProcess: child died
> 12:49:55.717  MAIN        ( WARN    ) : Module process uvmm died (pid: 10315, exit status: 1, signal: -1)
> 12:49:55.717  MAIN        ( INFO    ) : Checking for kill timer ()

UVMM Module:
> 12:49:55.602  PARSER      ( INFO    ) : UMCP REQUEST 135367139552674-65 parsed successfully
> 12:49:55.602  MODULE      ( INFO    ) : Received request 135367139552674-65
> 12:49:55.602  PROTOCOL    ( INFO    ) : Received UMCP COMMAND REQUEST 135367139552674-65
> 12:49:55.602  MODULE      ( INFO    ) : Executing ['uvmm/profile/query']
> 12:49:55.602  MODULE      ( INFO    ) : Sending request NODE_LIST to UVMMd
> 12:49:55.603  MODULE      ( INFO    ) : There are currently 1 threads running
> 12:49:55.603  MODULE      ( INFO    ) : Starting request thread ...
> 12:49:55.603  MODULE      ( INFO    ) : Thread is working on a request
> 12:49:55.603  MODULE      ( INFO    ) : Sending request NODE_LIST to UVMM daemon ...
> 12:49:55.603  MODULE      ( INFO    ) : Setting request arguments ...
> 12:49:55.603  MODULE      ( INFO    ) : Creating UVMM daemon connection
> 12:49:55.603  MODULE      ( INFO    ) : Sending request: Packet:
 command: NODE_LIST
 group: default
 pattern: 
> 12:49:55.605  MODULE      ( INFO    ) : Received response: Packet:
 data: []
 messages: None
 status: OK
> 12:49:55.605  MODULE      ( INFO    ) : Connection to UVMMd is closed
> 12:49:55.605  MODULE      ( INFO    ) : Returning result from UVMMd
> 12:49:55.613  MODULE      ( INFO    ) : Thread returned result: (True, [])

Ein Aufruf per Hand funktioniert allerdings:
# umc-command -U Administrator -P univention uvmm/profile/query -o "nodeURI=qemu://$(hostname -f)/system"
23.11.12 13:01:20.339  DEBUG_INIT
Response: COMMAND
  data length   : 1205
  message length: 1128
  ---
  ARGUMENTS: uvmm/profile/query
MIMETYPE   : application/json
  STATUS   : 200
  MESSAGE  : None
  RESULT   : [{'id': 'cn=Microsoft Windows XP,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'Microsoft Windows XP'}, {'id': 'cn=Microsoft Windows 7,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'Microsoft Windows 7'}, {'id': 'cn=Microsoft Windows 8,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'Microsoft Windows 8'}, {'id': 'cn=Microsoft Windows 2003,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'Microsoft Windows 2003'}, {'id': 'cn=Microsoft Windows 2008,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'Microsoft Windows 2008'}, {'id': 'cn=UCS 2.4,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'UCS 2.4'}, {'id': 'cn=UCS 3.0,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'UCS 3.0'}, {'id': 'cn=UCS 3.1,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'UCS 3.1'}, {'id': 'cn=Other,cn=kvm,cn=Profiles,cn=Virtual Machine Manager,dc=lwauq,dc=lwaca', 'label': 'Other'}]


Ist die nodeURI allerdings defekt (bei mir war es 'qemu:///.../system', also ein Slash zu viel), so bleibt das Kommando einfach hängen.

Firebug hat gezeigt, das getProfiles() aufgerufen ist, wobei options.nodeURI='' ist.
Patche ich dort per FireBug "qemu://xen11.lwauq.lwaca/system" rein, funktioniert die Abfrage.
Comment 1 Philipp Hahn univentionstaff 2012-11-23 13:50:01 CET
Ich habe Bug #29333, insbesondere svn37430 im Verdacht.
Comment 2 Dirk Wiesenthal univentionstaff 2012-11-23 16:44:26 CET
Bug #29333 sollte hier nur noch halbe Probleme machen. Das Widget zeigt jetzt wieder Profile basierend auf dem anderen Widget an. Es wird auf ein ready() gewartet bzw. geprüft.

Aber das grundlegende Problem dieses Bugs bleibt. Im Normalfall wird der Fehler nicht mehr auftreten, kann es aber, wenn ein Nutzer mit (oder ohne) Absicht das Widget leer lässt.

Den Fehler kann ich auch nur sehr schwer "systemweit" beheben. Denn durch Bug #29333 ist klar: Wir müssen '' als Input zulassen.

Außerdem: Anlass dieses Bugs hier war eine recht lasche Überprüfung der Werte in _updateDependencies meinerseits, aber Ursache ist, dass das Backend mit nodeURI='' nicht zurecht kommt. Das sollte es aber, ebenso mit anderen merkwürdigen Eingaben vom Nutzer, die nicht in der Liste stehen ("qemu://irgend.ein.ausgedachtes/system") - der Fehler war schon immer vorhanden.
Comment 3 Philipp Hahn univentionstaff 2012-11-23 18:05:25 CET
(In reply to comment #2)
> Bug #29333 sollte hier nur noch halbe Probleme machen.

Die andere Hälfte kommt unten.

> Aber das grundlegende Problem dieses Bugs bleibt. Im Normalfall wird der Fehler
> nicht mehr auftreten, kann es aber, wenn ein Nutzer mit (oder ohne) Absicht das
> Widget leer lässt.
...
> ... aber Ursache ist, dass das Backend mit
> nodeURI='' nicht zurecht kommt. Das sollte es aber, ebenso mit anderen
> merkwürdigen Eingaben vom Nutzer, die nicht in der Liste stehen
> ("qemu://irgend.ein.ausgedachtes/system") - der Fehler war schon immer
> vorhanden.

Das Problem ist hier, das in /usr/share/pyshared/univention/management/console/modules/uvmm/profiles.py#profile_query() ein IndexError auftritt, der aber nirgendwo ausgegeben wird:
Die Rückgabe ist leer und amit funktioniert self._filter_profile(data[0]) nicht.

- profiles = map( lambda item: { 'id' : item[ 0 ], 'label' : item[ 1 ].name }, self._filter_profiles( data[ 0 ] ) )
+ profiles = [{'id': dn, 'label': item.name} for pd in data for (dn, item) in self._filter_profiles(pd)]

Langfritig sollte an der Stelle, wo die eigentliche Callback-Funktion aufgerufen wird, ein Logging ergänzt werden und ein ordentlicher Fehler an Apache/umc-web-server zurückgegeben werden, damit dieser nicht ewig auf eine Antwort wartet.

svn37466, univention-virtual-machine-manager-daemon_2.0.28-2.420.201211231803

ChangeLog: svn15690
\item An internal bug was fixed, which caused UVMM to hang when no profiles  where found (\ucsBug{29375}).
Comment 4 Lukas Walter univentionstaff 2012-11-26 10:44:12 CET
Das Problem tritt nicht mehr auf.

Changelogeintrag vorhanden,
Verified.
Comment 5 Stefan Gohmann univentionstaff 2012-12-12 21:09:19 CET
UCS 3.1-0 has been released: 
 http://forum.univention.de/viewtopic.php?f=54&t=2125

If this error occurs again, please use "Clone This Bug".