client.py 22 KB
Newer Older
1
# SPDX-FileCopyrightText: Copyright (c) 2025-2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# 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
"""AI-Perf client implementation for fault tolerance testing."""

18
19
20
import json
import logging
import os
21
import signal
22
import subprocess
23
import time
24
25
from pathlib import Path
from typing import Any, Dict, List, Optional, Tuple
26

27
from kr8s.objects import Pod
28

29
from tests.utils.client import wait_for_model_availability
30
31
32
33
34
35
36
37
38
from tests.utils.managed_deployment import ManagedDeployment

LOG_FORMAT = "[TEST] %(asctime)s %(levelname)s %(name)s: %(message)s"
DATE_FORMAT = "%Y-%m-%dT%H:%M:%S"

# Configure logging
logging.basicConfig(
    level=logging.INFO,
    format=LOG_FORMAT,
39
    datefmt=DATE_FORMAT,
40
41
42
)


43
44
45
46
47
48
def get_frontend_port(
    managed_deployment: ManagedDeployment,
    client_index: int,
    deployment_spec: Any,
    pod_ports: Dict[str, Any],
    logger: logging.Logger,
49
) -> Tuple[Optional[str], Optional[int], Optional[Pod]]:
50
51
    """
    Select a frontend pod using round-robin and setup port forwarding.
52

53
54
55
56
57
58
59
60
    Args:
        managed_deployment: ManagedDeployment instance
        client_index: Client index for round-robin selection
        deployment_spec: Deployment specification with port info
        pod_ports: Dictionary to track existing port forwards
                  - Key: pod name (str)
                  - Value: port forward object from managed_deployment.port_forward()
        logger: Logger instance
61

62
63
64
    Returns:
        Tuple of (pod_name, local_port, pod_instance) or (None, None, None) if failed
    """
65
    pods = managed_deployment.get_pods([managed_deployment.frontend_service_name])
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
100
101
102
103
104
105
106
107
108
109
110
111
112

    port = 0
    pod_name = None
    selected_pod = None

    # Filter ready pods and cleanup stale port forwards
    pods_ready = []

    for pod in pods[managed_deployment.frontend_service_name]:
        if pod.ready():
            pods_ready.append(pod)
        else:
            # Cleanup port forwards for non-ready pods
            if pod.name in pod_ports:
                try:
                    pod_ports[pod.name].stop()
                except Exception as e:
                    logger.debug(f"Error stopping port forward for {pod.name}: {e}")
                del pod_ports[pod.name]

    if not pods_ready:
        logger.error("No ready frontend pods found")
        return None, None, None

    # Round-robin selection based on client index
    selected_pod = pods_ready[client_index % len(pods_ready)]
    pod_name = selected_pod.name

    # Setup or reuse port forward
    if pod_name not in pod_ports:
        # Get port from deployment_spec (default: 8000)
        port_value = getattr(deployment_spec, "_port", 8000)
        port_forward = managed_deployment.port_forward(selected_pod, port_value)
        if port_forward:
            pod_ports[pod_name] = port_forward
            port = port_forward.local_port
        else:
            logger.error(f"Failed to create port forward for pod {pod_name}")
            return None, None, None
    else:
        # Reuse existing port forward
        port = pod_ports[pod_name].local_port

    logger.debug(f"Selected pod {pod_name} with local port {port}")
    return pod_name, port, selected_pod


113
# wait_for_model_availability has been moved to tests.utils.client
114
115


