parse_results.py 32.7 KB
Newer Older
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# SPDX-FileCopyrightText: Copyright (c) 2025 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
# SPDX-License-Identifier: Apache-2.0
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
# http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.

16
17
"""Parser for AI-Perf results in fault tolerance tests."""

18
19
import argparse
import json
20
import logging
21
22
23
import os
import re
from datetime import datetime
24
from pathlib import Path
25
26
from typing import Any, Dict, List, Optional, Tuple

27
import numpy as np
28
29
from tabulate import tabulate

30
31
32
33
34
35
36
from tests.fault_tolerance.deploy.scenarios import (
    OVERFLOW_SUFFIX,
    RECOVERY_SUFFIX,
    WORKER_MAP,
    TestPhase,
)

37

38
39
40
41
42
43
44
45
46
47
48
49
def parse_test_log(
    file_path: str,
) -> Tuple[Optional[float], Optional[List[str]]]:
    """
    Parse test log for startup time and failure info.

    Args:
        file_path: Path to test.log.txt

    Returns:
        Tuple of (startup_time_seconds, failure_info)
    """
50
51
    start_time = None
    ready_time = None
52
53
    failure_info: Optional[List[str]] = None

54
    if not os.path.isfile(file_path):
55
56
        return None, None

57
58
    with open(file_path, "r") as f:
        for line in f:
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
            # Extract timestamp using regex to handle different log formats
            timestamp_match = re.search(r"(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2})", line)

            # Look for deployment start
            if "Starting Deployment" in line and timestamp_match:
                timestamp = timestamp_match.group(1)
                start_time = datetime.strptime(timestamp, "%Y-%m-%dT%H:%M:%S")

            # Look for deployment ready
            if "Deployment fault-tolerance-test is ready" in line and timestamp_match:
                timestamp = timestamp_match.group(1)
                ready_time = datetime.strptime(timestamp, "%Y-%m-%dT%H:%M:%S")

            # Look for fault injection
            if "Injecting failure for:" in line:
                # Extract failure details
                match = re.search(r"Failure\((.*?)\)", line)
                if match:
                    failure_str = match.group(1)
                    parts = failure_str.split(", ")
                    failure_dict = {}
                    for part in parts:
                        key_val = part.split("=")
                        if len(key_val) == 2:
                            failure_dict[key_val[0]] = key_val[1]

                    # Build command list from failure info
                    if failure_dict:
                        failure_info = [
                            failure_dict.get("pod_name", "unknown").strip("'\""),
                            failure_dict.get("command", "unknown").strip("'\""),
                        ]

    # Calculate startup time in seconds
    startup_time = None
    if start_time and ready_time:
        startup_time = (ready_time - start_time).total_seconds()

    return startup_time, failure_info


100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
def parse_timestamp(timestamp_str: str) -> Optional[datetime]:
    """
    Robustly parse timestamp with multiple format attempts.

    Args:
        timestamp_str: Timestamp string to parse

    Returns:
        datetime object or None if parsing fails
    """
    # List of common timestamp formats to try
    timestamp_formats = [
        "%Y-%m-%dT%H:%M:%S.%fZ",  # Full format with microseconds and Z
        "%Y-%m-%dT%H:%M:%SZ",  # Without microseconds, with Z
        "%Y-%m-%dT%H:%M:%S.%f",  # With microseconds, no timezone
        "%Y-%m-%dT%H:%M:%S",  # Basic ISO format
        "%Y-%m-%d %H:%M:%S.%f",  # Space separator with microseconds
        "%Y-%m-%d %H:%M:%S",  # Space separator without microseconds
    ]

    for fmt in timestamp_formats:
        try:
            return datetime.strptime(timestamp_str, fmt)
        except ValueError:
            continue

    # If no format matches, log the issue
    logging.debug(f"Could not parse timestamp: {timestamp_str}")
    return None


