diff --git a/visionA-backend/internal/api/devices.go b/visionA-backend/internal/api/devices.go index c8aabe6..0c1c318 100644 --- a/visionA-backend/internal/api/devices.go +++ b/visionA-backend/internal/api/devices.go @@ -13,6 +13,7 @@ package api import ( "context" "errors" + "log/slog" "net/http" "time" @@ -109,8 +110,13 @@ func devicesListHandler(deps Deps) gin.HandlerFunc { return } - // 查 tunnel 狀態(雛形:列全部 session 找當前 user 的;為空不致命) - tunnelAlive, lastSeen := resolveTunnelStatus(ctx, deps.SessionStore, userID) + // 查 tunnel 狀態(雛形:列全部 session 找當前 user 的;為空不致命)。 + // 用獨立 ctx(源自 request context)給 tunnel 判定完整 3s 預算,避免前面 DeviceRepo.List + // 吃掉共用 ctx 的時間導致 store.List 逾時被靜默判離線(R-3 離線誤判)。 + tunnelCtx, tunnelCancel := context.WithTimeout(c.Request.Context(), 3*time.Second) + defer tunnelCancel() + tunnelAlive, lastSeen := resolveTunnelStatus( + tunnelCtx, deps.SessionStore, userID, deps.Logger, "list", RequestIDFrom(c)) out := make([]DeviceListItem, 0, len(devices)) for _, d := range devices { @@ -194,7 +200,15 @@ func devicesGetHandler(deps Deps) gin.HandlerFunc { return } - tunnelAlive, lastSeen := resolveTunnelStatus(ctx, deps.SessionStore, userID) + // R-3 離線誤判修復(見 .autoflow/05-implementation/r3-offline-misjudge-rootcause.md): + // detail 過去用同一個 2s ctx 先跑 DeviceRepo.Get 再跑 resolveTunnelStatus,前面的 DB + // 呼叫吃掉時間後,打 relay 的 store.List 常逾時被靜默判離線,導致前端 fallback 到恆 + // offline 的 DB 靜態值、R-3 誤擋上傳。改用獨立 ctx(源自 request context)給 tunnel + // 判定完整 3s 預算,與 list endpoint 對齊。2s 對打 relay 的 HTTP 本來就偏緊。 + tunnelCtx, tunnelCancel := context.WithTimeout(c.Request.Context(), 3*time.Second) + defer tunnelCancel() + tunnelAlive, lastSeen := resolveTunnelStatus( + tunnelCtx, deps.SessionStore, userID, deps.Logger, "detail", RequestIDFrom(c)) item := DeviceListItem{ ID: d.ID, Name: d.Name, @@ -339,19 +353,55 @@ func devicesUnpairHandler(deps Deps) gin.HandlerFunc { // Phase 0.7 security audit M2:寬鬆比對暫保留待人工介入。 // 詳細理由見 pickActiveSessionToken 註解:relay 端 LocalHandle.Summary 不帶 UserID。 // 修復 caller (handler) 已先做 strict UserContext 檢查,userID 必非空。 -func resolveTunnelStatus(ctx context.Context, store session.Store, userID string) (bool, time.Time) { +// +// 可觀測性(R-3 離線誤判排查,見 .autoflow/05-implementation/r3-offline-misjudge-rootcause.md): +// list 與 detail 都呼叫此函式,但 detail 曾用較緊的 ctx timeout 導致 store.List 逾時被靜默 +// 判離線。加 log 以在 stage 重現時分辨兩個嫌疑: +// - 嫌疑 1:store.List 回 err(尤其 context deadline exceeded)→ 逾時判離線。 +// - 嫌疑 2:拿到 summaries 但沒有一筆命中 userID → 比對不中判離線。 +// +// endpoint 參數("list" / "detail")標明呼叫來源,log 不帶 token 等敏感資訊。 +func resolveTunnelStatus( + ctx context.Context, + store session.Store, + userID string, + logger *slog.Logger, + endpoint string, + requestID string, +) (bool, time.Time) { if store == nil || userID == "" { return false, time.Time{} } + log := logOrDefault(logger) summaries, err := store.List(ctx) if err != nil { + // 嫌疑 1:List 逾時 / 報錯 → 靜默判離線(fail-safe,語意保留)。 + // deadline 標記讓 stage log 能一眼分辨「ctx 逾時」vs「relay 其他錯誤」。 + log.Warn("devices: resolveTunnelStatus store.List failed, treating tunnel as offline", + "endpoint", endpoint, + "user_id", userID, + "deadline_exceeded", errors.Is(err, context.DeadlineExceeded), + "error", err.Error(), + "request_id", requestID) return false, time.Time{} } for _, s := range summaries { // 寬鬆比對:暫接受 s.UserID == "" 直到 relay 端 backfill UserID(M2 待人工介入)。 if s.UserID == "" || s.UserID == userID { + log.Debug("devices: resolveTunnelStatus matched session, tunnel online", + "endpoint", endpoint, + "user_id", userID, + "session_user_id_empty", s.UserID == "", + "summaries_count", len(summaries), + "request_id", requestID) return true, s.LastHeartbeat } } + // 嫌疑 2:拿到 list 但沒有一筆命中 → 比對不中判離線。 + log.Debug("devices: resolveTunnelStatus no matching session, tunnel offline", + "endpoint", endpoint, + "user_id", userID, + "summaries_count", len(summaries), + "request_id", requestID) return false, time.Time{} } diff --git a/visionA-backend/internal/api/devices_test.go b/visionA-backend/internal/api/devices_test.go index fcc0e15..05d4156 100644 --- a/visionA-backend/internal/api/devices_test.go +++ b/visionA-backend/internal/api/devices_test.go @@ -13,6 +13,7 @@ import ( "github.com/stretchr/testify/require" "visiona-backend/internal/device" + "visiona-backend/internal/session" ) // newDevicesFixture 建立 router 並塞好必要依賴(InMemory repo + fakeSessionStore)。 @@ -114,3 +115,78 @@ func TestDevicesGet_NotFound(t *testing.T) { r.ServeHTTP(w, httptest.NewRequest(http.MethodGet, "/api/devices/ghost", nil)) assert.Equal(t, http.StatusNotFound, w.Code) } + +// deadlineRecordingStore 記錄 List 收到的 ctx 剩餘 deadline,並回一筆命中 session。 +// 用來驗證 detail handler 給 resolveTunnelStatus 的 ctx 有足夠預算(≥3s,非被前面 +// DB 呼叫吃掉的殘餘)。 +type deadlineRecordingStore struct { + fakeSessionStore + gotRemaining time.Duration + hasDeadline bool +} + +func (s *deadlineRecordingStore) List(ctx context.Context) ([]*session.Summary, error) { + if dl, ok := ctx.Deadline(); ok { + s.hasDeadline = true + s.gotRemaining = time.Until(dl) + } + return []*session.Summary{ + {UserID: "demo-user", LastHeartbeat: time.Now().UTC()}, + }, nil +} + +// TestDevicesGet_TunnelCtxHasFullBudget 驗證 R-3 離線誤判修復: +// detail endpoint 給 tunnel 判定的 ctx 有完整 3s 預算(獨立於前面的 DeviceRepo.Get), +// 且能正確回 tunnel_online=true。修復前 detail 用同一個 2s ctx,前面的 DB 呼叫吃掉時間後 +// 打 relay 的 store.List 常逾時被靜默判離線。 +func TestDevicesGet_TunnelCtxHasFullBudget(t *testing.T) { + repo := device.NewInMemoryRepository() + require.NoError(t, repo.Save(context.Background(), &device.Device{ + ID: "mine", OwnerUserID: "demo-user", Name: "kl520", DeviceType: "kl520", + })) + + store := &deadlineRecordingStore{} + r := gin.New() + r.Use(RequestIDMiddleware()) + r.Use(injectStaticUserContext("demo-user", "")) + g := r.Group("/api") + registerDeviceRoutes(g, Deps{ + DeviceRepo: repo, + SessionStore: store, + }) + + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(http.MethodGet, "/api/devices/mine", nil)) + require.Equal(t, http.StatusOK, w.Code) + + var sb SuccessBody + require.NoError(t, json.Unmarshal(w.Body.Bytes(), &sb)) + item := sb.Data.(map[string]any) + assert.Equal(t, true, item["tunnel_online"], "命中 session 應判 tunnel_online=true") + + // 核心斷言:tunnel 判定拿到的 ctx 剩餘預算應接近完整 3s(獨立 ctx), + // 而非修復前殘餘的 <2s。給寬鬆下界 2.5s 容忍測試機排程抖動。 + require.True(t, store.hasDeadline, "tunnel ctx 應有 deadline") + assert.Greater(t, store.gotRemaining, 2500*time.Millisecond, + "tunnel 判定應拿到近乎完整的 3s 預算,不被前面 DeviceRepo.Get 吃掉") +} + +// TestResolveTunnelStatus_ListTimeoutTreatedOffline 驗證嫌疑 1 語意保留: +// store.List 逾時(context deadline exceeded)→ 靜默判離線(fail-safe 不變)。 +func TestResolveTunnelStatus_ListTimeoutTreatedOffline(t *testing.T) { + store := &fakeSessionStore{listErr: context.DeadlineExceeded} + alive, _ := resolveTunnelStatus( + context.Background(), store, "demo-user", nil, "detail", "test-req") + assert.False(t, alive, "List 逾時應判離線(fail-safe 語意保留)") +} + +// TestResolveTunnelStatus_NoMatchTreatedOffline 驗證嫌疑 2 語意: +// 拿到 list 但沒有一筆命中 userID → 判離線。 +func TestResolveTunnelStatus_NoMatchTreatedOffline(t *testing.T) { + store := &fakeSessionStore{sessions: []*session.Summary{ + {UserID: "someone-else", LastHeartbeat: time.Now().UTC()}, + }} + alive, _ := resolveTunnelStatus( + context.Background(), store, "demo-user", nil, "detail", "test-req") + assert.False(t, alive, "無命中 session 應判離線") +}