From 684008e3a5fc166bdd023e77540f0e1396553231 Mon Sep 17 00:00:00 2001 From: WeiCHEN Date: Tue, 22 Sep 2026 21:51:19 +0800 Subject: [PATCH] feat(trace): strengthen T2/T3 evidence and access-log design --- internal/config/config.go | 1 + internal/server/access_log_middleware.go | 82 ++++++++++++ internal/server/access_log_middleware_test.go | 89 +++++++++++++ internal/server/server.go | 2 +- internal/server/trace_handlers.go | 14 +- internal/traceimpact/pg_store.go | 20 +++ internal/traceimpact/service.go | 96 ++++++++++++++ internal/traceimpact/service_test.go | 123 ++++++++++++++++++ internal/traceimpact/store.go | 13 ++ 9 files changed, 435 insertions(+), 5 deletions(-) create mode 100644 internal/server/access_log_middleware.go create mode 100644 internal/server/access_log_middleware_test.go diff --git a/internal/config/config.go b/internal/config/config.go index 98b9d548..aece3cf5 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -84,6 +84,7 @@ type Config struct { VaultMasterKey string `json:"vault_master_key"` FAVDegradedRead bool `json:"fav_degraded_read"` // FAV_DEGRADED_READ; default false FAVPublisherEnabled bool `json:"fav_publisher_enabled"` // FAV_PUBLISHER_ENABLED; default false + HTTPAccessLogEnabled bool `json:"http_access_log_enabled"` // HTTP_ACCESS_LOG; default on for dev/test } func Load(path string) (*Config, error) { diff --git a/internal/server/access_log_middleware.go b/internal/server/access_log_middleware.go new file mode 100644 index 00000000..8c128fc9 --- /dev/null +++ b/internal/server/access_log_middleware.go @@ -0,0 +1,82 @@ +package server + +import ( + "log/slog" + "net/http" + "strings" + "time" + + "chat-agent-system/internal/httpx" +) + +// accessLogMiddleware emits one structured line per HTTP request when enabled. +// It never logs bodies, Authorization, Cookie, or raw query strings. +func (s *Server) accessLogMiddleware(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + if s == nil || s.cfg == nil || !s.cfg.HTTPAccessLogEnabled { + next.ServeHTTP(w, r) + return + } + started := time.Now() + requestID := httpx.RequestID(r) + w.Header().Set(httpx.HeaderRequestID, requestID) + rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} + next.ServeHTTP(rec, r) + slog.Info("http_access", + "method", r.Method, + "path", accessLogPath(r.URL.Path), + "status", rec.status, + "duration_ms", time.Since(started).Milliseconds(), + "request_id", requestID, + ) + }) +} + +type statusRecorder struct { + http.ResponseWriter + status int + wroteHeader bool +} + +func (r *statusRecorder) WriteHeader(code int) { + if r.wroteHeader { + return + } + r.wroteHeader = true + r.status = code + r.ResponseWriter.WriteHeader(code) +} + +func (r *statusRecorder) Write(b []byte) (int, error) { + if !r.wroteHeader { + r.WriteHeader(http.StatusOK) + } + return r.ResponseWriter.Write(b) +} + +// accessLogPath keeps only the URL path. Query strings are dropped so tokens +// and secrets in ?access_token=… never reach the log line. +func accessLogPath(path string) string { + path = strings.TrimSpace(path) + if path == "" { + return "/" + } + if i := strings.IndexByte(path, '?'); i >= 0 { + path = path[:i] + } + if i := strings.IndexByte(path, '#'); i >= 0 { + path = path[:i] + } + return path +} + +// accessLogSafeMessage is used by tests to assert the middleware contract. +func accessLogSafeMessage(method, path string, status int, durationMs int64, requestID string) map[string]any { + return map[string]any{ + "method": method, + "path": accessLogPath(path), + "status": status, + "duration_ms": durationMs, + "request_id": requestID, + } +} diff --git a/internal/server/access_log_middleware_test.go b/internal/server/access_log_middleware_test.go new file mode 100644 index 00000000..81f93fc5 --- /dev/null +++ b/internal/server/access_log_middleware_test.go @@ -0,0 +1,89 @@ +package server + +import ( + "bytes" + "log/slog" + "net/http" + "net/http/httptest" + "strings" + "testing" + + "chat-agent-system/internal/config" +) + +func TestAccessLogPath_DropsQueryAndFragment(t *testing.T) { + got := accessLogPath("/api/v1/chat?token=secret&q=1#frag") + if got != "/api/v1/chat" { + t.Fatalf("path=%q", got) + } + msg := accessLogSafeMessage("GET", "/x?password=p", 200, 3, "req_1") + blob := strings.ToLower(strings.Join([]string{ + msg["method"].(string), + msg["path"].(string), + msg["request_id"].(string), + }, " ")) + for _, leak := range []string{"password", "token", "secret", "bearer", "authorization"} { + if strings.Contains(blob, leak) { + t.Fatalf("leak %q in %#v", leak, msg) + } + } +} + +func TestAccessLogMiddleware_EmitsSafeFieldsOnly(t *testing.T) { + var buf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))) + t.Cleanup(func() { slog.SetDefault(prev) }) + + srv := &Server{cfg: &config.Config{HTTPAccessLogEnabled: true}} + inner := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Authorization", "Bearer should-not-log") + w.WriteHeader(http.StatusCreated) + _, _ = w.Write([]byte(`{"password":"nope","prompt":"secret text"}`)) + }) + handler := srv.accessLogMiddleware(inner) + req := httptest.NewRequest(http.MethodPost, "/api/v1/login?access_token=leak", strings.NewReader(`{"password":"x"}`)) + req.Header.Set("Authorization", "Bearer super-secret") + req.Header.Set("Cookie", "session=abc") + req.Header.Set("X-Request-ID", "req_test_access") + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, req) + if rec.Code != http.StatusCreated { + t.Fatalf("status=%d", rec.Code) + } + line := buf.String() + if !strings.Contains(line, `"msg":"http_access"`) && !strings.Contains(line, `"http_access"`) { + t.Fatalf("missing http_access log: %s", line) + } + if !strings.Contains(line, `"path":"/api/v1/login"`) { + t.Fatalf("expected redacted path, got %s", line) + } + if !strings.Contains(line, `"status":201`) { + t.Fatalf("expected status, got %s", line) + } + if !strings.Contains(line, "req_test_access") { + t.Fatalf("expected request_id, got %s", line) + } + low := strings.ToLower(line) + for _, leak := range []string{"super-secret", "access_token=leak", "password", "bearer super", "session=abc", "secret text"} { + if strings.Contains(low, leak) { + t.Fatalf("log leaked %q: %s", leak, line) + } + } +} + +func TestAccessLogMiddleware_DisabledIsNoOp(t *testing.T) { + var buf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))) + t.Cleanup(func() { slog.SetDefault(prev) }) + + srv := &Server{cfg: &config.Config{HTTPAccessLogEnabled: false}} + handler := srv.accessLogMiddleware(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusNoContent) + })) + handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest(http.MethodGet, "/health", nil)) + if strings.Contains(buf.String(), "http_access") { + t.Fatalf("disabled middleware must not log: %s", buf.String()) + } +} diff --git a/internal/server/server.go b/internal/server/server.go index e49b3584..e9ec2ea2 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -351,7 +351,7 @@ func (s *Server) Routes() http.Handler { // 10. 现代 SPA 前端页面与静态资产托管 mux.HandleFunc("GET /", s.serveSPA) - return s.corsMiddleware(s.bodyLimitMiddleware(s.authMiddleware(mux))) + return s.corsMiddleware(s.accessLogMiddleware(s.bodyLimitMiddleware(s.authMiddleware(mux)))) } // Start 启动 HTTP 守护进程 diff --git a/internal/server/trace_handlers.go b/internal/server/trace_handlers.go index ecda0b2e..67d9f7a6 100644 --- a/internal/server/trace_handlers.go +++ b/internal/server/trace_handlers.go @@ -33,11 +33,17 @@ func (s *Server) handleProjectTrace(w http.ResponseWriter, r *http.Request) { writeSafeError(w, r, http.StatusInternalServerError, `{"error":"ERR_INTERNAL","message":"`+err.Error()+`"}`) return } + candidates, err := s.rt.Trace.ListCandidateEdges(r.Context(), projectID) + if err != nil { + writeSafeError(w, r, http.StatusInternalServerError, `{"error":"ERR_INTERNAL","message":"`+err.Error()+`"}`) + return + } writeJSONResponse(w, http.StatusOK, map[string]any{ - "items": visible, - "hidden_count": hidden, - "index": index, - "recheck_marks": marks, + "items": visible, + "hidden_count": hidden, + "index": index, + "recheck_marks": marks, + "candidate_edges": candidates, }) } diff --git a/internal/traceimpact/pg_store.go b/internal/traceimpact/pg_store.go index 3937f72c..654517d3 100644 --- a/internal/traceimpact/pg_store.go +++ b/internal/traceimpact/pg_store.go @@ -178,6 +178,26 @@ func (p *pgStore) AddDecision(ctx context.Context, d Decision) (Decision, error) return d, err } +func (p *pgStore) ListDecisions(ctx context.Context, projectID int64) ([]Decision, error) { + rows, err := p.pool.Query(ctx, ` + SELECT id, project_id, edge_id, decision, reason, decided_by + FROM project_trace_edge_decisions WHERE project_id = $1 ORDER BY id + `, projectID) + if err != nil { + return nil, err + } + defer rows.Close() + var out []Decision + for rows.Next() { + var d Decision + if err := rows.Scan(&d.ID, &d.ProjectID, &d.EdgeID, &d.Decision, &d.Reason, &d.DecidedBy); err != nil { + return nil, err + } + out = append(out, d) + } + return out, rows.Err() +} + func (p *pgStore) PutReopen(ctx context.Context, req ReopenRequest) (ReopenRequest, error) { if req.ID == 0 { err := p.pool.QueryRow(ctx, ` diff --git a/internal/traceimpact/service.go b/internal/traceimpact/service.go index eee97e04..c97f8ff3 100644 --- a/internal/traceimpact/service.go +++ b/internal/traceimpact/service.go @@ -303,6 +303,102 @@ func (s *Service) DecideCandidate(ctx context.Context, edgeID, actorID int64, cr return err } +// UpsertModelCandidate stores a model_candidate edge that stays out of confirmed walks until decided. +func (s *Service) UpsertModelCandidate(ctx context.Context, projectID int64, fromKey, toKey, evidenceDoc string) (Edge, error) { + if projectID <= 0 || fromKey == "" || toKey == "" { + return Edge{}, fmt.Errorf("traceimpact: project and both keys are required") + } + items, err := s.store.ListItems(ctx, projectID) + if err != nil { + return Edge{}, err + } + var from, to Item + for _, it := range items { + if it.BusinessKey == fromKey { + from = it + } + if it.BusinessKey == toKey { + to = it + } + } + if from.ID == 0 || to.ID == 0 { + return Edge{}, fmt.Errorf("traceimpact: both items must already be indexed") + } + return s.store.UpsertEdge(ctx, Edge{ + ProjectID: projectID, FromItemID: from.ID, ToItemID: to.ID, + RelationType: RelationDependsOn, Provenance: ProvenanceModel, + ReviewState: ReviewCandidate, EvidenceDoc: evidenceDoc, + FromKey: from.BusinessKey, ToKey: to.BusinessKey, + }) +} + +// ListCandidateEdges returns undecided candidate edges with business keys filled in. +func (s *Service) ListCandidateEdges(ctx context.Context, projectID int64) ([]Edge, error) { + edges, err := s.store.ListEdges(ctx, projectID) + if err != nil { + return nil, err + } + items, err := s.store.ListItems(ctx, projectID) + if err != nil { + return nil, err + } + byID := map[int64]Item{} + for _, it := range items { + byID[it.ID] = it + } + var out []Edge + for _, e := range edges { + if e.ReviewState != ReviewCandidate { + continue + } + if e.FromKey == "" { + e.FromKey = byID[e.FromItemID].BusinessKey + } + if e.ToKey == "" { + e.ToKey = byID[e.ToItemID].BusinessKey + } + out = append(out, e) + } + if out == nil { + out = []Edge{} + } + return out, nil +} + +// ReplayDecisions re-applies the decision ledger onto edge review_state. +// Latest decision per edge wins. Repair rebuilds must call this so rejected +// candidates cannot re-enter confirmed walks. +func (s *Service) ReplayDecisions(ctx context.Context, projectID int64) (applied int, err error) { + decisions, err := s.store.ListDecisions(ctx, projectID) + if err != nil { + return 0, err + } + latest := map[int64]Decision{} + for _, d := range decisions { + latest[d.EdgeID] = d + } + for edgeID, d := range latest { + review := ReviewConfirmed + if d.Decision == DecisionReject { + review = ReviewRejected + } + if err := s.store.SetEdgeReview(ctx, edgeID, review); err != nil { + return applied, err + } + applied++ + } + return applied, nil +} + +// ListDecisions returns the authoritative decision ledger for a project. +func (s *Service) ListDecisions(ctx context.Context, projectID int64) ([]Decision, error) { + out, err := s.store.ListDecisions(ctx, projectID) + if err == nil && out == nil { + out = []Decision{} + } + return out, err +} + // NeedsRecheckAck is true when the stage still has an open mark. // Acknowledgement does not clear the mark. func (s *Service) NeedsRecheckAck(ctx context.Context, projectID int64, stageKey string) (bool, error) { diff --git a/internal/traceimpact/service_test.go b/internal/traceimpact/service_test.go index 3157dd35..9ce9ec49 100644 --- a/internal/traceimpact/service_test.go +++ b/internal/traceimpact/service_test.go @@ -246,3 +246,126 @@ func TestPropose_UnconfirmedDoesNotStore(t *testing.T) { t.Fatal(err) } } + +func TestReplayDecisions_RejectSurvivesProjectionReset(t *testing.T) { + svc := NewMemoryService() + ctx := t.Context() + if _, err := svc.IndexDocument(ctx, 7, DocRef{DocID: "up", Markdown: "UR-001 用户需要记录"}); err != nil { + t.Fatal(err) + } + if _, err := svc.IndexDocument(ctx, 7, DocRef{DocID: "down", Markdown: "RS-010 细化需求"}); err != nil { + t.Fatal(err) + } + edge, err := svc.UpsertModelCandidate(ctx, 7, "RS-010", "UR-001", "down") + if err != nil { + t.Fatal(err) + } + if err := svc.DecideCandidate(ctx, edge.ID, 9, false, "down", 9, DecisionReject, "误匹配"); err != nil { + t.Fatal(err) + } + if err := svc.store.SetEdgeReview(ctx, edge.ID, ReviewCandidate); err != nil { + t.Fatal(err) + } + got, err := svc.store.GetEdge(ctx, edge.ID) + if err != nil || got.ReviewState != ReviewCandidate { + t.Fatalf("reset failed: %+v err=%v", got, err) + } + n, err := svc.ReplayDecisions(ctx, 7) + if err != nil || n != 1 { + t.Fatalf("replay applied=%d err=%v", n, err) + } + got, err = svc.store.GetEdge(ctx, edge.ID) + if err != nil || got.ReviewState != ReviewRejected { + t.Fatalf("after replay %+v err=%v", got, err) + } + hits, _ := WalkReverse([]Edge{got}, []int64{got.ToItemID}, 3, 50) + for _, h := range hits { + if h.ItemID == got.FromItemID { + t.Fatal("rejected edge must not be walked") + } + } +} + +func TestAnalyze_BoundedMultiHopDepth3(t *testing.T) { + svc := NewMemoryService() + ctx := t.Context() + docs := []struct { + id, md string + }{ + {"d1", "UR-001 根需求"}, + {"d2", "RS-002 细化 UR-001"}, + {"d3", "REQ-003 依赖 RS-002"}, + {"d4", "TC-004 验证 REQ-003"}, + {"d5", "TC-005 验证 TC-004"}, + } + for _, d := range docs { + if _, err := svc.IndexDocument(ctx, 3, DocRef{DocID: d.id, Markdown: d.md}); err != nil { + t.Fatal(err) + } + } + // IndexDocument only confirms same-line pairs. d5→d4 is not same-line with UR, so chain + // depth-4 must be explicit confirmed edges built for the walk. + items, err := svc.ListItems(ctx, 3) + if err != nil { + t.Fatal(err) + } + byKey := map[string]Item{} + for _, it := range items { + byKey[it.BusinessKey] = it + } + chain := [][2]string{{"RS-002", "UR-001"}, {"REQ-003", "RS-002"}, {"TC-004", "REQ-003"}, {"TC-005", "TC-004"}} + for _, pair := range chain { + if _, err := svc.store.UpsertEdge(ctx, Edge{ + ProjectID: 3, FromItemID: byKey[pair[0]].ID, ToItemID: byKey[pair[1]].ID, + RelationType: RelationDependsOn, Provenance: ProvenanceExplicit, ReviewState: ReviewConfirmed, + FromKey: pair[0], ToKey: pair[1], + }); err != nil { + t.Fatal(err) + } + } + rep, err := svc.Analyze(ctx, 3, DocRef{DocID: "d1", Markdown: "UR-001 根需求变更"}, []DocRef{ + {DocID: "d2", Visible: true}, {DocID: "d3", Visible: true}, + {DocID: "d4", Visible: true}, {DocID: "d5", Visible: true}, + }) + if err != nil { + t.Fatal(err) + } + depths := map[string]int{} + for _, imp := range rep.Impacts { + if imp.ImpactType == ImpactConfirmed { + depths[imp.ItemKey] = imp.Depth + } + } + if depths["RS-002"] != 1 || depths["REQ-003"] != 2 || depths["TC-004"] != 3 { + t.Fatalf("expected depth 1..3, got %#v impacts=%#v", depths, rep.Impacts) + } + if _, ok := depths["TC-005"]; ok { + t.Fatalf("depth-4 TC-005 must not appear in confirmed impacts: %#v", depths) + } +} + +func TestListCandidateEdges_OnlyUndecided(t *testing.T) { + svc := NewMemoryService() + ctx := t.Context() + if _, err := svc.IndexDocument(ctx, 1, DocRef{DocID: "a", Markdown: "UR-001 x"}); err != nil { + t.Fatal(err) + } + if _, err := svc.IndexDocument(ctx, 1, DocRef{DocID: "b", Markdown: "RS-002 y"}); err != nil { + t.Fatal(err) + } + edge, err := svc.UpsertModelCandidate(ctx, 1, "RS-002", "UR-001", "b") + if err != nil { + t.Fatal(err) + } + cands, err := svc.ListCandidateEdges(ctx, 1) + if err != nil || len(cands) != 1 || cands[0].FromKey != "RS-002" { + t.Fatalf("cands=%#v err=%v", cands, err) + } + if err := svc.DecideCandidate(ctx, edge.ID, 1, true, "b", 0, DecisionConfirm, "ok"); err != nil { + t.Fatal(err) + } + cands, err = svc.ListCandidateEdges(ctx, 1) + if err != nil || len(cands) != 0 { + t.Fatalf("after confirm cands=%#v err=%v", cands, err) + } +} diff --git a/internal/traceimpact/store.go b/internal/traceimpact/store.go index 183d3150..b28ef2bb 100644 --- a/internal/traceimpact/store.go +++ b/internal/traceimpact/store.go @@ -17,6 +17,7 @@ type Store interface { ListIndex(ctx context.Context, projectID int64) ([]IndexState, error) SetEdgeReview(ctx context.Context, edgeID int64, review string) error AddDecision(ctx context.Context, d Decision) (Decision, error) + ListDecisions(ctx context.Context, projectID int64) ([]Decision, error) PutReopen(ctx context.Context, req ReopenRequest) (ReopenRequest, error) GetReopen(ctx context.Context, id int64) (ReopenRequest, error) PutMark(ctx context.Context, m RecheckMark) (RecheckMark, error) @@ -195,6 +196,18 @@ func (m *memStore) AddDecision(_ context.Context, d Decision) (Decision, error) return d, nil } +func (m *memStore) ListDecisions(_ context.Context, projectID int64) ([]Decision, error) { + m.mu.Lock() + defer m.mu.Unlock() + var out []Decision + for _, d := range m.decisions { + if d.ProjectID == projectID { + out = append(out, d) + } + } + return out, nil +} + func (m *memStore) PutReopen(_ context.Context, req ReopenRequest) (ReopenRequest, error) { m.mu.Lock() defer m.mu.Unlock()