def extract_timestamp_from_log(
    log_path: str, from_end: bool = False, max_lines: int = 10, debug_message: str = ""
) -> Optional[datetime]:
    """
    Extract a timestamp from a log file by parsing JSON lines.

    Args:
        log_path: Path to the log file
        from_end: If True, search from the end of file (for last timestamp)
                  If False, search from beginning (for first timestamp)
        max_lines: Maximum number of lines to check
        debug_message: Debug message to log when timestamp is found

    Returns:
        datetime object or None if no valid timestamp found
    """
    try:
        with open(log_path, "r") as f:
            lines = list(f.readlines())
            if from_end:
                # Read from the end of the file
                lines_to_check = list(reversed(lines))
            else:
                # Read from the beginning of the file
                lines_to_check = lines
            # Limit to max_lines
            lines_to_check = lines_to_check[:max_lines]

            for line in lines_to_check:
                if '"time":"' in line:
                    try:
                        log_entry = json.loads(line)
                        timestamp_str = log_entry.get("time", "")
                        if timestamp_str:
                            parsed_time = parse_timestamp(timestamp_str)
                            if parsed_time:
                                if debug_message:
                                    logging.debug(f"{debug_message}: {timestamp_str}")
                                return parsed_time
                    except (json.JSONDecodeError, ValueError) as e:
                        logging.debug(f"Failed to parse JSON line: {e}")
                        continue
    except IOError as e:
        logging.debug(f"Could not read {log_path}: {e}")

    return None


179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
def extract_test_info_from_dir(
    process_logs_dir: str,
) -> Tuple[Optional[str], Optional[str]]:
    """
    Extract backend and deployment type from process_logs_dir.

    Args:
        process_logs_dir: Path like test_fault_scenario[trtllm_agg_token_overflow_2x]

    Returns:
        Tuple of (backend, deploy_type) or (None, None) if not a token overflow test
    """
    test_name = os.path.basename(process_logs_dir)

    # Check if this is a token overflow test
    if "token_overflow" not in test_name:
        return None, None

    # Extract the content between brackets
    match = re.search(r"\[([^\]]+)\]", test_name)
    if not match:
        return None, None

    test_config = match.group(1)

    # Parse backend and deployment type
    # Format: {backend}_{deploy_type}_token_overflow_{multiplier}
    parts = test_config.split("_")

    if len(parts) < 4:
        return None, None

    backend = parts[0]  # vllm, trtllm, sglang
    deploy_type = parts[1]  # agg or disagg

    return backend, deploy_type


def get_decode_worker_dir(backend: str, deploy_type: str) -> Optional[str]:
    """
    Get decode worker directory name from WORKER_MAP.
    Reuses the exact logic from scenarios.py.

    Args:
        backend: Backend type (vllm, trtllm, sglang)
        deploy_type: Deployment type (agg or disagg)

    Returns:
        Worker directory name
    """
    if backend not in WORKER_MAP:
        return None

    # For trtllm agg deployments, use different worker name
    if backend == "trtllm" and deploy_type == "agg":
        return WORKER_MAP[backend]["decode_agg"]  # "TRTLLMWorker"
    else:
        return WORKER_MAP[backend]["decode"]
        # "TRTLLMDecodeWorker", "VllmDecodeWorker", or "decode"


240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
def calculate_recovery_time(
    failure_info: Optional[List[str]],
    process_logs_dir: str,
) -> Optional[float]:
    """
    Calculate recovery time by comparing last timestamp in .previous.log with first in current log.
    This avoids timezone issues between test.log.txt and container logs.

    Args:
        failure_info: List with [pod_name, command] from fault injection
        process_logs_dir: Directory containing process log files

    Returns:
        Recovery time in seconds or None if not found
    """
255

