From 43ac05aa06d7ae2d7dcdcc49a8e5d22a88ad81d7 Mon Sep 17 00:00:00 2001 From: Claude Date: Fri, 2 Oct 2026 20:08:19 +0000 Subject: [PATCH] =?UTF-8?q?Terminplaner:=20Jobs=20lesen=20abgeschaltete=20?= =?UTF-8?q?Funktionen=20vor=20dem=20L=C3=B6schen=20neu,=20Tagesbericht=20i?= =?UTF-8?q?m=20Log?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-Authored-By: Claude Sonnet 5.5 --- server/index.js | 10 +++- server/services/termine/jobs.js | 91 +++++++++++++++++++++++----- test/termineJobs.test.js | 102 ++++++++++++++++++++++++++++++-- 3 files changed, 182 insertions(+), 21 deletions(-) diff --git a/server/index.js b/server/index.js index 8c94ac2..c0a8ff9 100644 --- a/server/index.js +++ b/server/index.js @@ -23,7 +23,7 @@ import { purgeViewLog } from './services/customerViewLog.js' import { purgeUnclaimedNewsImages } from './services/newsImages.js' import { runActivation } from './services/siteFeatures.js' import { runAboCheck, runAnalyseReconcile } from './services/analyse.js' -import { fuenfMinutenJob, minutenJob, taeglicherJob } from './services/termine/jobs.js' +import { fuenfMinutenJob, minutenJob, tagesbericht, taeglicherJob } from './services/termine/jobs.js' import giteaWebhookRoutes from './routes/webhook/gitea.js' import pushTimeRoutes from './routes/pushTime.js' import adminGiteaRoutes from './routes/admin/gitea.js' @@ -203,8 +203,14 @@ const server = app.listen(config.port, '0.0.0.0', () => { const termineFuenfMinutenJob = () => fuenfMinutenJob(new Date()).catch((err) => console.warn('[termine] Fünf-Minuten-Job fehlgeschlagen:', err.message)) setInterval(termineFuenfMinutenJob, 5 * 60 * 1000).unref() + // Nach dem Tagesjob steht eine Zeile mit den Zahlen der Loeschungen im Log (Spur unwiderruflicher Loeschungen, ohne Personendaten) const termineTagesJob = () => - taeglicherJob(new Date()).catch((err) => console.warn('[termine] Tagesjob fehlgeschlagen:', err.message)) + taeglicherJob(new Date()) + .then((ergebnis) => { + const zeile = tagesbericht(ergebnis) + if (zeile) console.log(zeile) + }) + .catch((err) => console.warn('[termine] Tagesjob fehlgeschlagen:', err.message)) setTimeout(termineTagesJob, 180 * 1000).unref() setInterval(termineTagesJob, 24 * 60 * 60 * 1000).unref() diff --git a/server/services/termine/jobs.js b/server/services/termine/jobs.js index 8d1e535..cceca10 100644 --- a/server/services/termine/jobs.js +++ b/server/services/termine/jobs.js @@ -1,5 +1,5 @@ import { config } from '../../config.js' -import { Query, deleteDocument, listAllDocuments } from '../appwriteAdmin.js' +import { Query, deleteDocument, getDocument, listAllDocuments } from '../appwriteAdmin.js' import { withLocks } from '../keyedLock.js' import { gibFreiSicher, iso, vertragAm } from './ablauf.js' import { @@ -68,7 +68,7 @@ function melde(lauf, was, err, bookingId = null) { const zuletzt = letzteWarnung.get(lauf.job) if (zuletzt !== undefined && lauf.nowMs - zuletzt < STUNDE_MS) return letzteWarnung.set(lauf.job, lauf.nowMs) - console.warn(`[termine-jobs] ${lauf.job}: ${err.type}, die Termine-Einrichtung ist unvollständig (Warnung höchstens einmal je Stunde)`) + console.warn(`[termine-jobs] ${lauf.job}, Schritt „${was}“: ${err.type}, die Termine-Einrichtung ist unvollständig (Warnung höchstens einmal je Stunde)`) return } const nummer = bookingId ? ` (${buchungsNummer(bookingId)})` : '' @@ -314,9 +314,35 @@ async function loeschfristen(lauf, now) { return geloescht } +/** So viele Buchungen einer abgeschalteten Funktion hoechstens, bevor ihr Zustand erneut gelesen wird. */ +const ABGESCHALTET_NEU_PRUEFEN_ALLE = 50 + +/** + * Gilt die Funktion unmittelbar vor einem unwiderruflichen Loeschschritt noch als abgeschaltet? Frisch gelesen, weil ein Wieder- + * einschalten durch das Personal (siteFeatures.activate) weder sperrt noch disabledAt loescht: featureKey termine, state disabled + * und disabledAt vor der Grenze. Sonst false mit Log, ohne Wurf – auch bei einem Lesefehler: im Zweifel wird nichts geloescht. + */ +async function nochAbgeschaltet(lauf, funktionId, grenze) { + try { + const frisch = await getDocument(config.collections.portalFeatures, funktionId) + if (frisch.featureKey === 'termine' && frisch.state === 'disabled' && zeitMs(frisch.disabledAt) < grenze) return true + console.warn(`[termine-jobs] ${lauf.job}: eine Funktion ist inzwischen wieder aktiv oder neu abgeschaltet, die Löschung wird für sie abgebrochen`) + } catch (err) { + if (err?.status === 404 && !fehlendeCollection(err)) { + console.warn(`[termine-jobs] ${lauf.job}: eine Funktion wurde inzwischen entfernt, die Löschung wird für sie abgebrochen`) + } else { + melde(lauf, 'Funktion vor dem Löschen nicht gelesen', err) + } + } + return false +} + /** * Funktionen im Zustand `disabled` seit mehr als 30 Tagen (disabledAt): alle Buchungen mit Zellen und zuletzt die Einstellung - * loeschen. Scheitert eine Buchung, bleibt die Einstellung bis zum naechsten Lauf. Zellen ohne Buchung raeumt danach der Tagesjob. + * loeschen. Vor der Buchungsliste, nach jeweils 50 Buchungen und vor dem Loeschen der Einstellung wird die Funktion frisch gelesen + * (nochAbgeschaltet); gilt sie nicht mehr als abgeschaltet, endet die Loeschung fuer diese Funktion sofort (Log, kein Wurf). + * Scheitert eine Buchung, bleibt die Einstellung bis zum naechsten Lauf. Zellen ohne Buchung raeumt danach der Tagesjob. + * funktionen zaehlt die Funktionen, bei denen etwas geloescht wurde (Buchungen oder Einstellung). */ async function loescheAbgeschaltete(lauf) { const erg = { funktionen: 0, buchungen: 0 } @@ -324,26 +350,42 @@ async function loescheAbgeschaltete(lauf) { const funktionen = await listAllDocuments(config.collections.portalFeatures, [Query.equal('featureKey', 'termine'), Query.equal('state', 'disabled')]) for (const funktion of funktionen) { if (!(zeitMs(funktion.disabledAt) < grenze)) continue - erg.funktionen += 1 const buchungen = await schritt(lauf, 'Buchungen abgeschalteter Funktion', () => listAllDocuments(config.collections.termineBookings, [Query.equal('featureId', funktion.$id)]), null) - if (buchungen === null) continue + if (buchungen === null || !(await nochAbgeschaltet(lauf, funktion.$id, grenze))) continue + + let geloescht = 0 let vollstaendig = true - for (const buchung of buchungen) { + for (const [i, buchung] of buchungen.entries()) { + if (i > 0 && i % ABGESCHALTET_NEU_PRUEFEN_ALLE === 0 && !(await nochAbgeschaltet(lauf, funktion.$id, grenze))) { + vollstaendig = false + break + } const weg = await loescheMitZellen(lauf, buchung.$id, null) - if (weg) erg.buchungen += 1 + if (weg) geloescht += 1 if (weg === undefined) vollstaendig = false } + erg.buchungen += geloescht + + let einstellungWeg = false if (vollstaendig) { - await schritt(lauf, 'Einstellung abgeschalteter Funktion', () => - withLocks([`termine-cfg:${funktion.$id}`], async () => { - try { - await deleteDocument(config.collections.termineConfig, funktion.$id) - } catch (err) { - if (err?.status !== 404) throw err - } - }), + einstellungWeg = await schritt( + lauf, + 'Einstellung abgeschalteter Funktion', + () => + withLocks([`termine-cfg:${funktion.$id}`], async () => { + if (!(await nochAbgeschaltet(lauf, funktion.$id, grenze))) return false + try { + await deleteDocument(config.collections.termineConfig, funktion.$id) + return true + } catch (err) { + if (err?.status === 404 && !fehlendeCollection(err)) return false // schon weg + throw err + } + }), + false, ) } + if (geloescht > 0 || einstellungWeg) erg.funktionen += 1 } return erg } @@ -386,6 +428,25 @@ export async function taeglicherJob(now) { }) } +/** + * Eine Zeile fuers Log nach dem Tagesjob: nur Zahlen, keine personenbezogenen Daten und keine Buchungs- oder Funktions-IDs + * (Spur der unwiderruflichen Loeschungen). null, wenn der Job nicht gelaufen ist (Modus off, uebersprungen). + * @param {object} ergebnis Rueckgabe von taeglicherJob + * @returns {string|null} + */ +export function tagesbericht(ergebnis) { + if (!ergebnis || ergebnis.aus || ergebnis.uebersprungen) return null + const l = ergebnis.loeschfristen + const a = ergebnis.abgeschaltet + const gesamt = Object.values(l).reduce((summe, n) => summe + n, 0) + a.buchungen + return ( + `[termine] Tagesjob: ${gesamt} Buchungen gelöscht (verfallen ${l.verfallen}, abgesagt ${l.abgesagt}, abgelehnt ${l.abgelehnt}, ` + + `erledigt ${l.erledigt}, nichterschienen ${l.nichterschienen}, abgeschaltete Funktionen ${a.buchungen}), ` + + `${a.funktionen} Funktionen bereinigt, ${ergebnis.zellen} Zellen, ${ergebnis.aufgeraeumt} Outbox, ` + + `${ergebnis.festgefahren} Mails nicht zugestellt, ${ergebnis.fehler} Fehler` + ) +} + /** Nur fuer Tests: Ueberlappungsmerker und Warnungs-Zeitpunkte zuruecksetzen. */ export function resetJobsForTests() { laufend.clear() diff --git a/test/termineJobs.test.js b/test/termineJobs.test.js index e1dbd6c..a562ada 100644 --- a/test/termineJobs.test.js +++ b/test/termineJobs.test.js @@ -33,7 +33,7 @@ const { speichereEinstellung, resetKontextForTests } = await import('../server/s const { belegeZellen } = await import('../server/services/termine/zellen.js') const { bestaetige } = await import('../server/services/termine/ablauf.js') const J = await import('../server/services/termine/jobs.js') -const { minutenJob, fuenfMinutenJob, taeglicherJob, wendeLoeschfristenAn, loescheAbgeschalteteFunktionen, resetJobsForTests } = J +const { minutenJob, fuenfMinutenJob, taeglicherJob, tagesbericht, wendeLoeschfristenAn, loescheAbgeschalteteFunktionen, resetJobsForTests } = J after(() => setMailTransportForTests(null)) const MIN = 60000 @@ -774,7 +774,7 @@ test('loescheAbgeschalteteFunktionen: disabled länger als 30 Tage ⇒ Buchungen assert.equal(buchungen().length, 8, 'die Buchungen der anderen vier Funktionen bleiben') for (const featureId of [F2, F3, 'f_p_projekt04_termine', 'f_p_projekt05_termine']) assert.ok(aw.docs('termineConfig').get(featureId), `${featureId}: Einstellung bleibt`) assert.ok(aw.docs('portalFeatures').get(F1), 'das Funktionsdokument selbst bleibt') - assert.deepEqual(await loescheAbgeschalteteFunktionen(JETZT), { funktionen: 1, buchungen: 0 }, 'zweiter Lauf: nichts mehr zu löschen') + assert.deepEqual(await loescheAbgeschalteteFunktionen(JETZT), { funktionen: 0, buchungen: 0 }, 'zweiter Lauf: nichts mehr zu löschen, die Funktion zählt nicht noch einmal') }) test('loescheAbgeschalteteFunktionen: scheitert das Löschen einer Buchung, bleibt die Einstellung bis zum nächsten Lauf', async () => { @@ -789,6 +789,79 @@ test('loescheAbgeschalteteFunktionen: scheitert das Löschen einer Buchung, blei assert.equal(aw.docs('termineConfig').get(F1), undefined) }) +/** Eine abgeschaltete Funktion (seit 40 Tagen) mit n Buchungen; mit zellen bekommt jede ihre Zellen. */ +async function abgeschaltetMitBuchungen(n, { zellen = true } = {}) { + await richteFunktionEin(F1, { state: 'disabled', disabledAt: iso(plus(JETZT, -40 * TAG)) }) + for (let i = 0; i < n; i++) await legeBuchung(`b_ab${String(i).padStart(3, '0')}`, { start: plus(JETZT, TAG + i * 2 * STUNDE), zellen }) +} +/** Das Personal schaltet die Funktion wieder ein: siteFeatures.activate sperrt nicht und lässt disabledAt stehen. */ +const schalteEin = () => aw.seed('portalFeatures', { ...aw.docs('portalFeatures').get(F1), state: 'active', enabled: true }) +/** Anfragen an die Buchungsliste einer Funktion bzw. an die Funktionsliste */ +const funktionsListe = (url, methode) => methode === 'GET' && /\/collections\/portalFeatures\/documents(\?|$)/.test(url) +const buchungLoeschen = (url, methode) => methode === 'DELETE' && /\/collections\/termineBookings\/documents\/b_ab/.test(url) + +for (const [wann, passt] of [['zwischen Funktionsliste und Buchungsliste', funktionsListe], ['zwischen Buchungsliste und erster Löschung', listeVonBuchungen(/featureId/)]]) { + for (const [was, umschalten] of [ + ['wieder eingeschaltet (disabledAt bleibt alt)', schalteEin], + ['frisch neu abgeschaltet', () => aw.seed('portalFeatures', { ...aw.docs('portalFeatures').get(F1), disabledAt: iso(plus(JETZT, -TAG)) })], + ]) { + test(`loescheAbgeschalteteFunktionen: ${was} ${wann} ⇒ nichts wird gelöscht`, async () => { + await abgeschaltetMitBuchungen(3) + const erg = await mitEinwurf(passt, async () => umschalten(), () => loescheAbgeschalteteFunktionen(JETZT)) + assert.deepEqual(erg, { funktionen: 0, buchungen: 0 }) + assert.equal(buchungen().length, 3, 'alle Buchungen bleiben') + assert.equal(aw.docs('termineClaims').size > 0, true) + for (const b of buchungen()) assert.ok(claims(b.$id).length > 0, `${b.$id}: Zellen bleiben`) + assert.ok(aw.docs('termineConfig').get(F1), 'Einstellung bleibt') + assert.ok(warnLog().some((zeile) => /inzwischen wieder aktiv oder neu abgeschaltet/.test(zeile)), 'Abbruch steht im Log') + assert.equal(fehlerLog().length, 0, 'kein Fehler, kein Wurf') + }) + } +} + +test('loescheAbgeschalteteFunktionen: wird die Funktion nach 50 Buchungen wieder eingeschaltet, endet die Löschung dort', async () => { + await abgeschaltetMitBuchungen(60, { zellen: false }) + const echt = globalThis.fetch + let geloescht = 0 + globalThis.fetch = async (url, optionen) => { + const antwort = await echt(url, optionen) + if (buchungLoeschen(String(url), optionen?.method ?? 'GET')) { + geloescht += 1 + if (geloescht === 50) schalteEin() + } + return antwort + } + let erg + try { + erg = await loescheAbgeschalteteFunktionen(JETZT) + } finally { + globalThis.fetch = echt + } + assert.equal(geloescht, 50, 'nach dem Einschalten kommt keine Löschung mehr') + assert.deepEqual(erg, { funktionen: 1, buchungen: 50 }) + assert.equal(buchungen().length, 10) + assert.ok(aw.docs('termineConfig').get(F1), 'Einstellung bleibt') +}) + +test('loescheAbgeschalteteFunktionen: wird die Funktion nach der letzten Buchung wieder eingeschaltet, bleibt die Einstellung', async () => { + await abgeschaltetMitBuchungen(2) + const erg = await mitEinwurf(buchungLoeschen, async () => schalteEin(), () => loescheAbgeschalteteFunktionen(JETZT)) + // die erste Buchung ging noch vor dem Einschalten; die Funktion ist danach aktiv, ihre Einstellung muss bleiben + assert.ok(aw.docs('termineConfig').get(F1), 'Einstellung bleibt') + assert.equal(erg.funktionen, 1) + assert.equal(erg.buchungen, 2, 'beide Buchungen waren in einem Block von 50, vor der nächsten Prüfung gelöscht') +}) + +test('loescheAbgeschalteteFunktionen: kann die Funktion vor dem Löschen nicht gelesen werden, wird nichts gelöscht (Fehler im Log)', async () => { + await abgeschaltetMitBuchungen(2) + aw.failNext({ collection: 'portalFeatures', method: 'GET', status: 500, message: 'Nachbau kaputt', after: 1 }) // 1. GET = Liste, 2. = Neulesen + const erg = await loescheAbgeschalteteFunktionen(JETZT) + assert.deepEqual(erg, { funktionen: 0, buchungen: 0 }) + assert.equal(buchungen().length, 2) + assert.ok(aw.docs('termineConfig').get(F1)) + assert.equal(fehlerLog().length, 1) +}) + // ---------------------------------------------------------------- Tagesjob test('taeglicherJob: Löschfristen, Warteschlange, festgefahrene Mails, verwaiste Zellen und abgeschaltete Funktionen in einem Lauf', async () => { @@ -822,6 +895,20 @@ test('taeglicherJob: Löschfristen, Warteschlange, festgefahrene Mails, verwaist assert.equal(aw.docs('termineClaims').size, claims('b_zukunft').length, 'sonst bleibt keine Zelle übrig') assert.equal(aw.docs('termineOutbox').get('o_gesendet'), undefined) assert.equal(aw.docs('termineOutbox').get('o_festgefahren').status, 'fehler') + + // eine Zeile fürs Log: nur Zahlen, keine IDs, keine Personendaten + const zeile = tagesbericht(erg) + assert.equal( + zeile, + `[termine] Tagesjob: 3 Buchungen gelöscht (verfallen 1, abgesagt 0, abgelehnt 0, erledigt 1, nichterschienen 0, abgeschaltete Funktionen 1), 1 Funktionen bereinigt, ${erg.zellen} Zellen, 1 Outbox, 1 Mails nicht zugestellt, 0 Fehler`, + ) + assert.doesNotMatch(zeile, /\bb_|\bf_|@|Mustermann|Salon/) +}) + +test('tagesbericht: keine Zeile, wenn der Job nicht gelaufen ist', () => { + assert.equal(tagesbericht({ aus: true }), null) + assert.equal(tagesbericht({ uebersprungen: true }), null) + assert.equal(tagesbericht(undefined), null) }) test('taeglicherJob: festgefahrene Mail wird fehler und erst 48 Stunden später gelöscht (nicht im selben Lauf)', async () => { @@ -861,6 +948,8 @@ test('fehlende Collection: höchstens eine Warnung je Stunde und Job, kein Wurf' assert.equal(warnLog().filter((zeile) => /minutenJob/.test(zeile)).length, 2, 'nach einer Stunde wieder') }) assert.match(warnLog()[0], /collection_not_found/) + assert.match(warnLog().find((zeile) => /minutenJob/.test(zeile)), /Schritt „Verfall“/, 'die Warnung nennt den Schritt') + assert.match(warnLog().find((zeile) => /fuenfMinutenJob/.test(zeile)), /Schritt „Erinnerungen“/) }) test('fehlende Collection der Warteschlange: der Minutenjob verfällt trotzdem Haltungen', async () => { @@ -921,10 +1010,15 @@ test('server/index.js: die drei Jobs laufen alle 60 s, alle 5 min und täglich ( assert.match(index, /import \{[^}]*\bfuenfMinutenJob\b[^}]*\} from '\.\/services\/termine\/jobs\.js'/) assert.match(index, /import \{[^}]*\btaeglicherJob\b[^}]*\} from '\.\/services\/termine\/jobs\.js'/) for (const [job, takt] of [['minutenJob', '60 \\* 1000'], ['fuenfMinutenJob', '5 \\* 60 \\* 1000'], ['taeglicherJob', '24 \\* 60 \\* 60 \\* 1000']]) { - const lauf = new RegExp(`const (\\w+) = \\(\\) =>\\s*${job}\\(new Date\\(\\)\\)\\s*\\.catch\\(`) + const lauf = new RegExp(`const (\\w+) = \\(\\) =>\\s*${job}\\(new Date\\(\\)\\)([\\s\\S]*?)\\.catch\\(`) const treffer = lauf.exec(index) assert.ok(treffer, `${job} mit .catch eingebunden`) assert.match(index, new RegExp(`setInterval\\(${treffer[1]}, ${takt}\\)\\.unref\\(\\)`), `${job}: Intervall`) - if (job === 'taeglicherJob') assert.match(index, new RegExp(`setTimeout\\(${treffer[1]}, 180 \\* 1000\\)\\.unref\\(\\)`), 'täglicher Job: +180 s') + if (job === 'taeglicherJob') { + assert.match(index, new RegExp(`setTimeout\\(${treffer[1]}, 180 \\* 1000\\)\\.unref\\(\\)`), 'täglicher Job: +180 s') + assert.match(treffer[2], /\.then\(\(ergebnis\) => \{\s*const zeile = tagesbericht\(ergebnis\)\s*if \(zeile\) console\.log\(zeile\)\s*\}\)\s*$/, 'eine Zusammenfassung pro Tageslauf im Log') + } else { + assert.match(treffer[2], /^\s*$/, `${job}: direkt .catch`) + } } })