Erweiterte Suche

Wer eine IPTV Plattform anbietet, muss sie auch überwachen. Nur ist das nicht ganz so einfach, wenn nicht alle Komponenten aus einer Hand kommen. Wir standen vor der Aufgabe, an einer Zwischenstelle am Transportweg, die Qualität der Aussendung monitoren zu müssen.

Kurze Ausfälle

Das eigentliche Problem beim Fernsehen besteht darin, dass jeder auch noch so kurzfristige Ausfall vom Kunden bemerkt wird und instantan zu Störungsmeldungen führt.

Um schnellstmöglich von einem Problem zu erfahren, sollte also das Ausbleiben von Multicast-Paketen für eine bestimmten Sender nach wenigen Sekunden zu einem Alarm führen. Die Hotline muss also beim Entgegennehmen der Störungsmeldung bereits wissen, welcher Sender gerade kein Bild liefert. Dafür hat sie maximal fünf Sekunden Zeit.

Was wir also getan haben, ist einfach: Auf einem altersschwachen Rechner werden sämtliche Kanäle abonniert (macht nicht ganz ein Gigabit voll) und notiert, welcher Sender zuletzt ein Datenpaket abgeliefert an. Fehlen Daten für mehr als die definierten fünf Sekunden, wird protokolliert wie lange schon von welchem Streamer die Daten fehlen. Das füttert direkt das Alarmsystem. Und natürlich kann man dies auch auf malen (logarithmisch, um die kleinen Ausfälle nicht zu übersehen):

Ein zweites Ergebnis dieses Monitorings ist die Erkenntnis welcher Streamer noch wie viele Kanäle ausliefert. Fällt dieser Wert auf Null, ist dringender Handlungsbedarf gegeben, weil offenbar eine Komponente total ausgefallen ist. Man kann also sofort eine SMS an die Bereitschaft verschicken.

Details

Es stellt sich aber heraus, dass die Qualität eines Fernseh-Erlebnisses nicht allein von der Existenz eines Bildes abhängt (und vom Programminhalt), sondern auch von den Störungen, die das Bild überlagern oder unbrauchbar machen.

Die Software wurde also um die Fähigkeit erweitert, in die MPEG-TS Daten hineinzuschauen. Dies gibt eine Menge von interessanten Informationen:

Datenstrom liegt von a.b.c.d an.

Statistik über 3 Sekunden:
 Empfangene UDP Pakete      3446   Paket zu kurz                 0
 Verarbeitete MPEG Pakete  24122   Fehlende Sync-Markierung      0

Statistiken pro Datenstrom (MPEG-Programm)
 Programmkennung (PID)      6630 6610 6622 6620 6621 6600    0   32
                            19e6 19d2 19de 19dc 19dd 19c8 0000 0020
 Empfangene Pakete           56721738  865  494  377   29   28   24
 verschluesselte Daten         021366  829  448  331    0    0    0
 Ansetzpunkte, FullFrames      0    5   18   23   23    0    0    0
 priorisierte Daten            0    5    0    0    0    0    0    0
 Signalstoerung am Streamer    0    0    0    0    0    0    0    0
 Taktstoerung am Streamer      0    0    0    0    0    0    0    0
 Sequenzfehler(CC)             0    0    0    0    0    0    0    0

     Abweichungen vom Synchronisationstakt 19d2 (absoluter Jitter)
26%  ||                                                                   
20%  ||                                                                   
14% ||||                                                                  
 8% ||||||                                                                
 2% ||||||                                                                
   +----------------------------------------------------------------------
 ms 0123456789012345678901234567890123456789012345678901234567890123456789
    0         1         2         3         4         5         6         

     Abweichungen der Paketankunftszeiten (relativer Jitter)
66% |                                                                     
52% |                                                                     
37% |                                                                     
22% |                                                                     
 7% ||  ||||                                                              
   +----------------------------------------------------------------------
 ms 0123456789012345678901234567890123456789012345678901234567890123456789
    0         1         2         3         4         5         6         

Kanal ist durch Kunden im Moment abonniert.

Wie für einen HDTV Kanal üblich ist die Datenrate hoch und der Jitter klein. Beim einem Radioprogramm sieht das anders aus:

