diff --git a/gateway/qualification_contract_test.go b/gateway/qualification_contract_test.go index 26495c0..6a20af1 100644 --- a/gateway/qualification_contract_test.go +++ b/gateway/qualification_contract_test.go @@ -6,11 +6,13 @@ import ( "context" "encoding/binary" "errors" + "fmt" "io" "net" "os" "path/filepath" "reflect" + "runtime" "strconv" "strings" "testing" @@ -121,10 +123,10 @@ func TestQualificationApolloFixturePacesSourceShapedVideo(t *testing.T) { }() started = time.Now() - if err := fixture.sendVideo(context.Background(), packets); err != nil { + if err := fixture.sendVideo(context.Background(), 1, packets); err != nil { t.Fatal(err) } - if err := fixture.sendVideo(context.Background(), packets[:1]); err != nil { + if err := fixture.sendVideo(context.Background(), 2, packets[:1]); err != nil { t.Fatal(err) } elapsed := time.Since(started) @@ -154,7 +156,7 @@ func TestQualificationApolloFixturePacesSourceShapedVideo(t *testing.T) { beforeCancel := fixture.sentPackets.Load() cancelled, cancel := context.WithCancel(context.Background()) cancel() - if err := fixture.sendVideo(cancelled, packets[:1]); !errors.Is(err, context.Canceled) { + if err := fixture.sendVideo(cancelled, 3, packets[:1]); !errors.Is(err, context.Canceled) { t.Fatalf("cancelled pacing wait returned %v, want context.Canceled", err) } if fixture.sentPackets.Load() != beforeCancel { @@ -690,3 +692,200 @@ func TestQualificationCarriesCompleteLargeFramesThroughPublicPath(t *testing.T) } } } + +func TestQualificationLateSourceBatchDoesNotCollapseThroughPublicPath(t *testing.T) { + profile := qualificationMediaProfiles()[2] + path := newQualificationPath(t, profile, profile.BitrateKbps) + defer path.Close() + + const shardCount = 662 + payload := qualificationFramePayload(profile, 0) + if len(payload) != 666_664 { + t.Fatalf("4K60 keyframe bytes = %d, want 666664", len(payload)) + } + packets := qualificationSourceVideoPackets(t, path.key, 1, payload) + if len(packets) != shardCount { + t.Fatalf("source packet count = %d, want %d", len(packets), shardCount) + } + + var batchIndices []int + var batchStarts []time.Time + var firstBatch time.Time + path.fixture.observeVideoBatch = func(index int, at time.Time) { + if firstBatch.IsZero() { + firstBatch = at + } + batchIndices = append(batchIndices, index) + batchStarts = append(batchStarts, at) + } + stalled := false + path.fixture.beforeVideoBatch = func(ctx context.Context, index int) error { + if index != 63 || stalled { + return nil + } + stalled = true + return qualificationWaitContext(ctx, firstBatch.Add(5*time.Millisecond)) + } + + trace, _, err := path.traverse(t, payload) + if err != nil { + t.Fatal(err) + } + if !trace.NativeSetup || !trace.NativeOpen || !trace.NativeUDPIngress || !trace.ApolloRecovered || + !trace.ProductionQueue || !trace.ProductionMediaLoop || !trace.ProductionPacer || + !trace.VerseQUIC || !trace.PublicClientDecode || !trace.PayloadPreserved { + t.Fatalf("late-batch path skipped production stages: %#v", trace) + } + if got := path.sourceUDP.Load(); got != shardCount { + t.Fatalf("source UDP count = %d, want %d", got, shardCount) + } + if len(batchStarts) != (shardCount+62)/63 { + t.Fatalf("batch count = %d, want %d", len(batchStarts), (shardCount+62)/63) + } + packetsPerMillisecond, _ := qualificationApolloVideoPacing(apolloVideoRawPacketSize) + for index := 1; index < len(batchStarts); index++ { + previousPackets := min(63, shardCount-batchIndices[index-1]) + minimum := qualificationApolloVideoOffset(previousPackets, packetsPerMillisecond) + actual := batchStarts[index].Sub(batchStarts[index-1]) + if actual < minimum { + t.Fatalf("batch %d at packet %d started %s after packet %d, before raw serialization interval %s; starts=%v", + index, batchIndices[index], actual, batchIndices[index-1], minimum, batchStarts) + } + } + t.Logf("late-batch public path: packets=%d starts=%v ingress=%d recovered=%d enqueued=%d", + path.sourceUDP.Load(), batchStarts, path.session.mediaIngress.Load(), + path.session.mediaRecovered.Load(), path.session.mediaEnqueued.Load()) +} + +func TestQualificationProcessingRetainsProviderIngressDiagnostics(t *testing.T) { + profile := qualificationMediaProfiles()[2] + path := newQualificationProcessingPath(t, profile, profile.BitrateKbps) + defer path.Close() + + payload := qualificationFramePayload(profile, 0) + packets := qualificationSourceVideoPackets(t, path.key, 1, payload) + if len(payload) != 666_664 || len(packets) != 662 { + t.Fatalf("4K60 keyframe = %d bytes/%d shards, want 666664/662", len(payload), len(packets)) + } + before, err := path.process.snapshot() + if err != nil { + t.Fatal(err) + } + if _, err := path.emit(t, payload); err != nil { + t.Fatal(err) + } + recovered, err := path.receivePayload(context.Background()) + if err != nil { + t.Fatal(err) + } + diagnostics := path.processingDiagnostics(1) + if diagnostics.SnapshotError != "" { + t.Fatal(diagnostics.SnapshotError) + } + after := diagnostics.Gateway + batches := diagnostics.BatchHistory + if diagnostics.ProcessedFrames != 1 || diagnostics.SourceFrames != 1 || + diagnostics.ExpectedWritesThroughLastFrame != 662 || + diagnostics.FixtureSentPackets != 662 || diagnostics.SourceUDP != 662 || + after.MediaIngress-before.MediaIngress != 662 || + after.MediaRecovered-before.MediaRecovered != 1 || + after.MediaEnqueued-before.MediaEnqueued != 1 || !bytes.Equal(recovered, payload) { + t.Fatalf("provider ingress diagnostics: sent=%d source=%d ingress=%d recovered=%d enqueued=%d payload=%t", + diagnostics.FixtureSentPackets, diagnostics.SourceUDP, after.MediaIngress-before.MediaIngress, + after.MediaRecovered-before.MediaRecovered, after.MediaEnqueued-before.MediaEnqueued, + bytes.Equal(recovered, payload)) + } + if len(batches) != 11 { + t.Fatalf("provider batch history = %d entries, want 11", len(batches)) + } + for index := range batches { + wantPacket := index * 63 + if batches[index].ProviderFrame != 1 || batches[index].PacketWithinFrame != wantPacket || + batches[index].SourcePacket != uint64(wantPacket) { + t.Fatalf("provider batch %d = %#v, want frame 1 source/within %d", index, batches[index], wantPacket) + } + if index > 0 { + previousPackets := min(63, 662-batches[index-1].PacketWithinFrame) + minimum := qualificationApolloVideoOffset(previousPackets, 96) + if batches[index].StartedAfter-batches[index-1].StartedAfter < minimum { + t.Fatalf("provider batch %d collapsed: %#v", index, batches) + } + } + } + if (runtime.GOOS == "darwin" || runtime.GOOS == "linux") && !after.VideoReceiveBufferAvailable { + t.Fatal("provider video SO_RCVBUF unavailable on a supported diagnostic platform") + } + if after.VideoReceiveBufferAvailable && after.VideoReceiveBuffer <= 0 { + t.Fatalf("provider video SO_RCVBUF = %d available=%t, want measured >0", + after.VideoReceiveBuffer, after.VideoReceiveBufferAvailable) + } + if after.KernelDropsAvailable && after.KernelDrops != 0 { + t.Fatalf("provider UDP kernel drops = %d, want 0", after.KernelDrops) + } + t.Logf("provider ingress diagnostics: %#v", diagnostics) +} + +func TestQualificationActualEmissionDoesNotCatchUpAfterPreWritePause(t *testing.T) { + key := bytes.Repeat([]byte{0x4d}, 16) + packets := qualificationSourceVideoPackets(t, key, 1, make([]byte, 189*apolloVideoShardPayloadSize-8)) + receiver, err := net.ListenUDP("udp", &net.UDPAddr{IP: net.ParseIP("127.0.0.1")}) + if err != nil { + t.Fatal(err) + } + defer receiver.Close() + sender, err := net.ListenUDP("udp", &net.UDPAddr{IP: net.ParseIP("127.0.0.1")}) + if err != nil { + t.Fatal(err) + } + defer sender.Close() + fixture := &qualificationApolloFixture{video: sender, failures: make(chan error, 1)} + remote := *receiver.LocalAddr().(*net.UDPAddr) + fixture.videoRemote.Store(&remote) + stalled := false + fixture.beforeVideoFirstWrite = func(ctx context.Context, packetWithinFrame int) error { + if packetWithinFrame != 63 || stalled { + return nil + } + stalled = true + return qualificationWaitContext(ctx, time.Now().Add(5*time.Millisecond)) + } + var emitted []time.Time + fixture.observeVideoBatch = func(_ int, at time.Time) { emitted = append(emitted, at) } + drained := make(chan struct{}) + go func() { + defer close(drained) + buffer := make([]byte, 2048) + for range len(packets) { + if _, _, readErr := receiver.ReadFromUDP(buffer); readErr != nil { + return + } + } + }() + if err := fixture.sendVideo(context.Background(), 1, packets); err != nil { + t.Fatal(err) + } + select { + case <-drained: + case <-time.After(time.Second): + t.Fatal("actual-emission receiver did not drain") + } + if len(emitted) != 3 { + t.Fatalf("actual emitted batch starts = %d, want 3", len(emitted)) + } + minimum := qualificationApolloVideoOffset(63, 96) + if actual := emitted[2].Sub(emitted[1]); actual < minimum { + t.Fatalf("post-write batch 126 started %s after batch 63, before %s; emitted=%v", actual, minimum, emitted) + } + t.Logf("post-write emitted batch starts: %v", emitted) +} + +func TestQualificationProcessingDiagnosticsFormatUsesMonotonicOffsets(t *testing.T) { + diagnostics := qualificationProcessingDiagnostics{ + BatchHistory: []qualificationVideoBatchObservation{{StartedAfter: 1234567 * time.Nanosecond}}, + } + failureText := fmt.Errorf("qualification failed; diagnostics=%#v", diagnostics).Error() + if !strings.Contains(failureText, "StartedAfter") || !strings.Contains(failureText, "1234567") || + strings.Contains(failureText, "time.Date(") { + t.Fatalf("processing failure text does not retain explicit monotonic offsets: %s", failureText) + } +} diff --git a/gateway/qualification_harness_test.go b/gateway/qualification_harness_test.go index 98611ac..97fc108 100644 --- a/gateway/qualification_harness_test.go +++ b/gateway/qualification_harness_test.go @@ -31,7 +31,6 @@ import ( "strings" "sync" "sync/atomic" - "syscall" "testing" "time" @@ -39,7 +38,7 @@ import ( ) const ( - qualificationToolVersion = "versevdi-gateway-qualification/v7" + qualificationToolVersion = "versevdi-gateway-qualification/v8" qualificationImpairmentQueuePackets = nativeApolloVideoQueuePackets qualificationImpairmentMaxPackets = 100_000 qualificationImpairmentPacketCount = 10_000 @@ -76,20 +75,39 @@ type qualificationPathTrace struct { PayloadPreserved bool } +type qualificationVideoBatchObservation struct { + ProviderFrame uint32 + SourcePacket uint64 + PacketWithinFrame int + StartedAfter time.Duration +} + type qualificationPath struct { - client *independentGatewayClient - server *Server - session *nativeApolloSession - fixture *qualificationApolloFixture - backend *qualificationTracingBackend - process *qualificationGatewayProcess - key []byte - flow string - frame uint32 - bootTrace atomic.Bool - sourceUDP atomic.Uint64 - closeOnce sync.Once - shutdown func() + client *independentGatewayClient + server *Server + session *nativeApolloSession + fixture *qualificationApolloFixture + backend *qualificationTracingBackend + process *qualificationGatewayProcess + key []byte + flow string + frame uint32 + bootTrace atomic.Bool + sourceUDP atomic.Uint64 + expectedSourceUDP atomic.Uint64 + closeOnce sync.Once + shutdown func() +} + +type qualificationProcessingDiagnostics struct { + ProcessedFrames int64 + SourceFrames uint32 + ExpectedWritesThroughLastFrame uint64 + FixtureSentPackets uint64 + SourceUDP uint64 + BatchHistory []qualificationVideoBatchObservation + Gateway qualificationGatewayProcessSnapshot + SnapshotError string } type qualificationImpairmentProfile struct { @@ -414,23 +432,29 @@ func (b *qualificationTracingBackend) session(sessionID string) *nativeApolloSes } type qualificationApolloFixture struct { - sessionID string - management *httptest.Server - stream net.Listener - control *net.UDPConn - audio *net.UDPConn - video *net.UDPConn - videoRemote atomic.Pointer[net.UDPAddr] - key atomic.Pointer[[]byte] - keyReady chan []byte - failures chan error - closed atomic.Bool - closeOnce sync.Once - sentPackets atomic.Uint64 - work protocol.ProviderSessionWork - videoPaceMu sync.Mutex - videoNext time.Time - observeVideoBatch func(int, time.Time) + sessionID string + management *httptest.Server + stream net.Listener + control *net.UDPConn + audio *net.UDPConn + video *net.UDPConn + videoRemote atomic.Pointer[net.UDPAddr] + key atomic.Pointer[[]byte] + keyReady chan []byte + failures chan error + closed atomic.Bool + closeOnce sync.Once + sentPackets atomic.Uint64 + work protocol.ProviderSessionWork + videoPaceMu sync.Mutex + videoNext time.Time + beforeVideoBatch func(context.Context, int) error + beforeVideoFirstWrite func(context.Context, int) error + observeVideoBatch func(int, time.Time) + videoBatchMu sync.Mutex + videoBatchEpoch time.Time + videoBatchCount uint64 + videoBatches [128]qualificationVideoBatchObservation controlImpairmentMu sync.Mutex controlRTT time.Duration @@ -438,6 +462,30 @@ type qualificationApolloFixture struct { controlRandom uint64 } +func (f *qualificationApolloFixture) videoBatchHistory() []qualificationVideoBatchObservation { + f.videoBatchMu.Lock() + defer f.videoBatchMu.Unlock() + count := min(f.videoBatchCount, uint64(len(f.videoBatches))) + result := make([]qualificationVideoBatchObservation, 0, count) + for index := f.videoBatchCount - count; index < f.videoBatchCount; index++ { + result = append(result, f.videoBatches[index%uint64(len(f.videoBatches))]) + } + return result +} + +func (f *qualificationApolloFixture) recordVideoBatch(providerFrame uint32, sourcePacket uint64, packetWithinFrame int, started time.Time) { + f.videoBatchMu.Lock() + if f.videoBatchEpoch.IsZero() { + f.videoBatchEpoch = started + } + f.videoBatches[f.videoBatchCount%uint64(len(f.videoBatches))] = qualificationVideoBatchObservation{ + ProviderFrame: providerFrame, SourcePacket: sourcePacket, + PacketWithinFrame: packetWithinFrame, StartedAfter: started.Sub(f.videoBatchEpoch), + } + f.videoBatchCount++ + f.videoBatchMu.Unlock() +} + func newQualificationApolloFixture(t *testing.T, serverTLS, clientTLS *tls.Config, sessionID string, profile qualificationMediaProfile) *qualificationApolloFixture { t.Helper() fixture := &qualificationApolloFixture{sessionID: sessionID, keyReady: make(chan []byte, 1), failures: make(chan error, 8)} @@ -749,7 +797,7 @@ func (f *qualificationApolloFixture) serveMedia(socket *net.UDPConn, video bool) } } -func (f *qualificationApolloFixture) sendVideo(ctx context.Context, packets [][]byte) error { +func (f *qualificationApolloFixture) sendVideo(ctx context.Context, providerFrame uint32, packets [][]byte) error { for f.videoRemote.Load() == nil { select { case err := <-f.failures: @@ -770,21 +818,37 @@ func (f *qualificationApolloFixture) sendVideo(ctx context.Context, packets [][] f.videoPaceMu.Lock() defer f.videoPaceMu.Unlock() - frameStart := time.Now() - if f.videoNext.After(frameStart) { - frameStart = f.videoNext - } framePackets := 0 for batchStart := 0; batchStart < len(packets); batchStart += batchSize { batchEnd := min(batchStart+batchSize, len(packets)) - due := frameStart.Add(qualificationApolloVideoOffset(framePackets, packetsPerMillisecond)) - if err := qualificationWaitContext(ctx, due); err != nil { + sourceStart := f.sentPackets.Load() + if err := qualificationWaitContext(ctx, f.videoNext); err != nil { return err } - if f.observeVideoBatch != nil { - f.observeVideoBatch(framePackets, time.Now()) + if f.beforeVideoBatch != nil { + if err := f.beforeVideoBatch(ctx, framePackets); err != nil { + return err + } } - for _, packet := range packets[batchStart:batchEnd] { + if f.beforeVideoFirstWrite != nil { + if err := f.beforeVideoFirstWrite(ctx, framePackets); err != nil { + return err + } + } + firstPacket := packets[batchStart] + if len(firstPacket) != len(packets[0]) { + return ErrProviderMalformed + } + if _, err := f.video.WriteToUDP(firstPacket, remote); err != nil { + return err + } + batchStarted := time.Now() + f.sentPackets.Add(1) + f.recordVideoBatch(providerFrame, sourceStart, framePackets, batchStarted) + if f.observeVideoBatch != nil { + f.observeVideoBatch(framePackets, batchStarted) + } + for _, packet := range packets[batchStart+1 : batchEnd] { if len(packet) != len(packets[0]) { return ErrProviderMalformed } @@ -795,8 +859,8 @@ func (f *qualificationApolloFixture) sendVideo(ctx context.Context, packets [][] } currentBatch := batchEnd - batchStart framePackets += currentBatch + f.videoNext = batchStarted.Add(qualificationApolloVideoOffset(currentBatch, packetsPerMillisecond)) } - f.videoNext = frameStart.Add(qualificationApolloVideoOffset(framePackets, packetsPerMillisecond)) return nil } @@ -1145,15 +1209,31 @@ func (p *qualificationPath) emit(t *testing.T, payload []byte) (qualificationPat } p.frame++ packets := qualificationSourceVideoPackets(t, p.key, p.frame, payload) + p.expectedSourceUDP.Add(uint64(len(packets))) ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) defer cancel() - if err := p.fixture.sendVideo(ctx, packets); err != nil { + if err := p.fixture.sendVideo(ctx, p.frame, packets); err != nil { return qualificationPathTrace{}, err } p.sourceUDP.Add(uint64(len(packets))) return qualificationPathTrace{}, nil } +func (p *qualificationPath) processingDiagnostics(processed int64) qualificationProcessingDiagnostics { + diagnostics := qualificationProcessingDiagnostics{ + ProcessedFrames: processed, SourceFrames: p.frame, + ExpectedWritesThroughLastFrame: p.expectedSourceUDP.Load(), + FixtureSentPackets: p.fixture.sentPackets.Load(), SourceUDP: p.sourceUDP.Load(), + BatchHistory: p.fixture.videoBatchHistory(), + } + var err error + diagnostics.Gateway, err = p.process.snapshot() + if err != nil { + diagnostics.SnapshotError = err.Error() + } + return diagnostics +} + func (p *qualificationPath) receivePayload(parent context.Context) ([]byte, error) { ctx, cancel := context.WithTimeout(parent, 2*time.Second) defer cancel() @@ -1711,14 +1791,21 @@ func qualificationMaximumDeliveryBytes(deliveries []qualificationDeliverySample, return maximum } -func runQualificationProcessing(t *testing.T, profile qualificationMediaProfile, rawPath string) (qualificationProcessingSummary, error) { +func runQualificationProcessing(t *testing.T, profile qualificationMediaProfile, rawPath string) (summary qualificationProcessingSummary, err error) { t.Helper() payload := qualificationFramePayload(profile, 0) if len(payload) < 4 { return qualificationProcessingSummary{}, errors.New("qualification payload too small") } path := newQualificationProcessingPath(t, profile, qualificationFramePacerKbps(profile)) - defer path.Close() + var processed int64 + defer func() { + if err != nil { + diagnostics := path.processingDiagnostics(processed) + err = fmt.Errorf("%w; diagnostics=%#v", err, diagnostics) + } + path.Close() + }() if err := runQualificationProcessWarmup(t, path, profile, payload); err != nil { return qualificationProcessingSummary{}, err } @@ -1773,15 +1860,13 @@ func runQualificationProcessing(t *testing.T, profile qualificationMediaProfile, } receivedDone <- nil }() - var processed int64 var nextRelease time.Time payloadDigest := sha256.New() for processed < targetFrames { select { case receiveErr := <-receivedDone: if receiveErr != nil { - snapshot, _ := path.process.snapshot() - return qualificationProcessingSummary{}, fmt.Errorf("%w; gateway snapshot=%#v", receiveErr, snapshot) + return qualificationProcessingSummary{}, receiveErr } return qualificationProcessingSummary{}, errors.New("qualification processing receiver ended early") default: @@ -1799,8 +1884,7 @@ func runQualificationProcessing(t *testing.T, profile qualificationMediaProfile, processed++ } if err := <-receivedDone; err != nil { - snapshot, _ := path.process.snapshot() - return qualificationProcessingSummary{}, fmt.Errorf("%w; gateway snapshot=%#v", err, snapshot) + return qualificationProcessingSummary{}, err } qualificationWaitUntil(started.Add(profile.Duration)) actualDuration := time.Since(started) @@ -1827,7 +1911,7 @@ func runQualificationProcessing(t *testing.T, profile qualificationMediaProfile, if err != nil { return qualificationProcessingSummary{}, err } - summary, err := summarizeQualificationSamples(samples) + summary, err = summarizeQualificationSamples(samples) if err != nil { return qualificationProcessingSummary{}, err } @@ -1950,12 +2034,7 @@ func runQualificationWarmup(t *testing.T, path *qualificationPath, profile quali } func qualificationRuntimeSample(started time.Time) qualificationResourceSample { - var usage syscall.Rusage - cpuSeconds := -1.0 - if syscall.Getrusage(syscall.RUSAGE_SELF, &usage) == nil { - cpuSeconds = float64(usage.Utime.Sec+usage.Stime.Sec) + - float64(usage.Utime.Usec+usage.Stime.Usec)/1_000_000 - } + cpuSeconds := qualificationProcessCPUSeconds() samples := []runtimemetrics.Sample{ {Name: "/memory/classes/heap/objects:bytes"}, {Name: "/sched/goroutines:goroutines"}, diff --git a/gateway/qualification_process_test.go b/gateway/qualification_process_test.go index f15fc19..fbb03ea 100644 --- a/gateway/qualification_process_test.go +++ b/gateway/qualification_process_test.go @@ -47,17 +47,21 @@ type qualificationGatewayProcessReady struct { } type qualificationGatewayProcessSnapshot struct { - Metrics MetricsSnapshot - NativeSetups uint64 - NativeOpens uint64 - MediaIngress uint64 - MediaRecovered uint64 - MediaEnqueued uint64 - MediaDrops uint64 - MediaQueueMaximum uint64 - MediaQueueMaximumBytes uint64 - PacerReservations uint64 - ProviderTelemetry ProviderTelemetry + Metrics MetricsSnapshot + NativeSetups uint64 + NativeOpens uint64 + MediaIngress uint64 + MediaRecovered uint64 + MediaEnqueued uint64 + MediaDrops uint64 + MediaQueueMaximum uint64 + MediaQueueMaximumBytes uint64 + PacerReservations uint64 + ProviderTelemetry ProviderTelemetry + VideoReceiveBuffer int + VideoReceiveBufferAvailable bool + KernelDrops uint64 + KernelDropsAvailable bool } type qualificationProcessRecordRequest struct { @@ -242,7 +246,7 @@ func (r *qualificationProcessRecorder) stop() (qualificationProcessRecordResult, return qualificationProcessRecordResult{}, err } first, last := resources[0], resources[len(resources)-1] - result.CPUSeconds = max(last.CPUSeconds-first.CPUSeconds, 0) + result.CPUSeconds = qualificationCPUSecondsDelta(first.CPUSeconds, last.CPUSeconds) result.AllocatedObjects = last.AllocatedObjects - first.AllocatedObjects result.AllocatedBytes = last.AllocatedBytes - first.AllocatedBytes for _, sample := range resources { @@ -252,6 +256,35 @@ func (r *qualificationProcessRecorder) stop() (qualificationProcessRecordResult, return result, nil } +func qualificationCPUSecondsDelta(first, last float64) float64 { + cpuSeconds := -1.0 + if first >= 0 && last >= first { + cpuSeconds = last - first + } + return cpuSeconds +} + +func TestQualificationCPUSecondsDeltaRejectsUnavailableOrDecreasingSamples(t *testing.T) { + tests := []struct { + name string + first, last float64 + want float64 + }{ + {name: "positive", first: 1.25, last: 1.75, want: 0.5}, + {name: "zero", first: 1.25, last: 1.25, want: 0}, + {name: "unavailable first", first: -1, last: 1.25, want: -1}, + {name: "unavailable last", first: 1.25, last: -1, want: -1}, + {name: "decreasing", first: 1.75, last: 1.25, want: -1}, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + if got := qualificationCPUSecondsDelta(test.first, test.last); got != test.want { + t.Fatalf("CPU delta for first=%f last=%f = %f, want %f", test.first, test.last, got, test.want) + } + }) + } +} + type qualificationGatewayProcess struct { command *exec.Cmd cancel context.CancelFunc @@ -461,6 +494,9 @@ func TestQualificationGatewayProcessChild(t *testing.T) { snapshot.MediaQueueMaximum = session.mediaQueueMaximum.Load() snapshot.MediaQueueMaximumBytes = session.mediaQueueMaximumBytes.Load() snapshot.ProviderTelemetry = session.Telemetry() + snapshot.VideoReceiveBuffer, snapshot.VideoReceiveBufferAvailable, + snapshot.KernelDrops, snapshot.KernelDropsAvailable = + qualificationProviderVideoSocketDiagnostics(session.videoConn) } _ = json.NewEncoder(response).Encode(snapshot) }) diff --git a/gateway/qualification_socket_other_test.go b/gateway/qualification_socket_other_test.go new file mode 100644 index 0000000..5443168 --- /dev/null +++ b/gateway/qualification_socket_other_test.go @@ -0,0 +1,11 @@ +//go:build !darwin && !linux + +package gateway + +import "net" + +func qualificationProcessCPUSeconds() float64 { return -1 } + +func qualificationProviderVideoSocketDiagnostics(*net.UDPConn) (receiveBuffer int, receiveBufferAvailable bool, kernelDrops uint64, kernelDropsAvailable bool) { + return 0, false, 0, false +} diff --git a/gateway/qualification_socket_unix_test.go b/gateway/qualification_socket_unix_test.go new file mode 100644 index 0000000..375693c --- /dev/null +++ b/gateway/qualification_socket_unix_test.go @@ -0,0 +1,80 @@ +//go:build darwin || linux + +package gateway + +import ( + "io" + "net" + "os" + "runtime" + "strconv" + "strings" + "syscall" +) + +func qualificationProcessCPUSeconds() float64 { + var usage syscall.Rusage + if syscall.Getrusage(syscall.RUSAGE_SELF, &usage) != nil { + return -1 + } + return float64(usage.Utime.Sec+usage.Stime.Sec) + + float64(usage.Utime.Usec+usage.Stime.Usec)/1_000_000 +} + +func qualificationProviderVideoSocketDiagnostics(connection *net.UDPConn) (receiveBuffer int, receiveBufferAvailable bool, kernelDrops uint64, kernelDropsAvailable bool) { + if connection == nil { + return 0, false, 0, false + } + raw, err := connection.SyscallConn() + if err != nil { + return 0, false, 0, false + } + var inode uint64 + var socketErr error + if err := raw.Control(func(descriptor uintptr) { + receiveBuffer, socketErr = syscall.GetsockoptInt(int(descriptor), syscall.SOL_SOCKET, syscall.SO_RCVBUF) + if runtime.GOOS == "linux" { + var stat syscall.Stat_t + if statErr := syscall.Fstat(int(descriptor), &stat); statErr == nil { + inode = stat.Ino + } + } + }); err != nil || socketErr != nil { + return 0, false, 0, false + } + receiveBufferAvailable = true + if runtime.GOOS == "linux" { + kernelDrops, kernelDropsAvailable = qualificationLinuxUDPDrops(inode) + } + return receiveBuffer, receiveBufferAvailable, kernelDrops, kernelDropsAvailable +} + +func qualificationLinuxUDPDrops(inode uint64) (uint64, bool) { + if inode == 0 { + return 0, false + } + inodeText := strconv.FormatUint(inode, 10) + for _, path := range []string{"/proc/net/udp", "/proc/net/udp6"} { + file, err := os.Open(path) + if err != nil { + continue + } + raw, readErr := io.ReadAll(io.LimitReader(file, 1<<20)) + closeErr := file.Close() + if readErr != nil || closeErr != nil { + continue + } + for _, line := range strings.Split(string(raw), "\n") { + fields := strings.Fields(line) + if len(fields) < 11 || fields[9] != inodeText { + continue + } + drops, err := strconv.ParseUint(fields[len(fields)-1], 10, 64) + if err != nil { + return 0, false + } + return drops, true + } + } + return 0, false +} diff --git a/openspec/changes/truthful-fixed-frame-qualification/design.md b/openspec/changes/truthful-fixed-frame-qualification/design.md index 009a809..887b9a0 100644 --- a/openspec/changes/truthful-fixed-frame-qualification/design.md +++ b/openspec/changes/truthful-fixed-frame-qualification/design.md @@ -4,7 +4,11 @@ The current harness sends one fixed 1,179-byte payload per logical sample. It re The complete-frame fixture also must preserve the pinned Apollo source schedule. For each frame it derives packets per millisecond from the raw UDP block size at 80% of 1 Gbps, limits source batches to both 64 KiB and 64 packets, and carries the next-send time into the following frame. Waiting is context-cancellable. This is qualification-fixture behavior only; production transport and queue behavior remain unchanged. -Because the bounded fixture uses loopback rather than a physical 1 Gbps link, each batch begins at its cumulative wire-rate offset. This preserves Apollo's raw-block rate and batch ceilings without collapsing multiple batches into an instantaneous loopback burst. +Because the bounded fixture uses loopback rather than a physical 1 Gbps link, v8 writes the first shard of a batch successfully, captures that actual monotonic emission start, and schedules the next batch no earlier than that start plus the current batch's raw-block serialization interval. The persistent schedule carries across frames. A delayed batch therefore remains late instead of collapsing overdue batches into a catch-up burst. + +The retained v6 qualification run passed its then-current checks but is superseded because its tight-loop sender contradicted the pinned Apollo schedule. Private Linux runs 123 and 124 remain failed evidence. One local v8 sustained run passed on Darwin, but it is neither Linux proof nor normative Section 7 evidence. + +The later Darwin non-sustained pre-CI invocation was not green and was not retried. Its 1440p120 profile delivered the exact 6,250,000 bytes in 120 frames plus all 6,483 source and warm-up shards with zero drops, but measured 46,973.13 kbps over an implied approximately 1.0644383 seconds and failed the 5% throughput gate. Private Linux full verification/artifact retention and the replacement v8 normative run remain open. ## Goals / Non-Goals diff --git a/openspec/changes/truthful-fixed-frame-qualification/specs/gateway-qualification/spec.md b/openspec/changes/truthful-fixed-frame-qualification/specs/gateway-qualification/spec.md index 32b9c39..e82be79 100644 --- a/openspec/changes/truthful-fixed-frame-qualification/specs/gateway-qualification/spec.md +++ b/openspec/changes/truthful-fixed-frame-qualification/specs/gateway-qualification/spec.md @@ -3,7 +3,7 @@ ### Requirement: Fixed media processing qualification The qualification harness SHALL drive pinned-mTLS Apollo management, encrypted RTSP, ENet, and provider UDP through native source validation, `readUDPMedia`, recovery/FEC, byte/count/latency-bounded production queues, the production fair pacer, Protocol complete-frame fragmentation, Verse framing/QUIC, and an independent bounded client reassembler for 1080p60 H.264 at 20 Mbps, 1440p120 HEVC at 50 Mbps, and 4K60 HEVC at 80 Mbps. The source fixture SHALL emit deterministic variable-size complete encoded frame units at the named 60/120 FPS rate, preserve exact target bytes over each fixed interval, and include bounded larger keyframes without codec operation. After a recorded warm-up, the frozen candidate SHALL run each profile for ten wall-clock minutes, preserve every frame's bytes and boundary, retain every monotonic processing sample plus bounded provider-queue observations, and report frame count, frame rate, bitrate, count, min, median, p90, p95, p99, max, mean, standard deviation, measured batched monotonic-clock overhead and method, and observed bitrate. Processing begins at complete provider-frame receipt and ends at QUIC handoff, excluding client transit and pacing. Queue delay SHALL measure provider-queue residence, processing SHALL measure gateway work before pacing, and pacing delay SHALL measure scheduler waiting. CPU, heap, allocations, and goroutines SHALL be measured from the isolated gateway process only; CPU SHALL be actual OS user plus system consumption and MUST NOT include idle wall capacity or unrelated parent fixture/client work. Successive profiles SHALL use independent resource-counter baselines. Any bypass, payload or boundary mutation, frame-rate/count mismatch, wall-duration violation, bitrate outside both lower and upper bounds, unexplained clean-path loss, zero or unbounded clock overhead, or p95 above 5 ms SHALL fail. -Within each complete frame the source fixture SHALL reproduce pinned Apollo's source schedule by deriving packets per millisecond from the raw UDP block size at 80% of 1 Gbps, bounding each source batch to the smaller of 64 KiB or 64 packets, carrying the next-send time across frames, and making pacing waits context-cancellable. +Within each complete frame the source fixture SHALL reproduce pinned Apollo's source schedule by deriving packets per millisecond from the raw UDP block size at 80% of 1 Gbps, bounding each source batch to the smaller of 64 KiB or 64 packets, capturing the monotonic batch start immediately after the first successful shard write, scheduling the next batch no earlier than that start plus the current batch's raw-block serialization interval, carrying that schedule across frames, and making pacing waits context-cancellable. A delayed batch SHALL remain late rather than trigger an overdue catch-up burst. #### Scenario: Healthy fixed profile - **WHEN** a frozen candidate runs one fixed profile for the normative duration in the isolated qualification command @@ -15,4 +15,4 @@ Within each complete frame the source fixture SHALL reproduce pinned Apollo's so #### Scenario: Source-shaped Apollo pacing is preserved - **WHEN** the fixture emits 1,072-byte encrypted video shards with 1,040-byte raw blocks for consecutive complete frames -- **THEN** it uses 96 packets per millisecond, batches at most 63 shards at offsets derived from cumulative packet count, carries the next-send offset into the following frame, and emits no shard after a cancelled pacing wait +- **THEN** it uses 96 packets per millisecond, batches at most 63 shards, records each batch after its first successful shard write, starts each later batch no earlier than the prior batch's raw serialization interval, carries the schedule into the following frame, and emits no shard after a cancelled pacing wait diff --git a/openspec/changes/truthful-fixed-frame-qualification/tasks.md b/openspec/changes/truthful-fixed-frame-qualification/tasks.md index c75e935..4359ad3 100644 --- a/openspec/changes/truthful-fixed-frame-qualification/tasks.md +++ b/openspec/changes/truthful-fixed-frame-qualification/tasks.md @@ -21,5 +21,7 @@ ## 5. Pinned Apollo source-fidelity remediation - [x] 5.1 Retain the v6 qualification attempt and mark its passing result superseded by the tight-loop source defect -- [ ] 5.2 Rate- and batch-shape complete-frame UDP emission from the pinned Apollo behavior and verify focused, race, resource, full, artifact, and CI gates -- [ ] 5.3 Freeze the v7 harness descendant and run one separately approved replacement normative Section 7 qualification +- [x] 5.2 Implement v8 post-first-write, non-collapsing complete-frame UDP pacing with persistent cross-frame carry and verify the focused, race, short-resource, and cross-platform compile checks that passed +- [x] 5.3 Preserve private Linux runs 123 and 124 as failed evidence, the passing local v8 Darwin sustained run as non-Linux and non-normative, and the un-retried failed Darwin non-sustained pre-CI invocation with its exact throughput evidence +- [ ] 5.4 Run private Linux full verification and retain deterministic Linux artifacts for the frozen v8 harness descendant +- [ ] 5.5 Run one separately approved replacement v8 normative Section 7 qualification