bug: Lambda invocation times out repeatedly

[markmashworth]

Is there an existing issue for this?

• [X] I have searched the existing issues

Current Behavior

When running localstack I am able to successfully create a layer and lambda function. However, when I try to invoke the function it times out. After the invocation, I see this same error get logged repeatedly by the container.

local-localstack-1  | 2023-08-09T19:34:00.199  WARN --- [   Thread-20] l.s.l.i.runtime_environmen : Executor 6fe9edeacaa6f62a052023e6d2d17e32 for function arn:aws:lambda:us-east-1:000000000000:function:my-lambda:$LATEST timed out during startup

Expected Behavior

The lambda function should be invoked.

How are you starting LocalStack?

With a docker-compose file

Steps To Reproduce

Here is my docker-compose.yml:

version: '3.8'
services:
  localstack:
    image: localstack/localstack-pro:latest
    environment:
      - LOCALSTACK_API_KEY=${LOCALSTACK_API_KEY- }
      - SERVICES=lambda,logs
      - DEBUG=0
    ports:
      - "53:53"
      - "53:53/udp"
      - "443:443"
      - '4566:4566'
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock"

Steps to reproduce:

docker-compose up

# Create a layer that contains the numpy dependency
aws lambda publish-layer-version --region us-east-1 --endpoint-url http://localhost:4566 \
  --layer-name my-layer \
  --zip-file fileb://../../lambda/layers/numpy-layer.zip

# Create the lambda function
aws lambda create-function --region us-east-1 --endpoint-url http://localhost:4566 \
  --function-name my-lambda \
  --role arn:aws:iam::000000000000:role/lambda-role \
  --runtime python3.10 \
  --zip-file fileb://./../../lambda/poc/lambda.zip \
  --layers arn:aws:lambda:us-east-1:000000000000:layer:my-layer:1   <–– Generated from previous command

  # Invoke the lambda (which causes the error I'm seeing)
  aws lambda invoke --region us-east-1 --endpoint-url http://localhost:4566 \
    --function-name my-lambda \
    response.json

I see the error mentioned above begin to log after running the invoke command.

My lamba.zip contains a single file handler.py that looks like this:

import numpy

def handler(event, context):
    print(str(np.cos(0)))
    return "Test";

Environment

- OS: macOS 13.5
- LocalStack: 2.2.1.dev20230809125028

Anything else?

No response

[localstack-bot]

Welcome to LocalStack! Thanks for reporting your first issue and our team will be working towards fixing the issue for you or reach out for more background information. We recommend joining our Slack Community for real-time help and drop a message to LocalStack Pro Support if you are a Pro user! If you are willing to contribute towards fixing this issue, please have a look at our contributing guidelines and our contributing guide.

[joe4dev]

Thank you for reaching out @markmashworth

Could you try to increase the Lambda environment startup timeout? For example: LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT=30 (default is 10 seconds)

To mitigate startup delays, we recommend adding the following volume mount for caching (see Installation):

    volumes:
      - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack"
      - "/var/run/docker.sock:/var/run/docker.sock"

You can also try to pull the latest image docker pull localstack/localstack-pro because we recently started shipping the lambda runtime init, an asset that was previously downloaded lazily. The used Lambda images can also be updated through our CLI using localstack update all.

FYI: We are going to ship another improvement in the coming weeks that will prevent the infinite re-try loop in this case.

[Sotatek-HaiTrieu2]

I have the same problem when invoke lambda function, here is what I got from lambda execution container:

time="2023-08-26T15:27:01Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21"
time="2023-08-26T15:27:01Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:143"
time="2023-08-26T15:27:01Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:146" euid=0 gid=0 uid=0 username=root
time="2023-08-26T15:27:01Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:148" euid=993 gid=990 uid=993 username=sbx_user1051
2023-08-26T15:27:01Z [Info] Initializing AWS X-Ray daemon unknown
2023-08-26T15:27:01Z [Debug] Listening on UDP 127.0.0.1:2000
2023-08-26T15:27:01Z [Info] Using buffer memory limit of 78 MB
2023-08-26T15:27:01Z [Info] 1248 segment buffers allocated
2023-08-26T15:27:01Z [Debug] Using Endpoint read from Config file: http://172.17.0.1:4566
2023-08-26T15:27:01Z [Debug] Using proxy address:
2023-08-26T15:27:01Z [Debug] Fetch region us-east-1 from commandline/config file
2023-08-26T15:27:01Z [Info] Using region: us-east-1
2023-08-26T15:27:01Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.1:4566
2023-08-26T15:27:01Z [Debug] Using Endpoint: http://172.17.0.1:4566
2023-08-26T15:27:01Z [Debug] Batch size: 10
2023-08-26T15:27:01Z [Info] Starting proxy http server on 127.0.0.1:2000
time="2023-08-26T15:27:01Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:160"
time="2023-08-26T15:27:01Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:94"
time="2023-08-26T15:27:01Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptStartRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:391"
time="2023-08-26T15:27:01Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:363"
time="2023-08-26T15:27:01Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:71" error="open /opt/extensions: no such file or directory"
time="2023-08-26T15:27:01Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:189"
time="2023-08-26T15:27:01Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:222"
time="2023-08-26T15:27:01Z" level=debug msg="Received RUNNING" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:533"
Traceback (most recent call last):
  File "/var/runtime/bootstrap.py", line 60, in <module>
    main()
  File "/var/runtime/bootstrap.py", line 57, in main
    awslambdaricmain.main([os.environ["LAMBDA_TASK_ROOT"], os.environ["_HANDLER"]])
  File "/var/lang/lib/python3.9/os.py", line 679, in __getitem__
    raise KeyError(key) from None
KeyError: '_HANDLER'
time="2023-08-26T15:27:01Z" level=warning msg="First fatal error stored in appctx: Runtime.ExitError" func=go.amzn.com/lambda/appctx.StoreFirstFatalError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/appctx/appctxutil.go:156"
time="2023-08-26T15:27:01Z" level=warning msg="Process 17(bootstrap) exited: Runtime exited with error: exit status 1" func="go.amzn.com/lambda/core.(*Watchdog).GoWait.func1" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/core/watchdog.go:67"
time="2023-08-26T15:27:01Z" level=debug msg="Canceling flows: Runtime exited with error: exit status 1" func="go.amzn.com/lambda/core.(*Watchdog).CancelFlows.func1" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/core/watchdog.go:82"
time="2023-08-26T15:27:01Z" level=error msg="Init failed" func=go.amzn.com/lambda/rapid.handleStartError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:478" InvokeID= error="Runtime exited with error: exit status 1"
time="2023-08-26T15:27:01Z" level=info msg="blocking the credentials service" func="go.amzn.com/lambda/core.(*credentialsServiceImpl).BlockService" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/core/credentials.go:84"
time="2023-08-26T15:27:01Z" level=debug msg="Dispatching DONE:initCorrelationID" func="go.amzn.com/lambda/rapidcore.(*Server).dispatchDone" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:472"

edit: problem solved by adding PROVIDER_OVERRIDE_LAMBDA=legacy to docker compose file.

[joe4dev]

Hi @markmashworth and @Sotatek-HaiTrieu2

We just shipped major improvements to the Lambda data plane that fix the behavior where the "same error get logged repeatedly by the container" and provide better insights into errors and timeouts at the Lambda runtime startup (e.g., including container logs). Can you please pull the latest Docker image and try again with debug logs enabled using DEBUG=1?

The root cause is likely something else but our latest version hopefully helps to debug the issue quicker 📈

[joe4dev]

@markmashworth Please ensure to build the Numpy layer with the right target architecture in mind when deploying on an Apple Silicon ARM device.

[kirrg001]

Hi there! Do you know when the changes will be released? We are running into lambda startup errors and big timeouts a lot with 2.2.0 [OSX M1]

FYI my docker version is 2.2.1-dev already and it's not working. Lambda creation is around 20s and lambda invocation doesn't work at all.

Thank you

[joe4dev]

Thank you for sharing @kirrg001

The changes (i.e., Lambda improvements) are in latest and expected to be released later this week.

Have you tried the latest Docker image? What are the errors when running with DEBUG=1?

[aryamohanan]

Hi @joe4dev We are using the latest image to try to create and invoke a Lambda function. The creation was successful, but the invocation fails. I have attached the complete log for your reference.

Here is my docker-compose.yml:

localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME-localstack_main}"
    image: localstack/localstack:latest
    hostname: localstack
    ports:
      - "4566:4566"            # LocalStack Gateway
      - "4510-4559:4510-4559"  # external services port range
    environment:
      - DEBUG=1
      - DOCKER_HOST=unix:///var/run/docker.sock
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock"

Detailed Logs

localstack_main | 2023-09-26T12:56:46.937 INFO --- [ asgi_gw_1] localstack.request.aws : AWS lambda.CreateFunction => 201 localstack_main | 2023-09-26T12:56:46.939 DEBUG --- [rvice-task_1] l.s.l.i.lambda_models : Saving code wrapped-async-3cce0d01-da06-4add-b3ce-e4de0fc8bce5 to disk localstack_main | 2023-09-26T12:56:46.968 DEBUG --- [rvice-task_1] localstack.utils.run : Executing command: ['unzip', '-o', '-q', '/tmp/tmp9aba_w54'] localstack_main | 2023-09-26T12:56:46.969 DEBUG --- [rvice-task_1] l.s.l.i.version_manager : Version preparation of function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST took 30.51ms localstack_main | 2023-09-26T12:56:46.969 DEBUG --- [rvice-task_1] l.s.l.i.version_manager : Changing Lambda arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST (id c73395d7) to active localstack_main | 2023-09-26T12:56:46.969 DEBUG --- [rvice-task_1] l.s.l.i.event_manager : Starting event manager arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST id 281471252265424 localstack_main | 2023-09-26T12:56:46.972 DEBUG --- [ asgi_gw_1] l.services.sqs.provider : creating queue key=wrapped-async-b14816657d83d0168e4769eb22c58dd5 attributes=None tags=None localstack_main | 2023-09-26T12:56:47.091 INFO --- [ asgi_gw_2] localstack.request.aws : AWS lambda.GetFunctionConfiguration => 200 localstack_main | 2023-09-26T12:56:47.765 DEBUG --- [ asgi_gw_0] l.s.l.i.assignment : Starting new environment localstack_main | 2023-09-26T12:56:47.765 DEBUG --- [ asgi_gw_0] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST executor 916ddeabb4d4841522bc81436a4aa00c localstack_main | 2023-09-26T12:56:47.765 DEBUG --- [ asgi_gw_0] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST executor 916ddeabb4d4841522bc81436a4aa00c localstack_main | 2023-09-26T12:56:47.765 DEBUG --- [ asgi_gw_0] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c to executor 916ddeabb4d4841522bc81436a4aa00c localstack_main | 2023-09-26T12:56:47.773 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Creating container with attributes: {'mount_volumes': [], 'ports': , 'exposed_ports': [], 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'dns': '172.18.0.4', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'ulimits': None, 'command': None, 'detach': False, 'entrypoint': '/var/rapid/init', 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-2', 'AWS_REGION': 'us-east-2', 'AWS_LAMBDA_FUNCTION_NAME': 'wrapped-async', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/wrapped-async', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/09/26/[$LATEST]916ddeabb4d4841522bc81436a4aa00c', 'AWS_ACCESS_KEY_ID': 'xxxxxxxxxxx', 'AWS_SECRET_ACCESS_KEY': 'xxxxxxxxxxxx', 'AWS_SESSION_TOKEN': 'xxxxxxxxxxxxxxxxxxxxxxxxxx', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.xx.x.xx', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.18.0.4:4566', 'LOCALSTACK_RUNTIME_ID': '916ddeabb4d4841522bc81436a4aa00c', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.18.0.4:4566/_localstack_lambda/916ddeabb4d4841522bc81436a4aa00c', '_HANDLER': 'index.handler', 'AWS_EXECUTION_ENV': 'Aws_Lambda_nodejs18.x', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'image_name': 'public.ecr.aws/lambda/nodejs:18', 'interactive': False, 'name': 'localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c', 'network': 'nodejs_default', 'platform': 'linux/amd64', 'remove': False, 'self': , 'tty': False, 'user': None} localstack_main | 2023-09-26T12:56:47.798 DEBUG --- [ asgi_gw_0] localstack.packages.api : Installation of lambda-runtime skipped (already installed). localstack_main | 2023-09-26T12:56:47.798 DEBUG --- [ asgi_gw_0] localstack.packages.api : Performing runtime setup for already installed package. localstack_main | 2023-09-26T12:56:47.798 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.19-pre/arm64/. into localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c:/ localstack_main | 2023-09-26T12:56:47.884 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-2-tasks/wrapped-async-3cce0d01-da06-4add-b3ce-e4de0fc8bce5/code/. into localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c:/var/task localstack_main | 2023-09-26T12:56:47.937 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c localstack_main | 2023-09-26T12:56:48.303 DEBUG --- [ asgi_gw_0] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c in network nodejs_default. localstack_main | 2023-09-26T12:56:57.767 WARN --- [ Thread-18] l.s.l.i.execution_environm : Execution environment 916ddeabb4d4841522bc81436a4aa00c for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. localstack_main | 2023-09-26T12:56:57.771 DEBUG --- [ Thread-18] l.s.l.i.execution_environm : Logs from the execution environment 916ddeabb4d4841522bc81436a4aa00c after startup timeout: localstack_main | [lambda 916ddeabb4d4841522bc81436a4aa00c] time="2023-09-26T12:56:48Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:143" localstack_main | [lambda 916ddeabb4d4841522bc81436a4aa00c] time="2023-09-26T12:56:48Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" localstack_main | [lambda 916ddeabb4d4841522bc81436a4aa00c] time="2023-09-26T12:56:48Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:146" euid=0 gid=0 uid=0 username=root localstack_main | [lambda 916ddeabb4d4841522bc81436a4aa00c] localstack_main | 2023-09-26T12:56:57.771 DEBUG --- [ Thread-18] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c localstack_main | 2023-09-26T12:56:58.092 DEBUG --- [ Thread-18] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-wrapped-async-916ddeabb4d4841522bc81436a4aa00c localstack_main | 2023-09-26T12:56:58.131 INFO --- [ asgi_gw_0] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException)

Note : The invoke works when I set PROVIDER_OVERRIDE_LAMBDA=legacy in docker-compose, it takes ~18s but we do not want to use legacy.

Environment

- LocalStack: 2.2.1.dev
- Architecture: aarch64

Please let us know if you need any additional information. Thanks.

[joe4dev]

Hi @aryamohanan

Thank you for sharing the logs. The following warning message indicates that the Lambda function times out during the runtime startup:

localstack_main | 2023-09-26T12:56:57.767 WARN --- [ Thread-18] l.s.l.i.execution_environm : Execution environment 916ddeabb4d4841522bc81436a4aa00c for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT.

Given that your Lambda function takes ~18 seconds to start indicates that the default startup timeout (10s) might be insufficient. Could you try increasing LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT=30?

(sidenote: In the long term, there might be some potential to optimize the packaging of the Lambda function to reduce the long cold starts.)

[aryamohanan]

Hi @joe4dev Thanks for the replay, I've configured LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT=30, but unfortunately, it hasn't resolved my issue. I'm still encountering the same error.

[joe4dev]

@aryamohanan Could you try some extra long timeout such as LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT=300 (just for debugging)?

Is the Lambda package particularly big? Does the Lambda function do something time-consuming outside the handler function (i.e., during runtime startup)?

[aryamohanan]

@joe4dev! The lambda function is quite straightforward, as it solely entails the printing of a log message. The problem is specific to my computer, and when I make the same alterations, everything functions correctly on a machine with the x86_64 architecture.

[joe4dev]

@aryamohanan

The problem is specific to my computer,

You mentioned aarch64, what computer/operating system is it?