Datenstrom liegt von a.b.c.e an.

Statistik über 3 Sekunden:
 Empfangene UDP Pakete        43   Paket zu kurz                 0
 Verarbeitete MPEG Pakete    301   Fehlende Sync-Markierung      0

Statistiken pro Datenstrom (MPEG-Programm)
 Programmkennung (PID)       851    0  850
                            0353 0000 0352
 Empfangene Pakete           282   13    6
 verschluesselte Daten         0    0    0
 Ansetzpunkte, FullFrames      0    0    0
 priorisierte Daten            0    0    0
 Signalstoerung am Streamer    0    0    0
 Taktstoerung am Streamer      0    0    0
 Sequenzfehler(CC)             4    0    4

     Abweichungen vom Synchronisationstakt 0353 (absoluter Jitter)
59%                                                                      |
46%                                                                      |
33%                                                                      |
19%                                                                      |
 6% |    |     | |     |     ||   ||             ||   |      || |        |
   +----------------------------------------------------------------------
 ms 0123456789012345678901234567890123456789012345678901234567890123456789
    0         1         2         3         4         5         6         

     Abweichungen der Paketankunftszeiten (relativer Jitter)
15%         |                                                             
11%         |                                                             
 8%       | | |        |                                                  
 5%     | | | |  |  | || |                                                
 1%  | || ||| ||||||||||||  ||  | |                |                      
   +----------------------------------------------------------------------
 ms 0123456789012345678901234567890123456789012345678901234567890123456789
    0         1         2         3         4         5         6         

Kanal ist durch Kunden im Moment nicht abonniert.

Ein MPEG-Transportstrom (ein Programm im Fernseh-Sinne) besteht aus vielen Programmen (im MPEG-TS Sinne), die oben alle tabellarisch aufgelistet sind. Das Programm 0000 ist ein Indexkanal, der festlegt, welcher anderen Programme die Sendung ausmachen und wie sie zusammen spielen. Aber auch ohne diese Detailkenntnis kann man erraten, dass der höchstbandbreitige Anteil die Bildinformation sein wird. Weitere Programme sind Teletext, Untertitel, EPG, einer oder mehrere Audiokanäle. Besonders viele dieser Programme hat ZDF-HD.

Statistik

Diese kurzen Einblicke kann und sollte man auch graphisch aufbereiten, denn oft ist es erst nach dem Vorfall (wie oben aufgezeigt) möglich, sich um die Ursachen kurzer Ausfälle kümmern zu können. dazu braucht man historische Daten.

Um nicht zu viele Daten zu generieren, wird aktuell über eine Minute summiert und so pro Minute und Programm (im MPEG-TS Sinne) ein Messwert generiert. Diese lassen sich dann plotten.

Zuerst einmal die Datenrate als Pakete * Datengröße / Zeit. Man sieht schön, wie das Bildsignal eines HD-Kanals die Bandbreite dominiert.

Interessant ist der Einbruch zwischen 17:30 und 20:00. Das Signal war kurz weg, kam dann mit halber Bandbreite wieder. Eine mögliche Erklärung ist, daß der Sender hier eine Sendung in SDTV eingeschoben hat, die aus einer Fremdquelle konvertiert wurde.

Einige Sender, vor allem die dritten Programme übernehmen zeitweise den kompletten Datenstrom von der ARD. Man sieht deutlich den Wechsel der Programm-Nummer.

Zurück zum Fehler an dem bewussten Abend. Die Anzahl der Full-Frames, also der Wiederaufsetzpunkte für das Bild bzw. die anderen Kompressionsverfahren gibt Aufschluss, ob eine Störung im Netz oder beim Sender vorliegt. Eine Netzkomponente wird üblicherweise nicht das Signal transkodieren und eigenständig Aufsetzpunkte einstreuen:

In dem fraglichen Zeitraum hat also der Sender immer wieder versucht, sein Signal zu resynchronisieren. Natürlich auf einem wesentlich niedrigerem Level als wenn ein HD-Datenstrom abliegen würde. Interessant ist aber auch, wie andere Programme mit erheblich mehr Aufsetzpunkten versorgt werden.

