aws / aws/aws-lambda-base-images

Telemetry Subscribe API return 404

Open
#121 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
No language data
Stars
777
Forks
118
PR merge metrics
No merged PRs in 30d

Description

I am working on Localstack and I am trying to monitor my lambda function, written in Java 17. I found [this Lambda extension](https://aws-otel.github.io/docs/getting-started/lambda/lambda-java) for the OpenTelemetry Lambda Support and followed the steps described. The function runs, but shows an error when the extension calls the [Subscribe API](https://docs.aws.amazon.com/lambda/latest/dg/telemetry-api-reference.html#telemetry-subscribe-api):

```
Cannot register Telemetry API client","error":"request to http://127.0.0.1:9001/2022-07-01/telemetry failed: 404[404 Not Found] 404 page not found
```

Then, the lambda continues the execution until the end, but fails. Here are the logs:

```
time="2023-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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-10-19T14:58:25Z [Info] Initializing AWS X-Ray daemon unknown
2023-10-19T14:58:25Z [Debug] Listening on UDP 127.0.0.1:2000
2023-10-19T14:58:25Z [Info] Using buffer memory limit of 158 MB
2023-10-19T14:58:25Z [Info] 2528 segment buffers allocated
2023-10-19T14:58:25Z [Debug] Using Endpoint read from Config file: http://172.23.0.2:443
2023-10-19T14:58:25Z [Debug] Using proxy address:
2023-10-19T14:58:25Z [Debug] Fetch region us-east-1 from commandline/config file
2023-10-19T14:58:25Z [Info] Using region: us-east-1
2023-10-19T14:58:25Z [Info] HTTP Proxy server using X-Ray Endpoint : http://172.23.0.2:443
2023-10-19T14:58:25Z [Debug] Using Endpoint: http://172.23.0.2:443
2023-10-19T14:58:25Z [Debug] Batch size: 10
2023-10-19T14:58:25Z [Info] Starting proxy http server on 127.0.0.1:2000
time="2023-10-19T14:58:25Z" level=info msg="Hot reloading enabled, starting filewatcher. [/var/task]" func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:164"
time="2023-10-19T14:58:25Z" level=info msg="Release detected: 6.2.0-34-generic" func=go.amzn.com/cmd/localstack/filenotify.shouldUseEventWatcher file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/filenotify/filenotify.go:34"
time="2023-10-19T14:58:25Z" 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-10-19T14:58:25Z" level=debug msg="Using event based filewatcher" func=go.amzn.com/cmd/localstack/filenotify.New file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/filenotify/filenotify.go:44"
time="2023-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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"
time="2023-10-19T14:58:25Z" level=info msg="Subfolders: [/var/task /var/task/lib]" func="main.(*ChangeListener).AddTargetPaths" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/hotreloading.go:89"
{"level":"info","ts":1697727505.3726828,"msg":"Launching OpenTelemetry Lambda extension","version":"v0.33.0"}
time="2023-10-19T14:58:25Z" level=debug msg="API request - POST /2020-01-01/extension/register, Headers:map[Accept-Encoding:[gzip] Content-Length:[32] Lambda-Extension-Name:[collector] User-Agent:[Go-http-client/1.1]]" 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"
time="2023-10-19T14:58:25Z" level=debug msg="API request - POST /2020-01-01/extension/register, Headers:map[Accept-Encoding:[gzip] Content-Length:[32] Lambda-Extension-Name:[collector] User-Agent:[Go-http-client/1.1]]" 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"
time="2023-10-19T14:58:25Z" level=info msg="External agent collector (57860325-8ce1-49ae-9a49-ba597a121f5e) registered, subscribed to [INVOKE SHUTDOWN]" func="go.amzn.com/lambda/rapi/handler.(*agentRegisterHandler).registerExternalAgent" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapi/handler/agentregister.go:104"
time="2023-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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"
{"level":"info","ts":1697727505.3744254,"logger":"telemetryAPI.Listener","msg":"Listening for requests","address":"sandbox:53612"}
{"level":"info","ts":1697727505.3746564,"logger":"telemetryAPI.Client","msg":"Subscribing","baseURL":"http://127.0.0.1:9001/2022-07-01/telemetry"}
time="2023-10-19T14:58:25Z" level=debug msg="API request - PUT /2022-07-01/telemetry, Headers:map[Accept-Encoding:[gzip] Content-Length:[212] Content-Type:[application/json] Lambda-Extension-Identifier:[57860325-8ce1-49ae-9a49-ba597a121f5e] User-Agent:[Go-http-client/1.1]]" 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"
{"level":"error","ts":1697727505.3758273,"logger":"telemetryAPI.Client","msg":"Subscription failed"}
{"level":"fatal","ts":1697727505.3759294,"msg":"Cannot register Telemetry API client","error":"request to http://127.0.0.1:9001/2022-07-01/telemetry failed: 404[404 Not Found] 404 page not found\n"}
time="2023-10-19T14:58:25Z" level=warning msg="First fatal error stored in appctx: Extension.Crash" func=go.amzn.com/lambda/appctx.StoreFirstFatalError file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/appctx/appctxutil.go:156"
time="2023-10-19T14:58:25Z" level=warning msg="Process 15(collector) exited: 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-10-19T14:58:25Z" level=debug msg="Canceling flows: 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-10-19T14:58:25Z" 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="exit status 1"
time="2023-10-19T14:58:25Z" 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-10-19T14:58:25Z" 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"

// lambda custom logs

time="2023-10-19T14:58:28Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[aws-lambda-java/Corretto-17.0.8.8.1-2.4.1]]" 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"
time="2023-10-19T14:58:28Z" level=debug msg="API request - GET /2018-06-01/runtime/invocation/next, Headers:map[Accept:[*/*] User-Agent:[aws-lambda-java/Corretto-17.0.8.8.1-2.4.1]]" 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"
time="2023-10-19T14:58:34Z" level=info msg="Received signal" func=go.amzn.com/lambda/rapidcore.signalHandler file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/sandbox.go:255" signal=terminated
time="2023-10-19T14:58:34Z" level=info msg="Shutting down..." func=go.amzn.com/lambda/rapidcore.NewSandboxBuilder.func1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/sandbox.go:95"
time="2023-10-19T14:58:34Z" level=warning msg="Reset initiated: SandboxTerminated" func=go.amzn.com/lambda/rapid.handleReset file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/start.go:589"
time="2023-10-19T14:58:34Z" level=info msg="unblocking the credentials service" func="go.amzn.com/lambda/core.(*credentialsServiceImpl).UnblockService" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/core/credentials.go:97"
time="2023-10-19T14:58:34Z" level=debug msg="shutdown runtime" func=go.amzn.com/lambda/rapid.shutdownRuntime file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/graceful_shutdown.go:96"
time="2023-10-19T14:58:34Z" level=warning msg="Process 15 exited unexpectedly" func=go.amzn.com/lambda/rapid.shutdownRuntime file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/graceful_shutdown.go:117"
time="2023-10-19T14:58:34Z" level=info msg="runtime exited" func=go.amzn.com/lambda/rapid.shutdownRuntime file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/graceful_shutdown.go:113"
time="2023-10-19T14:58:34Z" level=debug msg="shutdown agents" func=go.amzn.com/lambda/rapid.shutdownAgents file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/graceful_shutdown.go:132"
time="2023-10-19T14:58:36Z" level=warning msg="collector (57860325-8ce1-49ae-9a49-ba597a121f5e) failed to transition to ShutdownFailed: State transition is not allowed (current state: Registered)" func=go.amzn.com/lambda/rapid.shutdownAgents file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/graceful_shutdown.go:188"
time="2023-10-19T14:58:36Z" level=warning msg="Killing agent collector (57860325-8ce1-49ae-9a49-ba597a121f5e) which failed to shutdown" func=go.amzn.com/lambda/rapid.shutdownAgents file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapid/graceful_shutdown.go:190"
time="2023-10-19T14:58:36Z" level=debug msg="Dispatching DONE:resetCorrelationID" func="go.amzn.com/lambda/rapidcore.(*Server).dispatchDone" file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/lambda/rapidcore/server.go:472"
time="2023-10-19T14:58:36Z" level=debug msg="Stopping file watcher" func=main.main.func1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:161"
time="2023-10-19T14:58:36Z" level=debug msg="Stopping DNS server" func=main.main.func1 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:163"
time="2023-10-19T14:58:36Z" level=debug msg="Shutting down xray daemon" func=main.main.func2 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:175"
time="2023-10-19T14:58:36Z" level=debug msg="Flushing segments in xray daemon" func=main.main.func2 file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/main.go:177"
time="2023-10-19T14:58:36Z" level=info msg="Closing down filewatcher." func=main.RunHotReloadingListener file="/home/runner/work/lambda-runtime-init/lambda-runtime-init/cmd/localstack/awsutil.go:176"
```

I have found other similar issues:
[Bug: AWS OTEL lambda layer fails with "Cannot register Telemetry API client" when running locally](https://github.com/aws/aws-sam-cli/issues/4570)
[Use of ADOT layers in Lambda](https://discuss.localstack.cloud/t/use-of-adot-layers-in-lambda/333/7)

Do I need some additional configuration or these APIs are not supported? Thank you

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.