Does the Lambda invocation work with LAMBDA_IGNORE_ARCHITECTURE=1 (see configuration https://docs.localstack.cloud/references/configuration/#lambda)?

Further suggestions:

• Consider updating to the latest Docker version, which fixes several bugs (especially for macOS) https://docs.docker.com/desktop/release-notes/

• Consider disabling "Features in development" in the Docker settings.

[willm]

I think I'm having the same issue, I've spent quite a while debugging through localstack logs and eventually found that the container that localstack starts is failing to start, see these logs

'docker' 'start' -i 'localstack-main-lambda-my-function-30e0a8296e46a94a95eef080c1107fec'                                                                                                      ✔ 
time="2023-10-03T20:43:22Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:71" error="open /opt/extensions: no such file or directory"
time="2023-10-03T20:43:22Z" level=panic msg="Post \"http://172.17.0.1:4566/_localstack_lambda/30e0a8296e46a94a95eef080c1107fec/status/30e0a8296e46a94a95eef080c1107fec/ready\": dial tcp 172.17.0.1:4566: connect: connection refused" func=go.amzn.com/lambda/rapid.handleStart file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:473"
panic: (*logrus.Entry) 0xc00011a0e0

goroutine 55 [running]:
github.com/sirupsen/logrus.Entry.log({0xc00011a000, 0xc019388030, {0x0, 0x0, 0x0}, 0x0, 0x0, {0x0, 0x0}, 0x0, ...}, ...)
    /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/entry.go:259 +0x2de
github.com/sirupsen/logrus.(*Entry).Log(0xc00011a070, 0x0, {0xc0004a7c20?, 0x0?, 0x98ca00?})
    /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/entry.go:287 +0xa8
github.com/sirupsen/logrus.(*Logger).Log(0xc00011a000, 0x0, {0xc0004a7c20, 0x1, 0x1})
    /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/logger.go:193 +0x65
github.com/sirupsen/logrus.(*Logger).Panic(...)
    /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/logger.go:234
github.com/sirupsen/logrus.Panic(...)
    /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/exported.go:129
go.amzn.com/lambda/rapid.handleStart({0xc992b8, 0xc00039a140}, 0xc000146000, 0x0?, 0xc00013a630)
    /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:473 +0x51a
go.amzn.com/lambda/rapid.start({0xc992b8?, 0xc00039a140}, 0xc000146000)
    /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:688 +0x545
go.amzn.com/lambda/rapid.Start(0xc0003b2000)
    /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/sandbox.go:72 +0xdfe
go.amzn.com/lambda/rapidcore.(*SandboxBuilder).Create(0xc0003a00f0)
    /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/sandbox.go:209 +0xf8
created by main.main
    /home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:194 +0xa4a

The localstack logs indicate

Execution environment 30e0a8296e46a94a95eef080c1107fec for function arn:aws:lambda:eu-west-1:000000000000:function:my-function:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT.

my lambda code is about as simple as could be

exports.main = async (event) => {
  return {
    statusCode: 200,
    headers: {
      'Content-Type': 'application/json'
    },
    body: {
      message: 'Hello World!'
    }
  };
};

I'm on Linux (manjaro)

[aryamohanan]

Hey @joe4dev ,

I attempted to use LAMBDA_IGNORE_ARCHITECTURE=1, but it didn't seem to work for me. I'm using Rancher Desktop for container management. Interestingly, when I set PROVIDER_OVERRIDE_LAMBDA=legacy, the invocation works perfectly fine. However, we don't wanted use the legacy mode. I'm attaching the docker information for your reference

OS : macOs 14.0

Docker details

Client: Version: 24.0.2-rd Context: rancher-desktop Debug Mode: false Plugins: buildx: Docker Buildx (Docker Inc.) Version: v0.11.0 Path: xxxxxxxxx compose: Docker Compose (Docker Inc.) Version: v2.19.0 Path: xxxxxxxxx Server: Containers: 28 Running: 18 Paused: 0 Stopped: 10 Images: 42 Server Version: 23.0.6 Storage Driver: overlay2 Backing Filesystem: extfs Supports d_type: true Using metacopy: false Native Overlay Diff: true userxattr: false Logging Driver: json-file Cgroup Driver: cgroupfs Cgroup Version: 1 Plugins: Volume: local Network: bridge host ipvlan macvlan null overlay Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog Swarm: inactive Runtimes: io.containerd.runc.v2 runc Default Runtime: runc Init Binary: docker-init containerd version: 1fbd70374134b891f97ce19c70b6e50c7b9f4e0d runc version: 860f061b76bb4fc671f0f9e900f7d80ff93d4eb7 init version: Security Options: seccomp Profile: builtin Kernel Version: 6.1.30-0-virt Operating System: Alpine Linux v3.18 OSType: linux Architecture: aarch64 CPUs: 6 Total Memory: 11.66GiB Name: lima-rancher-desktop ID: xxxxxxxxxxx Docker Root Dir: /var/lib/docker Debug Mode: false Experimental: false Insecure Registries: 127.0.0.0/8 Live Restore Enabled: false

[joe4dev]

I think I'm having the same issue, I've spent quite a while debugging through localstack logs and eventually found that the container that localstack starts is failing to start, see these logs

'docker' 'start' -i 'localstack-main-lambda-my-function-30e0a8296e46a94a95eef080c1107fec'                                                                                                      ✔ 
time="2023-10-03T20:43:22Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:71" error="open /opt/extensions: no such file or directory"
time="2023-10-03T20:43:22Z" level=panic msg="Post \"http://172.17.0.1:4566/_localstack_lambda/30e0a8296e46a94a95eef080c1107fec/status/30e0a8296e46a94a95eef080c1107fec/ready\": dial tcp 172.17.0.1:4566: connect: connection refused" func=go.amzn.com/lambda/rapid.handleStart file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:473"
panic: (*logrus.Entry) 0xc00011a0e0

goroutine 55 [running]:
github.com/sirupsen/logrus.Entry.log({0xc00011a000, 0xc019388030, {0x0, 0x0, 0x0}, 0x0, 0x0, {0x0, 0x0}, 0x0, ...}, ...)
  /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/entry.go:259 +0x2de
github.com/sirupsen/logrus.(*Entry).Log(0xc00011a070, 0x0, {0xc0004a7c20?, 0x0?, 0x98ca00?})
  /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/entry.go:287 +0xa8
github.com/sirupsen/logrus.(*Logger).Log(0xc00011a000, 0x0, {0xc0004a7c20, 0x1, 0x1})
  /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/logger.go:193 +0x65
github.com/sirupsen/logrus.(*Logger).Panic(...)
  /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/logger.go:234
github.com/sirupsen/logrus.Panic(...)
  /home/runner/go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/exported.go:129
go.amzn.com/lambda/rapid.handleStart({0xc992b8, 0xc00039a140}, 0xc000146000, 0x0?, 0xc00013a630)
  /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:473 +0x51a
go.amzn.com/lambda/rapid.start({0xc992b8?, 0xc00039a140}, 0xc000146000)
  /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:688 +0x545
go.amzn.com/lambda/rapid.Start(0xc0003b2000)
  /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/sandbox.go:72 +0xdfe
go.amzn.com/lambda/rapidcore.(*SandboxBuilder).Create(0xc0003a00f0)
  /home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/sandbox.go:209 +0xf8
created by main.main
  /home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:194 +0xa4a

The localstack logs indicate

Execution environment 30e0a8296e46a94a95eef080c1107fec for function arn:aws:lambda:eu-west-1:000000000000:function:my-function:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT.

my lambda code is about as simple as could be

exports.main = async (event) => {
  return {
    statusCode: 200,
    headers: {
      'Content-Type': 'application/json'
    },
    body: {
      message: 'Hello World!'
    }
  };
};

I'm on Linux (manjaro)

Hi @willm

The message dial tcp 172.17.0.1:4566: connect: connection refused indicates that the Lambda container cannot connect to LocalStack. This is likely a Docker networking issue. Please ensure that Lambda containers are in the same network as the LocalStack container. Notice that LAMBDA_DOCKER_NETWORK does currently not support host mode.

How do you start LocalStack? Feel free to share your LocalStack configuration (e.g., docker-compose.yml) for feedback.

[joe4dev]

Hey @joe4dev ,

I attempted to use LAMBDA_IGNORE_ARCHITECTURE=1, but it didn't seem to work for me. I'm using Rancher Desktop for container management. Interestingly, when I set PROVIDER_OVERRIDE_LAMBDA=legacy, the invocation works perfectly fine. However, we don't wanted use the legacy mode. I'm attaching the docker information for your reference

OS : macOs 14.0 Docker details

Hi @aryamohanan

The network field Network: bridge host ipvlan macvlan null overlay contains host but I guess the host network is not used in LocalStack (currently not supported for Lambda)?

You mentioned that "The problem is specific to my computer". Does it work for others in your team with "Rancher Desktop", "x86_64", "macOs 14.0"? I am trying to understand what's the distinguishing factor here.

Is there a specific reason you need hostname: localstack in the docker-compose?

I noticed in the initial LocalStack logs that the Lambda functions uses the network 'network': 'nodejs_default'. Did you configure a specific network?

[willm]

@joe4dev OK sorry maybe it's a different problem then, I'm actually trying to fix/get to the bottom of a different issue so I'm running localstack directly via make start. I don't want to hijack this issue, there's probably something I need to do to allow the docker containers that lambda spins up to talk back to my host machine.

[joe4dev]

@joe4dev OK sorry maybe it's a different problem then, I'm actually trying to fix/get to the bottom of a different issue so I'm running localstack directly via make start. I don't want to hijack this issue, there's probably something I need to do to allow the docker containers that lambda spins up to talk back to my host machine.

@willm I see. Feel free to reach out in our community Slack. In the meantime, these documentation pages might be helpful:

• Installation
• Network troubleshooting

[joe4dev]

Let's focus on resolving the issue from @markmashworth and @aryamohanan

✅ The infinite error loop has been resolved in major Lambda improvements https://github.com/localstack/localstack/pull/8970.

🚧 If I understand correctly, the remaining problem is specific to one machine setup (maybe related to aarch64, Rancher Desktop, 🤔 ) but generally works in LocalStack (tested on another x86_64 machine). Feel free to correct me @aryamohanan

Sidenote: Unless deploying large Lambda packages, startup times such as "~18s" or "20s" appear exceedingly slow.

[aryamohanan]

@joe4dev The lambda function is a simple function with minimal code; the issue is with only the invoke command; all other commands operate well. Even after removing the hostname from the docker-compose file, the problem persists. We need to run this in macOS M1 with rancher-desktop.

[joe4dev]

Hi @aryamohanan

I just tried Ranger Desktop (Version 1.10.0 (1.10.0)) on my M1 Macbook Pro (macOS 13.6) using our official docker-compose.yml with DEBUG=1:

version: "3.8"

services:
  localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME-localstack_main}"
    image: localstack/localstack
    ports:
      - "127.0.0.1:4566:4566"            # LocalStack Gateway
      - "127.0.0.1:4510-4559:4510-4559"  # external services port range
    environment:
      - DEBUG=1
      - DOCKER_HOST=unix:///var/run/docker.sock
    volumes:
      - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack"
      - "/var/run/docker.sock:/var/run/docker.sock"

I was able to successfully invoke some simple Nodejs and Python Lambda functions from our integration test suite against LocalStack with Ranger Desktop. I used the default configuration for Ranger Desktop, notably:

Volumes: reverse-sshfs
Network: Disabled experimental socket-vmnet
Emulation: QEMU

One thing I noticed having Docker Desktop installed (but stopped) at the same time: I had to use ~/.rd/bin/docker-compose directly to avoid permission issues (I guess a symlink without a Docker Desktop installation would fix the issue as well).

Suggestions

Does the container within Docker have root privileges? I noticed that the last line in your initial Lambda container logs ended right before dropping root privileges: "Process running as root user". This might indicate that the container fails to drop root privileges because it does not have them and then just hangs. You could try to disable that parity feature by setting LAMBDA_DOCKER_FLAGS=-e LOCALSTACK_USER=""

Would it be possible to share a minimal reproducible example?

[shen-qin]

Hi there,

I am having the same issues using OSX M1 and encountered the following issue.

2023-10-17 09:33:24 time="2023-10-17T01:33:24Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:71" error="open /opt/extensions: no such file or directory"

I installed localstack via homebrew, but I have since uninstalled and reinstalled using docker, but I am unsure of where to add ROVIDER_OVERRIDE_LAMBDA=legacy as mentioned by @Sotatek-HaiTrieu2

[joe4dev]

Hi there,

I am having the same issues using OSX M1 and encountered the following issue.

2023-10-17 09:33:24 time="2023-10-17T01:33:24Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:71" error="open /opt/extensions: no such file or directory"

I installed localstack via homebrew, but I have since uninstalled and reinstalled using docker, but I am unsure of where to add ROVIDER_OVERRIDE_LAMBDA=legacy as mentioned by @Sotatek-HaiTrieu2

Hi @shen-qin

Your log messages are expected if you do not use a custom Lambda extension. Can you please provide some more context such as a reproducible scenario and more detailed logs using DEBUG=1?

The provider override is a LocalStack configuration but not recommended. The legacy Lambda implementation will be removed with LocalStack 3.0. Hence, we prioritize solving any blocking issues.

[aryamohanan]

@joe4dev Sorry for the delay in responding; I'm still having problems despite having tried all you said above. I've attached my docker-compose file for your reference. In addition to the local stack, I'm running a couple more containers.

docker-compose

version: '2' services: zookeeper: image: wurstmeister/zookeeper ports: - 2181:2181 kafka: image: wurstmeister/kafka:2.12-2.2.1 ports: - 9092:9092 - 29092:29092 depends_on: - "zookeeper" hostname: kafka0 environment: KAFKA_LISTENERS: EXTERNAL://:9092,PLAINTEXT://:29092 KAFKA_ADVERTISED_LISTENERS: PLAINTEXT://kafka0:29092,EXTERNAL://localhost:9092 KAFKA_OFFSETS_TOPIC_REPLICATION_FACTOR: 1 KAFKA_INTER_BROKER_LISTENER_NAME: PLAINTEXT KAFKA_CREATE_TOPICS: "test:1:1" KAFKA_ZOOKEEPER_CONNECT: zookeeper:2181 volumes: - /var/run/docker.sock:/var/run/docker.sock - ./bin:/nodejs-test-bin command: ["/nodejs-test-bin/wait-for-it.sh", "-s", "-t", "120", "zookeeper:2181", "--", "start-kafka.sh"] schema-registry: image: confluentinc/cp-schema-registry:4.1.0 hostname: schema-registry depends_on: - "kafka" ports: - "8081:8081" environment: SCHEMA_REGISTRY_KAFKASTORE_CONNECTION_URL: "zookeeper:2181" SCHEMA_REGISTRY_KAFKASTORE_BOOTSTRAP_SERVERS: "PLAINTEXT://kafka0:29092" SCHEMA_REGISTRY_HOST_NAME: schema-registry localstack: container_name: "${LOCALSTACK_DOCKER_NAME-localstack_main}" image: localstack/localstack:latest hostname: localstack ports: - "4566:4566" # LocalStack Gateway - "4510-4559:4510-4559" # external services port range environment: - DEBUG=${DEBUG-} - DOCKER_HOST=unix:///var/run/docker.sock volumes: - "/var/run/docker.sock:/var/run/docker.sock"

error details

localstack_main | 2023-10-18T15:00:19.977 WARN --- [ Thread-12] l.s.l.i.execution_environm : Execution environment f0c4c8121bfccb7ef7d52d7e2c2b387b for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async-v3:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. localstack_main | 2023-10-18T15:00:20.324 INFO --- [ asgi_gw_0] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException)

Everything works OK when I run localstack alone in docker-compose, but it does not function with other containers, although it works well with the x86_64 architecture. If you require any other information, please let me know.

[joe4dev]

@joe4dev Sorry for the delay in responding; I'm still having problems despite having tried all you said above. I've attached my docker-compose file for your reference. In addition to the local stack, I'm running a couple more containers.

Thank you for the update @aryamohanan. We are sorry to hear that the configuration on ARM still causes issues.

Can you please try again with the latest LocalStack image and DEBUG=1 (or even LS_LOG=trace) for more detailed logging? In particular, I'm interested in the Lambda container logs. (Alternatively, the Lambda containers are retained when setting LAMBDA_REMOVE_CONTAINERS=0)

Sidenote: Adding the volume mount - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack" helps with caching.

[joe4dev]

Everything works OK when I run localstack alone in docker-compose, but it does not function with other containers, although it works well with the x86_64 architecture.

@aryamohanan Can you please clarify whether this interpretation is correct:

• ✅ Running LocalStack standalone (i.e., without other containers) in docker-compose works both with x86_64 and ARM
• ✅ Running LocalStack with other containers through a combined docker-compose works with x86_64
• ❌ Running LocalStack with other containers through a combined docker-compose fails on ARM with the Lambda function timed out during startup

What is the architecture of the Lambda function (x86_64 | arm64)?

[aryamohanan]

@joe4dev Your interpretations are correct. Running LocalStack with other containers through a combined docker-compose fails on ARM with the Lambda function invocation. Create command and other get commands are working fine. Here is my detailed log with DEBUG=1.

Log