256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
    if failure_info:
        # Regular test - use failure info
        component_type = failure_info[0].strip("'\"")  # e.g., "Frontend" or "decode"
        component_dir = os.path.join(process_logs_dir, component_type)
    else:
        # Check if this is a mixed token test
        backend, deploy_type = extract_test_info_from_dir(process_logs_dir)
        if not backend or not deploy_type:
            logging.warning(
                f"Could not determine backend or deploy type for {process_logs_dir}"
            )
            return None

        # Mixed token test - get decode worker directory
        decode_worker_dir = get_decode_worker_dir(backend, deploy_type)
        if not decode_worker_dir:
            logging.warning(
                f"Could not determine decode worker for {backend} {deploy_type}"
            )
            return None

        component_dir = os.path.join(process_logs_dir, decode_worker_dir)
        logging.info(
            f"Mixed token test - using decode worker directory: {component_dir}"
        )

282
    logging.info(f"Component directory: {component_dir}")
283

284
    if not os.path.exists(component_dir):
285
        logging.warning(f"Component directory {component_dir} does not exist")
286
        return None
287

288
289
290
291
292
293
294
    last_timestamp_before = None
    first_timestamp_after = None

    # Find the last timestamp from .previous.log (container before restart)
    for log_file in os.listdir(component_dir):
        if log_file.endswith(".previous.log"):
            log_path = os.path.join(component_dir, log_file)
295
296
297
298
299
300
301
302
303
            logging.info(f"Previous pod log path: {log_path}")
            last_timestamp_before = extract_timestamp_from_log(
                log_path,
                from_end=True,
                max_lines=50,  # Check more lines for better chance of finding timestamp
                debug_message="Last timestamp before failure",
            )
            if last_timestamp_before:
                break
304
305
306
307
308
309
310

    # Find the first timestamp from current container log
    for log_file in os.listdir(component_dir):
        if log_file.endswith(".log") and not log_file.endswith(
            (".previous.log", ".metrics.log")
        ):
            log_path = os.path.join(component_dir, log_file)
311
312
313
314
315
316
317
318
319
            logging.info(f"Pod log path: {log_path}")
            first_timestamp_after = extract_timestamp_from_log(
                log_path,
                from_end=False,
                max_lines=100,  # May need to skip initial non-JSON output
                debug_message="First timestamp after recovery",
            )
            if first_timestamp_after:
                break
320
321
322
323
324
325
326
327
328
329
330
331

    # Calculate recovery time from container timestamps (both in UTC)
    if last_timestamp_before and first_timestamp_after:
        recovery_time = (first_timestamp_after - last_timestamp_before).total_seconds()
        # Sanity check - recovery should be seconds/minutes, not hours
        if recovery_time > 3600:  # More than 1 hour is likely wrong
            logging.warning(
                f"Recovery time {recovery_time}s seems too large, possible timezone issue"
            )
        return recovery_time

    return None
332
333


334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
def parse_aiperf_client_results(log_dir: str) -> Dict[str, Any]:
    """
    Parse AI-Perf results from all client directories.

    Args:
        log_dir: Directory containing client result directories

    Returns:
        Dictionary with aggregated metrics and client count
    """
    all_metrics: Dict[str, Any] = {
        "total_requests": 0,
        "successful_requests": 0,
        "failed_requests": 0,
        "latencies": [],
        "ttft": [],  # Time to First Token
        "itl": [],  # Inter-Token Latency
        "throughputs": [],
        "p50_latencies": [],
        "p90_latencies": [],
        "p99_latencies": [],
        "num_clients": 0,
356
357
    }

358
359
360
361
362
363
    # Iterate over actual client directories
    for item in sorted(os.listdir(log_dir)):
        if not item.startswith("client_") or not os.path.isdir(
            os.path.join(log_dir, item)
        ):
            continue
364

365
366
        client_dir = Path(log_dir) / item
        all_metrics["num_clients"] += 1
367

368
369
        # Look for AI-Perf results in attempt directories
        profile_json = None
370

371
372
373
374
375
376
        # Check for attempt directories (attempt_0, attempt_1, etc.)
        for attempt_dir in sorted(client_dir.glob("attempt_*")):
            json_path = attempt_dir / "profile_export_aiperf.json"
            if json_path.exists():
                profile_json = json_path
                break  # Use the first successful attempt
377

378
379
380
381
382
383
384
        if not profile_json:
            logging.warning(f"No AI-Perf results found for {item} in {client_dir}")
        else:
            try:
                with open(profile_json) as f:
                    client_metrics = json.load(f)