Tzu-Ling Kan's avatar
Tzu-Ling Kan committed
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
179
180
181
182
183
184
185
186
187
188
def validate_aiperf_results(
    json_path: Path,
    requests_per_client: int,
    attempt: int,
    logger: logging.Logger,
    attempt_dir: Path,
    pod_name: str,
    port: int,
) -> bool:
    """
    Validate AI-Perf results from JSON output.

    Args:
        json_path: Path to the AI-Perf JSON output file
        requests_per_client: Expected number of requests
        attempt: Current attempt number (0-based)
        logger: Logger instance
        attempt_dir: Directory containing attempt results
        pod_name: Pod name for logging
        port: Port number for logging

    Returns:
        True if the attempt was successful, False if it should be retried
    """
    if not json_path.exists():
        # No JSON output, but aiperf returned 0 - might be okay
        logger.info(f"Attempt {attempt + 1} completed (return code 0, no JSON output)")
        log_summary_metrics(attempt_dir, logger, pod_name, port)
        return True

    try:
        with open(json_path, "r") as f:
            aiperf_data = json.load(f)

        # Check for errors in the output
        error_count = 0
        if "records" in aiperf_data and "error_request_count" in aiperf_data["records"]:
            error_count = int(
                aiperf_data["records"]["error_request_count"].get("avg", 0)
            )

        # Also check error_summary
        if "error_summary" in aiperf_data:
            error_summary_count = sum(
                err.get("count", 0) for err in aiperf_data["error_summary"]
            )
            error_count = max(error_count, error_summary_count)

        # Consider it a failure if most requests failed (> 90%)
        failure_threshold = requests_per_client * 0.9
        if error_count >= failure_threshold:
            logger.warning(
                f"Attempt {attempt + 1} had {error_count}/{requests_per_client} failed requests - retrying"
            )
            return False  # Not successful, continue retrying
        else:
            successful_count = requests_per_client - error_count
            logger.info(
                f"Attempt {attempt + 1} succeeded with {successful_count}/{requests_per_client} successful requests"
            )
            log_summary_metrics(attempt_dir, logger, pod_name, port)
            return True  # Successful

    except Exception as e:
        logger.warning(f"Could not parse AI-Perf output to check for failures: {e}")
        # Assume success if we can't parse the output but aiperf returned 0
        logger.info(
            f"Attempt {attempt + 1} completed (return code 0, could not verify success)"
        )
        log_summary_metrics(attempt_dir, logger, pod_name, port)
        return True  # Assume success


189
190
191
192
193
194
195
196
197
198
199
200
def run_aiperf(
    url: str,
    endpoint: str,
    model: str,
    pod_name: str,
    port: int,
    requests_per_client: int,
    input_token_length: int,
    output_token_length: int,
    output_dir: Path,
    logger: logging.Logger,
    max_retries: int = 1,
201
    max_request_rate: float = 1.0,
202
    continuous_load: bool = False,
203
204
205
206
207
208
209
210
211
212
) -> bool:
    """
    Execute AI-Perf with specified parameters.

    Args:
        url: Base URL (http://localhost:port)
        endpoint: API endpoint path (e.g., "v1/chat/completions")
        model: Model name
        pod_name: Selected pod name for logging
        port: Local port number
213
        requests_per_client: Number of requests to send (used if continuous load not enabled)
214
215
216
217
218
        input_token_length: Input token count
        output_token_length: Output token count
        output_dir: Directory for AI-Perf artifacts
        logger: Logger instance
        max_retries: Maximum number of retry attempts (default: 1)
219
        max_request_rate: Maximum requests per second for rate limiting (default: 1.0)
220
        continuous_load: If True, use continuous load instead of fixed request count
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250

    Returns:
        True if successful, False otherwise
    """
    # Validate required parameters
    if not model or not url or not endpoint:
        logger.error(
            f"Missing required parameter: model={model!r}, url={url!r}, endpoint={endpoint!r}"
        )
        return False

    # Build AI-Perf command
    cmd = [
        "aiperf",
        "profile",
        # Model configuration (required)
        "--model",
        model,
        # Endpoint configuration
        "--url",
        url,
        "--endpoint",
        endpoint if endpoint.startswith("/") else f"/{endpoint}",
        "--endpoint-type",
        "chat",  # Required: tells AI-Perf the API type
        # Enable streaming for TTFT and ITL metrics
        "--streaming",
        # Request parameters
        "--concurrency",
        "1",  # Optional: we set to 1 for sequential
251
252
253
254
        "--request-rate",
        str(max_request_rate),  # Rate limiting (requests/sec)
        "--request-rate-mode",
        "constant",  # Use constant arrival pattern for predictable rate
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
        # Token configuration
        "--synthetic-input-tokens-mean",
        str(input_token_length),
        "--synthetic-input-tokens-stddev",
        "0",  # Set to 0 for consistent token counts
        "--output-tokens-mean",
        str(output_token_length),
        "--output-tokens-stddev",
        "0",  # Set to 0 for consistent token counts
        # Skip warmup to avoid initial failures
        "--warmup-request-count",
        "0",
        # Output configuration
        "--artifact-dir",
        str(output_dir),
        "--random-seed",
        "100",  # For reproducible results
    ]

