Files
bf-infra/docs/handoff-20260901-fund-e-hebel1-zurueckgebaut.md
Christoph Emsenhuber 07b595c45a TP25 Fund E: Hebel 1 widerlegt und zurueckgebaut -- Ringpuffer-Messfehler korrigiert
Zwei Sessions haben denselben Fall bewertet und kamen zu entgegengesetzten
Schluessen. Aufgeloest zugunsten der Kollektor-Messung.

Der Widerspruch und sein Beleg:
- Die Nacht-Session las `get_log ... sinceMinutes=1440` -> total 0 und schloss
  auf "Fund E geheilt, Hebel 1 committen". Das ist der FLUECHTIGE Ringpuffer des
  Routers: live nachgemessen 1000 Zeilen, aeltester Eintrag 01.09. 00:38:58 --
  keine 9 h Tiefe. Der Core-Reboot 14:36 hatte ihn geleert, der 31.08. Vormittag
  war darin nicht enthalten. "total 0" hiess "im Puffer nichts", nicht "in 24 h
  nichts" -- genau die Falle, wegen der am 30.08. der Kollektor gebaut wurde.
- Im Kollektor stehen fuer 08:09-14:36 (Hebel 1 ALLEIN, vor dem Upgrade) 124x
  reauthenticating: 09h=1, 11h=2, 12h=20, 13h=31, 14h=70 -- alle vom iPhone
  allein, also Client-Befund nach der eigenen Merkregel. Dazu Christophs zwei
  erlebte Ausfaelle 13:16 und 14:23. Zwischen 09:00 und 14:36 lag kein Reboot.

Daraus gehandelt (User-Entscheid: symmetrisch am Geraet, jetzt):
- Backup pre-tp25-funde-rollback, dann ft-over-ds=yes + remote-cap provision
- Rueckbau-Diff zeigte genau eine Abweichung, kein Kollateral
- Abnahme: CAPs durchgehend Ok, ap2 9/9 und ap3 9/9 running, frische DHCP-Lease
  (~1 min alt), Transaktion "zurueckgebaut", Compliance 140/140
- Der Rueckbau IST das Experiment: bleibt es ruhig, war 7.24.1 die Ursache;
  kehrt das Haemmern zurueck, hatte die Nacht-Session recht. Bis zur Messung
  am 2026-09-02 frueh committet niemand.

Zwei Nebenbefunde:
- gc-configplan.py --refresh-compliance scheitert STILL ohne NAUTOBOT_TOKEN:
  Meldung ausgegeben, aber Exit-Code 0. Gehoert gefixt.
- Compliance ist 140/140, nicht 135/135: es gibt eine 28. ComplianceRule
  `interface-veth`, angelegt 31.08. 20:04, Urheber offen.

Der ap2-Befund der Nacht-Session (2 m Abstand, -80 dBm, 0 Clients auf ap2)
bleibt unberuehrt gueltig und ist weiter der beste Hinweis auf die
23:02-Stoerung. CLAUDE.md enthaelt in diesem Commit auch deren TP16.3-Zeile
(gemeinsame Datei, Hunks nicht trennbar).

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2026-09-01 09:21:46 +02:00

