Skip to content

Commit 2d46ae0

Browse files
committed
feat: Emit worker pool size as a DEBUG log event during init on Lambda Managed Instances
1 parent 3810eed commit 2d46ae0

8 files changed

Lines changed: 166 additions & 4 deletions

RELEASE.CHANGELOG.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,7 @@
1+
### September 2, 2026
2+
`4.0.3`
3+
- Emit a structured `runtime_worker_pool_initializing` DEBUG log event once per execution environment during INIT in multi-concurrent (Lambda Managed Instances) mode, reporting `workerCount` and `executionEnvironmentMaxConcurrency` for worker pool observability. Only visible when the function log level is DEBUG or lower; no impact on the standard on-demand path.
4+
15
### July 15, 2026
26
`4.0.2`
37
- Add `Lambda-Runtime-Invocation-Id` header support for cross-wiring protection. The RIC now echoes the invocation ID received from RAPID on `/next` back on `/response` and `/error`, enabling RAPID to detect and reject stale responses from timed-out invocations.

awslambdaric/__init__.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,4 +2,4 @@
22
Copyright 2021 Amazon.com, Inc. or its affiliates. All Rights Reserved.
33
"""
44

5-
__version__ = "4.0.2"
5+
__version__ = "4.0.3"

awslambdaric/bootstrap.py

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -493,6 +493,16 @@ def _log_preview_runtime_warning():
493493
logging.warning(get_lambda_preview_runtime_warning_message())
494494

495495

496+
def init_logging():
497+
"""Setup logging for the parent process before forking (LMI only)."""
498+
sys.stdout = Unbuffered(sys.stdout)
499+
sys.stderr = Unbuffered(sys.stderr)
500+
log_sink = create_log_sink()
501+
log_sink.__enter__()
502+
_setup_logging(_AWS_LAMBDA_LOG_FORMAT, _AWS_LAMBDA_LOG_LEVEL, log_sink)
503+
return log_sink
504+
505+
496506
def run(handler, lambda_runtime_client):
497507
sys.stdout = Unbuffered(sys.stdout)
498508
sys.stderr = Unbuffered(sys.stderr)

awslambdaric/lambda_multi_concurrent_utils.py

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
Copyright 2025 Amazon.com, Inc. or its affiliates. All Rights Reserved.
33
"""
44

5+
import logging
56
import os
67
import sys
78
import socket
@@ -10,6 +11,8 @@
1011
from . import bootstrap
1112
from .lambda_runtime_client import LambdaMultiConcurrentRuntimeClient
1213

14+
WORKER_POOL_INITIALIZING_EVENT = "runtime_worker_pool_initializing"
15+
1316

