lambda responses and logs

import%20marimo%0A%0A__generated_with%20%3D%20%220.17.7%22%0Aapp%20%3D%20marimo.App(width%3D%22medium%22)%0A%0A%0A%40app.cell(hide_code%3DTrue)%0Adef%20_()%3A%0A%20%20%20%20import%20marimo%20as%20mo%0A%20%20%20%20return%20(mo%2C)%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%20Lambda%20Response%20and%20Logs%0A%0A%20%20%20%20When%20you%20invoke%20a%20lambda%20function%2C%0A%20%20%20%20what%20do%20the%20responses%20and%20logs%20look%20like%0A%20%20%20%20-%20for%20cold%20versus%20warm%20start%3F%0A%20%20%20%20-%20if%20the%20init%20raises%20an%20exception%3F%0A%20%20%20%20-%20if%20the%20handler%20raises%20an%20exception%3F%0A%20%20%20%20-%20if%20the%20init%20times%20out%3F%0A%20%20%20%20-%20if%20the%20handler%20times%20out%3F%0A%20%20%20%20-%20if%20the%20handler%20returns%20an%20unserializable%20object%3F%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%20Stack%0A%0A%20%20%20%20Just%20a%20bunch%20of%20lambdas%3A%0A%20%20%20%20-%20%60slow_init%60%0A%20%20%20%20-%20%60init_exception%60%0A%20%20%20%20-%20%60handler_exception%60%0A%20%20%20%20-%20%60init_times_out%60%0A%20%20%20%20-%20%60handler_times_out%60%0A%20%20%20%20-%20%60handler_returns_unserializable%60%0A%0A%20%20%20%20each%20doing%20what%20its%20name%20suggests%2C%20via%20%60sleep()%60%20or%20%60raise%20Exception%60%20or%20%60return%20set()%60.%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%20Setup%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_()%3A%0A%20%20%20%20import%20boto3%0A%20%20%20%20import%20datetime%0A%20%20%20%20return%20boto3%2C%20datetime%0A%0A%0A%40app.cell%0Adef%20_(boto3)%3A%0A%20%20%20%20lambda_%20%3D%20boto3.client(%22lambda%22)%0A%20%20%20%20logs%20%3D%20boto3.client(%22logs%22)%0A%20%20%20%20return%20lambda_%2C%20logs%0A%0A%0A%40app.cell%0Adef%20_(datetime%2C%20lambda_)%3A%0A%20%20%20%20call_times%20%3D%20%7B%7D%0A%20%20%20%20responses%20%3D%20%7B%7D%0A%0A%20%20%20%20for%20function_name%20in%20(%0A%20%20%20%20%20%20%20%20%22slow_init%22%2C%0A%20%20%20%20%20%20%20%20%22slow_init%22%2C%20%20%23%20twice%2C%20to%20contrast%20cold%20versus%20warm%20start%0A%20%20%20%20%20%20%20%20%22init_exception%22%2C%0A%20%20%20%20%20%20%20%20%22handler_exception%22%2C%0A%20%20%20%20%20%20%20%20%22init_times_out%22%2C%0A%20%20%20%20%20%20%20%20%22handler_times_out%22%2C%0A%20%20%20%20%20%20%20%20%22handler_returns_unserializable%22%2C%0A%20%20%20%20)%3A%0A%20%20%20%20%20%20%20%20%23%20the%20dict%20values%20are%20all%20lists%20so%20i%20can%20treat%20once-called%20and%20twice-called%20functions%20uniformly%0A%20%20%20%20%20%20%20%20call_times.setdefault(function_name%2C%20%5B%5D).append(datetime.datetime.now(datetime.UTC))%0A%20%20%20%20%20%20%20%20response%20%3D%20lambda_.invoke(FunctionName%3Dfunction_name)%0A%20%20%20%20%20%20%20%20del%20response%5B%22ResponseMetadata%22%5D%20%20%23%20just%20noise%20for%20our%20purposes%0A%20%20%20%20%20%20%20%20del%20response%5B%22ExecutedVersion%22%5D%20%20%23%20%22%24LATEST%22%0A%20%20%20%20%20%20%20%20%23%20the%20%22Payload%22%20value%20is%20a%20botocore.response.StreamingBody%20object%0A%20%20%20%20%20%20%20%20%23%20it's%20file-like%2C%20so%20has%20a%20%60read()%60%20method%2C%20returning%20bytes%0A%20%20%20%20%20%20%20%20response%5B%22Payload%22%5D%20%3D%20response%5B%22Payload%22%5D.read().decode(%22utf-8%22)%0A%20%20%20%20%20%20%20%20responses.setdefault(function_name%2C%20%5B%5D).append(response)%0A%20%20%20%20return%20call_times%2C%20responses%0A%0A%0A%40app.cell%0Adef%20_(call_times%2C%20datetime%2C%20logs)%3A%0A%20%20%20%20def%20print_logs(function_name)%3A%0A%20%20%20%20%20%20%20%20earliest_call_time%20%3D%20min(call_times%5Bfunction_name%5D)%0A%0A%20%20%20%20%20%20%20%20earliest_call_timestamp_in_ms%20%3D%20int(earliest_call_time.timestamp())%20*%201000%0A%20%20%20%20%20%20%20%20response%20%3D%20logs.filter_log_events(%0A%20%20%20%20%20%20%20%20%20%20%20%20logGroupName%3Df%22%2Faws%2Flambda%2F%7Bfunction_name%7D%22%2C%0A%20%20%20%20%20%20%20%20%20%20%20%20startTime%3Dearliest_call_timestamp_in_ms%2C%0A%20%20%20%20%20%20%20%20)%0A%0A%20%20%20%20%20%20%20%20nice_logs%20%3D%20%22%22%0A%20%20%20%20%20%20%20%20for%20event%20in%20response%5B%22events%22%5D%3A%0A%20%20%20%20%20%20%20%20%20%20%20%20t%20%3D%20datetime.datetime.fromtimestamp(event%5B%22timestamp%22%5D%20%2F%201000%2C%20datetime.UTC)%0A%20%20%20%20%20%20%20%20%20%20%20%20message%20%3D%20event%5B%22message%22%5D%0A%20%20%20%20%20%20%20%20%20%20%20%20nice_logs%20%2B%3D%20f%22%7Bt%7D%3A%20%7Bmessage%7D%22%0A%0A%20%20%20%20%20%20%20%20print(nice_logs)%0A%20%20%20%20return%20(print_logs%2C)%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%20Results%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%23%20%60slow_init%60%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(responses)%3A%0A%20%20%20%20responses%5B%22slow_init%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(call_times)%3A%0A%20%20%20%20call_times%5B%22slow_init%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(print_logs)%3A%0A%20%20%20%20print_logs(%22slow_init%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20The%20%60StatusCode%60%20key%20is%20from%20the%20Lambda%20service%2C%20not%20the%20function.%0A%0A%20%20%20%20In%20happy%20cases%2C%20like%20this%20one%2C%20the%20%60%22Payload%22%60%20is%20the%20%60json.dumps()%60%20of%20the%20function's%20return%20value.%0A%0A%20%20%20%20The%20first%2C%20cold%20invocation%20has%20an%20%60INIT_START%60%20message%20and%20an%20%60Init%20Duration%60%20in%20the%20%60REPORT%60%20message.%0A%20%20%20%20The%20second%2C%20warm%20invocation%20has%20neither.%0A%0A%20%20%20%20The%20first%20invocation's%20%60Billed%20Duration%60%20is%20the%20_sum_%20of%20its%20%60Init%20Duration%60%20and%20(handler)%20%60Duration%60%2C%20rounded%20up%20to%20the%20nearest%20millsecond.%0A%20%20%20%20So%20you're%20billed%20for%20the%20init%20time.%0A%20%20%20%20That's%20a%20recent%20change.%0A%20%20%20%20Before%20August%201%202025%2C%20the%20init%20time%20for%0A%0A%20%20%20%20%3E%20on-demand%20invocations%20of%20Lambda%20functions%20packaged%20as%20ZIP%20files%20that%20use%20managed%20runtimes%0A%0A%20%20%20%20were%20not%20billed.%0A%0A%20%20%20%20The%20function's%20timeout%20is%203s%20(the%20default).%0A%20%20%20%20The%20init%20was%204s.%0A%20%20%20%20But%20no%20timeout.%0A%20%20%20%20So%20the%20init%20does%20not%20count%20towards%20the%20function's%20timeout.%0A%0A%20%20%20%20Payloads%20are%20meant%20to%20be%20json%2C%0A%20%20%20%20but%20%60%22hi%20there%22%60%20isn't%20json%2C%20is%20it%3F%0A%20%20%20%20Sure%20it%20is%20%5B2%5D%3A%0A%0A%20%20%20%20%3E%20A%20JSON%20text%20is%20a%20serialized%20value.%20Note%20that%20certain%20previous%20specifications%20of%20JSON%20constrained%20a%20JSON%20text%20to%20be%20an%20object%20or%20an%20array.%0A%0A%20%20%20%20%5B3%5D%20explains%20the%20confusion%20nicely.%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%23%20%60init_exception%60%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(responses)%3A%0A%20%20%20%20responses%5B%22init_exception%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(call_times)%3A%0A%20%20%20%20call_times%5B%22init_exception%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(print_logs)%3A%0A%20%20%20%20print_logs(%22init_exception%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%60%22StatusCode%22%3A%20200%60%20in%20the%20response%2C%0A%20%20%20%20despite%20the%20exception%2C%0A%20%20%20%20because%20it's%20about%20your%20request%20to%20the%20Lambda%20service%2C%0A%20%20%20%20not%20about%20your%20function%20%5B4%5D.%0A%0A%20%20%20%20%3E%20The%20status%20code%20in%20the%20API%20response%20doesn%E2%80%99t%20reflect%20function%20errors.%20Error%20codes%20are%20reserved%20for%20errors%20that%20prevent%20your%20function%20from%20executing%2C%20such%20as%20permissions%20errors%2C%20quota%20errors%2C%20or%20issues%20with%20your%20function%E2%80%99s%20code%20and%20configuration.%0A%0A%20%20%20%20What%20does%20flag%20that%20something%20went%20wrong%0A%20%20%20%20is%20the%20presence%20of%20%60%22FunctionError%22%60.%0A%20%20%20%20The%20value%20is%20%60%22Unhandled%22%60%2C%0A%20%20%20%20which%20makes%20sense%2C%0A%20%20%20%20but%20I%20wonder%20if%20any%20other%20values%20are%20possible.%0A%0A%20%20%20%20The%20payload%20is%20rich%0A%20%20%20%20%E2%80%94%20even%20a%20stacktrace%20(%22traceback%22%20in%20the%20logs).%0A%0A%20%20%20%20The%20response%20doesn't%20explicitly%20flag%20that%20the%20error%20was%20in%20the%20init.%0A%20%20%20%20In%20this%20case%2C%20it's%20plain%20from%20the%20stacktrace.%0A%20%20%20%20In%20actual%20cases%2C%20it%20might%20not%20be.%0A%0A%20%20%20%20Notice%20the%20empty%20request%20id%20in%20the%20payload%0A%20%20%20%20but%20populated%20request%20id%20in%20the%20last%20few%20logs.%0A%0A%20%20%20%20The%20logs%20have%20an%20%60INIT_REPORT%60%20message%20this%20time%2C%0A%20%20%20%20including%20%60Phase%3A%20init%60%20and%20%60Status%3A%20error%60.%0A%20%20%20%20That's%20helpful%0A%20%20%20%20%E2%80%94%20no%20mistaking%20that%20the%20init%20errored.%0A%20%20%20%20I%20guess%20we%20get%20an%20%60INIT_REPORT%60%20only%20when%20the%20init%20goes%20wrong%3F%0A%0A%20%20%20%20We%20also%20get%20a%20%60LAMBDA_WARNING%60%20message%20from%20the%20Lambda%20service%2C%0A%20%20%20%20and%20the%20same%20traceback%20as%20was%20in%20the%20response.%0A%0A%20%20%20%20In%20fact%20we%20get%20these%20messages%0A%20%20%20%20%E2%80%94%20the%20%60LAMBDA_WARNING%60%2C%20traceback%2C%20and%20%60INIT_REPORT%60%0A%20%20%20%20%E2%80%94%20twice!%0A%20%20%20%20But%20the%20second%20%60INIT_REPORT%60%20is%20slightly%20different%3A%0A%20%20%20%20a%20different%20duration%0A%20%20%20%20and%20%60Phase%3A%20invoke%60.%0A%0A%20%20%20%20And%20we%20also%20get%20a%20%60REPORT%60%2C%0A%20%20%20%20with%20yet%20a%20different%20duration.%0A%0A%20%20%20%20Puzzling.%0A%20%20%20%20Why%20does%20an%20%60INIT_REPORT%60%20refer%20to%20%60Phase%3A%20invoke%60%3F%0A%20%20%20%20Why%20repeat%20the%20warning%20and%20traceback%3F%0A%20%20%20%20Why%20three%20different%20durations%3F%0A%20%20%20%20Why%20request%20id%20in%20logs%20but%20not%20payload%3F%0A%20%20%20%20Does%20Lambda%20try%20to%20invoke%20your%20function%20even%20when%20the%20init%20failed%3F%0A%20%20%20%20Or%20is%20it%20just%20pretending%20that%20it%20tried%3F%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%23%20%60handler_exception%60%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(responses)%3A%0A%20%20%20%20responses%5B%22handler_exception%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(call_times)%3A%0A%20%20%20%20call_times%5B%22handler_exception%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(print_logs)%3A%0A%20%20%20%20print_logs(%22handler_exception%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20No%20surprises%20here.%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%23%20%60init_times_out%60%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(responses)%3A%0A%20%20%20%20responses%5B%22init_times_out%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(call_times)%3A%0A%20%20%20%20call_times%5B%22init_times_out%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(print_logs)%3A%0A%20%20%20%20print_logs(%22init_times_out%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20The%20init%20timed%20out%20after%2010s.%0A%20%20%20%20But%20the%20payload%20says%20%22Task%20timed%20out%20after%203.00%20seconds%22.%0A%0A%20%20%20%20We%20have%20two%20%60INIT_REPORT%60s%2C%0A%20%20%20%20as%20we%20did%20for%20%60init_exception%60.%0A%20%20%20%20One%20is%20for%20the%20init%20phase%20and%20records%20a%20duration%20of%2010s.%0A%20%20%20%20The%20other%20is%20for%20the%20invoke%20phase%20and%20records%20a%20duration%20of%20about%203s.%0A%0A%20%20%20%20We%20have%20a%20%60REPORT%60%20too%2C%0A%20%20%20%20this%20with%20a%20duration%20of%20exactly%203s.%0A%0A%20%20%20%20Puzzling%20again%2C%0A%20%20%20%20like%20for%20%60init_exception%60.%0A%0A%20%20%20%20The%20response%20and%20the%20logs%20are%20half-subsuming%20the%20init%20into%20the%20invoke.%0A%0A%20%20%20%20My%20takeaway%3A%20the%20logs%20are%20geared%20for%20the%20normal%20case%2C%20not%20init%20failures.%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%23%20%60handler_times_out%60%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(responses)%3A%0A%20%20%20%20responses%5B%22handler_times_out%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(call_times)%3A%0A%20%20%20%20call_times%5B%22handler_times_out%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(print_logs)%3A%0A%20%20%20%20print_logs(%22handler_times_out%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20No%20surprises%20here.%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%23%20%60handler_returns_unserializable%60%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(responses)%3A%0A%20%20%20%20responses%5B%22handler_returns_unserializable%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(call_times)%3A%0A%20%20%20%20call_times%5B%22handler_returns_unserializable%22%5D%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(print_logs)%3A%0A%20%20%20%20print_logs(%22handler_returns_unserializable%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20The%20error%20type%20in%20the%20response%20is%20%60Runtime.MarshalError%60%2C%0A%20%20%20%20not%20%60TypeError%60%2C%20which%20is%20what%20%60json.dumps(set())%60%20raises.%0A%20%20%20%20That%20makes%20sense%3A%0A%20%20%20%20a%20Lambda%20procedure%20failed%2C%0A%20%20%20%20so%20we%20get%20Lambda-specific%20errors%2C%0A%20%20%20%20even%20if%20that%20procedure%20is%20mimicking%20Python's%20%60json.dumps()%60.%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0A%40app.cell%0Adef%20_(mo)%3A%0A%20%20%20%20mo.md(r%22%22%22%0A%20%20%20%20%23%23%20References%0A%0A%20%20%20%20%5B1%5D%20https%3A%2F%2Faws.amazon.com%2Fblogs%2Fcompute%2Faws-lambda-standardizes-billing-for-init-phase%2F%0A%0A%20%20%20%20%5B2%5D%20https%3A%2F%2Fwww.ietf.org%2Frfc%2Frfc7159.txt%0A%0A%20%20%20%20%5B3%5D%20https%3A%2F%2Fstackoverflow.com%2Fa%2F7487892%0A%0A%20%20%20%20%5B4%5D%20https%3A%2F%2Fboto3.amazonaws.com%2Fv1%2Fdocumentation%2Fapi%2Flatest%2Freference%2Fservices%2Flambda%2Fclient%2Finvoke.html%0A%20%20%20%20%22%22%22)%0A%20%20%20%20return%0A%0A%0Aif%20__name__%20%3D%3D%20%22__main__%22%3A%0A%20%20%20%20app.run()%0A