385
386
387
388
389
390
391
392
393
                # AI-Perf format has "records" dictionary at the top level
                records = client_metrics.get("records", {})

                # Extract successful request count
                request_count_record = records.get("request_count", {})
                successful_count = (
                    int(request_count_record.get("avg", 0))
                    if request_count_record
                    else 0
394
                )
395

396
397
398
399
400
401
402
403
404
405
406
407
408
409
                # Extract error request count
                error_request_count_record = records.get("error_request_count", {})
                error_request_count = (
                    int(error_request_count_record.get("avg", 0))
                    if error_request_count_record
                    else 0
                )

                # Calculate total requests: successful + errors
                # Note: request_count appears to only track successful requests when errors are present
                request_count = successful_count + error_request_count

                # Fall back to input config if no requests were recorded
                if request_count == 0 and "input_config" in client_metrics:
410
411
412
                    input_config = client_metrics.get("input_config", {})
                    loadgen_config = (
                        input_config.get("loadgen", {}) if input_config else {}
413
414
415
                    )
                    request_count = loadgen_config.get("request_count", 0)

416
                # Check for errors in error_summary
417
418
419
                error_summary = client_metrics.get("error_summary", [])
                # Sum up actual error counts from each error type
                error_count = sum(error.get("count", 0) for error in error_summary)
420
421

                # Check if test was cancelled
422
                if client_metrics.get("was_cancelled", False):
423
424
                    error_count = request_count  # Mark all as failed if cancelled

425
426
427
428
429
430
431
                # Validate data consistency
                if request_count < error_count:
                    logging.warning(
                        f"Data inconsistency in {item}: error_count ({error_count}) > "
                        f"total_request_count ({request_count}). This may indicate incomplete data from aiperf."
                    )

432
433
434
435
                all_metrics["total_requests"] += request_count
                all_metrics["successful_requests"] += request_count - error_count
                all_metrics["failed_requests"] += error_count

436
437
                # Extract latency metrics
                request_latency = client_metrics.get("request_latency", None)
438
                if request_latency:
439
440
441
442
443
444
                    all_metrics["latencies"].append(request_latency["avg"] / 1000.0)
                    all_metrics["p50_latencies"].append(request_latency["p50"] / 1000.0)
                    all_metrics["p90_latencies"].append(request_latency["p90"] / 1000.0)
                    all_metrics["p99_latencies"].append(request_latency["p99"] / 1000.0)

                # Time to first token
445
446
                ttft_record = client_metrics.get("time_to_first_token", {})
                ttft = ttft_record.get("avg", None) if ttft_record else None
447
448
449
450
                if ttft:
                    all_metrics["ttft"].append(ttft / 1000.0)  # Convert ms to s

                # Inter-token latency
451
452
                itl_record = client_metrics.get("inter_token_latency", {})
                itl = itl_record.get("avg", None) if itl_record else None
453
454
                if itl:
                    all_metrics["itl"].append(itl / 1000.0)  # Convert ms to s
455
456

                # Throughput from request_throughput record
457
458
459
                throughput_record = client_metrics.get("request_throughput", {})
                req_throughput = (
                    throughput_record.get("avg", 0) if throughput_record else 0
460
                )
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
                if req_throughput:
                    all_metrics["throughputs"].append(req_throughput)

            except Exception as e:
                logging.error(f"Error parsing {item} results: {e}")

    return all_metrics


