имя файла отправителя убрано из журнала приёма

- расширение приводится к перечню известных форматов прежде метки метрики:
  страница метрик открыта, и хвост имени уезжал на неё дословно
- проверки приёма перехватывают все три потока журнала и читают реестр метрик,
  каждая падает при снятии того, что сторожит
This commit is contained in:
av
2026-08-11 16:37:58 +03:00
parent ffa36e96c7
commit bd6001cd8d
18 changed files with 1797 additions and 20 deletions
+214 -7
View File
@@ -5,7 +5,7 @@ import (
"database/sql"
"encoding/json"
"errors"
"io"
"fmt"
"log/slog"
"mime/multipart"
"net/http"
@@ -13,7 +13,10 @@ import (
"os"
"path"
"path/filepath"
"regexp"
"runtime"
"strings"
"sync"
"testing"
"time"
@@ -27,6 +30,8 @@ import (
"github.com/gin-gonic/gin"
_ "github.com/mattn/go-sqlite3"
"github.com/pressly/goose/v3"
"github.com/prometheus/client_golang/prometheus"
sloggin "github.com/samber/slog-gin"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
@@ -74,6 +79,31 @@ type testEnv struct {
handler *TranscribeHandler
db *sql.DB
storageDir string
journal *journalBuffer
}
// journalBuffer — перехваченный журнал одной проверки. Свой на случай: общий на
// пакет сделал бы исход функцией от соседних случаев — «поля на месте» прошло бы
// на чужой строке, а «маркера нет» покраснело бы от чужой. Замок нужен потому,
// что пишущих в него потоков три: логгер сервиса, стандартный `log` транспорта
// и middleware запроса.
type journalBuffer struct {
mu sync.Mutex
text strings.Builder
}
func (b *journalBuffer) Write(p []byte) (int, error) {
b.mu.Lock()
defer b.mu.Unlock()
return b.text.Write(p)
}
// String отдаёт весь перехваченный текст. Проверки ищут в нём значение, а не имя
// поля: имя, вернувшееся под другим ключом, поиск по ключу не разбудил бы.
func (b *journalBuffer) String() string {
b.mu.Lock()
defer b.mu.Unlock()
return b.text.String()
}
func setupTestDB(t *testing.T) (*sql.DB, *goqu.Database) {
@@ -115,11 +145,26 @@ func setupTestEnv(t *testing.T, metaviewer contract.AudioMetaViewer) *testEnv {
fileRepo := sqlite.NewFileRepository(db, gq)
jobRepo := sqlite.NewTranscriptJobRepository(db, gq)
// Журнал проверкам не нужен: судят они по ответу и по базе. А ветка отказа
// метаданных теперь проходится нарочно, и её ERROR-строки на зелёном
// прогоне размывали бы признак, по которому отличают новый красный шаг
// гейта от объявленного долга.
logger := slog.New(slog.NewTextHandler(io.Discard, nil))
// Журнал уходит в буфер, а не в никуда: по нему судит проверка запрета на
// имя отправителя. Вывод прогона от этого не меняется — ERROR-строки ветки
// отказа по-прежнему не попадают на экран и не размывают признак, по
// которому отличают новый красный шаг гейта от объявленного долга.
journal := &journalBuffer{}
logger := slog.New(slog.NewTextHandler(journal, nil))
// Второй писатель журнала приёма — HTTP-транспорт: он пишет через стандартный
// `log` (расхождение записано в docs/conventions/logging.md). В бою `main.go`
// зовёт `slog.SetDefault`, и такая запись садится в `msg` строки `slog`;
// повторяем это здесь, чтобы оракул видел ту же цепочку, что и прод, а не
// свою. Без перехвата оракул был бы уже требования, которое накрывает все
// журнальные записи приёма.
//
// Подмена процессная, а не своя у случая: `t.Parallel()` в этом файле
// запрещён. При параллельных случаях вывод указывал бы на буфер соседа, и
// проверка запрета прошла бы, ничего не прочитав.
prevDefault := slog.Default()
slog.SetDefault(logger)
t.Cleanup(func() { slog.SetDefault(prevDefault) })
trsService := service.NewTranscribeService(
jobRepo,
@@ -134,7 +179,12 @@ func setupTestEnv(t *testing.T, metaviewer contract.AudioMetaViewer) *testEnv {
handler := NewTranscribeHandler(jobRepo, trsService)
// Роутер собирается той же цепочкой, что и боевой (main.go): у приёма три
// пишущих в журнал потока, и middleware — третий. Без него требование «ни
// одна журнальная запись приёма» проверялось бы шире, чем оракул смотрит.
router := gin.New()
router.Use(sloggin.New(logger))
router.Use(gin.Recovery())
router.MaxMultipartMemory = 32 << 20 // 32 MiB
api := router.Group("/api")
@@ -143,7 +193,7 @@ func setupTestEnv(t *testing.T, metaviewer contract.AudioMetaViewer) *testEnv {
api.GET("/status/:id", handler.GetTranscribeJobStatus)
}
return &testEnv{router: router, handler: handler, db: db, storageDir: storageDir}
return &testEnv{router: router, handler: handler, db: db, storageDir: storageDir, journal: journal}
}
// createMultipartRequest собирает запрос из имени и содержимого. Файла на диске
@@ -382,6 +432,163 @@ func TestCreateTranscribeJob_MetaViewerFailure(t *testing.T) {
assert.Equal(t, 0, countJobs(t, env))
}
// senderNameMarker — метка внутри имени, которое даёт отправитель. ASCII и
// заведомо уникальна: в остальном выводе прогона такой строки нет, поэтому
// находка означает утечку, а не совпадение. Ищется она **значением**, а не
// именем журнального поля: имя, вернувшееся под другим ключом, поиск по ключу
// пропустил бы.
const senderNameMarker = "SENDERNAMELEAKMARKER7Q2"
// Тексты, по которым проверки находят журнальные строки. Оба — записанный долг
// `docs/conventions/logging.md`: `msg` обязан стать короткой категорией, а
// транспорту не положено логировать вовсе. Когда долг закроют, правка будет
// здесь и одна, а смысл утверждений менять не придётся.
const (
msgIntake = "Creating transcribe job"
msgTransportErr = "Err:"
msgMiddleware = "Incoming request"
)
func TestCreateTranscribeJob_SenderFileNameNotLogged(t *testing.T) {
env := setupTestEnv(t, readableMetaViewer())
// Метка стоит в основе имени, а расширение обычное: расширение запретом не
// накрыто и в журнале остаётся законно.
req := createMultipartRequest(t, senderNameMarker+".mp3", []byte("запись"))
w := httptest.NewRecorder()
env.router.ServeHTTP(w, req)
require.Equal(t, http.StatusCreated, w.Code)
journal := env.journal.String()
// Сперва — что поток middleware вообще перехвачен. Он третий писатель
// журнала приёма, и без этого утверждения снятие его из тестового роутера
// сузило бы оракул молча.
require.Contains(t, journal, msgMiddleware,
"строка middleware о запросе попадает в перехваченный журнал")
assert.NotContains(t, journal, senderNameMarker,
"имя, данное отправителем, не пишется в журнал: инвариант приватности")
}
func TestCreateTranscribeJob_SenderFileNameNotLoggedOnFailure(t *testing.T) {
// Отказ — тот путь, где имя приехало бы в журнал текстом ошибки: приём
// назван конвенцией логирующей границей, и цепочка `%w` осядет полем error.
env := setupTestEnv(t, &stubMetaViewer{err: errors.New("не удалось прочитать запись")})
req := createMultipartRequest(t, senderNameMarker+".mp3", []byte("не запись вовсе"))
w := httptest.NewRecorder()
env.router.ServeHTTP(w, req)
require.Equal(t, http.StatusInternalServerError, w.Code)
journal := env.journal.String()
// Сперва — что второй поток журнала вообще перехвачен. Без этого
// утверждения снятие `slog.SetDefault` из окружения оставило бы проверку
// зелёной, а оракул критического инварианта молча сузился бы вдвое.
require.Contains(t, journal, msgTransportErr,
"строка транспорта, идущая мимо slog, попадает в перехваченный журнал")
assert.NotContains(t, journal, senderNameMarker,
"имя отправителя не пишется в журнал и на пути отказа")
}
func TestCreateTranscribeJob_JournalTracesRecord(t *testing.T) {
env := setupTestEnv(t, readableMetaViewer())
content := []byte("содержимое записи")
req := createMultipartRequest(t, "sample.mp3", content)
w := httptest.NewRecorder()
env.router.ServeHTTP(w, req)
require.Equal(t, http.StatusCreated, w.Code)
var response CreateTranscribeJobResponse
require.NoError(t, json.Unmarshal(w.Body.Bytes(), &response))
job, err := env.handler.jobRepo.GetByID(response.JobID)
require.NoError(t, err)
require.NotNil(t, job.FileID)
// Отбор по идентификатору **этого** прогона: иначе утверждение прошло бы по
// строке, оставленной соседней проверкой, и прослеживаемость числилась бы
// сохранённой при пустом журнале.
journal := env.journal.String()
assert.Contains(t, journal, *job.FileID, "по журналу видно, какой файл заведён")
assert.Contains(t, journal, ".mp3", "расширение принятой записи в журнале остаётся")
// Разделитель ключа и значения задаёт обработчик: сегодня текстовый, по
// конвенции — JSON. Утверждение держится на значении и переживёт замену.
assert.Regexp(t, fmt.Sprintf(`size["=:\s]+%d`, len(content)), journal,
"размер принятой записи в байтах в журнале остаётся")
// Запись о приёме не сменила адресата: на DEBUG её в боевой настройке не
// будет вовсе, и разбор постфактум опереться будет не на что. Уровень
// ищется в строке самого приёма — соседние строки тоже идут на INFO, и
// поиск по всему журналу не упал бы от понижения этой.
assert.Regexp(t, `(?m)^.*level["=:\s]+INFO.*`+regexp.QuoteMeta(msgIntake)+`.*$`, journal,
"строка приёма остаётся на уровне INFO")
// И она ровно одна: вторая строка приёма означала бы второй путь заведения
// задачи мимо общей точки, то есть место, куда запрет не доехал.
assert.Equal(t, 1, strings.Count(journal, msgIntake),
"на принятую запись приходится одна журнальная строка приёма")
}
// metricLabelValues собирает значения меток названного семейства метрик из
// общего реестра процесса. Проверка судит реестр, а не функцию приведения:
// приведение, снятое в точке употребления, функцию не ломает, а хвост имени
// уходит на страницу метрик, которая отдаётся без проверки отправителя.
func metricLabelValues(t *testing.T, family string) []string {
families, err := prometheus.DefaultGatherer.Gather()
require.NoError(t, err)
var values []string
for _, mf := range families {
if mf.GetName() != family {
continue
}
for _, m := range mf.GetMetric() {
for _, label := range m.GetLabel() {
values = append(values, label.GetValue())
}
}
}
return values
}
func TestCreateTranscribeJob_MetricLabelCarriesNoSenderName(t *testing.T) {
env := setupTestEnv(t, readableMetaViewer())
// Хвост после последней точки — это тоже кусок имени, данного отправителем.
req := createMultipartRequest(t, "sample."+senderNameMarker, []byte("запись"))
w := httptest.NewRecorder()
env.router.ServeHTTP(w, req)
require.Equal(t, http.StatusCreated, w.Code)
values := metricLabelValues(t, "transcriber_input_file_size_bytes")
require.NotEmpty(t, values, "метрика размера принятой записи заполняется приёмом")
assert.NotContains(t, values, "."+senderNameMarker,
"метка метрики не несёт хвоста имени, данного отправителем")
assert.NotContains(t, values, senderNameMarker,
"метка метрики не несёт хвоста имени и без ведущей точки")
assert.Contains(t, values, "other",
"незнакомое расширение приведено к общему значению")
// А на диске расширение остаётся пришедшим: раскладка каталога записей
// объявлена необратимой, и приведение сюда не распространяется.
files := storedFiles(t, env)
require.Len(t, files, 1)
assert.Equal(t, "."+senderNameMarker, filepath.Ext(files[0]))
}
func TestGetTranscribeJobStatus_Success(t *testing.T) {
env := setupTestEnv(t, readableMetaViewer())
+69
View File
@@ -0,0 +1,69 @@
package metrics
import (
"strconv"
"strings"
)
// OtherFormatLabel — значение метки для всего, чего нет в перечне known-форматов.
const OtherFormatLabel = "other"
// knownFormats — закрытый перечень расширений, которые допускаются меткой.
//
// Состав: пути, которые выдаёт Telegram (голосовое приходит как
// `voice/file_N.oga`, кружок — с `.mp4`), плюс форматы, доезжающие приёмом по
// HTTP, плюс собственное умолчание сервиса на случай имени без расширения.
// Списку, по которому бот отбирает **документы** (`isAudioDocument`), перечень
// намеренно не равен: тот судит по типу содержимого и своим списком пользуется
// лишь когда типа нет, а сюда попадает и то, что приходит другими путями.
// Сведение двух списков в один уронило бы основной вход сервиса в `other`.
var knownFormats = map[string]struct{}{
"mp3": {},
"wav": {},
"ogg": {},
"oga": {},
"opus": {},
"flac": {},
"m4a": {},
"aac": {},
"wma": {},
"mp4": {},
"mkv": {},
"mov": {},
"avi": {},
"webm": {},
"audio": {}, // умолчание сервиса, когда расширения в имени не было
}
// FormatLabel приводит расширение к виду, годному для метки метрики.
//
// Расширение приходит из имени, которое дал отправитель, и потому может быть
// чем угодно: имя `запись.тайное-слово` отдаёт `тайное-слово`. Страница метрик
// открыта, то есть метка — поверхность пошире журнала. Незнакомое значение
// заменяется одним общим: это закрывает и утечку куска имени, и рост числа
// временных рядов, которым иначе распоряжается анонимный отправитель.
//
// Имени файла на диске это не касается — там расширение остаётся пришедшим.
// ObserveInputFileSize записывает размер принятой записи. Расширение приводится
// здесь, а не у вызывающего: сырая точка употребления — это место, где хвост
// имени отправителя однажды снова уедет наружу, и проверка у вызывающего этого
// не заметит.
func ObserveInputFileSize(ext string, size int64) {
InputFileSizeHistogram.WithLabelValues(FormatLabel(ext)).Observe(float64(size))
}
// ObserveConversionDuration записывает длительность конвертации. Исходный формат
// приводится по той же причине, что и в приёме.
func ObserveConversionDuration(srcExt, targetFormat string, failed bool, seconds float64) {
ConversionDurationHistogram.
WithLabelValues(FormatLabel(srcExt), targetFormat, strconv.FormatBool(failed)).
Observe(seconds)
}
func FormatLabel(ext string) string {
normalized := strings.ToLower(strings.TrimPrefix(ext, "."))
if _, ok := knownFormats[normalized]; ok {
return normalized
}
return OtherFormatLabel
}
+117
View File
@@ -0,0 +1,117 @@
package metrics
import (
"strings"
"testing"
"github.com/prometheus/client_golang/prometheus"
)
// Метка метрики уезжает на страницу, которая отдаётся без проверки отправителя,
// поэтому судим здесь ровно одно: что наружу выходит только известное значение.
func TestFormatLabel(t *testing.T) {
testCases := []struct {
name string
ext string
want string
}{
{name: "известное расширение с точкой", ext: ".mp3", want: "mp3"},
{name: "известное расширение без точки", ext: "mp3", want: "mp3"},
{name: "регистр приводится", ext: ".MP3", want: "mp3"},
{name: "умолчание сервиса", ext: ".audio", want: "audio"},
// Голосовое из Telegram приходит путём вида `voice/file_N.oga`, кружок —
// с `.mp4`. Это основной вход сервиса: усечение перечня до списка, по
// которому бот отбирает документы, схлопнуло бы его в общее значение.
{name: "голосовое из Telegram", ext: ".oga", want: "oga"},
{name: "видеокружок из Telegram", ext: ".mp4", want: "mp4"},
{name: "opus", ext: ".opus", want: "opus"},
// Значение сверяется с литералом, а не с самой константой: сверка с
// константой утверждала бы тавтологию, а спека нормирует слово `other`
// дословно.
{name: "хвост имени отправителя", ext: ".тайное-слово", want: "other"},
{name: "часть даты в имени", ext: ".08", want: "other"},
{name: "пустое", ext: "", want: "other"},
{name: "одна точка", ext: ".", want: "other"},
}
for _, tc := range testCases {
t.Run(tc.name, func(t *testing.T) {
if got := FormatLabel(tc.ext); got != tc.want {
t.Errorf("FormatLabel(%q) = %q, ожидалось %q", tc.ext, got, tc.want)
}
})
}
}
// labelValues собирает значения меток названного семейства из общего реестра.
func labelValues(t *testing.T, family string) []string {
families, err := prometheus.DefaultGatherer.Gather()
if err != nil {
t.Fatalf("не удалось прочитать реестр метрик: %v", err)
}
var values []string
for _, mf := range families {
if mf.GetName() != family {
continue
}
for _, m := range mf.GetMetric() {
for _, label := range m.GetLabel() {
values = append(values, label.GetValue())
}
}
}
return values
}
// Метку конвертации приёмом по HTTP не достать: шаг живёт в воркере, и своего
// окружения у него нет. Поэтому обёртка судится здесь — по реестру, а не по
// чистой функции: сырое употребление гистограммы мимо обёртки и есть то место,
// где хвост имени отправителя однажды снова уедет наружу.
func TestObserveConversionDurationLabelsAreKnown(t *testing.T) {
const tail = "CONVLEAKMARKER5X8"
ObserveConversionDuration("."+tail, "ogg", false, 1)
values := labelValues(t, "transcriber_conversion_duration_seconds")
if len(values) == 0 {
t.Fatal("метрика длительности конвертации не заполнилась")
}
assertTailAbsentAndOtherPresent(t, values, tail)
}
// Та же проверка для метки приёма — на случай, если обёртку обойдут только с
// одной стороны.
func TestObserveInputFileSizeLabelsAreKnown(t *testing.T) {
const tail = "INPUTLEAKMARKER5X8"
ObserveInputFileSize("."+tail, 42)
values := labelValues(t, "transcriber_input_file_size_bytes")
if len(values) == 0 {
t.Fatal("метрика размера принятой записи не заполнилась")
}
assertTailAbsentAndOtherPresent(t, values, tail)
}
// assertTailAbsentAndOtherPresent судит значения метки по двум признакам сразу.
// Одного «хвоста нет» мало: приведение, ослабленное до смены регистра, хвост
// пропустило бы, а поиск заглавного маркера в строчном значении его не нашёл бы.
// Поэтому сравнение регистронезависимое, и рядом стоит второй признак — что
// незнакомое расширение вообще доехало до общего значения.
func assertTailAbsentAndOtherPresent(t *testing.T, values []string, tail string) {
t.Helper()
for _, v := range values {
if strings.Contains(strings.ToLower(v), strings.ToLower(tail)) {
t.Fatalf("метка несёт хвост имени, данного отправителем: %q", v)
}
}
for _, v := range values {
if v == "other" {
return
}
}
t.Fatal("незнакомое расширение не приведено к общему значению")
}
+19
View File
@@ -0,0 +1,19 @@
package service
import (
"testing"
"git.vakhrushev.me/av/transcriber/internal/metrics"
)
// Умолчание расширения живёт в этом пакете, а перечень значений метки — в
// пакете метрик, и связывает их только совпадение двух литералов. Компилятор
// расхождения не поймает: смена умолчания просто сложит все записи без
// расширения в общее значение, и метка перестанет отличать «расширения не было»
// от чужого хвоста в имени.
func TestDefaultAudioExtIsKnownToMetrics(t *testing.T) {
if got := metrics.FormatLabel(defaultAudioExt); got == metrics.OtherFormatLabel {
t.Fatalf("умолчание %q не входит в перечень известных форматов: метка отдаёт %q",
defaultAudioExt, got)
}
}
+4 -6
View File
@@ -7,7 +7,6 @@ import (
"log/slog"
"os"
"path/filepath"
"strconv"
"strings"
"time"
@@ -102,9 +101,10 @@ func (s *TranscribeService) createTranscribeJob(job *entity.TranscribeJob, file
storageFileName := fmt.Sprintf("%s%s", fileId, ext)
storageFilePath := filepath.Join(s.storagePath, storageFileName)
// Имя, данное отправителем, в журнал не идёт: инвариант приватности.
// Расширение из него уже стоит в собственном имени файла на диске.
s.logger.Info("Creating transcribe job",
"file_id", fileId,
"file_name", fileName,
"storage_path", storageFilePath)
// Создаем файл на диске
@@ -139,7 +139,7 @@ func (s *TranscribeService) createTranscribeJob(job *entity.TranscribeJob, file
"duration_seconds", info.Seconds)
metrics.InputFileDurationHistogram.WithLabelValues().Observe(float64(info.Seconds))
metrics.InputFileSizeHistogram.WithLabelValues(ext).Observe(float64(size))
metrics.ObserveInputFileSize(ext, size)
// Создаем запись в таблице files
fileRecord := &entity.File{
@@ -207,9 +207,7 @@ func (s *TranscribeService) FindAndRunConversionJob() error {
conversionDuration := time.Since(startTime)
// Записываем метрику времени конвертации
metrics.ConversionDurationHistogram.
WithLabelValues(srcExt, "ogg", strconv.FormatBool(err != nil)).
Observe(conversionDuration.Seconds())
metrics.ObserveConversionDuration(srcExt, "ogg", err != nil, conversionDuration.Seconds())
if err != nil {
s.logger.Error("File conversion failed",