Bug 16318 - NetworkManager holt die DHCP Adresse recht spät für netzwerkbasierte Dienste
Summary: NetworkManager holt die DHCP Adresse recht spät für netzwerkbasierte Dienste
Status: CLOSED FIXED
Alias: None
Product: UCS
Classification: Unclassified
Component: Network
Version: UCS 2.3
Hardware: Other Linux
: P5 normal
Target Milestone: UCS 2.3
Assignee: Andreas Büsching
QA Contact: Arvid Requate
URL:
Keywords:
Depends on:
Blocks: 16323
  Show dependency treegraph
 
Reported: 2009-11-11 10:22 CET by Arvid Requate
Modified: 2009-12-21 08:47 CET (History)
1 user (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):
Customer ID:
Max CVSS v3 score:


Attachments
Die Änderung hat effektiv nichts gebracht, siehe timing profil im Anhang (2.41 KB, application/octet-stream)
2009-11-26 12:29 CET, Arvid Requate
Details
nm-vs-gdm-profil.log.0 (3.01 KB, application/octet-stream)
2009-11-26 13:49 CET, Arvid Requate
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Arvid Requate univentionstaff 2009-11-11 10:22:20 CET
Im Moment wird network-manager in /etc/rc2.d als S26network-manager gestartet, das ist meiner Meinung nach zu spät, da zuvor schon einige Netzwerkdienste gestartet wurden. Ich würde S24hal direkt nach S12dbus starten (quasi S13hal) und danach den NetworkManager. Wenn wir das für Server verwenden, kann das kein low-priority Service sein.
Comment 1 Stefan Gohmann univentionstaff 2009-11-11 14:45:18 CET
Ja, in dem Zuge sollte auch der Start von univention-iptables angepasst werden.
Comment 2 Arvid Requate univentionstaff 2009-11-11 16:00:09 CET
Hal und network-manager wurden so angepasst, dass die Sys-V init Scripte jetzt
als S13hal und S14network-manager direkt nach S12dbus starten.

svn/patches/hal/2.3-0-0-ucs/0.5.11-8/01_start_directly_after_dbus_in_init_sequence.patch

svn/patches/network-manager/2.3-0-0-ucs/0.7.1-1/03_start_directly_after_hal_in_init_sequence.patch

univention-firewall wurde so angepasst, dass univention-iptables als
S15univention-iptables gestartet wird.


Changelog:

Damit NetworkManager vor den eigentlichen Netwerkdiensten gestartet werden
kann, wird der notwendige Hardware Abstraction Layer (HAL) jetzt frühzeitig
direkt nach DBUS gestartet. Damit die Einstellungen für univention-firewall
ebenfalls vor den eigentlichen Netzwerkdiensten aktivert werden, wird
univention-iptables jetzt direkt nach dem Start des NetworkManager Dienstes
initialisiert. \ucsBug{16318}
Comment 3 Stefan Gohmann univentionstaff 2009-11-12 10:02:47 CET
Bitte diverse Installationen mit und ohne DHCP testen.
Comment 4 Felix Botner univentionstaff 2009-11-20 14:00:21 CET
auf mobile clients und managed clients (i386 und amd64) stimmt die Reihenfolge noch nicht:

 S10sysklogd -> ../init.d/sysklogd
 S11klogd -> ../init.d/klogd
 S12acpid -> ../init.d/acpid
 S12dbus -> ../init.d/dbus
 S15univention-iptables -> ../init.d/univention-iptables
 S15univention-runit -> ../init.d/univention-runit
 S16ssh -> ../init.d/ssh
 S20cups -> ../init.d/cups
 S20dirmngr -> ../init.d/dirmngr
 S20nfs-common -> ../init.d/nfs-common
 S20nscd -> ../init.d/nscd
 S20openbsd-inetd -> ../init.d/openbsd-inetd
 S20postfix -> ../init.d/postfix
 S20rsync -> ../init.d/rsync
 S20univention-directory-policy -> ../init.d/univention-directory-policy
 S20univention-management-console-server -> ../init.d/univention-management-console-server
 S21rdate -> ../init.d/rdate
 S23ntp -> ../init.d/ntp
 S24hal -> ../init.d/hal
 S26network-manager -> ../init.d/network-manager
 S30gdm -> ../init.d/gdm
 S32managed-client -> ../init.d/managed-client
 S50univention-directory-listener -> ../init.d/univention-directory-listener
 S89anacron -> ../init.d/anacron
 S89atd -> ../init.d/atd
 S89cron -> ../init.d/cron
 S91apache2 -> ../init.d/apache2
 S97univention-maintenance -> ../init.d/univention-maintenance
 S98usplash -> ../init.d/usplash
 S99rc.local -> ../init.d/rc.local
 S99rmnologin -> ../init.d/rmnologin
 S99stop-bootlogd -> ../init.d/stop-bootlogd


