Erweiterte Suche


Mit dem Wechsel eines älteren Systems auf einen neuen Kernel sollte sich ja nichts tun: Alle alten Programme sollten einfach weiter laufen. In einer berüchtigten Diskussion fordert die Phalanx der Kernelentwickler unmißverständlich, alles menschenmögliche zu tun, um die ABI des Kerneln kompatibel zu halten.

Nach dem Reboot schien alles zu funktionieren. Alles, nur IPv6 nicht. Genaugenommen ging SLAAC auf dem Manangementinterface nicht. Das Netz tauchte in der Routingtabelle auf, aber das Interface bekam keine Adresse.

Erst ein Blick auf die Konsole (kernlog) zeigte eine Unmenge von "Duplicate IP" Meldungen. Hat da ein anderes Gerät die gleiche IP? Evtl sogar die gleiche MAC? Mir selbst sind 1992 mal ein Satz Ethernet-Karten mit identischen MACs ins die Hände gefallen, ein Fabrikationsfehler. Ist das etwa wieder vorgekommen?

Am Switch zeigten zwei Port tatsächlich abwechselnd diese MAC. Beide Ports gehören zu einem Active-Backup-Bundle eines Bonding-Interfaces dieses Servers. Ist etwa das Bonding kaputt? Kurze Suche ergab den Bug 503082, einen Nicht-Bug: Won't fix, work's as designed. WTF?

Der Bug war hier ja gar nicht zutreffend, schließlich steht mein Bonding-Interface auf active-backup, nicht auf balance-xor. Oder vielleicht doch? ifconfig auf beiden Interfaces zeigt, daß beide Slaves des Bondings gleichgroße TX-Counter haben. Eine weitere Nachprüfung zeigt, daß /sys/class/net/bond0/bonding/mode tatsächlich auf balance-xor steht. WTF?

Im Initscript wird der Mode korrekt gesetzt. Das System ist frisch gebootet. Wie kann das sein? Der Versuch den Modus umzustellen scheitetet

# echo 1 > /sys/class/net/bond0/bonding/mode
Error: unable to update mode of bond0 because interface is up. 

Dann eben ausgeschaltet:

# (
 ip link set bond0 down;
 echo 1 > /sys/class/net/bond0/bonding/mode;
 ip link set bond0 up )
Error: unable to update mode of bond0 because it has slaves.

Das ist neu. Das ging vorher. Im Initscript steht eindeutig:

ip link set eth2 name eth down
ip link set eth3 name eth_bak down
echo +eth > /sys/class/net/bond0/bonding/slaves
echo +eth_bak > /sys/class/net/bond0/bonding/slaves
echo 1 > /sys/class/net/bond0/bonding/mode
# ... mehr Einstellungen
ip link set bond0 up

Und beim testweisen Reboot erscheint die Fehlermeldung tatsächlich direkt beim Booten.

Ich habe also die Festlegung des Modus vor die Einbindung der Slaves gelegt, neu gebootet und alles tat prima.

Ursachenforschung

Das Problem ist damit aus der Welt, aber nicht gelöst. Die Frage lautet: Warum konnte das überhaupt geschehen?

Die erste Frage muß also sein, wer, wann und warum diesen Änderung vorgenommen hat. Und das geschah im November 2011. Dort wird auch diskutiert, daß damit Änderungen an verbreiteter Software erforderlich werden, sonst fällt die auf die Nase. Wie ich.

Dort wird auch diskutiert, warum diese Änderung sinnvoll ist. Beim Hinzufügen eines Slaves zum Bundle werden viele modusabhängige Aktivitäten vorgenommen. Diese müßten rückabgewickelt und im neuen Modus neu vorgenommen werden. Ist diese Komplexität es an dieser Stelle wert?

Was wäre eigentlich zu tun? Der Code steht praktisch oben drüber:

