отработаны находки ревью кода
Триаж свёл 62 сырые находки девяти проходов к 33 причинам: 3 блокера, 4 «сейчас», 2 развилки. Все закрыты регрессионными тестами. - схема точки сна определяется по самой точке, а не по индексу в исходном массиве: одна пропущенная точка меняла эпизод и сводку местами - доставка сворачивается одной транзакцией: частичное состояние было недетерминированным (восемь прогонов — семь состояний) - граница размера на распакованном теле: 400 КиБ gzip разворачивались в 400 МиБ мимо max_body_mb - столкновение — расхождение канонических форм, а не байтов; WARN с координатами объекта; payload без HTML-экранирования - выравнивание по местной метке: получасовые зоны уводили часовую выгрузку в minute - доставка из одних суточных сводок больше не отвергается целиком - единицы не переписываются молча; счётчик считает сохранённые точки - все выходы Fold логируются, исход пишется на переживающем отмену контексте Четыре развилки вынесены блокерами в беклог.
This commit is contained in:
+123
-18
@@ -13,44 +13,73 @@ import (
|
||||
"fmt"
|
||||
"io"
|
||||
"log/slog"
|
||||
"strings"
|
||||
"time"
|
||||
|
||||
"git.vakhrushev.me/av/healthlog/internal/archive"
|
||||
"git.vakhrushev.me/av/healthlog/internal/hae"
|
||||
"git.vakhrushev.me/av/healthlog/internal/store"
|
||||
)
|
||||
|
||||
// maxBodyBytes — граница размера тела при чтении из архива.
|
||||
// defaultMaxBodyBytes — граница размера тела при чтении из архива, когда
|
||||
// вызывающий свою не задал.
|
||||
//
|
||||
// Наблюдалось 42 МиБ; сотня даёт запас втрое и при этом не даёт битому или
|
||||
// враждебному архивному файлу выесть память процесса. Граница явная, потому
|
||||
// что молчаливое «сколько дадут» — это отказ, который проявится только на
|
||||
// пике потока.
|
||||
const maxBodyBytes = 100 << 20
|
||||
// Наблюдалось 42 МиБ. Граница явная, потому что молчаливое «сколько дадут» —
|
||||
// это отказ, который проявится только на пике потока: битый или враждебный
|
||||
// файл архива выест память процесса.
|
||||
const defaultMaxBodyBytes = 64 << 20
|
||||
|
||||
// Service сворачивает доставки в часовые объекты.
|
||||
type Service struct {
|
||||
arch *archive.Archive
|
||||
store *store.Store
|
||||
log *slog.Logger
|
||||
|
||||
// maxBody — та же граница, что у приёма, и это существенно. Тело между
|
||||
// границами приёма и свёртки было бы принято со статусом 200, легло бы в
|
||||
// архив и потом вечно валилось бы при каждой пересборке.
|
||||
maxBody int64
|
||||
}
|
||||
|
||||
// New собирает свёртку.
|
||||
func New(arch *archive.Archive, st *store.Store, log *slog.Logger) *Service {
|
||||
return &Service{arch: arch, store: st, log: log.With("capability", "fold")}
|
||||
// New собирает свёртку. maxBody — граница размера РАСПАКОВАННОГО тела; ноль
|
||||
// означает умолчание.
|
||||
func New(arch *archive.Archive, st *store.Store, maxBody int64, log *slog.Logger) *Service {
|
||||
if maxBody <= 0 {
|
||||
maxBody = defaultMaxBodyBytes
|
||||
}
|
||||
return &Service{
|
||||
arch: arch,
|
||||
store: st,
|
||||
maxBody: maxBody,
|
||||
log: log.With("capability", "fold"),
|
||||
}
|
||||
}
|
||||
|
||||
// finishTimeout — сколько отводится записи исхода свёртки.
|
||||
//
|
||||
// Исход пишется на контексте, ПЕРЕЖИВАЮЩЕМ отмену исходного: иначе при
|
||||
// срабатывании дедлайна свёртки запись статуса гарантированно провалится, и
|
||||
// доставка навсегда останется `pending` — притом что часть объектов уже
|
||||
// записана. То есть ровно в том случае, ради которого дедлайн и заведён,
|
||||
// учёт разошёлся бы с содержимым витрины.
|
||||
const finishTimeout = 10 * time.Second
|
||||
|
||||
// Stats — итог свёртки одной доставки.
|
||||
type Stats struct {
|
||||
Metrics int
|
||||
Points int
|
||||
Stored int
|
||||
Buckets int
|
||||
Unchanged int
|
||||
Overwrites int
|
||||
SealedHits int
|
||||
UnitsConflicts int
|
||||
SkippedNoTime int
|
||||
SkippedMalformed int
|
||||
SkippedBadEnd int
|
||||
Layer string
|
||||
LayerMismatch bool
|
||||
Collisions []store.Collision
|
||||
}
|
||||
|
||||
// Fold разбирает тело доставки и раскладывает точки по часовым объектам.
|
||||
@@ -63,6 +92,10 @@ func (s *Service) Fold(ctx context.Context, deliveryID string) (Stats, error) {
|
||||
|
||||
d, err := s.store.DeliveryForParse(ctx, deliveryID)
|
||||
if err != nil {
|
||||
// Ни один выход с ошибкой не молчит: вызывающий эту ошибку сознательно
|
||||
// отбрасывает, и молчащий путь означал бы доставку вообще без событий
|
||||
// в журнале — её не найти ни по какому запросу.
|
||||
s.log.ErrorContext(ctx, "delivery fold failed", "error", err, "delivery_id", deliveryID)
|
||||
return stats, err
|
||||
}
|
||||
|
||||
@@ -74,6 +107,7 @@ func (s *Service) Fold(ctx context.Context, deliveryID string) (Stats, error) {
|
||||
|
||||
fallback, err := s.store.LastDerivedLayer(ctx, d.AutomationID, d.ReceivedAt, d.ID)
|
||||
if err != nil {
|
||||
s.log.ErrorContext(ctx, "delivery fold failed", "error", err, "delivery_id", deliveryID)
|
||||
return stats, err
|
||||
}
|
||||
|
||||
@@ -87,8 +121,10 @@ func (s *Service) Fold(ctx context.Context, deliveryID string) (Stats, error) {
|
||||
}
|
||||
|
||||
stats.Metrics = parsed.Metrics
|
||||
stats.Points = len(parsed.Points)
|
||||
stats.SkippedNoTime = parsed.SkippedNoTime
|
||||
stats.SkippedMalformed = parsed.SkippedMalformed
|
||||
stats.SkippedBadEnd = parsed.SkippedBadEnd
|
||||
stats.Layer = string(parsed.Layer)
|
||||
stats.LayerMismatch = parsed.LayerMismatch
|
||||
|
||||
@@ -98,13 +134,16 @@ func (s *Service) Fold(ctx context.Context, deliveryID string) (Stats, error) {
|
||||
return stats, err
|
||||
}
|
||||
|
||||
stats.Points = merge.Points
|
||||
stats.Stored = merge.Stored
|
||||
stats.Buckets = merge.Buckets
|
||||
stats.Unchanged = merge.Unchanged
|
||||
stats.Overwrites = merge.Overwrites
|
||||
stats.SealedHits = merge.SealedHits
|
||||
stats.UnitsConflicts = merge.UnitsConflicts
|
||||
stats.Collisions = merge.Collisions
|
||||
|
||||
if err := s.store.FinishParse(ctx, deliveryID, store.ParseDone, int64(stats.Points), stats.Layer); err != nil {
|
||||
if err := s.finish(ctx, deliveryID, store.ParseDone, int64(stats.Points), stats.Layer); err != nil {
|
||||
s.log.ErrorContext(ctx, "delivery fold failed", "error", err, "delivery_id", deliveryID)
|
||||
return stats, err
|
||||
}
|
||||
|
||||
@@ -112,25 +151,59 @@ func (s *Service) Fold(ctx context.Context, deliveryID string) (Stats, error) {
|
||||
return stats, nil
|
||||
}
|
||||
|
||||
// logResult — единственный логирующий чекпоинт свёртки.
|
||||
//
|
||||
// Все признаки идут АТРИБУТАМИ всегда, а уровень выбирается отдельно. Раньше
|
||||
// признаки жили только в тексте сообщения, и `switch` их терял: доставка,
|
||||
// одновременно задевшая запечатанный час и разошедшаяся с заголовком, не
|
||||
// оставляла следа о слое вовсе — а это единственный индикатор того, что слой
|
||||
// выводится неправильно.
|
||||
//
|
||||
// Значений точек и имён устройств здесь нет и быть не может: данные о здоровье
|
||||
// чувствительнее токенов. Координаты столкновений — метрика, слой, час — не
|
||||
// значения.
|
||||
func (s *Service) logResult(ctx context.Context, deliveryID string, st Stats) {
|
||||
skipped := st.SkippedNoTime + st.SkippedMalformed + st.SkippedBadEnd
|
||||
|
||||
attrs := []any{
|
||||
"delivery_id", deliveryID,
|
||||
"metrics", st.Metrics,
|
||||
"points", st.Points,
|
||||
"stored", st.Stored,
|
||||
"buckets", st.Buckets,
|
||||
"unchanged", st.Unchanged,
|
||||
"overwrites", st.Overwrites,
|
||||
"units_conflicts", st.UnitsConflicts,
|
||||
"sealed_hits", st.SealedHits,
|
||||
"skipped", skipped,
|
||||
"skipped_no_time", st.SkippedNoTime,
|
||||
"skipped_malformed", st.SkippedMalformed,
|
||||
"skipped_bad_end", st.SkippedBadEnd,
|
||||
"layer", st.Layer,
|
||||
"layer_mismatch", st.LayerMismatch,
|
||||
}
|
||||
if len(st.Collisions) > 0 {
|
||||
attrs = append(attrs, "collisions", formatCollisions(st.Collisions))
|
||||
}
|
||||
|
||||
// Доставка, у которой отброшены ВСЕ точки, — это сломавшийся формат, а не
|
||||
// штатная работа. Без этого условия смена формата метки выглядела бы как
|
||||
// здоровый поток: 200, parsed, INFO, points=0.
|
||||
allSkipped := st.Points == 0 && skipped > 0
|
||||
|
||||
switch {
|
||||
case st.Overwrites > 0:
|
||||
// Единственное наблюдение, по которому проверяется правило слияния.
|
||||
// В INFO оно тонуло: поток идёт раз в пять минут.
|
||||
s.log.WarnContext(ctx, "delivery folded, points overwritten", attrs...)
|
||||
case st.UnitsConflicts > 0:
|
||||
s.log.WarnContext(ctx, "delivery folded, units differ from stored", attrs...)
|
||||
case st.SealedHits > 0:
|
||||
// Досчёт часа, в который его уже не ждали: единственное наблюдение, по
|
||||
// которому вообще можно судить о глубине досчёта.
|
||||
s.log.WarnContext(ctx, "delivery folded, sealed hour changed",
|
||||
append(attrs, "sealed_hits", st.SealedHits)...)
|
||||
s.log.WarnContext(ctx, "delivery folded, sealed hour changed", attrs...)
|
||||
case allSkipped:
|
||||
s.log.WarnContext(ctx, "delivery folded, all points skipped", attrs...)
|
||||
case st.LayerMismatch:
|
||||
// Расхождение сверяется только с надёжным заголовком: `Default` не
|
||||
// означает режима, и сравнение с ним давало бы WARN на каждой доставке.
|
||||
@@ -140,18 +213,50 @@ func (s *Service) logResult(ctx context.Context, deliveryID string, st Stats) {
|
||||
}
|
||||
}
|
||||
|
||||
// formatCollisions превращает координаты столкновений в строку для лога.
|
||||
func formatCollisions(cs []store.Collision) string {
|
||||
parts := make([]string, 0, len(cs))
|
||||
for _, c := range cs {
|
||||
parts = append(parts, c.Metric+"/"+c.Layer+"@"+store.FormatTime(c.HourUTC))
|
||||
}
|
||||
return strings.Join(parts, " ")
|
||||
}
|
||||
|
||||
// keepLayer — значение слоя, означающее «оставить как было».
|
||||
const keepLayer = ""
|
||||
|
||||
// finish записывает исход разбора на контексте, переживающем отмену исходного.
|
||||
func (s *Service) finish(ctx context.Context, deliveryID, status string, points int64, layer string) error {
|
||||
ctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), finishTimeout)
|
||||
defer cancel()
|
||||
|
||||
if err := s.store.FinishParse(ctx, deliveryID, status, points, layer); err != nil {
|
||||
return fmt.Errorf("запись исхода разбора: %w", err)
|
||||
}
|
||||
return nil
|
||||
}
|
||||
|
||||
// fail отмечает доставку неразобранной. Тело остаётся в архиве, и её подберёт
|
||||
// пересборка — приём при этом не затрагивается: сохранили значит приняли.
|
||||
func (s *Service) fail(ctx context.Context, deliveryID string, cause error) {
|
||||
level := slog.LevelError
|
||||
if errors.Is(cause, hae.ErrLayerUnknown) {
|
||||
switch {
|
||||
case errors.Is(cause, hae.ErrLayerUnknown):
|
||||
// Слой не определился — это не поломка, а ожидаемый исход для доставки
|
||||
// без плотных метрик. Тело ждёт пересборки.
|
||||
level = slog.LevelWarn
|
||||
case errors.Is(cause, hae.ErrMalformed):
|
||||
// Непонятое содержимое от отправителя — норма жизни, разбирать нечего.
|
||||
// На границе приёма такой же отказ уходит в DEBUG; два разных уровня у
|
||||
// одного класса ошибки давали бы постоянный ERROR-шум.
|
||||
level = slog.LevelWarn
|
||||
}
|
||||
s.log.Log(ctx, level, "delivery fold failed", "error", cause, "delivery_id", deliveryID)
|
||||
|
||||
if err := s.store.FinishParse(ctx, deliveryID, store.ParseFailed, 0, ""); err != nil {
|
||||
// Слой НЕ затирается: доставка могла свернуться успешно раньше, и пустая
|
||||
// строка здесь оборвала бы цепочку наследования, то есть изменила бы
|
||||
// результат пересборки журнала.
|
||||
if err := s.finish(ctx, deliveryID, store.ParseFailed, 0, keepLayer); err != nil {
|
||||
s.log.ErrorContext(ctx, "delivery parse status not recorded", "error", err, "delivery_id", deliveryID)
|
||||
}
|
||||
}
|
||||
@@ -163,12 +268,12 @@ func (s *Service) readBody(rawPath string) ([]byte, error) {
|
||||
}
|
||||
defer func() { _ = r.Close() }()
|
||||
|
||||
body, err := io.ReadAll(io.LimitReader(r, maxBodyBytes+1))
|
||||
body, err := io.ReadAll(io.LimitReader(r, s.maxBody+1))
|
||||
if err != nil {
|
||||
return nil, fmt.Errorf("чтение тела из архива: %w", err)
|
||||
}
|
||||
if len(body) > maxBodyBytes {
|
||||
return nil, fmt.Errorf("тело больше %d байт", maxBodyBytes)
|
||||
if int64(len(body)) > s.maxBody {
|
||||
return nil, fmt.Errorf("тело больше %d байт", s.maxBody)
|
||||
}
|
||||
return body, nil
|
||||
}
|
||||
|
||||
@@ -28,7 +28,7 @@ func newFold(t *testing.T) (*fold.Service, *archive.Archive, *store.Store) {
|
||||
t.Cleanup(func() { _ = st.Close() })
|
||||
|
||||
log := slog.New(slog.DiscardHandler)
|
||||
return fold.New(arch, st, log), arch, st
|
||||
return fold.New(arch, st, 0, log), arch, st
|
||||
}
|
||||
|
||||
// deliver кладёт тело в архив и заводит доставку — ровно то, что делает приём.
|
||||
|
||||
@@ -0,0 +1,115 @@
|
||||
package fold_test
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"context"
|
||||
"encoding/json"
|
||||
"log/slog"
|
||||
"path/filepath"
|
||||
"strings"
|
||||
"testing"
|
||||
|
||||
"git.vakhrushev.me/av/healthlog/internal/archive"
|
||||
"git.vakhrushev.me/av/healthlog/internal/fold"
|
||||
"git.vakhrushev.me/av/healthlog/internal/store"
|
||||
)
|
||||
|
||||
// Данные о здоровье чувствительнее токенов, и требование «значения точек не в
|
||||
// логах» до сих пор не проверялось ничем: все тестовые логгеры выбрасывали
|
||||
// записи. Тест ловит записи и смотрит на них.
|
||||
func TestFoldНеПишетЗначенийВЛог(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
var buf bytes.Buffer
|
||||
log := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))
|
||||
|
||||
dir := t.TempDir()
|
||||
arch, err := archive.New(filepath.Join(dir, "raw"))
|
||||
if err != nil {
|
||||
t.Fatalf("архив: %v", err)
|
||||
}
|
||||
st, err := store.Open(filepath.Join(dir, "healthlog.db"))
|
||||
if err != nil {
|
||||
t.Fatalf("база: %v", err)
|
||||
}
|
||||
t.Cleanup(func() { _ = st.Close() })
|
||||
|
||||
f := fold.New(arch, st, 0, log)
|
||||
|
||||
// Значения и имя устройства выбраны так, чтобы их нельзя было спутать ни с
|
||||
// чем: если они окажутся в логе, это будет видно.
|
||||
body := []byte(`{"data":{"metrics":[{"name":"step_count","units":"count","data":[` +
|
||||
`{"date":"2025-06-05 10:00:00 +0300","qty":424242.7,"source":"Секретные Часы Антона"},` +
|
||||
`{"date":"2025-06-05 10:01:00 +0300","qty":313131.9,"source":"Секретные Часы Антона"},` +
|
||||
`{"date":"2025-06-05 10:02:00 +0300","qty":151515.1,"source":"Секретные Часы Антона"}` +
|
||||
`]}]}}`)
|
||||
|
||||
deliver(t, arch, st, "d1", "Minutes", "auto-1", body)
|
||||
if _, err := f.Fold(context.Background(), "d1"); err != nil {
|
||||
t.Fatalf("свёртка: %v", err)
|
||||
}
|
||||
|
||||
logged := buf.String()
|
||||
if logged == "" {
|
||||
t.Fatal("свёртка не записала ни одной строки — чекпоинт молчит")
|
||||
}
|
||||
|
||||
for _, secret := range []string{"424242", "313131", "151515", "Секретные Часы"} {
|
||||
if strings.Contains(logged, secret) {
|
||||
t.Errorf("в логе оказалось %q:\n%s", secret, logged)
|
||||
}
|
||||
}
|
||||
|
||||
// И одновременно — чекпоинт обязан нести счётчики, иначе он бесполезен.
|
||||
var rec map[string]any
|
||||
for line := range strings.SplitSeq(strings.TrimSpace(logged), "\n") {
|
||||
if err := json.Unmarshal([]byte(line), &rec); err != nil {
|
||||
t.Fatalf("строка лога не JSON: %v", err)
|
||||
}
|
||||
if rec["msg"] == "delivery folded" {
|
||||
break
|
||||
}
|
||||
}
|
||||
for _, attr := range []string{"delivery_id", "points", "stored", "buckets", "layer", "skipped"} {
|
||||
if _, ok := rec[attr]; !ok {
|
||||
t.Errorf("в записи нет атрибута %q: %v", attr, rec)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Доставка, у которой отброшены ВСЕ точки, — это сломавшийся формат, а не
|
||||
// штатная работа. Без WARN смена формата метки выглядела бы как здоровый
|
||||
// поток: 200, parsed, INFO, points=0.
|
||||
func TestFoldВсеТочкиОтброшеныДаётWarn(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
var buf bytes.Buffer
|
||||
log := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))
|
||||
|
||||
dir := t.TempDir()
|
||||
arch, err := archive.New(filepath.Join(dir, "raw"))
|
||||
if err != nil {
|
||||
t.Fatalf("архив: %v", err)
|
||||
}
|
||||
st, err := store.Open(filepath.Join(dir, "healthlog.db"))
|
||||
if err != nil {
|
||||
t.Fatalf("база: %v", err)
|
||||
}
|
||||
t.Cleanup(func() { _ = st.Close() })
|
||||
|
||||
f := fold.New(arch, st, 0, log)
|
||||
|
||||
// Метки в формате, которого разбор не знает: HAE сменил формат.
|
||||
body := []byte(`{"data":{"metrics":[{"name":"step_count","units":"count","data":[` +
|
||||
`{"date":"2025-06-05T10:00:00Z","qty":1},{"date":"2025-06-05T10:01:00Z","qty":2}` +
|
||||
`]}]}}`)
|
||||
|
||||
deliver(t, arch, st, "d1", "Minutes", "auto-1", body)
|
||||
if _, err := f.Fold(context.Background(), "d1"); err != nil {
|
||||
t.Fatalf("свёртка: %v", err)
|
||||
}
|
||||
|
||||
if !strings.Contains(buf.String(), `"level":"WARN"`) {
|
||||
t.Errorf("доставка без единой сохранённой точки записана не как WARN:\n%s", buf.String())
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user