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
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= dst= 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 ( 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
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 (, 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= dst= 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 ( 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

#!/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(
        ) / IPv6(
            ) / UDP(
                dport=520,         # RIP
                ) / Raw(
                    load="\x00" * 24,


sendp(frame, iface=SOURCE_INTF)

Sep 22, 2019

Outage RFO for September 6th/7th, 2019

Deutsche Übersetzung weiter unten.

Friday September 6th, the Selfnet core network was completely offline for a few hours. Getting the network back online took a few hours, but also led us down the wrong path. Because of that, more (but also shorter) outages followed. So what happened? Here's the Reason For Outage (RFO).

Volunteer Work

Selfnet is powered by 100% volunteer work. Friday morning in early September is probably the worst time for a big outage. Students are often not on campus, or when they are, they're preparing for exams. This of course also applies to the Selfnet folks. Early September is also a very busy time, because students move in and out of the dormitories, so there's a lot to do at the currently six Selfnet offices.

That means: an outage during those times is especially painful, because there is already a lot of work and few of us are here. So if you would like to join us, learn, experiment and build cool stuff with us, please don't hesitate to visit or email us!


So here is what happend, in chronological order.

Thursday, around 9pm

We have been using Juniper EX4500 switches for our network core since we bought them in 2012. We also have some EX4600 which is a newer platform. They seem to have fewer bugs, better CPU, etc. and so we decided to replace the remaining EX4500. On Thursday, the two core switches "vaih-core-1" and "vaih-core-3" were replaced. We already have a few EX4600 and they run smoothly with the features we're using, so we didn't expect any issues.

Selfnet Core Topology

Selfnet Core Topology

As you can guess from the topology, everything should be redundant. Even the access switches are usually interconnected, so we can replace the core switches one by one, without any outages.

After the replacement, we didn't see any issues, everything was running fine as usual.

the three core switches

vaih-core-1/2/3 (top to bottom: EX4600, EX4500, EX4600)

Friday, 2:18am

Selfnet is suddenly offline. A few of us are still awake and try to find out what has gone wrong. As you can seen in the topology, there is enough redundancy and this should never happen.

Friday, 3:26am

There seems to be an issue with one of the NAT/firewall machines, traceroutes are stuck there and they don't seem to be forwarding traffic. nat-1 gets rebooted, but won't boot because of hardware issues. When nat-1 is finally back, the connection tracking daemon "conntrackd" doesn't start and needs manual intervention.

After some more debugging, the guys who were still awake gave up and went to bed.

Friday, around 6am

More people wake up. Since Selfnet is still offline, email, Jabber and IRC-chat aren't working. We're setting up an emergency communication IRC channel on another IRC network and create a CryptPad to collect all the information we have and coordinate work.

Friday, 8:57am

Someone is back on site. Routing looks fine, but traceroutes end at nat-2. The forwarding between core and edge routers seems to be broken, but routing still uses this path, as OSPF packets get though. The firewall nat-2 won't let anyone log in, probably because of high load or forwarding issues. As a last resort, nat-2 gets rebooted, too. Somehow this solves the problem.

We notice that the core switches have logged "DDoS violations". That could mean a storm of OSPF packets because of link flaps or duplicate packets introduced by forwarding issues.

We're not sure yet, why the forwarding stopped working, but let OSPF packets through, but for now Selfnet is back in business. Since the mailserver is back online, we're receiveing well over 100 emails from members with questions and complaints. So we start answering them, telling everyone that we had an outage, that it's working again, that we're still investigating the root cause and therefore might have another interruption.

grafana visualisation of new or open tickets over time

Visualisation of new or open tickets in our ticket system (emails sent to being rapidly answered by volunteering members.

Friday, between 9am and 10am

Still debugging the outage. The logs show recoverable memory issues (i.e. not hardware faults). So that would explain why a reboot solved the problem.

nat-1 gets a run of "memtest" to check the RAM banks for any physical damage, but it shows no errors.

Friday, 11:45am

Currently both IPv6 and IPv4 gets routed via nat-2. We usually split the traffic by address family, so nat-1 handles IPv4 and nat-2 handles IPv6 by default. They also sync their connection tracking states, so a failover won't damage any open connections and nobody will notice.

We're reverting back to splitting the traffic and moving IPv4 back to nat-1.

Friday, 2:20pm

Another outage. This time, only IPv4 is affected. nat-1 shows high CPU load, which is almost exclusively SoftIRQs. We analyzed this in a previous blog post (german) and the level of SoftIRQs is pretty much an indicator of the amount of traffic (packets per second) going through the firewall. This is either a hefty DDoS attack, a problem of nat-1 or packets bouncing back and forth between the routers.

For some reason, another reboot of nat-1 resolves the problem.

Friday, 10pm

The same problem now happens with IPv6 via nat-2. Again, SoftIRQs are at 80% (which, if you consider the impact of hyperthreading means about 100% hardware utilization).

Screenshot of the Grafana SoftIRQ CPU usage monitoring

Screenshot of the Grafana SoftIRQ CPU usage monitoring

We already know that for some reason, a reboot can fix this, so we're rebooting nat-2, to get traffic flowing for the users, although this makes it harder for us to debug.

Traffic for both IPv4 and IPv6 is moved back to nat-2 now.

Saturday, 0:30am

SoftIRQs on both nat-1 and nat-2 are rising again, now both firewalls are again in trouble and the network gets unstable.

Saturday, 6am

Again, the firewalls collapse and the network is down.

Unfortunately, nobody is there to reboot the boxes, and since everything is down, we can't reboot the boxes remotely.

Saturday, 9:20am

Another reboot fixes the problem again.

Photo of from Saturday morning.

Uplink graph showing traffic increase when the problem is fixed (again) around 9:20 AM and another sharp drop in traffic volume at 12 AM.

Saturday, 12am

The issue is back again. We notice that both new core routers have high CPU utilization. The "Packet Forwarding Engine Manager", fxpc is using up all the resources. The other EX4600 in our network have a different (older) software version than the two new ones, so we decide that this might be another JunOS bug that was introduced in the new firmware. Sadly, this happens a lot with network vendor firmware. We decide to downgrade to the known good release that's running on the other EX4600s. During the downgrade, we see crashes and kernel dumps. The installation then fails due to filesystem erros. A complete reformat of the disks and a fresh installation finally gets them running again.

After both boxes have been downgraded, CPU utilization is back to normal, and fxpc is in the lower single-digit CPU percentage. Also, the OSPF issues are gone, the firewalls are working normal again, and we haven't seen this issue since.

So what happened?

It's hard to tell for sure, but we think that the Juniper boxes have a bug that's causing forwarding and OSPF issues. If you look at the SoftIRQ monitoring, it was always one CPU core that was overloaded during the outages. Usually the packets are load-balanced on all the CPU cores. The decision, which core to use is made on a per-flow basis, which means that a packets source and destination IP address and port and the protocol number are hashed. The hash sum is then used to point at one CPU core. If all packets have the same flow hash, they are all handled by the same CPU core.

Therefore we think that there had to be some kind of forwarding issue, where certain packets bounced back and forth between firewalls and core switches, until the link and single-core performance was saturated with handling those packets. Sadly, we focused on fixing this issue as quick as possible and didn't collect any packet dumps to analyze this issue further.

What now?

For now, the problem seems to be solved after the firmware downgrade. At the moment there is still an ongoing service request where Juniper is trying to resolve the problem - because although it is not really noticable - both new EX4600 core switches still have severe CPU utilisation spikes which does not look healthy.

But also (as we already noted in the NAT and firewall blog post) the firewall servers are a bit outdated. There are plans to replace them with new gear. We currently have demo equipment with modern AMD Epyc CPUs and 4x 10GbE NICs and will replace the old boxes soon.

Server with AMD Epyc CPU

AMD Epyc Demo Equipment for testing

There are also ideas to change the topology, so only user traffic passes the firewalls and server traffic goes to a separate DMZ.

Deutsche Übersetzung

Bericht über die Ausfälle vom Freitag und Samstag (6. und 7.9.)

Am Freitag Anfang September war das Wohnheimnetz für mehrere Stunden offline. Die Verbindung zum Internet wieder aufzubauen dauerte mehrere Stunden und hat uns erst einmal auf den Holzweg geführt. Deshalb folgten mehrere kürzere Ausfälle. Was war nun der Grund des Ausfalls?

Ehrenamtliche Arbeit

Der Selfnet e.V. wird zu 100% von ehrenamtlich aktiven Mitgliedern (Studierenden) getragen. Freitag morgens Anfang September ist vermutlich die schlechteste Zeit für einen Ausfall. Studierende sind aber nicht immer auf dem Campus bzw. wenn sie es sind lernen sie für Prüfungen. Das trifft natürlich auch auf die Mitglieder von Selfnet zu. Anfang September ist auch die Zeit zu der viele ins Wohnheim einziehen und dann Mitglied von Selfnet werden wollen und so lange Schlangen in den Sprechstunden entstehen.

Das beduetet: Ein Ausfall während dieser Zeit tut ziemlich weh, da sowieso viel Arbeit anfällt und wenige von uns Zeit haben oder überhaupt vor Ort sind. Wenn du also lust hast etwas neues zu lernen, zu experimentieren und coole Dinge mit uns zu bauen: Schreib uns einfach eine kurze E-Mail.


Also was ist nun - zeitlich geordnet - passiert?

Donnerstag Abend gegen 21 Uhr

Seit ca. 2012 verwenden wir Juniper EX4500 Layer3-Switche um alle Pakete im Kernnetz (core) zu routen. Mittlerweile setzen wir auch schon seit 1-2 Jahren das Nachfolgemodell EX4600 ein. Technisch gesehen handelt es sich um eine ganz neue Technik und bis jetzt war der Eindruck: Weniger Fehler/Bugs, bessere CPU, etc. und deswegen haben wir entschieden 2 der bisherigen EX4500 zu ersetzen. Am Donnerstag wurden nacheinander "vaih-core-1" und "vaih-core-3" ersetzt. Die bisherigen EX4600 die wir einsetzen haben immer gut funktioniert und dementsprechend haben wir keinerlei Probleme erwartet.

Selfnet Core Topology

Selfnet Core Topologie

Wie du vielleicht über die Topologie vermuten kannst ist alles Redundant. Sogar alle Access-Switche (also die Switche, an die die Zimmer direkt angeschlossen sind) sind üblicherweise an mehr als einem Core Switche angeschlossen und deshalb können wir diese Geräte auch austauschen ohne, dass ein Ausfall entsteht.

Direkt nach dem Austausch gab es keinerle Probleme. Alles schien gut zu funktionieren.

the three core switches

vaih-core-1/2/3 (von oben nach unten: EX4600, EX4500, EX4600)

Freitag 2:18 Uhr morgens

Selfnet ist plötzlich offline. Ein paar Selfnetter sind noch wach und versuchen herauszufinden was schief gelaufen ist. Wie du auf der Topologie sehen kannst: Das sollte nicht passieren. Der Ausfall eines einzelnen Gerätes sollte nie das gesamte Netz betreffen.

Freitag 3:26 Uhr morgens

Es sieht so aus als gäbe es ein Problem mit einer der NAT/Firewall Server. Traceroutes bleiben stecken und es scheint auch sonst kein Datenverkehr weitergeleitet werden. nat-1 wird neu gestartet, bleibt aber beim hochfahren aufgrund von Hardwarefehlern stecken. Als nat-1 schlussendlich hochgefahren ist verweigert "conntrackd" (der Dienst der für das Funktionieren von Netzwerkadressübersetzung / NAT notwendig ist) den Start.

Nach mehr Fehlersuche der noch "wachen" Mitglieder geben diese der Müdigkeit nach und gehen schlafen.

Freitag um 6 Uhr morgens

Mehr Mitglieder wachen auf. Da Selfnet immer noch offline ist, sind natürlich auch E-Mail, Jabber und der IRC-Chat außer funktion. Wir öffnen einen Notfall IRC Kanal in einem anderen IRC Netzwerk und erstellen ein CryptPad um alle Informationen zu sammeln und alles zu koordinieren.

Freitag um 8:57 Uhr morgens

Halbwegs ausgeschlafene Mitglieder sind vor Ort (Serverraum). Das Routing scheint in Ordnung zu sein aber Traceroutes enden bei nat-2. Das Weiterleiten von Paketen zwischen Core und Edge Routern (siehe Topologie) scheint kaputt zu sein aber das Routing nimmt trotzdem noch diesen Pfad, da die OSPF Pakete (Routing Protokoll) immer noch durch kommen. Die Firewall nat-2 lässt es nicht zu, dass sich jemand einloggt. Wir vermuten wegen hoher CPU-/System-Last und Problemen bei der Weiterleitung von Paketen. Als letzten Ausweg wird nun auch nat-2 neu gestartet. Unerklärlicherweise funktioniert jetzt plötzlich wieder alles.

Uns fallen in den Logs der Cores "DDoS violations" auf. Dies könnte an einem Sturm von OSPF Paketen (aufgrund von "link flaps") oder duplizierten Paketen durch die nicht funktionierenden Weiterleitung der Pakete liegen.

Wir sind noch nicht sicher warum die Weiterleitung von allen anderen Datenpaketen durch die NATs/Firewalls nicht mehr funktioniert hat obwohl OSPF Pakete weitergeleitet wurden. Da jetzt auch der Mailserver wieder online ist bekommen wir über 100 E-Mails von anderen Mitgliedern mit Fragen und Beschwerden zum Ausfall. Wir fangen an die E-Mails zu beantworten und teilen mit, dass es einen Ausfall gab, das es jetzt wieder funktioniert und wir immer noch nach der Ursache suchen.

grafana Visualisierung von neuen oder offenen Tickets über Zeit

Visualisierung von neuen und offenen Tickets (E-Mails an die von ehrenamtlich aktiven Mitgliedern rapide beantwortet werden.

Freitag zwischen 9 und 10 Uhr morgens

Wir sind immer noch auf Fehlersuche. Die Logs zeigen "wiederherstellbare" Probleme mit dem Arbeitsspeicher (vermutlich also kein Hardware Problem). Das würde erklären warum ein Neustart das Problem gelöst hat.

nat-1 wird zur Sicherheit mit "memtest" geprüft ob der Arbeitsspeicher (RAM) physisch in Ordnung ist. Es werden keine Fehler gefunden.

Freitag um 14:20 Uhr mittags

Ein weiterer Ausfall. Dieses Mal ist nur IPv4 betroffen. nat-1 zeigt eine hohe CPU Last die hauptsächlich aus SoftIRQs besteht. Das haben wir schon einmal in einem vorherigen Blogeintrag analysiert und die Anzahl der SoftIRQs ist üblicherweise ein guter Indikator von hohem Verkehrsaufkommen (Pakete pro Sekunde, nicht Volumen) die durch die Firewall fließen. Es handelt sich also entweder um einen heftigen DDoS Angriff, ein Problem mit nat-1 oder Pakete springen zwischen den Routern hin und her.

Aus irgendeinem Grund löst ein Neustart von nat-1 das Problem.

Freitag 22 Uhr abends

Das selbe Problem tritt mit IPv6 über nat-2 auf. Wieder SoftIRQs bei 80% was - wenn man Hyperthreading bedenkt - etwa 100% Hardwareauslastung entspricht.

Screenshot of the Grafana SoftIRQ CPU usage monitoring

Screenshot aus unserem Grafana der SoftIRQ CPU Auslastung

Wir wissen schon, dass aus irgendeinem Grund ein Neustart das Problem löst. Also starten wir nat-2neu und die Daten unserer Mitglieder fließen wieder. Allerdings macht das die Fehleranalyse nicht unbedingt einfacher.

Der Datenverkehr wird jetzt für IPv4 und IPv6 gleichermaßen über nat-2 geleitet.

Samstag 0:30 morgens

SoftIRQs auf nat-1 sowie nat-2 steigen wieder an. Nun haben beide Firewalls wieder Probleme und das Netzwerk wird instabil.

Samstag 6 Uhr morgens

Wieder kollabieren die Firewalls und das Wohnheimnetzwerk ist offline.

Unglücklicherweise ist niemand vor Ort um die Firewalls neu zu starten und da alles offline ist können wir sie nicht aus der Ferne neustarten.

Samstag 9:20 Uhr morgens

Ein weiterer Neustart löst wieder das Problem.

Foto von am Samstagmorgen.

Uplink Graph der zeigt wie sich nach wiederholter "Behebung" des Problems die Menge des übertragenen Datenverkehrs gegen 9:20 Uhr erhohlt und dann wieder um 12 Uhr stark einbricht.

Samstag 12 Uhr

Das Problem ist zurück. Wir bemerken das beide der neuen Core Router eine hohe CPU auslastung aufweisen. Der "Packet Forwarding Engine Manager", fpxc nutzt alle zur Verfügung stehende Ressourcen aus. Die anderen EX4600 die wir bis jetzt in unserem Netz eingesetzt haben verwenden eine andere - ältere - Firmware (Software) Version als die beiden neuen. Wir vermuten jetzt, dass es sich um einen Fehler von JunOS (Betriebssystem für Juniper Router/Switche) handelt der in einer neueren Version vorhanden ist. Leider passiert so etwas öfters bei Firmware von Netzwerkhardwareherstellern. Wir entscheiden uns für ein "Downgrade" zu der - bekanntlich - funktionierenden Version von JunOS die auf den bisherigen EX4600 schon gut funktioniert. Während des Downgrades sehen wir Crashes und Kernel Dumps. Die Installation schlägt dann mit Dateisystemfehlern fehl. Nach dem kompletten Neuformatieren der Festplatten und einer sauberen Installation funktioniert jetzt wieder alles.

Nachdem die Kisten auf die ältere Version downgegraded wurden ist die CPU Auslastung wieder normal und fxpc nutzt nur noch eine einstellige Prozentzahl der CPU. Auch die Probleme mit OSPF sind verschwunden, die Firewalls funktionieren wieder normal und seit dem haben wir auch keine weiteren Probleme beobachtet.

Also was ist passiert?

Im Nachhinein kann können wir leider nicht mit Sicherheit sagen, wo das Problem ganz genau lag. Wir vermuten aber, dass die Juniper Kisten einen Bug hatten, der die Forwarding- und OSPF-Probleme ausgelöst hat. Man kann im SoftIRQ Monitoring sehen, dass während den Ausfällen immer ein CPU Core überlastet ist. Normalerweise werden die Pakete in der Firewall auf alle Cores verteilt. Die Zuweisung, welcher Core für ein Paket zuständig ist, passiert pro Flow. Das bedeutet, die Source- und Destination-Adresse, sowie die Portnummern und die Protokollnummer werden gehasht. Die Hashsumme wird dann verwendet, um den Core auszuwählen, der das Paket verarbeitet. Wenn alle ankommenden Pakete den gleichen Flow Hash haben, werden sie vom gleichen Core verarbeitet.

Wir gehen deshalb davon aus, dass es ein Forwardingproblem gab, das dazu geführt hat, dass Pakete zwischen Core-Switch und Firewall hin- und hergeworfen wurden, bis der Link gefüllt und der CPU Core ausgelastet war. Wir haben uns leider sehr darauf konzentriert, das Problem zu lösen und haben dabei keine Packet Dumps gesammelt, die wir jetzt analysieren könnten, um den Bug genauer festzupinnen.

Was nun?

Kurzfristig scheint das Problem durch das Downgrade der Firmware behoben zu sein. Im Moment läuft noch ein offener "service request" bei Juniper in dem Juniper versucht das Problem zu beheben, denn obwohl man es nicht wirklich bei der Nutzung des Wohnheimnetzwerks merkt haben beide der EX4600 Core Switches immer noch regelmäßig Spitzen bei der CPU auslastung die nicht wirklich gesund aussehen.

Allerdings (wie wir schon im NAT/Firewall Blogartikel erwähnt haben sind unsere Firewall Server schon etwas älter. Es gibt schon Pläne diese mit neuer Hardware zu ersetzen und zur Zeit haben wir Testgeräte mit sehr modernen AMD Epyc CPUs und 4x 10 Gigabit Netzwerkkarten die vermutlich bald die alten Firewalls ersetzen soll da.

Server with AMD Epyc CPU

AMD Epyc Testhardware

Außerdem gibt es Pläne die Topologie zu ändern, so dass der Datenverkehr der Mitglieder und der Firewalls durch eine jeweils separate DMZ fließt.

Dec 16, 2018

Die Selfnet-Firewalls und ihre Grenzen

Selfnet verwendet zwei Server für Firewall und NAT. In den letzten Tagen war die Internetanbindung durch diese Firewalls immer wieder mal etwas wackelig. Wir haben mal tief reingeschaut, was diese beiden Server machen, wo Bottlenecks sein könnten, und wie wir mögliche Performanceprobleme lösen können.

Wir wollen hier mal aufschreiben, was die Server machen, welche Probleme wir gefunden haben, und wie es weitergeht. Es wird also sehr technisch und detailiert!

perf top flame graph, verschmälert, illustrativ

Server als Firewall?

Bei Selfnet gibt es für alle User IPv4 und IPv6 Adressen. Bei IPv4 werden intern Adressen aus einem privaten Bereich pro Zimmer oder WLAN-Client vergeben. Jedes Mitglied hat eine öffentliche IPv4-Adresse. Es muss also eine Umsetzung, sprich Network Address Translation (NAT) passieren. Die Konfiguration für das NAT, für Portforwardings und für die IPv6-Firewall wird aus einer Datenbank generiert.

NAT und Firewall halten große Tabellen mit states der einzelnen Verbindungen. Grundsätzlich lässt sich das gut mit Servern machen. Die Last wird auf alle CPU-Kerne verteilt, für die Firewallregeln und state Tabellen ist im RAM genug Platz.

Topologie des Core-Netzwerks

Selfnet Core Netztopologie

Die Firewalls sind im Netzwerk zwischen den Border-Routern (Uplink zum BelWü) und den Core-Routern in Vahingen eingebaut und firewallen damit ganz Selfnet. Um Redundanz für Ausfälle zu haben sind es zwei Stück. Eines macht primär IPv4 und eines macht primär IPv6. Beide synchronisieren die states mittels conntrackd, sodass ein Failover sehr wenig Impact hat.

Wo ist das Problem?

In den letzten Wochen haben sich mehrere Leute gemeldet und über hohe Round-Trip Times (RTT) geklagt. Die meisten davon sind Gamer, denen "ein hoher Ping" natürlich keinen Spaß macht. An manchen Abenden stieg die RTT über 300ms, was die Internetanbindung deutlich beeinträchtigt.

Durch hohe RTT dauern zum Beispiel TCP Handshakes länger, weshalb Websites langsamer laden, und der Datendurchsatz zum Beispiel bei TCP sinkt deutlich.

Intern war dieses Problem nicht sichtbar, nur vom/zum restlichen Internet. Zusätzlich waren hohe Latenzen im Spiel, was auf die Firewall schließen lässt. Die Router und Switche haben üblicherweise keine großen Buffer und können in unserem Fall maximal ca. 200ms RTT induzieren.

Was passiert da?

Das Leben eines IP-Paketes, das durch unsere Firewall geht ist... kompliziert.

Es landet erstmal im Receive Buffer der Netzwerkkarte und wird in eine Queue (max. 128, bei uns 16 wegen 16 CPU Threads) gesteckt. Die Karte löst einen Interrupt aus, damit die Pakete in der Queue vom System abgearbeitet werden. Dann kommt der Linux Kernel dran und arbeitet die Pakete in einem Soft-IRQ im Kernel-Space ab.

Packet Flow in Netfilter and General Networking

Packet Flow in Netfilter: jedes Paket durchläuft viele Stationen, an denen es geprüft, geroutet, verändert, getaggt oder genattet wird. Grafik von Jan Engelhardt, CC-BY-SA-3.0

Zunächst schaut conntrack nach, ob es zu einer Verbindung gehört, die schon bekannt ist. Dafür hält es eine Hashmap mit allen bekannten Verbindungen, macht darin einen Lookup und taggt das Paket zum Beispiel mit "established". Das ist wichtig, weil man damit ermöglichen kann, dass ein User von innen heraus eine Verbindung öffnen kann (z.B. zu einer Website), aber keine Verbindung von außen geöffnet werden kann, ohne dass der User das will. Eine klassische Stateful Firewall eben.

Danach kommen iptables Regeln, konkret Mangle und NAT. Hier gibt es Chains für jeden User, die z.B. eine User-ID an das Paket taggen und NAT machen, sofern die Regel oder conntrack das erlauben. Falls ein neuer Eintrag in conntrack entsteht, wird dieser mittels conntrackd auch auf die andere Firewall synchornisiert, sodass wir ein hot-standby haben. Die Regeln des iptables werden aus der User- und Netzdatenbank alle paar Minuten autogeneriert.

Wenn das alles geschafft ist, werden die User-IDs noch verwendet, um Traffic-Accounting (Info für den User) und um Traffic Shaping zu machen. Das Shaping greift eigentlich nur in zwei Fällen: entweder, wenn der Internetuplink an der Lastgrenze sein sollte. Dann wird versucht, die User mit viel Traffic zu bremsen, damit nicht ein paar wenige "bad guys" das Netz ausbremsen können. Oder ein User hat z.B. einen Testzugang, dann shapen wir aktuell auf ein paar MBit/s.


Derzeit (Dezember 2018) enthält die conntrack Tabelle zu Spitzenzeiten gut 200k Verbindugen. Auf der Primär-Firewall für IPv4 lasten dann gut 5 GBit/s (nach Innen) und 1 GBit/s (nach Außen) Traffic mit insgesamt knapp 700k Packets per Second (PPS).

Das Rule-Set für iptables ist rund 40MB groß und enthält 1,6 Mio. Regeln.

Bemerkenswert ist dabei, dass die beiden Firewall-Server mittlerweile seit über 8 Jahren im Einsatz sind und ursprünglich für ca. 2500 Selfnet-User konzipiert waren. Mittlerweile hat sich diese Zahl mehr als verdoppelt und die Server sind doch etwas in die Jahre gekommen.

Die Frage ist: Würde neue Hardware das Problem lösen? Trotz des Alters der Server sind diese technisch nicht schlecht: jeder hat 2 CPUs mit insgesamt 8 physischen Kernen, die bei 2,4 GHz takten. Wenn man sich Moore's Law anschaut, würde man in 8 Jahren einen Faktor 32 in der CPU-Leistung erwarten. Tatsächlich ist man im wirtschaftlich sinnvollen Bereich eher bei einem Faktor von 4 bis 8. Wie viele Jahre würden neue Firewall-Server halten, bis wir wieder an Grenzen stoßen?

Also was tun?

Eine Option wäre, potentere Hardware zu kaufen. Alternativ lassen sich vielleicht Optimierungen finden, die nochmal ein paar Prozent rausquetschen. Oder wir bauen Features aus, die nicht zwingend benötigt werden, bzw. lagern diese auf andere Systeme aus. Hm.


Um informierte Entscheidungen zu treffen, wollen wir einmal ganz tief in die Firewalls reinschauen. Wo genau werden CPU-Zyklen verbraten? Gibts Features, die wir nicht (mehr) brauchen? Was wären die Anforderungen an neue Hardware?

Also: Was passiert bei einer Lastspitze? Offensichtlich ist schonmal: die RTT steigt, der Traffic sinkt, bzw. kommt im Mittel an eine Grenze. Gleichzeitig zeigt uns das Monitoring: die CPUs arbeiten weniger Interrupts pro Sekunde ab, befinden sich aber zu fast 100% im Interrupt-Handling. Die Load ist in diesen Momenten ungefär bei 8, was der Anzahl der cores (nicht Threads) entspricht. Die CPU Kerne peaken kurzzeitig bei 100% Last, sind im Mittel aber bei ca. 50% Idle bzw. 50% Soft-IRQ. Vermutlich ist Hyperthreading hier nicht hilfreich.

Plot der Interrupts pro Sekunde und der Anteiligen CPU-Zeit in Interrupts

Interrupts: bearbeitete Interrupts pro Sekunde (oben, gelb) und Anteil an Interrupts der CPU-Zeit pro Core (unten)

Wir schließen daraus, dass die CPU-Cores ab einem gewissen Punkt die Pakete in einer Queue nicht mehr schnell genug abarbeiten können und deshalb länger in einem Interrupt bleiben. Prinzipiell bedeutet das weniger Context Switches und weniger Cache Flushes, was ein kleines bisschen Geschwindigkeit bringt, allerdings gibt es offenbar trotzdem den Punkt, wo die Queues sehr groß werden und dadurch hohe RTTs entstehen. Da sich das Gesamtsystem (inkl. der Clients) gewissermaßen selbst regelt, haben wir praktisch keine Packet Drops.

Warum dauert das in den Interrupts denn so lange?!

Praktisch unsere gesamte Packet Processing Pipeline findet im Kernel statt. Mit dem Tool perf top kann man gut sehen, in welchen Threads der Kernel sich am meisten aufhält. Wir haben vorher die CPU Taktfrequenz aufs Maximum festgenagelt. Damit sind die Zahlen ein guter Anhaltspunkt für die tatsächliche Hardwareauslastung.

Output von perf top - iptables braucht am meisten CPU Zyklen

Output von perf top: Zeigt die Kernelfunktionen, die die meisten CPU-Zyklen verheizen

Die beiden größten Zyklenfresser sind der Durchlauf des großen iptables Regelwerks und die tc shaper mit je ca. 15-20%, je nach Last. Nochmal gut 6% gehen für die Netzwerkkartentreiber ixgbe drauf und conntrack (inklusive seiner Funktion tcp_packet) macht nur ca. 4-5% aus. Dazu kommt noch ein bisschen Interrupt-Handling.

Zur Analyze einer hohen CPU Auslast sind FlameGraphs ein nützliche Darstellung. Mit einem "kurzen" 4-Zeiler kann damit ein Diagramm erzeugt werden, dass in der horizontalen Achse die verbrauchte CPU-Zeit und in der vertikalen Achse den Kernel-Funktionsnamen darstellt.

perf record -g -a; &
sleep 60;
kill %;
perf script | | sed -r "s/.*;(__do_softirq;.*)/\\1/;t;d" | > do_softirq.svg;

Da hier die Auslastung innerhalb des Linux-Soft-IRQ-Handler untersucht werden soll, werden nur Events betrachtet, die auf der Funktion __do_softirq aufbauen dargestellt.

Flame Graph für __do_softirq

FlameGraph für perf von __do_softirq

Wenn man diesen Graphen von unten analysiert, sieht man wie über verschiedene Wege fast immer in der Funktion ixgbe_poll des Intel-Netzwerktreibers landet. Diese Wege stellen interne Details des Soft-IRQ-Handlers da, die aber keine Auswirkung auf uns haben. Deswegen können wir diesen Graphen vereinfachen, indem ixgbe_poll als Basis verwendet wird.

Flame Graph für __do_softirq

FlameGraph für perf von ixgbe_poll

Hier sind wir an der Basis unseres Netzwerkstacks angekommen. Leider können wir auf dieser Ebene nicht viel optimieren, aber wenn wir die einzelnen Türme vergleichen, fallen Ähnlichkeiten auf. Diese Türme scheinen alle auf nf_iterate zu basieren, weshalb wir hier nochmals reinzoomen.

Flame Graph für __do_softirq

FlameGraph für perf von nf_iterate

Dieser Graph scheint nun die CPU-Last der einzelnen Pakete zu sein. Die Blöcke lassen sich recht gut dem oben gezeigten "Packet Flow in Netfilter" Diagram zuordnen. Hier sieht man schön, wie conntrack in etwa auf 10% des Aufwands kommt (inkl der iptables/nat Tabellen). Die Brigde kommt auf etwa 3%, die iptables Regeln so auf 7% und das NAT auf ebenfalls 7%. Die größten zwei Brocken mit über 50% verstecken sich hinter der Funktion __dev_queue_xmit (source).

Flame Graph für __do_softirq

FlameGraph für perf von dev_queue_xmit

Hier handelt es sich um den Traffic-Shaper. Hier fallen zwei Probleme direkt auf: Die Funktion fw_classify (source) verwendet 18% der Ressourcen des Shapers, um bereits markierte Verbindungen neu einzugruppieren. Das ist viel zu viel. Diese Funktion schafft es damit mit 7% der gesamten CPU-Zeit auf den dritten Platz vom Output von perf top. Grund dafür sind unsere derzeit gut 24.000 Shaperklassen. Der Kernel hat eine Hashtable, um die richtige Shaperklasse zuzuordnen. Allerdings ist die Größe der Hashtable nicht dynamisch, oder konfigurierbar, sondern auf 256 hardcoded.

Zusätzlich verschwendet die Funktion _raw_spin_lock (via inline __dev_xmit_skb) 40% der Ressourcen des Shapers. Spinlocks werden in der Multi-Core-Programmierung verwendet, um exklusive Funktionen zu synchronisieren, die nicht gleichzeitig ausgeführt werden dürfen. Aber das heißt leider, dass der Shaper nicht über mehrere CPU-Kerne skaliert und nur neue Hardware kaufen hier nichts helfen wird. Wir haben hier also eine Kombination aus einem (effektiv) single-threaded Shaper pro Interface-Queue, der viel zu Aufwändig eine Klassifikation der Pakete durchführt. Die teuren Funktionen des Traffic-Shapers (fw_classify, htb_enqueue, htb_dequeue und htb_lookup_leaf) laufen lasten wegen den Spinlocks unserer Vermutung nach ca. zwei CPU-Threads aus. Sie liegen aktuell bei ca. 170% CPU-Zeit eines Threads. Wir sind damit nah an der Leistungsgrenze und treffen hier auf das wohl kritischste Bottleneck. Auch neue Hardware mit mehr Cores bzw. Threads würde dieses Problem nicht lösen!

Die einfache Lösung ist das Abschalten der Shaper. Eine bessere Lösung ist es, den Shaper an allen Stellen zu umgehen, wo es möglich ist. Ein CPU Kern müsste für die Shaper aller Testzugänge mehr als ausreichen. Die beste Lösung jedoch wäre ein Shaper, der über mehrere Kerne skaliert. Leider scheint es da noch nichts zu geben, also bliebe nur selber schreiben, oder Linux/Netfilter/Intel-Entwickler dazu überreden... Wir fänden einen "TC Multiqueue-HTB Shaper" sehr hilfreich.

Parameter Tuning

IRQ-Mapping: Die Interrupts der Queues sollen auf alle CPU-Kerne gleichmäßig verteilt sein, damit sich alle an der Last beteiligen. Standardmäßig ist das offenbar nicht der Fall, weil so ein Linux-Rechner ja auch andere Dinge zu tun haben kann. Wir haben dafür ein Script, das einen Interrupt fest auf einen Core mappt. Man muss dafür Pakete wie irqbalance deinstallieren, sonst kommt das in die Quere. Das haben wir aber schon immer, da gibt's nix zu optimieren.

Hashtable Size: Für so eine Firewall muss man conntrack_max (die maximale Anzahl von getrackten Verbindungen) hochdrehen. Auch die conntrack_hashsize sollte erhöht werden. Bisher hatten wir 64k Buckets. Bei 200k Verbindungen sorgt das dafür, dass zunächst eine Suche in der Hashmap läuft und dann noch in einer Linked-List gesucht werden muss, weil in jedem Bucket mehrere Verbindungen liegen. Wir haben den Wert nun auf 1M erhöht, d.h. jede Verbindung sollte direkt über die Hashmap gefunden werden. Da die jetzt nicht mehr in den CPU Cache passt, haben wir gleich viele Cache Misses wie vorher, dafür ist der Lookup effizienter. Ersparnis: rund 1% CPU Zeit.

State-Sync: Der Service conntrackd synchonisiert die States mit der jeweils anderen Firewall über einen separaten 1G Link. Abschalten dieses Services ist eine Option, spart aber auch nur rund 1% CPU Zeit. Dafür wird aus dem hot-standby ein cold-standby. Lohnt sich also nicht.

Timeouts: Eine Verbindung, die ohne weitere Pakete Abbricht (z.B. weil er Client einfach ausgeht) wird in der Firewall weiter gehalten. Standardmäßig werden solche Einträge erst nach 5 Tagen gelöscht. Bei uns sind derzeit 12 Stunden eingestellt. Man könnte aber noch aggressivere Werte, z.B. eine Stunde, oder 30min verwenden. Wieviel das ausmachen kann, zeigt der Plot:

Plot der Anzahl der Verbindungen über ihre verbleibende Zeit im Tracking Plot der Anzahl der Verbindungen über ihre verbleibende Zeit im Tracking, Zoom auf kurzlebige Verbindungen

Plot der Anzahl der Verbindungen über ihre verbleibende Zeit im Tracking - an der linken Seite sieht man, dass viele Verbindungen bald gelöscht werden (z.B. wegen kurzen Timeouts bei UDP, oder weil sie geschlossen wurden), die grüne Linie sind aktive TCP Verbindungen

Wie man an dem eher horizontalen Teil der grünen Linie sieht, sind nur vergleichsweise wenige Verbindungen in einem langen Established Timeout offen. Würde man die Timeouts kleiner setzen, würde sich die grüne Linie nach links verschieben. Bei 1 Stunde statt 12 Stunden, würden knapp 10% gespart werden. Die 12 Stunden sind also ein sinnvoller Wert. Auch eine Stunde wäre wohl brauchbar, aber deutlich darunter (z.B. 5 bis 10 Minuten) würde schon Probleme bringen, weil Verbindungen rausfallen, die gar keine Leichen sind. Da die Verbindungen bis zu ca. 30-60min ungefähr linear abnehmen, deutet das darauf hin, dass Verbindungen älter als 30-60 Minuten fast nie wieder aufgenommen werden, sondern nach 12 Stunden timeouten. Diese aggressiver zu löschen würde auch bei Portscans oder Angriffen helfen.

Shaper: Die Shaper sind für uns nicht kritisch. Wenn wir sie abschalten, ist das schlimmste, was passiert, dass die Testzugänge nicht mehr gedrosselt sind. Aber vielleicht wollen wir das Shaping ja eh irgendwann abschaffen?

Plot der CPU Auslastung

CPU-Auslastung: Last durch Soft-IRQ in Lila. Idle in Dunkelblau. Die rote Linie markiert die Abschaltung der Shaper.

Man sieht ganz deutlich, wie viel die Shaper ausmachen! Im Plot sieht man rund 20% mehr freie CPU Zeit. Zusätzlich gibts in den iptables Regeln noch Einträge, die Pakete flaggen, die nachher von den Shapern bearbeitet werden. Der Teil würde zusätzlich wegfallen, d.h. eine weitere kleine Einsparung bringen.

Firewallregeln: Unsere Firewallregeln werden autogeneriert. Die Templates und Scripte dafür sind eigentlich schon recht weitgehend optimiert. Beispielsweise sind die Regeln pro externe Adresse und pro Netzbereich in Chains aggregiert, sodass iptables nicht bei jedem Paket durch alle 1,6 Millionen Regeln laufen muss, sondern z.B. nach 10 Regeln in die Chain für den passenden Netzbereich abbiegt, nach weiteren 20 Regeln zur passenden User-Chain abbiegt und dort nurnoch wenige Regeln hat. Wir haben uns das angeschaut und Optimierungspotential gefunden. Beispielsweise wurde früher Traffic zur Uni Stuttgart separat gezählt. Das passiert heute nicht mehr, aber die Regeln dafür sind prinzipiell noch vorhanden. Auch die Markierungen für die Shaper können ggf. zukünftig abgeschafft werden. Außerdem hilft es, ganz oben in der FORWARD Chain die bereits akzeptierten (und damit in conntrack bekannten) Verbindungen direkt zu akzeptieren, damit die Regeln nicht durchlaufen werden müssen:


Wir haben diese Optimierungen in den Firewallregeln direkt umgesetzt, um die aktuellen Probleme schnell zu lösen. Diese winzigen Änderungen bringen direkt einen großen Performancegewinn, wie man in dem Vergleich sieht:

CPU-Last durch Interrupts vor den Optimierungen CPU-Last durch Interrupts nach den Optimierungen

CPU-Auslastung durch Soft-Interrupts (unten) vor und nach den Optimierungen in den Firewallregeln. Auslastung (Traffic-Level) waren an beiden Tagen vergleichbar.

Solange die CPU nicht mehr komplett in Interrupts feststeckt, bzw. das TC Lock nicht mehr Zeit benötigt, als es hat, werden mehr Pakete abgearbeitet, als rein kommen. Damit baut sich keine Queue auf, und es gibt keine Probleme. Das Problem ist also vorerst (kurzzeitig) gelöst.

Wie geht's weiter?

Wir können mit einigen Optimierungen ca. 20-30% CPU Last einsparen. Das wäre die Hälfte der aktuellen Spitzenlast. Damit wäre kurzfristig wieder ein gutes Stück Kapazität auf den Firewalls vorhanden.

Offloading von mehr Arbeit in die Netzwerkkarte (z.B. mit XDP und eBPF) könnte auch nochmal einen guten Performance-Boost geben.

Zu guter letzt: Neue Hardware muss her. Die alten Firewalls haben treue Dienste geleistet, aber sind jetzt 8 Jahre alt. Mit neuer Hardware kann die Leistung nochmal deutlich gesteigert werden. Wo genau dieser Faktor liegt, hängt von sehr vielen Parametern ab. Wir schätzen aber, dass mindestens Faktor 4-10 bezahlbar sein sollte. Bei einer Hardwarebeschaffung wird auch auch der Schritt in Richtung 100 Gigabit interessant.

Wir werden vermutlich über die Weihnachtsfeiertage und zwischen den Jahren weiter an der Performance schrauben, aber parallel dazu auch die Beschaffung neuer Hardware planen. Wir werden berichten.

Dieser Beitrag wurde von Markus Wick und Sebastian Neuner verfasst.

Next → Page 1 of 4