HY2XS_flamy/apps/middleware/log_test.go

package middleware

import (
	"bytes"
	"encoding/json"
	"net/http"
	"net/http/httptest"
	"strings"
	"testing"

	"github.com/gin-gonic/gin"
	"github.com/sirupsen/logrus"
)

// sentinel имитирует действующий machine token: если он окажется в журнале —
// значит секрет утёк в /var/log/hy2xs/hy2xs-admin.log, который отдаётся
// оператору через ExportLog и попадает в diagnostics-бандл.
const sentinel = "SUPER_SECRET_SENTINEL"

func captureLog(t *testing.T, request *http.Request) string {
	t.Helper()

	previousOut := logrus.StandardLogger().Out
	previousFormatter := logrus.StandardLogger().Formatter
	t.Cleanup(func() {
		logrus.SetOutput(previousOut)
		logrus.SetFormatter(previousFormatter)
	})

	buffer := &bytes.Buffer{}
	logrus.SetOutput(buffer)
	logrus.SetFormatter(&logrus.JSONFormatter{})

	gin.SetMode(gin.TestMode)
	engine := gin.New()
	engine.Use(LogHandler())
	engine.POST("/internal/hysteria/auth", func(c *gin.Context) { c.Status(http.StatusOK) })
	engine.GET("/api/peers", func(c *gin.Context) { c.Status(http.StatusOK) })

	engine.ServeHTTP(httptest.NewRecorder(), request)
	return buffer.String()
}

// Регрессия: логировался c.Request.RequestURI, то есть путь ВМЕСТЕ с query.
// Hysteria обращается к машинному endpoint'у при каждом подключении пира, так
// что токен оседал в журнале в штатном режиме работы.
func TestLogHandlerNeverLogsQueryValues(t *testing.T) {
	request := httptest.NewRequest(
		http.MethodPost,
		"/internal/hysteria/auth?access_token="+sentinel,
		strings.NewReader("{}"),
	)

	logged := captureLog(t, request)

	if strings.Contains(logged, sentinel) {
		t.Fatalf("machine token попал в журнал: %s", logged)
	}
	if !strings.Contains(logged, `"reqPath":"/internal/hysteria/auth"`) {
		t.Fatalf("в журнале нет пути запроса: %s", logged)
	}
	if strings.Contains(logged, "reqUri") {
		t.Fatalf("поле reqUri вернулось в журнал: %s", logged)
	}
}

// Имена параметров для диагностики сохраняются: важно видеть, что параметр был
// передан, а не что в нём лежало.
func TestLogHandlerKeepsQueryKeyNames(t *testing.T) {
	request := httptest.NewRequest(
		http.MethodPost,
		"/internal/hysteria/auth?access_token="+sentinel,
		strings.NewReader("{}"),
	)

	logged := captureLog(t, request)

	if !strings.Contains(logged, `"reqQueryKeys":"access_token"`) {
		t.Fatalf("имя query-параметра не попало в журнал: %s", logged)
	}
}

func TestLogHandlerOmitsQueryKeysWhenThereAreNone(t *testing.T) {
	request := httptest.NewRequest(http.MethodGet, "/api/peers", nil)

	logged := captureLog(t, request)

	if strings.Contains(logged, "reqQueryKeys") {
		t.Fatalf("пустой список параметров не должен появляться в журнале: %s", logged)
	}
}

// Регрессия LOG-01: `entry.Info()` вызывался БЕЗ аргумента, и logrus честно
// записывал `"msg":""` для каждого HTTP-запроса. Страница системных логов
// показывала оператору пустой столбец сообщений — она отражала ровно то, что
// backend записал.
func TestLogHandlerWritesNonEmptyMessage(t *testing.T) {
	request := httptest.NewRequest(http.MethodGet, "/api/peers", nil)

	logged := captureLog(t, request)

	var record map[string]any
	if err := json.Unmarshal([]byte(strings.TrimSpace(logged)), &record); err != nil {
		t.Fatalf("запись журнала не разбирается как JSON: %s", logged)
	}

	message, _ := record["msg"].(string)
	if strings.TrimSpace(message) == "" {
		t.Fatalf("запись журнала пришла с пустым msg: %s", logged)
	}

	// `msg` обязан быть читаемым сам по себе: ради этого он и существует.
	for _, fragment := range []string{"GET", "/api/peers", "200"} {
		if !strings.Contains(message, fragment) {
			t.Errorf("в msg нет %q: %q", fragment, message)
		}
	}

	// Структурные поля при этом остаются на месте — `msg` их не заменяет.
	for _, field := range []string{"reqMethod", "reqPath", "statusCode", "latencyTime", "clientIP"} {
		if _, ok := record[field]; !ok {
			t.Errorf("структурное поле %q исчезло из записи: %s", field, logged)
		}
	}
}

// Человекочитаемое сообщение НЕ является лазейкой для query-строки: контракт
// безопасности сильнее удобства чтения.
func TestLogHandlerMessageNeverCarriesQueryValues(t *testing.T) {
	request := httptest.NewRequest(
		http.MethodPost,
		"/internal/hysteria/auth?access_token="+sentinel,
		strings.NewReader("{}"),
	)

	logged := captureLog(t, request)

	var record map[string]any
	if err := json.Unmarshal([]byte(strings.TrimSpace(logged)), &record); err != nil {
		t.Fatalf("запись журнала не разбирается как JSON: %s", logged)
	}

	message, _ := record["msg"].(string)
	if strings.TrimSpace(message) == "" {
		t.Fatalf("запись журнала пришла с пустым msg: %s", logged)
	}
	if strings.Contains(message, sentinel) {
		t.Fatalf("machine token попал в msg: %q", message)
	}
	if strings.Contains(message, "?") {
		t.Fatalf("query-строка попала в msg: %q", message)
	}
	if !strings.Contains(message, "/internal/hysteria/auth") {
		t.Fatalf("в msg нет пути запроса: %q", message)
	}
}

// Значение секретоподобного параметра не должно попасть в журнал ни на каком
// маршруте, а не только на машинном.
func TestLogHandlerRedactsQueryValuesOnOperatorRoutes(t *testing.T) {
	request := httptest.NewRequest(http.MethodGet, "/api/peers?includeSecrets=true&name="+sentinel, nil)

	logged := captureLog(t, request)

	if strings.Contains(logged, sentinel) {
		t.Fatalf("значение query-параметра попало в журнал: %s", logged)
	}
	if !strings.Contains(logged, `"reqPath":"/api/peers"`) {
		t.Fatalf("в журнале нет пути запроса: %s", logged)
	}
}