Es kann natürlich sein, dass der Streamer selbst kein Signal anliegen hatte. In dem Fall signalisiert er diese Information mit, um eine komplette Neusynchronisierung des MPEG Programms zu erzwingen.

Es ist deutlich zu erkennen, dass der Streamer zu Beginn der Störung nicht ausreichend neue Information erhalten hat. Die Effekte, die sich dann hinzogen sind aber nicht mehr an dieser Stelle zu suchen.

Eine zweite Fehlerquelle liegt auf Seiten der Sendeanstalt. Die Programme sind untereinander mit einem 33MHz Takt synchronisiert. Dies stellt sicher, dass Bild und Ton nicht auseinander laufen. Der hohe Takt eignet sich auch zur Taktregeneration und -kalibrierung an der Empfangsstelle, wenn dort keine stabilen Quarze vorhanden sein sollten. Trotzdem muss ab und zu dieser Taktquelle getauscht werden. Dann sendet die Anstalt eine entsprechende Markierung, um auch diese Synchronisation neu zu erzwingen.

Auch hier ist deutlich, dass diese Taktinformation schon senderseitig zu den Ausfallzeiten auftrat. Ein Fehler auf Seiten der Netzplattform ist damit eigentlich auszuschließen.

Was aber im Netz auftreten kann sind Paketvertauschungen und -verluste. Diese äußern sich in Fehlern an den Sequenznummern (die allerdings nur zyklisch von 0 bis 15 laufen).

Interessant an diesem Bild sind die kleinen CC-Fehler im Bereich nach 18 Uhr. Hier werden die Datenpakete immer wieder mit Verlusten oder vertauscht beobachtet. Ein Grund könnte sein, dass die Programme vom Sender immer wieder neu synchronisiert werden. Dann kann auch der Sequenzzähler zurückgesetzt werden, was hier offenbar der Fall ist.

Zum Schluss noch ein Blick auf den mittleren Jitter.

Keine weiteren Fragen.

Fazit

Man kann einige hundert Sender ohne extra teure Technik monitoren. Man muss es nur tun.

Ich habe das Problem, dass DSLAMs das DSL-Netz segmentieren, während die Layer2 Wolke es als ein durchgehendes Netz ansehen. Ein Lösungsvorschlag ist, die Layer2 Wolke zu drastisch zu verkleinern. Dies probiere ich aus.

Ausgangslage

Die DSLAMs verhindern eine direkte Kommunikation von CPEs, die an diesem einem DSLAM angeschlossen sind. Eine Firma kann also nicht mit ihren Mitarbeitern im gleichen Dorf kommunizieren, wenn diese von zu Hause arbeiten wollen.

Die kanonische Lösung mit local-proxy-arp besteht darin, dass der Router die ARP-Antworten fälscht und damit die Kommunikation wieder ermöglicht. Leider macht das massiv Probleme, wenn man Redundanz oder mehrere zentrale Geräte in das Netz bringen will.

Netzmaske verkleinern

Wie ich gelernt habe, besteht die branchenübliche Lösung darin, dem Endgerät (CPE) eine extrem kleine Netzmaske (/32) zu geben. Damit glaubt das Endgerät es sei alleine am Netz.

Aber wie erreicht es sein Gateway? Das liegt doch außerhalb des zugewiesenen Netzes? Was man bräuchte wäre folgendes:

# ip address add a.b.c.d/32 dev eth
# ip route a.b.c.e/32 dev eth
# ip route 0.0.0.0/0 via a.b.c.e

Aber wie bekommt man so etwas Krankes der CPE beigebogen? Schließlich hat sich der Kunde den Router selbst gekauft und wir haben keinen Einfluss auf die Kiste.

Alles was, wir tun können, ist eine passende DHCP Antwort schicken. Also probiere ich das mal (ganz vorsichtig)

subclass "Dynamisch" 1:00:90:33:1f:19:1a {option subnet-mask 255.255.255.255;}
subclass "Dynamisch" 1:9c:c7:a6:ba:e0:1b {option subnet-mask 255.255.255.255;}

Das sollte tun (Pools etc. sind anderweitig konfiguriert).