/* linux/drivers/net/bonding/bond_sysfs.c */
switch (command[0]) {
 case '+':
   pr_info("%s: Adding slave %s.\n", bond->dev->name, dev->name);
   res = bond_enslave(bond->dev, dev);
   break;
 
 case '-':
   pr_info("%s: Removing slave %s.\n", bond->dev->name, dev->name)$
   res = bond_release(bond->dev, dev);
   break;

Es wäre also ein Leichtes, die bestehenden Interfaces rauszuwerfen, den Modus umzustellen und die Interfaces wieder reinzunehmen. Gut, man muß die Fehlerfälle durchgehen: Was ist, wenn sich ein Interface nicht im neuen Modus einbringen läßt? Was ist wenn alle Interfaces im neuen Modus nicht laufen? Eine Variante wäre eine Warnung und ein Rollback. Eine andere wäre, die Fehlermeldungen auszugeben und das Interface im Zweifel unbenutzbar (weil ohne Slaves) zurückzulassen.

Mit Linus Anspruch, man müsse die Kompatibilität halten, müßte man diese Anstrengungen eben unternehmen. Das das nicht gemacht wird, scheint sysfs keine ABI zu sein.

Ursachenforschung Teil 2

Die eigentliche Ursache liegt aber tiefer. Per Voreinstellung wird der Treiber mit balance-xor initialisiert. Dieser Modus erfordert aber spezielle Vorbereitungen des Switches auf der anderen Seite des Bundels. Mit einfach "anstecken und geht schon" hat das nichts zu tun. Im Gegenteil: Da der Switch nichts von der besonderen Konfiguration weiß, schickt er die Frames eines Interfaces auch zum anderen. Fertig ist der IPv6 DAD.

Das es bei IPv4 klappt, ist eher Zufall. Multicast und Broadcast kommen gleichermaßen durcheinander. Möglicherweise ist dieser Default auch der Grund für die Probleme mit den Streamern einer IPTV Plattform: Diese ertrinken in ihren eigenen Streams.

In einem anderen Ticket wird zuerst versucht, auch unter diesen Umständen DAD korrekt auszuführen. Dies muß aber konzeptionell scheitern, weil man nicht zwischen "das bin ich doch selbst" und "da benutzt jemand anderes meine MAC und meine IP" unterscheiden kann. Im Zweifel ist vom Schlimmsten auszugehen. Dies tut DAD konsequent. Konsequenterweise ist der DAD Fehler im balance-Mode ein "Won't fix", weil die Konfiguration fehlerhaft ist.

Es wäre also ein Doppelpatch angebracht: Zum einen sind die fehlerhaften Defaults auf einen harmloseren Fall umzustellen und zum anderen ist der Aufwand zum Moduswechsel notwendig.

Für die Massenterminierung von PPPoX Verbindungen gab es die Empfehlung, MPD zu nehmen. Das braucht FreeBSD. Ich habe mir ehrlich gesagt wenig Gedanken gemacht, ob die geplante Hardware im Detail passen wird oder nicht. Das war ein Fehler. Man kann leider bei vielen Betriebssytemen (Mainstream oder nicht) immer wieder erleben, daß aktuelle oder alte Hardware nicht unterstützt wird.

Mit dem stabilen FreeBSD 9.0 bootet das System bis in den Installer, der dann keine Festplatten sieht. Der Adaptec RAID 6805 Controller wird nicht unterstützt. Dies ist ein besonders dummer Fall, weil es die Installation grundsätzlich verbietet. Hat man ein System erstmal auf der Platte, findet sich i.d.R. immer ein Weg, fremde Treiber auf- oder Sourcecodeanpassungen vorzunehmen. Aber ohne Platte?

Adaptec bietet einen Treiber für FreeBSD 8.2, der aber nicht auf den Installationsmedien liegt. In Foren finden sich verschiedene Vorschläge, den Treiber auf anderen Medien bereitzustellen, sei es per FreeBSD formatiertem USB (hab ich nicht) oder FAT formatiertem USB mit zwei CDs (ich hab nur ein Laufwerk und das auch nur via BMC).

Das Installmedium

Was liegt näher, als sich selbst ein individuelles Installationmedium zu bauen? Linux Kenntnisse sind ja glücklicherweise vorhanden:

$ wget ftp://ftpv6.plusline.net/pub/FreeBSD/releases/amd64/ISO-IMAGES/8.3/FreeBSD-8.3-RELEASE-amd64-disc1.iso
$ mkdir install-cd
# mount -o loop -t iso9660 FreeBSD-8.3-RELEASE-amd64-disc1.iso install-cd
$ tar -C install-cd -cf - . | (mkdir cd.adaptec; tar -C cd.adaptec -xvpf -)

Eine Kopie des Images steht nun zur Verfügung. Die muß nun modifiziert werden.

$ wget http://download.adaptec.com/raid/aac/unix/aacraid_freebsd_b18668.tgz
$ tar -xzf aacraid_freebsd_b18668.tgz freebsd8/
$ cp -a freebsd8/aacu64.ko cd.adaptec/boot/kernel/
$ chmod u+w cd.adaptec/boot/defaults/loader.conf
$ vi cd.adaptec/boot/defaults/loader.conf 

Damit ist der Treiber an der richtigen Stelle und ja, es funktioniert auch mit FreeBSD 8.3. In der loader.conf muß nun der Treiber auch aktiviert werden. Der Editor ist schon offen, fehlt also noch der Patch.

--- install-cd/boot/defaults/loader.conf        2011-02-17 03:19:19.000000000 +0100
+++ cd.adaptec/boot/defaults/loader.conf        2012-09-17 14:22:48.000000000 +0200
@@ -455,6 +455,7 @@
 ###  Other modules  ##########################################
 ##############################################################

+aacu64_load="YES"              # Adaptec RAID
 aio_load="NO"                  # Asynchronous I/O
 bktr_load="NO"                 # Brooktree Bt848/Bt878 TV/Video Capture Card
 ispfw_load="NO"                        # Qlogic ISP Firmware

Nun noch das bootfähige Medium bauen.

$ mkisofs -R -no-emul-boot -b boot/cdboot -o FreeBSD-8.3-Adaptec-disk1.iso cd.adaptec/

Und davon booten.

Die Scheckminuten

Es bootet. Der Loader läd den Kernel. Er läd das Modul. Die Freude ist groß.

FreeBSD/i386 bootstrap loader, Revision 1.1
 
Loading /boot/defaults/loader.conf /kernel text=0x277391 data=0x3268c+0x332a8 ...
Loading /boot/kernel/aacu64.ko text=0x100042321

Der Loader ist da:

boot-loader-menu

Und dann steht alles. De Zähler ist auf Null. Das Rädchen steht. Absturz.

Versuche mit der 8.2 und anderen Medien blieben erfolglos. Immer ein Absturz, wenn der Loader weiter booten soll.

Und weiter geht's

Irgendwann erwischte mich ein Telefonanruf eines Kunden an dieser Stelle. Ich war eine gute Viertelstunde weg.

Und als ich wieder da war, grinste mich der Installationschirm an. Dieser blöde Loader tut einige Minuten(!) lang gar nichts Sichtbares. Dann geht's plötzlich weiter. Und die Platte steht zur Verfügung. Hurra!

Nach mehreren Fehlversuchen, die durch Kleinigkeiten verursacht wurden, ist das System auf der Platte:

Bei der Automatic-Partitionierung erschienen mir 16G /var und 300G /usr im Mißverhältnis. Also beide Partitionen löschen und neu anlegen. Allerdings ist die zweite Partition immer "Partition to big?". Erst viel später habe ich mitbekommen, daß beim Löschen von /var vor der /tmp Partition eine 16G Lücke reißt, die nicht trivial sichtbar ist. Ich hatte mir die Platte fragmentiert und Platz zwischen den Partitionen verbrannt. FreeBSD schlägt eben nicht, wie dokumentiert, den größten zusammenhängende Bereich vor, sondern den gesamten Restplatz.

Bei dem Anlegen der Nutzeraccounts schlug das System /home/<user> als Verzeichnisbaum vor. Stop! Das liegt auf Root. Da gehört eine extra Partition rein. Also nochmal von vorn.

                         FreeBSD Disklabel Editor

Disk: aacd0     Partition name: aacd0s1 Free: 0 blocks (0MB)

Part      Mount          Size Newfs   Part      Mount          Size Newfs
----      -----          ---- -----   ----      -----          ---- -----
aacd0s1a  /            1024MB UFS2     Y
aacd0s1b  swap         4096MB SWAP
aacd0s1d  /var        32768MB UFS2+S   Y
aacd0s1e  /tmp         1024MB UFS2+S   Y
aacd0s1f  /usr        32768MB UFS2+S   Y
aacd0s1g  /home         208GB UFS2+S   Y

Zum Schluß rebootet das System und endlich läuft alles von der Platte.

Nochmal Adaptec

Unglücklicherweise bootet das System von der Platte ohne den Adpatec Treiber und bleibt so nach dem Kernelladen hängen. Verdammt!

Also nochmal von CD gebootet, und im loader mit "set rootdev=disk1s1a:" (nicht /dev/aacd1s1a) von der Platte weiter gebootet. Dann eingeloggt und via Netzwerk (wie hieß gleich der Treiber, der vom BMC virtualisierte CD Laufwerke erkennt?) das Kernelmodul geholt, loader.conf angepaßt ... Fertig.

Jetzt bootet das System wie gewünscht. Es gibt zwar immer noch die Gedenkminute nach dem Loader, aber ich erschrecke nicht mehr.

Auf dem 5. Deutschen IPv6 Gipfel habe ich die Ehre, einen Vortrag zu den Ankündigungen der letzten Jahre zu halten.

Hier die Folien: Fünf Jahre IPv6 im Rückblick (PDF)

Auszüge

ripe-ipv6-isps

Stand der deutschen ISPs zu heitigen Tag (Quelle RIPEness):

  • 1/3 hat sich gar nicht mit IPv6 beschäftigt
  • 1/3 hat kein IPv6 anliegen
  • 1/3 könnte sich mit IPv6 befassen
    • 1/3 davon bietet sichtbar Dienste an (DNS, Mail, Web)
    • Drei Handvoll Provider mit IPv6 im Hosting
    • Eine Handvoll Provider mit IPv6 im Access

Das ist einfach nur peinlich.

Aktueller Stand beim IPv6 Rat

  • DAX30: 0 (in Worten: Null)
  • Alexa 100: 12
  • Exemplarisch GMX
    • Kein IPv6
    • Rate-Limits per IP (CGNs ausgeschlossen)
  • Exemplarisch BITKOM, Fortinet, 1&1, O2
    • Nur DNS und beim IPv6 Day
  • Exemplarisch DTAG
    • DNS, Web und Mail seit IPv6 Launch Day aktiv
    • Seit August 2012 Ausfall von SMTP über IPv6
    • AAAA für MXe sind immer noch im DNS

Wo stehen wir im Projektplan?

  • Planung: 1996-2000
  • Begeisterung: 2000-2006
  • Ernüchterung: 2006-2011
  • Massenflucht der Verantwortlichen:2011-2014
  • Bestrafung der Unschuldigen: 2014-2017
  • Auszeichnung der Nichtbeteiligten: 2017-2020

Und wer ist für die Auszeichung eigentlich geeignet?

  • DE-CIX für IPv6 Peerings ab 2001
  • SpaceNet für IPv6 im Access ab 2003
  • DTAG für die Ankündigung von IPv6 im Access bis zum Jahresende seit 2004
  • DTAG für die Vorstandsentscheidung: "IPv6 ist Infrastruktur, kein Produkt" im Jahr 2006
  • Strato für IPv6 im Hosting seit 2009
  • Tagesschau für den Aprilscherz im Jahre 2010

Der MPD tut an sich zuverlässig für PPPoE Terminierung. Wenn es aber zu Abstürzen des zugrundeliegenden Systems kommt, bekommen die anderen LNS im Verbund die wegfallenden Teilnehmer mit einem Schlag ab. Und dann können andere System ebenfalls zusammenbrechen.

Genauere Beobachtung des Effektes zeigt, daß der nächste LNS ca. 10min später abstürzt. In einigen Fällen meldet er vorher noch den Verlust einer oder mehrerer L2TP Sessions. Als Gründe werden i.d.R. angegeben:

mpd: L2TP: Control connection X terminated: 6 (Control channel timeout - Remote peer dead)
mpd: L2TP: Control connection Y terminated: 6 (expecting reply; none received)

Rückfrage beim Carrier ergibt, daß er kurz vorher schon einen ähnlichen Eintrag in seinem Log hat. Dort wird ebenfalls die L2TP Verbindung für tot erklärt.

Wie kommt es dazu? Der MPD arbeitet doch weiter? Er meldet aber immer wieder im Log.

mpd: Daemon overloaded, ignoring request.

Normalerweise tritt dieser Eintrag selten auf. Wenn die Maschine nachts mit den von den Kunden in vorauseilendem Gehorsam verursachten "Zwangs"-Trennungen loslegt, tritt so ein Eintrag ein bis zehnmal pro Sekunde auf.

Nach dem Absturz eines LNS werden aber schlagartig alle Kunden auf die anderen LNS verteilt. Dann ist die Überlast fast übermächtig. Vierhundert bis sechshundert Verbindungsaufbauten pro Sekunde sind dann der Normalfall.

Im MPD ist ein Überlastschutz eingebaut. Er stellt sich einfach tot:

if (OVERLOAD()) {
   Log(LG_PHYS, ("Daemon overloaded, ignoring request."));
   goto failed;
}

Damit er nicht die Arbeit völlig einstellt, kommt eine zufällige Anzahl von Verbindungsversuchen trotzdem durch:

#define OVERLOAD()            (gOverload > (random() % 100))

Allerdings erreicht der Wert von gOverload schnell die 100. Dann stellt sich der Daemon wirklich tot.

  #define SETOVERLOAD(q)        do {                                    \
                                    int t = (q);                        \
                                    if (t > 60) {                       \
                                        gOverload = 100;                \
                                    } else if (t > 10) {                \
                                        gOverload = (t - 10) * 2;       \
                                    } else {                            \
                                        gOverload = 0;                  \
                                    }                                   \
                                } while (0)

