Skip to content

Commit c79320e

Browse files
committed
feat: add training job observability prints for script mode
1 parent 1572b32 commit c79320e

5 files changed

Lines changed: 224 additions & 10 deletions

File tree

Lines changed: 59 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,59 @@
1+
# Replace eval Rich spinner with plain-text observability output
2+
3+
Replaces the Rich Live spinner in the terminal `wait()` path with plain-text status prints that stream correctly to agents and piped processes.
4+
5+
## Problem
6+
7+
The eval `wait()` terminal path used a Rich Live spinner that:
8+
- Outputs ANSI escape sequences agents can't parse
9+
- Uses `transient=True` so output disappears after completion
10+
- Only shows "Current status: Executing" with no step details
11+
12+
## Changes
13+
14+
- Remove Rich Live spinner from terminal `wait()` path
15+
- Print pipeline name and execution ARN at start
16+
- Print step transitions with ✓/⋯, durations, and job ARNs on each poll
17+
- Print "Running... Xs" elapsed timer for in-progress steps
18+
- Print S3 output path on success
19+
- Print failed step details with log group and CloudWatch link on failure
20+
- All prints use `flush=True` for agent compatibility
21+
- Log group derived from job ARN type (training/processing/transform)
22+
23+
Jupyter path is unchanged.
24+
25+
## Example output
26+
27+
```
28+
Evaluation started: eval-meta-5190c33c
29+
Pipeline: SagemakerEvaluation-LLMAJEvaluation-565d3249
30+
Execution ARN: arn:aws:sagemaker:us-west-2:099324990371:pipeline/.../execution/rstzamudixmz
31+
32+
--------------------------------------
33+
34+
Status Transitions:
35+
✓ CreateEvaluationAction: Succeeded (3.0s)
36+
⋯ EvaluateCustomInferenceModel: Executing (Running... 17s)
37+
Job ARN: arn:aws:sagemaker:us-west-2:099324990371:training-job/CustomInference-rstzamudixmz-6ZP4YbszZc
38+
39+
Status: Executing (Elapsed: 21.5s)
40+
```
41+
42+
On failure:
43+
```
44+
Failed
45+
Failure reason: Step failure: One or multiple steps failed.
46+
47+
Failed step: EvaluateCustomInferenceModel
48+
Failure reason: ClientError: No S3 objects found under S3 URL...
49+
Job ARN: arn:aws:sagemaker:us-west-2:099324990371:training-job/CustomInference-xyz
50+
Log group: /aws/sagemaker/TrainingJobs
51+
Log stream prefix: CustomInference-xyz
52+
CloudWatch Logs: https://us-west-2.console.aws.amazon.com/cloudwatch/...
53+
```
54+
55+
## Testing
56+
57+
- 382 existing unit tests pass (0 regressions)
58+
- 4 new tests covering start, step transitions, success, and failure output
59+
- Manually validated with real LLM-as-Judge eval jobs
Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,26 @@
1+
# Expose poll interval parameter on all trainers
2+
3+
Adds a `poll` parameter to `train()` on SFTTrainer, DPOTrainer, RLVRTrainer, and RLAIFTrainer, allowing callers to control how frequently the SDK polls for training job status updates.
4+
5+
## Problem
6+
7+
The `trainer_wait.wait()` function already accepts a `poll` parameter (default 5s), but there was no way to configure it from the trainer API. Users running in agent/script contexts want longer intervals (e.g., 30s) to reduce output noise and API calls.
8+
9+
## Changes
10+
11+
- Add `poll: int = 5` parameter to `train()` on all 4 trainers
12+
- Pass through to `trainer_wait.wait()` via `wait_kwargs`
13+
- Add docstring for the new parameter
14+
15+
```python
16+
# Before: no way to control poll interval
17+
trainer.train(wait=True)
18+
19+
# After: configurable
20+
trainer.train(wait=True, poll=30)
21+
```
22+
23+
## Testing
24+
25+
- 93 existing trainer unit tests pass (assertions updated to include `poll=5`)
26+
- Manually validated with SFT and RLAIF jobs showing correct 10s intervals
Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
# Add training job observability prints for script mode
2+
3+
Adds structured output at job start and on failure so users and agents always know where to find logs without scrolling or guessing.
4+
5+
## Problem
6+
7+
The terminal wait path printed only `TrainingJob Name:` at start and raised an exception on failure with no debug links. Users had to manually construct CloudWatch URLs or find the job in the console.
8+
9+
## Changes
10+
11+
- Print job name, log group, and log stream prefix at start
12+
- Print failure reason, log group, stream prefix, and CloudWatch Logs URL on failure
13+
- Add `flush=True` to all prints for agent compatibility
14+
- Preserve existing behavior: MLflow link on success, loss metrics by epoch
15+
16+
## Example output
17+
18+
At start:
19+
```
20+
Training job started: meta-textgeneration-llama-3-1-8b-instruct-sft-20260514
21+
Log group: /aws/sagemaker/TrainingJobs
22+
Log stream prefix: meta-textgeneration-llama-3-1-8b-instruct-sft-20260514
23+
```
24+
25+
On failure:
26+
```
27+
Failure reason: ClientError: Unable to download training image...
28+
29+
Log group: /aws/sagemaker/TrainingJobs
30+
Log stream prefix: meta-textgeneration-llama-3-1-8b-instruct-sft-20260514
31+
CloudWatch Logs: https://us-west-2.console.aws.amazon.com/cloudwatch/home?region=us-west-2#logsV2:log-groups/log-group/$252Faws$252Fsagemaker$252FTrainingJobs$3FlogStreamNameFilter$3Dmeta-textgeneration-llama-3-1-8b-instruct-sft-20260514
32+
```
33+
34+
## Testing
35+
36+
- 277 existing unit tests pass (0 regressions)
37+
- 4 new tests covering start prints, failure debug info, and CloudWatch URL generation
38+
- Manually validated with SFT and DPO jobs

