From 355d204e9998fe1119d5f9c0a4e9b35094bb0fc3 Mon Sep 17 00:00:00 2001 From: heaven Date: Sat, 29 Aug 2026 14:06:55 +0300 Subject: [PATCH] Land the money-test repair: it searched a raw log buffer whose nanosecond timestamps collide with the very amounts it looks for, so it went red over a leak that never happened --- platform/docs/DEFECT_REGISTER.md | 1 + platform/internal/config/effective_test.go | 72 +++++++++++++++++++++- 2 files changed, 71 insertions(+), 2 deletions(-) diff --git a/platform/docs/DEFECT_REGISTER.md b/platform/docs/DEFECT_REGISTER.md index e91d1e06..6f3269b1 100644 --- a/platform/docs/DEFECT_REGISTER.md +++ b/platform/docs/DEFECT_REGISTER.md @@ -572,3 +572,4 @@ | PD-166 | bug | info | `internal/ingest/tail.go`, `internal/pgstore/sink.go` `Begin` | **`chunker_version` из хендшейка теряется навсегда,** если краш пришёлся между двумя стейтментами `Begin` (привязка `engine_run_id` и запись версии — два отдельных автокоммита): при повторном чтении своего же `hello` тейлер видит, что поток уже привязан, и `Begin` больше не зовёт. Сегодня поле никем не читается (нужно для строки 100), поэтому info; закрывать — одной транзакцией в `Begin` ⚠ **ПАК P8-REVIEW 24.08: первая фраза сужена построенным.** У колонки `books.chunker_version` появился ВТОРОЙ независимый писатель — интейк (`internal/pgstore/books.go` `FinishParse` пишет её из манифеста движка). Значит крах между двумя стейтментами `Begin` оставляет не пустую колонку, а СТАРОЕ значение разбора: теряется дельта, а не значение. Читателя по-прежнему нет, вес `info` верен ⚠⚠ **МОЯ ДОПИСКА ВЫШЕ ОПРОВЕРГНУТА РЕФУТЕРОМ, и опровергнута верно — снимаю её.** Механизм, который строка описывает (крах между ДВУМЯ автокоммитами `Begin`), СЕГОДНЯ НЕДОСТИЖИМ: запись версии переехала из `Begin` в `effect` и идёт в ОДНОЙ транзакции с курсором (`internal/pgstore/sink.go:105-127`), а сам `Begin` объявлен legacy (`sink.go:33-38`) и для попыток этой сборки недостижим — `engine_run_id` присваивается в INSERT попытки и бэкфилится в `RecordSpawn`. Доказано исполнением: при уцелевшей привязке и нулевом курсоре хендшейк идёт в `Apply`, а не в `Begin` (`Begin calls=0 Apply calls=1`), то есть терять между двумя стейтментами нечего. Посадка мутации (вырезан `case ingest.TypeHello` из `effect`) роняет `TestTheChunkerVersionOfTheStreamReachesTheBook` — атомарный писатель есть и запинен. **Правильная диспозиция — не «сузить до потери дельты», а ЗАКРЫТЬ как построенное:** атомарность, которой строка требовала, существует. Читателя у колонки по-прежнему нет, и это отдельный факт, а не этот дефект ⚠ **ЗАКРЫТА актом лендинга P9 (D39.162):** акт объявил закрытие состоявшимся, статус переведён по аудиту документации 28.08 — обязательство акта висело неисполненным (класс «строка open при легшем лечении», носитель — строка бэклога 225) | fixed(акт D39.162, перевод по аудиту 28.08) | самопроверка дофикса (ревью вне карты) · аудит документации 28.08 | | PD-254 | standards | info | `internal/httpapi/problem.go` `WriteStatusProblem`, `codeForStatus` | **Два писателя ошибок на одну форму тела.** `WriteProblem` выводит статус ИЗ кода (пара не может разойтись), а `WriteStatusProblem` идёт обратно — от статуса к коду — потому что вне версионного префикса (`/auth`, `/readyz`) есть статусы, которых в словаре контракта нет вовсе (405, 429). Свести в один писатель можно только назначив форму ответа для этих двух статусов, а это ратификация, не правка зоны. Пока — два пути и обратная функция рядом с прямой ⚠ **ЗАКРЫТО решением контрактной сессии 17.08 (релей владельца):** поверхность входа отвечает тем же конвертом и БЕЗ машинного кода — это ратифицированное решение, а не пробел («различать причины отказа клиент не может по замыслу», компаньон §2.14 с 0.2.3), а единственный осмысленный для пользователя случай `429` машинен без словаря, потому что лечение едет в `Retry-After`. Следствие для кода: писатель входа кода не эмитит, `codeForStatus` и `writeRaw` удалены — обратной функции, то есть второго источника истины, больше нет. Пин `httpapi.TestTheSignInSurfaceAnswersTheSameEnvelopeWithoutAVersionedCode` (шесть статусов). Отвергнуто с доводом: расширение `ErrorCode` (значения, недостижимые на описываемой им поверхности, ломают инвариант «код называет свой статус») и словарь в компаньоне (документ, не нормативный для формы, стал бы нормативным с чёрного хода) | fixed(P7, дерево сессии) | кросс-модельное ревью P7 (линза скоупа) | | PD-255 | doc | info | `internal/pgstore/migrations/00016_read_surface.sql`, `internal/pgstore/readmodel.go` | **Плотность комментариев выше нормы зоны** («одна-две строки почему», владелец 26.07): миграция 00016 — 250 строк, из них около половины проза; у `readmodel.go` многие символы несут абзацы. Часть прозы несущая (порядок delete/insert в двух таблицах — ровно то, на чём пак и споткнулся), часть — эссе. Подрезано самое тяжёлое; остальное — предмет решения владельца о норме, а не тихой правки ⚠ **ЗАКРЫТО решением владельца 21.08: НОРМА СМЕНИЛАСЬ, и строка была открыта против снятой формулы.** Счёт строк снят как негодный гейт — комментарий на три строки может быть нужен, на одну достаточен; режется ВОДА (пересказ решений, провенанс, изложение исследования вместо ссылки), а всё, что из одной функции НЕ выводится — порядок блокировок, инварианты между таблицами, цена забывания, вендор-квирк — остаётся, сколько бы строк ни заняло. Формулировка — `docs/architecture/12-go-style-notes` §1. Обе названные здесь прозы под новой нормой законны: порядок delete/insert между двумя таблицами из функции не выводится, а сам дефект пака это доказал. Тихой правки не было и не будет | fixed(решение владельца 21.08) | кросс-модельное ревью P7 (линза энтропии) | +| PD-429 | bug | minor | `internal/config/effective_test.go` `TestAConfiguredAmountIsNeverPrinted` | **Денежный тест краснел на совпадении с ЧАСАМИ, то есть на факте, которого не существует.** Он искал суммы подстрокой во всём буфере `slog.NewJSONHandler`, а тот несёт `time` в RFC3339Nano — девять знаков дробной части. Замерено на 200 000 таймстемпов: `7.50` встречается в **205**, `42500` в 5, `0.0425` в 3 — и это НА СТРОКУ, а прогон печатает по строке на настройку, поэтому совпадения приходят вспышками (все строки одного прогона делят одну секунду). Воспроизведено `-count=3000`: падение на `42500`. ⚠ **Утечки не было и нет:** значение скрывается (`config.go` пишет `valueAmount`), и этот же тест двумя строками выше сам это и проверяет. ⚠ **Почему это чинится, а не оставляется под запретом D39.121:** запрет защищает тест, ловящий НАСТОЯЩИЙ дефект, — такой нельзя ослаблять ради зелени. Здесь дефектен САМ тест: ложно-положительное срабатывание на данных, к предмету не относящихся. Оставить как есть — худший исход: флейк в ДЕНЕЖНОМ тесте приучает читать красное как шум, и в день настоящей утечки красное не отличат. ⚠ **Лечение НЕ ослабляет:** каждая строка разбирается как JSON, поле `time` выбрасывается, поиск идёт по значениям и ключам всего остального (`loggedFields`), то есть проверка перестала зависеть от формата времени. ⚠ **Честная оговорка, установленная ПОСАДКОЙ:** охват при этом НЕ вырос — сырой поиск покрывал и `msg`, и посадка «сумма печатается в msg» валит ОБЕ формы. Выигрыш ровно один и он назван: убрано ложное срабатывание. Проверка: `-count=5000` чисто (падало на 3000), посадка в `msg` — красная. ⚠ **Родня, сегодня безопасная по причине, которую стоит знать:** `internal/runs/sweep_test.go` ищет `1.000000`/`0.200000` в буфере `slog.NewTextHandler`, а у текстового обработчика дробная часть ТРИ знака (замерено: `.437` против `.437860545` у JSON), поэтому шестизначные хвосты там не совпадут никогда — переключение того теста на JSON-обработчик воскресит этот же дефект | fixed(пак P11, дофикс 29.08 — лендинг оркестратора; статус проставлен зоной) | охотник приёмки; механизм пере-проверен оркестратором №19 и независимо пере-замерен сессией P11 | diff --git a/platform/internal/config/effective_test.go b/platform/internal/config/effective_test.go index c3572859..9cd548d0 100644 --- a/platform/internal/config/effective_test.go +++ b/platform/internal/config/effective_test.go @@ -3,6 +3,7 @@ package config import ( "bytes" "encoding/json" + "fmt" "log/slog" "os" "regexp" @@ -36,6 +37,71 @@ func effective(t *testing.T) (map[string]Setting, string) { return by, buf.String() } +// loggedFields is every key and every value the boot log printed, MINUS the handler's own timestamp. +// +// ⚠ It exists because the money test used to search the RAW buffer, and that buffer carries an +// RFC3339Nano time whose digits collide with the very amounts it looks for. Measured on 200 000 +// timestamps: `7.50` appears in 205 of them, `42500` in 5, `0.0425` in 3 — and that is PER LINE, +// while a run prints one line per setting, so the collisions arrive in bursts (every line of one run +// shares the same second). Reproduced at `-count=3000`. The test therefore went red over a fact that +// does not exist: the value IS withheld — `config.go` records `valueAmount` for both, which this same +// test asserts a few lines above. Register row PD-429. +// +// ⚠ A flake in a MONEY test is worse than no test, and that is why this is repaired rather than left +// with a note: red that is usually noise trains the reader to skip it, and the day an amount really +// leaks is the day that habit costs the most. +// +// ⚠ PARSED, not muted, and the reason is INDEPENDENCE FROM THE FORMAT rather than reach. Silencing +// `time` through slog's ReplaceAttr would work today and break the day the handler, its options or +// the time layout change — the search would still be over one rendered blob, and the next collision +// would be someone else's afternoon. +// +// ⚠ What this does NOT buy, measured rather than assumed: it is not WIDER than the old form. The +// raw-buffer search covered `msg` too — planted an amount into the message and both forms went red, +// so "now it catches the amount in any field" would have been a pleasing sentence and a false one. +// What changed is that the false POSITIVE is gone and the assertion no longer depends on how time is +// rendered. Equal reach, no noise. +func loggedFields(t *testing.T, log string) []string { + t.Helper() + var out []string + var walk func(v any) + walk = func(v any) { + switch v := v.(type) { + case map[string]any: + for k, sub := range v { + if k == slog.TimeKey { + continue // the handler's own clock is not part of what this deployment printed + } + out = append(out, k) + walk(sub) + } + case []any: + for _, sub := range v { + walk(sub) + } + case nil: + default: + out = append(out, fmt.Sprint(v)) + } + } + for _, l := range strings.Split(strings.TrimSpace(log), "\n") { + if l == "" { + continue + } + var m map[string]any + if err := json.Unmarshal([]byte(l), &m); err != nil { + // Not a skip: a line this cannot read is a line nothing checks, and the whole point is + // that every field is looked at. + t.Fatalf("the boot log emitted a line that is not JSON: %q (%v)", l, err) + } + walk(m) + } + if len(out) == 0 { + t.Fatal("the boot log yielded no fields at all: this assertion would pass over anything") + } + return out +} + // The completeness gate, and the reason it is written against the SOURCE rather than a list: a print // that covers most of the configuration is worse than none, because the variable an operator is // hunting is exactly the one nobody remembered to record. A setting added without a record fails @@ -117,8 +183,10 @@ func TestAConfiguredAmountIsNeverPrinted(t *testing.T) { } } for _, amount := range []string{"7.50", "7500000", "0.0425", "42500"} { - if strings.Contains(line, amount) { - t.Errorf("the boot line carries the amount %q", amount) + for _, field := range loggedFields(t, line) { + if strings.Contains(field, amount) { + t.Errorf("the boot line carries the amount %q, in the field %q", amount, field) + } } } c, err := Load()