Und nun der Test vom Router aus:

cisco#ping 198.51.100.128

Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 198.51.100.128, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 4/5/8 ms

cisco#ping  198.51.100.201

Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 198.51.100.201, timeout is 2 seconds:
!!!!!
Success rate is 100 percent (5/5), round-trip min/avg/max = 8/12/24 ms

cisco#sh arp | in 198.51.100.128|198.51.100.201
Internet  198.51.100.201          2   9cc7.a6ba.e01b  ARPA   Vlan140
Internet  198.51.100.128          2   0090.331f.191a  ARPA   Vlan140

Tada! Das tut doch schon mal. Und Tests an dem Gerät bestätigen auch die Funktionalität des Internets.

Andere Server

Nun der kompliziertere Teil. Wie kommen zentrale Geräte, die nicht das Gateway sind, mit dem Setup klar?

Probieren wir's aus:

linux# ip addr add 198.51.100.108/23 dev eth_slot
linux# ping -c2 198.51.100.201
PING 198.51.100.201 (198.51.100.201) 56(84) bytes of data.
64 bytes from 198.51.100.201: icmp_seq=1 ttl=64 time=7.01 ms
64 bytes from 198.51.100.201: icmp_seq=2 ttl=64 time=6.83 ms

--- 198.51.100.201 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1004ms
rtt min/avg/max/mdev = 6.834/6.922/7.011/0.121 ms 

Und der Tcpdump dazu sagt:

13:36:57.930798 00:1b:21:2d:3a:bb > 9c:c7:a6:ba:e0:1b, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.201: icmp 64: echo request seq 1

13:36:57.937778 9c:c7:a6:ba:e0:1b > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.201 > 198.51.100.108: icmp 64: echo reply seq 1

13:36:58.935366 00:1b:21:2d:3a:bb > 9c:c7:a6:ba:e0:1b, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.201: icmp 64: echo request seq 2

13:36:58.942188 9c:c7:a6:ba:e0:1b > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.201 > 198.51.100.108: icmp 64: echo reply seq 2 

Geht hin und her. Die Pakete kommen direkt von der CPE (eine Fritzbox) und reden mit dem Server.

Stop mal! Warum kommen die Pakete direkt? Sollten die nicht über den Router gehen?

Offensichtlich hat die Fritzbox gelernt, dass sie dieses Gerät direkt am WAN-Bein erreichen kann und schickt auch die Pakete direkt.

Genauer gefragt: Ist das ein Problem?

Wenn zwei CPEs miteinander reden sollen, aber nicht können (DSLAM-Sperre), dann können sie gegenseitig ihre ARP-Anfragen nicht sehen und beantworten. Also werden sie nie versuchen, direkt miteinander zu kommunizieren. Also kein Problem.

Apropos ARP. Da waren keine ARP-Pakete im Tcpdump. Also nochmal mit gelöschtem ARP-Cache.

linux# arp -d 198.51.100.201
linux# ping  -c2 198.51.100.201
PING 198.51.100.201 (198.51.100.201) 56(84) bytes of data.
64 bytes from 198.51.100.201: icmp_seq=2 ttl=63 time=6.97 ms

--- 198.51.100.201 ping statistics ---
2 packets transmitted, 1 received, 50% packet loss, time 999ms
rtt min/avg/max/mdev = 6.970/6.970/6.970/0.000 ms

Und der Dump dazu:

13:46:38.389346 00:1b:21:2d:3a:bb > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42:
 arp who-has 198.51.100.201 tell 198.51.100.108

13:46:38.390063 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype ARP (0x0806), length 60:
 arp reply 198.51.100.201 is-at 00:07:b4:00:8c:02

13:46:38.390073 00:1b:21:2d:3a:bb > 00:07:b4:00:8c:02, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.201: icmp 64: echo request seq 1

13:46:38.396544 9c:c7:a6:ba:e0:1b > 00:1b:21:2d:3a:bb, ethertype ARP (0x0806), length 60:
 arp reply 198.51.100.201 is-at 9c:c7:a6:ba:e0:1b

13:46:39.389251 00:1b:21:2d:3a:bb > 00:07:b4:00:8c:02, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.201: icmp 64: echo request seq 2

