nodejs integration-test doesn't seem to work

[Danwakeem]

Hey there, I wanted to try out the nodejs extension but I wasn't able to get the demo in the nodejs/integration-tests/aws-sdk/wrapper to work. Here are the steps I followed.

• run make publish-layer in the collector folder to have a local build of the collector
• run npm i in the nodejs folder
• Run terraform init in the nodejs/integration-tests/aws-sdk/wrapper
• Run terraform apply to deploy
• Run a GET request on the endpoint that was exposed on API gateway.

Then in CloudWatch I am just seeing the following followed by a timeout from lambda and API gateway

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   timestamp   |                                                                                                        message                                                                                                        |
|---------------|-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| 1640891812819 | 2021/12/30 19:16:52 [collector] Launching OpenTelemetry Lambda extension, version:  v0.1.0                                                                                                                            |
| 1640891812834 | 2021-12-30T19:16:52.834Z info service/collector.go:186 Applying configuration...                                                                                                                                      |
| 1640891812835 | 2021-12-30T19:16:52.834Z info builder/exporters_builder.go:254 Exporter was built. {"kind": "exporter", "name": "logging"}                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/pipelines_builder.go:222 Pipeline was built. {"name": "pipeline", "name": "metrics"}                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/pipelines_builder.go:222 Pipeline was built. {"name": "pipeline", "name": "traces"}                                                                                             |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/receivers_builder.go:224 Receiver was built. {"kind": "receiver", "name": "otlp", "datatype": "metrics"}                                                                        |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/receivers_builder.go:224 Receiver was built. {"kind": "receiver", "name": "otlp", "datatype": "traces"}                                                                         |
| 1640891812835 | 2021-12-30T19:16:52.835Z info service/service.go:86 Starting extensions...                                                                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info service/service.go:91 Starting exporters...                                                                                                                                             |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/exporters_builder.go:40 Exporter is starting... {"kind": "exporter", "name": "logging"}                                                                                         |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/exporters_builder.go:48 Exporter started. {"kind": "exporter", "name": "logging"}                                                                                               |
| 1640891812835 | 2021-12-30T19:16:52.835Z info service/service.go:96 Starting processors...                                                                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/pipelines_builder.go:54 Pipeline is starting... {"name": "pipeline", "name": "metrics"}                                                                                         |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/pipelines_builder.go:65 Pipeline is started. {"name": "pipeline", "name": "metrics"}                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/pipelines_builder.go:54 Pipeline is starting... {"name": "pipeline", "name": "traces"}                                                                                          |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/pipelines_builder.go:65 Pipeline is started. {"name": "pipeline", "name": "traces"}                                                                                             |
| 1640891812835 | 2021-12-30T19:16:52.835Z info service/service.go:101 Starting receivers...                                                                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/receivers_builder.go:68 Receiver is starting... {"kind": "receiver", "name": "otlp"}                                                                                            |
| 1640891812835 | 2021-12-30T19:16:52.835Z info otlpreceiver/otlp.go:68 Starting GRPC server on endpoint 0.0.0.0:4317 {"kind": "receiver", "name": "otlp"}                                                                              |
| 1640891812835 | 2021-12-30T19:16:52.835Z info otlpreceiver/otlp.go:86 Starting HTTP server on endpoint 0.0.0.0:4318 {"kind": "receiver", "name": "otlp"}                                                                              |
| 1640891812835 | 2021-12-30T19:16:52.835Z info otlpreceiver/otlp.go:141 Setting up a second HTTP listener on legacy endpoint 0.0.0.0:55681 {"kind": "receiver", "name": "otlp"}                                                        |
| 1640891812835 | 2021-12-30T19:16:52.835Z info otlpreceiver/otlp.go:86 Starting HTTP server on endpoint 0.0.0.0:55681 {"kind": "receiver", "name": "otlp"}                                                                             |
| 1640891812835 | 2021-12-30T19:16:52.835Z info builder/receivers_builder.go:73 Receiver started. {"kind": "receiver", "name": "otlp"}                                                                                                  |
| 1640891812835 | 2021-12-30T19:16:52.835Z info service/telemetry.go:92 Setting up own telemetry...                                                                                                                                     |
| 1640891812836 | 2021-12-30T19:16:52.836Z info service/telemetry.go:116 Serving Prometheus metrics {"address": ":8888", "level": "basic", "service.instance.id": "27f930a5-d42a-4826-af98-8b11dc15fec2", "service.version": "latest"}  |
| 1640891812836 | 2021-12-30T19:16:52.836Z info service/collector.go:235 Starting otelcol... {"Version": "v0.1.0", "NumCPU": 2}                                                                                                         |
| 1640891812836 | 2021-12-30T19:16:52.836Z info service/collector.go:131 Everything is ready. Begin running and processing data.                                                                                                        |
| 1640891822826 | START RequestId: 80ac2185-73a7-4743-8b6d-5b4edb2d1ee4 Version: $LATEST                                                                                                                                                |
| 1640891823432 | 2021/12/30 19:17:03 [collector] Launching OpenTelemetry Lambda extension, version:  v0.1.0                                                                                                                            |
| 1640891823469 | 2021-12-30T19:17:03.469Z info service/collector.go:186 Applying configuration...                                                                                                                                      |
| 1640891823469 | 2021-12-30T19:17:03.469Z info builder/exporters_builder.go:254 Exporter was built. {"kind": "exporter", "name": "logging"}                                                                                            |
| 1640891823469 | 2021-12-30T19:17:03.469Z info builder/pipelines_builder.go:222 Pipeline was built. {"name": "pipeline", "name": "traces"}                                                                                             |
| 1640891823469 | 2021-12-30T19:17:03.469Z info builder/pipelines_builder.go:222 Pipeline was built. {"name": "pipeline", "name": "metrics"}                                                                                            |
| 1640891823469 | 2021-12-30T19:17:03.469Z info builder/receivers_builder.go:224 Receiver was built. {"kind": "receiver", "name": "otlp", "datatype": "traces"}                                                                         |
| 1640891823470 | 2021-12-30T19:17:03.469Z info builder/receivers_builder.go:224 Receiver was built. {"kind": "receiver", "name": "otlp", "datatype": "metrics"}                                                                        |
| 1640891823470 | 2021-12-30T19:17:03.469Z info service/service.go:86 Starting extensions...                                                                                                                                            |
| 1640891823470 | 2021-12-30T19:17:03.469Z info service/service.go:91 Starting exporters...                                                                                                                                             |
| 1640891823470 | 2021-12-30T19:17:03.469Z info builder/exporters_builder.go:40 Exporter is starting... {"kind": "exporter", "name": "logging"}                                                                                         |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/exporters_builder.go:48 Exporter started. {"kind": "exporter", "name": "logging"}                                                                                               |
| 1640891823470 | 2021-12-30T19:17:03.470Z info service/service.go:96 Starting processors...                                                                                                                                            |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/pipelines_builder.go:54 Pipeline is starting... {"name": "pipeline", "name": "traces"}                                                                                          |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/pipelines_builder.go:65 Pipeline is started. {"name": "pipeline", "name": "traces"}                                                                                             |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/pipelines_builder.go:54 Pipeline is starting... {"name": "pipeline", "name": "metrics"}                                                                                         |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/pipelines_builder.go:65 Pipeline is started. {"name": "pipeline", "name": "metrics"}                                                                                            |
| 1640891823470 | 2021-12-30T19:17:03.470Z info service/service.go:101 Starting receivers...                                                                                                                                            |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/receivers_builder.go:68 Receiver is starting... {"kind": "receiver", "name": "otlp"}                                                                                            |
| 1640891823470 | 2021-12-30T19:17:03.470Z info otlpreceiver/otlp.go:68 Starting GRPC server on endpoint 0.0.0.0:4317 {"kind": "receiver", "name": "otlp"}                                                                              |
| 1640891823470 | 2021-12-30T19:17:03.470Z info otlpreceiver/otlp.go:86 Starting HTTP server on endpoint 0.0.0.0:4318 {"kind": "receiver", "name": "otlp"}                                                                              |
| 1640891823470 | 2021-12-30T19:17:03.470Z info otlpreceiver/otlp.go:141 Setting up a second HTTP listener on legacy endpoint 0.0.0.0:55681 {"kind": "receiver", "name": "otlp"}                                                        |
| 1640891823470 | 2021-12-30T19:17:03.470Z info otlpreceiver/otlp.go:86 Starting HTTP server on endpoint 0.0.0.0:55681 {"kind": "receiver", "name": "otlp"}                                                                             |
| 1640891823470 | 2021-12-30T19:17:03.470Z info builder/receivers_builder.go:73 Receiver started. {"kind": "receiver", "name": "otlp"}                                                                                                  |
| 1640891823470 | 2021-12-30T19:17:03.470Z info service/telemetry.go:92 Setting up own telemetry...                                                                                                                                     |
| 1640891823471 | 2021-12-30T19:17:03.471Z info service/telemetry.go:116 Serving Prometheus metrics {"address": ":8888", "level": "basic", "service.instance.id": "0c59d806-ac4d-4b29-88e7-55cfea4607df", "service.version": "latest"}  |
| 1640891823471 | 2021-12-30T19:17:03.471Z info service/collector.go:235 Starting otelcol... {"Version": "v0.1.0", "NumCPU": 2}                                                                                                         |
| 1640891823471 | 2021-12-30T19:17:03.471Z info service/collector.go:131 Everything is ready. Begin running and processing data.                                                                                                        |
| 1640891842847 | EXTENSION Name: collector State: Started Events: []                                                                                                                                                                   |
| 1640891842847 | END RequestId: 80ac2185-73a7-4743-8b6d-5b4edb2d1ee4                                                                                                                                                                   |
| 1640891842847 | REPORT RequestId: 80ac2185-73a7-4743-8b6d-5b4edb2d1ee4 Duration: 20020.53 ms Billed Duration: 20000 ms Memory Size: 384 MB Max Memory Used: 31 MB                                                                     |
| 1640891842847 | 2021-12-30T19:17:22.847Z 80ac2185-73a7-4743-8b6d-5b4edb2d1ee4 Task timed out after 20.02 seconds                                                                                                                      |
| 1640891843166 | 2021/12/30 19:17:23 [collector] Launching OpenTelemetry Lambda extension, version:  v0.1.0                                                                                                                            |
| 1640891843196 | 2021-12-30T19:17:23.196Z info service/collector.go:186 Applying configuration...                                                                                                                                      |
| 1640891843196 | 2021-12-30T19:17:23.196Z info builder/exporters_builder.go:254 Exporter was built. {"kind": "exporter", "name": "logging"}                                                                                            |
| 1640891843196 | 2021-12-30T19:17:23.196Z info builder/pipelines_builder.go:222 Pipeline was built. {"name": "pipeline", "name": "traces"}                                                                                             |
| 1640891843196 | 2021-12-30T19:17:23.196Z info builder/pipelines_builder.go:222 Pipeline was built. {"name": "pipeline", "name": "metrics"}                                                                                            |
| 1640891843196 | 2021-12-30T19:17:23.196Z info builder/receivers_builder.go:224 Receiver was built. {"kind": "receiver", "name": "otlp", "datatype": "traces"}                                                                         |
| 1640891843197 | 2021-12-30T19:17:23.196Z info builder/receivers_builder.go:224 Receiver was built. {"kind": "receiver", "name": "otlp", "datatype": "metrics"}                                                                        |
| 1640891843197 | 2021-12-30T19:17:23.197Z info service/service.go:86 Starting extensions...                                                                                                                                            |
| 1640891843197 | 2021-12-30T19:17:23.197Z info service/service.go:91 Starting exporters...                                                                                                                                             |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/exporters_builder.go:40 Exporter is starting... {"kind": "exporter", "name": "logging"}                                                                                         |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/exporters_builder.go:48 Exporter started. {"kind": "exporter", "name": "logging"}                                                                                               |
| 1640891843197 | 2021-12-30T19:17:23.197Z info service/service.go:96 Starting processors...                                                                                                                                            |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/pipelines_builder.go:54 Pipeline is starting... {"name": "pipeline", "name": "traces"}                                                                                          |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/pipelines_builder.go:65 Pipeline is started. {"name": "pipeline", "name": "traces"}                                                                                             |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/pipelines_builder.go:54 Pipeline is starting... {"name": "pipeline", "name": "metrics"}                                                                                         |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/pipelines_builder.go:65 Pipeline is started. {"name": "pipeline", "name": "metrics"}                                                                                            |
| 1640891843197 | 2021-12-30T19:17:23.197Z info service/service.go:101 Starting receivers...                                                                                                                                            |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/receivers_builder.go:68 Receiver is starting... {"kind": "receiver", "name": "otlp"}                                                                                            |
| 1640891843197 | 2021-12-30T19:17:23.197Z info otlpreceiver/otlp.go:68 Starting GRPC server on endpoint 0.0.0.0:4317 {"kind": "receiver", "name": "otlp"}                                                                              |
| 1640891843197 | 2021-12-30T19:17:23.197Z info otlpreceiver/otlp.go:86 Starting HTTP server on endpoint 0.0.0.0:4318 {"kind": "receiver", "name": "otlp"}                                                                              |
| 1640891843197 | 2021-12-30T19:17:23.197Z info otlpreceiver/otlp.go:141 Setting up a second HTTP listener on legacy endpoint 0.0.0.0:55681 {"kind": "receiver", "name": "otlp"}                                                        |
| 1640891843197 | 2021-12-30T19:17:23.197Z info otlpreceiver/otlp.go:86 Starting HTTP server on endpoint 0.0.0.0:55681 {"kind": "receiver", "name": "otlp"}                                                                             |
| 1640891843197 | 2021-12-30T19:17:23.197Z info builder/receivers_builder.go:73 Receiver started. {"kind": "receiver", "name": "otlp"}                                                                                                  |
| 1640891843197 | 2021-12-30T19:17:23.197Z info service/telemetry.go:92 Setting up own telemetry...                                                                                                                                     |
| 1640891843198 | 2021-12-30T19:17:23.198Z info service/telemetry.go:116 Serving Prometheus metrics {"address": ":8888", "level": "basic", "service.instance.id": "8dbe0f4d-2c62-406f-b5ad-cf9178feebe3", "service.version": "latest"}  |
| 1640891843198 | 2021-12-30T19:17:23.198Z info service/collector.go:235 Starting otelcol... {"Version": "v0.1.0", "NumCPU": 2}                                                                                                         |
| 1640891843198 | 2021-12-30T19:17:23.198Z info service/collector.go:131 Everything is ready. Begin running and processing data.                                                                                                        |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Am I missing something here? 🤔

[Danwakeem]

When I rolled back to this commit f6aadfd5932fa7e1e590936be153294645143694 and things seem to be working alright but any commit after that seem to result in some kind of error 🤔

[Danwakeem]

Okay looking through more commits I was able to track down the issue to this PR. If I revert this PR I am able to get the nodejs test app to work, but I have to admit I am not a Go expert so I don't know exactly what the issue with this PR 🤔

[Danwakeem]

I guess I will open an issue since this appears to be a problem with that PR 😎

[NathanielRN]

Hey thanks for posting this issue! I wished I had seen this before trying to debug our issue this weekend 🥲

I should have a a fix for this in #207, please follow up if you think there is still an issue! 😄