founder
cb20d8d28f
Отзыв секрета не сходился: `auth_id` при смене секрета оставался прежним, поэтому сессия, установленная по отозванным учётным данным, была неотличима от законной, и цикл учёта не имел признака, по которому её следовало завершить. У состояния есть путь без единой неудачи — Hysteria регистрирует соединение в Traffic Stats API только после возврата backend-auth, поэтому успешный /kick может пройти мимо. Новое поколение credentials получает новый auth_id, kick идёт по старому, пережившая сессия становится orphan. Адрес Traffic Stats API имел два контракта: оркестратор принимал любой IPv4, админка всегда шла на loopback. Валидная по всем гейтам конфигурация выключала лимит устройств, учёт трафика и принудительное отключение разом. Адрес зафиксирован, а расхождение файла с ним админка называет. Состояние службы стало трёхзначным: util.Exec выбрасывал вывод systemctl при ненулевом коде, поэтому «остановлена» и «спросить не удалось» приходили одним значением, а доступность Traffic Stats API выводилась из него же. Журнал Hysteria разбирается в фактическом формате upstream (time — дробное число), страница конфигурации показывает файл вместо дефолтов UI и не возит секреты в браузер, санитайзер выгрузки следует по YAML-якорям. Разбор: docs/acceptance/2026-09-02-v1.0.0-rc4-preflight-findings.md
272 lines
11 KiB
Go
272 lines
11 KiB
Go
package service
|
||
|
||
import (
|
||
"encoding/json"
|
||
"strings"
|
||
"testing"
|
||
"time"
|
||
)
|
||
|
||
// Разбор журнала проверяется на ФАКТИЧЕСКОМ формате Hysteria 2.12.2.
|
||
//
|
||
// Записи в тестах не выдуманы: они собираются тем же способом, каким их пишет
|
||
// zap с EncoderConfig upstream — `time` числом epoch millis (дробным, потому
|
||
// что EpochMillisTimeEncoder делит наносекунды на миллисекунду), `level`
|
||
// строчными буквами, `msg` и произвольный структурный контекст рядом.
|
||
//
|
||
// Прежний разбор падал на КАЖДОЙ такой строке (`cannot unmarshal number into
|
||
// Go struct field ... of type string`) и уходил в fallback, показывая оператору
|
||
// сырой JSON. То есть `HYSTERIA_LOG_FORMAT=json` в юните был включён, а
|
||
// структурой никто не пользовался.
|
||
|
||
// hysteriaJSONLine собирает запись так же, как её пишет zap Hysteria.
|
||
func hysteriaJSONLine(t *testing.T, fields map[string]any) string {
|
||
t.Helper()
|
||
|
||
encoded, err := json.Marshal(fields)
|
||
if err != nil {
|
||
t.Fatalf("не удалось собрать запись журнала: %v", err)
|
||
}
|
||
return string(encoded)
|
||
}
|
||
|
||
func journalLine(message string) journalctlLogLine {
|
||
return journalctlLogLine{
|
||
Message: journalMessage(message),
|
||
Priority: "6",
|
||
RealtimeTimestamp: "1788321234567000",
|
||
}
|
||
}
|
||
|
||
// Главная регрессия: числовое `time` больше не роняет разбор.
|
||
func TestParseHysteriaJournalRecordReadsNumericEpochMillis(t *testing.T) {
|
||
// Значение дробное намеренно: EpochMillisTimeEncoder печатает float64.
|
||
moment := time.Date(2026, 9, 2, 12, 34, 56, 789_012_345, time.Local)
|
||
millis := float64(moment.UnixNano()) / float64(time.Millisecond)
|
||
|
||
record := parseHysteriaJournalRecord(journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": millis,
|
||
"level": "info",
|
||
"msg": "server up and running",
|
||
})))
|
||
|
||
if record.Level != "info" {
|
||
t.Fatalf("уровень %q, ожидался info", record.Level)
|
||
}
|
||
if record.Msg != "server up and running" {
|
||
t.Fatalf("сообщение %q, ожидался разобранный msg", record.Msg)
|
||
}
|
||
want := moment.Format("2006-01-02 15:04:05")
|
||
if record.Time != want {
|
||
t.Fatalf("время %q, ожидалось %q", record.Time, want)
|
||
}
|
||
// Сырой JSON в сообщение не попадает: это и был прежний исход.
|
||
if strings.Contains(record.Msg, "{") {
|
||
t.Fatalf("в сообщение уехала сырая запись: %q", record.Msg)
|
||
}
|
||
}
|
||
|
||
// Структурный контекст upstream сохраняется: именно он отвечает на вопрос,
|
||
// ради которого журнал открывают.
|
||
func TestParseHysteriaJournalRecordKeepsStructuredContext(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": 1788321234567.1235,
|
||
"level": "error",
|
||
"msg": "authentication failed",
|
||
"addr": "203.0.113.10:51820",
|
||
"id": "alpha-auth-id",
|
||
"error": "device limited",
|
||
"listen": ":443",
|
||
})))
|
||
|
||
for _, want := range []string{
|
||
"authentication failed",
|
||
"addr=203.0.113.10:51820",
|
||
"error=device limited",
|
||
"id=alpha-auth-id",
|
||
"listen=:443",
|
||
} {
|
||
if !strings.Contains(record.Msg, want) {
|
||
t.Fatalf("контекст %q потерян: %q", want, record.Msg)
|
||
}
|
||
}
|
||
}
|
||
|
||
// Порядок полей устойчив: карта в Go обходится случайно, и без сортировки одна
|
||
// и та же запись выглядела бы по-разному при каждом обновлении страницы.
|
||
func TestParseHysteriaJournalRecordContextOrderIsStable(t *testing.T) {
|
||
line := journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": 1788321234567.0,
|
||
"level": "info",
|
||
"msg": "client connected",
|
||
"zulu": "z",
|
||
"alpha": "a",
|
||
"mike": "m",
|
||
}))
|
||
|
||
first := parseHysteriaJournalRecord(line).Msg
|
||
for i := 0; i < 20; i++ {
|
||
if got := parseHysteriaJournalRecord(line).Msg; got != first {
|
||
t.Fatalf("порядок контекста не устойчив: %q против %q", got, first)
|
||
}
|
||
}
|
||
if !strings.Contains(first, "[alpha=a mike=m zulu=z]") {
|
||
t.Fatalf("контекст собран не по алфавиту: %q", first)
|
||
}
|
||
}
|
||
|
||
// Числа контекста печатаются человеку, а не в экспоненте.
|
||
func TestParseHysteriaJournalRecordFormatsNumbers(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": 1788321234567.0,
|
||
"level": "info",
|
||
"msg": "traffic",
|
||
"tx": float64(1_234_567_890),
|
||
"ratio": 0.5,
|
||
"ok": true,
|
||
})))
|
||
|
||
for _, want := range []string{"tx=1234567890", "ratio=0.5", "ok=true"} {
|
||
if !strings.Contains(record.Msg, want) {
|
||
t.Fatalf("значение %q отформатировано неверно: %q", want, record.Msg)
|
||
}
|
||
}
|
||
}
|
||
|
||
// Вложенный объект остаётся однострочным и читаемым.
|
||
func TestParseHysteriaJournalRecordFlattensNestedFields(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": 1788321234567.0,
|
||
"level": "warn",
|
||
"msg": "acl reloaded",
|
||
"stats": map[string]any{"rules": float64(12)},
|
||
})))
|
||
|
||
if !strings.Contains(record.Msg, `stats={"rules":12}`) {
|
||
t.Fatalf("вложенный объект потерян: %q", record.Msg)
|
||
}
|
||
if strings.Contains(record.Msg, "\n") {
|
||
t.Fatalf("запись журнала стала многострочной: %q", record.Msg)
|
||
}
|
||
}
|
||
|
||
// Секреты вырезаются и из сообщения, и из структурного контекста: HY2_AUTH_URL
|
||
// несёт access_token, и upstream волен упомянуть его в тексте ошибки.
|
||
func TestParseHysteriaJournalRecordSanitizesSecrets(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": 1788321234567.0,
|
||
"level": "error",
|
||
"msg": "auth backend request failed",
|
||
"url": "http://127.0.0.1:8080/internal/hysteria/auth?access_token=super-secret-value",
|
||
})))
|
||
|
||
if strings.Contains(record.Msg, "super-secret-value") {
|
||
t.Fatalf("секрет уехал в журнал панели: %q", record.Msg)
|
||
}
|
||
// Внутри query маркер приезжает percent-кодированным: URL обязан остаться
|
||
// валидным URL (см. encodedRedactedPlaceholder в log_sanitize.go).
|
||
if !strings.Contains(record.Msg, RedactedPlaceholder) &&
|
||
!strings.Contains(record.Msg, encodedRedactedPlaceholder) {
|
||
t.Fatalf("секрет вырезан без маркера: %q", record.Msg)
|
||
}
|
||
// Остальная часть адреса остаётся читаемой: без неё запись перестаёт быть
|
||
// диагностикой.
|
||
if !strings.Contains(record.Msg, "/internal/hysteria/auth") {
|
||
t.Fatalf("адрес вырезан целиком вместо секрета: %q", record.Msg)
|
||
}
|
||
}
|
||
|
||
// Не-JSON строка показывается как есть: console-формат и посторонний вывод
|
||
// рантайма терять нельзя.
|
||
func TestParseHysteriaJournalRecordFallsBackToRawMessage(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine("panic: runtime error: invalid memory address"))
|
||
|
||
if record.Msg != "panic: runtime error: invalid memory address" {
|
||
t.Fatalf("сырое сообщение потеряно: %q", record.Msg)
|
||
}
|
||
// Время и уровень берутся у journald: у него они есть всегда.
|
||
if record.Time == "" {
|
||
t.Fatal("время journald не подставлено")
|
||
}
|
||
if record.Level != "info" {
|
||
t.Fatalf("уровень journald не подставлен: %q", record.Level)
|
||
}
|
||
}
|
||
|
||
// JSON без `msg` — не запись Hysteria, и терять её тоже нельзя.
|
||
func TestParseHysteriaJournalRecordKeepsForeignJSON(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine(`{"foo":"bar"}`))
|
||
|
||
if !strings.Contains(record.Msg, "foo") {
|
||
t.Fatalf("посторонний JSON потерян: %q", record.Msg)
|
||
}
|
||
}
|
||
|
||
// Запись без собственного времени и уровня добирает их у journald.
|
||
func TestParseHysteriaJournalRecordUsesJournaldFallbacks(t *testing.T) {
|
||
line := journalLine(hysteriaJSONLine(t, map[string]any{"msg": "no level, no time"}))
|
||
line.Priority = "3"
|
||
|
||
record := parseHysteriaJournalRecord(line)
|
||
|
||
if record.Level != "error" {
|
||
t.Fatalf("уровень не взят из PRIORITY: %q", record.Level)
|
||
}
|
||
if record.Time != convertJournalTimestamp(line.RealtimeTimestamp) {
|
||
t.Fatalf("время не взято из __REALTIME_TIMESTAMP: %q", record.Time)
|
||
}
|
||
}
|
||
|
||
// Строковое `time` (console-формат, будущая смена энкодера) принимается как
|
||
// есть: переписывать чужой формат продукт не обязан.
|
||
func TestParseHysteriaJournalRecordAcceptsStringTime(t *testing.T) {
|
||
record := parseHysteriaJournalRecord(journalLine(hysteriaJSONLine(t, map[string]any{
|
||
"time": "2026-09-02T12:34:56Z",
|
||
"level": "info",
|
||
"msg": "server up and running",
|
||
})))
|
||
|
||
if record.Time != "2026-09-02T12:34:56Z" {
|
||
t.Fatalf("строковое время подменено: %q", record.Time)
|
||
}
|
||
}
|
||
|
||
// MESSAGE, отданный journald массивом байт (сообщение не является корректным
|
||
// UTF-8), больше не выбрасывает запись целиком.
|
||
func TestJournalMessageAcceptsByteArray(t *testing.T) {
|
||
var line journalctlLogLine
|
||
// Так journald кодирует «hi\xff» в `-o json`.
|
||
raw := `{"MESSAGE":[104,105,255],"PRIORITY":"6","__REALTIME_TIMESTAMP":"1788321234567000"}`
|
||
if err := json.Unmarshal([]byte(raw), &line); err != nil {
|
||
t.Fatalf("запись с байтовым MESSAGE отвергнута целиком: %v", err)
|
||
}
|
||
if string(line.Message) != "hi\xff" {
|
||
t.Fatalf("байтовое сообщение разобрано неверно: %q", string(line.Message))
|
||
}
|
||
if line.Priority != "6" {
|
||
t.Fatalf("остальные поля записи потеряны: %+v", line)
|
||
}
|
||
}
|
||
|
||
func TestJournalMessageAcceptsString(t *testing.T) {
|
||
var line journalctlLogLine
|
||
if err := json.Unmarshal([]byte(`{"MESSAGE":"plain","PRIORITY":"4"}`), &line); err != nil {
|
||
t.Fatalf("обычная запись отвергнута: %v", err)
|
||
}
|
||
if string(line.Message) != "plain" {
|
||
t.Fatalf("сообщение разобрано неверно: %q", string(line.Message))
|
||
}
|
||
}
|
||
|
||
// Отсутствующее или неизвестной формы MESSAGE не роняет запись: у неё остаются
|
||
// время и приоритет.
|
||
func TestJournalMessageSurvivesUnknownShape(t *testing.T) {
|
||
var line journalctlLogLine
|
||
if err := json.Unmarshal([]byte(`{"MESSAGE":{"unexpected":true},"PRIORITY":"6"}`), &line); err != nil {
|
||
t.Fatalf("запись с неизвестной формой MESSAGE отвергнута: %v", err)
|
||
}
|
||
if string(line.Message) != "" {
|
||
t.Fatalf("неизвестная форма превратилась в сообщение: %q", string(line.Message))
|
||
}
|
||
}
|