Skip to content

Commit 59e6a2f

Browse files
joe4devclaude
andcommitted
fix(init): fix REPORT log format and add init timeout retry support
- Move Init Duration after Max Memory Used in REPORT line (matches AWS) - Add Status: timeout to REPORT line on invoke timeout - Fix timeout error message format to "RequestId: <id> Error: Task timed out after N.00 seconds" - Add ErrorType: "Sandbox.Timedout" to timeout error response - Track init start time and emit Init Duration on first non-retry invocation - Add is-init-retry field to InvokeRequest to suppress Init Duration on retry invokes Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
1 parent a08c667 commit 59e6a2f

2 files changed

Lines changed: 20 additions & 6 deletions

File tree

cmd/localstack/awsutil.go

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -92,7 +92,7 @@ func getBootstrap(args []string) (interop.Bootstrap, string) {
9292
return NewSimpleBootstrap(bootstrapLookupCmd, currentWorkingDir), handler
9393
}
9494

95-
func PrintEndReports(invokeId string, initDuration string, memorySize string, invokeStart time.Time, timeoutDuration time.Duration, w io.Writer) {
95+
func PrintEndReports(invokeId string, initDuration string, status string, memorySize string, invokeStart time.Time, timeoutDuration time.Duration, w io.Writer) {
9696
// Calculate invoke duration
9797
invokeDuration := math.Min(float64(time.Now().Sub(invokeStart).Nanoseconds()),
9898
float64(timeoutDuration.Nanoseconds())) / float64(time.Millisecond)
@@ -102,11 +102,12 @@ func PrintEndReports(invokeId string, initDuration string, memorySize string, in
102102
// not a clean way to get this information from rapidcore
103103
_, _ = fmt.Fprintf(w,
104104
"REPORT RequestId: %s\t"+
105-
initDuration+
106105
"Duration: %.2f ms\t"+
107106
"Billed Duration: %.f ms\t"+
108107
"Memory Size: %s MB\t"+
109-
"Max Memory Used: %s MB\t\n",
108+
"Max Memory Used: %s MB\t"+
109+
initDuration+
110+
status+"\n",
110111
invokeId, invokeDuration, math.Ceil(invokeDuration), memorySize, memorySize)
111112
}
112113

cmd/localstack/custom_interop.go

Lines changed: 16 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,8 @@ type CustomInteropServer struct {
2727
localStackAdapter *LocalStackAdapter
2828
port string
2929
upstreamEndpoint string
30+
initStart time.Time
31+
warmStart bool
3032
}
3133

3234
type LocalStackAdapter struct {
@@ -87,6 +89,7 @@ type InvokeRequest struct {
8789
InvokedFunctionArn string `json:"invoked-function-arn"`
8890
Payload string `json:"payload"`
8991
TraceId string `json:"trace-id"`
92+
IsInitRetry bool `json:"is-init-retry,omitempty"`
9093
}
9194

9295
// The ErrorResponse is sent TO LocalStack when encountering an error
@@ -127,6 +130,13 @@ func NewCustomInteropServer(lsOpts *LsOpts, adapter *LocalStackAdapter, delegate
127130
functionVersion := GetEnvOrDie("AWS_LAMBDA_FUNCTION_VERSION") // default $LATEST
128131
_, _ = fmt.Fprintf(logCollector, "START RequestId: %s Version: %s\n", invokeR.InvokeId, functionVersion)
129132

133+
initDuration := ""
134+
if !server.warmStart && !invokeR.IsInitRetry {
135+
initTimeMS := float64(time.Since(server.initStart).Nanoseconds()) / float64(time.Millisecond)
136+
initDuration = fmt.Sprintf("Init Duration: %.2f ms\t", initTimeMS)
137+
}
138+
server.warmStart = true
139+
130140
invokeStart := time.Now()
131141
err = server.Invoke(invokeResp, &interop.Invoke{
132142
ID: invokeR.InvokeId,
@@ -148,15 +158,17 @@ func NewCustomInteropServer(lsOpts *LsOpts, adapter *LocalStackAdapter, delegate
148158
})
149159
timeout := int(server.delegate.GetInvokeTimeout().Seconds())
150160
isErr := false
161+
status := ""
151162
if err != nil {
152163
switch {
153164
case errors.Is(err, rapidcore.ErrInvokeTimeout):
154165
log.Debugf("Got invoke timeout")
155166
isErr = true
167+
status = "Status: timeout"
156168
errorResponse := ErrorResponse{
169+
ErrorType: "Sandbox.Timedout",
157170
ErrorMessage: fmt.Sprintf(
158-
"%s %s Task timed out after %d.00 seconds",
159-
time.Now().Format("2006-01-02T15:04:05Z"),
171+
"RequestId: %s Error: Task timed out after %d.00 seconds",
160172
invokeR.InvokeId,
161173
timeout,
162174
),
@@ -185,7 +197,7 @@ func NewCustomInteropServer(lsOpts *LsOpts, adapter *LocalStackAdapter, delegate
185197
}
186198
timeoutDuration := time.Duration(timeout) * time.Second
187199
memorySize := GetEnvOrDie("AWS_LAMBDA_FUNCTION_MEMORY_SIZE")
188-
PrintEndReports(invokeR.InvokeId, "", memorySize, invokeStart, timeoutDuration, logCollector)
200+
PrintEndReports(invokeR.InvokeId, initDuration, status, memorySize, invokeStart, timeoutDuration, logCollector)
189201

190202
if err2 := server.localStackAdapter.SendLogs(invokeR.InvokeId, logCollector.getLogs()); err2 != nil {
191203
log.Error("failed to send logs to LocalStack: ", err2)
@@ -272,6 +284,7 @@ func (c *CustomInteropServer) SendRuntimeReady() error {
272284

273285
func (c *CustomInteropServer) Init(i *interop.Init, invokeTimeoutMs int64) error {
274286
log.Traceln("Init called")
287+
c.initStart = time.Now()
275288
return c.delegate.Init(i, invokeTimeoutMs)
276289
}
277290

0 commit comments

Comments
 (0)