Files
dogfather-universe/server/pruef-push-eilig.mjs
T
DogFatherGitandClaude Opus 5 e349de0040 Sendeprotokoll fuer Benachrichtigungen: "ich bekomme nichts" ist jetzt beantwortbar
Beim Nachsehen zu Dienes Meldung ist aufgefallen, dass ueber den
Versand selbst nichts festgehalten wird. Im Protokoll standen nur
push_angemeldet und push_abgemeldet -- kein Wort darueber, ob je
etwas verschickt wurde, an wie viele Geraete, und warum nicht.

Von neun Aufrufstellen wertete genau eine den Rueckgabewert aus; die
anderen acht warfen ihn weg. Sagt jemand "ich bekomme nichts", liess
sich also nicht nachsehen, OB gesendet wurde -- dieselbe Falle wie am
06.09. in VanVans Shop, wo zwei Stunden in die Zustellung ermittelt
wurden, bevor jemand fragte, ob die Mails abgeschickt waren. Sie
waren es, alle, nachweisbar in einer Abfrage.

zuletzt_ok reicht dafuer nicht: Es sagt, wann zuletzt irgendetwas
ankam -- nicht was, nicht an wen sonst, und nichts ueber die Faelle,
in denen gar nicht erst gesendet wurde. Genau die (abgeschaltet,
Ruhezeit, kein Geraet) sind die haeufigste Antwort auf die Frage.

Neue Tabelle push_versand: Zeit, Person, Art, Grund, Geraete,
zugestellt. Festgehalten wird JEDER Ausgang, auch der, bei dem nichts
hinausging -- ein Protokoll, das nur Erfolge kennt, kann die Frage
nicht beantworten, fuer die es angelegt wurde.

Das Protokoll sitzt als Huelle um den Versand, nicht in ihm: Sieben
Ausgaenge einzeln zu protokollieren waere eine Liste zum Pflegen, und
der achte, den jemand naechstes Jahr einbaut, umginge sie still --
so sind am 11.09. die Spalten beim Tabellenumbau verschwunden. So
steht ein neuer Ausgang ohne Zutun mit drin.

Aufraeumen nach 30 Tagen, neben dem bestehenden Aufraeumen von
push_verschickt. Gemessen statt geschaetzt: rund 16 Chat-Nachrichten
am Tag an bis zu acht angemeldete Geraete -- ein paar tausend Zeilen
im Monat.

Das Schreiben kann den Versand nicht aufhalten (try), meldet sich
aber, wenn es scheitert: ein Protokoll, das heimlich nichts
schreibt, ist schlimmer als keins.

pruef-push-eilig 13 -> 20. Darunter die Gegenprobe, dass auch das
NICHT-Senden protokolliert wird, und dass ein Fehlschlag nicht als
zugestellt gilt.

Datenbank vorher gesichert und die Sicherung geprueft (integrity_check,
20 Personen, 10 Anmeldungen lesbar).

Co-Authored-By: Claude Opus 5 <[email protected]>
2026-10-03 13:03:29 +02:00

331 lines
15 KiB
JavaScript

