From 5ef517d0fc0d8bbc43940e79bf023d6182ad080e Mon Sep 17 00:00:00 2001 From: Achord Chan Date: Tue, 6 Oct 2026 13:59:37 +0800 Subject: [PATCH] fix(accounts): attribute connectivity test failure logs --- .../internal/service/account_test_logging.go | 48 ++++++++++ .../service/account_test_logging_test.go | 93 +++++++++++++++++++ .../internal/service/account_test_service.go | 5 +- 3 files changed, 145 insertions(+), 1 deletion(-) create mode 100644 backend/internal/service/account_test_logging.go create mode 100644 backend/internal/service/account_test_logging_test.go diff --git a/backend/internal/service/account_test_logging.go b/backend/internal/service/account_test_logging.go new file mode 100644 index 0000000000..f1f5501d57 --- /dev/null +++ b/backend/internal/service/account_test_logging.go @@ -0,0 +1,48 @@ +package service + +import ( + "github.com/Wei-Shaw/sub2api/internal/pkg/logger" + "github.com/Wei-Shaw/sub2api/internal/util/logredact" + "github.com/gin-gonic/gin" + "github.com/google/uuid" + "go.uber.org/zap" +) + +const accountTestBackgroundKey = "account_test_background" + +// Bind attribution before lookup so missing accounts are identifiable too. The +// request logger retains HTTP request IDs or the caller's background correlation. +func initAccountTestLogger(c *gin.Context, accountID int64, modelID, mode string) { + source := "http" + if c.GetBool(accountTestBackgroundKey) { + source = "background" + } + ctx := c.Request.Context() + l := logger.FromContext(ctx).With( + zap.String("component", "service.account_test"), + zap.Int64("account_id", accountID), + zap.String("test_id", uuid.NewString()), + zap.String("test_source", source), + zap.String("requested_model", modelID), + zap.String("test_mode", normalizeAccountTestMode(mode)), + ) + c.Request = c.Request.WithContext(logger.IntoContext(ctx, l)) +} + +func bindAccountTestPlatform(c *gin.Context, account *Account) { + ctx := c.Request.Context() + l := logger.FromContext(ctx).With( + zap.String("platform", account.Platform), + zap.String("account_type", account.Type), + ) + c.Request = c.Request.WithContext(logger.IntoContext(ctx, l)) +} + +func logAccountTestError(c *gin.Context, message string) { + // Redact known credential fields before bounding text; truncating first can + // cut a quoted credential in half and prevent the redactor from matching it. + message = logredact.RedactText(message, "api_key", "authorization") + logger.FromContext(c.Request.Context()).Warn("account_test.failed", + zap.String("error", truncateString(message, 2048)), + ) +} diff --git a/backend/internal/service/account_test_logging_test.go b/backend/internal/service/account_test_logging_test.go new file mode 100644 index 0000000000..8defd03563 --- /dev/null +++ b/backend/internal/service/account_test_logging_test.go @@ -0,0 +1,93 @@ +//go:build unit + +package service + +import ( + "context" + "errors" + "net/http/httptest" + "strings" + "testing" + + "github.com/Wei-Shaw/sub2api/internal/pkg/logger" + "github.com/gin-gonic/gin" + "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zaptest/observer" +) + +type accountTestLoggingRepo struct { + AccountRepository + account *Account +} + +func (r *accountTestLoggingRepo) GetByID(context.Context, int64) (*Account, error) { + if r.account == nil { + return nil, errors.New("missing") + } + return r.account, nil +} + +func TestAccountTestFailureLogAttribution(t *testing.T) { + gin.SetMode(gin.TestMode) + for _, background := range []bool{false, true} { + for _, missing := range []bool{false, true} { + core, logs := observer.New(zap.WarnLevel) + ctx := logger.IntoContext(context.Background(), zap.New(core).With(zap.String("request_id", "req-test"))) + repo := &accountTestLoggingRepo{} + if !missing { + repo.account = &Account{ID: 77, Platform: PlatformAnthropic, Type: AccountTypeAPIKey} + } + svc := &AccountTestService{accountRepo: repo} + if background { + result, err := svc.RunTestBackground(ctx, 77, "test-model") + require.NoError(t, err) + require.Equal(t, "failed", result.Status) + require.NotEmpty(t, result.ErrorMessage) + } else { + rec := httptest.NewRecorder() + c, _ := gin.CreateTestContext(rec) + c.Request = httptest.NewRequest("POST", "/accounts/77/test", nil).WithContext(ctx) + err := svc.TestAccountConnection(c, 77, "test-model", "private prompt", "") + require.Error(t, err) + require.Contains(t, rec.Body.String(), `"type":"error"`) + } + entries := logs.FilterMessage("account_test.failed").All() + require.Len(t, entries, 1) + fields := entries[0].ContextMap() + require.Equal(t, int64(77), fields["account_id"]) + require.Equal(t, "req-test", fields["request_id"]) + require.Equal(t, "test-model", fields["requested_model"]) + require.NotEmpty(t, fields["test_id"]) + if background { + require.Equal(t, "background", fields["test_source"]) + } else { + require.Equal(t, "http", fields["test_source"]) + } + if !missing { + require.Equal(t, PlatformAnthropic, fields["platform"]) + } + require.NotContains(t, fields, "prompt") + } + } +} + +func TestAccountTestErrorLogRedaction(t *testing.T) { + core, logs := observer.New(zap.WarnLevel) + c, _ := gin.CreateTestContext(httptest.NewRecorder()) + c.Request = httptest.NewRequest("POST", "/test", nil).WithContext(logger.IntoContext(context.Background(), zap.New(core))) + initAccountTestLogger(c, 1, "", "") + message := `API returned 403: {"api_key":"secret-key","access_token":"secret-token","message":"denied"}` + err := (&AccountTestService{}).sendErrorAndEnd(c, message) + require.EqualError(t, err, message) + entry := logs.FilterMessage("account_test.failed").All()[0] + logged, ok := entry.ContextMap()["error"].(string) + require.True(t, ok) + require.NotContains(t, logged, "secret-key") + require.NotContains(t, logged, "secret-token") + require.Contains(t, logged, "denied") + logAccountTestError(c, strings.Repeat("x", 10000)) + last, ok := logs.All()[1].ContextMap()["error"].(string) + require.True(t, ok) + require.Less(t, len(last), 2100) +} diff --git a/backend/internal/service/account_test_service.go b/backend/internal/service/account_test_service.go index 4da30d610b..8d7641c970 100644 --- a/backend/internal/service/account_test_service.go +++ b/backend/internal/service/account_test_service.go @@ -359,6 +359,7 @@ func createTestPayload(modelID string) (map[string]any, error) { // mode is optional - "compact" routes OpenAI accounts to the /responses/compact probe path // opts is optional media (image/audio data URLs for real generation / STT). func (s *AccountTestService) TestAccountConnection(c *gin.Context, accountID int64, modelID string, prompt string, mode string, opts ...AccountTestOptions) error { + initAccountTestLogger(c, accountID, modelID, mode) ctx := c.Request.Context() testOpts := firstAccountTestOptions(opts) @@ -367,6 +368,7 @@ func (s *AccountTestService) TestAccountConnection(c *gin.Context, accountID int if err != nil { return s.sendErrorAndEnd(c, "Account not found") } + bindAccountTestPlatform(c, account) // Synthetic UI load-test accounts exercise the real SSE parsing and modal // interactions, but intentionally do not send their placeholder credentials @@ -3271,7 +3273,7 @@ func (s *AccountTestService) sendEvent(c *gin.Context, event TestEvent) { // sendErrorAndEnd sends an error event and ends the stream func (s *AccountTestService) sendErrorAndEnd(c *gin.Context, errorMsg string) error { - log.Printf("Account test error: %s", errorMsg) + logAccountTestError(c, errorMsg) s.sendEvent(c, TestEvent{Type: "error", Error: errorMsg}) return fmt.Errorf("%s", errorMsg) } @@ -3284,6 +3286,7 @@ func (s *AccountTestService) RunTestBackground(ctx context.Context, accountID in w := httptest.NewRecorder() ginCtx, _ := gin.CreateTestContext(w) ginCtx.Request = (&http.Request{}).WithContext(ctx) + ginCtx.Set(accountTestBackgroundKey, true) testErr := s.TestAccountConnection(ginCtx, accountID, modelID, "", AccountTestModeDefault)