Advanced search


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.

A customer complained about network problems. An SMB/CIFS mount would always break down between two of his servers. Not that there were any noticeable problems, but there are still some error messages in the log.

Setup

The customer has a certain number of servers in his Layer2 segment. One of them is a Windows file server for a group of Windows computers. Another is the Linux monitoring system, which regularly tries to access the share.

The whole thing has a longer history, which led half a year ago to the recommendation to abandon SMB1. This part is not relevant, it is what followed the recommendation.
Since the transition, the monitoring Linux has had strange entries in the kernel log:

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

Where do these 120 seconds come from? The man page does help:

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.

That explains the 120 seconds: Every minute an SMB echo is sent and if no echo is answered twice, the connection is believed to be dead. Therefore, the customer (understandably) thinks that there would be packet loss in the network.

To prove this assumption wrong takes weeks. For this purpose, the data traffic is recorded on both sides and put next to each other packet by packet.

Unfortunately, this still doesn't solve the real problem.

Analysis

Again and again such a recording is examined, in order to discover any unusual phenomenon.

smb-tcp-flow

It's awesome to see each minute the keep-alive request-response game is happening. Then data is sent.

The communication comes to a sudden pause and the time-out stated in the log occurs. Between 19:05:01.99... and 19:07:02.25... there are a little more than 120 seconds. So far that seems to fit.

The transmission error (the one with the TCP keep-alive) is remarkable, because it hits the server directly before the connection is terminated. This must be investigated!

Why are the lines black? Because the keep-alive sends exactly one byte over again, which has been acked for a long time. It is a very unusual conversation. Wireshark colours such sequence errors in black.

  • At 19:05:01.949511 128 bytes are received.
  • At 19:05:01.997203 the reception of these 128 bytes is confirmed.
  • At 19:07:01.999481 the final of the 128 bytes is transmitted again (together with the keep-alive flag).

If the acknowledgement of the data reception (ACK) had not arrived, the entire 128 bytes would be sent again. But they are not.

Did a firewall gamble on the sequence numbers underway? But there is no firewall in between, both servers are in the same LAN and see each other directly. But the other side verifies that the acknowledgement has arrived completely.

So why should the kernel resend a single byte? It turns out that the Windows implementation of the TCP keepalive sends exactly one byte again, while the Linux implementation sends the keepalive without payload. This is apparently an adjustment of Windows to broken middleware, which drops TCP packets without payload.

So the part is fine. But what is it then?

Maybe there are some delays somewhere? So let's take a look at the round-trip times. Maybe there are outliers.

smb-tcp-rtt

There are no particular irregularities with the remote location. Everything looks nice.

smb-tcp-rtt2

Even the local processing is completely inconspicuous: Everything that the kernel can process directly is done in almost no time. If the application software is involved, it takes longer. One can see very clearly how regular the measurements are.

Nothing is striking here either. But what is it then?

A closer look reveals that an echo request should have been sent at 19:06:00. But that is missing!

Kernel Archaeology

The function cifs_echo_request is responsible for sending the echo requests in the Linux kernel. There it says:

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);
}

The code is interesting in several ways:

  • On the one hand, an echo is sent only if there exists a real need to do so.
  • On the other hand, this is a daisy chain scheduling: Only after work has been done the next action is planned.

As far as the needs are concerned, no echoes are sent out as long as the last response was received earlier than one echo interval.

But what is a response? In the code, the server→lstrp is always set to the current time whenever a packet is received. Regardless wether it is an echo response or normal data.

Subtracting HZ (one second) is a countermeasure preventing the echo response to your own request from being interpreted as interesting traffic. So this hard-coded value is calculated assuming that the answer from the remote station comes always more quickly than in a second.

If such an SMB connection runs over a longer distance or against a slower server, every second echo request will be suppressed if no further traffic occurs. This directly leads to the fact that SMB only works in the LAN.

Due to the protocol architecture, all requests are processed sequentially. If an echo request is sent while another request is running on the server, the echo request will not be processed until the previous request has been completed. Asynchronous processing was abandoned with the transition from SMB1 to SMB2. Now the server should tell the client that a more complex request is still being processed.

In this case an answer was received at 19:05:01.91... from the server. The echo packet should have been sent around 19:06:00. That's a very precise mistake!

The second problem is the scheduling. Only when all the work has been done (sending the echo packet) the next echo is scheduled to be sent 60 seconds later. The entire processing time is missing from the planning. This means that the echo packets are not sent exactly after 60 seconds, but always a bit later.

The recording shows this very clearly: 19:01:55.05, 19:02:56.49, 19:03:57.94, 19:04:59.37, 19:06:00.90, 19:07:02.27. The intervals are about 61.5 seconds. So 1.5 seconds more than planned. In the last step the interval is shorter, because the echo packet was not sent.

Racecondition

But what really happens is explained quickly: Suppressing the planned echo request is faulty.

In detail:

smb-tcp-timing
  • Daisy chaining scheduling creates a gap.
  • If traffic comes unfortunate shortly after the last echo, the planned echo is suppressed.
  • Due to the gap, the next echo transmission is delayed until after the timeout, which is set hard to twice the echo interval.

It is particularly charming to realize that the final echo request is first sent and then the time-out strikes, because the first action when receiving the echo response is to check for a time-out and terminate it. Ironically, the successful echo triggered the abort.

Now the question arises since when the problem occurred and who is responsible for it:

  • The patch c740 will send permanently echo requests every 60 seconds if no other traffic occurred. (Jan 11, 2011)
  • The patch fda3 all these echoes are used to trigger a timeout at five times the interval (configurable) without traffic. (Jan 20, 2011)
  • The patch 6dae switches from the configurable 60s x variable(5) to variable(60s) x two. (Feb 21, 2012)

The gap and suppression was introduced on 11 January 2011. However, this has no effect, as the time-out starts at five times the interval.

With the changeover on 21 February 2012, the gap now takes effect, as the time-out was set hard to twice the interval.

Solutions

There are three options.

First, eliminate the gap by scheduling at fixed times (always add 60 seconds to the last schedule time). By the way, it is not enough to move the rescheduling to the beginning of the routine. This only shortens the gap, but it will not disappear.

Another possibility is to send the echo requests in any case regardless of other traffic. In other words, if traffic is already running, the additional request will not bother any more. There is a potential risk that a server will choke on an echo between other requests.

Furthermore, avoiding the entire problem by waiting at least three times the interval length seems plausible.

If you want a quick fix, you should choose the third approach: Change a 2 to a 3 in the code:

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;
}

All that remains is the question of the TCP keepalive. Windows will wait exactly 120s until it sends a keepalive on a TCP session. Note that the Windows server sends the TCP keepalive first, because it transmitted the last packet before it arrived at Linux.

Acknowledgement

The entire analysis was done by my colleague Jens, who just asked me to write things together. This is what I did here.

The only thing left to do now is to send a bug report to the right place.