13:46:39.396208 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.201 > 198.51.100.108: icmp 64: echo reply seq 2

Das erste Paket ging über local-proxy-arp und wurde nicht beantwortet.

Das könnte daran liegen, dass die Fritzbox bereits einen ARP EIntrag hat, so dass sie das ankommende Paket als gespooft verwirft. Aber das bedarf noch der Klärung.

Innovaphone

Die andere Test-CPE ist eine Innovaphone.

linux# arp -d 198.51.100.128
linux# ping  -c2 198.51.100.128
PING 198.51.100.128 (198.51.100.128) 56(84) bytes of data.
64 bytes from 198.51.100.128: icmp_seq=2 ttl=127 time=5.86 ms

--- 198.51.100.128 ping statistics ---
2 packets transmitted, 1 received, 50% packet loss, time 1000ms
rtt min/avg/max/mdev = 5.860/5.860/5.860/0.000 ms

Auch das geht! Aber auch hier fehlt das erste Paket. Liegt es am proxy ARP?

13:56:05.356955 00:1b:21:2d:3a:bb > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42:
 arp who-has 198.51.100.128 tell 198.51.100.108

13:56:05.359382 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype ARP (0x0806), length 60:
 arp reply 198.51.100.128 is-at 00:07:b4:00:8c:02

13:56:05.359392 00:1b:21:2d:3a:bb > 00:07:b4:00:8c:02, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 1

13:56:05.362879 00:90:33:1f:19:1a > 00:1b:21:2d:3a:bb, ethertype ARP (0x0806), length 64:
 arp reply 198.51.100.128 is-at 00:90:33:1f:19:1a

13:56:06.356946 00:1b:21:2d:3a:bb > 00:07:b4:00:8c:02, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 2

13:56:06.362793 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.128 > 198.51.100.108: icmp 64: echo reply seq 2 

Diesmal erfolgt der Ping komplett über den zentrale local-proxy-arp Router.

Und noch ein Pingtest bei vorhandenem ARP-Eintrag:

linux# ping  -c2 198.51.100.128
PING 198.51.100.128 (198.51.100.128) 56(84) bytes of data.
64 bytes from 198.51.100.128: icmp_seq=1 ttl=127 time=6.02 ms
64 bytes from 198.51.100.128: icmp_seq=2 ttl=127 time=5.84 ms

--- 198.51.100.128 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1004ms
rtt min/avg/max/mdev = 5.841/5.930/6.020/0.118 ms

Und der Dump dazu:

14:09:37.939110 00:1b:21:2d:3a:bb > 00:07:b4:00:8c:02, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 1

14:09:37.945105 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.128 > 198.51.100.108: icmp 64: echo reply seq 1

14:09:38.943687 00:1b:21:2d:3a:bb > 00:07:b4:00:8c:02, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 2

14:09:38.949516 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.128 > 198.51.100.108: icmp 64: echo reply seq 2 

Die Kommunikation erfolgt komplett über den Router.

Stop mal! Warum antwortet die Innovaphone nicht auf ARP? Für einen zentralen Server heißt das, dass er auf local-proxy-arp angewiesen ist.

Aber genau diese Funktion soll doch abgeschaltet werden! Das ist genau der Zweck der Übung.

Bei einem Versuch einige Minuten später zeigt sich erstaunlicherweise ein anderes Bild

14:23:44.753899 00:1b:21:2d:3a:bb > 00:90:33:1f:19:1a, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 1

14:23:44.759817 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.128 > 198.51.100.108: icmp 64: echo reply seq 1

14:23:45.757222 00:1b:21:2d:3a:bb > 00:90:33:1f:19:1a, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 2

14:23:45.762979 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.128 > 198.51.100.108: icmp 64: echo reply seq 2

Die Pakete werden direkt an die Innovaphone gesendet, aber über den Router beantwortet. Das ist komplett in Ordnung!

Aber was ist da passiert? Ich lösche nochmal den ARP-Cache auf dem Linux und schnüffle mit:

