iop/apps/edge/internal/openai/provider_observability_test.go
toki 01dc2ef78b refactor: readability baseline 및 테스트 구조 개선
- agent-readable-repository-refactor 완료: 기존 테스트 파일 아카이브 이동
- 새 테스트 파일 추가 (edge, node, client, config, readability)
- readability_audit 스크립트 및 baseline 추가
- roadmap/SDD 문서 갱신
- agent-client/pi/extensions/openai-sampling-parameters 추가
2026-07-17 16:02:12 +09:00

405 lines
15 KiB
Go

package openai
import (
"net/http"
"net/http/httptest"
"strings"
"testing"
"go.uber.org/zap"
"go.uber.org/zap/zaptest/observer"
edgeservice "iop/apps/edge/internal/service"
"iop/packages/go/config"
iop "iop/proto/gen/iop"
)
func TestResponsesMetadataIncludesTypedEstimateAndClassification(t *testing.T) {
fake := &fakeRunService{events: make(chan *iop.RunEvent, 2)}
fake.events <- &iop.RunEvent{Type: "delta", Delta: "ok"}
fake.events <- &iop.RunEvent{Type: "complete"}
srv := NewServer(config.EdgeOpenAIConf{Adapter: "ollama"}, fake, nil)
req := httptest.NewRequest(http.MethodPost, "/v1/responses", strings.NewReader(`{
"model":"client-model",
"input":"test",
"metadata":{"request_id":"req-001"}
}`))
w := httptest.NewRecorder()
srv.routes().ServeHTTP(w, req)
if w.Code != http.StatusOK {
t.Fatalf("status: got %d body=%s", w.Code, w.Body.String())
}
estStr := fake.req.Metadata["estimated_input_tokens"]
if estStr == "" {
t.Fatalf("estimated_input_tokens should be present")
}
ctxClass := fake.req.Metadata["context_class"]
if ctxClass != "normal" {
t.Fatalf("context_class: got %q, want normal", ctxClass)
}
est := fake.req.EstimatedInputTokens
if est <= 0 {
t.Fatalf("EstimatedInputTokens: got %d", est)
}
if fake.req.ContextClass != "normal" {
t.Fatalf("ContextClass: got %q, want normal", fake.req.ContextClass)
}
}
func TestResponsesMetadataIncludesTypedEstimateAndClassification_LargePayload(t *testing.T) {
largeInput := make([]byte, 400000)
for i := range largeInput {
largeInput[i] = 'x'
}
fake := &fakeRunService{events: make(chan *iop.RunEvent, 2)}
fake.events <- &iop.RunEvent{Type: "delta", Delta: "ok"}
fake.events <- &iop.RunEvent{Type: "complete"}
srv := NewServer(config.EdgeOpenAIConf{Adapter: "ollama"}, fake, nil)
body := `{"model":"client-model","input":"` + string(largeInput) + `"}`
req := httptest.NewRequest(http.MethodPost, "/v1/responses", strings.NewReader(body))
w := httptest.NewRecorder()
srv.routes().ServeHTTP(w, req)
if w.Code != http.StatusOK {
t.Fatalf("status: got %d body=%s", w.Code, w.Body.String())
}
if fake.req.ContextClass != "long" {
t.Fatalf("context_class: got %q, want long", fake.req.ContextClass)
}
if fake.req.EstimatedInputTokens < 100000 {
t.Fatalf("EstimatedInputTokens: got %d, want >= 100000", fake.req.EstimatedInputTokens)
}
}
func TestChatCompletionsMetadataIncludesTypedEstimateAndClassification(t *testing.T) {
fake := &fakeRunService{events: make(chan *iop.RunEvent, 2)}
fake.events <- &iop.RunEvent{Type: "delta", Delta: "ok"}
fake.events <- &iop.RunEvent{Type: "complete"}
srv := NewServer(config.EdgeOpenAIConf{Adapter: "ollama"}, fake, nil)
req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader(`{
"model":"client-model",
"messages":[{"role":"user","content":"hi"}]
}`))
w := httptest.NewRecorder()
srv.handleChatCompletions(w, req)
if w.Code != http.StatusOK {
t.Fatalf("status: got %d body=%s", w.Code, w.Body.String())
}
estStr := fake.req.Metadata["estimated_input_tokens"]
if estStr == "" {
t.Fatalf("estimated_input_tokens should be present")
}
ctxClass := fake.req.Metadata["context_class"]
if ctxClass != "normal" {
t.Fatalf("context_class: got %q, want normal", ctxClass)
}
est := fake.req.EstimatedInputTokens
if est <= 0 {
t.Fatalf("EstimatedInputTokens: got %d", est)
}
if fake.req.ContextClass != "normal" {
t.Fatalf("ContextClass: got %q, want normal", fake.req.ContextClass)
}
}
func TestChatCompletionsAssembledLogs(t *testing.T) {
core, observed := observer.New(zap.DebugLevel)
logger := zap.New(core)
fake := &fakeRunService{events: make(chan *iop.RunEvent, 4)}
fake.events <- &iop.RunEvent{Type: "delta", Delta: "hello"}
fake.events <- &iop.RunEvent{Type: "reasoning_delta", Delta: "reasoning..."}
fake.events <- &iop.RunEvent{Type: "complete", Metadata: map[string]string{
"openai_tool_calls": `[{"id":"call_001","type":"function","function":{"name":"get_weather","arguments":"{}"}}]`,
}}
srv := NewServer(config.EdgeOpenAIConf{Adapter: "ollama"}, fake, logger)
req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader(`{
"model":"client-model",
"messages":[{"role":"user","content":"hi"}],
"tools":[{"type":"function","function":{"name":"get_weather"}}]
}`))
w := httptest.NewRecorder()
srv.handleChatCompletions(w, req)
found := false
for _, entry := range observed.All() {
if entry.Message == "openai chat completion output" {
found = true
m := entry.ContextMap()
if m["response_mode"] != "normalized" {
t.Errorf("expected response_mode=normalized, got %v", m["response_mode"])
}
if m["assembled_content"] != "hello" {
t.Errorf("expected assembled_content=hello, got %v", m["assembled_content"])
}
if m["assembled_reasoning"] != "reasoning..." {
t.Errorf("expected assembled_reasoning=reasoning..., got %v", m["assembled_reasoning"])
}
tc, ok := m["assembled_tool_calls"].([]interface{})
if !ok || len(tc) != 1 || tc[0] != "get_weather" {
t.Errorf("expected assembled_tool_calls=[get_weather], got %v", m["assembled_tool_calls"])
}
if count, ok := m["assembled_tool_call_count"].(int64); !ok || count != 1 {
t.Errorf("expected assembled_tool_call_count=1, got %v", m["assembled_tool_call_count"])
}
}
}
if !found {
t.Error("expected log message 'openai chat completion output' not found")
}
}
// TestChatCompletionsAssembledLogsNormalized verifies the normalized-path
// completion log reports the internal response_mode execution label
// (normalized) and the assembled observation fields.
func TestChatCompletionsAssembledLogsNormalized(t *testing.T) {
core, observed := observer.New(zap.DebugLevel)
logger := zap.New(core)
fake := &fakeRunService{events: make(chan *iop.RunEvent, 4)}
fake.events <- &iop.RunEvent{Type: "delta", Delta: "hello normalized"}
fake.events <- &iop.RunEvent{Type: "reasoning_delta", Delta: "reasoning normalized..."}
fake.events <- &iop.RunEvent{Type: "complete", Metadata: map[string]string{
"openai_tool_calls": `[{"id":"call_002","type":"function","function":{"name":"run_code","arguments":"{}"}}]`,
}}
srv := NewServer(config.EdgeOpenAIConf{Adapter: "ollama"}, fake, logger)
req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader(`{
"model":"client-model",
"messages":[{"role":"user","content":"hi"}],
"tools":[{"type":"function","function":{"name":"run_code"}}]
}`))
w := httptest.NewRecorder()
srv.handleChatCompletions(w, req)
found := false
for _, entry := range observed.All() {
if entry.Message == "openai chat completion output" {
found = true
m := entry.ContextMap()
if m["response_mode"] != "normalized" {
t.Errorf("expected response_mode=normalized, got %v", m["response_mode"])
}
if m["assembled_content"] != "hello normalized" {
t.Errorf("expected assembled_content=hello normalized, got %v", m["assembled_content"])
}
if m["assembled_reasoning"] != "reasoning normalized..." {
t.Errorf("expected assembled_reasoning=reasoning normalized..., got %v", m["assembled_reasoning"])
}
tc, ok := m["assembled_tool_calls"].([]interface{})
if !ok || len(tc) != 1 || tc[0] != "run_code" {
t.Errorf("expected assembled_tool_calls=[run_code], got %v", m["assembled_tool_calls"])
}
if count, ok := m["assembled_tool_call_count"].(int64); !ok || count != 1 {
t.Errorf("expected assembled_tool_call_count=1, got %v", m["assembled_tool_call_count"])
}
}
}
if !found {
t.Error("expected log message 'openai chat completion output' not found")
}
}
func TestChatCompletionsAssembledLogsPassthrough(t *testing.T) {
core, observed := observer.New(zap.DebugLevel)
logger := zap.New(core)
providerBody := `{"choices":[{"message":{"content":"passthrough content","reasoning_content":"passthrough reasoning","tool_calls":[{"function":{"name":"call_passthrough"}}]}}]}`
frames := make(chan *iop.ProviderTunnelFrame, 3)
frames <- &iop.ProviderTunnelFrame{Kind: iop.ProviderTunnelFrameKind_PROVIDER_TUNNEL_FRAME_KIND_RESPONSE_START, StatusCode: 200}
frames <- &iop.ProviderTunnelFrame{Kind: iop.ProviderTunnelFrameKind_PROVIDER_TUNNEL_FRAME_KIND_BODY, Body: []byte(providerBody)}
frames <- &iop.ProviderTunnelFrame{Kind: iop.ProviderTunnelFrameKind_PROVIDER_TUNNEL_FRAME_KIND_END, End: true}
close(frames)
fake := &providerFakeRunService{
tunnelFrames: frames,
}
catalog := []config.ModelCatalogEntry{
{ID: "pool-model", Providers: map[string]string{"prov-1": "served-model"}},
}
srv := NewServer(config.EdgeOpenAIConf{}, fake, logger)
srv.SetModelCatalog(catalog)
req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader(`{
"model":"pool-model",
"messages":[{"role":"user","content":"hello"}]
}`))
w := httptest.NewRecorder()
srv.handleChatCompletions(w, req)
found := false
for _, entry := range observed.All() {
if entry.Message == "openai chat completion passthrough closed" {
found = true
m := entry.ContextMap()
if m["assembled_content"] != "passthrough content" {
t.Errorf("expected assembled_content='passthrough content', got %v", m["assembled_content"])
}
if m["assembled_reasoning"] != "passthrough reasoning" {
t.Errorf("expected assembled_reasoning='passthrough reasoning', got %v", m["assembled_reasoning"])
}
tc, ok := m["assembled_tool_calls"].([]interface{})
if !ok || len(tc) != 1 || tc[0] != "call_passthrough" {
t.Errorf("expected assembled_tool_calls=[call_passthrough], got %v", m["assembled_tool_calls"])
}
if count, ok := m["assembled_tool_call_count"].(int64); !ok || count != 1 {
t.Errorf("expected assembled_tool_call_count=1, got %v", m["assembled_tool_call_count"])
}
}
}
if !found {
t.Error("expected log message 'openai chat completion passthrough closed' not found")
}
}
// TestProviderPoolDispatchLogObservationFields verifies that provider-pool
// dispatch logs carry provider_id, provider_type, execution_path, and
// queue_reason fields populated from the selected candidate (SURFACE_OBS-2).
func TestProviderPoolDispatchLogObservationFields(t *testing.T) {
core, observed := observer.New(zap.InfoLevel)
logger := zap.New(core)
const rawToken = "sk-pool-obs-token"
const edgeID = "edge-pool-obs-logs"
const model = "pool-obs-model"
// Build tunnel frames that complete successfully.
frames := staticProviderTunnelFrames(`{"choices":[{"message":{"role":"assistant","content":"ok"}}],"usage":{"prompt_tokens":4,"completion_tokens":3}}`)
fake := &providerFakeRunService{
poolDispatchPath: "provider_tunnel",
tunnelFrames: frames,
}
srv := NewServer(config.EdgeOpenAIConf{
PrincipalTokens: []config.OpenAIPrincipalTokenConf{
{TokenRef: "iop-tok-alice", TokenHashSHA256: sha256Hex(rawToken), PrincipalRef: "user:alice", PrincipalAlias: "alice"},
},
}, fake, logger)
srv.SetEdgeID(edgeID)
srv.SetModelCatalog([]config.ModelCatalogEntry{
{ID: model, Providers: map[string]string{"prov-obs": "served-obs"}},
})
req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader(`{
"model":"pool-obs-model",
"messages":[{"role":"user","content":"hello"}]
}`))
req.Header.Set("Authorization", "Bearer "+rawToken)
w := httptest.NewRecorder()
srv.routes().ServeHTTP(w, req)
if w.Code != http.StatusOK {
t.Fatalf("status: got %d body=%s", w.Code, w.Body.String())
}
// Verify the observer logger captured the dispatch log line with the
// expected provider observation fields. The structured log line from
// handleChatCompletionsProviderPool must carry provider_id, provider_type,
// execution_path, adapter, target, and queue_reason.
var found bool
for _, entry := range observed.All() {
if entry.Message != "openai chat completion provider-pool dispatch" {
continue
}
found = true
// Verify provider observation fields exist on the structured log.
if _, ok := entry.ContextMap()["provider_id"]; !ok {
t.Error("dispatch log missing provider_id field")
}
if _, ok := entry.ContextMap()["provider_type"]; !ok {
t.Error("dispatch log missing provider_type field")
}
if _, ok := entry.ContextMap()["execution_path"]; !ok {
t.Error("dispatch log missing execution_path field")
}
if _, ok := entry.ContextMap()["queue_reason"]; !ok {
t.Error("dispatch log missing queue_reason field")
}
if _, ok := entry.ContextMap()["adapter"]; !ok {
t.Error("dispatch log missing adapter field")
}
if _, ok := entry.ContextMap()["target"]; !ok {
t.Error("dispatch log missing target field")
}
}
if !found {
t.Fatal("expected provider-pool dispatch log line in observer")
}
}
// TestResponsesProviderPoolTunnelMetadataAndContextPropagation verifies that the
// provider-pool tunnel path preserves metadata, estimated_input_tokens, and
// context_class from the base request into the tunnel dispatch (SDD S02/S03).
func TestResponsesProviderPoolTunnelMetadataAndContextPropagation(t *testing.T) {
frames := make(chan *iop.ProviderTunnelFrame, 3)
frames <- &iop.ProviderTunnelFrame{Kind: iop.ProviderTunnelFrameKind_PROVIDER_TUNNEL_FRAME_KIND_RESPONSE_START, StatusCode: 200}
frames <- &iop.ProviderTunnelFrame{Kind: iop.ProviderTunnelFrameKind_PROVIDER_TUNNEL_FRAME_KIND_BODY, Body: []byte(`{"ok":true}`)}
frames <- &iop.ProviderTunnelFrame{Kind: iop.ProviderTunnelFrameKind_PROVIDER_TUNNEL_FRAME_KIND_END, End: true}
close(frames)
fake := &providerFakeRunService{
poolDispatchPath: string(edgeservice.ProviderPoolPathTunnel),
tunnelFrames: frames,
tunnelServedTarget: "served-model",
}
catalog := []config.ModelCatalogEntry{
{ID: "pool-model", Providers: map[string]string{"prov-1": "served-model"}},
}
srv := NewServer(config.EdgeOpenAIConf{}, fake, nil)
srv.SetModelCatalog(catalog)
req := httptest.NewRequest(http.MethodPost, "/v1/responses", strings.NewReader(`{
"model":"pool-model",
"input":"hello",
"metadata":{"experiment":"pool-test"}
}`))
w := httptest.NewRecorder()
srv.handleResponses(w, req)
if w.Code != http.StatusOK {
t.Fatalf("status: got %d body=%s", w.Code, w.Body.String())
}
tunnelReqs := fake.tunnelReqsSnapshot()
if len(tunnelReqs) != 1 {
t.Fatalf("expected one tunnel req, got %d", len(tunnelReqs))
}
tunnelReq := tunnelReqs[0]
// Metadata must contain the principal and pool-echoed fields.
if tunnelReq.Metadata == nil {
t.Fatalf("tunnel metadata must not be nil")
}
if tunnelReq.Metadata["openai_model"] == "" {
t.Error("openai_model missing from tunnel metadata")
}
if tunnelReq.Metadata["openai_stream"] == "" {
t.Error("openai_stream missing from tunnel metadata")
}
if tunnelReq.Metadata["estimated_input_tokens"] == "" {
t.Error("estimated_input_tokens missing from tunnel metadata")
}
if tunnelReq.Metadata["context_class"] == "" {
t.Error("context_class missing from tunnel metadata")
}
if tunnelReq.Metadata["experiment"] != "pool-test" {
t.Errorf("caller metadata lost: got %v", tunnelReq.Metadata)
}
// EstimatedInputTokens and ContextClass must be non-zero/non-empty on the
// tunnel request itself, so Node observability preserves the same values
// as the direct tunnel path.
if tunnelReq.EstimatedInputTokens <= 0 {
t.Errorf("EstimatedInputTokens must be > 0: got %d", tunnelReq.EstimatedInputTokens)
}
if tunnelReq.ContextClass == "" {
t.Error("ContextClass must be non-empty on tunnel request")
}
}