feat: implement AWS Lambda compatible JSON logging (#76)

* feat: implement AWS Lambda compatible JSON logging

Replace RequestContextFormatter with AWS Lambda JSON format:
- Add structured JSON output with timestamp, level, message, logger fields
- Include requestId and sessionId when available
- Add exception handling with errorType, errorMessage, stackTrace, location
- Update exception logging to use logger.exception() for proper capture
- Update tests to validate JSON format structure

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>

* fix: eliminate duplicate exception logging in handler chain

Change _invoke_handler exception logging from ERROR to DEBUG level to prevent
duplicate logs when exceptions bubble up to _handle_invocation. The outer handler
provides better context with timing information.

Before: Two identical ERROR logs for same exception
After: Single ERROR log with duration metrics

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>

* fix: enable debug mode in integration test to resolve timeout

Add debug=True to BedrockAgentCoreApp in test_simple_agent.py to enable
verbose logging that will help identify the root cause of the 5-minute
timeout in CI integration tests.

This provides better visibility into server startup issues.

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>

---------

Co-authored-by: Abhimanyu Siwach <siwabhi@amazon.com>
Co-authored-by: Claude <noreply@anthropic.com>

Author: 3 people

src/bedrock_agentcore/runtime/app.py

@@ -37,18 +37,34 @@ class RequestContextFormatter(logging.Formatter):
     """Formatter including request and session IDs."""
 
     def format(self, record):
-        """Format log record with request and session ID context."""
-        request_id = BedrockAgentCoreContext.get_request_id()
-        session_id = BedrockAgentCoreContext.get_session_id()
+        """Format log record as AWS Lambda JSON."""
+        import json
+        from datetime import datetime
 
-        parts = []
+        log_entry = {
+            "timestamp": datetime.utcnow().strftime("%Y-%m-%dT%H:%M:%S.%f")[:-3] + "Z",
+            "level": record.levelname,
+            "message": record.getMessage(),
+            "logger": record.name,
+        }
+
+        request_id = BedrockAgentCoreContext.get_request_id()
         if request_id:
-            parts.append(f"[rid:{request_id}]")
+            log_entry["requestId"] = request_id
+
+        session_id = BedrockAgentCoreContext.get_session_id()
         if session_id:
-            parts.append(f"[sid:{session_id}]")
+            log_entry["sessionId"] = session_id
+
+        if record.exc_info:
+            import traceback
+
+            log_entry["errorType"] = record.exc_info[0].__name__
+            log_entry["errorMessage"] = str(record.exc_info[1])
+            log_entry["stackTrace"] = traceback.format_exception(*record.exc_info)
+            log_entry["location"] = f"{record.pathname}:{record.funcName}:{record.lineno}"
 
-        record.request_id = " ".join(parts) + " " if parts else ""
-        return super().format(record)
+        return json.dumps(log_entry, ensure_ascii=False)
 
 
 class BedrockAgentCoreApp(Starlette):
@@ -78,7 +94,7 @@ def __init__(self, debug: bool = False, lifespan: Optional[Lifespan] = None):
         self.logger = logging.getLogger("bedrock_agentcore.app")
         if not self.logger.handlers:
             handler = logging.StreamHandler()
-            formatter = RequestContextFormatter("%(asctime)s - %(name)s - %(levelname)s - %(request_id)s%(message)s")
+            formatter = RequestContextFormatter()
             handler.setFormatter(formatter)
             self.logger.addHandler(handler)
             self.logger.setLevel(logging.DEBUG if self.debug else logging.INFO)
@@ -128,11 +144,9 @@ async def wrapper(*args, **kwargs):
                 duration = time.time() - start_time
                 self.logger.info("Async task completed: %s (%.3fs)", func.__name__, duration)
                 return result
-            except Exception as e:
+            except Exception:
                 duration = time.time() - start_time
-                self.logger.error(
-                    "Async task failed: %s (%.3fs) - %s: %s", func.__name__, duration, type(e).__name__, e
-                )
+                self.logger.exception("Async task failed: %s (%.3fs)", func.__name__, duration)
                 raise
             finally:
                 self.complete_async_task(task_id)
@@ -333,8 +347,8 @@ def _handle_ping(self, request):
             status = self.get_current_ping_status()
             self.logger.debug("Ping request - status: %s", status.value)
             return JSONResponse({"status": status.value, "time_of_last_update": int(self._last_status_update_time)})
-        except Exception as e:
-            self.logger.error("Ping endpoint failed: %s: %s", type(e).__name__, e)
+        except Exception:
+            self.logger.exception("Ping endpoint failed")
             return JSONResponse({"status": PingStatus.HEALTHY.value, "time_of_last_update": int(time.time())})
 
     def run(self, port: int = 8080, host: Optional[str] = None):
@@ -365,9 +379,9 @@ async def _invoke_handler(self, handler, request_context, takes_context, payload
                 loop = asyncio.get_event_loop()
                 ctx = contextvars.copy_context()
                 return await loop.run_in_executor(None, ctx.run, handler, *args)
-        except Exception as e:
+        except Exception:
             handler_name = getattr(handler, "__name__", "unknown")
-            self.logger.error("Handler '%s' execution failed: %s: %s", handler_name, type(e).__name__, e)
+            self.logger.debug("Handler '%s' execution failed", handler_name)
             raise
 
     def _handle_task_action(self, payload: dict) -> Optional[JSONResponse]:
@@ -413,7 +427,7 @@ def _handle_task_action(self, payload: dict) -> Optional[JSONResponse]:
             return JSONResponse({"error": f"Unknown action: {action}"}, status_code=400)
 
         except Exception as e:
-            self.logger.error("Debug action '%s' failed: %s: %s", action, type(e).__name__, e)
+            self.logger.exception("Debug action '%s' failed", action)
             return JSONResponse({"error": "Debug action failed", "details": str(e)}, status_code=500)
 
     async def _stream_with_error_handling(self, generator):
@@ -422,7 +436,7 @@ async def _stream_with_error_handling(self, generator):
             async for value in generator:
                 yield self._convert_to_sse(value)
         except Exception as e:
-            self.logger.error("Error in async streaming: %s: %s", type(e).__name__, e)
+            self.logger.exception("Error in async streaming")
             error_event = {
                 "error": str(e),
                 "error_type": type(e).__name__,
@@ -477,7 +491,7 @@ def _sync_stream_with_error_handling(self, generator):
             for value in generator:
                 yield self._convert_to_sse(value)
         except Exception as e:
-            self.logger.error("Error in sync streaming: %s: %s", type(e).__name__, e)
+            self.logger.exception("Error in sync streaming")
             error_event = {
                 "error": str(e),
                 "error_type": type(e).__name__,

tests/bedrock_agentcore/runtime/test_app.py

@@ -1464,43 +1464,57 @@ class TestRequestContextFormatter:
 
     def test_request_context_formatter_with_both_ids(self):
         """Test formatter with both request and session IDs."""
+        import json
         import logging
 
         from bedrock_agentcore.runtime.app import RequestContextFormatter
         from bedrock_agentcore.runtime.context import BedrockAgentCoreContext
 
-        formatter = RequestContextFormatter("%(request_id)s%(message)s")
+        formatter = RequestContextFormatter()
 
         BedrockAgentCoreContext.set_request_context("req-123", "sess-456")
         record = logging.LogRecord("test", logging.INFO, "", 1, "Test message", (), None)
         formatted = formatter.format(record)
 
-        assert "[rid:req-123] [sid:sess-456] Test message" == formatted
+        log_data = json.loads(formatted)
+        assert log_data["message"] == "Test message"
+        assert log_data["level"] == "INFO"
+        assert log_data["logger"] == "test"
+        assert log_data["requestId"] == "req-123"
+        assert log_data["sessionId"] == "sess-456"
+        assert "timestamp" in log_data
 
     def test_request_context_formatter_with_only_request_id(self):
         """Test formatter with only request ID."""
+        import json
         import logging
 
         from bedrock_agentcore.runtime.app import RequestContextFormatter
         from bedrock_agentcore.runtime.context import BedrockAgentCoreContext
 
-        formatter = RequestContextFormatter("%(request_id)s%(message)s")
+        formatter = RequestContextFormatter()
 
         BedrockAgentCoreContext.set_request_context("req-789", None)
         record = logging.LogRecord("test", logging.INFO, "", 1, "Test message", (), None)
         formatted = formatter.format(record)
 
-        assert "[rid:req-789] Test message" == formatted
-        assert "[sid:" not in formatted
+        log_data = json.loads(formatted)
+        assert log_data["message"] == "Test message"
+        assert log_data["level"] == "INFO"
+        assert log_data["logger"] == "test"
+        assert log_data["requestId"] == "req-789"
+        assert "sessionId" not in log_data
+        assert "timestamp" in log_data
 
     def test_request_context_formatter_with_no_ids(self):
         """Test formatter with no IDs set."""
         import contextvars
+        import json
         import logging
 
         from bedrock_agentcore.runtime.app import RequestContextFormatter
 
-        formatter = RequestContextFormatter("%(request_id)s%(message)s")
+        formatter = RequestContextFormatter()
 
         # Run in fresh context to ensure no IDs are set
         ctx = contextvars.Context()
@@ -1510,4 +1524,10 @@ def format_in_new_context():
             return formatter.format(record)
 
         formatted = ctx.run(format_in_new_context)
-        assert formatted == "Test message"
+        log_data = json.loads(formatted)
+        assert log_data["message"] == "Test message"
+        assert log_data["level"] == "INFO"
+        assert log_data["logger"] == "test"
+        assert "requestId" not in log_data
+        assert "sessionId" not in log_data
+        assert "timestamp" in log_data

tests_integ/runtime/test_simple_agent.py

@@ -15,7 +15,7 @@ def setup(self):
                 from bedrock_agentcore import BedrockAgentCoreApp
                 from strands import Agent
 
-                app = BedrockAgentCoreApp()
+                app = BedrockAgentCoreApp(debug=True)
                 agent = Agent()
 
                 @app.entrypoint