14:38:22.492139 00:1b:21:2d:3a:bb > ff:ff:ff:ff:ff:ff, ethertype ARP (0x0806), length 42:
 arp who-has 198.51.100.128 tell 198.51.100.108

14:38:22.498015 00:90:33:1f:19:1a > 00:1b:21:2d:3a:bb, ethertype ARP (0x0806), length 64:
 arp reply 198.51.100.128 is-at 00:90:33:1f:19:1a

14:38:22.498027 00:1b:21:2d:3a:bb > 00:90:33:1f:19:1a, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 1

14:38:22.503751 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.128 > 198.51.100.108: icmp 64: echo reply seq 1

14:38:22.509747 ac:f2:c5:df:30:3f > 00:1b:21:2d:3a:bb, ethertype ARP (0x0806), length 60:
 arp reply 198.51.100.128 is-at 00:07:b4:00:8c:02

14:38:23.497404 00:1b:21:2d:3a:bb > 00:90:33:1f:19:1a, ethertype IPv4 (0x0800), length 98:
 IP 198.51.100.108 > 198.51.100.128: icmp 64: echo request seq 2

Die Innovaphone scheint sich diesmal kooperativer zu verhalten. Damit hat sie den Test auch bestanden.

Fazit

Der Ansatz scheint zu tun.

• Ein Fritzbox als CPE tut wie erwartet. Die bedient andere Geräte im gleichen Layer2 Netzwerk direkt, sobald sie ARP-Kontakt hatte.
• Eine Innovaphone als CPE tut völlig korrekt. Der Rückweg geht immer den konfigurierten Weg über den Router. Im Test hatte sie sich ab und zu mal zickig, aber kein prinzipelles Problem.

Beide benutzen den Router, der außerhalb ihres logischen Netzsegementes liegt, korrekt. Andere zentrale Komponenten werden ebenso behandelt.

Damit steht einer schrittweisen Einführung nichts prinzipelles im Wege.

Über DirectAccess hatte ich schon einiges erzählt, und natürlich auch ausprobiert. Was ich aber noch nie angesehen habe, war DirectAccess ohne IPv6 im inneren oder äußeren Netz, also total legacy. In der Schulung habe ich die Gelegenheit dazu und möchte die Ergebnisse nicht vorenthalten.

IPv4 only Lab

Nachdem der DirectAccess Client in die weite Welt verschwunden ist, und er voller Verzweiflung nach Hause telefoniert hat, bietet sich folgendes Bild.

C:\> ipconfig
Ethernet adapter Ethernet 2:
   Connection-specific DNS Suffix  . :
   Link-local IPv6 Address . . . . . : fe80::a19f:cc85:1320:8c4%5
   IPv4 Address. . . . . . . . . . . : 131.107.0.2
   Subnet Mask . . . . . . . . . . . : 255.255.0.0
   Default Gateway . . . . . . . . . :
Tunnel adapter iphttpsinterface:
   Connection-specific DNS Suffix  . :
   IPv6 Address. . . . . . . . . . . : 2002:836b:c8:1000:1934:30a2:9e84:cdf4
   Temporary IPv6 Address. . . . . . : 2002:836b:c8:1000:f037:3b8d:cabc:bfcb
   Link-local IPv6 Address . . . . . : fe80::1934:30a2:9e84:cdf4%24
   Default Gateway . . . . . . . . . :

Es gibt also ein Interface im Internet mit öffentlichen Adressen ohne IPv6 Versorgung. Und dann gibt es den Tunnel nach Hause. Da sowohl Client als auch der DirectAccess Server öffentliche IPs haben, wurde der Tunnel mit 6to4-Adressen aufgebaut.

In den Schulungsunterlagen steht Notice the IP address for Tunnel Adapter is IPHTTPSInterface starting with 2002. This is an IP-HTTPS address. (Fehler sind so übernommen)

Nein, Microsoft! Es ist eine 6to4 Adresse. Offenbar habt Ihr wirklich keine praktische Erfahrungen mit IPv6.

Die zugehörige Routingtabelle zeigt:

c:\> route print -6
===========================================================================
Interface List
  5...00 15 5d 64 4d 4d ......Microsoft Hyper-V Network Adapter #2
  1...........................Software Loopback Interface 1
 24...00 00 00 00 00 00 00 e0 iphttpsinterface
