aws / aws/aws-lambda-base-images
Telemetry Subscribe API return 404
- 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
Assessment
This issue has not been assessed yet.