/* =====================================================================
WECKT DIE MELDUNG DAS TELEFON -- oder darf sie warten?
WARUM ES DIESE PRUEFUNG GIBT (03.10.2026).
Diene hat gemeldet: "Die Benachrichtigungen werden nicht angezeigt,
wenn neue Nachrichten reinkommen. Erst, wenn man die App oeffnet."
Alles, was wir bis dahin messen konnten, war gruen: Der Service
Worker zeigt die Meldung (pruef-push-zu, 13 Pruefungen), jede
Anmeldung im Haus stand auf `fehler = 0`, und der Push-Dienst
quittierte jede Zustellung mit 201. Nur hat niemand den Kopf
gemessen, der auf dem Weg mitgeht:
Urgency: normal
Beide Dienste behandeln das ausdruecklich als "darf warten".
Android/FCM haelt solche Meldungen zurueck, solange das Telefon
doest, und stellt sie zu, wenn es aufwacht -- typischerweise, wenn
jemand entsperrt oder die App oeffnet. Apple/APNs nennt es
"verzoegert, gebuendelt oder gedrosselt". Das ist Dienes Satz, Wort
fuer Wort, und es stand als Vorgabe in unserem eigenen Quelltext.
`zuletzt_ok` konnte das nie zeigen: Es beweist, dass der DIENST
angenommen hat (201), nicht dass das GERAET etwas angezeigt hat.
Zwischen beidem liegt genau dieser Kopf.
WAS HIER GEMESSEN WIRD, und warum in dieser Reihenfolge:
1. Die ENTSCHEIDUNG je Art -- und zwar unabhaengig notiert, nicht
aus der Artenliste abgelesen. Eine Pruefung, die ihre Erwartung
aus derselben Tabelle holt, die sie prueft, ist ein Spiegel:
Sie ist immer gruen, auch wenn jemand die Tabelle falsch
aendert.
2. VOLLSTAENDIGKEIT -- jede Art muss unten eine Entscheidung
haben. Wer eine neue eintraegt, ohne sich zu entscheiden,
bekommt einen Fehler statt stillschweigend "darf warten".
3. Der KOPF AUF DER LEITUNG, durch `benachrichtige` hindurch bis
zu einem nachgebauten Push-Dienst. Nur das beweist, dass die
Entscheidung auch ankommt.
4. Dass Dringlichkeit und HALTBARKEIT getrennt bleiben. Das war
die Falle beim Beheben: Beides hing an einem Schalter, und ein
eiliger Chat haette damit TTL 150 bekommen -- wer sein Telefon
drei Minuten aus hat, haette die Nachricht dann GAR nicht mehr
bekommen. Aus "zu spaet" waere "nie" geworden.
GEGENPROBE: Der alte Name `dringend` muss krachen, und eine nicht
eilige Art muss nachweislich "normal" bekommen -- sonst koennte
diese Pruefung gar nichts anderes als "high" sehen.
DREI AUSGAENGE: 0 in Ordnung · 1 Befunde · 2 konnte nicht nachsehen.
===================================================================== */
/* ---- DIE UHR IST HIER EINE EINGABE, KEINE ANNAHME --------------------
`istRuhezeit` fragt `Date.getHours()`, also die Zeitzone dieses
Prozesses. Liefe die Pruefung um 23 Uhr, wuerde `benachrichtige` zu
Recht nichts verschicken, und alles unten saehe nach Befund aus,
ohne dass etwas kaputt waere -- eine Zeitbombe wie die
Gate-Pruefung vom 06.09. Deshalb wird die Zone so gewaehlt, dass
JETZT auf 12 Uhr mittags faellt, egal wann der Lauf startet. */
const utcStunde = new Date().getUTCHours();
const versatz = ((12 - utcStunde + 12) % 24) - 12; /* -12 .. +11 */
process.env.TZ = versatz === 0 ? "Etc/GMT"
: `Etc/GMT${versatz > 0 ? "-" : "+"}${Math.abs(versatz)}`; /* POSIX: Vorzeichen umgekehrt */
import { mkdtempSync, rmSync } from "node:fs";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { createServer } from "node:http";
import { createECDH, randomBytes } from "node:crypto";
const ordner = mkdtempSync(join(tmpdir(), "ws-eilig-"));
process.env.WORKSPACE_DB = join(ordner, "workspace.db");
import { notbremse } from "./helfer-notbremse.mjs";
const { eigenerPort } = await import("./helfer-port.mjs");
const PORT = await eigenerPort(import.meta, "pruef-push-eilig", 0);
const PORT_DIENST = await eigenerPort(import.meta, "pruef-push-eilig (Push-Dienst)", 1);
process.env.PORT = `${PORT}`;
process.env.SITE_ACCESS_SECRET = "lokaler-test";
process.env.SITE_PUBLIC_LAUNCH_AT = "2020-01-01T00:00:00+01:00";
await import("./index.js");
notbremse(120_000, "pruef-push-eilig");
await new Promise((r) => setTimeout(r, 900));
let fehler = 0, geprueft = 0;
const ok = (b, t) => { geprueft++; console.log((b ? " ok " : " FEHL ") + t); if (!b) fehler++; };
const abbruch = (grund) => {
console.log(`\n KONNTE NICHT NACHSEHEN: ${grund}`);
try { rmSync(ordner, { recursive: true, force: true }); } catch { /* egal */ }
process.exit(2);
};
const push = await import("./workspace-push.js");
const { b64u } = await import("./workspace-push-krypto.js");
const { DatabaseSync } = await import("node:sqlite");
/* =====================================================================
DIE ENTSCHEIDUNG -- von Hand notiert, nicht abgelesen.
Massstab: eilig ist, was durch Warten WERTLOS wird. Nicht eilig
ist, was auch eine halbe Stunde spaeter noch stimmt. Waere alles
eilig, waere nichts mehr eilig -- die Geraete duerfen uns die
Dringlichkeit glauben, sonst drosseln sie uns, und der Akku zahlt.
===================================================================== */
const ERWARTET = {
/* --- weckt das Geraet: jemand wartet, oder es ist gleich vorbei --- */
anruf: true, /* klingelt 120 Sekunden */
test: true, /* jemand steht davor und tippt "Probe" */
chat_nachricht: true, /* jemand wartet auf eine Antwort */
chat_erwaehnung: true, /* jemand meint DICH */
support: true, /* Meldung oder Antwort darauf */
hilfe: true, /* vertrauliche Meldung */
termin_gleich: true, /* in einer Stunde -- danach wertlos */
termin_wecker: true, /* selbst gestellt; ein spaeter Wecker ist keiner */
dogfather_live: true, /* "jetzt" oder gar nicht */
reaktion_live: true, /* dito */
/* --- darf warten: stimmt spaeter auch noch ----------------------- */
aufgabe_faellig: false, /* morgen faellig */
aufgabe_ueberfaellig: false, /* ist es schon */
protokoll_fehlt: false,
followup: false,
bewerbung_neu: false,
bewerbung_antwort: false,
manager_ziele: false,
tagesruf: false, /* Tagesuebersicht */
befinden: false, /* alle zwei Wochen */
};
console.log("\n=== Die Entscheidung je Art ===");
{
const arten = push.ARTEN.map((a) => a.schluessel);
/* Vollstaendigkeit in BEIDE Richtungen -- eine neue Art ohne
Entscheidung ist ein Fehler, und eine Entscheidung ohne Art ist
ein Rest, der niemanden mehr schuetzt. */
const ohneEntscheidung = arten.filter((a) => !(a in ERWARTET));
const ohneArt = Object.keys(ERWARTET).filter((a) => !arten.includes(a));
ok(arten.length > 0 && ohneEntscheidung.length === 0,
ohneEntscheidung.length
? `OHNE ENTSCHEIDUNG: ${ohneEntscheidung.join(", ")} -- eilig oder nicht?`
: `alle ${arten.length} Arten haben eine Entscheidung`);
ok(ohneArt.length === 0,
ohneArt.length ? `Entscheidung ohne Art: ${ohneArt.join(", ")}` : "keine Karteileiche");
let stimmt = 0;
for (const [art, soll] of Object.entries(ERWARTET)) {
if (push.eiligRegel(art) === soll) stimmt++;
else ok(false, `${art}: erwartet ${soll ? "eilig" : "darf warten"}, ist es nicht`);
}
const anzahl = Object.keys(ERWARTET).length;
ok(anzahl > 0 && stimmt === anzahl, `${stimmt} von ${anzahl} Arten wie entschieden`);
const eilige = arten.filter((a) => push.eiligRegel(a)).length;
ok(eilige > 0 && eilige < arten.length,
`${eilige} von ${arten.length} sind eilig -- geteilt, nicht pauschal`);
ok(push.eiligRegel("gibtsnicht") === false,
"eine unbekannte Art ist NICHT eilig (im Zweifel nicht wecken)");
}
/* =====================================================================
Der Kopf auf der Leitung
===================================================================== */
console.log("\n=== Was wirklich beim Push-Dienst ankommt ===");
const empfangen = [];
const dienst = createServer((q, a) => {
q.on("data", () => {});
q.on("end", () => { empfangen.push(q.headers); a.writeHead(201); a.end(); });
});
await new Promise((r) => dienst.listen(PORT_DIENST, "127.0.0.1", r));
const browser = createECDH("prime256v1");
browser.generateKeys();
let d;
try { d = new DatabaseSync(process.env.WORKSPACE_DB); }
catch (e) { abbruch(`die Testdatenbank laesst sich nicht oeffnen: ${e.message}`); }
const jetzt = new Date().toISOString();
/* Der Zugangscode ist hier BEDEUTUNGSLOS -- angemeldet wird sich
nicht, gemessen wird der Weg nach draussen. Die Spalten sind nur
NOT NULL, also stehen dort Zufallsbytes: kein echter Code, kein
erfundener, und keiner, der jemandem Zugang gaebe. */
const fuellung = randomBytes(32).toString("hex");
d.prepare(`INSERT INTO personen
(name, rolle, code_hash, code_salt, code_n, aktiv, erstellt)
VALUES (?,?,?,?,?,1,?)`)
.run("Probeperson", "admin", fuellung, fuellung.slice(0, 32), 32768, jetzt);
const personId = d.prepare("SELECT id FROM personen WHERE name = 'Probeperson'").get().id;
d.prepare(`INSERT INTO push_anmeldungen
(endpunkt, person_id, p256dh, auth, geraet, erstellt, zuletzt_ok, fehler)
VALUES (?,?,?,?,?,?,NULL,0)`)
.run(`http://127.0.0.1:${PORT_DIENST}/push/probe`, personId,
b64u(browser.getPublicKey()), b64u(Buffer.alloc(16, 7)), "Pruefgeraet", jetzt);
d.close();
/** Verschickt EINE Meldung und gibt den Kopf zurueck, der ankam. */
const kopfVon = async (art) => {
const vorher = empfangen.length;
const e = await push.benachrichtige(personId, art, {
titel: "Probe", text: art, ziel: "/workspace/start.html",
});
if (e.verschickt !== 1) return { grund: e.grund };
return { kopf: empfangen[vorher], grund: e.grund };
};
{
/* Je ein Vertreter beider Seiten -- beide mit `ruhe: "immer"`, damit
die Messung nicht an der Ruhezeit haengt (die oben auf Mittag
festgenagelt ist). */
const eilig = await kopfVon("chat_nachricht");
const ruhig = await kopfVon("aufgabe_faellig");
if (!eilig.kopf || !ruhig.kopf) {
abbruch("es ging nichts hinaus "
+ `(chat_nachricht: ${eilig.grund}, aufgabe_faellig: ${ruhig.grund}) `
+ "-- ohne eine zugestellte Meldung ist der Kopf nicht messbar");
}
ok(eilig.kopf.urgency === "high",
`chat_nachricht geht mit Urgency: ${eilig.kopf.urgency} hinaus (muss "high" sein)`);
ok(ruhig.kopf.urgency === "normal",
`aufgabe_faellig geht mit Urgency: ${ruhig.kopf.urgency} hinaus (muss "normal" sein)`);
/* DIE GEGENPROBE: Saehe diese Pruefung grundsaetzlich nur "high",
waere die Zeile darueber wertlos. Dass sich die beiden Koepfe
UNTERSCHEIDEN, ist der Beweis, dass gemessen und nicht geraten
wird. */
ok(eilig.kopf.urgency !== ruhig.kopf.urgency,
"die beiden unterscheiden sich -- es wird wirklich gemessen");
/* HALTBARKEIT: der eigentliche Grund, warum es zwei Felder sind.
Ein eiliger Chat darf NICHT nebenbei kurzlebig werden. */
ok(eilig.kopf.ttl === "3600",
`chat_nachricht bleibt ${eilig.kopf.ttl} s gueltig (muss 3600 sein, nicht 150)`);
ok(ruhig.kopf.ttl === "3600", `aufgabe_faellig: TTL ${ruhig.kopf.ttl}`);
/* Und das, was kurzlebig sein SOLL, ist es noch: ein Anruf von vor
einer Stunde darf nicht nachtraeglich aufploppen. */
const anruf = await kopfVon("anruf");
if (!anruf.kopf) abbruch(`der Anruf ging nicht hinaus (${anruf.grund})`);
ok(anruf.kopf.urgency === "high", `anruf: Urgency ${anruf.kopf.urgency}`);
ok(anruf.kopf.ttl === "150",
`anruf verfaellt nach ${anruf.kopf.ttl} s -- eilig UND kurzlebig, beides zugleich`);
}
/* =====================================================================
Das Sendeprotokoll -- damit "ich bekomme nichts" beantwortbar wird
===================================================================== */
console.log("\n=== Was hinausging, steht hinterher da ===");
{
const p = new DatabaseSync(process.env.WORKSPACE_DB);
const zaehle = (wo = "1=1", ...w) =>
p.prepare(`SELECT COUNT(*) AS n FROM push_versand WHERE ${wo}`).get(...w).n;
/* Drei Meldungen sind oben wirklich hinausgegangen. */
const geschickt = zaehle("grund = 'ok'");
ok(geschickt >= 3, `${geschickt} zugestellte Meldungen stehen im Protokoll (mindestens 3)`);
const mitGeraet = zaehle("grund = 'ok' AND geraete >= 1 AND zugestellt >= 1");
ok(mitGeraet === geschickt,
`bei allen ${mitGeraet} steht, an wie viele Geraete (nicht nur DASS)`);
const arten = p.prepare(
"SELECT DISTINCT art FROM push_versand ORDER BY art").all().map((r) => r.art);
ok(arten.includes("chat_nachricht") && arten.includes("anruf"),
`die Art steht dabei: ${arten.join(", ")}`);
/* DER EIGENTLICHE ZWECK: auch das NICHT-Senden muss dastehen.
"Abgeschaltet", "Ruhezeit", "kein Geraet" sind die haeufigsten
Antworten auf "ich bekomme nichts" -- ein Protokoll, das nur
Erfolge kennt, kann die Frage nicht beantworten, fuer die es
angelegt wurde. */
const vorher = zaehle();
const nichts = await push.benachrichtige(personId, "gibtsnicht", {
titel: "x", text: "x", ziel: "/workspace/start.html",
});
const nachher = zaehle();
ok(nichts.verschickt === 0 && nichts.grund === "unbekannte_art",
`es ging nichts hinaus (${nichts.grund})`);
ok(nachher === vorher + 1,
`und genau DAS steht jetzt auch da (${vorher} -> ${nachher})`);
ok(zaehle("grund = 'unbekannte_art'") === 1,
"mit dem Grund, nicht nur als leere Zeile");
/* Gegenprobe: Koennte diese Messung ueberhaupt "nein" sagen? Eine
Art, die es nicht gibt, darf nicht als zugestellt gelten -- sonst
waere jede Zeile oben wertlos. */
ok(zaehle("grund = 'ok' AND art = 'gibtsnicht'") === 0,
"Gegenprobe: der Fehlschlag steht NICHT als zugestellt drin");
p.close();
}
/* =====================================================================
Gegenprobe: der alte Name darf nicht still durchrutschen
===================================================================== */
console.log("\n=== Der alte Schalter ist weg -- und zwar laut ===");
{
const { schicken, schluesselErzeugen } = await import("./workspace-push-krypto.js");
let krachte = false;
try {
await schicken({ endpunkt: `http://127.0.0.1:${PORT_DIENST}/alt`,
p256dh: b64u(browser.getPublicKey()), auth: b64u(Buffer.alloc(16, 7)) },
"{}", schluesselErzeugen(), "mailto:[email protected]",
{ dringend: true });
} catch { krachte = true; }
ok(krachte,
"schicken({ dringend: true }) bricht ab -- sonst gaebe es klaglos \"normal\" zurueck");
}
/* ---- SAUBER ZUMACHEN, SONST IST GRUEN TROTZDEM ROT ------------------
`fetch` haelt die Verbindungen zum nachgebauten Dienst offen
(keep-alive). Wer dann `process.exit()` ruft, reisst libuv ein
Handle mitten im Schliessen weg, und Windows antwortet mit
Assertion failed: !(handle->flags & UV_HANDLE_CLOSING)
-- Rueckgabewert 127 NACH "13 Pruefungen, 0 Fehler". Genau das ist
am 05.09. schon einmal passiert. Eine Pruefung, die inhaltlich
besteht und trotzdem rot meldet, ist das Schlimmste von beidem:
Man gewoehnt sich an, das Rot zu uebersehen. Also erst die
Verbindungen kappen, dann zumachen, dann einen Takt warten. */
dienst.closeAllConnections?.();
await new Promise((r) => dienst.close(r));
await new Promise((r) => setTimeout(r, 250));
try { rmSync(ordner, { recursive: true, force: true }); } catch { /* egal */ }
console.log(`\n${geprueft} Pruefungen, ${fehler} Fehler`);
console.log(fehler === 0 ? "ALLES IN ORDNUNG" : "NICHT IN ORDNUNG");
process.exit(fehler ? 1 : 0);