Und genau das fällt dem LAC auf. Er trennt die L2TP Session zu dem vermeindlich "toten" Peer. Damit antwortet er auch selbst nicht mehr auf die Pakete des LNS im gerade geschlossenen Kanal. Und nun macht auch der LNS die Pforten dicht. Wieder fallen Tausende von Kunden aus dem Netz.

Die Lösung ist so einfach wie nur möglich. Ich habe die Berechnungsvorschrift für gOverload geändert:

/* SETOVERLOAD: can reach 0 .. 98 */
gOverload = (q < 10) ? 0 : (99.0 * (1.0 - 10.0/q));

Nun gibt es immer eine Chance eine neue Verbindung durchzubekommen.

Der LAC ist happy, weil er den Tunnel nicht länger verliert. Der LNS ist happy, weil er unter Last nicht zusammenbrechen muß, sondern weiterhin Aufgaben verweigern kann.

Leider ist das Verfahren doch zu einfach gestrickt. Es kommen unter Last so viele Neuverbindungen noch durch, daß deren Behandlung das betroffene System mächtig belastet. Die LACs erkennen trotzdem auf "Dead Peer" und das Spiel geht von vorne los. Nun müßte man die Implementierung des kommerziellen LAC kennen, um zu wissen, woran ein Peer als "tot" erkannt wird. Aber das definitiv zu erfahren, ist wohl unmöglich.

Was kann man tun? Zum einen ist zu kontrollieren, ob vom Overload auch die Pakete des Control Channels betroffen sind. Andererseits sollte der LNS sich im Überlastfall nicht tot stellen, sondern eine klare Fehlermeldung an den LAC schicken. Da hilft nur, die Standards zu lesen.

Aber zuerstmal zurück zu striktem Overload:

static void
update_overload(void) {
   int i,o=0;
   time_t now;
   static time_t last_reported = 0;
   static int peak[2] = {0};

   time(&now);

   for(i=0; i<sizeof(queue)/sizeof(*queue); i++)
     if(queue[i].port) {
        int l = mesg_port_qlen(queue[i].port);
        o += l * (2 + queue[i].max_workers);
        if(peak[i] < l)
          peak[i] = l;
     }

   /* SETOVERLOAD */
   gOverload = (o < 10) ? 0 : (o < 110) ? o-10 : 100;

   if(now > last_reported) {
      Log(LG_ALWAYS, ("Queues had up to %d (serial) and %d (parallel) entries."$
                      peak[0], peak[1]));
      peak[0] = 0;
      peak[1] = 0;
      last_reported = now + (60 - 1);  /* 1 second due to strict less then */
   }

}

Wirklich tot?

Eine genauere Überprüfung des MPD-Codes ergab, daß sich hinter dem goto failed doch eine Benachrichtigung des LAC findet. Diese meldet eine temporäre Überlastung ohne weitere Angaben. Trotzdem klassifiziert der LAC den LNS als tot.

Offenbar genügt der temporäre Fehler dem LAC nicht, um einen anderen LNS zu probieren. Immer und immer wieder wirft er ein und dieselbe Anmeldung dem gleichen LNS vor.

Aber es gibt ja "LNS guided LAC" und das sollte dort wirklich stehen.

--- mpd-5.6/src/l2tp.c  2011-12-21 15:58:49.000000000 +0100
+++ mpd-5.6-lutz/src/l2tp.c     2013-06-09 16:40:35.000000000 +0200
@@ -1112,6 +1123,7 @@
        Link    l = NULL;
        L2tpInfo pi = NULL;
        int     k;
+       char const * failreason = NULL;

        /* Convert AVP's to friendly form */
        if ((ptrs = ppp_l2tp_avp_list2ptrs(avps)) == NULL) {
@@ -1126,12 +1138,12 @@
            ppp_l2tp_sess_get_serial(sess), ctrl));

        if (gShutdownInProgress) {
-               Log(LG_PHYS, ("Shutdown sequence in progress, ignoring request."));
+               failreason = "Shutdown sequence in progress, ignoring request.";
                goto failed;
        }

        if (OVERLOAD()) {
-               Log(LG_PHYS, ("Daemon overloaded, ignoring request."));
+               failreason ="Daemon overloaded, ignoring request.";
                goto failed;
        }

@@ -1194,10 +1206,10 @@
                ppp_l2tp_avp_ptrs_destroy(&ptrs);
                return;
        }
-       Log(LG_PHYS, ("L2TP: No free link with requested parameters "
-           "was found"));
+       failreason = "L2TP: No free link with requested parameters was found";
 failed:
-       ppp_l2tp_terminate(sess, L2TP_RESULT_AVAIL_TEMP, 0, NULL);
+       Log(LG_PHYS, ("%s", failreason));
+       ppp_l2tp_terminate(sess, L2TP_RESULT_AVAIL_TEMP, L2TP_ERROR_TRY_ANOTHER, failreason);
        ppp_l2tp_avp_ptrs_destroy(&ptrs);
 }

Bei der Überprüfung einer anderen Verbindung kam die Rückmeldung vom Carrier, er würde in seinen Logfiles folgende Einträge sehen, die da bisher nicht standen:

%L2TP-7-SES: 16646:53888 Sending ICRQ
%L2TP-7-SES: 16646:53888 Rcvd CDN rid:0 (4,7) L2TP: No free link with requested parameters was found
%L2TP-7-SES: 16646:53888: peer failure, rerouting session
%L2TP-7-SES: 16646:53888 remote abort: peer failure, rerouting session (tc 23)

Das ist genau das, was der MPD nun dem LAC sendet. Der kommerzielle LAC (Redback) reagiert darauf genau wie gewünscht, er versucht die Session auf einem anderen L2TP Kanal abzukippen.

Damit ist die Änderung ein voller Erfolg:

  • Kunden kommen deutlich schneller wieder online, weil sie im Überlastfall auf andere, höher belegte L2TP-Tunnel verschoben werden.
  • Es ist nun möglich, die Annahme neuer Session gezielt zu verweigern, ohne den Carrier um Abschaltung des Tunnel bitten zu müssen. Damit kann man ein Komponente gezielt freiräumen, um unterbrechungsfrei arbeiten (z.B. Software tauschen) zu können.

Problem gelöst.

PPP-Verbindungen werden von Carrier zum ISP per L2TP-Tunnel zugeführt. Diese Tunnel tragen einige tausend Sessions gleichzeitig. Deswegen sollten sie gegen Störungen sehr nachsichtig sein. Und dazu hat man sich einiges einfallen lassen.

Der TCP-Nachbau

L2TP ist gemäß RFC 2661 ein Tunnelprotokoll mit gesichertem Kanal für Kontrollnachrichten.

Dazu führt jede Seite 16bit-Sequenznummern für die eignenen Nachrichten ein, die sich mit jeder Kontrollnachricht erhöhen. Empfängt der L2TP-Stack der Gegenstelle eine neue Nachricht, so sendet es selbst die fremde Sequenznummer wieder als Bestätigung bei der nächsten ausgehenden Kontrollnachricht mit. Liegt keine Kontrollnachricht vor, so kann auch eine leere Nachricht gesendet werden, die praktisch nur das ACK transportiert.

Damit die Verbindung nicht so stottert, vereinbaren beide Seiten ein Fenster an "unbestätigten" Nachrichten, die sich noch im Transport befinden dürfen. Dieses Fenster ist üblicherweise vier bis acht Nachrichten groß.

Das entspricht vollständig dem bekannten TCP Protokoll.

Um die Funktionsweise dieses L2TP-Kanals muß man sich normalerweise nicht kümmern: Man wird eine Kontrollnachricht ein und wartet auf die Antwort bzw. die Kontrollnachricht der Gegenseite. Dafür reicht ein Fenster für eine Handvoll Nachrichten völlig aus.

Eine explizite Möglichkeit, die Unerreichbarkeit der Gegenseite zu bemerken, gibt es nicht. (TCP hat dafür RST und FIN.) Deswegen definiert man sich einen Timeout, innerhalb dessen eine Nachricht von der Gegenseite bearbeitet bekommen haben möchte.

Wenn es kurz klemmt?

Wie immer bringt ein Blick in den Sourcecode (hier sys/netgraph/ng_l2tp.c von FreeBSD) Klarheit:

/* Some hard coded values */
#define L2TP_MAX_XWIN           128                     /* my max xmit window */
#define L2TP_MAX_REXMIT         5                       /* default max rexmit */
#define L2TP_MAX_REXMIT_TO      30                      /* default rexmit to */
#define L2TP_DELAYED_ACK        ((hz + 19) / 20)        /* delayed ack: 50 ms */

Insgesamt läßt sich das Fenster auf bis zu 128 Nachrichten vergrößern. Aber wie erfolgt die Wiederholung?

/* Restart timer, this time with an increased delay */
delay = (seq->rexmits > 12) ? (1 << 12) : (1 << seq->rexmits);
if (delay > priv->conf.rexmit_max_to)
    delay = priv->conf.rexmit_max_to;
ng_callout(&seq->rack_timer, node, NULL,
    hz * delay, ng_l2tp_seq_rack_timeout, NULL, 0);

Auf die ACKs von Nachrichten wird also bis zu 30 Sekunden gewartet. Und zwar immer expotentiell länger werdend:

Resend Delay
Versuch 1 2 3 4 5 6 7 ...
Wartezeit 1 2 4 8 16 30 30 30

Der Default liegt bei fünf Wiederholungen, was insgesamt eine Kommunikationslücke von 31 Sekunden abdecken kann.

Es nützt also nichts, einen globalen Timeout von mehr als diesen Zeitraum anzusetzen, da spätestens nach dieser halben Minute die Verbindung lokal für tot erklärt wird, wenn Nachrichten vorliegen.

Will man höhere Timeouts haben, so muß man die Wiederholungsraten auf beiden Seiten anheben. Diese Parameter werden ausgehandelt:

ncgtl> msg [0x00030854]: getconfig
Args:   { enabled=1 match_id=1 tunnel_id=0x6e9f peer_id=0x5685
         peer_win=8 rexmit_max=8 rexmit_max_to=10 }

Konkret werden hier also ein Fenster von acht Nachrichten, sowie acht Wiederholungen bis zu einem Maximalwert von 10 Sekunden pro Wiederholung vereinbart. Dies bedeutet also, daß diese Kontrollnachrichten nach 1+2+4+8+10+10+10+10 = 45 Sekunden bestätigt sein müssen.

Da L2TP Pakete über normales IP-Routing laufen, sollte die Konvergenzzeit dieser Netze kleiner sein als diese halbe Minute.

Überlastverhalten

Ganz anders ist die Situation, wenn auf einem L2TP-Tunnel einige tausend Sessions gleichzeitig laufen. Die Anzahl der hier benötigten Kontrollnachrichten ist dann sehr viel größer. Es erreicht schnell mal einige hundert Nachrichten auf einen Schlag.

Aber was passiert, wenn mehr Nachrichten gesendet werden sollen, als in den Puffer der Nachrichtenfensters passen?

Auch hier schult wieder ein Blick in den Quellcode die Sachkenntnis:

struct l2tp_seq {
        ...
        struct mbuf             *xwin[L2TP_MAX_XWIN];   /* transmit window */
};
/*
 * Handle an outgoing control frame.
 */
static int
ng_l2tp_rcvdata_ctrl(hook_p hook, item_p item)
{
        ...
        /* Find next empty slot in transmit queue */
        for (i = 0; i < L2TP_MAX_XWIN && seq->xwin[i] != NULL; i++);
        if (i == L2TP_MAX_XWIN) {
                mtx_unlock(&seq->mtx);
                priv->stats.xmitDrops++;
                m_freem(m);
                ERROUT(ENOBUFS);
        }
        seq->xwin[i] = m;
        ...
}

Eine Kontrollnachricht wird also zur Versendung in den 128 Nachrichten großen Kernelpuffer geworfen. Aus diesem werden soviele Nachrichten versendet, wie in das vereinbarte Sendefenster passen. Nach Bestätigung einer Aussendung werden die so bestätigten Nachrichten durch umkopieren nach vorn entfernt. Das Feld xwin ist also stets einseitig bündig mit Nachrichten gefüllt.

Kommen nun mehr Kontrollnachrichten herein als versendet werden können, puffert der Kernel bis zu 128 Nachrichten intern zwischen.

Reicht der Platz für diese 128 Nachrichten nicht aus, weil beispielsweise das Routing zwischen den Gegenstellen kurz gestört ist, oder weil die Gegenstelle gerade mächtig beschäftigt ist, so meldet der Kernel an den sendenden Prozess ENOBUFS "Kein Platz mehr".

Der MPD reagiert darauf verschnupft:

        if (NgSendData(ctrl->dsock, NG_L2TP_HOOK_CTRL, data, 2 + len) == -1)
                goto fail;

        /* Done */
        goto done;

fail:
        /* Close up shop */
        Perror("L2TP: error sending ctrl packet");
        ppp_l2tp_ctrl_close(ctrl, L2TP_RESULT_ERROR,
            L2TP_ERROR_GENERIC, strerror(errno));

done:
        /* Clean up */

Unabhängig vom Grund des Fehlers wird die gesamte L2TP Verbindung hingeworfen. Im Log sieht das dann so aus.

mpd: L2TP: error sending ctrl packet: No buffer space available

Der offenkunde Fix besteht darin, es mehrfach zu probieren:

    int rtn, retry = 10, delay = 1000;