localstack_main | 2023-10-19T09:52:32.586 DEBUG --- [ asgi_gw_1] l.s.l.i.assignment : Starting new environment localstack_main | 2023-10-19T09:52:32.586 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async-v3:$LATEST executor 8159049be77df1b5a9632b167e59f293 localstack_main | 2023-10-19T09:52:32.586 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async-v3:$LATEST executor 8159049be77df1b5a9632b167e59f293 localstack_main | 2023-10-19T09:52:32.586 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293 to executor 8159049be77df1b5a9632b167e59f293 localstack_main | 2023-10-19T09:52:32.594 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/nodejs:18', 'name': 'localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-2', 'AWS_REGION': 'us-east-2', 'AWS_LAMBDA_FUNCTION_NAME': 'wrapped-async-v3', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/wrapped-async-v3', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/10/19/[$LATEST]8159049be77df1b5a9632b167e59f293', 'AWS_ACCESS_KEY_ID': 'xxxxxxxxx', 'AWS_SECRET_ACCESS_KEY': ‘xxxxxxxxxxx, 'AWS_SESSION_TOKEN': ‘x’xxxxxxxxxxxxx, 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.18.0.7', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.18.0.7:4566', 'LOCALSTACK_RUNTIME_ID': '8159049be77df1b5a9632b167e59f293', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.18.0.7:4566/_localstack_lambda/8159049be77df1b5a9632b167e59f293', '_HANDLER': 'index.handler', 'AWS_EXECUTION_ENV': 'Aws_Lambda_nodejs18.x', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'nodejs_default', 'dns': '172.18.0.7', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} localstack_main | 2023-10-19T09:52:32.625 DEBUG --- [ asgi_gw_1] localstack.packages.api : Installation of lambda-runtime skipped (already installed). localstack_main | 2023-10-19T09:52:32.625 DEBUG --- [ asgi_gw_1] localstack.packages.api : Performing runtime setup for already installed package. localstack_main | 2023-10-19T09:52:32.625 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.19-pre/arm64/. into localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293:/ localstack_main | 2023-10-19T09:52:32.732 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-2-tasks/wrapped-async-v3-901acaa5-57fe-4379-884e-cd0c03827f6c/code/. into localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293:/var/task localstack_main | 2023-10-19T09:52:32.779 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293 localstack_main | 2023-10-19T09:52:33.253 DEBUG --- [ asgi_gw_1] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293 in network nodejs_default. nodejs-kafka-1 | waiting for kafka to be ready localstack_main | 2023-10-19T09:52:42.587 WARN --- [ Thread-18] l.s.l.i.execution_environm : Execution environment 8159049be77df1b5a9632b167e59f293 for function arn:aws:lambda:us-east-2:000000000000:function:wrapped-async-v3:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. localstack_main | 2023-10-19T09:52:42.591 DEBUG --- [ Thread-18] l.s.l.i.execution_environm : Logs from the execution environment 8159049be77df1b5a9632b167e59f293 after startup timeout: localstack_main | [lambda 8159049be77df1b5a9632b167e59f293] time="2023-10-19T09:52:33Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" localstack_main | [lambda 8159049be77df1b5a9632b167e59f293] time="2023-10-19T09:52:33Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:143" localstack_main | [lambda 8159049be77df1b5a9632b167e59f293] time="2023-10-19T09:52:33Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:146" euid=0 gid=0 uid=0 username=root localstack_main | [lambda 8159049be77df1b5a9632b167e59f293] localstack_main | 2023-10-19T09:52:42.591 DEBUG --- [ Thread-18] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293 localstack_main | 2023-10-19T09:52:42.878 DEBUG --- [ Thread-18] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-wrapped-async-v3-8159049be77df1b5a9632b167e59f293 localstack_main | 2023-10-19T09:52:42.911 INFO --- [ asgi_gw_1] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException)

Lambda function architectures: [ 'x86_64' ]

[joe4dev]

There are no more logs after Process running as root user.

@aryamohanan Could you please try again without dropping the root privileges in the container?

1. Pull the latest LocalStack image. (I noticed in the previous logs that we have released 4 newer versions of the lambda-runtime-init in the meantime v0.1.19-pre => v0.1.22-pre).
2. Set LAMBDA_INIT_USER=root to disable dropping root privileges
3. Try again.

We cannot reproduce the issue on our side.

[shen-qin]

@joe4dev Hi there, sorry for the delay, the following is my log message. Thank you for the help!

log

