Source identity
| Field | Recorded value |
|---|---|
| Source type | GitHub source |
| Original record | Janady13/missionmatch / tools/verify/stress/phase2.go |
| Date | Not specified in source |
| Repository | Janady13/missionmatch |
| Revision | 720d47fae476b0d38477ae4401697d372b1ea2bc |
| Branch | feature/opportunity-to-outcome |
| Path or archive member | tools/verify/stress/phase2.go |
| Original SHA-256 | e79ee3e166ac3eef4ae5a703f547ea7870befe4511fb6da30999ad8575da166d |
| Git blob SHA | d885ea62cc757df8549fa50a8b584b218e96fc61 |
| Reading-copy SHA-256 | e79ee3e166ac3eef4ae5a703f547ea7870befe4511fb6da30999ad8575da166d |
Recovered source transcript
Download complete source text ↓313 lines · 13.3 KB
package main
import (
"fmt"
"log"
"runtime"
"strings"
"sync"
"time"
"github.com/missionworkforce/missionmatch/internal/modules/opportunities"
"github.com/missionworkforce/missionmatch/internal/platform/scrub"
)
// THE THREE PHASE 2 STRESS PROFILES THE PROTOCOL NAMES AND NOBODY RAN.
//
// docs/BUILD_CONTINUATION_PROTOCOL.md lists five Phase 2 stress items. Three were run at the phase close, the
// 32 way promotion race, load, and soak. These are the other three, and their absence was not recorded as a
// gap, which is how a gate reports PASS while a third of its list was never attempted:
//
// concurrent extraction of 25 documents, memory bounded
// a 200 page PWS parses within cap
// the scrub gate flooded with mixed payloads misroutes zero private items, positive control planted
//
// Each one carries its own control, and each control must FAIL before the counted run is allowed to mean
// anything. They are pure CPU and memory profiles rather than database profiles, so they run anywhere and
// measure the thing they claim to measure.
// synthPWS builds a solicitation of roughly the requested page count, in the shape a real one has: numbered
// clauses, prose, and a rate table. It is generated rather than fixture loaded so the cap can be pushed past
// anything a real package has contained.
func synthPWS(pages int) string {
var b strings.Builder
b.Grow(pages * 2200)
for p := 1; p <= pages; p++ {
fmt.Fprintf(&b, "\fPage %d of %d\n", p, pages)
fmt.Fprintf(&b, "C.%d.1 SCOPE OF WORK\n", p)
b.WriteString("The contractor shall provide continuous monitoring of the enclave in accordance with " +
"the customer's baseline. All personnel shall hold a TS/SCI clearance with a CI polygraph, and " +
"travel is estimated at 15 percent of the period of performance.\n\n")
fmt.Fprintf(&b, "C.%d.2 STAFFING\n", p)
b.WriteString("The contractor shall provide four Cyber Systems Operations specialists with a " +
"minimum of 5 years experience and Security+ certification.\n\n")
// A rate table, so the table reader is exercised at volume too.
b.WriteString("OCCUPATION CODE - TITLE FOOTNOTE RATE\n")
for r := 0; r < 8; r++ {
fmt.Fprintf(&b, "%05d - Systems Administrator %d %d.%02d\n",
1000+p*10+r, r, 20+r, (r*7)%100)
}
b.WriteString("\n")
}
return b.String()
}
// volumeProfile parses one very large PWS and reports time and peak memory. The protocol asks for "a 200 page
// PWS parses within cap"; the cap is stated here rather than left implicit so a regression is visible.
//
// THE CONTROL asks for a document so large that the time cap cannot be met, proving the timer is real. A
// profile that passes because it never actually measured the clock is the failure mode this build keeps
// finding.
func volumeProfile(control bool) error {
pages := 200
timeCap := 20 * time.Second
memCapMB := uint64(512)
if control {
// A deliberately unmeetable cap on the SAME work, so the control proves the assertion fires rather
// than proving that a bigger document is slower.
timeCap = time.Nanosecond
}
text := synthPWS(pages)
log.Printf("volume: %d page PWS, %d bytes of text", pages, len(text))
var before, after runtime.MemStats
runtime.GC()
runtime.ReadMemStats(&before)
start := time.Now()
chunks := opportunities.ExtractDeterministic(text)
tables := opportunities.ExtractTables(text)
rates := opportunities.ExtractRateRows(text)
elapsed := time.Since(start)
runtime.ReadMemStats(&after)
usedMB := (after.TotalAlloc - before.TotalAlloc) / (1 << 20)
log.Printf("volume: %d chunks, %d tables, %d rate rows in %v, %d MB allocated",
len(chunks), len(tables), len(rates), elapsed.Round(time.Millisecond), usedMB)
if len(chunks) == 0 {
return fmt.Errorf("a %d page PWS produced no chunks", pages)
}
if len(rates) == 0 {
return fmt.Errorf("a %d page PWS with a rate table on every page produced no rate rows", pages)
}
if elapsed > timeCap {
return fmt.Errorf("parsing took %v, over the %v cap", elapsed.Round(time.Millisecond), timeCap)
}
if usedMB > memCapMB {
return fmt.Errorf("parsing allocated %d MB, over the %d MB cap", usedMB, memCapMB)
}
return nil
}
// concurrentExtractProfile extracts 25 documents at once and asserts the work is MEMORY BOUNDED, which is the
// property the protocol names. Bounded means the peak does not scale with the number of documents in flight,
// so the same total work is measured at concurrency 1 and at concurrency 25 and the ratio is checked.
//
// THE CONTROL retains every document's text in a live slice, which is precisely the leak this profile exists
// to catch: it makes peak memory scale with concurrency and the ratio assertion must fire.
func concurrentExtractProfile(control bool) error {
const docs = 25
const pagesEach = 60
// AN ABSOLUTE BOUND ON RETAINED HEAP, NOT A RATIO. The ratio version could not work: both measurements
// include the runtime's own baseline heap, so retaining a few megabytes on top of it moved the ratio by a
// fraction and never crossed any threshold worth setting. Measuring GROWTH above a baseline, in kilobytes,
// asks the question the protocol actually asks: after extracting 25 documents concurrently, is anything
// still held? Bounded means the answer is no, whatever the concurrency was.
// THE CAP IS MEASURED, NOT GUESSED. The counted run retains 180 KB and the planted leak retains several
// megabytes, so 512 KB sits well clear of the real behaviour and well below the defect. The first version
// used 4096 KB, a number chosen from nothing, and the leak came in under it, which is a cap that cannot
// fail.
const growthCapKB = 512
text := synthPWS(pagesEach)
// LIVE HEAP, NOT CUMULATIVE ALLOCATION. The first version measured the TotalAlloc delta, which counts every
// byte ever allocated and is therefore IDENTICAL whether the results are retained or thrown away. The leak
// control scored a ratio of 1.00 and still "passed" because the function returned an error unconditionally,
// which is a control that passes by construction rather than by detecting anything. That is precisely the
// instrument failure this whole protocol exists to catch, so it is fixed rather than explained.
heapKB := func() uint64 {
var m runtime.MemStats
runtime.GC()
runtime.ReadMemStats(&m)
return m.HeapAlloc / 1024
}
measure := func(workers int, leak *[][]opportunities.Chunk) uint64 {
baseline := heapKB()
sem := make(chan struct{}, workers)
var wg sync.WaitGroup
var mu sync.Mutex
for i := 0; i < docs; i++ {
wg.Add(1)
go func() {
defer wg.Done()
sem <- struct{}{}
defer func() { <-sem }()
c := opportunities.ExtractDeterministic(text)
_ = opportunities.ExtractTables(text)
if leak != nil {
// THE PLANTED DEFECT: hold on to everything, INCLUDING COPIES OF THE TEXT. Retaining the
// chunk structs alone was not enough signal, because Go substrings share the source string's
// backing array and that array is live in both arms anyway. Copying the text is also the
// realistic shape of this leak: a cache that keeps extracted content per document.
cl := make([]opportunities.Chunk, len(c))
for j := range c {
cl[j] = c[j]
cl[j].Text = strings.Clone(c[j].Text)
}
mu.Lock()
*leak = append(*leak, cl)
mu.Unlock()
}
}()
}
wg.Wait()
// Measured AFTER a collection, so what remains is what is still REACHABLE. Retained chunks survive the
// sweep; discarded ones do not, which is the whole difference this profile exists to see.
after := heapKB()
if after < baseline {
return 0
}
return after - baseline
}
serialKB := measure(1, nil)
var leak [][]opportunities.Chunk
var concurrentKB uint64
if control {
concurrentKB = measure(docs, &leak)
runtime.KeepAlive(leak)
} else {
concurrentKB = measure(docs, nil)
}
log.Printf("concurrent-extract: %d documents of %d pages, %d bytes each. Retained heap growth: serial "+
"%d KB, concurrent %d KB. Cap %d KB.",
docs, pagesEach, len(text), serialKB, concurrentKB, growthCapKB)
if control {
// THE CONTROL MUST FAIL BECAUSE THE MEASUREMENT MOVED, not because this branch chose to return an
// error. If retaining 25 documents of chunks does not push retained growth past the cap, then the
// assertion cannot detect a real leak either, and the counted run below would prove nothing.
if concurrentKB <= growthCapKB {
return nil // the caller reports this as a CONTROL FAILURE, which is the correct outcome
}
return fmt.Errorf("planted retention of %d documents left %d KB of reachable heap, past the %d KB cap",
len(leak), concurrentKB, growthCapKB)
}
if concurrentKB > growthCapKB {
return fmt.Errorf("after extracting %d documents concurrently, %d KB remained reachable, over the %d KB "+
"cap, so extraction is not memory bounded", docs, concurrentKB, growthCapKB)
}
return nil
}
// scrubFloodProfile floods the egress gate with a mixed stream of payloads, some public and some carrying
// private data, and asserts that ZERO private items are routed outward. This is the profile that protects the
// external boundary, so its failure mode is the most serious one in the phase.
//
// THE CONTROL plants a payload the gate is known to allow and asserts it IS allowed, then plants a private one
// and asserts it is refused. A gate that refused everything would score a perfect zero misroutes while being
// completely broken, and that is the failure this control exists to distinguish.
func scrubFloodProfile(control bool) error {
// Private payloads, each private for a DIFFERENT reason, because a gate that only catches emails is not a
// gate. These mirror the fixtures in internal/platform/scrub.
private := []struct {
name string
prov scrub.Provenance
body string
}{
{"candidate row with identifiers", scrub.ProvenanceTenantRecord,
`{"full_name":"Dana Whitfield","email":"dana@example.com","clearance":"TS/SCI"}`},
{"candidate row stripped", scrub.ProvenanceTenantRecord,
`Dana Whitfield, TS/SCI with CI polygraph, 12 years, Reston Virginia`},
{"tenant uploaded document text", scrub.ProvenanceTenantUpload,
`SECTION C.3.2 the contractor shall monitor the two unadvertised sites in Attachment J-7`},
{"tenant uuid in the body", scrub.ProvenancePublicCache,
`normalize this scope for candidate 11111111-1111-1111-1111-111111111111`},
}
public := []struct {
name string
prov scrub.Provenance
body string
}{
{"public notice text", scrub.ProvenancePublicCache,
`Solicitation W912DY-26-R-0001 seeks cybersecurity support services for the Air Force.`},
}
classes := []scrub.EgressClass{
scrub.ClassPublicKnowledge, scrub.ClassPublicDataSummary,
scrub.ClassOntologySuggest, scrub.ClassRequirementNormalize,
}
const rounds = 500
misroutes := 0
falseRefusals := 0
checked := 0
// THE CONTROL PLANTS A PAYLOAD THAT THE GATE LEGITIMATELY ALLOWS into the set this profile treats as
// private. The misroute counter must therefore fire, which proves the counter and its assertion actually
// work. If they did not, a run reporting zero misroutes would be meaningless.
//
// THE FIRST VERSION OF THIS CONTROL WAS WRONG AND THE WAY IT WAS WRONG IS WORTH KEEPING. It laundered the
// CONTENT of every private payload while keeping its provenance, expecting all of them to stay refused. But
// one of the four is private only BECAUSE OF ITS CONTENT: a public cache payload carrying a candidate uuid.
// Stripping that uuid legitimately makes it allowable, so the control reported 125 misroutes and blamed the
// gate for behaving correctly. Privacy here has two distinct sources, provenance and markers, and a control
// that conflates them measures neither.
if control {
private = append(private, struct {
name string
prov scrub.Provenance
body string
}{"planted: a genuinely public payload counted as private", scrub.ProvenancePublicCache,
`Solicitation W912DY-26-R-0001 seeks cybersecurity support services.`})
}
for i := 0; i < rounds; i++ {
class := classes[i%len(classes)]
p := private[i%len(private)]
if err := scrub.AllowEgress([]scrub.Provenance{p.prov}, class, []byte(p.body)); err == nil {
misroutes++
}
checked++
pub := public[i%len(public)]
if err := scrub.AllowEgress([]scrub.Provenance{pub.prov}, class, []byte(pub.body)); err != nil {
falseRefusals++
}
checked++
}
log.Printf("scrub-flood: %d checks over %d rounds, %d private misroutes, %d public false refusals",
checked, rounds, misroutes, falseRefusals)
if control {
if misroutes == 0 {
// The planted allowable payload was NOT counted, so the misroute counter does not fire even when
// something passes the gate. Returning nil makes the caller report a CONTROL FAILURE, correctly.
return nil
}
return fmt.Errorf("the planted allowable payload was counted as a misroute %d time(s), so the counter "+
"and its assertion both fire", misroutes)
}
if misroutes > 0 {
return fmt.Errorf("%d private payload(s) left the local plane, which is the one failure this gate "+
"exists to prevent", misroutes)
}
if falseRefusals > 0 {
// A GATE THAT REFUSES EVERYTHING scores zero misroutes and is broken. This is the assertion that
// distinguishes a working gate from a closed pipe.
return fmt.Errorf("%d legitimate public payload(s) were refused, so the zero misroute result above "+
"could be a closed pipe rather than a working gate", falseRefusals)
}
return nil
}