retry:
    if ((NgSendData(ctrl->dsock, NG_L2TP_HOOK_CTRL, data, 2 + len) == -1) {
        if (errno == ENOBUFS && retry > 0) {
            Log(LG_ERR, ("[%s] XMIT stalled, retrying...", ctrl));
            usleep(delay);
            retry--;
            delay *= 2;
            goto retry;
        }

Selbstverständlich hilft das nicht viel. Denn in dieser Schleife kann der Prozeß nicht beliebig viel Zeit vergeuden. Er hat schließlich noch anderes zu tun.

Was man also braucht ist eine echte, dynamisch wachsende Warteschlange für diese Kontrollnachrichten.

--- mpd-5.6/src/l2tp_ctrl.c     2011-12-21 15:58:49.000000000 +0100
+++ mpd-5.6-lutz/src/l2tp_ctrl.c        2013-09-27 16:08:15.000000000 +0200
@@ -153,6 +153,14 @@
        int                     req_avps[AVP_MAX + 1];
 };

+/* Control message queue */
+struct ctrl_queue_entry {
+   void *                      data;
+   unsigned int                        len;
+   STAILQ_ENTRY(ctrl_queue_entry) next;
+};
+STAILQ_HEAD(l2tp_ctrl_queue, ctrl_queue_entry);
+
 /* Control connection */
 struct ppp_l2tp_ctrl {
        enum l2tp_ctrl_state    state;                  /* control state */
@@ -164,6 +172,7 @@
        char                    path[32];               /* l2tp node path */
        int                     csock;                  /* netgraph ctrl sock */
        int                     dsock;                  /* netgraph data sock */
+       struct l2tp_ctrl_queue  *dsock_queue;           /* queue if netgraph is
        u_char                  *secret;                /* shared secret */
        u_int                   seclen;                 /* share secret len */
        u_char                  chal[L2TP_CHALLENGE_LEN]; /* our L2TP challenge
@@ -533,6 +544,10 @@
            ctrl->mutex, ppp_l2tp_data_event, ctrl, PEVENT_READ,
            ctrl->dsock) == -1)
                goto fail;
+
+       /* Initialize send queue */
+       ctrl->dsock_queue = Malloc(CTRL_MEM_TYPE, sizeof(*ctrl->dsock_queue));
+       STAILQ_INIT(ctrl->dsock_queue);

        /* Copy initial AVP list */
        ctrl->avps = (avps == NULL) ?
@@ -616,5 +632,6 @@
        ppp_l2tp_avp_list_destroy(&ctrl->avps);
        ghash_remove(ppp_l2tp_ctrls, ctrl);
        ghash_destroy(&ctrl->sessions);
-       Freee(ctrl->secret);
+       l2tp_ctrl_queue_destroy(&ctrl->dsock_queue);
+       Freee(ctrl->secret);
        Freee(ctrl);
        if (ppp_l2tp_ctrls != NULL && ghash_size(ppp_l2tp_ctrls) == 0)
                ghash_destroy(&ppp_l2tp_ctrls);
@@ -1261,8 +1290,32 @@
                ppp_l2tp_ctrl_dump(ctrl, avps, "L2TP: XMIT(0x%04x) ",
                    ntohs(session_id));
        }
-       if (NgSendData(ctrl->dsock, NG_L2TP_HOOK_CTRL, data, 2 + len) == -1)
-               goto fail;
+
+        /* Schedule packet */
+        n = Malloc(CTRL_MEM_TYPE, sizeof(*n));
+       n->data = data; data = NULL;
+       n->len = 2 + len;
+       MUTEX_LOCK(gNgMutex);
+       STAILQ_INSERT_TAIL(ctrl->dsock_queue, n, next);
+       MUTEX_UNLOCK(gNgMutex);
+
+       MUTEX_LOCK(gNgMutex);
+       /* Try to send outstanding messages */
+       while(!STAILQ_EMPTY(ctrl->dsock_queue)) {
+          struct ctrl_queue_entry *o = STAILQ_FIRST(ctrl->dsock_queue);
+          if (NgSendData(ctrl->dsock, NG_L2TP_HOOK_CTRL, o->data, o->len) == -1
+             if (errno == ENOBUFS) {
+                Log(LG_ERR, ("[%p] L2TP: XMIT stalled, queueing ...", ctrl));
+                break;
+             }
+             MUTEX_UNLOCK(gNgMutex);
+             goto fail;
+          }
+          STAILQ_REMOVE_HEAD(ctrl->dsock_queue, next);
+          Freee(o->data);
+          Freee(o);
+       }
+       MUTEX_UNLOCK(gNgMutex);

        /* Done */
        goto done;
@@ -1277,7 +1330,6 @@
        /* Clean up */
        ppp_l2tp_avp_destroy(&avp);
        ppp_l2tp_avp_list_destroy(&avps);
-       Freee(data);
 }

 /*
@@ -1412,6 +1464,22 @@
 }

 /*
+ * Free all outstanding entries in the control message queue.
+ * Remove the queue.
+ */
+static void
+l2tp_ctrl_queue_destroy(struct l2tp_ctrl_queue ** q) {
+   while(!STAILQ_EMPTY(*q)) {
+      struct ctrl_queue_entry * n = STAILQ_FIRST(*q);
+      STAILQ_REMOVE_HEAD(*q, next);
+      Freee(n->data);
+      Freee(n);
+   }
+   Freee(*q);
+}
+
+
+/*
  * Notify link side that the control connection has gone away
  * and begin death timer.
  *

Damit ist es möglich, die Kontrollnachrichten beliebig lange zwischenzuspeichern, auch wenn es auf dem L2TP Server mal heiß hergeht.

An den Timeouts für die Verbindung ändert sich dabei noch nicht viel. Diese Resende-Timeouts müssen anderweitig angepaßt werden.

Immer wieder benötigt man im Privatkunden-Umfeld die Möglichkeit die Zuweisung der IP Adressen zu dynamisieren. Hier ist der Hauptgrund, daß die Kunden darauf konditioniert wurden und sich ohne regelmäßige Adreßwechsel unsicher fühlen. Erfolgreiches Marketing eben. Muß man halt haben.

Standardsoftware

Wir setzen auf den ISC-DHCP. Und der ist bezüglich der IP Vergabe sehr konservativ. Solange auch nur eine Anhaltspunkt gefunden werden kann, daß der Client die spezielle IP bekommen müßte, wird er die bekommen. Gründe sind obskure Historien, schon mal gesehenen MAC Adressen oder ganz einfach die Anfrage des Clients, diese IP zu erhalten.

Die Dynamisierung besteht im Prinzip aus zwei Schritten.

  • Zum einen darf ein Client seine vorher mal benutzte IP nicht erneut angeboten (DISCOVER) bekommen.
  • Zum anderen darf ein Client eine Lease mit einer zugewiesenen IP ab einem bestimmten Zeitpunkt nicht mehr verlängert (REQUEST) bekommen.

Konsequenterweise sind das zwei getrennte, poolspezifische Optionen:

  • avoid-reuse bool sorgt dafür, daß ein Client jedesmal eine andere IP angeboten bekommt, wenn er keine gültige IP hat. Das gestattet einen Adreßwechsel jedesmal, wenn der Client rebootet oder neue IPs anfordert.
  • force-nack hour minute dagegen sorgt dafür, daß ein Client zu einem bestimmten Zeitpunkt seine aktuell zugewiesene IP verliert. Überstreicht eine Lease den definierten Zeitpunkt, wird die niemals verlängert. Der Client muß dann nach einer neuen IP fragen.

Die Optionen können unabhängig voneinander agieren.

Es ist also möglich, nur den Adreßwechsel zu erzwingen, nicht aber die Zwangstrennung du8rchzuführen. Diese quasi-statische Zuordnung ist im Zusammenhang mit Triple-Play wichtig, wenn der ISP erhebliche Risiken eingehen, falls er ein wichtiges Telefonat (z.B. einen Notruf) oder eine Sportübertragung (Fußball, SuperBowl) unterbricht.

Es ist ebenso möglich, nur die Zwangstrennung zu aktivieren, falls das durch Beschränkungen der Abrechnungssoftware oder andere interne Mechanismen erforderlich ist.

Umsetzung

Zuerst einmal brauchtes ein paar Token, die beide Funktionen kennzeichnen sollen.

diff -pbBru ../ORIGINAL/includes/dhcpd.h includes/dhcpd.h
--- ../ORIGINAL/includes/dhcpd.h        2011-07-09 00:56:26.000000000 +0200
+++ includes/dhcpd.h    2012-03-06 15:54:40.000000000 +0100
@@ -713,6 +713,9 @@ struct lease_state {
 # define SV_LDAP_TLS_RANDFILE           77
 #endif
 #endif
+/* private options */
+#define SV_AVOID_REUSE                 200
+#define SV_FORCE_NACK                  201
 
 #if !defined (DEFAULT_PING_TIMEOUT)
 # define DEFAULT_PING_TIMEOUT 1
diff -pbBru ../ORIGINAL/includes/dhctoken.h includes/dhctoken.h
--- ../ORIGINAL/includes/dhctoken.h     2011-05-12 14:02:47.000000000 +0200
+++ includes/dhctoken.h 2012-03-06 15:54:06.000000000 +0100
@@ -362,6 +362,9 @@ enum dhcp_token {
        REWIND = 663,
        INITIAL_DELAY = 664,
        GETHOSTBYNAME = 665
+       /* Private usage. Prepend COMMA to keep patches context independant */
+     ,  AVOID_REUSE = 1000
+     ,  FORCE_NACK = 1001
 };
 
 #define is_identifier(x)       ((x) >= FIRST_TOKEN &&  \

Als nächstes sind diese Werte pro Pool aus der Konfiguration zu parsen:

diff -pbBru ../ORIGINAL/server/stables.c server/stables.c
--- ../ORIGINAL/server/stables.c        2011-05-20 16:21:11.000000000 +0200
+++ server/stables.c    2012-03-06 15:27:42.000000000 +0100
@@ -266,6 +266,8 @@ static struct option server_options[] = 
        { "ldap-tls-randfile", "t",             &server_universe,  77, 1 },
 #endif /* LDAP_USE_SSL */
 #endif /* LDAP_CONFIGURATION */
+       { "avoid-reuse", "f",                   &server_universe,  SV_AVOID_REUSE, 1 },
+       { "force-nack", "BB",                   &server_universe,  SV_FORCE_NACK, 1 },
        { NULL, NULL, NULL, 0, 0 }
 };
diff -pbBru ../ORIGINAL/common/conflex.c common/conflex.c
--- ../ORIGINAL/common/conflex.c        2011-05-11 16:20:59.000000000 +0200
+++ ./common/conflex.c  2012-03-06 15:56:22.000000000 +0100
@@ -782,6 +782,8 @@ intern(char *atom, enum dhcp_token dfv) 
                                return AUTO_PARTNER_DOWN;
                        break;
                }
+               if (!strcasecmp(atom + 1, "void-reuse"))
+                       return AVOID_REUSE;
                break;
              case 'b':
                if (!strcasecmp (atom + 1, "ackup"))
@@ -986,6 +988,8 @@ intern(char *atom, enum dhcp_token dfv) 
                        return FIXED_PREFIX6;
                if (!strcasecmp (atom + 1, "ddi"))
                        return TOKEN_FDDI;
+               if (!strcasecmp(atom + 1, "orce-nack"))
+                       return FORCE_NACK;
                if (!strcasecmp (atom + 1, "ormerr"))
                        return NS_FORMERR;
                if (!strcasecmp (atom + 1, "unction"))

Und dann braucht es noch Funktionalität. Dazu werden Hooks in die betreffenden Funktionen eingepaßt. Diese Hooks ermitteln, ob die betreffende Funktionalität jetzt im Moment für diese Anfrage aktiviert werden soll oder nicht.

diff -pbBru ../ORIGINAL/server/dhcp.c server/dhcp.c
--- ../ORIGINAL/server/dhcp.c   2011-07-20 00:22:49.000000000 +0200
+++ server/dhcp.c       2012-03-16 11:33:11.000000000 +0100
@@ -40,6 +40,8 @@
 static void commit_leases_ackout(void *foo);
 static void maybe_return_agent_options(struct packet *packet,
                                       struct option_state *options);
