TL;DR
Das ist der verfluchte Übeltäter: UniFis DHCP Guarding
Wie üblich in der IT eine eigentlich gut gemeinte Sicherheitsfunktion, die mich unzählige Stunden an Debugging gekostet hat:
Aus irgendeinem Grund war diese Funktion auf dem UniFi Controller, welcher früher bei einer Bekannten in Gebrauch war, aktiviert. Und nicht nur aktiviert, auch die eingetragene IP des DHCP-Servers stimmte nicht; anstelle des Servers war das Gateway eingetragen, welches hier keine DHCP-Funktionen (mehr?) ausübt.
Problembeschreibung
Seit dem Bezug der Wochenaufenthalter-Wohnung in Zürich hatte ich ein nerviges Problem:
Mir gelang es seinerzeit nicht, zwei gebrauchte, aktuell nicht mehr im Einsatz befindliche UniFi-Switches vom Typ US-8 und US-8-60W mit einem auf einem Debian Server laufenden UniFi Controller zu koppeln. Sie tauchten im nicht-adoptierten Zustand im Netzwerk auf, erhielten vom auf dem Linux-Server laufenden DHCP eine IP zugewiesen (static leases basierend auf deren MAC-Adresse) und erschienen im UniFi Controller als adoptierbare Geräte. Ich konnte die Switches anpingen. Doch sobald ich den Switch adoptierte, dauerte es ein paar Minuten, dann hiess es „Adoption failed“, der Switch zeigte im UniFi Controller die IP 192.168.1.20 und konnte nicht mehr angepingt werden. Da ich ursprünglich den Access Point auch noch hinter dem Switch betrieb, verlor dieser dann lustigerweise auch die Verbindung zum Netzwerk (rückblickend ein Indiz auf das zu Grunde liegende Problem, aber dazu später mehr).
In dieser Situation, in welche ich mich sicherlich ein gutes dutzend Mal hineinmanövrierte, half dann jeweils nur der physische Reset des Switches: Mit einer Büroklammer drückte ich auf den Reset-Knopf, hielt den 10 Sekunden gedrückt, und nach dem loslassen starte der Switch den Factory Reset.
Im UniFi Controller gab ich beim Switch dann den Befehl, diesen zu vergessen („Forget“), und schlussendlich tauchte der Switch irgendwann wieder in jungfräulicher Form in der Liste auf.
Erneuter Versuch
Gestern verschob ich aus Lärmgründen das kleine 1-Disk Synology NAS vom Router in die andere Ecke der Wohnung, weshalb ich es intelligent fand, in der Ecke auch einen der beiden Switches zu installieren — zumal ich in der Ecke auch den UniFi U6-LR platziert habe, der bis dahin von einem PoE-Injektor beim Router gespeist wurde.
Einschub: Der US-8-60W (!) liefert auf seinen PoE-Ports nicht ausreichend Strom, um einen U6-LR mit Strom zu versorgen. Dies führt dazu, dass der Access Point regelmässig abstürzt und im UniFi Controller eine entsprechende Warnmeldung aufpoppt. Somit verwende ich bis zur Ankunft des USW-Lite-8-POE weiterhin den PoE Injector. Hässlich, aber als temporärer Workaround machbar.
Selbstverständlich endete ich innert weniger Minuten wieder in der oben beschriebenen Situation.
Das Debugging begann erneut — dieses Mal wollte ich das Problem ein für allemal nachhaltig lösen.
Wirklich Factory Reset?
Waren die Geräte wirklich auf die Werkseinstellungen zurückgesetzt? Wie ich nach einer Weile herausfand, ist das ganz einfach zu überprüfen: Die Switches sind im nicht-adoptierten Zustand per SSH zu erreichen. Wenn in Werksteinstellungen, kann man sich mit folgenden Daten einloggen:
- Benutzernamen: ubnt
- Kennwort: ubnt
Das funktionierte in der Tat mit beiden Switches. Um ganz sicherzugehen kann man — ist man erst einmal eingeloggt — noch folgenden Befehl ausführen:
# set-default Clearing CFG ... [%100] done! syswrapper: restart triggered by restore-default
Dies hat denselben Effekt wie man den Switch physisch mit der Büroklammer zurücksetzt.
Ist der Controller erreichbar?
Ist man auf dem Switch eingeloggt, kann dem Switch sagen, wo sich der UniFi Controller befindet:
# set-inform "http://1.2.3.4:8080/inform" Adoption request sent to 'http://1.2.3.4:8080/inform'. Use UniFi Network to complete the adopt process.
Die URL kann man auch in einem Browser öffnen, und es sollte einem keine Fehlermeldung entgegenstarren.
Das war hier der Fall, ich sah ein leeres, weisses Browser-Fenster, was signalisiert, dass der Server antwortet.
Leider macht dieser Befehl nichts; er dient dazu, das Gerät mit dem UniFi Controller bekannt zu machen, wenn dieses aus irgendeinem Grund nicht automatisch auftaucht.
Zu neue Switch Firmware mit altem Controller?
Irgendwann entdeckte ich mit Schrecken, dass die Switches zwar auf der neuesten verfügbaren Firmware liefen (7.1.26, gemass UniFi Controller, aber auch der Shell-Linie), doch der UniFi Controller noch auf Version 7 festsass. Aktuell ist Version 9.
Es folgte ein langwieriges, stundenlanges Upgrade, welches ich hier nicht im Detail beschreiben möchte. Nur soviel: Zuerst musste ich von Bullseye auf Bookworm aktualisieren. Dann musste ich MongoDB Paketverzeichnis vom Hersteller direkt einbinden, nur um zu realisieren, dass die CPU des Lenovo ThinkPads, auf welchem Debian läuft, den AVX Befehlssatz nicht unterstützt, welcher seit MongoDB 5 benötigt wird. Nach einem gescheiterten Selbstkompilationsversuch fand ich dann einen Weg, um das letzte kompatible MongoDB-Release (4.4.26) zu installieren. Danach musste ich UniFi mit einem Backup migrieren, sowie viele andere Services, welche wegen dem Upgrade kaputt gegangen waren.
Nur um schlussendlich zu realisieren, dass das Adoptionsproblem auch weiterhin bestand.
DHCP-Logs
Der Lösung (unbewusst) näher kam ich, als ich auf dem Debian Server die DHCP-Logs genauer anschaute. Dort sah ich nach der Adoption im Sekundentakt folgende Einträge:
... Aug 4 04:25:03 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:03 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:06 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:06 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:09 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:09 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:22 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:22 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:25 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:25 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:28 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:28 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:41 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:41 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:44 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:44 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:25:47 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:25:47 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 Aug 4 04:26:00 SERVER dhcpd[212067]: DHCPDISCOVER from 00:11:22:33:44:55 via eth0 Aug 4 04:26:00 SERVER dhcpd[212067]: DHCPOFFER on 1.2.3.4 to 00:11:22:33:44:55 via eth0 ...
Der Switch versuchte verzweifelt, ein DHCP-Lease zu kriegen, aber aus irgendeinem Grund kam die Antwort nicht beim Switch an. Das war auch die Erklärung dafür, weshalb der Switch sich die UniFi Standard-IP 192.168.1.20 zuteilte, wenn dann zum Tragen kommt, wenn der Switch keine IP beziehen kann.
AppArmor
Bei BIND- und DHCP-Problemen mit Debian kann auch immer AppArmor das Problem sein. Da sich dieser Service schlecht deinstallieren lässt (respektive er sich irgendwie immer wieder selber installiert), ist es besser, mit entsprechender Konfiguration dafür zu sorgen, dass nur gewarnt, und nicht geblockt wird. Auf dem Server habe ich diese Einstellungen aktiv. Ich führte das Script zur Sicherheit noch einmal aus, doch das änderte leider nichts an der Sache.
Irgendwann gab ich auf und ging schlafen.
Die Lösung
Heute wählte ich mich mit Wireguard aus der Ferne in das Netzwerk ein, um im UniFi Controller etwas nachzuschauen. Aus irgendeinem Grund endete ich in den Netzwerk-Einstellungen, und … da starrte mich plötzlich die Option DHCP Guarding an.
Auf einmal war alles klar: Diese Scheiss-Funktion wird auf UniFi-Geräten erst aktiv, wenn man es adoptiert und die Konfiguration ausgerollt hat. In meinem Fall führte dies dazu, dass der Switch sich selber ins Knie schoss, sprich: Er verlangte vom DHCP-Server eine IP, doch diese Schutzfunktion verhinderte, dass der Switch die zugeteilte IP erhielt und konfigurieren konnte. Absolut schizophren.
Nicht nur das: Jetzt war mir auch klar, was mit den am Switch angeschlossenen Geräten passierte — sei es NAS, aber auch Access Point. Diese Geräte fragten beim DHCP-Server auch nach IPs an, doch die Pakete wurden vom Switch blockiert und kamen dementsprechend nicht bei den Endgeräten an. Nicht nur das — da am Switch zu Testzwecken noch der zweite Switch hing, und der Access Point, fielen diese alle zusammen auf 192.168.1.20 zurück. Das bedeutete, dass ich im Netzwerk insgesamt drei Geräte mit derselben nicht routbaren IP hatte.
Heute Abend kam ich nach Hause, deaktivierte die DHCP Guarding-Funktionalität, adoptierte zuerst einen Switch — was innert 1–2 Minuten erfolgreich war, und anschliessend noch den zweiten Switch. HALLELUJA!