274
275
276
277
278
279
280
    if continuous_load:
        cmd.extend(["--benchmark-duration", "1800"])  # 30 minutes for continuous load
        logger.info("Using continuous load with duration: 30 minutes")
        timeout = 1860  # 31 minutes default for duration-based tests (30 minutes + 1 minute buffer)
    else:
        cmd.extend(["--request-count", str(requests_per_client)])
        timeout = max(requests_per_client * 2 + 60, 300)  # At least 5 minutes
281
282
283
284
285

    # Log execution
    logger.info(f"Starting AI-Perf for Pod {pod_name} Local Port {port}")
    logger.info(f"Using model name: {model}")

286
287
288
289
    # Wait for model to be available initially
    # Note: We only check once at start, then clients continue sending requests
    # regardless of service health. This mimics real-world scenarios where clients
    # don't know the server is down and continue retrying.
Tzu-Ling Kan's avatar
Tzu-Ling Kan committed
290
291
292
    model_ready = wait_for_model_availability(url, endpoint, model, logger)
    if not model_ready:
        logger.warning("Model not ready, but proceeding with AI-Perf test anyway")
293
        # Clients will continue attempting - measuring failure/recovery is the point
294
295
296
297

    logger.info(f"Command: {' '.join(cmd)}")

    # Retry logic for fault tolerance - retry FULL request count until success
298
299
    # Note: For continuous load, we only run once and expect SIGINT to stop it
    max_attempts = 1 if continuous_load else (max_retries if max_retries > 0 else 1)
300
301
302
    success = False

    for attempt in range(max_attempts):
303
304
305
306
307
308
309
310
        if continuous_load:
            logger.info(
                "AI-Perf continuous load (will run until interrupted by SIGINT)"
            )
        else:
            logger.info(
                f"AI-Perf attempt {attempt + 1}/{max_attempts} with {requests_per_client} requests"
            )
311
312
313
314
315
316
317
318
319
320
321

        # Update output directory for this attempt
        attempt_dir = output_dir / f"attempt_{attempt}"
        attempt_dir.mkdir(parents=True, exist_ok=True)

        # Use the original command but update artifact directory
        cmd_attempt = cmd.copy()
        artifact_dir_idx = cmd_attempt.index("--artifact-dir") + 1
        cmd_attempt[artifact_dir_idx] = str(attempt_dir)

        try:
322
            result = run_aiperf_with_signal_handling(cmd_attempt, logger, timeout)
323
324
325
326
327
328
329

            # Save logs for this attempt
            with open(attempt_dir / "genai_perf.log", "w") as f:
                f.write("=== STDOUT ===\n")
                f.write(result.stdout)
                f.write("\n\n=== STDERR ===\n")
                f.write(result.stderr)
330

331
            if result.returncode == 0:
Tzu-Ling Kan's avatar
Tzu-Ling Kan committed
332
333
334
335
336
337
338
339
340
341
                # AI-Perf returns 0 even if all requests failed, so we need to check the output
                json_path = attempt_dir / "profile_export_aiperf.json"
                success = validate_aiperf_results(
                    json_path=json_path,
                    requests_per_client=requests_per_client,
                    attempt=attempt,
                    logger=logger,
                    attempt_dir=attempt_dir,
                    pod_name=pod_name,
                    port=port,
342
                )
Tzu-Ling Kan's avatar
Tzu-Ling Kan committed
343
344
                if success:
                    break  # Success - exit the retry loop
345
            ## TODO: bug with aiperf git+https://github.com/ai-dynamo/aiperf.git@54cd6dc820bff8bfebc875da104e59d745e14f75
346
347
348
349
350
351
352
353
354
355
356
357
            ## where sending a SIGINT on Mac can sometimes have an error code of -9 (SIGABRT) which results in profile_export_aiperf.json not being created
            elif result.returncode == -9 and continuous_load:
                logger.warning(
                    f"""
                    Attempt {attempt + 1} failed with return code {result.returncode}
                    This is a known bug with aiperf on Mac where sending a SIGINT can sometimes have an error code of -9 (SIGABRT)
                    which results in profile_export_aiperf.json not being created
                    """
                )
                logger.debug(
                    f"Stderr: {result.stderr[:500] if result.stderr else 'No stderr'}"
                )
358
            else:
359
360
361
362
363
364
365
366
367
                logger.warning(
                    f"Attempt {attempt + 1} failed with return code {result.returncode}"
                )
                logger.debug(
                    f"Stderr: {result.stderr[:500] if result.stderr else 'No stderr'}"
                )
        except Exception as e:
            logger.error(f"Error in attempt {attempt + 1}: {str(e)}")