+static int avoid_reuse(struct packet *packet, struct lease * lease);
+static int force_nack(struct packet *packet, struct lease * lease);
 
 int outstanding_pings; 

Die Funktion von avoid-reuse besteht darin, jede zuvor gefundenen Lease während der DISCOVER Verarbeitung zu verwerfen. Deswegen steht sie am Ende aller Lease-Ermittlungen. Diese Platzierung gestattet es, alle anderen Funktionen unverändert zu belassen.

diff -pbBru ../ORIGINAL/server/dhcp.c server/dhcp.c
--- ../ORIGINAL/server/dhcp.c 2011-07-20 00:22:49.000000000 +0200
+++ server/dhcp.c 2012-03-16 11:33:11.000000000 +0100
@@ -341,6 +343,18 @@ void dhcpdiscover (packet, ms_nulltp)
                }
        }
 #endif
+       /*
+        * Special handling to insist on new IPs whenever possible
+        */
+       if (avoid_reuse(packet, lease)) {
+          log_info ("Avoid reuse of old lease %s", piaddr (lease -> ip_addr));
+          if(lease -> ends > cur_time)
+            dissociate_lease (lease);   /* Free lease to enable reuse. */
+          lease_dereference (&lease, MDL);
+          if(lease)
+            log_error ("Lease %s can't be avoided, it's still referenced.",
+                       piaddr (lease -> ip_addr));
+       }
 
        /* If we didn't find a lease, try to allocate one... */
        if (!lease) {

Die Funktion von force-nack dagegen besteht darin, die Verarbeitung des REQUEST zu unterbinden.

diff -pbBru ../ORIGINAL/server/dhcp.c server/dhcp.c
--- ../ORIGINAL/server/dhcp.c   2011-07-20 00:22:49.000000000 +0200
+++ server/dhcp.c       2012-03-16 11:33:11.000000000 +0100
@@ -671,6 +685,12 @@ void dhcprequest (packet, ms_nulltp, ip_
                goto out;
        }
 
+       if (force_nack (packet, lease)) {
+               log_info ("%s: force disconnect.", msgbuf, piaddr (cip));
+               nak_lease (packet, &cip);
+               goto out;
+       }
+       
        /* Otherwise, send the lease to the client if we found one. */
        if (lease) {
                ack_lease (packet, lease, DHCPACK, 0, msgbuf, ms_nulltp,

Bleibt also die Hooks auch zu aktivieren. Unglücklicherweise ist das Optionshandling nicht trivial. Es gilt nicht nur die Konfiguration zum jetzigen Zeitpunkt, sondern auch die Konfiguration, die bei der letzten Verlängerung der Lease galt. Dieses ist Suche habe ich in eine separate Funktion get_lease_state ausgelagert.

Mit dieser Hilfsfunktion ist es wesentlich leichter, die Funktionalität aufzubauen.

diff -pbBru ../ORIGINAL/server/dhcp.c server/dhcp.c
--- ../ORIGINAL/server/dhcp.c   2011-07-20 00:22:49.000000000 +0200
+++ server/dhcp.c       2012-03-16 11:33:11.000000000 +0100
@@ -4472,3 +4492,129 @@ maybe_return_agent_options(struct packet
                        options->universe_count = agent_universe.index + 1;
        }
 }
+
+/*
+ * 
+ * 
+ * 
+ */
+static int get_lease_state(struct lease_state * state,
+                          struct packet * packet, struct lease * lease) {
+   int i;
+
+   state -> got_requested_address = packet -> got_requested_address;
+   shared_network_reference (&state -> shared_network,
+                            packet -> interface -> shared_network, MDL);
+   
+   /* See if we got a server identifier option. */
+   if (lookup_option (&dhcp_universe,
+                     packet -> options, DHO_DHCP_SERVER_IDENTIFIER))
+     state -> got_server_identifier = 1;
+   
+   maybe_return_agent_options(packet, state->options);
+   
+   /* Execute statements in scope starting with the subnet scope. */
+   execute_statements_in_scope ((struct binding_value **)0,
+                               packet, lease, (struct client_state *)0,
+                               packet -> options,
+                               state -> options, &lease -> scope,
+                               lease -> subnet -> group,
+                               (struct group *)0);
+   
+   /* If the lease is from a pool, run the pool scope. */
+   if (lease -> pool)
+     (execute_statements_in_scope
+      ((struct binding_value **)0, packet, lease,
+       (struct client_state *)0, packet -> options,
+       state -> options, &lease -> scope, lease -> pool -> group,
+       lease -> pool -> shared_network -> group));
+   
+   /* Execute statements from class scopes. */
+   for (i = packet -> class_count; i > 0; i--) {
+      execute_statements_in_scope
+       ((struct binding_value **)0,
+        packet, lease, (struct client_state *)0,
+        packet -> options, state -> options,
+        &lease -> scope, packet -> classes [i - 1] -> group,
+        (lease -> pool
+         ? lease -> pool -> group
+         : lease -> subnet -> group));
+   }
+}
+
+static int avoid_reuse(struct packet *packet, struct lease * lease) {
+   int avoid_this_lease = 0;
+   struct option_cache * oc;
+   struct lease_state * state;
+   int ignorep;
+
+   /* Shortcut: Nothing to do. */
+   if (!packet || !lease || (lease -> flags & STATIC_LEASE))
+     return avoid_this_lease;
+   
+   state = new_lease_state (MDL);
+   if (!state)
+     return avoid_this_lease;         /* silently ignore the error */
+   else
+     get_lease_state(state, packet, lease);
+   
+   oc = lookup_option(&server_universe, state -> options, SV_AVOID_REUSE);
+   if (oc &&
+       evaluate_boolean_option_cache(&ignorep, packet, lease,
+                                    (struct client_state *)0,
+                                    packet -> options, state -> options,
+                                    &lease -> scope, oc, MDL)) {
+      /* 120 seconds is the typical hold time for temporary allocations */
+      if(cur_time - 120 > lease -> starts)
+       avoid_this_lease = 1;          /* do not OFFER an "old" lease */
+   }
+
+   free_lease_state (state, MDL);
+   
+   return avoid_this_lease;
+}
+   
+
+static int force_nack(struct packet *packet, struct lease * lease) {
+   int force_nack = 0;
+   struct option_cache * oc;
+   struct lease_state * state;
+   struct data_string data;
+
+   /* Shortcut: Nothing to do. */
+   if (!packet || !lease || (lease -> flags & STATIC_LEASE))
+     return force_nack;
+   
+   state = new_lease_state (MDL);
+   if (!state)
+     return force_nack;               /* silently ignore the error */
+   else
+     get_lease_state(state, packet, lease);
+   
+   memset(&data, 0, sizeof(data));
+   oc = lookup_option(&server_universe, state -> options, SV_FORCE_NACK);
+   if (oc &&
+       evaluate_option_cache(&data, packet, lease,
+                            (struct client_state *)0,
+                            packet -> options, state -> options,
+                            &lease -> scope, oc, MDL)) {
+      struct tm disconnect_tm;
+      TIME disconnect;
+      
+      if(localtime_r(&cur_time, &disconnect_tm)) {
+        disconnect_tm.tm_sec  = 0;
+        disconnect_tm.tm_min  = data.data[1];
+        disconnect_tm.tm_hour = data.data[0];   
+        disconnect = mktime(&disconnect_tm);
+        if(disconnect <= cur_time &&
+           disconnect >  lease -> starts) {
+           force_nack = 1;            /* NAK the lease if it spans the disconnect time */
+        }
+      }
+      data_string_forget (&data, MDL);
+   }
+
+   free_lease_state (state, MDL);
+   
+   return force_nack;
+}

Konfiguration

Wie sieht das nun aus, wenn man diese Optionen auch benutzen will?

# short lease times to allow quick changes
shared-network Internet_Vlan {
        default-lease-time 3000;
        max-lease-time 3600;

        # static and other subnets as usual

        subnet x.y.z.0 netmask 255.255.255.0 {
                option subnet-mask 255.255.255.0;
                option routers x.y.z.1;
                option domain-name-servers a.b.c.d;
                pool {
                        allow members of "dynamic";
                        range x.y.z.10 x.y.z.254;
                        avoid-reuse on;
                        force-nack 3 0;
                }
        }

        subnet 100.64.0.0 netmask 255.255.128.0 {
                option subnet-mask 255.255.128.0;
                option routers 100.64.0.1;
                option domain-name-servers 100.64.0.4, 100.64.0.5;
                pool {
                        allow members of "CGN";
                        range 100.64.0.10 100.64.127.254;
                        avoid-reuse on;
                }
        }
}

Es gibt mehrere statische Bereiche, die wie gewohnt konfiguriert werden.

Es gibt darüberhinaus mehrere dynamische Bereiche (einer ist hier dargestellt), bei denen nachts um 3:00 eine vertraglich vereinbarte Zwangstrennung erfolgt und die IP Adressen gewechselt werden.

Darüberhinaus gibt es mehrere dynamische Carrier Grade NAT Bereiche (einer ist hier dargestellt), bei denen keine Zwangstrennung, wohl aber ein Adreßwechsel erfolgt.

Der ganze Kram ist Failover fähig und läuft hier problemlos in einem DHCP-Cluster.

Das Backup einer Kundenwebseite wächst und wächst und wächst. Warum auch nicht? Allerdings wird es mittlerweile etwas unhandlich. Die Frage ist also, ob man jedes Mal alle Dateien ins Backup nehmen muß, oder ob man einen Teil davon als Altbestand lieber archivieren soll.

Bestandsaufnahme

Der Kunde betreibt eine Typo3-Webseite, auf der er über Sportereignisse berichtet. Natürlich mit entsprechend vielen Bildern.

Es ist also anzunehmen, daß die Anzahl der Bilder das Problem darstellen könnte. Und natürlich bilden diese auch die Chance ein Backup nach "neuen" und "alten" Dateien unterscheiden zu können.

# du -sh * | grep G
32G     fileadmin
20K     GPL.txt
41G     typo3temp
19G     uploads

Also gut. typo3temp muß man nicht ins Backup werfen.

Aber der Rest ist eine ziemlich flache Struktur aus Bildergalerien. Dateien sind nicht nach Datums-Verzeichnissen gruppiert.

Aber wie schaut die aktuelle Verteilung der Daten genau aus?

# (find fileadmin/ -type f -print0; find uploads/ -type f -print0) |
> xargs -0 ls -l |
> perl -ne '
     next unless /(\d+) (\d+)-(\d+)-(\d+)/;
     $s{"$2-$3-01"}+=$1;
     $c{"$2-$3-01"}++;
     END {
       foreach (sort keys %c) {
         printf "%s %d %d %d\n", $_, $c{$_}, $s{$_}, ($s{$_}/$c{$_})
       }
     }'

Das gibt pro Monat eine Liste der Dateien, ihre Gesamtgröße und die durchschnittliche Größe.

Und natürlich plottet man sich das lieber hin (logarithmisch auf der Y-Achse)

filesize

Es gab offensichtlich eine größere Datenübernahme im zweiten Quartal 2011 und seit dem ist die Webseite regelmäßig gewachsen.

Erfreulich: Zumindest bietet sich die Möglichkeit, ältere Bilder separat zu archivieren und nur die neueren Dateien regulär im Backup zu halten.

Ausblick

Für die weitere Planung zeigt sich, daß eigentlich eine konstante Anzahl von Dateien pro Monat dazu kommt. Das ist erfreulich.

Allerdings wir die Datenmenge in den letzten Monaten merklich mehr. Deswegen lohnt sich ein Blick auf die durchschnittliche Dateigröße (in Byte, linear)

filesize2

Sehr deutlich ist zu sehen, daß ab Frühjahr 2015 die Dateigröße um das zweieinhalbfache zugenommen hat.

Offenbar haben die Fotografen auf neue Kameras und neue Bildformate gewechselt. Und die Bildredaktion scheint die Bilder unbearbeitet zu übernehmen.

Das ist kein Fehler, denn Typo3 (zumindest die Extension) skaliert die Bildgrößen gemäß eines responsive Designs permanent neu. Diese Neuberechnung ist ein Quell steter Freude gewesen, weil da schon mal einige zig Konvertierungen pro Sekunde zusammen kommen. Das hatten wir schon letztes Jahr eingefangen und ist ein Thema für sich. Inzwischen sind wir bei erfreulichen 700 Konvertierungen pro Tag, wenn keine neuen Bilder hochgeladen werden.

Die Kapazitätsplanung des Backups kann also davon ausgehen, daß die Datenmengen sich verdreifachen werden, während ein Grundstock per separatem Archiv aus dem Backup entfernt werden kann. Das Backup wird also nicht weiter aus dem Ruder laufen.

Ein Kunde beschwerte sich über Netzwerkprobleme. Zwischen zwei seiner Server würde immer wieder ein SMB/CIFS-Mount weg brechen. Nicht, dass es irgendwelche bemerkbaren Störungen gegeben hätte, aber es gäbe halt immer wieder diese Fehlermeldungen im Log.

Aufbau

Der Kunde hat in seinem Layer2-Segment eine ganze Latte Server stehen. Einer davon spielt Windows-Fileserver für eine Gruppe von Windows Rechnern. Ein anderer ist das Linux-Monitoring-System, das u.a. regelmäßig versucht auf die Freigabe zuzugreifen.

Das Ganze hat eine längere Vorgeschichte, die vor einem halben Jahr zur Empfehlung führte, doch konsequent auf SMB1 zu verzichten. Dieser Teil ist nicht von Belang, sondern das, was der Empfehlung folgte.

Denn seit der Umstellung hat das Monitoring-Linux seltsame Einträge im Kernellog stehen:

Feb 12 19:07:02 kernel: CIFS VFS: Server a.b.c.d has not responded in 120 seconds. Reconnecting...

Woher kommen die 120 Sekunden? Das Handbuch hilft weiter:

echo_interval=n

sets the interval at which echo requests are sent to the server on an idling
connection. This setting also affects the time required for a connection to
an unresponsive server to timeout. Here n is the echo interval in seconds.
The reconnection happens at twice the value of the echo_interval set for
an unresponsive server. If this option is not given then the default value of
60 seconds is used.

Das erklärt schon mal die 120 Sekunden: Alle Minute wird ein SMB Echo versendet und wenn zweimal kein Echo beantwortet wird, nimmt man an die Verbindung sei tot. Deswegen wird seitens des Kunden (verständlicherweise) vermutet, dass es Paketverlust im Netzwerk gäbe.

Allein diese Vermutung zu widerlegen, dauert Wochen. Dazu wird auf beiden Seiten der Datenverkehr mitgeschnitten und Paket für Paket nebeneinander gelegt.

Dem eigentlichen Problem ist man damit aber leider immer noch nicht näher gekommen.

Analyse

Immer wieder wird so ein Mitschnitt angeschaut, um irgendeine Auffälligkeit zu entdecken.

smb-tcp-flow

Es ist sehr schön zu sehen, wie jede Minute das Keep-Alive Request-Response Spiel passiert. Anschließend werden Daten übertragen.

Kurz darauf kommt die Kommunikation zum Erliegen und der im Log erwähnte Timeout schlägt zu. Zwischen 19:05:01.99... und 19:07:02.25... liegen etwas mehr als 120 Sekunden. Das passt so weit.

Auffällig ist der Übertragungsfehler (der mit dem TCP-Keepalive), der direkt vor dem Abbruch der Verbindung rein schlägt. Das muss untersucht werden!

Warum ist die Zeile schwarz? Weil der Keepalive genau ein Byte nochmal sendet, dass schon lange geackt wurde. Es ist eine sehr ungewöhnliche Kommunikation. Wireshark markiert solche Sequenzfehler mit schwarzer Farbe.

  • Um 19:05:01.949511 werden 128 Byte empfangen.
  • Um 19:05:01.997203 wird der Empfang dieser 128 Bytes bestätigt.
  • Um 19:07:01.999481 wird das letzte der 128 Bytes nochmal übertragen (zusammen mit dem Keepalive-Flag)

Wenn die Bestätigung des Datenempfangs (ACK) nicht angekommen wäre, würden die gesamten 128 Byte nochmal gesendet. Werden sie aber nicht.

Hat irgend eine Firewall unterwegs an den Sequenznummern gespielt? Es ist aber gar keine Firewall dazwischen, beide Server stehen im gleichen LAN und sehen sich direkt. Der Mitschitt auf der anderen Seite bestätigt, dass die Bestätigung komplett angekommen ist.

Warum sollte der Kernel also ein einzelnes Byte nochmal senden? Es stellt sich heraus, dass die Windows-Implementation des TCP-Keepalives genau ein Byte nochmal sendet, während die Linux-Implementation das Keepalive ohne Payload auskommt. Es handelt sich offenbar um eine Anpassung von Windows an kaputte Middleware, die TCP-Pakete ohne Payload verwirft.

Der Teil ist also in Ordnung. Aber was ist es dann?

Vielleicht hat es irgendwo Verzögerungen gegeben? Also schauen wir mal auf die Round-Trip-Zeiten. Vielleicht gibt es Ausreißer.

smb-tcp-rtt

Von der remote Stelle gibt es keine besonderen Auffälligkeiten. Alles schön.

smb-tcp-rtt2

Auch die lokale Verarbeitung ist völlig unauffällig: Das der Kernel direkt bearbeiten kann, ist nahezu in Nullzeit erledigt. Wenn die Anwendungssoftware involviert ist, dauert's länger. Man sieht sehr schön, wie regelmäßig die Messungen vorgenommen werden.

Auch hier ist nichts auffällig. Aber was ist es dann?

Beim genaueren Hinsehen fällt auf, dass um 19:06:00 ein Echo-Request hätte versendet werden sollen. Der fehlt aber!

Kernel Archäologie

Im Linux-Kernel ist für das Versenden der Echo-Requests die Funktion cifs_echo_request zuständig. Dort steht:

static void
cifs_echo_request(struct work_struct *work)
{
 int rc;
 struct TCP_Server_Info *server = container_of(work,
     struct TCP_Server_Info, echo.work);
 unsigned long echo_interval;

 /*
  * If we need to renegotiate, set echo interval to zero to
  * immediately call echo service where we can renegotiate.
  */
 if (server->tcpStatus == CifsNeedNegotiate)
  echo_interval = 0;
 else
  echo_interval = server->echo_interval;

 /*
  * We cannot send an echo if it is disabled.
  * Also, no need to ping if we got a response recently.
  */

 if (server->tcpStatus == CifsNeedReconnect ||
     server->tcpStatus == CifsExiting ||
     server->tcpStatus == CifsNew ||
     (server->ops->can_echo && !server->ops->can_echo(server)) ||
     time_before(jiffies, server->lstrp + echo_interval - HZ))
  goto requeue_echo;

 rc = server->ops->echo ? server->ops->echo(server) : -ENOSYS;
 if (rc)
  cifs_dbg(FYI, "Unable to send echo request to server: %s\n",
    server->hostname);

requeue_echo:
 queue_delayed_work(cifsiod_wq, &server->echo, server->echo_interval);
}

Der Code ist in mehrfacher Hinsicht interessant:

  • Zum Einen wird ein Echo nur gesendet, wenn dafür eine echte Notwendigkeit besteht.
  • Zum Anderen handelt es sich um ein Daisy-Chain Scheduling: Erst nach getaner Arbeit wird die nächste Aktion geplant.

Was die Notwendigkeit betrifft, so werden keine Echos ausgesendet, solange die letzte Response kürzer als eine Echo-Abstand einging.

Aber was ist eine Response? Im Code wird der server-›lstrp immer dann auf die aktuelle Zeit gesetzt, wenn ein Paket empfangen wird. Unabhängig davon ob es ein Echo-Response oder normale Daten sind.

Das Abziehen von HZ (eine Sekunde) ist eine Maßnahme dagegen, dass die Echo-Response auf die eigene Anfrage schon als interessanter Traffic interpretiert wird. Dieser hartkodierte Wert gilt also unter der Annahme, dass die Antwort der Gegenstelle immer schneller da ist als in einer Sekunde.

Betreibt man einen solchen SMB Zugriff über eine längere Strecke oder gegen einen langsameren Server, so wird jeder zweite Echo-Request unterdrückt, wenn kein weiterer Traffic auftritt. Das führt direkt dazu, dass SMB nur im LAN wirklich funktioniert.

Aufgrund der Protokollarchitektur werden alle Anfragen sequentiell bearbeitet. Wenn also ein Echo-Request gesendet wird, während noch eine andere Abfrage an den Server läuft, so wird die Verarbeitung des Echo-Requests erst dann erfolgen, wenn der vorherige Request bearbeitet wurde. Eine asynchrone Bearbeitung wurde mit dem Wechsel von SMB1 zu SMB2 aufgegeben. Stattdessen soll der Server den Client mitteilen, dass die Bearbeitung einer aufwändigeren Anfrage noch andauert.

In diesem Fall war um 19:05:01.91... eine Antwort vom Server eingegangen. Das Echo-Paket hätte gegen 19:06:00 gesendet werden sollen. Das ist haarscharf daneben!

Die zweite Auffälligkeit ist das Scheduling. Erst, wenn alle Arbeiten (Echo-Paket versenden) erledigt sind, wird der nächste Echo-Versand geplant und zwar 60 Sekunden später. Die gesamte Verarbeitungszeit fehlt in der Planung. Das führt dazu, dass die Echo-Pakete nicht genau nach 60 Sekunden versendet werden, sondern immer ein Stück später.

Man sieht das im Mitschnitt sehr schön: 19:01:55.05, 19:02:56.49, 19:03:57.94, 19:04:59.37, 19:06:00.90, 19:07:02.27. Die Abstände betragen etwa 61,5 Sekunden. Also 1,5 Sekunden mehr als geplant. Im letzten Schritt ist das Intervall kürzer, weil das Echo-Paket ja nicht versendet werden musste.

Racecondition

Was wirklich passiert ist schnell erklärt: Das Unterdrücken des geplanten Echo-Requests ist fehlerhaft.

Im Detail:

smb-tcp-timing
  • Durch das Daisy-Chaining-Schedulung entsteht eine Lücke.
  • Kommt Traffic unglücklich kurz nach dem letzten Echo, so wird das geplante Echo unterdrückt.
  • Durch die Lücke verzögert sich der nächste Echo-Versand bis nach dem Timeout, das hart auf das doppelte Echo-Intervall gesetzt wird.

Besonderen Charme hat die Erkenntnis, dass der finale Echo-Request erst versendet wird und danach der Timeout zuschlägt, weil die erste Aktion beim Empfangen des Echo-Response ist, auf einen Timeout zu prüfen und abzubrechen. Ironischerweise hat also das erfolgreiche Echo den Abbruch getriggert.

Stellt sich nun die Frage, seit wann das Problem auftritt und wer dafür verantwortlich ist:

  • Im Patch c740 werden fest alle 60 Sekunden Echo-Requests versendet, wenn kein anderer Traffic auftrat. (Jan 11, 2011)
  • Im Patch fda3 werden diese Echos genutzt um nach dem fünffachen Intervall (konfigurierbar) ohne Traffic den Timeout auszulösen. (Jan 20, 2011)
  • Im Patch 6dae wird die Konfigurierbarkeit von 60s x variabel(5) zu variabel(60s) x zwei umgestellt. (Feb 21, 2012)

Die Lücke und das Unterdrücken wurde also am 11. Januar 2011 eingeführt. Allerdings hat diese keine Auswirkung, da der Timeout erst beim fünffachen Intervall eintritt.

Mit der Umstellung vom 21. Februar 2012 wirkt sich die Lücke nun aus, da man den Timeout hart auf das doppelte Intervall setzte.

Lösungen

Es gibt drei Möglichkeiten.

Zum einen kann man die Lücke beseitigen, indem man das Scheduling zu festen Zeiten macht (immer 60 Sekunden zum letzten Schedule-Zeitpunkt addieren). Es genügt übrigends nicht, das Rescheduling an den Anfang der Routine zu stellen. Damit wird die Lücke nur kürzer, bleibt aber bestehen.

Eine andere Möglichkeit wäre, den Echo-Request unabhängig von anderem Traffic in jedem Fall zu versenden. Motto: Wenn eh schon Traffic läuft, stört der zusätzliche Request auch nicht mehr. Es besteht dabei die potentielle Gefahr, dass sich ein Server an einem Echo zwischen anderen Requests verschluckt.

Und dann wäre es noch denkbar, dass man dem gesamten Problem aus dem Weg geht, indem man minimal die dreifache Intervall-Länge wartet.

Für einen Quick-Fix sollte man den dritten Weg beschreiten: Aus einer 2 eine 3 im Code machen:

static bool
server_unresponsive(struct TCP_Server_Info *server)
{
 /*
  * We need to wait 2 echo intervals to make sure we handle such
  * situations right:
  * 1s  client sends a normal SMB request
  * 2s  client gets a response
  * 30s echo workqueue job pops, and decides we got a response recently
  *     and don't need to send another
  * ...
  * 65s kernel_recvmsg times out, and we see that we haven't gotten
  *     a response in >60s.
  */
 if ((server->tcpStatus == CifsGood ||
     server->tcpStatus == CifsNeedNegotiate) &&
     time_after(jiffies, server->lstrp + 2 * server->echo_interval)) {
  cifs_dbg(VFS, "Server %s has not responded in %lu seconds. Reconnecting...\n",
    server->hostname, (2 * server->echo_interval) / HZ);
  cifs_reconnect(server);
  wake_up(&server->response_q);
  return true;
 }

 return false;
}

Bleibt nur noch die Frage nach dem TCP-Keepalive. Windows hat exakt 120s bis es auf einer TCP Session einen Keepalive schickt. Man sieht sehr schön, dass zuerst der Windows-Server den TCP-Keepalive schickt, weil er das letzte Paket eher abgesendet hat als es beim Linux ankam.

Danksagung

Die gesamte Analyse wurde von meinem Kollegen Jens durchgeführt, der mich nur bat, die Dinge zusammen zu schreiben. Was ich hier mit getan habe.

jetzt muss nur noch ein Bugreport an die richtige Stelle geschickt werden.