187 lines
10 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# Handoff 2026-09-01 — Hebel 1 widerlegt und zurückgebaut, 7.24.1 ist der Verdächtige
> Vorgänger: [`handoff-20260831-tp27-upgrade-und-hebel1-befund.md`](handoff-20260831-tp27-upgrade-und-hebel1-befund.md).
> **Dieses Dokument ist der Stand danach.** Offene Aufgabe: **eine Messung am 2026-09-02 früh.**
## Die Messung, die Hebel 1 widerlegt
| Fenster | Bedingung | iPhone-`reauthenticating` | pro Stunde |
|---|---|---|---|
| 31.08. 07:00–08:00 | Baseline | **79** | 79 |
| 31.08. 08:09–14:36 | **nur Hebel 1** (ROS 7.24) | **124** | ~19 |
| 31.08. 14:37–24:00 | Hebel 1 + **7.24.1** | 17 | ~1,8 |
| 01.09. 00:00–07:57 | Hebel 1 + 7.24.1 | **0** | 0 |
6,4 Stunden Hebel 1 **allein** haben nichts verbessert. Der Einbruch fällt exakt auf den
Core-Reboot um 14:36 — also auf das TP27-Upgrade, nicht auf den Hebel.
**Beide Gegenproben bestanden** — ohne sie wäre die Null wertlos:
- **War das Telefon da?** Ja: 27 Zeilen am 01.09., mehrfaches Roaming, live verbunden.
- **Lief das Logging?** Ja: keine Lücke > 15 min in der Tagesdatei.
## 🔴 Widerspruch zu einer Parallelsession — und wie er aufzulösen ist
Eine zweite Session hat in der Nacht denselben Fall bearbeitet und kam zum **gegenteiligen**
Schluss: [`handoff-20260901-tp25-ap2-verdacht.md`](handoff-20260901-tp25-ap2-verdacht.md) wertet
Fund E als **geheilt durch Hebel 1** und empfiehlt, ihn zu **committen**.
**Ihr Beleg war eine Fehlmessung.** Zitiert wird
`get_log topics=[wireless] prefix=reauthenticating sinceMinutes=1440` → `total 0`. Das ist der
**flüchtige Ringpuffer des Routers**, nicht der Kollektor:
```
/log am Core, live geprüft 2026-09-01 09:1x:
1000 Zeilen im Ringpuffer, ältester Eintrag 2026-09-01 00:38:58 ← keine 9 Stunden Tiefe
```
Der Core wurde am 31.08. um **14:36** neu gestartet; der Puffer war danach leer und um 01:18
längst überschrieben. Eine 1440-Minuten-Abfrage konnte den 31.08. Vormittag **nicht sehen** —
`total 0` heißt „im Puffer nichts", nicht „in 24 h nichts". Genau diese Falle war der Anlass, am
30.08. das persistente Logging einzurichten (CLAUDE.md: „ein seit Wochen gemeldetes Client-Problem
war rückwirkend nicht diagnostizierbar").
**Der zweite Einwand — die 124 seien Reboot-Artefakte — trägt ebenfalls nicht.** Die Upgrade-Reboots
waren ap2 08:56, core 14:36, ap1 14:50, branch 14:52. Zwischen **09:00 und 14:36 gab es keinen
Reboot**, und in diesem Fenster stehen im Kollektor 09h=1, 11h=2, 12h=20, 13h=31, 14h=70 — **alle
vom iPhone allein**, also nach dem eigenen Gotcha der Session (viele MACs = Infrastruktur, eine MAC
= Client) ein Client-Befund. Dazu Christophs **zwei erlebte Ausfälle** um 13:16 und 14:23.
⚖️ **Auflösung: der Rückbau IST das Experiment, das den Streit entscheidet.** Steht `ft-over-ds`
wieder auf `yes` und bleibt es trotzdem ruhig, war 7.24.1 die Ursache. Kommt das Hämmern zurück,
hatte die Parallelsession recht und Hebel 1 wird als neue Transaktion erneut gezogen. **Vor dem
2026-09-02 früh sollte niemand committen.**
✅ **Unabhängig davon wertvoll: ihr `ap2`-Befund.** Am 31.08. um 23:02 meldete Christoph eine
Störung am Schreibtisch; die Session maß **−80 dBm bei 2 m Abstand** zu ap2, `not responding` bei
−82, und **0 Clients auf ap2** bei 29 auf ap3. Das ist weder Coverage noch FT, sondern ein
Hardware-/Störungsverdacht (Kandidat: DTU auf ch11, Transaktion `TP17.1-dtu-pin-ap2`). **Das
erklärt den 23:02-Schmerz, den mein Rückbau nicht adressiert** — eigener Strang, braucht eine
In-situ-Messung.
## Was heute getan wurde: Rückbau statt Commit
**Warum nicht committen:** Solange Hebel 1 steht, sind zwei Änderungen gleichzeitig aktiv. Der
Rückbau isoliert das Upgrade — **er ist der Test**, nicht bloß Aufräumen. Und weil das GC-Template
in Z. 220 ohnehin `ft-over-ds=yes` führt, kommt die Compliance **ohne Template-Änderung** zurück.
Weg **symmetrisch zum Hinweg** (Christoph-Entscheid), also am Gerät, nicht über GC:
```
/system backup save name=pre-tp25-funde-rollback # 0
/interface wifi security set [find name="sec-main"] ft-over-ds=yes
/interface wifi capsman remote-cap provision [find]
```
Der Rückbau-Vorschlag aus dem Snapshot zeigte **genau eine** Abweichung — kein Kollateral-Drift:
```
JETZT NUR AM GERAET ... ft=yes ft-over-ds=no name=sec-main
IM SNAPSHOT, FEHLT ... ft=yes ft-over-ds=yes name=sec-main
```
### Abnahme
| Prüfung | Ergebnis |
|---|---|
| `ft-over-ds` am Core | **`ft=yes ft-over-ds=yes`** ✓ |
| CAPs | 3 × `Ok`, CAPWAP-Verbindung **ununterbrochen** (17 h) — `provision` trennt sie nicht |
| VAPs **am CAP** gelesen | ap2 **9/9** `running`, ap3 **9/9** `running` |
| **Frische DHCP-Lease** (die vorgeschriebene Abnahme) | iPhone `10.40.10.196`, `bound`, `expires-after 23h58m56s` bei 24 h Laufzeit ⇒ **~1 min alt** |
| Clients | 25 → 28 zurück |
| Transaktion | `gc-transaktion.py status` → **`zurueckgebaut`**, kein Drift im Scope |
| Compliance | **140/140, 0 Drifts** — ohne jede Template-Änderung, wie vorhergesagt |
### ⚠️ Zwei Nebenbefunde beim Compliance-Lauf
**1. `gc-configplan.py --refresh-compliance` scheitert STILL, wenn `NAUTOBOT_TOKEN` fehlt** —
Ausgabe „NAUTOBOT_TOKEN nicht gesetzt", danach **Exit-Code 0**. Wer nur den Rückgabewert prüft,
hält einen nie gelaufenen Compliance-Check für erfolgreich. Behelf in dieser Session:
```bash
NAUTOBOT_TOKEN="$(sed -n 's/^[[:space:]]*-[[:space:]]*NAUTOBOT_SUPERUSER_API_TOKEN=//p' \
docs/nas-vlan20/stacks/210-nautobot.yml | head -1)" python3 nautobot/gc-configplan.py --refresh-compliance
```
Dauerhafte Antwort wäre `NAUTOBOT_TOKEN` in `~/.secrets/exports.zsh` (steht schon im Handoff vom
31.08. als offener Punkt). ⇒ **Der Exit-Code gehört gefixt**, sonst wiederholt sich das.
**2. Die Compliance-Zahl ist von 135 auf 140 gestiegen — das ist erklärt, nicht übergangen.**
Es gibt jetzt **28 ComplianceRules** statt 27 (5 Geräte × 28 = 140). Neu ist **`interface-veth`**,
angelegt **2026-08-31 20:04**, also **nach** der Session vom 31.08. und **nicht** in dieser hier.
🔴 **Wer sie angelegt hat, ist offen** — `veth` betrifft Container auf RouterOS. Bitte klären,
bevor jemand die Zahl als Basislinie zitiert.
## 🔴 Die `cap-wifiN`-Karte ist beim Provisionieren SOFORT wieder gewandert
Innerhalb dieser Session, zwischen zwei Reads im Abstand von Minuten:
| | vor dem Rückbau (galt 31.08. 14:52 – 01.09. 08:2x) | **ab jetzt** |
|---|---|---|
| ap3 | `cap-wifi3` / `cap-wifi4` | `cap-wifi3` / **`cap-wifi5`** |
| ap2 | `cap-wifi5` / `cap-wifi6` | **`cap-wifi4`** / `cap-wifi6` |
| ap1 | `cap-wifi1` / `cap-wifi2` | **getauscht** (`cap-wifi2` / `cap-wifi1`) |
Belastbar ist nur die **`radio-mac`**, weil sie am Gerät hängt:
`ap3 …:9F` = 5 GHz → `cap-wifi3` · `ap3 …:A0` = 2,4 GHz → `cap-wifi5` ·
`ap2 …:3E` → `cap-wifi4` · `ap2 …:3F` → `cap-wifi6` · `ap1 …:E5` → `cap-wifi2` · `…:E6` → `cap-wifi1`
*(Bandzuordnung für ap2/ap1 in dieser Session **nicht** nachgemessen — nicht raten.)*
⚠️ **Folge für die Auswertung:** Logzeilen vom 01.09. **vor** ca. 08:25 gehören zur linken Spalte.
Sie sind zuschreibbar, weil im ganzen Messfenster **0 `caps`-Ereignisse** standen — das war
Glück, kein Verdienst.
## Die Messung am 2026-09-02
```bash
ssh root@10.40.20.100 "pct exec 400 -- sh -c '
D=/opt/tp5-syslog/log/10.40.20.1;
echo -n \"caps: \"; grep -c \" caps,\" $D/2026-09-02.log;
echo -n \"reauth: \"; grep reauthenticating $D/2026-09-02.log | grep -c E1:AF:09;
echo -n \"iPhone da? \"; grep -c E1:AF:09 $D/2026-09-02.log'"
```
**Reihenfolge einhalten:** erst `caps` (Rejoins erzeugen Bursts, die wie ein Client-Problem
aussehen), dann `reauth`, dann die Anwesenheitsprobe. Vergleichszeitraum ist **07:00–08:00** —
dort standen am 31.08. 79 Ereignisse, am 01.09. null.
| Ergebnis | Schluss | Nächster Schritt |
|---|---|---|
| weiter ~0 | **7.24.1 hat es behoben**, Hebel 1 war wirkungslos | Fund E schließen; offen bleibt das Band-Ping-Pong (s. u.) |
| Hämmern kommt zurück | Hebel 1 hat doch beigetragen | neue Transaktion, `ft-over-ds=no` erneut — diesmal auf 7.24.1 **isoliert** |
## Neues Symptom, das die Reauth-Schleife ablöst: Band-Ping-Pong
Am 01.09. hämmert nichts mehr, aber das iPhone oszilliert zwischen den **beiden Bändern desselben
AP** (alte Karte, also ap3 5 GHz ↔ ap3 2,4 GHz):
```
01:49:14 ap3-2,4G → ap3-5G (−65)
01:49:32 ap3-5G → ap3-2,4G (−55) ← 18 s später zurück
01:50:28 ap3-2,4G → ap3-5G (−69)
07:45 / 07:46 / 07:47 dasselbe im Minutentakt
```
Verbindungsalter beim Nachsehen: **1:26 min** bei −72 dBm. Das ist kein Auth-Problem mehr, sondern
genau das, wofür **Hebel 3 (`2g-probe-delay=yes`)** gedacht war. **Nicht** in diesem Durchgang.
## ⚠️ Zwei Anomalien aus dem Gesamtlog — eigener Durchgang, nicht nebenbei
**1. Das Log besteht zu 98,4 % aus Rauschen.** 5457 von 5548 Zeilen sind Firewall-Drops, davon
**3810 MNDP-Broadcasts (udp/5678) der eigenen Netzgeräte** (ap1/ap2/ap3/branch, je ~950/Tag).
Nutzsignal 1,6 % — in genau dem Log, das unser Diagnosewerkzeug ist.
**2. 🔴 IGMP aus VLAN30 wird verworfen** (funktional, nicht kosmetisch):
```
in:vlan30 proto 2, 10.40.30.211->224.0.0.251
in:vlan30 proto 2, 10.40.30.215->224.0.0.251
```
Membership-Reports für die **mDNS-Gruppe** von zwei IoT-Geräten. Der Core betreibt
`mdns-repeat-ifaces` — er verwirft also Anmeldungen für genau den Dienst, den er weiterreichen
soll. Kandidat für Matter/HomeKit-Discovery-Probleme (TP12.1).
**3. Nebenbefund zur Hypothese:** `dirtyvader-iot` (mit `ft=no`) hatte am 31.08. **7
`reauthenticating`**, und `association rejected, no cached PMK` tritt dort ebenfalls auf. Die
ursprüngliche Trennschärfe „93/93 nur auf der `ft=yes`-SSID" galt für die Nacht-Baseline, **nicht
für den vollen Tag**. `no cached PMK` ist PMKSA-Caching und nicht FT-spezifisch.
## Unverändert offen
1. TP25-Messrunde mit Rundgang (`bash docs/tp25-runde.sh`) — **Terrasse und Arbeitszimmer**;
`ap-map` dabei neu einfrieren (s. o., sie wandert bei jedem Provision).
2. Passwort-Rotation TP30 (Admin-PW am 08-30 verbrannt).
3. ap1-Umzug ans Sideboard (`core ether3`, `5260/Ce`, Frequenz-**Liste**, `tx-power` vorher messen).