Timeouts, Remaining Time and Structured Logs

Scenario

Example app: a nightly function receives a list of 5,000 customer IDs and recalculates each customer's statistics. The function timeout is 15 minutes; usually it finishes in 10.

What you see in production

On busy nights some customers' statistics are never updated. The logs end abruptly with Task timed out after 900.00 seconds, and there is no record of which customers were processed. Logs are plain print() lines.

The naive code

def handler(event, context):
    for customer_id in event["customer_ids"]:
        recalculate(customer_id)            # killed mid-loop at the timeout
        print("done " + customer_id)
    return {"processed": len(event["customer_ids"])}

Reproduce it

A simulated clock stands in for context.get_remaining_time_in_millis():

TIMEOUT_MS, SAFETY_MS = 900_000, 30_000
costs = [200] * 3000 + [400] * 2000          # ms per customer; busy night

def naive(costs):
    elapsed = 0
    for i, c in enumerate(costs):
        if elapsed + c > TIMEOUT_MS:
            return {"processed": i, "status": "TIMED OUT", "remaining_recorded": False}
        elapsed += c
    return {"processed": len(costs), "status": "ok"}

def checkpointed(costs):
    elapsed = 0
    for i, c in enumerate(costs):
        if TIMEOUT_MS - elapsed < SAFETY_MS:          # like context.get_remaining_time_in_millis()
            return {"processed": i, "status": "stopped early", "requeued": len(costs) - i}
        elapsed += c
    return {"processed": len(costs), "status": "ok"}

print("naive:       ", naive(costs))
print("checkpointed:", checkpointed(costs))

naive:        {'processed': 3750, 'status': 'TIMED OUT', 'remaining_recorded': False}
checkpointed: {'processed': 3676, 'status': 'stopped early', 'requeued': 1324}

Root cause

When a function reaches its timeout, Lambda stops it immediately: no finally blocks, no final log line, no return value. Work in progress is lost, and with unstructured logs nobody knows how far it got. Long loops whose total time grows with data volume will eventually hit the limit.

The fix

• Check context.get_remaining_time_in_millis() and stop with a safety margin, returning or re-queuing the remaining work (send it to SQS, or return it to a Step Functions loop).
• Better, split the work: one message per customer (SQS) or a Step Functions Distributed Map over the list, so each unit is small, parallel and retried independently.
• Use Powertools Logger for structured JSON logs with the request ID and progress fields, so you can query exactly what was processed.

from aws_lambda_powertools import Logger
logger = Logger(service="stats")

@logger.inject_lambda_context
def handler(event, context):
    ids = event["customer_ids"]
    for i, customer_id in enumerate(ids):
        if context.get_remaining_time_in_millis() < 30_000:
            requeue(ids[i:])
            logger.warning("stopping early", extra={"processed": i, "requeued": len(ids) - i})
            return {"processed": i, "requeued": len(ids) - i}
        recalculate(customer_id)
    logger.info("finished", extra={"processed": len(ids)})
    return {"processed": len(ids)}

Trade-offs

• A safety margin wastes a little runtime but guarantees a clean stop; pick it from the slowest unit of work.
• Fanning out per item costs more invocations but scales and retries far better.
• Recalculations must be idempotent, because stopped or retried work may run again.

Detect it in production

• Task timed out log lines and the function's Duration approaching the timeout.
• Structured progress logs (processed counts) and reconciliation of expected versus processed items.
• Alarms on timeouts as errors.

Key points

• Timeouts kill the function instantly; nothing after that point runs.
• Check remaining time and stop or re-queue with a safety margin.
• Prefer splitting work into small units (SQS, Distributed Map); log structured progress.

Further reading: Using the Lambda context object to retrieve Python function information · Powertools for AWS Lambda (Python): Logger