368
369
        # Sleep before next attempt (if not the last attempt and not continuous load)
        if not success and attempt < max_attempts - 1 and not continuous_load:
370
            retry_delay = 5  # Hardcoded delay between retry attempts
371
372
            time.sleep(retry_delay)

373
    if success and not continuous_load:
374
375
376
        logger.info(
            f"AI-Perf successfully completed all {requests_per_client} requests for {pod_name}"
        )
377
378
379
380
    elif success and continuous_load:
        logger.info(
            f"AI-Perf sustained continuous load for {pod_name} and existed succesfully"
        )
381
382
383
384
385
386
    else:
        logger.error(f"AI-Perf failed all {max_attempts} attempts for {pod_name}")

    return success


387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
# TODO: use file redirection and wait() instead of pipes and communicate
def run_aiperf_with_signal_handling(
    cmd_attempt: List[str],
    logger: logging.Logger,
    timeout: int,
) -> subprocess.CompletedProcess:
    """
    Run aiperf with signal handling for graceful shutdown.

    Handles SIGINT and SIGTERM forwarding and timeout when running with subprocess.Popen.
    This ensures that Ctrl-C (SIGINT) and graceful termination signals (SIGTERM)
    are properly forwarded to the subprocess so it can clean up gracefully and write results files.
    """
    proc = subprocess.Popen(
        cmd_attempt,
        stdout=subprocess.PIPE,
        stderr=subprocess.PIPE,
        text=True,
        stdin=subprocess.DEVNULL,
    )

    def signal_handler(signum, frame):
        signal_names = {
            signal.SIGINT: "SIGINT",
            signal.SIGTERM: "SIGTERM",
        }
        signal_name = signal_names.get(signum, f"signal {signum}")
        logger.info(f"Received {signal_name}, forwarding to aiperf subprocess")
        try:
            proc.send_signal(signum)
        except ProcessLookupError:
            pass  # Process already terminated

    signal.signal(signal.SIGINT, signal_handler)
    signal.signal(signal.SIGTERM, signal_handler)

    try:
        stdout, stderr = proc.communicate(timeout=timeout)
        returncode = proc.returncode
    except subprocess.TimeoutExpired:
        logger.warning(f"AI-Perf subprocess timed out after {timeout}s")
        proc.kill()
        stdout, stderr = proc.communicate()
        returncode = proc.returncode
    except KeyboardInterrupt:
        logger.info("Received KeyboardInterrupt, sending SIGINT to aiperf subprocess")
        proc.send_signal(signal.SIGINT)
        try:
            stdout, stderr = proc.communicate(timeout=30)  # Give it time to clean up
            returncode = proc.returncode
        except subprocess.TimeoutExpired:
            logger.warning("Subprocess didn't terminate gracefully, killing it")
            proc.kill()
            stdout, stderr = proc.communicate()
            returncode = proc.returncode

    return subprocess.CompletedProcess(cmd_attempt, returncode, stdout, stderr)


446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
def log_summary_metrics(
    output_dir: Path, logger: logging.Logger, pod_name: str, port: int
) -> None:
    """
    Log summary metrics from AI-Perf results.

    Args:
        output_dir: Directory containing AI-Perf artifacts
        logger: Logger instance
        pod_name: Pod name for logging
        port: Port number for logging
    """
    # Look for AI-Perf output file
    profile_json = output_dir / "profile_export_aiperf.json"
    if not profile_json.exists():
        # Try alternative names
        for name in ["profile_export.json", "profile_results.json"]:
            alt_path = output_dir / name
            if alt_path.exists():
                profile_json = alt_path
466
467
                break

468
469
470
471
472
    if profile_json.exists():
        try:
            with open(profile_json) as f:
                metrics = json.load(f)

473
474
            # Request count
            request_count = int(metrics.get("request_count", {}).get("avg", 0))
475

476
            # Check for errors
477
            error_count = len(metrics.get("error_summary", []))
478
479

            # Latency metrics (in milliseconds)
480
            request_latency = metrics.get("request_latency", {})
481
482
483
484
            avg_latency = request_latency.get("avg", 0) / 1000.0  # Convert to seconds
            p99_latency = request_latency.get("p99", 0) / 1000.0  # Convert to seconds

            # Throughput metrics
485
            throughput = metrics.get("request_throughput", {}).get("avg", 0)
