Skip to main content

mockforge_bench/
executor.rs

1//! k6 execution and output handling
2
3use crate::error::{BenchError, Result};
4use indicatif::{ProgressBar, ProgressStyle};
5use std::path::Path;
6use std::process::Stdio;
7use std::sync::Arc;
8use tokio::io::{AsyncBufReadExt, BufReader};
9use tokio::process::Command as TokioCommand;
10
11/// Extract a `MOCKFORGE_<KIND>:` JSON payload from a k6 output line.
12///
13/// k6 emits these via `console.log`, which goes through one of two paths
14/// depending on the runner config:
15/// - **Raw**: `MOCKFORGE_EXCHANGE:{"check":"...", ...}` straight to stdout.
16/// - **Logfmt**: `time="..." level=info msg="MOCKFORGE_EXCHANGE:{...}" source=console`
17///   where the JSON's `"` are escaped as `\"` and `\` as `\\` so it fits
18///   inside the `msg="..."` field.
19///
20/// Round 46 (#79) — Srikanth on 0.3.190: a multipart upload landed `[]`
21/// in `conformance-requests.json` even though `MOCKFORGE_EXCHANGE:` was
22/// present in the k6 log. Root cause: the previous parser used a naive
23/// `replace("\\\\", "\\").replace("\\\"", "\"")` chain. With binary
24/// multipart bytes the JSON content includes sequences like `\\"`
25/// (literal backslash followed by literal quote inside a JSON string),
26/// which logfmt-escapes to `\\\\\"`. The replace chain processed `\\`
27/// → `\` first, leaving `\\\"`, then `\"` → `"`, mangling the JSON.
28/// Replaced with a single character walk that consumes one logfmt
29/// escape at a time. Also rewrote the suffix-strip to scan for the
30/// matching closing `"` of the `msg="..."` field instead of a
31/// fixed-string suffix so we tolerate any trailing logfmt fields k6
32/// might add.
33fn extract_mockforge_marker_json(line: &str, marker: &str) -> Option<String> {
34    let start = line.find(marker)?;
35    let json_start = start + marker.len();
36    let rest = &line[json_start..];
37
38    // Is this the logfmt-wrapped form? The `msg="` opener sits 5 bytes
39    // before the marker. (Plain `msg=MOCKFORGE_...` would also be valid
40    // logfmt for a value with no spaces, but k6 always quote-wraps.)
41    let is_logfmt = start >= 5 && line.as_bytes().get(start - 5..start) == Some(b"msg=\"");
42    if is_logfmt {
43        // Walk forward until the unescaped closing `"` of msg=. Inside
44        // the field, `\\` is one escaped backslash and `\"` is one
45        // escaped quote — those bytes belong to the JSON content. Any
46        // unescaped `"` is the field terminator.
47        let bytes = rest.as_bytes();
48        let mut i = 0;
49        let mut out = String::with_capacity(rest.len());
50        while i < bytes.len() {
51            let b = bytes[i];
52            if b == b'"' {
53                // End of msg= field.
54                return Some(out);
55            }
56            if b == b'\\' && i + 1 < bytes.len() {
57                let next = bytes[i + 1];
58                match next {
59                    b'"' => out.push('"'),
60                    b'\\' => out.push('\\'),
61                    // Other escapes (`\n`, `\r`, `\t`, `\uXXXX`) are
62                    // PART of the JSON content — keep them verbatim so
63                    // serde_json::from_str interprets them.
64                    other => {
65                        out.push('\\');
66                        out.push(other as char);
67                    }
68                }
69                i += 2;
70                continue;
71            }
72            // Non-ASCII multi-byte UTF-8 codepoint or plain ASCII char.
73            // `rest` is a `&str` so we can rely on UTF-8 boundaries.
74            let ch_start = i;
75            // Advance i past the codepoint.
76            i += 1;
77            while i < bytes.len() && (bytes[i] & 0b1100_0000) == 0b1000_0000 {
78                i += 1;
79            }
80            out.push_str(&rest[ch_start..i]);
81        }
82        // Reached EOL without a closing quote — return what we have so
83        // the downstream parser can decide whether to keep it.
84        if out.is_empty() {
85            None
86        } else {
87            Some(out)
88        }
89    } else {
90        // Raw form: rest of the line is the JSON, possibly with trailing
91        // whitespace. No escape processing needed.
92        let trimmed = rest.trim();
93        if trimmed.is_empty() {
94            None
95        } else {
96            Some(trimmed.to_string())
97        }
98    }
99}
100
101/// Extract `MOCKFORGE_EXCHANGE:` JSON payload from a k6 output line (--export-requests).
102fn extract_exchange_json(line: &str) -> Option<String> {
103    extract_mockforge_marker_json(line, "MOCKFORGE_EXCHANGE:")
104}
105
106/// Extract `MOCKFORGE_FAILURE:` JSON payload from a k6 output line.
107fn extract_failure_json(line: &str) -> Option<String> {
108    extract_mockforge_marker_json(line, "MOCKFORGE_FAILURE:")
109}
110
111/// Round 47 (#79) — extract `MOCKFORGE_NETWORK_EVENT:` JSON payload.
112/// Emitted by the k6 captureExchange when `res.status === 0`, capturing
113/// the wire-level failure with a classified `kind`.
114fn extract_network_event_json(line: &str) -> Option<String> {
115    extract_mockforge_marker_json(line, "MOCKFORGE_NETWORK_EVENT:")
116}
117
118/// Merge `http2client=0` into `GODEBUG` without clobbering other flags.
119///
120/// Round 63 (#79) / grafana/k6#2222: k6 has no per-request HTTP/1.1 API.
121/// An explicit `http2client=` already in the environment is left alone.
122pub(crate) fn merge_godebug_http2client_off(existing: Option<&str>) -> String {
123    const FLAG: &str = "http2client=0";
124    let existing = existing.unwrap_or("").trim();
125    if existing.is_empty() {
126        return FLAG.to_string();
127    }
128    if existing.split(',').any(|part| part.trim().starts_with("http2client=")) {
129        return existing.to_string();
130    }
131    format!("{existing},{FLAG}")
132}
133
134/// k6 executor
135static K6_EGRESS_PROXY: std::sync::OnceLock<String> = std::sync::OnceLock::new();
136
137/// Route every k6 process this crate starts through `proxy_url` (an
138/// `http://host:port` forward proxy). The cloud runner installs this from
139/// `MOCKFORGE_RUNNER_K6_EGRESS_PROXY`. Returns `false` if already set.
140pub fn install_k6_egress_proxy(proxy_url: String) -> bool {
141    K6_EGRESS_PROXY.set(proxy_url).is_ok()
142}
143
144/// The proxy installed by [`install_k6_egress_proxy`], if any.
145pub fn k6_egress_proxy() -> Option<&'static str> {
146    K6_EGRESS_PROXY.get().map(String::as_str)
147}
148
149/// Environment for a k6 child process.
150///
151/// No guard and no proxy (the CLI): nothing is added. A proxy: k6 sends
152/// http and https through it (Go's `ProxyFromEnvironment`), with `NO_PROXY`
153/// cleared so nothing is exempted, and redirects off. Go never proxies a
154/// literal loopback or `localhost` URL, and the target itself is
155/// pre-checked, so a redirect is the only way k6 could reach one;
156/// `K6_MAX_REDIRECTS=0` removes it. A guard without a proxy: refuse, since
157/// k6 would then reach any address it resolves.
158pub fn k6_egress_env(
159    guard: Option<crate::ssrf::Policy>,
160    proxy: Option<&str>,
161) -> Result<Vec<(&'static str, String)>> {
162    match (guard, proxy) {
163        (_, Some(proxy)) => Ok(vec![
164            ("HTTP_PROXY", proxy.to_string()),
165            ("HTTPS_PROXY", proxy.to_string()),
166            ("http_proxy", proxy.to_string()),
167            ("https_proxy", proxy.to_string()),
168            ("NO_PROXY", String::new()),
169            ("no_proxy", String::new()),
170            ("K6_MAX_REDIRECTS", "0".to_string()),
171            // k6 otherwise phones home to stats.grafana.org on every run.
172            ("K6_NO_USAGE_REPORT", "true".to_string()),
173        ]),
174        (Some(_), None) => Err(BenchError::K6ExecutionFailed(
175            "k6 refused: SSRF guard is active and no k6 egress proxy is configured".to_string(),
176        )),
177        (None, None) => Ok(Vec::new()),
178    }
179}
180
181pub struct K6Executor {
182    k6_path: String,
183    /// Comma-joined IPs/ranges/CIDRs forwarded to `k6 run --local-ips`.
184    /// Empty → flag omitted. Populated by callers that pass through the
185    /// CLI's `--source-ip`; lets a VU make requests from one of several
186    /// bound interfaces (k6 supports this natively, contrary to my
187    /// round-22 warning).
188    local_ips: String,
189    /// Round 56 (#79) — when true, set `K6_DISCARD_RESPONSE_BODIES=true` so k6
190    /// does not buffer every response body in memory. On long, high-concurrency
191    /// multi-target runs (Srikanth on 0.3.203 saw `k6 ... signal: 9 (SIGKILL)`,
192    /// i.e. the OOM killer) the buffered bodies plus k6's own metric
193    /// accumulation exhaust RAM. Plain load only checks status codes, so
194    /// dropping the bodies is safe there.
195    discard_response_bodies: bool,
196    /// Round 61 (#79) — value for `k6 run --dns "policy=<...>"`. Empty → flag
197    /// omitted (k6 default `preferIPv4`). Srikanth on 0.3.208 GEODB-tests a WAF
198    /// via hostnames (his proxy routes by Host/SNI, so he can't pass bracket
199    /// IPs), but needs those hostnames resolved to their AAAA/IPv6 record;
200    /// k6/Go default to IPv4, which then can't be dialed from his IPv6
201    /// `--local-ips` source ("no suitable address found"). `preferIPv6` /
202    /// `onlyIPv6` fix that while keeping the hostname on the wire.
203    dns_policy: String,
204    /// Round 63 (#79) — set `GODEBUG=http2client=0` so k6/Go does not
205    /// ALPN-negotiate HTTP/2. HTTP/2 forbids `Connection`; WAF hop-by-hop
206    /// cases must keep that header. grafana/k6#2222: no per-request HTTP/1.1
207    /// API, process-wide GODEBUG is the workaround.
208    force_http1: bool,
209    /// Round 67 (#79) — when false, do not buffer every k6 stdout/stderr
210    /// line and do not write `k6-output.log` or the automatic detail
211    /// sidecars (`conformance-failure-details.json`,
212    /// `conformance-network-events.json`). Srikanth's 24–48h
213    /// `--repeat-until` campaigns wrote a full k6 output dump per
214    /// round × target and filled the disk. `summary.json` (needed for
215    /// results) and an explicitly-requested `--export-requests` dump are
216    /// unaffected.
217    capture_logs: bool,
218}
219
220impl K6Executor {
221    /// Create a new k6 executor
222    pub fn new() -> Result<Self> {
223        let k6_path = which::which("k6")
224            .map_err(|_| BenchError::K6NotFound)?
225            .to_string_lossy()
226            .to_string();
227
228        Ok(Self {
229            k6_path,
230            local_ips: String::new(),
231            discard_response_bodies: false,
232            dns_policy: String::new(),
233            force_http1: false,
234            capture_logs: true,
235        })
236    }
237
238    /// Set the `--local-ips` value for subsequent k6 invocations.
239    /// Accepts a comma-joined list of IPs, ranges (`10.0.0.1-10.0.0.5`),
240    /// and/or CIDRs (`192.168.0.0/24`) - same syntax k6 expects.
241    pub fn with_local_ips(mut self, local_ips: impl Into<String>) -> Self {
242        self.local_ips = local_ips.into();
243        self
244    }
245
246    /// Round 56 (#79) — enable `K6_DISCARD_RESPONSE_BODIES` so k6 does not hold
247    /// response bodies in memory. Use for plain load runs (status-only checks);
248    /// do NOT use where the script inspects/extracts response bodies.
249    pub fn with_discard_response_bodies(mut self, discard: bool) -> Self {
250        self.discard_response_bodies = discard;
251        self
252    }
253
254    /// Round 61 (#79) — set the `--dns` resolution policy (e.g. `preferIPv6`,
255    /// `onlyIPv6`, `preferIPv4`, `onlyIPv4`, `any`). Empty string → flag omitted
256    /// (k6 default). Passed to k6 as `--dns "policy=<value>"`.
257    pub fn with_dns_policy(mut self, policy: impl Into<String>) -> Self {
258        self.dns_policy = policy.into();
259        self
260    }
261
262    /// Round 63 (#79) — force HTTP/1.1 for this k6 process via
263    /// `GODEBUG=http2client=0`. Use when the script sets a `Connection`
264    /// header or when `--wafbench-verbatim` is on.
265    pub fn with_force_http1(mut self, force: bool) -> Self {
266        self.force_http1 = force;
267        self
268    }
269
270    /// Round 67 (#79) — pass `false` to skip writing `k6-output.log` and the
271    /// automatic detail sidecars, and to stop buffering k6's whole output in
272    /// memory. Use for long campaigns where per-run logs outgrow the disk.
273    /// `summary.json` and `--export-requests` output still write.
274    pub fn with_capture_logs(mut self, capture: bool) -> Self {
275        self.capture_logs = capture;
276        self
277    }
278
279    /// `GODEBUG` value this executor will set, or `None` when HTTP/2 is left
280    /// alone. Used by tests; `execute_with_port` applies the same string.
281    #[cfg(test)]
282    pub(crate) fn godebug_env_value(&self) -> Option<String> {
283        if !self.force_http1 {
284            return None;
285        }
286        Some(merge_godebug_http2client_off(std::env::var("GODEBUG").ok().as_deref()))
287    }
288
289    /// Check if k6 is installed
290    pub fn is_k6_installed() -> bool {
291        which::which("k6").is_ok()
292    }
293
294    /// Warn when the installed k6 predates the 1.x semantics this crate
295    /// relies on (#860): `constant-arrival-rate` executor behaviour and the
296    /// JSON-summary keys that stabilised in 1.x. Best-effort — a missing or
297    /// unparsable `k6 version` never blocks a run.
298    pub async fn warn_if_pre_v1() {
299        const DOCS: &str =
300            "See https://docs.mockforge.dev/reference/bench-capacity-sizing.html#tooling-requirements";
301        let output = match TokioCommand::new("k6").arg("version").output().await {
302            Ok(o) if o.status.success() => o,
303            _ => return,
304        };
305        let stdout = String::from_utf8_lossy(&output.stdout);
306        let Some(major) = stdout
307            .split_whitespace()
308            .find_map(|t| t.strip_prefix('v'))
309            .and_then(|rest| rest.split('.').next())
310            .and_then(|major| major.parse::<u64>().ok())
311        else {
312            return;
313        };
314        if major < 1 {
315            crate::reporter::TerminalReporter::print_warning(&format!(
316                "Detected k6 {}.x; mockforge bench requires k6 >= 1.0.0 \
317                 (older versions break executors and summary parsing). Upgrade k6. {DOCS}",
318                major
319            ));
320        }
321    }
322
323    /// Get k6 version
324    pub async fn get_version(&self) -> Result<String> {
325        let output = TokioCommand::new(&self.k6_path)
326            .arg("version")
327            .output()
328            .await
329            .map_err(|e| BenchError::K6ExecutionFailed(e.to_string()))?;
330
331        if !output.status.success() {
332            return Err(BenchError::K6ExecutionFailed("Failed to get k6 version".to_string()));
333        }
334
335        Ok(String::from_utf8_lossy(&output.stdout).trim().to_string())
336    }
337
338    /// Execute a k6 script.
339    ///
340    /// `api_port` — when set, overrides k6's default API server address (`localhost:6565`)
341    /// to `localhost:<api_port>`. This prevents "address already in use" errors when
342    /// running multiple k6 instances in parallel (e.g., multi-target bench).
343    /// Pass `Some(0)` to bind an OS-assigned ephemeral port — the collision-proof
344    /// choice for parallel runs, since the kernel never hands out a busy port
345    /// (see the k6 `CannotStartRESTAPI` / exit-106 fix in `parallel_executor`).
346    /// Pass `None` for single-target runs (uses k6's default `localhost:6565`).
347    pub async fn execute(
348        &self,
349        script_path: &Path,
350        output_dir: Option<&Path>,
351        verbose: bool,
352    ) -> Result<K6Results> {
353        self.execute_with_port(script_path, output_dir, verbose, None).await
354    }
355
356    /// Execute a k6 script with an optional custom API server port.
357    pub async fn execute_with_port(
358        &self,
359        script_path: &Path,
360        output_dir: Option<&Path>,
361        verbose: bool,
362        api_port: Option<u16>,
363    ) -> Result<K6Results> {
364        println!("Starting load test...\n");
365
366        // Cloud runner containment. k6 resolves names and follows redirects
367        // itself, so the SSRF pre-check cannot bind it; under a process guard
368        // it may only run through an egress proxy that enforces the IP policy
369        // after DNS resolution.
370        let egress_env = k6_egress_env(crate::ssrf::process_guard(), k6_egress_proxy())?;
371
372        let mut cmd = TokioCommand::new(&self.k6_path);
373        cmd.arg("run");
374        cmd.envs(egress_env);
375
376        // When running multiple k6 instances in parallel, each needs its own API server port
377        // to avoid "bind: address already in use" on the default port 6565.
378        if let Some(port) = api_port {
379            cmd.arg("--address").arg(format!("localhost:{}", port));
380        }
381
382        // `--local-ips` rotates each VU through a pool of source IPs that
383        // must already be bound on the host (CIDRs/ranges accepted). This
384        // gives the k6 path the same source-IP coverage as the native
385        // self-test driver's `--source-ip`.
386        if !self.local_ips.is_empty() {
387            cmd.arg("--local-ips").arg(&self.local_ips);
388        }
389
390        // Round 56 (#79) — drop response bodies to bound k6's memory on long,
391        // high-concurrency runs (guards against the SIGKILL/OOM Srikanth hit).
392        if self.discard_response_bodies {
393            cmd.env("K6_DISCARD_RESPONSE_BODIES", "true");
394        }
395
396        // Round 63 (#79) — disable the Go HTTP/2 client so WAF `Connection`
397        // headers are not rejected as `http2: invalid Connection request
398        // header`. Merge with an existing GODEBUG rather than clobbering it.
399        if self.force_http1 {
400            let existing = std::env::var("GODEBUG").ok();
401            cmd.env("GODEBUG", merge_godebug_http2client_off(existing.as_deref()));
402        }
403
404        // Round 61 (#79) — force a DNS resolution policy so hostname targets can
405        // be pinned to IPv6 (or IPv4). Needed for GEODB IPv6 tests where the
406        // proxy routes by Host/SNI (so the target must stay a hostname) but the
407        // dial has to use the AAAA record to match an IPv6 `--local-ips` source.
408        if !self.dns_policy.is_empty() {
409            cmd.arg("--dns").arg(format!("policy={}", self.dns_policy));
410        }
411
412        // summary.json is written by the k6 script's handleSummary() function
413        // (relative to CWD, set to output_dir below). We no longer use
414        // --summary-export as it's deprecated in newer k6 versions and
415        // conflicts with handleSummary when both try to write the same file.
416
417        // Add verbosity
418        if verbose {
419            cmd.arg("--verbose");
420        }
421
422        // Use absolute path for the script so it's found regardless of CWD.
423        let abs_script =
424            std::fs::canonicalize(script_path).unwrap_or_else(|_| script_path.to_path_buf());
425        cmd.arg(&abs_script);
426
427        // Set working directory to output dir so handleSummary's relative
428        // "summary.json" path lands next to the script.
429        if let Some(dir) = output_dir {
430            cmd.current_dir(dir);
431        }
432
433        cmd.stdout(Stdio::piped());
434        cmd.stderr(Stdio::piped());
435
436        let mut child = cmd.spawn().map_err(|e| BenchError::K6ExecutionFailed(e.to_string()))?;
437
438        let stdout = child
439            .stdout
440            .take()
441            .ok_or_else(|| BenchError::K6ExecutionFailed("Failed to capture stdout".to_string()))?;
442
443        let stderr = child
444            .stderr
445            .take()
446            .ok_or_else(|| BenchError::K6ExecutionFailed("Failed to capture stderr".to_string()))?;
447
448        // Stream output
449        let stdout_reader = BufReader::new(stdout);
450        let stderr_reader = BufReader::new(stderr);
451
452        let mut stdout_lines = stdout_reader.lines();
453        let mut stderr_lines = stderr_reader.lines();
454
455        // Create progress indicator
456        let spinner = ProgressBar::new_spinner();
457        spinner.set_style(
458            ProgressStyle::default_spinner().template("{spinner:.green} {msg}").unwrap(),
459        );
460        spinner.set_message("Running load test...");
461
462        // Collect failure details from k6's console.log output
463        // k6 may emit console.log to either stdout or stderr depending on version/config
464        let failure_details: Arc<tokio::sync::Mutex<Vec<String>>> =
465            Arc::new(tokio::sync::Mutex::new(Vec::new()));
466        let fd_stdout = Arc::clone(&failure_details);
467        let fd_stderr = Arc::clone(&failure_details);
468
469        // Collect request/response exchanges for --export-requests
470        let exchange_details: Arc<tokio::sync::Mutex<Vec<String>>> =
471            Arc::new(tokio::sync::Mutex::new(Vec::new()));
472        let ex_stdout = Arc::clone(&exchange_details);
473        let ex_stderr = Arc::clone(&exchange_details);
474
475        // Round 47 (#79) — collect wire-level network events the
476        // k6 script emits on status=0 (connect / tls / timeout). Same
477        // shape as the native + self-test sinks so we can write a
478        // unified `conformance-network-events.json`.
479        let network_events: Arc<tokio::sync::Mutex<Vec<String>>> =
480            Arc::new(tokio::sync::Mutex::new(Vec::new()));
481        let ne_stdout = Arc::clone(&network_events);
482        let ne_stderr = Arc::clone(&network_events);
483
484        // Collect all k6 output for saving to a log file
485        let log_lines: Arc<tokio::sync::Mutex<Vec<String>>> =
486            Arc::new(tokio::sync::Mutex::new(Vec::new()));
487        let log_stdout = Arc::clone(&log_lines);
488        let log_stderr = Arc::clone(&log_lines);
489
490        // Round 67 (#79): when capture_logs is off, lines are drained (k6's
491        // pipes must be emptied or it blocks) and echoed, but nothing is
492        // buffered for the on-disk log / detail sidecars.
493        let capture_logs = self.capture_logs;
494        let capture_stdout = capture_logs;
495        let capture_stderr = capture_logs;
496
497        // Read stdout lines, capturing MOCKFORGE_FAILURE / MOCKFORGE_EXCHANGE / MOCKFORGE_NETWORK_EVENT markers
498        let stdout_handle = tokio::spawn(async move {
499            while let Ok(Some(line)) = stdout_lines.next_line().await {
500                if capture_stdout {
501                    log_stdout.lock().await.push(format!("[stdout] {}", line));
502                }
503                if let Some(json_str) = extract_failure_json(&line) {
504                    if capture_stdout {
505                        fd_stdout.lock().await.push(json_str);
506                    }
507                } else if let Some(json_str) = extract_exchange_json(&line) {
508                    ex_stdout.lock().await.push(json_str);
509                } else if let Some(json_str) = extract_network_event_json(&line) {
510                    if capture_stdout {
511                        ne_stdout.lock().await.push(json_str);
512                    }
513                } else {
514                    spinner.set_message(line.clone());
515                    if !line.is_empty() && !line.contains("running") && !line.contains("default") {
516                        println!("{}", line);
517                    }
518                }
519            }
520            spinner.finish_and_clear();
521        });
522
523        // Read stderr lines, capturing MOCKFORGE_FAILURE / MOCKFORGE_EXCHANGE / MOCKFORGE_NETWORK_EVENT markers
524        let stderr_handle = tokio::spawn(async move {
525            while let Ok(Some(line)) = stderr_lines.next_line().await {
526                if !line.is_empty() {
527                    if capture_stderr {
528                        log_stderr.lock().await.push(format!("[stderr] {}", line));
529                    }
530                    if let Some(json_str) = extract_failure_json(&line) {
531                        if capture_stderr {
532                            fd_stderr.lock().await.push(json_str);
533                        }
534                    } else if let Some(json_str) = extract_exchange_json(&line) {
535                        ex_stderr.lock().await.push(json_str);
536                    } else if let Some(json_str) = extract_network_event_json(&line) {
537                        if capture_stderr {
538                            ne_stderr.lock().await.push(json_str);
539                        }
540                    } else {
541                        eprintln!("{}", line);
542                    }
543                }
544            }
545        });
546
547        // Wait for completion
548        let status =
549            child.wait().await.map_err(|e| BenchError::K6ExecutionFailed(e.to_string()))?;
550
551        // Wait for both reader tasks to finish processing all lines
552        let _ = stdout_handle.await;
553        let _ = stderr_handle.await;
554
555        // k6 exit code 99 = thresholds crossed. The test DID run and summary.json
556        // should still be present. Only treat non-99 failures as hard errors.
557        //
558        // Round 65 (#79): when the OS OOM-kills k6, `ExitStatus::code()` is
559        // None and Unix reports signal 9 (SIGKILL). Surface that hint so the
560        // next run uses --no-per-op-metrics / lower --max-concurrency /
561        // --discard-response-bodies instead of chasing a phantom k6 bug.
562        let exit_code = status.code().unwrap_or(-1);
563        if !status.success() && exit_code != 99 {
564            let oom_hint = {
565                #[cfg(unix)]
566                {
567                    use std::os::unix::process::ExitStatusExt;
568                    if status.signal() == Some(9) {
569                        " — process received SIGKILL (signal 9). This is usually the \
570                         Linux OOM killer, not a k6 bug. For huge OpenAPI specs or \
571                         multi-hour longevity runs: pass --no-per-op-metrics, lower \
572                         --max-concurrency, and/or --discard-response-bodies; ensure \
573                         the client has enough RAM (see docs.mockforge.dev/reference/\
574                         bench-capacity-sizing.html)."
575                    } else {
576                        ""
577                    }
578                }
579                #[cfg(not(unix))]
580                {
581                    ""
582                }
583            };
584            return Err(BenchError::K6ExecutionFailed(format!(
585                "k6 exited with status: {}{}",
586                status, oom_hint
587            )));
588        }
589        if exit_code == 99 {
590            tracing::warn!("k6 thresholds crossed (exit code 99) — results will still be parsed");
591        }
592
593        // Write failure details to file if any were captured
594        if let Some(dir) = output_dir {
595            if capture_logs {
596                let details = failure_details.lock().await;
597                if !details.is_empty() {
598                    let failure_path = dir.join("conformance-failure-details.json");
599                    let parsed: Vec<serde_json::Value> =
600                        details.iter().filter_map(|s| serde_json::from_str(s).ok()).collect();
601                    if let Ok(json) = serde_json::to_string_pretty(&parsed) {
602                        let _ = std::fs::write(&failure_path, json);
603                    }
604                }
605            }
606
607            // Write exchange details (--export-requests) if any were captured.
608            // Deliberately NOT gated on capture_logs: --export-requests is an
609            // explicit output request, not an automatic debug sidecar.
610            let exchanges = exchange_details.lock().await;
611            if !exchanges.is_empty() {
612                let exchange_path = dir.join("conformance-requests.json");
613                let parsed: Vec<serde_json::Value> =
614                    exchanges.iter().filter_map(|s| serde_json::from_str(s).ok()).collect();
615                if let Ok(json) = serde_json::to_string_pretty(&parsed) {
616                    let _ = std::fs::write(&exchange_path, json);
617                    tracing::info!(
618                        "Exported {} request/response pairs to {}",
619                        parsed.len(),
620                        exchange_path.display()
621                    );
622                }
623            }
624
625            if capture_logs {
626                // Round 47 (#79) — write the wire-level events sink. We
627                // ALWAYS write the file (empty array when nothing failed)
628                // so a caller can tell "everything succeeded" from "nobody
629                // looked" at a glance. (Round 67: skipped under
630                // --no-k6-logs, where the caller opted out of per-run
631                // artifacts entirely.)
632                let net_events = network_events.lock().await;
633                let net_path = dir.join("conformance-network-events.json");
634                let parsed: Vec<serde_json::Value> =
635                    net_events.iter().filter_map(|s| serde_json::from_str(s).ok()).collect();
636                if let Ok(json) = serde_json::to_string_pretty(&parsed) {
637                    let _ = std::fs::write(&net_path, json);
638                    if !parsed.is_empty() {
639                        tracing::warn!(
640                            "Recorded {} wire-level network event(s) to {}",
641                            parsed.len(),
642                            net_path.display()
643                        );
644                    }
645                }
646
647                // Save full k6 output to a log file for debugging
648                let lines = log_lines.lock().await;
649                if !lines.is_empty() {
650                    let log_path = dir.join("k6-output.log");
651                    let _ = std::fs::write(&log_path, lines.join("\n"));
652                    println!("k6 output log saved to: {}", log_path.display());
653                }
654            }
655        }
656
657        // Parse results if output directory was specified
658        let results = if let Some(dir) = output_dir {
659            Self::parse_results(dir)?
660        } else {
661            K6Results::default()
662        };
663
664        Ok(results)
665    }
666
667    /// Parse k6 results from JSON output
668    fn parse_results(output_dir: &Path) -> Result<K6Results> {
669        let summary_path = output_dir.join("summary.json");
670
671        if !summary_path.exists() {
672            return Ok(K6Results::default());
673        }
674
675        let content = std::fs::read_to_string(summary_path)
676            .map_err(|e| BenchError::ResultsParseError(e.to_string()))?;
677
678        let json: serde_json::Value = serde_json::from_str(&content)
679            .map_err(|e| BenchError::ResultsParseError(e.to_string()))?;
680
681        let duration_values = &json["metrics"]["http_req_duration"]["values"];
682
683        let server_latency = &json["metrics"]["mockforge_server_injected_latency_ms"]["values"];
684        let server_jitter = &json["metrics"]["mockforge_server_injected_jitter_ms"]["values"];
685        let server_fault = &json["metrics"]["mockforge_server_fault_total"]["values"]["count"];
686
687        // Issue #79 (round 5) — surface TCP connect / TLS handshake stats and
688        // a connection-rate count for `--cps` runs.
689        //
690        // Round 6 follow-up: k6's `http_req_connecting` Trend doesn't expose a
691        // `count` field in summary.json (only avg/min/med/max/p90/p95), so we
692        // can't use it for "connections opened". The template now feeds a
693        // dedicated Counter, `mockforge_connections_opened`, every time a
694        // request's `res.timings.connecting > 0`. That gives us an accurate
695        // count for both `--cps` (≈ total_requests) and pooled-reuse (≈ vus_max)
696        // runs. The Trend is still useful for the avg/max timing display.
697        let tcp_connecting = &json["metrics"]["http_req_connecting"]["values"];
698        let tls_handshake = &json["metrics"]["http_req_tls_handshaking"]["values"];
699        let mf_conns_opened = &json["metrics"]["mockforge_connections_opened"]["values"]["count"];
700
701        Ok(K6Results {
702            total_requests: json["metrics"]["http_reqs"]["values"]["count"].as_u64().unwrap_or(0),
703            // k6 Rate metric: `passes` = count of non-zero values.
704            // For http_req_failed, non-zero means the request failed.
705            // So `passes` = failed request count, `fails` = successful request count.
706            failed_requests: json["metrics"]["http_req_failed"]["values"]["passes"]
707                .as_u64()
708                .unwrap_or(0),
709            avg_duration_ms: duration_values["avg"].as_f64().unwrap_or(0.0),
710            p95_duration_ms: duration_values["p(95)"].as_f64().unwrap_or(0.0),
711            p99_duration_ms: duration_values["p(99)"].as_f64().unwrap_or(0.0),
712            rps: json["metrics"]["http_reqs"]["values"]["rate"].as_f64().unwrap_or(0.0),
713            vus_max: json["metrics"]["vus_max"]["values"]["value"].as_u64().unwrap_or(0) as u32,
714            min_duration_ms: duration_values["min"].as_f64().unwrap_or(0.0),
715            max_duration_ms: duration_values["max"].as_f64().unwrap_or(0.0),
716            med_duration_ms: duration_values["med"].as_f64().unwrap_or(0.0),
717            p90_duration_ms: duration_values["p(90)"].as_f64().unwrap_or(0.0),
718            server_injected_latency_samples: server_latency["count"].as_u64().unwrap_or(0),
719            server_injected_latency_avg_ms: server_latency["avg"].as_f64().unwrap_or(0.0),
720            server_injected_latency_max_ms: server_latency["max"].as_f64().unwrap_or(0.0),
721            server_injected_jitter_samples: server_jitter["count"].as_u64().unwrap_or(0),
722            server_injected_jitter_avg_ms: server_jitter["avg"].as_f64().unwrap_or(0.0),
723            server_reported_faults: server_fault.as_u64().unwrap_or(0),
724            // Counter from the template, not the Trend's count (which is
725            // absent in k6 summary JSON).
726            tcp_connect_samples: mf_conns_opened.as_u64().unwrap_or(0),
727            tcp_connect_avg_ms: tcp_connecting["avg"].as_f64().unwrap_or(0.0),
728            tcp_connect_max_ms: tcp_connecting["max"].as_f64().unwrap_or(0.0),
729            // TLS handshake Trend has no `count` either; gate display on avg>0.
730            tls_handshake_samples: if tls_handshake["avg"].as_f64().unwrap_or(0.0) > 0.0 {
731                // Use connection count as a proxy — every new TLS session
732                // requires a handshake.
733                mf_conns_opened.as_u64().unwrap_or(0)
734            } else {
735                0
736            },
737            tls_handshake_avg_ms: tls_handshake["avg"].as_f64().unwrap_or(0.0),
738            tls_handshake_max_ms: tls_handshake["max"].as_f64().unwrap_or(0.0),
739            iterations_completed: json["metrics"]["iterations"]["values"]["count"]
740                .as_u64()
741                .unwrap_or(0),
742        })
743    }
744}
745
746impl Default for K6Executor {
747    fn default() -> Self {
748        Self::new().expect("k6 not found")
749    }
750}
751
752/// k6 test results
753#[derive(Debug, Clone, Default, serde::Serialize, serde::Deserialize)]
754pub struct K6Results {
755    pub total_requests: u64,
756    pub failed_requests: u64,
757    pub avg_duration_ms: f64,
758    pub p95_duration_ms: f64,
759    pub p99_duration_ms: f64,
760    pub rps: f64,
761    pub vus_max: u32,
762    pub min_duration_ms: f64,
763    pub max_duration_ms: f64,
764    pub med_duration_ms: f64,
765    pub p90_duration_ms: f64,
766    /// Issue #79 — client-side visibility into MockForge-injected latency,
767    /// parsed from the `X-Mockforge-Injected-Latency-Ms` response header that
768    /// the chaos middleware sets. Zero when chaos isn't firing or the target
769    /// isn't MockForge.
770    #[serde(default)]
771    pub server_injected_latency_samples: u64,
772    #[serde(default)]
773    pub server_injected_latency_avg_ms: f64,
774    #[serde(default)]
775    pub server_injected_latency_max_ms: f64,
776    #[serde(default)]
777    pub server_injected_jitter_samples: u64,
778    #[serde(default)]
779    pub server_injected_jitter_avg_ms: f64,
780    /// Count of responses that carried an `X-Mockforge-Fault` header.
781    #[serde(default)]
782    pub server_reported_faults: u64,
783    /// Issue #79 (round 5) — TCP connect samples / timing. With `--cps`
784    /// (`noConnectionReuse: true`) k6 records one connect per request, so
785    /// `tcp_connect_samples` equals connections opened. Without `--cps` this
786    /// is typically a small count (k6 reuses pooled connections), so it tells
787    /// you whether reuse was actually happening.
788    #[serde(default)]
789    pub tcp_connect_samples: u64,
790    #[serde(default)]
791    pub tcp_connect_avg_ms: f64,
792    #[serde(default)]
793    pub tcp_connect_max_ms: f64,
794    /// TLS handshake samples / timing — same shape as TCP connect, but only
795    /// non-zero for HTTPS targets.
796    #[serde(default)]
797    pub tls_handshake_samples: u64,
798    #[serde(default)]
799    pub tls_handshake_avg_ms: f64,
800    #[serde(default)]
801    pub tls_handshake_max_ms: f64,
802    /// Issue #79 round 10 — k6 iteration counter from `iterations.values.count`.
803    /// For `constant-arrival-rate` (`--rps`), this is the number of full
804    /// iterations completed within the duration. When `iterations × num_ops`
805    /// is much less than `total_requests`, mid-iteration cancellation truncated
806    /// the run and not every operation in the spec was exercised.
807    #[serde(default)]
808    pub iterations_completed: u64,
809}
810
811impl K6Results {
812    /// Get error rate as a percentage
813    pub fn error_rate(&self) -> f64 {
814        if self.total_requests == 0 {
815            return 0.0;
816        }
817        (self.failed_requests as f64 / self.total_requests as f64) * 100.0
818    }
819
820    /// Get success rate as a percentage
821    pub fn success_rate(&self) -> f64 {
822        100.0 - self.error_rate()
823    }
824}
825
826#[cfg(test)]
827mod tests {
828    use super::*;
829
830    #[test]
831    fn test_k6_results_error_rate() {
832        let results = K6Results {
833            total_requests: 100,
834            failed_requests: 5,
835            avg_duration_ms: 100.0,
836            p95_duration_ms: 200.0,
837            p99_duration_ms: 300.0,
838            ..Default::default()
839        };
840
841        assert_eq!(results.error_rate(), 5.0);
842        assert_eq!(results.success_rate(), 95.0);
843    }
844
845    #[test]
846    fn test_k6_results_zero_requests() {
847        let results = K6Results::default();
848        assert_eq!(results.error_rate(), 0.0);
849    }
850
851    #[test]
852    fn discard_response_bodies_defaults_off_and_builder_flips_it() {
853        // Round 56 (#79) — guards the OOM fix for multi-target load runs.
854        // Default must stay off so body-inspecting paths (extract/conformance)
855        // are unaffected; the builder opts a run in.
856        let exec = K6Executor {
857            k6_path: "k6".to_string(),
858            local_ips: String::new(),
859            discard_response_bodies: false,
860            dns_policy: String::new(),
861            force_http1: false,
862            capture_logs: true,
863        };
864        assert!(!exec.discard_response_bodies);
865        let exec = exec.with_discard_response_bodies(true);
866        assert!(exec.discard_response_bodies);
867    }
868
869    #[test]
870    fn dns_policy_defaults_empty_and_builder_sets_it() {
871        // Round 61 (#79) — empty default → k6's `--dns` flag is omitted; the
872        // builder records the policy string the executor turns into
873        // `--dns "policy=<value>"`.
874        let exec = K6Executor {
875            k6_path: "k6".to_string(),
876            local_ips: String::new(),
877            discard_response_bodies: false,
878            dns_policy: String::new(),
879            force_http1: false,
880            capture_logs: true,
881        };
882        assert!(exec.dns_policy.is_empty());
883        let exec = exec.with_dns_policy("preferIPv6");
884        assert_eq!(exec.dns_policy, "preferIPv6");
885    }
886
887    #[test]
888    fn capture_logs_defaults_on_and_builder_disables() {
889        // Round 67 (#79) — the default keeps writing k6-output.log and the
890        // detail sidecars; --no-k6-logs opts a run out so longevity
891        // campaigns do not buffer/write a full k6 dump per round × target.
892        let exec = K6Executor {
893            k6_path: "k6".to_string(),
894            local_ips: String::new(),
895            discard_response_bodies: false,
896            dns_policy: String::new(),
897            force_http1: false,
898            capture_logs: true,
899        };
900        assert!(exec.capture_logs);
901        let exec = exec.with_capture_logs(false);
902        assert!(!exec.capture_logs);
903    }
904
905    #[test]
906    fn test_extract_failure_json_raw() {
907        let line = r#"MOCKFORGE_FAILURE:{"check":"test","expected":"status === 200"}"#;
908        let result = extract_failure_json(line).unwrap();
909        let parsed: serde_json::Value = serde_json::from_str(&result).unwrap();
910        assert_eq!(parsed["check"], "test");
911    }
912
913    #[test]
914    fn test_extract_failure_json_logfmt() {
915        let line = r#"time="2026-01-01T00:00:00Z" level=info msg="MOCKFORGE_FAILURE:{\"check\":\"test\",\"response\":{\"body\":\"{\\\"key\\\":\\\"val\\\"}\"}} " source=console"#;
916        let result = extract_failure_json(line).unwrap();
917        let parsed: serde_json::Value = serde_json::from_str(&result).unwrap();
918        assert_eq!(parsed["check"], "test");
919        assert_eq!(parsed["response"]["body"], r#"{"key":"val"}"#);
920    }
921
922    #[test]
923    fn test_extract_failure_json_no_marker() {
924        assert!(extract_failure_json("just a regular log line").is_none());
925    }
926
927    /// Round 46 (#79) — regression: Srikanth's multipart upload landed
928    /// `[]` in `conformance-requests.json` because the old
929    /// `replace("\\\\","\\").replace("\\\"","\"")` chain misparsed
930    /// adjacent backslashes inside the JSON body (binary multipart
931    /// bytes encoded as `\\u00XX` etc.). Pin both shapes here.
932    #[test]
933    fn test_extract_exchange_logfmt_with_backslash_escapes() {
934        // A JSON body that contains a JSON-encoded `` (one escape
935        // sequence the validator survives). Logfmt wraps it: each `\`
936        // becomes `\\`, each `"` becomes `\"`.
937        let line = r#"time="2026-06-26T10:00:00Z" level=info msg="MOCKFORGE_EXCHANGE:{\"check\":\"u\",\"request\":{\"body\":\"--bnd\\r\\n\\u001a\"}}" source=console"#;
938        let result = extract_exchange_json(line).unwrap();
939        let parsed: serde_json::Value = serde_json::from_str(&result).unwrap();
940        assert_eq!(parsed["check"], "u");
941        // The unescape preserves the JSON's `\r\n` and `` so the
942        // downstream consumer can interpret them as JSON escapes.
943        assert_eq!(parsed["request"]["body"], "--bnd\r\n\u{001a}");
944    }
945
946    #[test]
947    fn test_extract_exchange_raw_no_logfmt_wrapping() {
948        let line =
949            r#"MOCKFORGE_EXCHANGE:{"check":"x","request":{"body":""},"response":{"status":200}}"#;
950        let result = extract_exchange_json(line).unwrap();
951        let parsed: serde_json::Value = serde_json::from_str(&result).unwrap();
952        assert_eq!(parsed["check"], "x");
953        assert_eq!(parsed["response"]["status"], 200);
954    }
955
956    /// The end of `msg="..."` is a single unescaped `"`, not the old
957    /// fixed-string `" source=console`. If k6 ever appends another
958    /// logfmt field (or omits source=), we still get the JSON out.
959    #[test]
960    fn test_extract_exchange_logfmt_tolerates_extra_trailing_fields() {
961        let line = r#"msg="MOCKFORGE_EXCHANGE:{\"check\":\"t\"}" source=console vu=1 iter=0"#;
962        let result = extract_exchange_json(line).unwrap();
963        let parsed: serde_json::Value = serde_json::from_str(&result).unwrap();
964        assert_eq!(parsed["check"], "t");
965    }
966
967    /// Round 46 — JSON-encoded backslash inside a JSON string (`\\u00XX`
968    /// in the JSON, `\\\\u00XX` in logfmt) must round-trip cleanly.
969    /// The naive `.replace` chain choked on this exact pattern.
970    #[test]
971    fn test_extract_exchange_double_backslash_followed_by_quote() {
972        // JSON content: `\\"x"` is `\` then `"x"`. Logfmt:
973        // `\\\\\"x\"` (4 backslashes + escaped quote + x + escaped quote).
974        let line = r#"msg="MOCKFORGE_EXCHANGE:{\"k\":\"a\\\\\\\"x\\\"\"}" source=console"#;
975        let result = extract_exchange_json(line).unwrap();
976        let parsed: serde_json::Value = serde_json::from_str(&result).unwrap();
977        assert_eq!(parsed["k"], r#"a\"x""#);
978    }
979
980    #[test]
981    fn merge_godebug_appends_http2client_off_and_honors_existing() {
982        assert_eq!(merge_godebug_http2client_off(None), "http2client=0");
983        assert_eq!(merge_godebug_http2client_off(Some("")), "http2client=0");
984        assert_eq!(merge_godebug_http2client_off(Some("netdns=go")), "netdns=go,http2client=0");
985        assert_eq!(
986            merge_godebug_http2client_off(Some("http2client=1")),
987            "http2client=1",
988            "an explicit http2client= in the environment wins"
989        );
990        assert_eq!(merge_godebug_http2client_off(Some("http2client=0")), "http2client=0");
991    }
992
993    #[test]
994    fn force_http1_builder_sets_godebug_env_value() {
995        let exec = K6Executor {
996            k6_path: "k6".to_string(),
997            local_ips: String::new(),
998            discard_response_bodies: false,
999            dns_policy: String::new(),
1000            force_http1: false,
1001            capture_logs: true,
1002        };
1003        assert!(exec.godebug_env_value().is_none());
1004        let exec = exec.with_force_http1(true);
1005        let value = exec.godebug_env_value().expect("force_http1 must set GODEBUG");
1006        assert!(
1007            value.split(',').any(|p| p.trim() == "http2client=0"),
1008            "spawn env must contain http2client=0, got {value}"
1009        );
1010    }
1011
1012    #[test]
1013    fn execute_with_port_applies_godebug_when_force_http1() {
1014        let src = include_str!("executor.rs");
1015        assert!(
1016            src.contains("merge_godebug_http2client_off"),
1017            "k6 spawn must merge GODEBUG=http2client=0 so Connection headers survive HTTPS ALPN"
1018        );
1019        assert!(
1020            src.contains("if self.force_http1"),
1021            "GODEBUG must be gated on force_http1, not applied to every k6 run"
1022        );
1023    }
1024
1025    #[test]
1026    fn k6_egress_env_requires_a_proxy_under_the_guard() {
1027        assert!(k6_egress_env(None, None).unwrap().is_empty());
1028        let err = k6_egress_env(Some(crate::ssrf::Policy::strict()), None).unwrap_err();
1029        assert!(err.to_string().contains("no k6 egress proxy"), "{err}");
1030        let env =
1031            k6_egress_env(Some(crate::ssrf::Policy::strict()), Some("http://egress:4750")).unwrap();
1032        let get = |k: &str| env.iter().find(|(n, _)| *n == k).map(|(_, v)| v.as_str());
1033        assert_eq!(get("HTTP_PROXY"), Some("http://egress:4750"));
1034        assert_eq!(get("HTTPS_PROXY"), Some("http://egress:4750"));
1035        assert_eq!(get("NO_PROXY"), Some(""));
1036        assert_eq!(get("no_proxy"), Some(""));
1037        assert_eq!(get("K6_MAX_REDIRECTS"), Some("0"));
1038        assert_eq!(get("K6_NO_USAGE_REPORT"), Some("true"));
1039    }
1040}