1417
class MultiConcurrentRunner:
1518
@staticmethod
@@ -32,6 +35,21 @@ def run_single(
3235
client = LambdaMultiConcurrentRuntimeClient(api_addr, use_thread)
3336
bootstrap.run(handler, client)
3437

38+
@classmethod
39+
def _emit_worker_pool_event(cls, socket_path: str, max_concurrency: int):
40+
"""Emit worker pool DEBUG event once from the parent before forking."""
41+
if socket_path:
42+
cls._redirect_output(socket_path)
43+
bootstrap.init_logging()
44+
logging.getLogger().debug(
45+
{
46+
"event": WORKER_POOL_INITIALIZING_EVENT,
47+
"workerCount": max_concurrency,
48+
"executionEnvironmentMaxConcurrency": max_concurrency,
49+
}
50+
)
51+
logging.getLogger().handlers.clear()
52+
3553
@classmethod
3654
def run_concurrent(
3755
cls,
@@ -41,6 +59,8 @@ def run_concurrent(
4159
socket_path: str,
4260
max_concurrency: int,
4361
):
62+
cls._emit_worker_pool_event(socket_path, max_concurrency)
63+
4464
processes = []
4565
for _ in range(max_concurrency):
4666
p = multiprocessing.Process(

awslambdaric/lambda_runtime_log_utils.py

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -117,7 +117,11 @@ def format(self, record: logging.LogRecord) -> str:
117117
result = {
118118
"timestamp": self.formatTime(record, self.datefmt),
119119
"level": record.levelname,
120-
"message": record.getMessage(),
120+
"message": (
121+
record.msg
122+
if isinstance(record.msg, dict) and not record.args
123+
else record.getMessage()
124+
),
121125
"logger": record.name,
122126
"stackTrace": self.__format_stacktrace(record.exc_info),
123127
"errorType": self.__format_exception_name(record.exc_info),

tests/test_bootstrap.py

Lines changed: 74 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1540,6 +1540,80 @@ def test_set_log_level_with_dictConfig(self, mock_stderr, mock_stdout):
15401540
self.assertEqual(mock_stdout.getvalue(), "")
15411541

15421542

1543+
class TestWorkerPoolInitializedLog(unittest.TestCase):
1544+
def setUp(self):
1545+
logging.getLogger().handlers.clear()
1546+
logging.getLogger().level = logging.NOTSET
1547+
1548+
def tearDown(self):
1549+
logging.getLogger().handlers.clear()
1550+
logging.getLogger().level = logging.NOTSET
1551+
1552+
def _setup_json_logging(self, log_level):
1553+
bootstrap._setup_logging(
1554+
LogFormat.from_str("JSON"), log_level, bootstrap.StandardLogSink()
1555+
)
1556+
1557+
@patch("sys.stdout", new_callable=StringIO)
1558+
def test_dict_message_serialized_as_nested_json_at_debug(self, mock_stdout):
1559+
self._setup_json_logging("DEBUG")
1560+
1561+
logging.getLogger().debug(
1562+
{
1563+
"event": "runtime_worker_pool_initializing",
1564+
"workerCount": 17,
1565+
"executionEnvironmentMaxConcurrency": 34,
1566+
}
1567+
)
1568+
1569+
data = json.loads(mock_stdout.getvalue().strip())
1570+
self.assertEqual(data["level"], "DEBUG")
1571+
self.assertEqual(
1572+
data["message"],
1573+
{
1574+
"event": "runtime_worker_pool_initializing",
1575+
"workerCount": 17,
1576+
"executionEnvironmentMaxConcurrency": 34,
1577+
},
1578+
)
1579+
1580+
@patch("sys.stdout", new_callable=StringIO)
1581+
def test_not_emitted_at_higher_log_levels(self, mock_stdout):
1582+
for log_level in ("INFO", "WARN", "ERROR", "FATAL"):
1583+
with self.subTest(log_level):
1584+
logging.getLogger().handlers.clear()
1585+
logging.getLogger().level = logging.NOTSET
1586+
self._setup_json_logging(_get_log_level_from_env_var(log_level))
1587+
1588+
logging.getLogger().debug({"event": "test"})
1589+
1590+
self.assertEqual(mock_stdout.getvalue(), "")
1591+
1592+
@patch("sys.stdout", new_callable=StringIO)
1593+
def test_init_logging_enables_parent_emission(self, mock_stdout):
1594+
with patch.dict(
1595+
os.environ,
1596+
{"AWS_LAMBDA_LOG_FORMAT": "JSON", "AWS_LAMBDA_LOG_LEVEL": "DEBUG"},
1597+
clear=True,
1598+
):
1599+
importlib.reload(bootstrap)
1600+
bootstrap.init_logging()
1601+
1602+
logging.getLogger().debug(
1603+
{
1604+
"event": "runtime_worker_pool_initializing",
1605+
"workerCount": 4,
1606+
"executionEnvironmentMaxConcurrency": 4,
1607+
}
1608+
)
1609+
1610+
importlib.reload(bootstrap)
1611+
1612+
data = json.loads(mock_stdout.getvalue())
1613+
self.assertEqual(data["level"], "DEBUG")
1614+
self.assertEqual(data["message"]["event"], "runtime_worker_pool_initializing")
1615+
1616+
15431617
class TestBootstrapModule(unittest.TestCase):
15441618
def test_run(self):
15451619
expected_handler = "app.my_test_handler"

tests/test_concurrency.py

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,8 @@ def fake_bootstrap_run(handler, lambda_runtime_client):
3838

3939
with patch(
4040
"awslambdaric.lambda_multi_concurrent_utils.MultiConcurrentRunner._redirect_output"
41+
), patch(
42+
"awslambdaric.lambda_multi_concurrent_utils.MultiConcurrentRunner._emit_worker_pool_event"
4143
), patch(
4244
"awslambdaric.lambda_multi_concurrent_utils.bootstrap.run",
4345
side_effect=fake_bootstrap_run,

tests/test_multi_concurrent_runner.py

Lines changed: 50 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@
44

55
import sys
66
import unittest
7-
from unittest.mock import patch, MagicMock
7+
from unittest.mock import patch, MagicMock, call
88

99
from awslambdaric.lambda_multi_concurrent_utils import MultiConcurrentRunner
1010

@@ -58,8 +58,9 @@ def test_run_single_creates_client_and_calls_bootstrap(
5858
mock_client_cls.assert_called_once_with("addr", True)
5959
mock_bootstrap.run.assert_called_once_with("h.fn", mock_client)
6060

61+
@patch.object(MultiConcurrentRunner, "_emit_worker_pool_event")
6162
@patch("multiprocessing.Process")
62-
def test_run_concurrent_spawns_and_joins(self, mock_process):
63+
def test_run_concurrent_spawns_and_joins(self, mock_process, mock_emit):
6364
fake_proc = MagicMock()
6465
mock_process.return_value = fake_proc
6566

@@ -77,6 +78,53 @@ def test_run_concurrent_spawns_and_joins(self, mock_process):
7778
self.assertEqual(target, MultiConcurrentRunner.run_single)
7879
self.assertEqual(args, ("h", "a", False, "/sock"))
7980

81+
@patch("multiprocessing.Process")
82+
def test_run_concurrent_emits_worker_pool_event_once_before_spawning(
83+
self, mock_process
84+
):
85+
mock_process.return_value = MagicMock()
86+
order_tracker = MagicMock()
87+
order_tracker.attach_mock(mock_process, "process")
88+
89+
with patch.object(
90+
MultiConcurrentRunner, "_emit_worker_pool_event"
91+
) as mock_emit:
92+
order_tracker.attach_mock(mock_emit, "emit")
93+
MultiConcurrentRunner.run_concurrent(
94+
"h", "a", False, "/sock", max_concurrency=3
95+
)
96+
97+
mock_emit.assert_called_once_with("/sock", 3)
98+
self.assertEqual(order_tracker.mock_calls[0], call.emit("/sock", 3))
99+
100+
@patch("awslambdaric.lambda_multi_concurrent_utils.logging")
101+
@patch("awslambdaric.lambda_multi_concurrent_utils.bootstrap")
102+
def test_emit_worker_pool_event_sets_up_parent_logging_and_emits(
103+
self, mock_bootstrap, mock_logging
104+
):
105+
with patch.object(MultiConcurrentRunner, "_redirect_output") as mock_redirect:
106+
MultiConcurrentRunner._emit_worker_pool_event("/sock", 16)
107+
108+
mock_redirect.assert_called_once_with("/sock")
109+
mock_bootstrap.init_logging.assert_called_once_with()
110+
mock_logging.getLogger.return_value.debug.assert_called_once()
111+
event = mock_logging.getLogger.return_value.debug.call_args[0][0]
112+
self.assertEqual(event["workerCount"], 16)
113+
self.assertEqual(event["executionEnvironmentMaxConcurrency"], 16)
114+
mock_logging.getLogger.return_value.handlers.clear.assert_called_once_with()
115+
116+
@patch("awslambdaric.lambda_multi_concurrent_utils.logging")
117+
@patch("awslambdaric.lambda_multi_concurrent_utils.bootstrap")
118+
def test_emit_worker_pool_event_skips_redirect_when_no_socket(
119+
self, mock_bootstrap, mock_logging
120+
):
121+
with patch.object(MultiConcurrentRunner, "_redirect_output") as mock_redirect:
122+
MultiConcurrentRunner._emit_worker_pool_event(None, 4)
123+
124+
mock_redirect.assert_not_called()
125+
mock_bootstrap.init_logging.assert_called_once_with()
126+
mock_logging.getLogger.return_value.debug.assert_called_once()
127+
80128
@patch(
81129
"awslambdaric.lambda_multi_concurrent_utils.LambdaMultiConcurrentRuntimeClient"
82130
)

0 commit comments

Comments
 (0)