def print_summary_table(
    log_dir: str,
    num_clients: int,
    startup_time: Optional[float],
    recovery_time: Optional[float],
    metrics: Dict[str, Any],
    tablefmt: str = "grid",
    sla: Optional[float] = None,
) -> None:
    """
    Print formatted summary table with AI-Perf metrics.

    Args:
        log_dir: Test directory path
        num_clients: Number of client processes
        startup_time: Time to start deployment (seconds)
        recovery_time: Time to recover from fault (seconds)
        metrics: Aggregated metrics from AI-Perf
        tablefmt: Table format for output
        sla: Service level agreement for latency (optional)
    """
    headers = ["Metric", "Value"]
    rows = []

    # Test info
    rows.append(["Test Directory", log_dir])
    rows.append(["Number of Clients", str(num_clients)])
    rows.append(["", ""])

    # Deployment metrics
    rows.append(["=== Deployment Metrics ===", ""])
    if startup_time:
        rows.append(["Startup Time", f"{startup_time:.2f} sec"])
    else:
        rows.append(["Startup Time", "N/A"])
505

506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
    if recovery_time:
        rows.append(["Recovery Time", f"{recovery_time:.2f} sec"])
    else:
        rows.append(["Recovery Time", "N/A"])
    rows.append(["", ""])

    # Request metrics
    rows.append(["=== Request Metrics ===", ""])
    rows.append(["Total Requests", metrics["total_requests"]])
    rows.append(["Successful Requests", metrics["successful_requests"]])
    rows.append(["Failed Requests", metrics["failed_requests"]])

    if metrics["total_requests"] > 0:
        success_rate = (
            metrics["successful_requests"] / metrics["total_requests"]
        ) * 100
        rows.append(["Success Rate", f"{success_rate:.2f}%"])
    rows.append(["", ""])

    # Latency metrics
    rows.append(["=== Latency Metrics (seconds) ===", ""])

    if metrics["latencies"]:
        mean_latency = np.mean(metrics["latencies"])
        rows.append(["Mean Latency", f"{mean_latency:.3f}"])

        # Check SLA if provided
        if sla is not None:
            sla_status = "✓ PASS" if mean_latency <= sla else "✗ FAIL"
            rows.append(["SLA Status", f"{sla_status} (target: {sla:.3f}s)"])

    if metrics["p50_latencies"]:
        rows.append(["P50 Latency", f"{np.mean(metrics['p50_latencies']):.3f}"])

    if metrics["p90_latencies"]:
        rows.append(["P90 Latency", f"{np.mean(metrics['p90_latencies']):.3f}"])

    if metrics["p99_latencies"]:
        rows.append(["P99 Latency", f"{np.mean(metrics['p99_latencies']):.3f}"])
    rows.append(["", ""])

    # Token generation metrics
    rows.append(["=== Token Generation Metrics ===", ""])

    if metrics["ttft"]:
        rows.append(
            ["Time to First Token (mean)", f"{np.mean(metrics['ttft']):.3f} sec"]
        )

    if metrics["itl"]:
        rows.append(
            ["Inter-Token Latency (mean)", f"{np.mean(metrics['itl']):.4f} sec"]
        )
    rows.append(["", ""])

    # Throughput metrics
    rows.append(["=== Throughput Metrics ===", ""])

    if metrics["throughputs"]:
        total_throughput = sum(metrics["throughputs"])
        rows.append(["Total Throughput", f"{total_throughput:.2f} req/s"])
        rows.append(
            ["Avg Client Throughput", f"{np.mean(metrics['throughputs']):.2f} req/s"]
        )

571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
    # Log table
    logging.info(
        "\n" + "=" * 60 + "\n"
        "FAULT TOLERANCE TEST SUMMARY - AI-PERF\n"
        + "=" * 60
        + "\n"
        + tabulate(rows, headers=headers, tablefmt=tablefmt)
        + "\n"
        + "=" * 60
        + "\n"
    )