===========================================================================
IPv6 Route Table
===========================================================================
Active Routes:
 If Metric Network Destination      Gateway
  1    331 ::1/128                  On-link
 24   4171 2002::/16                fe80::d92f:34d4:3add:e715
 24    331 2002:836b:c8::/48        fe80::d92f:34d4:3add:e715
 24    331 2002:836b:c8::/64        fe80::d92f:34d4:3add:e715
 24    331 2002:836b:c8:1::/64      fe80::d92f:34d4:3add:e715
 24    331 2002:836b:c8:5::/64      fe80::d92f:34d4:3add:e715
 24    331 2002:836b:c8:1000::/64   On-link
 24    331 2002:836b:c8:1000:1934:30a2:9e84:cdf4/128
                                    On-link
 24    331 2002:836b:c8:1000:f037:3b8d:cabc:bfcb/128
                                    On-link
 24    331 fd68:d6bf:56b6:7777::/96 fe80::d92f:34d4:3add:e715
  5    271 fe80::/64                On-link
 24    331 fe80::/64                On-link
 24    331 fe80::1934:30a2:9e84:cdf4/128
                                    On-link
  5    271 fe80::a19f:cc85:1320:8c4/128
                                    On-link
  1    331 ff00::/8                 On-link
  5    271 ff00::/8                 On-link
 24    331 ff00::/8                 On-link
===========================================================================
Persistent Routes:
  None

Das Routingziel ist eine Link-Local-Adresse, wie es sich für IPv6 gehört. Prima! Und die Adresse ist auch über den Tunnel erreichbar.

C:\>netsh int ipv6 sho nei 24
Internet Address                              Physical Address   Type
--------------------------------------------  -----------------  -----------
2002:836b:c8:1000:d92f:34d4:3add:e715                            Reachable (Router)
fe80::d92f:34d4:3add:e715                                        Reachable (Router)

Spielt man nun mit Browser und Explorer im Netz rum, gibt es offene Verbindungen:

C:\> netstat -n
Active Connections
  Proto  Local Address          Foreign Address        State
  TCP    131.107.0.2:49782      131.107.0.200:443      ESTABLISHED
  TCP    [2002:836b:c8:1000:f037:3b8d:cabc:bfcb]:49785  [fd68:d6bf:56b6:7777::ac10:c8]:80  ESTABLISHED
  TCP    [2002:836b:c8:1000:f037:3b8d:cabc:bfcb]:61893  [fd68:d6bf:56b6:7777::ac10:b]:80  ESTABLISHED

Die Verbindungen sind also offenbar über IPv6 zu einem ULA-Ziel (bäh!).

Das DirectAccess-Gateway macht noch NAT64, bettet also die IPv4 Adressen der LAN-Geräte ins IPv6 ein. Sieht man deutlich.

Dazu muss das Gateway offenbar auch DNS64 machen, um die DNS Antworten umzubiegen. Das sieht man leicht:

c:\>ipconfig /displaydns
Windows IP Configuration
    directaccess-webprobehost.adatum.com
    ----------------------------------------
    Record Name . . . . . : directaccess-WebProbeHost.Adatum.com
    Record Type . . . . . : 28
    Time To Live  . . . . : 213
    Data Length . . . . . : 16
    Section . . . . . . . : Answer
    AAAA Record . . . . . : fd68:d6bf:56b6:7777::ac10:c8

Aber warum macht der Client das? Der hat doch einen ganz anderen DNS Server?

C:\>netsh name show eff
DNS Effective Name Resolution Policy Table Settings

Settings for .Adatum.com
----------------------------------------------------------------------
DirectAccess (Certification Authority)  :
DirectAccess (IPsec)                    : disabled
DirectAccess (DNS Servers)              : 2002:836b:c8:3333::1
DirectAccess (Proxy Settings)           : Bypass Proxy

Settings for DirectAccess-NLS.Adatum.com
----------------------------------------------------------------------
DirectAccess (Certification Authority)  :
DirectAccess (IPsec)                    : disabled
DirectAccess (DNS Servers)              :
DirectAccess (Proxy Settings)           : Use default browser settings