2023-10-27 03:50:24 LocalStack supervisor: starting 2023-10-27 03:50:24 LocalStack supervisor: localstack process (PID 15) starting 2023-10-27 03:50:24 2023-10-27 03:50:24 LocalStack version: 2.3.3.dev 2023-10-27 03:50:24 LocalStack Docker container id: 6a4413a4e9b3 2023-10-27 03:50:24 LocalStack build date: 2023-10-26 2023-10-27 03:50:24 LocalStack build git hash: 30b6049a 2023-10-27 03:50:24 2023-10-27 03:50:24 2023-10-26T19:50:24.562 DEBUG --- [ MainThread] stevedore._cache : reading /root/.cache/python-entrypoints/cd849a539cf6e018f562141345dc55e4984c17a8ba62d9f8e50f89b91fb384ea 2023-10-27 03:50:24 2023-10-26T19:50:24.565 DEBUG --- [ MainThread] stevedore._cache : writing to /root/.cache/python-entrypoints/cd849a539cf6e018f562141345dc55e4984c17a8ba62d9f8e50f89b91fb384ea 2023-10-27 03:50:24 2023-10-26T19:50:24.565 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_patch_botocore_json_parser', value='localstack.aws.client:_patch_botocore_json_parser', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.566 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_publish_config_as_analytics_event', value='localstack.runtime.analytics:_publish_config_as_analytics_event', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.566 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_publish_container_info', value='localstack.runtime.analytics:_publish_container_info', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.566 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_run_init_scripts_on_start', value='localstack.runtime.init:_run_init_scripts_on_start', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.567 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='deprecation_warnings', value='localstack.plugins:deprecation_warnings', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.567 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_partition_adjusting_proxy_listener', value='localstack.plugins:register_partition_adjusting_proxy_listener', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.567 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='setup_dns_configuration_on_host', value='localstack.dns.plugins:setup_dns_configuration_on_host', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.567 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='start_dns_server', value='localstack.dns.plugins:start_dns_server', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.567 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='validate_configuration', value='localstack.services.lambda_.plugins:validate_configuration', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.569 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_pickle_patches_runtime', value='localstack_persistence.pickling.__plugins__:register_pickle_patches_runtime', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.570 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_public_cloudpods_endpoints', value='localstack_persistence.pods.__plugins__:register_public_cloudpods_endpoints', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.570 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_reset_state_resource', value='localstack_persistence.reset.__plugins__:register_reset_state_resource', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.570 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_state_load_strategy', value='localstack_persistence.snapshot.__plugins__:register_state_load_strategy', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.681 WARN --- [ MainThread] l.services.internal : Enabling diagnose endpoint, please be aware that this can expose sensitive information via your network. 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_state_resource', value='localstack_persistence.snapshot.__plugins__:register_state_resource', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_state_save_strategy', value='localstack_persistence.snapshot.__plugins__:register_state_save_strategy', group='localstack.hooks.on_infra_start') 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._patch_botocore_json_parser = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_patch_botocore_json_parser 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._publish_config_as_analytics_event = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_publish_config_as_analytics_event 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._publish_container_info = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_publish_container_info 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._run_init_scripts_on_start = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_run_init_scripts_on_start 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.deprecation_warnings = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:deprecation_warnings 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_partition_adjusting_proxy_listener = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.683 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_start:register_partition_adjusting_proxy_listener is disabled 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.setup_dns_configuration_on_host = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:setup_dns_configuration_on_host 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.start_dns_server = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:start_dns_server 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.validate_configuration = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:validate_configuration 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_pickle_patches_runtime = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:register_pickle_patches_runtime 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_public_cloudpods_endpoints = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:register_public_cloudpods_endpoints 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_reset_state_resource = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_start:register_reset_state_resource is disabled 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_state_load_strategy = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_start:register_state_load_strategy is disabled 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_state_resource = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_start:register_state_resource is disabled 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_state_save_strategy = ) 2023-10-27 03:50:24 2023-10-26T19:50:24.684 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_start:register_state_save_strategy is disabled 2023-10-27 03:50:24 2023-10-26T19:50:24.697 DEBUG --- [ MainThread] localstack.dns.server : Determined fallback dns: 192.168.65.7 2023-10-27 03:50:24 2023-10-26T19:50:24.697 DEBUG --- [ MainThread] localstack.dns.server : Starting DNS servers (tcp/udp port 53 on 0.0.0.0)... 2023-10-27 03:50:24 2023-10-26T19:50:24.697 DEBUG --- [ MainThread] localstack.dns.server : Adding host .*localhost.localstack.cloud pointing to LocalStack 2023-10-27 03:50:24 2023-10-26T19:50:24.697 DEBUG --- [ MainThread] localstack.dns.server : Adding host .*localhost.localstack.cloud with record DynamicRecord(record_type=, record_id=None) 2023-10-27 03:50:24 2023-10-26T19:50:24.697 DEBUG --- [ MainThread] localstack.dns.server : Adding host .*localhost.localstack.cloud with record DynamicRecord(record_type=, record_id=None) 2023-10-27 03:50:24 2023-10-26T19:50:24.698 DEBUG --- [-functhread1] localstack.dns.server : DNS Server started 2023-10-27 03:50:24 2023-10-26T19:50:24.701 DEBUG --- [ MainThread] localstack.dns.server : DNS server startup finished. 2023-10-27 03:50:24 2023-10-26T19:50:24.702 DEBUG --- [ MainThread] localstack.runtime.init : Init scripts discovered: {BOOT: [], START: [], READY: [], SHUTDOWN: []} 2023-10-27 03:50:24 2023-10-26T19:50:24.702 DEBUG --- [ MainThread] localstack.plugins : Checking for the usage of deprecated community features and configs... 2023-10-27 03:50:24 2023-10-26T19:50:24.702 DEBUG --- [ MainThread] localstack.dns.server : Overwriting container DNS server to point to localhost 2023-10-27 03:50:24 2023-10-26T19:50:24.769 DEBUG --- [ MainThread] localstack.utils.threads : start_thread called without providing a custom name 2023-10-27 03:50:24 2023-10-26T19:50:24.769 DEBUG --- [-functhread3] localstack.utils.run : Executing command: whoami 2023-10-27 03:50:24 2023-10-26T19:50:24.776 DEBUG --- [-functhread3] localstack.utils.ssl : Using cached SSL certificate (less than 6hrs since last update). 2023-10-27 03:50:24 2023-10-26T19:50:24.780 INFO --- [-functhread4] hypercorn.error : Running on https://0.0.0.0:4566 (CTRL + C to quit) 2023-10-27 03:50:24 2023-10-26T19:50:24.780 INFO --- [-functhread4] hypercorn.error : Running on https://0.0.0.0:4566 (CTRL + C to quit) 2023-10-27 03:50:25 2023-10-26T19:50:25.077 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='acm:default', value='localstack.services.providers:acm', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.088 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='apigateway:default', value='localstack.services.providers:apigateway', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.088 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='cloudformation:default', value='localstack.services.providers:cloudformation', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.089 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='cloudwatch:default', value='localstack.services.providers:cloudwatch', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.089 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='config:default', value='localstack.services.providers:awsconfig', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.089 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='dynamodb:default', value='localstack.services.providers:dynamodb', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.089 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='dynamodbstreams:default', value='localstack.services.providers:dynamodbstreams', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.089 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ec2:default', value='localstack.services.providers:ec2', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.089 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='es:default', value='localstack.services.providers:es', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.092 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='events:default', value='localstack.services.providers:events', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.092 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='firehose:default', value='localstack.services.providers:firehose', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.093 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='iam:default', value='localstack.services.providers:iam', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.093 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='kinesis:default', value='localstack.services.providers:kinesis', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.098 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='kms:default', value='localstack.services.providers:kms', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.098 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:asf', value='localstack.services.providers:lambda_asf', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:default', value='localstack.services.providers:lambda_', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:legacy', value='localstack.services.providers:lambda_legacy', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:v1', value='localstack.services.providers:lambda_v1', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:v2', value='localstack.services.providers:lambda_v2', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='logs:default', value='localstack.services.providers:logs', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='opensearch:default', value='localstack.services.providers:opensearch', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ram:default', value='localstack.services.providers:ram', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='redshift:default', value='localstack.services.providers:redshift', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='resource-groups:default', value='localstack.services.providers:resource_groups', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='resourcegroupstaggingapi:default', value='localstack.services.providers:resourcegroupstaggingapi', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='route53:default', value='localstack.services.providers:route53', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='route53resolver:default', value='localstack.services.providers:route53resolver', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:asf', value='localstack.services.providers:s3_asf', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.099 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:default', value='localstack.services.providers:s3', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:legacy', value='localstack.services.providers:s3_legacy', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:stream', value='localstack.services.providers:s3_stream', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:v1', value='localstack.services.providers:s3_v1', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:v2', value='localstack.services.providers:s3_v2', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:v3', value='localstack.services.providers:s3_v3', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3control:default', value='localstack.services.providers:s3control', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='scheduler:default', value='localstack.services.providers:scheduler', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='secretsmanager:default', value='localstack.services.providers:secretsmanager', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ses:default', value='localstack.services.providers:ses', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sns:default', value='localstack.services.providers:sns', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sqs:default', value='localstack.services.providers:sqs', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ssm:default', value='localstack.services.providers:ssm', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:default', value='localstack.services.providers:stepfunctions', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:v1', value='localstack.services.providers:stepfunctions_v1', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:v2', value='localstack.services.providers:stepfunctions_v2', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sts:default', value='localstack.services.providers:sts', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='support:default', value='localstack.services.providers:support', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='swf:default', value='localstack.services.providers:swf', group='localstack.aws.provider') 2023-10-27 03:50:25 2023-10-26T19:50:25.100 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='transcribe:default', value='localstack.services.providers:transcribe', group='localstack.aws.provider') 2023-10-27 03:50:25 Ready. 2023-10-27 03:50:25 2023-10-26T19:50:25.101 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_run_init_scripts_on_ready', value='localstack.runtime.init:_run_init_scripts_on_ready', group='localstack.hooks.on_infra_ready') 2023-10-27 03:50:25 2023-10-26T19:50:25.101 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_virtual_host_routes', value='localstack.services.s3.virtual_host:register_virtual_host_routes', group='localstack.hooks.on_infra_ready') 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='do_run_state_load_all', value='localstack_persistence.snapshot.__plugins__:do_run_state_load_all', group='localstack.hooks.on_infra_ready') 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_ready._run_init_scripts_on_ready = ) 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_ready:_run_init_scripts_on_ready 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_ready.register_virtual_host_routes = ) 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_ready:register_virtual_host_routes 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_ready.do_run_state_load_all = ) 2023-10-27 03:50:25 2023-10-26T19:50:25.102 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_ready:do_run_state_load_all is disabled 2023-10-27 03:50:34 2023-10-26T19:50:34.379 DEBUG --- [ asgi_gw_0] l.a.p.service_router : loading service catalog index cache file /var/lib/localstack/cache/service-catalog-2_3_3_dev-1_31_71.pickle 2023-10-27 03:50:53 2023-10-26T19:50:53.918 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.dynamodb:default = ) 2023-10-27 03:50:53 2023-10-26T19:50:53.918 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.aws.provider:dynamodb:default 2023-10-27 03:50:54 2023-10-26T19:50:54.101 DEBUG --- [ asgi_gw_0] localstack.packages.api : Installation of dynamodb-local skipped (already installed). 2023-10-27 03:50:54 2023-10-26T19:50:54.101 DEBUG --- [ asgi_gw_0] localstack.packages.api : Performing runtime setup for already installed package. 2023-10-27 03:50:54 2023-10-26T19:50:54.101 DEBUG --- [ asgi_gw_0] l.services.dynamodb.server : Starting DynamoDB Local: ['java', '-Xmx256m', '-javaagent:/usr/lib/localstack/dynamodb-local/latest/ddb-local-loader-0.1.jar', '-Djava.library.path=/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal_lib', '-jar', '/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal.jar', '-port', '47005', '-dbPath', '/var/lib/localstack/tmp/state/dynamodb'] 2023-10-27 03:50:54 2023-10-26T19:50:54.101 DEBUG --- [functhread11] localstack.utils.run : Executing command: ['java', '-Xmx256m', '-javaagent:/usr/lib/localstack/dynamodb-local/latest/ddb-local-loader-0.1.jar', '-Djava.library.path=/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal_lib', '-jar', '/usr/lib/localstack/dynamodb-local/latest/DynamoDBLocal.jar', '-port', '47005', '-dbPath', '/var/lib/localstack/tmp/state/dynamodb'] 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : Initializing DynamoDB Local with the following configuration: 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : Port:47005 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : InMemory:false 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : DbPath:/var/lib/localstack/tmp/state/dynamodb 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : SharedDb:false 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : shouldDelayTransientStatuses:false 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : CorsParams:null 2023-10-27 03:50:54 2023-10-26T19:50:54.591 DEBUG --- [functhread11] l.services.dynamodb.server : 2023-10-27 03:50:57 2023-10-26T19:50:57.393 INFO --- [ asgi_gw_0] localstack.utils.bootstrap : Execution of "require" took 3475.05ms 2023-10-27 03:50:57 2023-10-26T19:50:57.610 INFO --- [ asgi_gw_0] localstack.request.aws : AWS dynamodb.CreateTable => 200 2023-10-27 03:51:00 2023-10-26T19:51:00.009 INFO --- [ asgi_gw_1] localstack.request.aws : AWS dynamodb.PutItem => 200 2023-10-27 03:51:25 2023-10-26T19:51:25.568 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.lambda:default = ) 2023-10-27 03:51:25 2023-10-26T19:51:25.569 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.aws.provider:lambda:default 2023-10-27 03:51:25 2023-10-26T19:51:25.574 DEBUG --- [ asgi_gw_0] plugin.manager : no extensions found in namespace localstack.hooks.lambda_inject_layer_fetcher 2023-10-27 03:51:25 2023-10-26T19:51:25.588 DEBUG --- [ asgi_gw_0] l.s.lambda_.urlrouter : Registering parameterized Lambda routes. 2023-10-27 03:51:25 2023-10-26T19:51:25.589 DEBUG --- [ asgi_gw_0] stevedore.extension : found extension EntryPoint(name='docker', value='localstack.services.lambda_.invocation.plugins:DockerRuntimeExecutorPlugin', group='localstack.lambda.runtime_executor') 2023-10-27 03:51:25 2023-10-26T19:51:25.589 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.lambda.runtime_executor.docker = ) 2023-10-27 03:51:25 2023-10-26T19:51:25.589 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.lambda.runtime_executor:docker 2023-10-27 03:51:25 2023-10-26T19:51:25.619 DEBUG --- [ asgi_gw_1] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.sts:default = ) 2023-10-27 03:51:25 2023-10-26T19:51:25.619 DEBUG --- [ asgi_gw_1] plugin.manager : loading plugin localstack.aws.provider:sts:default 2023-10-27 03:51:25 2023-10-26T19:51:25.896 DEBUG --- [ asgi_gw_1] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.s3:default = ) 2023-10-27 03:51:25 2023-10-26T19:51:25.896 DEBUG --- [ asgi_gw_1] plugin.manager : loading plugin localstack.aws.provider:s3:default 2023-10-27 03:51:26 2023-10-26T19:51:26.143 INFO --- [ asgi_gw_0] localstack.request.aws : AWS lambda.CreateFunction => 201 2023-10-27 03:51:26 2023-10-26T19:51:26.143 DEBUG --- [rvice-task_0] plugin.manager : no extensions found in namespace localstack.hooks.lambda_prepare_docker_executors 2023-10-27 03:51:26 2023-10-26T19:51:26.144 DEBUG --- [rvice-task_0] l.s.l.i.lambda_models : Saving code CreateRole-869c9126-6063-47fe-897c-12735f307eb3 to disk 2023-10-27 03:51:26 2023-10-26T19:51:26.163 DEBUG --- [rvice-task_0] localstack.utils.run : Executing command: ['unzip', '-o', '-q', '/tmp/tmpyen25srd'] 2023-10-27 03:51:26 2023-10-26T19:51:26.164 DEBUG --- [rvice-task_0] l.u.c.docker_sdk_client : Pulling Docker image: public.ecr.aws/lambda/provided:al2 2023-10-27 03:51:28 2023-10-26T19:51:28.537 DEBUG --- [rvice-task_0] l.s.l.i.version_manager : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST took 2393.82ms 2023-10-27 03:51:28 2023-10-26T19:51:28.537 DEBUG --- [rvice-task_0] l.s.l.i.version_manager : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST (id 263862b6) to active 2023-10-27 03:51:28 2023-10-26T19:51:28.537 DEBUG --- [rvice-task_0] l.s.l.i.event_manager : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST id 281472531710672 2023-10-27 03:51:28 2023-10-26T19:51:28.554 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.sqs:default = ) 2023-10-27 03:51:28 2023-10-26T19:51:28.554 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.aws.provider:sqs:default 2023-10-27 03:51:28 2023-10-26T19:51:28.623 DEBUG --- [ asgi_gw_0] l.services.sqs.provider : creating queue key=CreateRole-6229ff7dc6de6d2380bcb5f30c420329 attributes=None tags=None 2023-10-27 03:51:30 2023-10-26T19:51:30.675 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.cloudwatch:default = ) 2023-10-27 03:51:30 2023-10-26T19:51:30.675 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.aws.provider:cloudwatch:default 2023-10-27 03:51:30 2023-10-26T19:51:30.688 DEBUG --- [ asgi_gw_0] l.s.cloudwatch.provider : starting cloudwatch scheduler 2023-10-27 03:51:32 2023-10-26T19:51:32.153 DEBUG --- [ asgi_gw_0] l.s.l.i.assignment : Starting new environment 2023-10-27 03:51:32 2023-10-26T19:51:32.153 DEBUG --- [ asgi_gw_0] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST executor 6fa7dc5e1d7f1a9747d5cc391ec72a7e 2023-10-27 03:51:32 2023-10-26T19:51:32.153 DEBUG --- [ asgi_gw_0] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST executor 6fa7dc5e1d7f1a9747d5cc391ec72a7e 2023-10-27 03:51:32 2023-10-26T19:51:32.153 DEBUG --- [ asgi_gw_0] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e to executor 6fa7dc5e1d7f1a9747d5cc391ec72a7e 2023-10-27 03:51:32 2023-10-26T19:51:32.170 DEBUG --- [ asgi_gw_0] l.u.c.container_client : Getting networks for container: localstack_main 2023-10-27 03:51:32 2023-10-26T19:51:32.175 INFO --- [ asgi_gw_0] l.u.container_networking : Determined main container network: bridge 2023-10-27 03:51:32 2023-10-26T19:51:32.175 DEBUG --- [ asgi_gw_0] l.u.c.container_client : Getting ipv4 address for container localstack_main in network bridge. 2023-10-27 03:51:32 2023-10-26T19:51:32.181 INFO --- [ asgi_gw_0] l.u.container_networking : Determined main container target IP: 172.17.0.2 2023-10-27 03:51:32 2023-10-26T19:51:32.183 DEBUG --- [ asgi_gw_0] plugin.manager : no extensions found in namespace localstack.hooks.lambda_start_docker_executor 2023-10-27 03:51:32 2023-10-26T19:51:32.183 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/provided:al2', 'name': 'localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-1', 'AWS_REGION': 'us-east-1', 'AWS_LAMBDA_FUNCTION_NAME': 'CreateRole', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/CreateRole', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/10/26/[$LATEST]6fa7dc5e1d7f1a9747d5cc391ec72a7e', 'AWS_ACCESS_KEY_ID': 'ASIAQAAAAAAAAZHDC67S', 'AWS_SECRET_ACCESS_KEY': 'lE5WlzxV4OPQSAc/+iuLgZjsfj0MQjc0cwqan9Le', 'AWS_SESSION_TOKEN': 'FQoGZXIvYXdzEBYaDP5e8XoPQZJjKZFeB64oBDxdMyyFePBsUvPWSxqsJo/A+jxuC8W3kkqET/RO98KaXLt7LyHBwdAW7DIIuQORMdILQIlDNbErZwa+n/s69zXZ1uE2nLojaVDwKTF8dtgjwPnZgI5SnppVUCGdrB4zRkV3irEDAmyE1pAj/VunXOPCcp5Y7BCl37ZH2BIZXcL7KBU1mHX4fA10EN43N5e5gT6LKXQ8wg8/ONiRgrXOrwi3eCSwfXjGJeNJIt0U3OSb+tCO48sP4p3G54k3eddyojwidEEKHFlhCTWiSToQHc7QWR2pG/LMC2M4y3PdDI1WJaX+TuiFprFNU/KM8P4=', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.17.0.2', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.17.0.2:4566', 'LOCALSTACK_RUNTIME_ID': '6fa7dc5e1d7f1a9747d5cc391ec72a7e', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.17.0.2:4566/_localstack_lambda/6fa7dc5e1d7f1a9747d5cc391ec72a7e', '_HANDLER': 'role_createRole.lambda_handler', 'AWS_EXECUTION_ENV': 'Aws_Lambda_provided.al2', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'bridge', 'dns': '172.17.0.2', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} 2023-10-27 03:51:32 2023-10-26T19:51:32.214 DEBUG --- [ asgi_gw_0] localstack.packages.api : Installation of lambda-runtime skipped (already installed). 2023-10-27 03:51:32 2023-10-26T19:51:32.214 DEBUG --- [ asgi_gw_0] localstack.packages.api : Performing runtime setup for already installed package. 2023-10-27 03:51:32 2023-10-26T19:51:32.214 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.24-pre/arm64/. into localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e:/ 2023-10-27 03:51:32 2023-10-26T19:51:32.407 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-1-tasks/CreateRole-869c9126-6063-47fe-897c-12735f307eb3/code/. into localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e:/var/task 2023-10-27 03:51:32 2023-10-26T19:51:32.421 DEBUG --- [ asgi_gw_0] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e 2023-10-27 03:51:32 2023-10-26T19:51:32.554 DEBUG --- [ asgi_gw_0] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e in network bridge. 2023-10-27 03:51:42 2023-10-26T19:51:42.161 WARN --- [ Thread-14] l.s.l.i.execution_environm : Execution environment 6fa7dc5e1d7f1a9747d5cc391ec72a7e for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. 2023-10-27 03:51:42 2023-10-26T19:51:42.182 DEBUG --- [ Thread-14] l.s.l.i.execution_environm : Logs from the execution environment 6fa7dc5e1d7f1a9747d5cc391ec72a7e after startup timeout: 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Bootstrap not executable, setting permissions to 0755.../var/task/bootstrap" func=main.getBootstrap file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:85" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=warning msg="Error setting bootstrap to 0755 permissions: /var/task/bootstrapchmod /var/task/bootstrap: no such file or directory" func=main.getBootstrap file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:88" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:164" euid=0 gid=0 uid=0 username=root 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:169" euid=993 gid=990 uid=993 username=sbx_user1051 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Info] Initializing AWS X-Ray daemon unknown 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Debug] Listening on UDP 127.0.0.1:2000 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Info] Using buffer memory limit of 79 MB 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Info] 1264 segment buffers allocated 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Debug] Using Endpoint read from Config file: http://172.17.0.2:4566 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Debug] Using proxy address: 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Debug] Fetch region us-east-1 from commandline/config file 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Info] Using region: us-east-1 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.2:4566 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Debug] Using Endpoint: http://172.17.0.2:4566 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Debug] Batch size: 10 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-26T19:51:32Z [Info] Starting proxy http server on 127.0.0.1:2000 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Starting runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:232" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptInitRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:552" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:522" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Received RUNNING: {7221639071209 7221639215209 0 7221639071209 true 0x40001aed20}" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:510" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Awaiting initialization of runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:235" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=info msg="Configuring and starting Operator Domain" func=go.amzn.com/lambda/rapid.doOperatorDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:255" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=info msg="Starting runtime domain" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:302" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:162" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:24" error="open /opt/extensions: no such file or directory" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:102" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:329" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:349" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=warning msg="First fatal error stored in appctx: Runtime.InvalidEntrypoint" func=go.amzn.com/lambda/appctx.StoreFirstFatalError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/appctx/appctxutil.go:157" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=error msg="Init failed" func=go.amzn.com/lambda/rapid.handleInitError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/exit.go:109" InvokeID= error="fork/exec /var/task/bootstrap: no such file or directory" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=info msg="Error releasing after init failure InitDoneFailed: NotReserved" func="go.amzn.com/lambda/rapidcore.(*Server).AwaitInitialized" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:754" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] time="2023-10-26T19:51:32Z" level=error msg="Runtime init failed to initialize: InitDoneFailed. Exiting." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:238" 2023-10-27 03:51:42 [lambda 6fa7dc5e1d7f1a9747d5cc391ec72a7e] 2023-10-27 03:51:42 2023-10-26T19:51:42.182 DEBUG --- [ Thread-14] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e 2023-10-27 03:51:42 2023-10-26T19:51:42.192 DEBUG --- [ Thread-14] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-createrole-6fa7dc5e1d7f1a9747d5cc391ec72a7e 2023-10-27 03:51:42 2023-10-26T19:51:42.351 INFO --- [ asgi_gw_0] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException) 2023-10-27 03:51:43 2023-10-26T19:51:43.265 DEBUG --- [ asgi_gw_1] l.s.l.i.assignment : Starting new environment 2023-10-27 03:51:43 2023-10-26T19:51:43.265 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST executor 4c635695afb9f338c953de64198b0ee6 2023-10-27 03:51:43 2023-10-26T19:51:43.265 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST executor 4c635695afb9f338c953de64198b0ee6 2023-10-27 03:51:43 2023-10-26T19:51:43.266 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6 to executor 4c635695afb9f338c953de64198b0ee6 2023-10-27 03:51:43 2023-10-26T19:51:43.275 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/provided:al2', 'name': 'localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-1', 'AWS_REGION': 'us-east-1', 'AWS_LAMBDA_FUNCTION_NAME': 'CreateRole', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/CreateRole', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/10/26/[$LATEST]4c635695afb9f338c953de64198b0ee6', 'AWS_ACCESS_KEY_ID': 'ASIAQAAAAAAAACSIJ4Q2', 'AWS_SECRET_ACCESS_KEY': 'G75y8wwWnPSeqeYbapMoKaNHhCLFD1nk3AdhFLLJ', 'AWS_SESSION_TOKEN': 'FQoGZXIvYXdzEBYaDhOEgis1eHqApaMMJV7ARfbsYNH2Y6a7giR4c/gnVJO4kvLCjtemgFD+foso0KfIRKBdlViuJPWDShfQHsTedFaTiW0v89S9T2eDXnHjQPwHeSAFSzMPsV8PBYn+pHFODwYR03MhE0BkGWoMJTDmSopaH9ZDP3rxujQndEXVMP4566kOBs7eTGEb54YBu2x+yEcrZmjqeLDCBBvgLrAffd9IzRGcytJaDhuWfTJSC3JPKpsm6t5MAOl2bIxHfRbmrAsj5ofMNCIQg348qhd1dk4ujBTggAzKRnKkOgTBnYi+gqk9AuvoZskzv9urQppVpGyi+z2hkD64kXqzxOY=', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.17.0.2', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.17.0.2:4566', 'LOCALSTACK_RUNTIME_ID': '4c635695afb9f338c953de64198b0ee6', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.17.0.2:4566/_localstack_lambda/4c635695afb9f338c953de64198b0ee6', '_HANDLER': 'role_createRole.lambda_handler', 'AWS_EXECUTION_ENV': 'Aws_Lambda_provided.al2', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'bridge', 'dns': '172.17.0.2', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} 2023-10-27 03:51:43 2023-10-26T19:51:43.301 DEBUG --- [ asgi_gw_1] localstack.packages.api : Installation of lambda-runtime skipped (already installed). 2023-10-27 03:51:43 2023-10-26T19:51:43.301 DEBUG --- [ asgi_gw_1] localstack.packages.api : Performing runtime setup for already installed package. 2023-10-27 03:51:43 2023-10-26T19:51:43.302 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.24-pre/arm64/. into localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6:/ 2023-10-27 03:51:43 2023-10-26T19:51:43.417 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-1-tasks/CreateRole-869c9126-6063-47fe-897c-12735f307eb3/code/. into localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6:/var/task 2023-10-27 03:51:43 2023-10-26T19:51:43.435 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6 2023-10-27 03:51:43 2023-10-26T19:51:43.555 DEBUG --- [ asgi_gw_1] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6 in network bridge. 2023-10-27 03:51:53 2023-10-26T19:51:53.265 WARN --- [ Thread-16] l.s.l.i.execution_environm : Execution environment 4c635695afb9f338c953de64198b0ee6 for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. 2023-10-27 03:51:53 2023-10-26T19:51:53.283 DEBUG --- [ Thread-16] l.s.l.i.execution_environm : Logs from the execution environment 4c635695afb9f338c953de64198b0ee6 after startup timeout: 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Bootstrap not executable, setting permissions to 0755.../var/task/bootstrap" func=main.getBootstrap file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:85" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=warning msg="Error setting bootstrap to 0755 permissions: /var/task/bootstrapchmod /var/task/bootstrap: no such file or directory" func=main.getBootstrap file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:88" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:164" euid=0 gid=0 uid=0 username=root 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:169" euid=993 gid=990 uid=993 username=sbx_user1051 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Info] Initializing AWS X-Ray daemon unknown 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Debug] Listening on UDP 127.0.0.1:2000 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Info] Using buffer memory limit of 79 MB 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Info] 1264 segment buffers allocated 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Debug] Using Endpoint read from Config file: http://172.17.0.2:4566 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Debug] Using proxy address: 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Debug] Fetch region us-east-1 from commandline/config file 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Info] Using region: us-east-1 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.2:4566 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Debug] Using Endpoint: http://172.17.0.2:4566 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Debug] Batch size: 10 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-26T19:51:43Z [Info] Starting proxy http server on 127.0.0.1:2000 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Starting runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:232" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptInitRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:552" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:522" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Received RUNNING: {7232635602464 7232635739255 0 7232635602464 true 0x40003acd20}" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:510" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Awaiting initialization of runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:235" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:162" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=info msg="Configuring and starting Operator Domain" func=go.amzn.com/lambda/rapid.doOperatorDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:255" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=info msg="Starting runtime domain" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:302" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:24" error="open /opt/extensions: no such file or directory" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:329" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:349" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:102" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=warning msg="First fatal error stored in appctx: Runtime.InvalidEntrypoint" func=go.amzn.com/lambda/appctx.StoreFirstFatalError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/appctx/appctxutil.go:157" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=error msg="Init failed" func=go.amzn.com/lambda/rapid.handleInitError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/exit.go:109" InvokeID= error="fork/exec /var/task/bootstrap: no such file or directory" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=info msg="Error releasing after init failure InitDoneFailed: NotReserved" func="go.amzn.com/lambda/rapidcore.(*Server).AwaitInitialized" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:754" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] time="2023-10-26T19:51:43Z" level=error msg="Runtime init failed to initialize: InitDoneFailed. Exiting." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:238" 2023-10-27 03:51:53 [lambda 4c635695afb9f338c953de64198b0ee6] 2023-10-27 03:51:53 2023-10-26T19:51:53.283 DEBUG --- [ Thread-16] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6 2023-10-27 03:51:53 2023-10-26T19:51:53.292 DEBUG --- [ Thread-16] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-createrole-4c635695afb9f338c953de64198b0ee6 2023-10-27 03:51:53 2023-10-26T19:51:53.350 INFO --- [ asgi_gw_1] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException) 2023-10-27 03:51:54 2023-10-26T19:51:54.164 DEBUG --- [ asgi_gw_2] l.s.l.i.assignment : Starting new environment 2023-10-27 03:51:54 2023-10-26T19:51:54.165 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST executor 42d11a4c5ed6390e4ad8d1946fd550c2 2023-10-27 03:51:54 2023-10-26T19:51:54.165 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST executor 42d11a4c5ed6390e4ad8d1946fd550c2 2023-10-27 03:51:54 2023-10-26T19:51:54.165 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2 to executor 42d11a4c5ed6390e4ad8d1946fd550c2 2023-10-27 03:51:54 2023-10-26T19:51:54.181 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/provided:al2', 'name': 'localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-1', 'AWS_REGION': 'us-east-1', 'AWS_LAMBDA_FUNCTION_NAME': 'CreateRole', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/CreateRole', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/10/26/[$LATEST]42d11a4c5ed6390e4ad8d1946fd550c2', 'AWS_ACCESS_KEY_ID': 'ASIAQAAAAAAAB7VYLBNA', 'AWS_SECRET_ACCESS_KEY': 'n+iJy7i0YaClE5lVrb3WUFSHO15EtPnlQrd+Etl5', 'AWS_SESSION_TOKEN': 'FQoGZXIvYXdzEBYaDPoQlU1zQsSs3FWqU43+hy9DL8k7+ro7SLpGFdREGe4gqFV3I8iEcWXdlYEJxGdiJIfXFVrGDgdio/Q2zwT6WOtAVF6XhAnbOWluhQV6+5h94XGyOAcThZFbUN3sgRS+q1DXrpTNcZgUt5/Z7MHib1rFYleBUm01m+XgkVAieF9ue9vPcvfSq6B7XhnqMClowkhYtxeuJYDtcvu2INA+vLAJAXy1p7//hM0+x3wY6D0nX44KfQ50ItjChbFZsjtqhGwh5byv17mf1JeDDmR9OqSV1AD2hMtzf2Zh4O0v6iLSQACuTRneyPjYcdXuxCGg5/i0Va/Ja29kn4w5QI4=', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.17.0.2', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.17.0.2:4566', 'LOCALSTACK_RUNTIME_ID': '42d11a4c5ed6390e4ad8d1946fd550c2', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.17.0.2:4566/_localstack_lambda/42d11a4c5ed6390e4ad8d1946fd550c2', '_HANDLER': 'role_createRole.lambda_handler', 'AWS_EXECUTION_ENV': 'Aws_Lambda_provided.al2', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'bridge', 'dns': '172.17.0.2', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} 2023-10-27 03:51:54 2023-10-26T19:51:54.209 DEBUG --- [ asgi_gw_2] localstack.packages.api : Installation of lambda-runtime skipped (already installed). 2023-10-27 03:51:54 2023-10-26T19:51:54.209 DEBUG --- [ asgi_gw_2] localstack.packages.api : Performing runtime setup for already installed package. 2023-10-27 03:51:54 2023-10-26T19:51:54.210 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.24-pre/arm64/. into localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2:/ 2023-10-27 03:51:54 2023-10-26T19:51:54.348 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-1-tasks/CreateRole-869c9126-6063-47fe-897c-12735f307eb3/code/. into localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2:/var/task 2023-10-27 03:51:54 2023-10-26T19:51:54.373 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2 2023-10-27 03:51:54 2023-10-26T19:51:54.474 DEBUG --- [ asgi_gw_2] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2 in network bridge. 2023-10-27 03:52:04 2023-10-26T19:52:04.167 WARN --- [ Thread-18] l.s.l.i.execution_environm : Execution environment 42d11a4c5ed6390e4ad8d1946fd550c2 for function arn:aws:lambda:us-east-1:000000000000:function:CreateRole:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. 2023-10-27 03:52:04 2023-10-26T19:52:04.188 DEBUG --- [ Thread-18] l.s.l.i.execution_environm : Logs from the execution environment 42d11a4c5ed6390e4ad8d1946fd550c2 after startup timeout: 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Bootstrap not executable, setting permissions to 0755.../var/task/bootstrap" func=main.getBootstrap file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:85" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=warning msg="Error setting bootstrap to 0755 permissions: /var/task/bootstrapchmod /var/task/bootstrap: no such file or directory" func=main.getBootstrap file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:88" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:164" euid=0 gid=0 uid=0 username=root 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:169" euid=993 gid=990 uid=993 username=sbx_user1051 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Info] Initializing AWS X-Ray daemon unknown 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Debug] Listening on UDP 127.0.0.1:2000 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Info] Using buffer memory limit of 79 MB 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Info] 1264 segment buffers allocated 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Debug] Using Endpoint read from Config file: http://172.17.0.2:4566 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Debug] Using proxy address: 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Debug] Fetch region us-east-1 from commandline/config file 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Info] Using region: us-east-1 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.2:4566 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Debug] Using Endpoint: http://172.17.0.2:4566 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Debug] Batch size: 10 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-26T19:51:54Z [Info] Starting proxy http server on 127.0.0.1:2000 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Starting runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:232" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptInitRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:552" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:522" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:102" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:162" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Received RUNNING: {7243556039385 7243556190510 0 7243556039385 true 0x40004a4d20}" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:510" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Awaiting initialization of runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:235" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=info msg="Configuring and starting Operator Domain" func=go.amzn.com/lambda/rapid.doOperatorDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:255" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=info msg="Starting runtime domain" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:302" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:24" error="open /opt/extensions: no such file or directory" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:329" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:349" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=warning msg="First fatal error stored in appctx: Runtime.InvalidEntrypoint" func=go.amzn.com/lambda/appctx.StoreFirstFatalError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/appctx/appctxutil.go:157" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=error msg="Init failed" func=go.amzn.com/lambda/rapid.handleInitError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/exit.go:109" InvokeID= error="fork/exec /var/task/bootstrap: no such file or directory" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=info msg="Error releasing after init failure InitDoneFailed: NotReserved" func="go.amzn.com/lambda/rapidcore.(*Server).AwaitInitialized" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:754" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] time="2023-10-26T19:51:54Z" level=error msg="Runtime init failed to initialize: InitDoneFailed. Exiting." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:238" 2023-10-27 03:52:04 [lambda 42d11a4c5ed6390e4ad8d1946fd550c2] 2023-10-27 03:52:04 2023-10-26T19:52:04.188 DEBUG --- [ Thread-18] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2 2023-10-27 03:52:04 2023-10-26T19:52:04.198 DEBUG --- [ Thread-18] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-createrole-42d11a4c5ed6390e4ad8d1946fd550c2 2023-10-27 03:52:04 2023-10-26T19:52:04.263 INFO --- [ asgi_gw_2] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException)