dpkg -l network-manager -> 0.7.1-1.18.200911171558
Comment 5 Arvid Requate univentionstaff 2009-11-20 15:34:29 CET
Die Patches für hal und network-manager wurden disabled, weil sie für den Betrieb auf Servern gedacht waren, was aktuell nicht Entwicklungsziel ist.
Comment 6 Felix Botner univentionstaff 2009-11-20 16:42:05 CET
Dann zu.
Comment 7 Arvid Requate univentionstaff 2009-11-25 15:25:31 CET
Auf Mobile Clients mit DHCP ist das interface beim Start von gdm noch nicht konfiguriert. In manchen Tests ist hat NM selbst nach dem 'sleep 8' im gdm init Script (nach dem Start von GDM) noch keine IP für eth0 konfiguriert.
Das äußert sich darin, dass der Anmeldebildschirm je nach Timing nochmal verschwindet weil GDM neu gestartet wird, wenn das Interface dann endlich seine IP bekommen hat.
Wenn Nichts dagegen spricht, schlage ich vor, die Patches wieder zu aktivieren.
Im Test hat das Nichts an der Boot-Performance geändert, dafür war das Interface mit IP da bevor der gdm gestartet wird.
Comment 8 Stefan Gohmann univentionstaff 2009-11-25 15:47:20 CET
(In reply to comment #7)
> Auf Mobile Clients mit DHCP ist das interface beim Start von gdm noch nicht
> konfiguriert. In manchen Tests ist hat NM selbst nach dem 'sleep 8' im gdm init
> Script (nach dem Start von GDM) noch keine IP für eth0 konfiguriert.
> Das äußert sich darin, dass der Anmeldebildschirm je nach Timing nochmal
> verschwindet weil GDM neu gestartet wird, wenn das Interface dann endlich seine
> IP bekommen hat.
> Wenn Nichts dagegen spricht, schlage ich vor, die Patches wieder zu aktivieren.
> Im Test hat das Nichts an der Boot-Performance geändert, dafür war das
> Interface mit IP da bevor der gdm gestartet wird.

Nein, wir hatten auf unseren Servern während des Updates sehr viel dbus, NetworkManager Probleme beim Starten.

Das eigentliche Problem scheint zu sein, dass der NetworkManager in deinem Fall bis zu 24 Sekunden benötigt, bis er eine IP bekommt. Das ist deutlich zu lange, ich denke der sollte binnen weniger Sekunden durch sein.
Comment 9 Andreas Büsching univentionstaff 2009-11-25 18:54:18 CET
Die 24 Sekunden kann ich auf einem Test Mobile Client gerade nicht bestätigen. Nachdem NM gestartet wurde und den Carrier erkannt hat (1 Sekunde nach dem Kernel) braucht er noch 4 Sekunden um das Interface abschließend zu konfigurieren.

Dadurch dass der NM allerdings erst direkt vor dem GDM gestartet wird, kann es passieren, das der GDM kurz darauf mit einem Reload noch einmal gestartet wird. Das ist unschön.

Hier könnte es helfen hal und NM wieder früher zu starten. Ich halte die vorher beobachteten Verzögerungen eher für ein Problem in unserer dbus Version. Ich teste gerade auf meinem Notebook die Version 1.2.16 (statt 1.2.1)
Comment 10 Stefan Gohmann univentionstaff 2009-11-25 20:10:51 CET
Ein ganz interessanter Bug in diesem Zusammenhang:

http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=495257

Zitat:
----------
A dbus developer also cited a mailing list thread
<http://mail.gnome.org/archives/networkmanager-list/2005-March/msg00022.html>
where it was stated,

"I don't think we should really try to support this.  Restarting D-BUS
should be viewed like trying to live-restart a new kernel.  There's so
many complicated issues in it, and it'll be a rarely-tested code path.
Right now it's a bug that the Fedora D-BUS and NetworkManager RPM
scripts restart after a package upgrade."
----------

> Hier könnte es helfen hal und NM wieder früher zu starten. Ich halte die vorher
> beobachteten Verzögerungen eher für ein Problem in unserer dbus Version. Ich
> teste gerade auf meinem Notebook die Version 1.2.16 (statt 1.2.1)

Es mag sein, dass die beobachteten Probleme auf unsere dbus Version zurückzuführen sind, aber wir werden die Version jetzt nicht mehr aktualisieren können.

@Arvid, kannst du bei dir nochmal prüfen, warum es so lange gedauert hast, bist du eine IP bekommen hast?
Wenn das kein generisches Problem ist, dann sollten wir uns das zur nächsten Version UCS 2.3-1 nochmal genauer anschauen.
Comment 11 Arvid Requate univentionstaff 2009-11-26 09:54:55 CET
Ich hatte in einer VM nebenbei per 'watch' alle 2 sec den Stand der Netzwerkkonfigutation (ifconfig) mitprotokollieren lassen, um herauszubekommen in welcher Phase der NM was macht (Bug 16078 -  Netzwerk wird während des Updates deaktiviert). Zusammen mit der VM-Performance hat das vermutlich zu der großen Verzögerung geführt.
Comment 12 Andreas Büsching univentionstaff 2009-11-26 10:04:13 CET
Folgendes wurde jetzt verändert um das Problem zu verhindern:

- gdm wird erst später (97) gestartet
- univention-directory-policy wird über die if-up event skripte gestartet (ist auch eigentlich besser).
Comment 13 Arvid Requate univentionstaff 2009-11-26 12:29:43 CET
Created attachment 2062 [details]
Die Änderung hat effektiv nichts gebracht, siehe timing profil im Anhang

Direkt nach dem Start des GDM hat das Interface noch keine IP (per DHCP). Das geschieht erst kurze Zeit später. Die drei ifconfig Ausgaben wurden jeweils aus /etc/init.d/gdm heraus erzeugt.
Man sieht auch am Loginbildschirm, dass er nochmal neu gestartet wird, kurz nachdem der Login Prompt erschienen ist.

/etc/rc2.d/S20univention-directory-policy schlägt ausserdem weiterhin fehl, vermutlich weil der fqdn des Masters zu dem Zeitpunkt noch nicht auflösbar ist. Nach dem Boot ist ein /etc/init.d/univention-directory-policy start hingegen erfolgreich möglich.
Comment 14 Arvid Requate univentionstaff 2009-11-26 13:49:13 CET
Created attachment 2063 [details]
nm-vs-gdm-profil.log.0

Ein etwas detailierteres Log, das zeigt, warum die Zeit mittendrin springt.
In diesem Fall setzt NetworkManager die IP schon während des ersten GDM starts, aber über /etc/network/if-up.d/50_gdm kommt es dann erst später noch zum restart des GDM.
Bizarrerweise scheinen die if-up.d Scripte jeweils zwei Mal aufgrufen zu werden?
Comment 15 Andreas Büsching univentionstaff 2009-11-26 21:27:57 CET
Ich konnte das jetzt soweit einschränken, dass die Skripte nur noch einmal ausgeführt werden. Was allerdings bleibt ist das Problem, dass _manchmal_ der DHCP Client bis zu 20 Sekunden braucht um die Adresse zu "verarbeiten". Man sieht das er gestartet wird und vom Server eine Adresse bekommt. dann hat es bis zu 20 Sekunden gedauert, bis der die abschließende Meldung ausgegeben hat. die Zeit ist nicht deterministisch. Auf der selben Maschine hat das zwischen 1 und 20 Sekunden gedauert.

Eine Möglichkeit wäre eventuell:

- Am Anfang des NM  Init-Skript eine Datei anlegen, die erst durch das letzte Hook-Skript entfernt wird.

- der GDM wartet bis diese Datei entfernt wurde und wird erst dann gestartet. Nach max. 20 Sekunden sollte er dann auf jeden Fall starten.

Hier wäre auf jeden Fall zu testen, ob das auch mit statischen Interfaces sauber funktioniert.
Comment 16 Stefan Gohmann univentionstaff 2009-11-27 06:37:17 CET
(In reply to comment #15)
> Ich konnte das jetzt soweit einschränken, dass die Skripte nur noch einmal
> ausgeführt werden. Was allerdings bleibt ist das Problem, dass _manchmal_ der
> DHCP Client bis zu 20 Sekunden braucht um die Adresse zu "verarbeiten". Man
> sieht das er gestartet wird und vom Server eine Adresse bekommt. dann hat es
> bis zu 20 Sekunden gedauert, bis der die abschließende Meldung ausgegeben hat.
> die Zeit ist nicht deterministisch. Auf der selben Maschine hat das zwischen 1
> und 20 Sekunden gedauert.

Mir ist noch nicht ganz klar, was manchmal bedeutet. 

Bei statisch konfigurierten Devices haben wir derzeit kein Problem, richtig?
 
> Eine Möglichkeit wäre eventuell:
> 
> - Am Anfang des NM  Init-Skript eine Datei anlegen, die erst durch das letzte
> Hook-Skript entfernt wird.
> 
> - der GDM wartet bis diese Datei entfernt wurde und wird erst dann gestartet.
> Nach max. 20 Sekunden sollte er dann auf jeden Fall starten.
> 
> Hier wäre auf jeden Fall zu testen, ob das auch mit statischen Interfaces
> sauber funktioniert.

Hmm, und was machen wir, wenn der NM keine IP bekommt? Wird dann immer 20 Sekunden gewartet?

Wir müssen das Problem heute vom Tisch haben, entweder lösen oder verschieben.

Mögliche Ansätze:

1) GDM prüfen: https://bugzilla.gnome.org/show_bug.cgi?id=315846

2) NetworkManager auch von den Managed und Mobile Clients per Default entfernen