Der Client hat also eine Policy für die Namensauflösung, die bei bestimmten Domains einen anderen DNS Server befragt. Genau, das Gateway.

C:\> ping lon-svr1.adatum.com
Pinging lon-svr1.adatum.com [fd68:d6bf:56b6:7777::ac10:b] with 32 bytes of data:
Reply from fd68:d6bf:56b6:7777::ac10:b: time=4ms
Reply from fd68:d6bf:56b6:7777::ac10:b: time=10ms
Reply from fd68:d6bf:56b6:7777::ac10:b: time=1ms
Ping statistics for fd68:d6bf:56b6:7777::ac10:b:
    Packets: Sent = 3, Received = 3, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
    Minimum = 1ms, Maximum = 10ms, Average = 5ms

Allerdings funktioniert das nur, wenn diese Policy Regeln auch von der Applikation berücksichtigt werden:

C:\> nslookup lon-svr1.adatum.com
Server:  UnKnown
Address:  131.107.0.100

DNS request timed out.
    timeout was 2 seconds.
*** Request to UnKnown timed-out

Fragt man den richtigen Server, gibt es ganz andere Antworten:

C:\> nslookup lon-svr1.adatum.com 2002:836b:c8:3333::1
Server:  UnKnown
Address:  2002:836b:c8:3333::1

Non-authoritative answer:
Name:    lon-svr1.adatum.com
Addresses:  fd68:d6bf:56b6:7777::ac10:b
          172.16.0.11

All das ist mir all die Jahre verborgen geblieben, weil ich IPv6 ausgerollt hatte.

Ich vermisse nichts.

Was IPv6 ändert

Wird auf dem Außeninterface natives IPv6 eingesetzt, verschwinden sofort die 2002-er 6to4 Adressen. Dazu ist anzumerken:

• Das im Lab die Kommunikation geklappt hatte, liegt daran, dass Microsoft das 2002:836b:c8:1000::/64 auf dem Interface betreibt.
• Um mit 6to4 Adressen zu kommunizieren, muss man sich auf externe 6to4 Gateways verlassen. Dies kommt ins Spiel, weil der DNS Server 2002:836b:c8:3333::1 angesprochen wird.
• Da beide Hosts über den IPv4-HTTPS-Tunnel IPv6 im externen Routing komplett umgehen, benötigen sie keine 6to4 Router im Internet.
• Da beide Server extern öffentliche IPv4 Adressen haben, wird überhaupt 6to4 benutzt. Steht ein Gerät hinter NAT wird es auf Teredo zurück fallen.
• Teredo funktioniert nicht mit allen NAT-Typen, speziell gibt es Probleme, wenn die öffentliche NAT-IP nicht stabil ist (z.B. bei Carrier Grade NAT oder Large Scale NAT)
• Mit RFC 6540 ist IPv6 auf den Außeninterfaces Pflicht für die ISPs.

Wird IPv6 im LAN eingesetzt, verschwindet sofort das fc00::/7 ULA Netz. Stattdessen bekommen die Clients die gleiche IP, wie sie auch im LAN hätten. Das hat folgende Implikationen:

• Der Client ist intern, wie extern unter der gleichen IP ansprechbar.
• Die Fernwartung wird damit im Unternehmen unabhängig vom Aufenthaltsort des Clients.
• Da Server und Clients IPv6 einsetzen, entfällt DNS64 und NAT64.
• Applikationen können mit allen benötigten Ports Verbindungen in alle benötigten Richtungen ausführen. Es ist nicht notwendig im DirectAccess-Server NAT-Helper pro Protokoll zu haben.
• Auf diese Weise funktionieren Protokolle wie Telefonie, Videokonferenzen, FTP, etc. pp. einfach auch extern.
• Fremdapplikationen, die ihre eigene Namensauflösung fahren, funktionieren problemlos, weil sich nur das Routing zum DNS Server ändert. Es ist nicht länger notwendig, sich Domainabhängig an unterschiedliche DNS Server zu wenden.

Man sollte sich also wirklich überlegen, ob man weiter auf IPv6 verzichten will.

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.

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.

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

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:

• 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.