[joe4dev]

Hi @shen-qin 👋

@shen-qin Can you quickly confirm whether you are working on the same issue/same team as @aryamohanan ?

---

@shen-qin The most recent logs indicate that there is some other issue with the Lambda image:

fork/exec /var/task/bootstrap: no such file    or directory

❓ Are you using some customized Lambda image that does not contain a bootstrap file?

❓ Can you share a minimal example to reproduce the issue? Feel free to link a Github repository with a minimal reproducer sample.

[shen-qin]

Hi @joe4dev,

Thank you for the prompt response, I am not on the same team as aryamohanan. I am using whatever lambda image that is out of the box, I did not make any modifications. Sure let me make 1 to demostrate.

[joe4dev]

Hi @joe4dev,

Thank you for the prompt response, I am not on the same team as aryamohanan. I am using whatever lambda image that is out of the box, I did not make any modifications. Sure let me make 1 to demostrate.

@shen-qin That would be very helpful. Thank you for the clarifications.

[wyilio]

Encountering the same issue of fork/exec /var/task/bootstrap: no such file or directory after setting PROVIDER_OVERRIDE_LAMBDA=legacy. Otherwise, setting it to v2 leads to timeout

Using a zipped bootstrap file implemented in Rust. On localstack version 1.4.0

**Resolved on version 2.3.2. Thanks @joe4dev

[joe4dev]

Encountering the same issue of fork/exec /var/task/bootstrap: no such file or directory after setting PROVIDER_OVERRIDE_LAMBDA=legacy. Otherwise, setting it to v2 leads to timeout

Using a zipped bootstrap file implemented in Rust. On localstack version 1.4.0

Hi @wyilio

Can you please try at least LocalStack version 2.3.2 or even better our latest RC for the upcoming 3.0 release this week? You can start LocalStack with DEBUG=1 to get more detailed log output. Feel free to share your logs or ideally a minimal example that reproduces the timeout.

FYI: The legacy Lambda provider is removed in LocalStack 3.0.

[sineto]

I'm having similar issues to those @aryamohanan is facing. I followed all the tips that @joe4dev gave. But without success so far.

My docker-compose.yml:

version: "3.8"

services:
  localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME-localstack_main}"
    image: localstack/localstack
    ports:
      - "127.0.0.1:4566:4566"            # LocalStack Gateway
      - "127.0.0.1:4510-4559:4510-4559"  # external services port range
    environment:
      - DEBUG=1
      - DOCKER_HOST=unix:///var/run/docker.sock
    volumes:
      - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack"
      - "/var/run/docker.sock:/var/run/docker.sock"

$ sudo chmod 666 /var/run/docker.sock

Steps To Reproduce

$ docker compose -f docker-compose.yml up localstack --build

Create the lambda function

$ aws --endpoint-url=http://localhost:4566 lambda create-function \
    --function-name test-go \
    --runtime go1.x \
    --zip-file fileb://lambda.zip \
    --handler lambda.main \
    --role arn:aws:iam::000000000000:role/test-go

Invoke function

$ aws --endpoint-url=http://localhost:4566 lambda invoke \
    --function-name test-go \
    --cli-binary-format raw-in-base64-out \
    --payload '{"body": "{\"num1\": \"10\", \"num2\": \"10\"}" }' output.txt

My lamba.zip:

package main

import (
    "errors"
    "fmt"

    "github.com/aws/aws-lambda-go/events"
    "github.com/aws/aws-lambda-go/lambda"
)

func handler(request events.APIGatewayProxyRequest) (events.APIGatewayProxyResponse, error) {
    return events.APIGatewayProxyResponse{
        Body:       fmt.Sprintf("Hello, %v", "World"),
        StatusCode: 200,
    }, nil
}

func main() {
    lambda.Start(handler)
}

My environment:

$ uname -a
Linux user 6.1.XX-X-MANJARO #1 ... x86_64 GNU/Linux

$ localstack --version
2.3.0

$ aws --version
aws-cli/2.13.33 Python/3.11.5 Linux/6.1.62-1-MANJARO source/x86_64.manjaro.23 prompt/off

Lambda creation response

{
    "FunctionName": "test-go",
    "FunctionArn": "arn:aws:lambda:us-east-1:000000000000:function:test-go",
    "Runtime": "go1.x",
    "Role": "arn:aws:iam::000000000000:role/test-go",
    "Handler": "lambda.main",
    "CodeSize": 164,
    "Description": "",
    "Timeout": 3,
    "MemorySize": 128,
    "LastModified": "2023-11-21T22:05:15.438170+0000",
    "CodeSha256": "Usj+xGrrL7m2IWJseME1/l/7ivUl2WRaSxc0t7Q4MhQ=",
    "Version": "$LATEST",
    "TracingConfig": {
        "Mode": "PassThrough"
    },
    "RevisionId": "0c2e932b-b3b2-4013-bedf-efdb9be91c88",
    "State": "Pending",
    "StateReason": "The function is being created.",
    "StateReasonCode": "Creating",
    "PackageType": "Zip",
    "Architectures": [
        "x86_64"
    ],
    "EphemeralStorage": {
        "Size": 512
    },
    "SnapStart": {
        "ApplyOn": "None",
        "OptimizationStatus": "Off"
    },
    "RuntimeVersionConfig": {
        "RuntimeVersionArn": "arn:aws:lambda:us-east-1::runtime:8eeff65f6809a3ce81507fe733fe09b835899b99481ba22fd75b5a7338290ec1"
    }
}

DEBUG log

Details

