Skip to content

Commit 0713ea3

Browse files
committed
feat(logging): attach structured JSON logging with sessionId to root logger
1 parent e952dae commit 0713ea3

6 files changed

Lines changed: 218 additions & 12 deletions

File tree

examples/strands_math_agent/basic_app.py

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,14 @@
1+
import logging
2+
13
from bedrock_agentcore.runtime import BedrockAgentCoreApp
24
from dotenv import load_dotenv
35
from strands import Agent
46
from strands.models import BedrockModel
57
from strands_tools import calculator
68

9+
logging.basicConfig(level=logging.INFO)
10+
logger = logging.getLogger(__name__)
11+
712
app = BedrockAgentCoreApp()
813

914
load_dotenv()
@@ -28,7 +33,7 @@ def invoke_agent(payload):
2833
"""
2934
user_input = payload.get("prompt")
3035

31-
print("User input:", user_input)
36+
logger.info("User input: %s", user_input)
3237

3338
response = agent(user_input)
3439

examples/strands_math_agent/rl_app.py

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,15 @@
1+
import logging
2+
13
from reward import GSM8KReward
24
from strands import Agent
35
from strands.models.openai import OpenAIModel
46
from strands_tools import calculator
57

68
from agentcore_rl_toolkit import AgentCoreRLApp
79

10+
logging.basicConfig(level=logging.INFO)
11+
logger = logging.getLogger(__name__)
12+
813
app = AgentCoreRLApp()
914

1015
system_prompt = (
@@ -51,7 +56,7 @@ def invoke_agent(payload: dict):
5156
user_input = payload.get("prompt")
5257
answer = payload.get("answer") # used for computing reward
5358

54-
print("User input:", user_input)
59+
logger.info("User input: %s", user_input)
5560

5661
response = agent(user_input)
5762

examples/strands_migration_agent/reward.py

Lines changed: 7 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import logging
12
import os
23
import shutil
34
import tempfile
@@ -7,6 +8,8 @@
78

89
from agentcore_rl_toolkit import RewardFunction
910

11+
logger = logging.getLogger(__name__)
12+
1013

1114
class MigrationReward(RewardFunction):
1215
def __call__(
@@ -33,21 +36,21 @@ def __call__(
3336
shutil.copytree(repo_dir, temp_repo_dir)
3437

3538
if self.eval_build_success(repo_dir=temp_repo_dir, require_maximal_migration=require_maximal_migration):
36-
print("build succeeded!")
39+
logger.info("build succeeded!")
3740
reward += 0.5
3841
else:
39-
print("build failed!")
42+
logger.info("build failed!")
4043
return reward
4144

4245
if self.eval_test_equivalence(
4346
repo_dir=temp_repo_dir,
4447
original_num_tests=original_num_tests,
4548
original_commit_id=original_commit_id,
4649
):
47-
print("test equivalence check passed!")
50+
logger.info("test equivalence check passed!")
4851
reward += 0.5
4952
else:
50-
print("test equivalence check failed!")
53+
logger.info("test equivalence check failed!")
5154

5255
return reward
5356

src/agentcore_rl_toolkit/app.py

Lines changed: 11 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,10 @@
99
import boto3
1010
from bedrock_agentcore.runtime import BedrockAgentCoreApp
1111

12+
from .logging import configure_logging
13+
14+
logger = logging.getLogger(__name__)
15+
1216
_S3_CONFIG_FIELDS = ("exp_id", "input_id", "s3_bucket")
1317

1418

@@ -36,6 +40,7 @@ def from_dict(cls, data: dict) -> "RolloutConfig":
3640
class AgentCoreRLApp(BedrockAgentCoreApp):
3741
def __init__(self):
3842
super().__init__()
43+
configure_logging()
3944
self.s3_client = boto3.client("s3")
4045

4146
def save_result(self, result: dict, rollout_config: dict, result_key: str, payload: dict = None):
@@ -67,7 +72,7 @@ def save_result(self, result: dict, rollout_config: dict, result_key: str, paylo
6772
try:
6873
config = RolloutConfig.from_dict(rollout_config)
6974
except ValueError as e:
70-
logging.error(f"Invalid rollout configuration: {e}")
75+
logger.error(f"Invalid rollout configuration: {e}")
7176
raise
7277

7378
if "status_code" not in result:
@@ -93,9 +98,9 @@ def save_result(self, result: dict, rollout_config: dict, result_key: str, paylo
9398
Body=json.dumps(result, indent=2),
9499
ContentType="application/json",
95100
)
96-
logging.info(f"Stored complete results at {result_key}")
101+
logger.info(f"Stored complete results at {result_key}")
97102
except Exception as e:
98-
logging.error(f"Failed to store results in S3: {e}")
103+
logger.error(f"Failed to store results in S3: {e}")
99104
raise
100105

101106
def rollout_entrypoint(self, func):
@@ -160,7 +165,7 @@ async def rollout_background_task(payload, context, result_key):
160165
payload=payload,
161166
result_key=result_key,
162167
)
163-
logging.info(f"Result saved for function: {func.__name__}")
168+
logger.info(f"Result saved for function: {func.__name__}")
164169

165170
return result
166171

@@ -181,9 +186,9 @@ async def rollout_background_task(payload, context, result_key):
181186
payload=payload,
182187
result_key=result_key,
183188
)
184-
logging.error(f"Error result saved for function: {func.__name__}: {e}")
189+
logger.error(f"Error result saved for function: {func.__name__}: {e}")
185190
except Exception:
186-
logging.error(f"Failed to save error result for function: {func.__name__}", exc_info=True)
191+
logger.error(f"Failed to save error result for function: {func.__name__}", exc_info=True)
187192
raise
188193
finally:
189194
# Complete the async task for logging and ping status
Lines changed: 58 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,58 @@
1+
import json
2+
import logging
3+
import traceback
4+
from datetime import datetime, timezone
5+
6+
7+
class CorrelatedFormatter(logging.Formatter):
8+
"""JSON formatter that injects sessionId and requestId from ACR request context."""
9+
10+
def format(self, record):
11+
from bedrock_agentcore.runtime import BedrockAgentCoreContext
12+
13+
log_entry = {
14+
"timestamp": datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%S.%f")[:-3] + "Z",
15+
"level": record.levelname,
16+
"message": record.getMessage(),
17+
"logger": record.name,
18+
}
19+
20+
request_id = BedrockAgentCoreContext.get_request_id()
21+
if request_id:
22+
log_entry["requestId"] = request_id
23+
24+
session_id = BedrockAgentCoreContext.get_session_id()
25+
if session_id:
26+
log_entry["sessionId"] = session_id
27+
28+
if record.exc_info and record.exc_info[0]:
29+
log_entry["errorType"] = record.exc_info[0].__name__
30+
log_entry["errorMessage"] = str(record.exc_info[1])
31+
log_entry["stackTrace"] = traceback.format_exception(*record.exc_info)
32+
33+
return json.dumps(log_entry, ensure_ascii=False)
34+
35+
36+
def configure_logging(level=logging.INFO):
37+
"""Attach CorrelatedFormatter to the root logger for automatic sessionId injection.
38+
39+
Idempotent — safe to call multiple times.
40+
"""
41+
root = logging.getLogger()
42+
if getattr(root, "_art_logging_configured", False):
43+
return
44+
45+
root.handlers.clear()
46+
47+
handler = logging.StreamHandler()
48+
handler.setFormatter(CorrelatedFormatter())
49+
root.addHandler(handler)
50+
# Use the more verbose level: honors user's basicConfig(level=DEBUG) even though we default to INFO.
51+
# Root default is WARNING (30); min(30, 20) = INFO; min(10, 20) = DEBUG.
52+
root.setLevel(min(root.level, level))
53+
54+
# The SDK's bedrock_agentcore.app logger already has its own JSON handler.
55+
# Suppress propagation to avoid duplicate output.
56+
logging.getLogger("bedrock_agentcore.app").propagate = False
57+
58+
root._art_logging_configured = True

tests/test_logging.py

Lines changed: 130 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,130 @@
1+
"""Tests for the structured logging module."""
2+
3+
import json
4+
import logging
5+
from unittest.mock import patch
6+
7+
import pytest
8+
9+
from agentcore_rl_toolkit.logging import CorrelatedFormatter, configure_logging
10+
11+
12+
@pytest.fixture(autouse=True)
13+
def reset_root_logger():
14+
"""Reset root logger state before each test."""
15+
root = logging.getLogger()
16+
original_handlers = root.handlers[:]
17+
original_level = root.level
18+
if hasattr(root, "_art_logging_configured"):
19+
delattr(root, "_art_logging_configured")
20+
yield
21+
root.handlers = original_handlers
22+
root.setLevel(original_level)
23+
if hasattr(root, "_art_logging_configured"):
24+
delattr(root, "_art_logging_configured")
25+
26+
27+
class TestCorrelatedFormatter:
28+
def test_outputs_valid_json(self):
29+
formatter = CorrelatedFormatter()
30+
record = logging.LogRecord(
31+
name="test.logger",
32+
level=logging.INFO,
33+
pathname="test.py",
34+
lineno=1,
35+
msg="hello %s",
36+
args=("world",),
37+
exc_info=None,
38+
)
39+
40+
output = formatter.format(record)
41+
parsed = json.loads(output)
42+
43+
assert parsed["level"] == "INFO"
44+
assert parsed["message"] == "hello world"
45+
assert parsed["logger"] == "test.logger"
46+
assert "timestamp" in parsed
47+
48+
@patch("bedrock_agentcore.runtime.BedrockAgentCoreContext.get_session_id", return_value="sess-123")
49+
@patch("bedrock_agentcore.runtime.BedrockAgentCoreContext.get_request_id", return_value="req-456")
50+
def test_includes_session_and_request_id(self, mock_req, mock_sess):
51+
formatter = CorrelatedFormatter()
52+
record = logging.LogRecord(
53+
name="test", level=logging.INFO, pathname="", lineno=0, msg="msg", args=(), exc_info=None
54+
)
55+
56+
parsed = json.loads(formatter.format(record))
57+
58+
assert parsed["sessionId"] == "sess-123"
59+
assert parsed["requestId"] == "req-456"
60+
61+
@patch("bedrock_agentcore.runtime.BedrockAgentCoreContext.get_session_id", return_value=None)
62+
@patch("bedrock_agentcore.runtime.BedrockAgentCoreContext.get_request_id", return_value=None)
63+
def test_omits_ids_when_no_context(self, mock_req, mock_sess):
64+
formatter = CorrelatedFormatter()
65+
record = logging.LogRecord(
66+
name="test", level=logging.INFO, pathname="", lineno=0, msg="msg", args=(), exc_info=None
67+
)
68+
69+
parsed = json.loads(formatter.format(record))
70+
71+
assert "sessionId" not in parsed
72+
assert "requestId" not in parsed
73+
74+
def test_includes_exception_info(self):
75+
formatter = CorrelatedFormatter()
76+
77+
try:
78+
raise ValueError("test error")
79+
except ValueError:
80+
import sys
81+
82+
exc_info = sys.exc_info()
83+
84+
record = logging.LogRecord(
85+
name="test", level=logging.ERROR, pathname="", lineno=0, msg="failed", args=(), exc_info=exc_info
86+
)
87+
88+
parsed = json.loads(formatter.format(record))
89+
90+
assert parsed["errorType"] == "ValueError"
91+
assert parsed["errorMessage"] == "test error"
92+
assert isinstance(parsed["stackTrace"], list)
93+
assert len(parsed["stackTrace"]) > 0
94+
95+
96+
class TestConfigureLogging:
97+
def test_attaches_handler_to_root(self):
98+
configure_logging()
99+
100+
root = logging.getLogger()
101+
assert len(root.handlers) == 1
102+
assert isinstance(root.handlers[0].formatter, CorrelatedFormatter)
103+
104+
def test_sets_root_level(self):
105+
configure_logging(level=logging.DEBUG)
106+
107+
assert logging.getLogger().level == logging.DEBUG
108+
109+
def test_idempotent(self):
110+
configure_logging()
111+
configure_logging()
112+
configure_logging()
113+
114+
assert len(logging.getLogger().handlers) == 1
115+
116+
def test_clears_existing_handlers(self):
117+
logging.basicConfig(level=logging.INFO)
118+
assert len(logging.getLogger().handlers) >= 1
119+
120+
configure_logging()
121+
122+
root = logging.getLogger()
123+
assert len(root.handlers) == 1
124+
assert isinstance(root.handlers[0].formatter, CorrelatedFormatter)
125+
126+
def test_suppresses_sdk_logger_propagation(self):
127+
configure_logging()
128+
129+
sdk_logger = logging.getLogger("bedrock_agentcore.app")
130+
assert sdk_logger.propagate is False

0 commit comments

Comments
 (0)