3) NetworkManager früher im Bootprozess starten

4) Vor dem NetworkManager Start ein dhclient ausführen, so dass das Interface schon mal eine IP hat und auf den GDM Neustart verzichten

5) Upstream Version des NetworkManagers prüfen, wurde dort ggf. schon etwas behoben?

Ich persönlich bevorzuge 2 und würde in einem SDB Artikel beschreiben, wie der ifplugd ausgetauscht werden kann. Wir sollten vorher aber noch kurz die anderen Punkte prüfen.

Da es ein NetworkManager Problem zu sein scheint, sollten wir das Upstream melden.
Comment 17 Andreas Büsching univentionstaff 2009-11-27 10:05:34 CET
Der NetworkManager wird jetzt nur noch auf dem Mobile Client eingesetzt, da er dort noch einen Mehrwert bringt, der auf anderen Systemrollen nicht so ausschlaggebend ist. Bei Updates wird auch erst einmal der ifplugd beibehalten. Nur bei Neuinstallationen wird der NetworkManager eingesetzt.
Comment 18 Andreas Büsching univentionstaff 2009-11-27 10:54:31 CET
(In reply to comment #17)
> Der NetworkManager wird jetzt nur noch auf dem Mobile Client eingesetzt, da er
> dort noch einen Mehrwert bringt, der auf anderen Systemrollen nicht so
> ausschlaggebend ist. Bei Updates wird auch erst einmal der ifplugd beibehalten.
> Nur bei Neuinstallationen wird der NetworkManager eingesetzt.

univention-server und univention-installer sind angepasst. Neue DVDs werden gerade erstellt
Comment 19 Andreas Büsching univentionstaff 2009-11-27 17:48:48 CET
Die Installation sieht jetzt gut aus. Allerdings joint der Mobile Client am Ende der Installation nicht. Das schaue ich mir am Wochenende an.
Comment 20 Andreas Büsching univentionstaff 2009-11-28 00:39:07 CET
(In reply to comment #19)
> Die Installation sieht jetzt gut aus. Allerdings joint der Mobile Client am
> Ende der Installation nicht. Das schaue ich mir am Wochenende an.

So wie es aussieht hat der Mobile Client während der Installation kein Netz. Daher schlägt der Join-Vorgang fehl. Es gibt im Log Meldung, die darauf hindeuten, dass der NetworkManager auf den HAL-Daemon wartet. Ohne den findet er keine Netzinterfaces.

Vielleicht sollten wir auch hier auf den ifplugd zurückwechseln.
Comment 21 Stefan Gohmann univentionstaff 2009-11-30 06:37:56 CET
(In reply to comment #20)
> (In reply to comment #19)
> > Die Installation sieht jetzt gut aus. Allerdings joint der Mobile Client am
> > Ende der Installation nicht. Das schaue ich mir am Wochenende an.
> 
> So wie es aussieht hat der Mobile Client während der Installation kein Netz.
> Daher schlägt der Join-Vorgang fehl. Es gibt im Log Meldung, die darauf
> hindeuten, dass der NetworkManager auf den HAL-Daemon wartet. Ohne den findet
> er keine Netzinterfaces.
> 
> Vielleicht sollten wir auch hier auf den ifplugd zurückwechseln.

Ist das reproduzierbar? Meines Wissens hat das schon funktioniert. Bekommt der Mobile Client beim nächsten Boot eine IP? Ansonsten sollten wir in den Skripten dhclient aufrufen, siehe svn r13583
Comment 22 Andreas Büsching univentionstaff 2009-11-30 09:14:30 CET
(In reply to comment #21)
> Ist das reproduzierbar? Meines Wissens hat das schon funktioniert.

Das ist bei meinen letzten beiden Installationen passiert.

> Bekommt der
> Mobile Client beim nächsten Boot eine IP?

Ja
Comment 23 Andreas Büsching univentionstaff 2009-11-30 10:14:12 CET
dhclient wird jetzt vor dem Join noch einmal aufgerufen. univention-installer baut gerade.
Comment 24 Andreas Büsching univentionstaff 2009-11-30 18:10:02 CET
Die Installation war jetzt inkl. Join-Vorgang erfolgreich.
Comment 25 Arvid Requate univentionstaff 2009-12-01 15:09:57 CET
Reopen wegen:
 * gdm startet jetzt früher als in UCS 2.2, wo es als S99 gestartet wurde
   und somit leider noch direkt kurz von S97univention-maintenance.

Verified:
 * Installation eines Mobile Client kann am Ende erfolgreich Joinen. Beim Update wird weiterhin ifplugd verwendet (interfaces/handler: ifplugd)

 * die if-up.d Scripte werden pro interface (lo, eth0, all) nur einmal gestartet und laufen wegen ucs_ignore_interface dann nur für eth0. 

 * univention-directory-policy wird über die if-up event skripte gestartet:
   /etc/network/if-up.d/30_univention-directory-policy

 * GDM wird jetzt in S97 gestartet statt bisher (in lenny) in S30
   ( svn/patches/gdm/2.3-0-0-ucs/2.20.7-4lenny1/40_init_99.patch )

Schöneitsfehler:
 * Das init Script univention-directory-policy 'failed' aber weiterhin
   da es vor dem NetworkManager gestartet wird. Nicht kritisch.

Was ggf. jemand anderes nochmal QAen sollte:

 * univention-iptables wird jetzt in S15 gestartet statt bisher in S41
   (hatte Felix schon in Kommentar #c4 beobachtet)
 * Changelog dafür angepasst: 
\item Damit die Einstellungen für univention-firewall vor den eigentlichen
      Netzwerkdiensten aktivert werden, wird univention-iptables jetzt beim
      Systemstart früher aktiviert. \ucsBug{16318}
Comment 26 Arvid Requate univentionstaff 2009-12-01 15:18:24 CET
Weiterhin offen, aber nur bei Neuinstallationen relevant und daher wohl derzeit unkritisch (siehe Kommentar #c16):

  * Wenn der Network-Manager verwendet wird, wird GDM einmal neu gestartet nachdem er am Ende der Bootphase gestartet worden ist und der Loginbildschirm bereits erschienen ist.
Comment 27 Andreas Büsching univentionstaff 2009-12-01 16:04:58 CET
(In reply to comment #25)
> Reopen wegen:
>  * gdm startet jetzt früher als in UCS 2.2, wo es als S99 gestartet wurde
>    und somit leider noch direkt kurz von S97univention-maintenance.

Fixed. gdm baut neu.
Comment 28 Andreas Büsching univentionstaff 2009-12-01 16:19:05 CET
(In reply to comment #25)
>  * univention-iptables wird jetzt in S15 gestartet statt bisher in S41
>    (hatte Felix schon in Kommentar #c4 beobachtet)
>  * Changelog dafür angepasst: 
> \item Damit die Einstellungen für univention-firewall vor den eigentlichen
>       Netzwerkdiensten aktivert werden, wird univention-iptables jetzt beim
>       Systemstart früher aktiviert. \ucsBug{16318}

Bei einem neu installiertem System ist das der Fall. ich prüfe jetzt noch ein aktualisiertes.
Comment 29 Andreas Büsching univentionstaff 2009-12-01 17:13:55 CET
(In reply to comment #28)
> (In reply to comment #25)
> >  * univention-iptables wird jetzt in S15 gestartet statt bisher in S41
> >    (hatte Felix schon in Kommentar #c4 beobachtet)
> >  * Changelog dafür angepasst: 
> > \item Damit die Einstellungen für univention-firewall vor den eigentlichen
> >       Netzwerkdiensten aktivert werden, wird univention-iptables jetzt beim
> >       Systemstart früher aktiviert. \ucsBug{16318}
> 
> Bei einem neu installiertem System ist das der Fall. ich prüfe jetzt noch ein
> aktualisiertes.

Klappt auch beim Update
Comment 30 Arvid Requate univentionstaff 2009-12-01 17:17:34 CET
Verified: gdm startet jetzt mit S99. In wenigstens einem Testfall fiel dadurch der erneute Restart auch nicht mehr auf.
Comment 31 Stefan Gohmann univentionstaff 2009-12-21 08:47:44 CET
UCS 2.3 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".