def _process_test_phase_results(
    test_phase: TestPhase,
    metrics: Dict[str, Any],
    success_threshold: float,
) -> None:
    """Helper function to process and log results for a specific test phase."""
    if test_phase == TestPhase.OVERFLOW:
        total_reqs = metrics.get("total_requests", 0)
        failed_reqs = metrics.get("failed_requests", 0)
        if total_reqs > 0:
            failure_rate = (failed_reqs / total_reqs) * 100
            logging.info(
                "\n" + "=" * 60 + "\n"
                "Processing OVERFLOW phase - Expecting rejections\n" + "=" * 60 + "\n"
                f"\nOverflow Results: {failed_reqs}/{total_reqs} requests rejected ({failure_rate:.1f}%)"
            )
            if failure_rate < success_threshold:
                logging.warning(
                    f"Expected rejection rate >= {success_threshold}%, got {failure_rate:.1f}%"
                )
            else:
                logging.info("Overflow validation working correctly")
        else:
            logging.warning("No requests to process, total_requests is 0.")

    elif test_phase == TestPhase.RECOVERY:
        total_reqs = metrics.get("total_requests", 0)
        success_reqs = metrics.get("successful_requests", 0)
        if total_reqs > 0:
            success_rate = (success_reqs / total_reqs) * 100
            logging.info(
                "\n" + "=" * 60 + "\n"
                "Processing RECOVERY phase - Expecting success\n" + "=" * 60 + "\n"
                f"\nRecovery Results: {success_reqs}/{total_reqs} requests succeeded ({success_rate:.1f}%)"
            )
            if success_rate < success_threshold:
                logging.warning(
                    f"Expected success rate >= {success_threshold}%, got {success_rate:.1f}%"
                )
            else:
                logging.info("System recovered successfully")
        else:
            logging.warning("No requests to process, total_requests is 0.")
    elif test_phase == TestPhase.STANDARD:
        # Standard test phase doesn't need special processing
        pass
    else:
        raise ValueError(f"Unknown test phase: {test_phase}")
632
633
634


def process_single_test(
635
636
637
638
639
    log_dir: str,
    tablefmt: str = "grid",
    sla: Optional[float] = None,
    success_threshold: float = 90.0,
    print_output: bool = True,
640
641
642
643
644
645
646
647
) -> Dict[str, Any]:
    """
    Process a single test log directory.

    Args:
        log_dir: Directory containing test results
        tablefmt: Table format for output
        sla: Service level agreement for latency (optional)
648
649
        success_threshold: Success rate threshold for pass/fail (default: 90.0)
        print_output: If True, print tables and phase headers. If False, only return results.
650
651
652
653

    Returns:
        Dictionary with test results
    """
654
655
656
657
658
659
660
661
    # Detect test phase (overflow or recovery) - check suffix to avoid ambiguity
    test_phase = TestPhase.STANDARD

    if log_dir.endswith(OVERFLOW_SUFFIX):
        test_phase = TestPhase.OVERFLOW
    elif log_dir.endswith(RECOVERY_SUFFIX):
        test_phase = TestPhase.RECOVERY

662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
    # Parse test configuration
    test_log = os.path.join(log_dir, "test.log.txt")
    startup_time, failure_info = parse_test_log(test_log)

    # Calculate recovery time only if fault was injected
    recovery_time = None
    if failure_info:
        recovery_time = calculate_recovery_time(failure_info, log_dir)

    # Parse AI-Perf results (also counts clients)
    metrics = parse_aiperf_client_results(log_dir)

    # Extract client count from metrics
    num_clients = metrics.get("num_clients", 0)

677
678
679
680
681
682
683
    # Add phase information to metrics (store as string for JSON serialization)
    metrics["test_phase"] = test_phase.name.lower()

    # Process and print phase-specific results
    if print_output:
        _process_test_phase_results(test_phase, metrics, success_threshold)

684
    # Print summary
685
686
687
688
    if print_output:
        print_summary_table(
            log_dir, num_clients, startup_time, recovery_time, metrics, tablefmt, sla
        )
689
690

    return {
691
692
693
        "log_dir": log_dir,
        "num_clients": num_clients,
        "startup_time": startup_time,
694
        "recovery_time": recovery_time,
695
        "metrics": metrics,
696
697
698
    }