‎sagemaker-train/src/sagemaker/train/common_utils/trainer_wait.py‎

Lines changed: 23 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -419,7 +419,9 @@ def get_cached_mlflow_url():
419419
raise TimeoutExceededError(resource_type="TrainingJob", status=status)
420420

421421
else:
422-
print(f"\nTrainingJob Name: {training_job.training_job_name}")
422+
print(f"\nTraining job started: {training_job.training_job_name}", flush=True)
423+
print(f"Log group: /aws/sagemaker/TrainingJobs", flush=True)
424+
print(f"Log stream prefix: {training_job.training_job_name}", flush=True)
423425
iteration = 0
424426
while True:
425427
iteration += 1
@@ -432,8 +434,8 @@ def get_cached_mlflow_url():
432434

433435
# Show transitions with checkmarks
434436
if training_job.secondary_status_transitions:
435-
print("\n--------------------------------------\n")
436-
print("Status Transitions:")
437+
print("\n--------------------------------------\n", flush=True)
438+
print("Status Transitions:", flush=True)
437439
for trans in training_job.secondary_status_transitions:
438440
duration, check = _calculate_transition_duration(trans)
439441

@@ -452,28 +454,39 @@ def get_cached_mlflow_url():
452454
if progress_pct is not None:
453455
step_msg += f" - {progress_pct:.1f}%{progress_text.replace(chr(10), ', ')}"
454456

455-
print(step_msg)
456-
print(f"\nStatus: {status} - {secondary_status} (Elapsed: {elapsed:.1f}s)")
457+
print(step_msg, flush=True)
458+
print(f"\nStatus: {status} - {secondary_status} (Elapsed: {elapsed:.1f}s)", flush=True)
457459

458460
if status in ["Completed", "Failed", "Stopped"]:
459461
if status == "Completed":
460462
if mlflow_url:
461-
print(f"\n✓ Training completed! View metrics in MLflow: {mlflow_url}")
463+
print(f"\n✓ Training completed! View metrics in MLflow: {mlflow_url}", flush=True)
462464
try:
463465
steps_per_epoch = training_job.progress_info.total_step_count_per_epoch
464466
loss_metrics_by_epoch = metrics_util._get_loss_metrics_by_epoch(run_name=mlflow_run_name,
465467
steps_per_epoch=steps_per_epoch)
466468
if loss_metrics_by_epoch:
467-
print("\n------------ Loss Metrics by Epoch ------------")
469+
print("\n------------ Loss Metrics by Epoch ------------", flush=True)
468470
for epoch, metrics in list(loss_metrics_by_epoch.items())[:-1]:
469-
print(f"Epoch {epoch}: {metrics}")
470-
print("----------------------------------------------")
471+
print(f"Epoch {epoch}: {metrics}", flush=True)
472+
print("----------------------------------------------", flush=True)
471473
except Exception:
472474
pass
475+
if status == "Failed":
476+
failure_reason = training_job.failure_reason
477+
if failure_reason and not _is_unassigned_attribute(failure_reason):
478+
print(f"\nFailure reason: {failure_reason}", flush=True)
479+
print(f"\nLog group: /aws/sagemaker/TrainingJobs", flush=True)
480+
print(f"Log stream prefix: {training_job.training_job_name}", flush=True)
481+
from sagemaker.train.common_utils.metrics_visualizer import get_cloudwatch_logs_url
482+
cw_url = get_cloudwatch_logs_url(training_job.training_job_arn)
483+
if cw_url:
484+
print(f"CloudWatch Logs: {cw_url}", flush=True)
485+
raise FailedStatusError(resource_type="TrainingJob", status=status, reason=failure_reason)
473486
return
474487