``` Attaching to localstack_main localstack_main | LocalStack supervisor: starting localstack_main | LocalStack supervisor: localstack process (PID 15) starting localstack_main | localstack_main | LocalStack version: 3.0.1.dev localstack_main | LocalStack build date: 2023-11-21 localstack_main | LocalStack build git hash: f354fd43 localstack_main | localstack_main | 2023-11-21T22:00:28.711 DEBUG --- [ MainThread] stevedore._cache : reading /root/.cache/python-entrypoints/34d3c11768fc3a8d98b3943afb64d7b0b3abb3186ed714ff524e4736c2519853 localstack_main | 2023-11-21T22:00:28.716 DEBUG --- [ MainThread] stevedore._cache : writing to /root/.cache/python-entrypoints/34d3c11768fc3a8d98b3943afb64d7b0b3abb3186ed714ff524e4736c2519853 localstack_main | 2023-11-21T22:00:28.717 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_patch_botocore_json_parser', value='localstack.aws.client:_patch_botocore_json_parser', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.718 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_publish_config_as_analytics_event', value='localstack.runtime.analytics:_publish_config_as_analytics_event', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.718 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_publish_container_info', value='localstack.runtime.analytics:_publish_container_info', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.718 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_run_init_scripts_on_start', value='localstack.runtime.init:_run_init_scripts_on_start', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.719 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='deprecation_warnings', value='localstack.plugins:deprecation_warnings', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.719 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_partition_adjusting_proxy_listener', value='localstack.plugins:register_partition_adjusting_proxy_listener', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.719 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='setup_dns_configuration_on_host', value='localstack.dns.plugins:setup_dns_configuration_on_host', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.720 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='start_dns_server', value='localstack.dns.plugins:start_dns_server', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.720 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='validate_configuration', value='localstack.services.lambda_.plugins:validate_configuration', group='localstack.hooks.on_infra_start') localstack_main | 2023-11-21T22:00:28.721 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._patch_botocore_json_parser = ) localstack_main | 2023-11-21T22:00:28.721 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_patch_botocore_json_parser localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._publish_config_as_analytics_event = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_publish_config_as_analytics_event localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._publish_container_info = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_publish_container_info localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start._run_init_scripts_on_start = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:_run_init_scripts_on_start localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.deprecation_warnings = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:deprecation_warnings localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.register_partition_adjusting_proxy_listener = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_start:register_partition_adjusting_proxy_listener is disabled localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.setup_dns_configuration_on_host = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:setup_dns_configuration_on_host localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.start_dns_server = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:start_dns_server localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_start.validate_configuration = ) localstack_main | 2023-11-21T22:00:28.722 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_start:validate_configuration localstack_main | 2023-11-21T22:00:28.869 DEBUG --- [ MainThread] localstack.dns.server : Determined fallback dns: 127.0.0.11 localstack_main | 2023-11-21T22:00:28.869 DEBUG --- [ MainThread] localstack.dns.server : Starting DNS servers (tcp/udp port 53 on 0.0.0.0)... localstack_main | 2023-11-21T22:00:28.870 DEBUG --- [ MainThread] localstack.dns.server : Adding host .*localhost.localstack.cloud pointing to LocalStack localstack_main | 2023-11-21T22:00:28.870 DEBUG --- [ MainThread] localstack.dns.server : Adding host .*localhost.localstack.cloud with record DynamicRecord(record_type=, record_id=None) localstack_main | 2023-11-21T22:00:28.870 DEBUG --- [ MainThread] localstack.dns.server : Adding host .*localhost.localstack.cloud with record DynamicRecord(record_type=, record_id=None) localstack_main | 2023-11-21T22:00:28.871 DEBUG --- [-functhread1] localstack.dns.server : DNS Server started localstack_main | 2023-11-21T22:00:29.876 DEBUG --- [ MainThread] localstack.dns.server : DNS server startup finished. localstack_main | 2023-11-21T22:00:29.877 DEBUG --- [ MainThread] localstack.runtime.init : Init scripts discovered: {BOOT: [], START: [], READY: [], SHUTDOWN: []} localstack_main | 2023-11-21T22:00:29.877 DEBUG --- [ MainThread] localstack.plugins : Checking for the usage of deprecated community features and configs... localstack_main | 2023-11-21T22:00:29.878 DEBUG --- [ MainThread] localstack.dns.server : Overwriting container DNS server to point to localhost localstack_main | 2023-11-21T22:00:29.887 DEBUG --- [ MainThread] localstack.utils.threads : start_thread called without providing a custom name localstack_main | 2023-11-21T22:00:29.889 DEBUG --- [-functhread3] localstack.utils.run : Executing command: whoami localstack_main | 2023-11-21T22:00:30.043 WARN --- [-functhread3] l.services.internal : Enabling diagnose endpoint, please be aware that this can expose sensitive information via your network. localstack_main | 2023-11-21T22:00:30.047 DEBUG --- [-functhread3] localstack.utils.ssl : Using cached SSL certificate (less than 6hrs since last update). localstack_main | 2023-11-21T22:00:30.050 INFO --- [-functhread4] hypercorn.error : Running on https://0.0.0.0:4566 (CTRL + C to quit) localstack_main | 2023-11-21T22:00:30.050 INFO --- [-functhread4] hypercorn.error : Running on https://0.0.0.0:4566 (CTRL + C to quit) localstack_main | 2023-11-21T22:00:30.189 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='acm:default', value='localstack.services.providers:acm', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='apigateway:default', value='localstack.services.providers:apigateway', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='cloudformation:default', value='localstack.services.providers:cloudformation', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='cloudwatch:default', value='localstack.services.providers:cloudwatch', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='config:default', value='localstack.services.providers:awsconfig', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='dynamodb:default', value='localstack.services.providers:dynamodb', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='dynamodbstreams:default', value='localstack.services.providers:dynamodbstreams', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ec2:default', value='localstack.services.providers:ec2', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='es:default', value='localstack.services.providers:es', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='events:default', value='localstack.services.providers:events', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='firehose:default', value='localstack.services.providers:firehose', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='iam:default', value='localstack.services.providers:iam', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='kinesis:default', value='localstack.services.providers:kinesis', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='kms:default', value='localstack.services.providers:kms', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:asf', value='localstack.services.providers:lambda_asf', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:default', value='localstack.services.providers:lambda_', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='lambda:v2', value='localstack.services.providers:lambda_v2', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='logs:default', value='localstack.services.providers:logs', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='opensearch:default', value='localstack.services.providers:opensearch', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='redshift:default', value='localstack.services.providers:redshift', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='resource-groups:default', value='localstack.services.providers:resource_groups', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='resourcegroupstaggingapi:default', value='localstack.services.providers:resourcegroupstaggingapi', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='route53:default', value='localstack.services.providers:route53', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='route53resolver:default', value='localstack.services.providers:route53resolver', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:asf', value='localstack.services.providers:s3_asf', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.193 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:default', value='localstack.services.providers:s3', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:legacy_v2', value='localstack.services.providers:s3_legacy_v2', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:stream', value='localstack.services.providers:s3_stream', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:v2', value='localstack.services.providers:s3_v2', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3:v3', value='localstack.services.providers:s3_v3', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='s3control:default', value='localstack.services.providers:s3control', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='scheduler:default', value='localstack.services.providers:scheduler', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='secretsmanager:default', value='localstack.services.providers:secretsmanager', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ses:default', value='localstack.services.providers:ses', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sns:default', value='localstack.services.providers:sns', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sqs-query:default', value='localstack.services.providers:sqs_query', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sqs:default', value='localstack.services.providers:sqs', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='ssm:default', value='localstack.services.providers:ssm', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:default', value='localstack.services.providers:stepfunctions', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:legacy', value='localstack.services.providers:stepfunctions_v1', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:v1', value='localstack.services.providers:stepfunctions_legacy', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='stepfunctions:v2', value='localstack.services.providers:stepfunctions_v2', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='sts:default', value='localstack.services.providers:sts', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='support:default', value='localstack.services.providers:support', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='swf:default', value='localstack.services.providers:swf', group='localstack.aws.provider') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='transcribe:default', value='localstack.services.providers:transcribe', group='localstack.aws.provider') localstack_main | Ready. localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='_run_init_scripts_on_ready', value='localstack.runtime.init:_run_init_scripts_on_ready', group='localstack.hooks.on_infra_ready') localstack_main | 2023-11-21T22:00:30.194 DEBUG --- [ MainThread] stevedore.extension : found extension EntryPoint(name='register_virtual_host_routes', value='localstack.services.s3.virtual_host:register_virtual_host_routes', group='localstack.hooks.on_infra_ready') localstack_main | 2023-11-21T22:00:30.195 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_ready._run_init_scripts_on_ready = ) localstack_main | 2023-11-21T22:00:30.195 DEBUG --- [ MainThread] plugin.manager : loading plugin localstack.hooks.on_infra_ready:_run_init_scripts_on_ready localstack_main | 2023-11-21T22:00:30.195 DEBUG --- [ MainThread] plugin.manager : instantiating plugin PluginSpec(localstack.hooks.on_infra_ready.register_virtual_host_routes = ) localstack_main | 2023-11-21T22:00:30.195 DEBUG --- [ MainThread] plugin.manager : plugin localstack.hooks.on_infra_ready:register_virtual_host_routes is disabled localstack_main | 2023-11-21T22:00:38.588 DEBUG --- [ asgi_gw_0] l.a.p.service_router : loading service catalog index cache file /var/lib/localstack/cache/service-catalog-3_0_1_dev-1_31_85.pickle localstack_main | 2023-11-21T22:05:14.793 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.lambda:default = ) localstack_main | 2023-11-21T22:05:14.793 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.aws.provider:lambda:default localstack_main | 2023-11-21T22:05:14.910 DEBUG --- [ asgi_gw_0] plugin.manager : no extensions found in namespace localstack.hooks.lambda_inject_layer_fetcher localstack_main | 2023-11-21T22:05:14.930 DEBUG --- [ asgi_gw_0] l.s.lambda_.urlrouter : Registering parameterized Lambda routes. localstack_main | 2023-11-21T22:05:14.931 DEBUG --- [ asgi_gw_0] stevedore.extension : found extension EntryPoint(name='docker', value='localstack.services.lambda_.invocation.plugins:DockerRuntimeExecutorPlugin', group='localstack.lambda.runtime_executor') localstack_main | 2023-11-21T22:05:14.932 DEBUG --- [ asgi_gw_0] plugin.manager : instantiating plugin PluginSpec(localstack.lambda.runtime_executor.docker = ) localstack_main | 2023-11-21T22:05:14.932 DEBUG --- [ asgi_gw_0] plugin.manager : loading plugin localstack.lambda.runtime_executor:docker localstack_main | 2023-11-21T22:05:15.030 DEBUG --- [ asgi_gw_1] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.sts:default = ) localstack_main | 2023-11-21T22:05:15.030 DEBUG --- [ asgi_gw_1] plugin.manager : loading plugin localstack.aws.provider:sts:default localstack_main | 2023-11-21T22:05:15.323 DEBUG --- [ asgi_gw_1] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.s3:default = ) localstack_main | 2023-11-21T22:05:15.323 DEBUG --- [ asgi_gw_1] plugin.manager : loading plugin localstack.aws.provider:s3:default localstack_main | 2023-11-21T22:05:15.440 INFO --- [ asgi_gw_0] localstack.request.aws : AWS lambda.CreateFunction => 201 localstack_main | 2023-11-21T22:05:15.440 DEBUG --- [rvice-task_0] plugin.manager : no extensions found in namespace localstack.hooks.lambda_prepare_docker_executors localstack_main | 2023-11-21T22:05:15.440 DEBUG --- [rvice-task_0] l.s.l.i.lambda_models : Saving code test-go-d7ccc3e4-fa51-48ee-85a5-0cd436df8765 to disk localstack_main | 2023-11-21T22:05:15.561 DEBUG --- [rvice-task_0] localstack.utils.run : Executing command: ['unzip', '-o', '-q', '/tmp/tmpppdzt4pw'] localstack_main | 2023-11-21T22:05:15.562 DEBUG --- [rvice-task_0] l.u.c.docker_sdk_client : Pulling Docker image: public.ecr.aws/lambda/go:1 localstack_main | 2023-11-21T22:05:17.199 DEBUG --- [rvice-task_0] l.s.l.i.version_manager : Version preparation of function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST took 1759.08ms localstack_main | 2023-11-21T22:05:17.199 DEBUG --- [rvice-task_0] l.s.l.i.version_manager : Changing Lambda arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST (id a2938bae) to active localstack_main | 2023-11-21T22:05:17.199 DEBUG --- [rvice-task_0] l.s.l.i.event_manager : Starting event manager arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST id 140299853702352 localstack_main | 2023-11-21T22:05:17.209 DEBUG --- [ asgi_gw_1] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.sqs:default = ) localstack_main | 2023-11-21T22:05:17.209 DEBUG --- [ asgi_gw_1] plugin.manager : loading plugin localstack.aws.provider:sqs:default localstack_main | 2023-11-21T22:05:17.285 DEBUG --- [ asgi_gw_1] l.services.sqs.provider : creating queue key=test-go-c62ed795ceedf07b5c5bdaaed8552243 attributes=None tags=None localstack_main | 2023-11-21T22:05:19.315 DEBUG --- [ asgi_gw_1] plugin.manager : instantiating plugin PluginSpec(localstack.aws.provider.cloudwatch:default = ) localstack_main | 2023-11-21T22:05:19.315 DEBUG --- [ asgi_gw_1] plugin.manager : loading plugin localstack.aws.provider:cloudwatch:default localstack_main | 2023-11-21T22:05:19.320 DEBUG --- [ asgi_gw_1] l.s.cloudwatch.provider : starting cloudwatch scheduler localstack_main | 2023-11-21T22:07:31.667 DEBUG --- [ asgi_gw_1] l.s.l.i.assignment : Starting new environment localstack_main | 2023-11-21T22:07:31.667 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST executor 27a84ff58599dd7de50af78bcf14702f localstack_main | 2023-11-21T22:07:31.667 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST executor 27a84ff58599dd7de50af78bcf14702f localstack_main | 2023-11-21T22:07:31.667 DEBUG --- [ asgi_gw_1] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f to executor 27a84ff58599dd7de50af78bcf14702f localstack_main | 2023-11-21T22:07:31.673 DEBUG --- [ asgi_gw_1] l.u.c.container_client : Getting networks for container: localstack-main localstack_main | 2023-11-21T22:07:31.674 INFO --- [ asgi_gw_1] l.u.container_networking : Unable to get network name of main container "localstack-main", falling back to "bridge": localstack-main localstack_main | 2023-11-21T22:07:31.674 INFO --- [ asgi_gw_1] l.u.container_networking : Determined main container network: bridge localstack_main | 2023-11-21T22:07:31.674 DEBUG --- [ asgi_gw_1] l.u.c.container_client : Getting ipv4 address for container localstack-main in network bridge. localstack_main | 2023-11-21T22:07:31.675 INFO --- [ asgi_gw_1] l.u.container_networking : Unable to get main container IP address: localstack-main localstack_main | 2023-11-21T22:07:31.713 DEBUG --- [ asgi_gw_1] plugin.manager : no extensions found in namespace localstack.hooks.lambda_start_docker_executor localstack_main | 2023-11-21T22:07:31.713 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/go:1', 'name': 'localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-1', 'AWS_REGION': 'us-east-1', 'AWS_LAMBDA_FUNCTION_NAME': 'test-go', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/test-go', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/11/21/[$LATEST]27a84ff58599dd7de50af78bcf14702f', 'AWS_ACCESS_KEY_ID': 'ASIAQAAAAAAAILZUDGO5', 'AWS_SECRET_ACCESS_KEY': 'JnsSIF7MAplhHNOTPD6Q5RElFH5q8pi7B+wn7759', 'AWS_SESSION_TOKEN': 'FQoGZXIvYXdzEBYaDMAsxXSDp7nCNgFvG1yGXHe/ZzQhPx4GMFYzeUsTlZJACU+QE2vjl/nzsvstK0xr9+WNbsBCR/c/N/ejCZoZ2wpGywHGKIKYSncU1TNpngzJRY8A4EMtbz0zqonS/RrV/rB/+tAm4BkxsJHOF1RCdlZTFBWZRsQkVuL2woCk94Lkf97oV2YqXvsx2iRTUKcXnYJB0zFk+3MPwAi1jyhSCUFOR/2ld8csH7vPap4+dBi67N4YzhilhHMB9J9jK71pD89kzoGpDr4KCKayGXuFy9LcsS9RiA7TY8GbooKzdf2x2gXJEW+UO0MdQGAbVOyTWmwf/6G0M/TtAN9tGgo=', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.17.0.1', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.17.0.1:4566', 'LOCALSTACK_RUNTIME_ID': '27a84ff58599dd7de50af78bcf14702f', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.17.0.1:4566/_localstack_lambda/27a84ff58599dd7de50af78bcf14702f', '_HANDLER': 'lambda.main', 'AWS_EXECUTION_ENV': 'Aws_Lambda_go1.x', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'bridge', 'dns': '172.17.0.1', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} localstack_main | 2023-11-21T22:07:31.764 DEBUG --- [ asgi_gw_1] localstack.packages.api : Installation of lambda-runtime skipped (already installed). localstack_main | 2023-11-21T22:07:31.764 DEBUG --- [ asgi_gw_1] localstack.packages.api : Performing runtime setup for already installed package. localstack_main | 2023-11-21T22:07:31.764 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.24-pre/x86_64/. into localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f:/ localstack_main | 2023-11-21T22:07:31.812 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-1-tasks/test-go-d7ccc3e4-fa51-48ee-85a5-0cd436df8765/code/. into localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f:/var/task localstack_main | 2023-11-21T22:07:31.821 DEBUG --- [ asgi_gw_1] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f localstack_main | 2023-11-21T22:07:32.027 DEBUG --- [ asgi_gw_1] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f in network bridge. localstack_main | 2023-11-21T22:07:41.667 WARN --- [ Thread-52] l.s.l.i.execution_environm : Execution environment 27a84ff58599dd7de50af78bcf14702f for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. localstack_main | 2023-11-21T22:07:41.670 DEBUG --- [ Thread-52] l.s.l.i.execution_environm : Logs from the execution environment 27a84ff58599dd7de50af78bcf14702f after startup timeout: localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:164" euid=0 gid=0 uid=0 username=root localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:169" euid=993 gid=990 uid=993 username=sbx_user1051 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Info] Initializing AWS X-Ray daemon unknown localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Debug] Listening on UDP 127.0.0.1:2000 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Info] Using buffer memory limit of 138 MB localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Info] 2208 segment buffers allocated localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Debug] Using Endpoint read from Config file: http://172.17.0.1:4566 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Debug] Using proxy address: localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Debug] Fetch region us-east-1 from commandline/config file localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Info] Using region: us-east-1 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.1:4566 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Debug] Using Endpoint: http://172.17.0.1:4566 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Debug] Batch size: 10 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] 2023-11-21T22:07:32Z [Info] Starting proxy http server on 127.0.0.1:2000 localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Starting runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:232" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:102" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptInitRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:552" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:522" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=info msg="Configuring and starting Operator Domain" func=go.amzn.com/lambda/rapid.doOperatorDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:255" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=info msg="Starting runtime domain" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:302" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Received RUNNING: {33622078650147 33622079442566 0 33622078650147 true 0xc00008ee40}" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:510" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:24" error="open /opt/extensions: no such file or directory" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Awaiting initialization of runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:235" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:329" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:349" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:162" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[AWS_Lambda_Cpp/0.2.6]]" func=go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/middleware/middleware.go:76" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[AWS_Lambda_Cpp/0.2.6]]" func=go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/middleware/middleware.go:76" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] time="2023-11-21T22:07:32Z" level=debug msg="Completed initialization of runtime init. Sending status ready to LocalStack." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:244" localstack_main | [lambda 27a84ff58599dd7de50af78bcf14702f] localstack_main | 2023-11-21T22:07:41.670 DEBUG --- [ Thread-52] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f localstack_main | 2023-11-21T22:07:46.957 DEBUG --- [ Thread-52] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-test-go-27a84ff58599dd7de50af78bcf14702f localstack_main | 2023-11-21T22:07:46.993 INFO --- [ asgi_gw_1] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException) localstack_main | 2023-11-21T22:07:47.593 DEBUG --- [ asgi_gw_2] l.s.l.i.assignment : Starting new environment localstack_main | 2023-11-21T22:07:47.593 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST executor bae1233bf183d7018c790862ca2b9baf localstack_main | 2023-11-21T22:07:47.593 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST executor bae1233bf183d7018c790862ca2b9baf localstack_main | 2023-11-21T22:07:47.593 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf to executor bae1233bf183d7018c790862ca2b9baf localstack_main | 2023-11-21T22:07:47.603 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/go:1', 'name': 'localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-1', 'AWS_REGION': 'us-east-1', 'AWS_LAMBDA_FUNCTION_NAME': 'test-go', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/test-go', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/11/21/[$LATEST]bae1233bf183d7018c790862ca2b9baf', 'AWS_ACCESS_KEY_ID': 'ASIAQAAAAAAAAH6XI5SB', 'AWS_SECRET_ACCESS_KEY': 'ZDqwZH5ZpbCyif64Z3F99U8ofy0Hv6bM3M+FEWfL', 'AWS_SESSION_TOKEN': 'FQoGZXIvYXdzEBYaDHGDnHakH4CkkIZwZHNarQdastBne0MG40Df0i4uc+Qc0mpq8P4tEAZ2gYBKajTefxANCiWskKtfbB2Vwu6K1445umhfnNTDlDb/+0iS+SSs9zOja5cYRJ8tXI+cJsbyj8oKpgl0rwU2DHO/sMYYBkZlm3+7HjxZHQYKE+yRH9Ha8TwI0+92GA7gzuyY7QJhe1Qi+brJnsKs4Ev6TYZ4u5IxSVzBWMHoSz2Yg8e6ZdUWsAA2E8eOITMAxvzpBV67nVGVKs4sJvfvNeeZX7tOOolVOsWvN+z8lQkDyQl3Y5hx+i8yULM8iPc5M9nWOoQaA46MacU4s5NQPKM6Onw=', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.17.0.1', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.17.0.1:4566', 'LOCALSTACK_RUNTIME_ID': 'bae1233bf183d7018c790862ca2b9baf', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.17.0.1:4566/_localstack_lambda/bae1233bf183d7018c790862ca2b9baf', '_HANDLER': 'lambda.main', 'AWS_EXECUTION_ENV': 'Aws_Lambda_go1.x', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'bridge', 'dns': '172.17.0.1', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} localstack_main | 2023-11-21T22:07:47.619 DEBUG --- [ asgi_gw_2] localstack.packages.api : Installation of lambda-runtime skipped (already installed). localstack_main | 2023-11-21T22:07:47.619 DEBUG --- [ asgi_gw_2] localstack.packages.api : Performing runtime setup for already installed package. localstack_main | 2023-11-21T22:07:47.619 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.24-pre/x86_64/. into localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf:/ localstack_main | 2023-11-21T22:07:47.662 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-1-tasks/test-go-d7ccc3e4-fa51-48ee-85a5-0cd436df8765/code/. into localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf:/var/task localstack_main | 2023-11-21T22:07:47.669 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf localstack_main | 2023-11-21T22:07:47.892 DEBUG --- [ asgi_gw_2] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf in network bridge. localstack_main | 2023-11-21T22:07:57.594 WARN --- [ Thread-58] l.s.l.i.execution_environm : Execution environment bae1233bf183d7018c790862ca2b9baf for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. localstack_main | 2023-11-21T22:07:57.597 DEBUG --- [ Thread-58] l.s.l.i.execution_environm : Logs from the execution environment bae1233bf183d7018c790862ca2b9baf after startup timeout: localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:164" euid=0 gid=0 uid=0 username=root localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:169" euid=993 gid=990 uid=993 username=sbx_user1051 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Info] Initializing AWS X-Ray daemon unknown localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Debug] Listening on UDP 127.0.0.1:2000 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Info] Using buffer memory limit of 138 MB localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Info] 2208 segment buffers allocated localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Debug] Using Endpoint read from Config file: http://172.17.0.1:4566 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Debug] Using proxy address: localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Debug] Fetch region us-east-1 from commandline/config file localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Info] Using region: us-east-1 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.1:4566 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Debug] Using Endpoint: http://172.17.0.1:4566 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Debug] Batch size: 10 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] 2023-11-21T22:07:47Z [Info] Starting proxy http server on 127.0.0.1:2000 localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Starting runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:232" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptInitRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:552" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:102" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:522" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=info msg="Configuring and starting Operator Domain" func=go.amzn.com/lambda/rapid.doOperatorDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:255" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=info msg="Starting runtime domain" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:302" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:24" error="open /opt/extensions: no such file or directory" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:329" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:162" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:349" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Received RUNNING: {33637942695276 33637943669352 0 33637942695276 true 0xc0005a8240}" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:510" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Awaiting initialization of runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:235" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[AWS_Lambda_Cpp/0.2.6]]" func=go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/middleware/middleware.go:76" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[AWS_Lambda_Cpp/0.2.6]]" func=go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/middleware/middleware.go:76" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] time="2023-11-21T22:07:47Z" level=debug msg="Completed initialization of runtime init. Sending status ready to LocalStack." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:244" localstack_main | [lambda bae1233bf183d7018c790862ca2b9baf] localstack_main | 2023-11-21T22:07:57.597 DEBUG --- [ Thread-58] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf localstack_main | 2023-11-21T22:08:02.920 DEBUG --- [ Thread-58] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-test-go-bae1233bf183d7018c790862ca2b9baf localstack_main | 2023-11-21T22:08:02.955 INFO --- [ asgi_gw_2] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException) localstack_main | 2023-11-21T22:08:03.892 DEBUG --- [ asgi_gw_2] l.s.l.i.assignment : Starting new environment localstack_main | 2023-11-21T22:08:03.892 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST executor b579db6d67f53cd7c2282ecdd9666842 localstack_main | 2023-11-21T22:08:03.892 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Finished creating service endpoint for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST executor b579db6d67f53cd7c2282ecdd9666842 localstack_main | 2023-11-21T22:08:03.892 DEBUG --- [ asgi_gw_2] l.s.l.i.docker_runtime_exe : Assigning container name of localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842 to executor b579db6d67f53cd7c2282ecdd9666842 localstack_main | 2023-11-21T22:08:03.900 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Creating container with attributes: {'self': , 'image_name': 'public.ecr.aws/lambda/go:1', 'name': 'localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842', 'entrypoint': '/var/rapid/init', 'remove': False, 'interactive': False, 'tty': False, 'detach': False, 'command': None, 'mount_volumes': [], 'ports': , 'exposed_ports': [], 'env_vars': {'AWS_DEFAULT_REGION': 'us-east-1', 'AWS_REGION': 'us-east-1', 'AWS_LAMBDA_FUNCTION_NAME': 'test-go', 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE': 128, 'AWS_LAMBDA_FUNCTION_VERSION': '$LATEST', 'AWS_LAMBDA_INITIALIZATION_TYPE': 'on-demand', 'AWS_LAMBDA_LOG_GROUP_NAME': '/aws/lambda/test-go', 'AWS_LAMBDA_LOG_STREAM_NAME': '2023/11/21/[$LATEST]b579db6d67f53cd7c2282ecdd9666842', 'AWS_ACCESS_KEY_ID': 'ASIAQAAAAAAAMYZYTLNL', 'AWS_SECRET_ACCESS_KEY': 'LW7WbOGqvxmb3OQZaRrt7z8S2l6THxvm3H+uLSws', 'AWS_SESSION_TOKEN': 'FQoGZXIvYXdzEBYaDTaXv3wvvmHYD4UaHH70dHeT/HCh434OtjKZFDRHuvaOj1osKolejRlqGmTJnFcTYhLrq2LdcTkmgUy7eugDffGi5eexw4cnmF2saJnw9+OdANnncmOLNGoH47VIGle27KIqbrlL7eaS80teR6CUrDBDeqQM83gnG/+lXHYXgFOQgvojvxmlHlXzvvi37TNS1AqFyltfAtNARoP0jbtnYukcDiuNLv8zUOmG5Vq2rJ1C4xlsedYzQuoh8sWUDdtfi1nMTddJboOXtVtXQswrX1NivlgY+3hOeno5F5Il5Z8h6Dpi2MYGuEREELxooXWFsiedwR7LjbVjTb0s/1M=', 'LAMBDA_TASK_ROOT': '/var/task', 'LAMBDA_RUNTIME_DIR': '/var/runtime', 'AWS_XRAY_CONTEXT_MISSING': 'LOG_ERROR', 'AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1:2000', '_AWS_XRAY_DAEMON_PORT': '2000', '_AWS_XRAY_DAEMON_ADDRESS': '127.0.0.1', 'TZ': ':UTC', 'AWS_LAMBDA_FUNCTION_TIMEOUT': 3, 'LOCALSTACK_HOSTNAME': '172.17.0.1', 'EDGE_PORT': '4566', 'AWS_ENDPOINT_URL': 'http://172.17.0.1:4566', 'LOCALSTACK_RUNTIME_ID': 'b579db6d67f53cd7c2282ecdd9666842', 'LOCALSTACK_RUNTIME_ENDPOINT': 'http://172.17.0.1:4566/_localstack_lambda/b579db6d67f53cd7c2282ecdd9666842', '_HANDLER': 'lambda.main', 'AWS_EXECUTION_ENV': 'Aws_Lambda_go1.x', 'LOCALSTACK_INIT_LOG_LEVEL': 'debug'}, 'user': None, 'cap_add': None, 'cap_drop': None, 'security_opt': None, 'network': 'bridge', 'dns': '172.17.0.1', 'additional_flags': '', 'workdir': None, 'privileged': False, 'labels': None, 'platform': 'linux/amd64', 'ulimits': None} localstack_main | 2023-11-21T22:08:03.916 DEBUG --- [ asgi_gw_2] localstack.packages.api : Installation of lambda-runtime skipped (already installed). localstack_main | 2023-11-21T22:08:03.916 DEBUG --- [ asgi_gw_2] localstack.packages.api : Performing runtime setup for already installed package. localstack_main | 2023-11-21T22:08:03.916 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Copying file /usr/lib/localstack/lambda-runtime/v0.1.24-pre/x86_64/. into localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842:/ localstack_main | 2023-11-21T22:08:03.954 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Copying file /tmp/lambda/awslambda-us-east-1-tasks/test-go-d7ccc3e4-fa51-48ee-85a5-0cd436df8765/code/. into localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842:/var/task localstack_main | 2023-11-21T22:08:03.963 DEBUG --- [ asgi_gw_2] l.u.c.docker_sdk_client : Starting container localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842 localstack_main | 2023-11-21T22:08:04.193 DEBUG --- [ asgi_gw_2] l.u.c.container_client : Getting ipv4 address for container localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842 in network bridge. localstack_main | 2023-11-21T22:08:13.892 WARN --- [ Thread-62] l.s.l.i.execution_environm : Execution environment b579db6d67f53cd7c2282ecdd9666842 for function arn:aws:lambda:us-east-1:000000000000:function:test-go:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT. localstack_main | 2023-11-21T22:08:13.895 DEBUG --- [ Thread-62] l.s.l.i.execution_environm : Logs from the execution environment b579db6d67f53cd7c2282ecdd9666842 after startup timeout: localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Process running as root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:164" euid=0 gid=0 uid=0 username=root localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Process running as non-root user." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:169" euid=993 gid=990 uid=993 username=sbx_user1051 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Info] Initializing AWS X-Ray daemon unknown localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Debug] Listening on UDP 127.0.0.1:2000 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Info] Using buffer memory limit of 138 MB localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Info] 2208 segment buffers allocated localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Debug] Using Endpoint read from Config file: http://172.17.0.1:4566 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Debug] Using proxy address: localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Debug] Fetch region us-east-1 from commandline/config file localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Info] Using region: us-east-1 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.17.0.1:4566 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Debug] Using Endpoint: http://172.17.0.1:4566 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Debug] Batch size: 10 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] 2023-11-21T22:08:04Z [Info] Starting proxy http server on 127.0.0.1:2000 localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Starting runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:232" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=info msg="Configure environment for Init Caching." func="go.amzn.com/lambda/rapid.(*rapidContext).acceptInitRequestForInitCaching" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:552" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=info msg="extensionsDisabledByLayer(/opt/disable-extensions-jwigqn8j) -> stat /opt/disable-extensions-jwigqn8j: no such file or directory" func=go.amzn.com/lambda/rapid.extensionsDisabledByLayer file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:522" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Received RUNNING: {33654244034365 33654244202892 0 33654244034365 true 0xc000180e40}" func="go.amzn.com/lambda/rapidcore.(*Server).Init" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:510" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Awaiting initialization of runtime init." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:235" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Runtime API Server listening on 127.0.0.1:9001" func="go.amzn.com/lambda/rapi.(*Server).Listen" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/server.go:102" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Hot reloading disabled." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:162" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=info msg="Configuring and starting Operator Domain" func=go.amzn.com/lambda/rapid.doOperatorDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:255" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=info msg="Starting runtime domain" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:302" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=warning msg="Cannot list external agents" func=go.amzn.com/lambda/agents.ListExternalAgentPaths file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/agents/agent.go:24" error="open /opt/extensions: no such file or directory" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Preregister runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:329" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Start runtime" func=go.amzn.com/lambda/rapid.doRuntimeDomainInit file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:349" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[AWS_Lambda_Cpp/0.2.6]]" func=go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/middleware/middleware.go:76" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[AWS_Lambda_Cpp/0.2.6]]" func=go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/middleware/middleware.go:76" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] time="2023-11-21T22:08:04Z" level=debug msg="Completed initialization of runtime init. Sending status ready to LocalStack." func=main.main file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:244" localstack_main | [lambda b579db6d67f53cd7c2282ecdd9666842] localstack_main | 2023-11-21T22:08:13.895 DEBUG --- [ Thread-62] l.u.c.docker_sdk_client : Stopping container: localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842 localstack_main | 2023-11-21T22:08:19.194 DEBUG --- [ Thread-62] l.u.c.docker_sdk_client : Removing container: localstack-main-lambda-test-go-b579db6d67f53cd7c2282ecdd9666842 localstack_main | 2023-11-21T22:08:19.231 INFO --- [ asgi_gw_2] localstack.request.aws : AWS lambda.Invoke => 500 (ServiceException) ```