699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742
743
744
745
746
747
748
749
750
751
752
753
754
755
756
757
758
759
760
761
762
763
764
765
766
767
768
769
770
771
772
773
774
775
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
794
795
796
797
798
def process_overflow_recovery_test(
    overflow_path: str,
    recovery_path: str,
    tablefmt: str = "fancy_grid",
    sla: Optional[float] = None,
    success_threshold: float = 90.0,
) -> Dict[str, Any]:
    """
    Process paired overflow/recovery test and print combined summary.

    Args:
        overflow_path: Path to overflow test directory
        recovery_path: Path to recovery test directory
        tablefmt: Table format for output
        sla: Optional SLA threshold
        success_threshold: Success rate threshold for pass/fail (default: 90.0)

    Returns:
        Combined results dictionary
    """
    overflow_results = process_single_test(
        overflow_path, tablefmt, sla, success_threshold, print_output=False
    )
    recovery_results = process_single_test(
        recovery_path, tablefmt, sla, success_threshold, print_output=False
    )

    combined_metrics = {
        "total_requests": overflow_results["metrics"]["total_requests"]
        + recovery_results["metrics"]["total_requests"],
        "successful_requests": overflow_results["metrics"]["successful_requests"]
        + recovery_results["metrics"]["successful_requests"],
        "failed_requests": overflow_results["metrics"]["failed_requests"]
        + recovery_results["metrics"]["failed_requests"],
        # Performance metrics from recovery phase
        "latencies": recovery_results["metrics"].get("latencies", []),
        "ttft": recovery_results["metrics"].get("ttft", []),
        "itl": recovery_results["metrics"].get("itl", []),
        "throughputs": recovery_results["metrics"].get("throughputs", []),
        "p50_latencies": recovery_results["metrics"].get("p50_latencies", []),
        "p90_latencies": recovery_results["metrics"].get("p90_latencies", []),
        "p99_latencies": recovery_results["metrics"].get("p99_latencies", []),
    }

    base_path = overflow_path
    if overflow_path.endswith(OVERFLOW_SUFFIX):
        base_path = overflow_path[: -len(OVERFLOW_SUFFIX)]
    test_log_path = os.path.join(base_path, "test.log.txt")
    startup_time, _ = parse_test_log(test_log_path)
    recovery_time = calculate_recovery_time(failure_info=[], process_logs_dir=base_path)

    if overflow_results["metrics"]["total_requests"] == 0:
        overflow_rate = 0
    else:
        overflow_rate = (
            overflow_results["metrics"]["failed_requests"]
            / overflow_results["metrics"]["total_requests"]
            * 100
        )

    if recovery_results["metrics"]["total_requests"] == 0:
        recovery_rate = 0
    else:
        recovery_rate = (
            recovery_results["metrics"]["successful_requests"]
            / recovery_results["metrics"]["total_requests"]
            * 100
        )

    logging.info(
        "\n" + "=" * 60 + "\n"
        "SESSION SUMMARY - COMBINED OVERFLOW/RECOVERY TEST\n" + "=" * 60 + "\n"
        "\nPhase Breakdown:\n"
        f"  Overflow: {overflow_results['metrics']['failed_requests']}/"
        f"{overflow_results['metrics']['total_requests']} rejected ({overflow_rate:.1f}%)\n"
        f"  Recovery: {recovery_results['metrics']['successful_requests']}/"
        f"{recovery_results['metrics']['total_requests']} succeeded ({recovery_rate:.1f}%)"
    )

    print_summary_table(
        log_dir=base_path,
        num_clients=overflow_results["num_clients"],
        startup_time=startup_time,
        recovery_time=recovery_time,
        metrics=combined_metrics,
        tablefmt=tablefmt,
        sla=sla,
    )

    return {
        "log_dir": base_path,
        "num_clients": overflow_results["num_clients"],
        "startup_time": startup_time,
        "recovery_time": recovery_time,
        "metrics": combined_metrics,
        "overflow_results": overflow_results,
        "recovery_results": recovery_results,
    }