475488
failure_reason = training_job.failure_reason
476-
if status == "Failed" or (failure_reason and not _is_unassigned_attribute(failure_reason)):
489+
if failure_reason and not _is_unassigned_attribute(failure_reason):
477490
raise FailedStatusError(resource_type="TrainingJob", status=status, reason=failure_reason)
478491

479492
if timeout and elapsed >= timeout:
Lines changed: 78 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,78 @@
1+
"""Tests for training job observability prints in script/terminal mode."""
2+
import time
3+
from unittest.mock import MagicMock, patch
4+
5+
import pytest
6+
7+
from sagemaker.train.common_utils.trainer_wait import wait, _is_unassigned_attribute
8+
9+
10+
class MockUnassigned:
11+
pass
12+
13+
14+
class MockTrainingJob:
15+
def __init__(self, status="Completed", failure_reason=None):
16+
self.training_job_name = "test-sft-job-2026"
17+
self.training_job_arn = "arn:aws:sagemaker:us-west-2:123456789:training-job/test-sft-job-2026"
18+
self.training_job_status = status
19+
self.secondary_status = "Training"
20+
self.secondary_status_transitions = []
21+
self.progress_info = MockUnassigned()
22+
self.failure_reason = failure_reason
23+
self.mlflow_config = MockUnassigned()
24+
self._call_count = 0
25+
26+
def refresh(self):
27+
self._call_count += 1
28+
29+
30+
class TestTrainingObservabilityAtStart:
31+
"""Test that job info is printed at start in terminal mode."""
32+
33+
@patch("sagemaker.train.common_utils.trainer_wait._is_jupyter_environment", return_value=False)
34+
@patch("sagemaker.train.common_utils.trainer_wait._setup_mlflow_integration", return_value=(None, None, None))
35+
def test_prints_job_info_at_start(self, mock_mlflow, mock_jupyter, capsys):
36+
job = MockTrainingJob(status="Completed")
37+
wait(job, poll=0, timeout=1)
38+
captured = capsys.readouterr()
39+
assert "Training job started: test-sft-job-2026" in captured.out
40+
assert "Log group: /aws/sagemaker/TrainingJobs" in captured.out
41+
assert "Log stream prefix: test-sft-job-2026" in captured.out
42+
43+
44+
class TestTrainingObservabilityOnFailure:
45+
"""Test that debug info is printed on failure."""
46+
47+
@patch("sagemaker.train.common_utils.trainer_wait._is_jupyter_environment", return_value=False)
48+
@patch("sagemaker.train.common_utils.trainer_wait._setup_mlflow_integration", return_value=(None, None, None))
49+
def test_prints_debug_info_on_failure(self, mock_mlflow, mock_jupyter, capsys):
50+
job = MockTrainingJob(status="Failed", failure_reason="OOM error")
51+
with pytest.raises(Exception):
52+
wait(job, poll=0, timeout=1)
53+
captured = capsys.readouterr()
54+
assert "Failure reason: OOM error" in captured.out
55+
assert "Log group: /aws/sagemaker/TrainingJobs" in captured.out
56+
assert "Log stream prefix: test-sft-job-2026" in captured.out
57+
assert "CloudWatch Logs:" in captured.out
58+
59+
@patch("sagemaker.train.common_utils.trainer_wait._is_jupyter_environment", return_value=False)
60+
@patch("sagemaker.train.common_utils.trainer_wait._setup_mlflow_integration", return_value=(None, None, None))
61+
def test_prints_cloudwatch_url_on_failure(self, mock_mlflow, mock_jupyter, capsys):
62+
job = MockTrainingJob(status="Failed", failure_reason="ClientError")
63+
with pytest.raises(Exception):
64+
wait(job, poll=0, timeout=1)
65+
captured = capsys.readouterr()
66+
assert "us-west-2.console.aws.amazon.com/cloudwatch" in captured.out
67+
68+
69+
class TestTrainingObservabilityOnSuccess:
70+
"""Test that MLflow link is printed on success (existing behavior preserved)."""
71+
72+
@patch("sagemaker.train.common_utils.trainer_wait._is_jupyter_environment", return_value=False)
73+
@patch("sagemaker.train.common_utils.trainer_wait._setup_mlflow_integration", return_value=("https://mlflow.example.com", None, None))
74+
def test_prints_mlflow_on_success(self, mock_mlflow, mock_jupyter, capsys):
75+
job = MockTrainingJob(status="Completed")
76+
wait(job, poll=0, timeout=1)
77+
captured = capsys.readouterr()
78+
assert "mlflow.example.com" in captured.out

0 commit comments

Comments
 (0)