486
487
488
489
490
491
492
493
494
495
496
497
498

            # Log summary
            logger.info(
                f"Summary: Pod {pod_name} Port {port} "
                f"Requests: {request_count} "
                f"Errors: {error_count} "
                f"Throughput: {throughput:.1f} req/s "
                f"Avg Latency: {avg_latency:.3f}s "
                f"P99 Latency: {p99_latency:.3f}s"
            )

            # Log success rate
            if request_count > 0:
499
                success_rate = ((request_count - error_count) / request_count) * 100
500
501
502
503
504
505
506
507
508
                logger.info(f"Success rate: {success_rate:.1f}%")

            # Also write summary to CSV file for aggregation
            csv_path = output_dir / "profile_export_aiperf.csv"
            if csv_path.exists():
                logger.info(f"AI-Perf results saved to {csv_path}")

        except Exception as e:
            logger.warning(f"Failed to parse AI-Perf metrics: {e}")
509
510
511
512


def client(
    deployment_spec,
513
514
515
516
517
518
519
520
    namespace: str,
    model: str,
    log_dir: str,
    index: int,
    requests_per_client: int,
    input_token_length: int,
    output_token_length: int,
    max_retries: int,
521
    max_request_rate: float = 1.0,
522
    continuous_load: bool = False,
523
):
524
525
526
527
528
529
530
531
532
533
534
535
536
    """
    Generate load using AI-Perf for fault tolerance testing.

    This function sets up port forwarding to a frontend pod and uses AI-Perf
    to generate synthetic requests for performance testing and fault tolerance
    evaluation.

    Args:
        deployment_spec: Deployment specification object
        namespace: Kubernetes namespace
        model: Model name
        log_dir: Directory for output logs and AI-Perf artifacts
        index: Client index used for round-robin pod selection
537
        requests_per_client: Number of requests to generate (used if continuous load not enabled)
538
539
540
        input_token_length: Number of input tokens per request
        output_token_length: Number of output tokens per request
        max_retries: Maximum retry attempts for AI-Perf execution
541
        max_request_rate: Maximum requests per second for rate limiting (default: 1.0)
542
        continuous_load: If True, use continuous load instead of fixed request count
543
    """
544
545
546
547
548
549
550
551
    logger = logging.getLogger(f"CLIENT: {index}")
    logging.getLogger("httpx").setLevel(logging.WARNING)

    managed_deployment = ManagedDeployment(log_dir, deployment_spec, namespace)
    pod_ports: Dict[str, Any] = {}

    try:
        os.makedirs(log_dir, exist_ok=True)
552
553
554
555
        client_output_dir = Path(log_dir) / f"client_{index}"
        client_output_dir.mkdir(parents=True, exist_ok=True)

        # Add a startup delay for early clients to give model time to load
Tzu-Ling Kan's avatar
Tzu-Ling Kan committed
556
        time.sleep(15)
557
558
559
560
561
562
563
564
565
566
567
568
569

        # Select frontend pod and setup port forwarding
        pod_name, port, selected_pod = get_frontend_port(
            managed_deployment=managed_deployment,
            client_index=index,
            deployment_spec=deployment_spec,
            pod_ports=pod_ports,
            logger=logger,
        )

        if not pod_name or not port:
            logger.error("Failed to select pod or setup port forwarding")
            return
570

571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
        url = f"http://localhost:{port}"

        # Get endpoint from deployment_spec (default: /v1/chat/completions)
        endpoint = getattr(deployment_spec, "_endpoint", "/v1/chat/completions")

        success = run_aiperf(
            url=url,
            endpoint=endpoint,
            model=model,
            pod_name=pod_name,
            port=port,
            requests_per_client=requests_per_client,
            input_token_length=input_token_length,
            output_token_length=output_token_length,
            output_dir=client_output_dir,
            logger=logger,
            max_retries=max_retries,
588
            max_request_rate=max_request_rate,
589
            continuous_load=continuous_load,
590
591
592
593
        )

        if not success:
            logger.error("AI-Perf execution failed")
594
595

    except Exception as e:
596
597
598
599
600
601
602
603
604
        logger.error(f"Client error: {str(e)}")
    finally:
        for pf_name, port_forward in pod_ports.items():
            try:
                port_forward.stop()
                logger.debug(f"Stopped port forward for {pf_name}")
            except Exception as e:
                logger.debug(f"Error stopping port forward for {pf_name}: {e}")

605
    logger.info("Exiting")