799
800
801
802
803
def main(
    logs_dir: Optional[str] = None,
    log_paths: Optional[List[str]] = None,
    tablefmt: str = "grid",
    sla: Optional[float] = None,
804
805
    success_threshold: float = 90.0,
    print_output: bool = True,
806
807
808
809
810
811
812
813
814
):
    """
    Main parser entry point with support for multiple log paths.

    Args:
        logs_dir: Base directory for logs (optional)
        log_paths: List of log directories to process
        tablefmt: Table format for output
        sla: Service level agreement for latency (optional)
815
816
        success_threshold: Success rate threshold for pass/fail (default: 90.0)
        print_output: If True, print tables and summaries. If False, only return results.
817
818
819
820
821

    Returns:
        Combined results from all processed tests
    """
    # Handle different input formats
822
    if log_paths:
823
824
        # Process multiple log paths
        all_results = []
825
        for log_path in log_paths:
826
827
828
829
830
831
            if logs_dir:
                full_path = os.path.join(logs_dir, log_path)
            else:
                full_path = log_path

            if os.path.isdir(full_path):
832
833
834
835
                logging.info(f"\nProcessing: {full_path}")
                results = process_single_test(
                    full_path, tablefmt, sla, success_threshold, print_output
                )
836
                all_results.append(results)
837
            else:
838
                logging.warning(f"{full_path} is not a valid directory, skipping...")
839

840
841
        # If multiple tests, also log combined summary
        if len(all_results) > 1 and print_output:
842
843
844
            total_requests = sum(r["metrics"]["total_requests"] for r in all_results)
            total_successful = sum(
                r["metrics"]["successful_requests"] for r in all_results
845
            )
846
847
            total_failed = sum(r["metrics"]["failed_requests"] for r in all_results)

848
849
850
851
852
853
854
855
856
857
            # Build summary message
            summary_lines = [
                "\n" + "=" * 60,
                "COMBINED TEST SUMMARY",
                "=" * 60,
                f"Total Tests: {len(all_results)}",
                f"Total Requests: {total_requests}",
                f"Total Successful: {total_successful}",
                f"Total Failed: {total_failed}",
            ]
858
859

            if total_requests > 0:
860
                summary_lines.append(
861
862
863
                    f"Overall Success Rate: {(total_successful/total_requests)*100:.2f}%"
                )

864
865
866
867
868
869
870
871
872
873
874
875
876
877
878
879
880
881
882
883
884
885
886
887
888
889
890
            # Check if this is an overflow/recovery pair and show timing info
            has_overflow = any(
                r["log_dir"].endswith(OVERFLOW_SUFFIX) for r in all_results
            )
            has_recovery = any(
                r["log_dir"].endswith(RECOVERY_SUFFIX) for r in all_results
            )

            if has_overflow and has_recovery:
                # Find startup time from overflow phase
                for r in all_results:
                    if r["log_dir"].endswith(OVERFLOW_SUFFIX) and r.get("startup_time"):
                        summary_lines.append(f"Startup Time: {r['startup_time']}")
                        break

                # Find recovery time stored in recovery phase
                for r in all_results:
                    if r["log_dir"].endswith(RECOVERY_SUFFIX) and r.get(
                        "recovery_time"
                    ):
                        summary_lines.append(
                            f"Recovery Time (gap between phases): {r['recovery_time']}"
                        )
                        break

            summary_lines.append("=" * 60 + "\n")
            logging.info("\n".join(summary_lines))
891
892
893
894
895

        return all_results

    elif logs_dir:
        # Process single directory
896
897
898
        return process_single_test(
            logs_dir, tablefmt, sla, success_threshold, print_output
        )
899
    else:
900
        logging.error("Must provide either logs_dir or log_paths")
901
        return None
902
903
904


if __name__ == "__main__":
905
906
907
908
    # Configure logging
    logging.basicConfig(level=logging.INFO, format="%(levelname)s: %(message)s")

    parser = argparse.ArgumentParser(description="Parse fault tolerance test results")
909
    parser.add_argument(
910
        "log_dir", type=str, help="Directory containing test logs and results"
911
912
913
914
    )

    args = parser.parse_args()

915
916
917
    if not os.path.isdir(args.log_dir):
        logging.error(f"{args.log_dir} is not a valid directory")
        exit(1)
918

919
    main(args.log_dir)