Lambda invoke log

An error occurred (ServiceException) when calling the Invoke operation (reached max retries: 2): Internal error while executing lambda

[joe4dev]

I'm having similar issues to those @aryamohanan is facing. I followed all the tips that @joe4dev gave. But without success so far.

Hi @sineto 👋

Thank you for sharing your details. What is currently missing is the build step.

I created a working sample with a few adjustments: https://github.com/joe4dev/localstack-lambda-golang1-sample

• Add details about how to build the Lambda function
• Adjust --handler lambda.main => --handler main according to the build

The AWS documentation about Building Lambda functions with Go provides more details on how to build and package Golang Lambda functions.

Note that the go1.x runtime is deprecated and will reach EOL by the end of this year. Check out the AWS migration guide: https://aws.amazon.com/blogs/compute/migrating-aws-lambda-functions-from-the-go1-x-runtime-to-the-custom-runtime-on-amazon-linux-2/

@sineto Does the sample work for you? Feel free to adjust the sample or adapt it to your scenario and share it if you can reproduce the issue.

---

A few unrelated setup comments:

• localstack --version == 2.3.0 shows that you are running an older CLI version. Please update your CLI: https://docs.localstack.cloud/getting-started/installation/
• Please replace localstack_main with localstack-main as the container name in container_name: "${LOCALSTACK_DOCKER_NAME-localstack_main}"

See LocalStack v3 release notes for more details.

[localstack-bot]

Hello 👋! It looks like this issue hasn’t been active in longer than two weeks. We encourage you to check if this is still an issue in the latest release. In the absence of more information, we will be closing this issue soon. If you find that this is still a problem, please feel free to provide a comment or upvote with a reaction on the initial post to prevent automatic closure. If the issue is already closed, please feel free to open a new one.

[alex35mil]

Hi @joe4dev, I'm trying to run Rust-based lambda function locally with LocalStack, but getting this issue as well. I'm not sure if it's the build issue or LocalStack issue. I'm on macOS/M1, building a binary for provided.al2023 runtime via Docker. I pushed the reproduction including detailed log: https://github.com/alex35mil/localstack-rust-lambda-issue

[alex35mil]

I found the culprits. It was a combo of naming and environment issues when deploying but not building with cargo lambda.

Fix: https://github.com/alex35mil/localstack-rust-lambda-issue/commit/f86d07267d3dec84d4b1e63477a5fa3d968fe52a

[Bandes]

I am having a similar problem with Localstack 3.0.2 and Serverless 3.38, also on a M1Pro Mac. My lambda is using node 18 as its environment. I have the latest version of docker, arm64 version.

localstack-main  | 2023-12-26T13:02:29.065 DEBUG --- [   Thread-22] l.u.c.docker_sdk_client    : Stopping container: localstack-main-lambda-lambda-name-goes-here-d17013f096ba8f6ff727c8a8908ec335
localstack-main  | 2023-12-26T13:02:29.680 DEBUG --- [   Thread-22] l.u.c.docker_sdk_client    : Removing container: localstack-main-lambda-lambda-name-goes-here-d17013f096ba8f6ff727c8a8908ec335
localstack-main  | 2023-12-26T13:02:29.795 DEBUG --- [ve:$LATEST_0] l.s.l.i.event_manager      : Service exception in lambda arn:aws:lambda:us-west-2:000000000000:function:lambda-name-goes-here:$LATEST: Execution environment timed out during startup.
localstack-main  | 2023-12-26T13:02:29.814 DEBUG --- [   asgi_gw_4] l.services.sqs.models      : deleting message 5dfeab90-03e4-499d-a757-d98545c4c66f from queue arn:aws:sqs:us-west-2:949334387222:lambda-name-goes-here-c872282e7a48b2d0ef6c0febfc1f5b5a
localstack-main  | 2023-12-26T13:02:31.609 DEBUG --- [functhread41] l.services.sqs.models      : enqueueing delayed messages 27948f53-941c-4aac-be54-d7ebbe8f3cf0 into queue arn:aws:sqs:us-west-2:949334387222:lambda-name-goes-here-c872282e7a48b2d0ef6c0febfc1f5b5a
localstack-main  | 2023-12-26T13:02:31.609 DEBUG --- [   asgi_gw_2] l.services.sqs.models      : de-queued message SqsMessage(id=27948f53-941c-4aac-be54-d7ebbe8f3cf0,group=None) from arn:aws:sqs:us-west-2:949334387222:lambda-name-goes-here-c872282e7a48b2d0ef6c0febfc1f5b5a

My docker-compose.yml looks like this:

version: '3.8'
services:
  localstack:
    image: localstack/localstack:latest
    container_name: "${LOCALSTACK_DOCKER_NAME-localstack-main}"
    dns: 127.0.0.1
    ports:
      - "443:443"
      - '4566:4566'
    environment:
      - DEBUG=1
      - LAMBDA_DOCKER_FLAGS=-e NODE_OPTIONS=--inspect-brk=0.0.0.0:9229 -p 9229:9229
      - LAMBDA_INIT_USER=root
      - LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT=60
      - DOCKER_HOST=unix:///var/run/docker.sock
    volumes:
      - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack"
      - "/var/run/docker.sock:/var/run/docker.sock"

I have tried with LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT up to 300 with the same results

I also sometimes see things like this:

localstack-main  | 2023-12-26T13:02:28.920  WARN --- [   Thread-22] l.s.l.i.execution_environm : Execution environment d17013f096ba8f6ff727c8a8908ec335 for function arn:aws:lambda:us-west-2:000000000000:function:lambda-name-goes-here:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT.
localstack-main  | 2023-12-26T13:02:29.064 DEBUG --- [   Thread-22] l.s.l.i.execution_environm : Logs from the execution environment d17013f096ba8f6ff727c8a8908ec335 after startup timeout:
localstack-main  | [lambda d17013f096ba8f6ff727c8a8908ec335] time="2023-12-26T13:01:29Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21"
localstack-main  | [lambda d17013f096ba8f6ff727c8a8908ec335] time="2023-12-26T13:01:29Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145"

I don't understand how to access the logs that are alluded to here Logs from the execution environment d17013f096ba8f6ff727c8a8908ec335 so I don't know how to 'Check for errors during the startup of your Lambda function', but I don't think it is even starting the lambda because the debugger never enters it.

[joe4dev]

I found the culprits. It was a combo of naming and environment issues when deploying but not building with cargo lambda.

Fix: alex35mil/localstack-rust-lambda-issue@f86d072

We are happy to hear the Rust Lambda deployment issue is resolved @alex35mil ✨ Thank you for sharing @alex35mil 🙏🙏

[joe4dev]

I am having a similar problem with Localstack 3.0.2 and Serverless 3.38, also on a M1Pro Mac. My lambda is using node 18 as its environment. I have the latest version of docker, arm64 version.

localstack-main  | 2023-12-26T13:02:29.065 DEBUG --- [   Thread-22] l.u.c.docker_sdk_client    : Stopping container: localstack-main-lambda-lambda-name-goes-here-d17013f096ba8f6ff727c8a8908ec335
localstack-main  | 2023-12-26T13:02:29.680 DEBUG --- [   Thread-22] l.u.c.docker_sdk_client    : Removing container: localstack-main-lambda-lambda-name-goes-here-d17013f096ba8f6ff727c8a8908ec335
localstack-main  | 2023-12-26T13:02:29.795 DEBUG --- [ve:$LATEST_0] l.s.l.i.event_manager      : Service exception in lambda arn:aws:lambda:us-west-2:000000000000:function:lambda-name-goes-here:$LATEST: Execution environment timed out during startup.
localstack-main  | 2023-12-26T13:02:29.814 DEBUG --- [   asgi_gw_4] l.services.sqs.models      : deleting message 5dfeab90-03e4-499d-a757-d98545c4c66f from queue arn:aws:sqs:us-west-2:949334387222:lambda-name-goes-here-c872282e7a48b2d0ef6c0febfc1f5b5a
localstack-main  | 2023-12-26T13:02:31.609 DEBUG --- [functhread41] l.services.sqs.models      : enqueueing delayed messages 27948f53-941c-4aac-be54-d7ebbe8f3cf0 into queue arn:aws:sqs:us-west-2:949334387222:lambda-name-goes-here-c872282e7a48b2d0ef6c0febfc1f5b5a
localstack-main  | 2023-12-26T13:02:31.609 DEBUG --- [   asgi_gw_2] l.services.sqs.models      : de-queued message SqsMessage(id=27948f53-941c-4aac-be54-d7ebbe8f3cf0,group=None) from arn:aws:sqs:us-west-2:949334387222:lambda-name-goes-here-c872282e7a48b2d0ef6c0febfc1f5b5a

My docker-compose.yml looks like this:

version: '3.8'
services:
  localstack:
    image: localstack/localstack:latest
    container_name: "${LOCALSTACK_DOCKER_NAME-localstack-main}"
    dns: 127.0.0.1
    ports:
      - "443:443"
      - '4566:4566'
    environment:
      - DEBUG=1
      - LAMBDA_DOCKER_FLAGS=-e NODE_OPTIONS=--inspect-brk=0.0.0.0:9229 -p 9229:9229
      - LAMBDA_INIT_USER=root
      - LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT=60
      - DOCKER_HOST=unix:///var/run/docker.sock
    volumes:
      - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack"
      - "/var/run/docker.sock:/var/run/docker.sock"

I have tried with LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT up to 300 with the same results

I also sometimes see things like this:

localstack-main  | 2023-12-26T13:02:28.920  WARN --- [   Thread-22] l.s.l.i.execution_environm : Execution environment d17013f096ba8f6ff727c8a8908ec335 for function arn:aws:lambda:us-west-2:000000000000:function:lambda-name-goes-here:$LATEST timed out during startup. Check for errors during the startup of your Lambda function and consider increasing the startup timeout via LAMBDA_RUNTIME_ENVIRONMENT_TIMEOUT.
localstack-main  | 2023-12-26T13:02:29.064 DEBUG --- [   Thread-22] l.s.l.i.execution_environm : Logs from the execution environment d17013f096ba8f6ff727c8a8908ec335 after startup timeout:
localstack-main  | [lambda d17013f096ba8f6ff727c8a8908ec335] time="2023-12-26T13:01:29Z" level=debug msg="No code archives set. Skipping download." func=main.DownloadCodeArchives file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/codearchive.go:21"
localstack-main  | [lambda d17013f096ba8f6ff727c8a8908ec335] time="2023-12-26T13:01:29Z" level=debug msg="DNS server disabled." func=main.RunDNSRewriter file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:145"

I don't understand how to access the logs that are alluded to here Logs from the execution environment d17013f096ba8f6ff727c8a8908ec335 so I don't know how to 'Check for errors during the startup of your Lambda function', but I don't think it is even starting the lambda because the debugger never enters it.

Hi @Bandes Thank you for reaching out. Let me share some comments regarding the configuration and log inspection.

Configuration

1. What is the reason for setting LAMBDA_INIT_USER=root?
2. Exposing a debug port via LAMBDA_DOCKER_FLAGS is currently limited to a single port mapping. Hence, please ensure that only one Lambda instance is active at any time. Does the code work without debugging?
3. Refer to our official docker-compose.yml for a recommended configuration. Other services might require additional port mappings.
4. Refer to our DNS documentation for custom DNS configuration

Log inspection

To check the Lambda container logs, please use Docker utilities (e.g., Docker Desktop or Docker logs) to inspect the logs of the Lambda docker container. The ID of the "execution environment" (e.g., d17013f096ba8f6ff727c8a8908ec335) is part of the Docker container name:

Hint: Using LAMBDA_REMOVE_CONTAINERS=0, Lambda containers are not removed, which might be helpful for debugging.

👉 We are looking forward to hearing your feedback @Bandes 👂

[localstack-bot]

Hello 👋! It looks like this issue hasn’t been active in longer than two weeks. We encourage you to check if this is still an issue in the latest release. In the absence of more information, we will be closing this issue soon. If you find that this is still a problem, please feel free to provide a comment or upvote with a reaction on the initial post to prevent automatic closure. If the issue is already closed, please feel free to open a new one.

[aryamohanan]

Hi @joe4dev I successfully invoked the Lambda function after configuring the LAMBDA_INIT_USER=root on my M1 machine. However, I couldn't locate documentation for this variable. Could you provide more information about it?

I've included the configuration in the docker-compose file for your reference.

localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME:-localstack-main}"
    image: localstack/localstack:latest
    ports:
      - "4566:4566"            # LocalStack Gateway
      - "4510-4559:4510-4559"  # external services port range
    environment:
      - DEBUG=${DEBUG-}
      - DOCKER_HOST=unix:///var/run/docker.sock 
      - LAMBDA_INIT_USER=root
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock"

Thanks in advance.

[joe4dev]

Hi @joe4dev I successfully invoked the Lambda function after configuring the LAMBDA_INIT_USER=root on my M1 machine. However, I couldn't locate documentation for this variable. Could you provide more information about it?

I've included the configuration in the docker-compose file for your reference.

localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME:-localstack-main}"
    image: localstack/localstack:latest
    ports:
      - "4566:4566"            # LocalStack Gateway
      - "4510-4559:4510-4559"  # external services port range
    environment:
      - DEBUG=${DEBUG-}
      - DOCKER_HOST=unix:///var/run/docker.sock 
      - LAMBDA_INIT_USER=root
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock"

Thanks in advance.

Thank you for sharing your feedback @aryamohanan 🙏 That's a very interesting behavior 🤔

LAMBDA_INIT_USER is (currently) an internal configuration for LocalStack developers and therefore not (yet) documented in our LocalStack configuration page. It is implemented here in our custom Golang lambda-runtime-init and was primarily used for internal testing. When setting it to root, we do not switch from the default container user root to the user sbx_user1051 (matching the environment at AWS). Hence, we do not drop root privileges.

1. Does the same Lambda code run successfully at real AWS Lambda?
2. Does your code require root privileges or make other assumptions about users? Our introspection tests (e.g., tests.aws.services.lambda_.test_lambda.TestLambdaBehavior.test_runtime_introspection_x86) indicate a parity difference: at real AWS, the user slicer exists and owns /var/task. Since we are not (yet) aware of any related issues, we skip creating this user for now to avoid introducing unnecessary delay.
3. Could you share a minimal reproducer? This would be extremely helpful to reproduce the issue on our side, so we can investigate and fix the root cause.

[aryamohanan]

Hello @joe4dev , I appreciate the clarification.

I'm encountering an issue solely with the invocation, as the other actions are functioning properly. The lambda code runs successfully on an actual AWS Lambda, and even when I set PROVIDER_OVERRIDE_LAMBDA=legacy, the invocation performs without any issues. I have other containers running using the same docker-compose file. I am attaching reproducer,

zookeeper:
    image: wurstmeister/zookeeper
    platform: linux/amd64
    ports:
      - 2181:2181

  kafka:
    image: wurstmeister/kafka:2.12-2.2.1
    platform: linux/amd64
    ports:
      - 9092:9092
      - 29092:29092
    depends_on:
      - "zookeeper"
    hostname: kafka0
    environment:

      KAFKA_LISTENERS: EXTERNAL://:9092,PLAINTEXT://:29092
      KAFKA_ADVERTISED_LISTENERS: PLAINTEXT://kafka0:29092,EXTERNAL://localhost:9092
      KAFKA_OFFSETS_TOPIC_REPLICATION_FACTOR: 1
      KAFKA_LISTENER_SECURITY_PROTOCOL_MAP: PLAINTEXT:PLAINTEXT,EXTERNAL:PLAINTEXT
      KAFKA_INTER_BROKER_LISTENER_NAME: PLAINTEXT

      KAFKA_CREATE_TOPICS: "test:1:1,test-topic-1:1:1"
      KAFKA_ZOOKEEPER_CONNECT: zookeeper:2181
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock
      - ./bin:/nodejs-bin
    command: ["/nodejs-bin/wait-for-it.sh", "-s", "-t", "120", "zookeeper:2181", "--", "start-kafka.sh"]

  schema-registry:
    image: confluentinc/cp-schema-registry:4.1.0
    platform: linux/amd64
    hostname: schema-registry
    depends_on:
      - "kafka"
    ports:
      - "8081:8081"
    environment:
      SCHEMA_REGISTRY_KAFKASTORE_CONNECTION_URL: "zookeeper:2181"
      SCHEMA_REGISTRY_KAFKASTORE_BOOTSTRAP_SERVERS: "PLAINTEXT://kafka0:29092"
      SCHEMA_REGISTRY_HOST_NAME: schema-registry

localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME:-localstack-main}"
    image: localstack/localstack:latest
    ports:
      - "4566:4566"            # LocalStack Gateway
      - "4510-4559:4510-4559"  # external services port range
    environment:
      - DEBUG=${DEBUG-}
      - DOCKER_HOST=unix:///var/run/docker.sock 
      - LAMBDA_INIT_USER=root
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock"

Lambda function creation code.

const { LambdaClient} = require('@aws-sdk/client-lambda');
const lambdaClient = new LambdaClient({
  endpoint: xxxxxxxxx,
  region: 'us-east'
});
const lambdaFunctionCode = `
  exports.handler = async (event) => {
    const response = {
      statusCode: 200,
      body: JSON.stringify({ message: 'Hello, Lambda!' }),
    };
    return response;
  };
`;
exports.createFunction = async functionName => {
  zip.addFile('index.js', Buffer.from(lambdaFunctionCode));
  const zipBuffer = zip.toBuffer();
  const createFunctionParams = {
    FunctionName: functionName,
    Runtime: 'nodejs18.x',
    Role: 'test/lambda-role',
    Handler: 'index.handler',
    Code: {
      ZipFile: zipBuffer
    }
  };
  await lambdaClient.send(new CreateFunctionCommand(createFunctionParams));
}

Please let me know if you need any other information.

[joe4dev]

Hello @joe4dev , I appreciate the clarification.

I'm encountering an issue solely with the invocation, as the other actions are functioning properly. The lambda code runs successfully on an actual AWS Lambda, and even when I set PROVIDER_OVERRIDE_LAMBDA=legacy, the invocation performs without any issues. I have other containers running using the same docker-compose file. I am attaching reproducer,

...

Please let me know if you need any other information.

Thank you for sharing @aryamohanan

Unfortunately, the reproducer is not fully self-contained, despite a few modifications:

// Modification 1: provide a working endpoint
const lambdaClient = new LambdaClient({
  endpoint: 'http://127.0.0.1:4566',
  region: 'us-east-1'
});

// Modification 2: invoke the deployment helper at the bottom
this.createFunction("my-lambda-function")

// Undefined dependencies
/Users/joe/Projects/LocalStack/issues/8878-lambda-timeout-node/deploy.js:17
  zip.addFile('index.js', Buffer.from(lambdaFunctionCode));
  ^

ReferenceError: zip is not defined
    at exports.createFunction (/Users/joe/Projects/LocalStack/issues/8878-lambda-timeout-node/deploy.js:17:3)
    at Object.<anonymous> (/Users/joe/Projects/LocalStack/issues/8878-lambda-timeout-node/deploy.js:31:6)
    at Module._compile (node:internal/modules/cjs/loader:1254:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1308:10)
    at Module.load (node:internal/modules/cjs/loader:1117:32)
    at Module._load (node:internal/modules/cjs/loader:958:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)
    at node:internal/main/run_main_module:23:47

Node.js v18.16.0

Working Sample

Using the provided Lambda code within handler.js:

exports.handler = async (event) => {
    const response = {
      statusCode: 200,
      body: JSON.stringify({ message: 'Hello, Lambda!' }),
    };
    return response;
  };

The following Makefile successfully deploys make deploy and invokes make invoke the sample Nodejs Lambda function using the aws CLI:

package:
    rm -f lambda.zip && zip lambda.zip handler.js

deploy: package
    aws --endpoint-url http://localhost:4566 lambda create-function \
        --function-name my-lambda-function \
        --runtime nodejs18.x \
        --zip-file fileb://lambda.zip \
        --handler handler.handler \
        --role arn:aws:iam::000000000000:role/lambda-role

invoke:
    aws --endpoint-url=http://localhost:4566 lambda invoke \
        --function-name my-lambda-function \
        output.txt

Using this reference docker-compose.yml to start LocalStack (latest as of 2024-02-06):

version: "3.8"

services:
  localstack:
    container_name: "${LOCALSTACK_DOCKER_NAME:-localstack-main}"
    image: localstack/localstack
    ports:
      - "127.0.0.1:4566:4566"            # LocalStack Gateway
      - "127.0.0.1:4510-4559:4510-4559"  # external services port range
    environment:
      # LocalStack configuration: https://docs.localstack.cloud/references/configuration/
      - DEBUG=${DEBUG:-0}
    volumes:
      - "${LOCALSTACK_VOLUME_DIR:-./volume}:/var/lib/localstack"
      - "/var/run/docker.sock:/var/run/docker.sock"

[localstack-bot]

Hello 👋! It looks like this issue hasn’t been active in longer than two weeks. We encourage you to check if this is still an issue in the latest release. In the absence of more information, we will be closing this issue soon. If you find that this is still a problem, please feel free to provide a comment or upvote with a reaction on the initial post to prevent automatic closure. If the issue is already closed, please feel free to open a new one.