Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

node v20 nightly causes failure in @elastic/elasticsearch tests #3192

Closed
trentm opened this issue Mar 6, 2023 · 3 comments
Closed

node v20 nightly causes failure in @elastic/elasticsearch tests #3192

trentm opened this issue Mar 6, 2023 · 3 comments
Assignees
Labels
agent-nodejs Make available for APM Agents project planning.

Comments

@trentm
Copy link
Member

trentm commented Mar 6, 2023

Recent "test-nightly (20)" Edge tests are failing.

When run locally the failures are in the @elastic/elasticsearch and @elastic/elasticsearch-canary tests:

.ci/scripts/test.sh -b "nightly" "20"
...
node_tests_1     | running test: cd . && node --unhandled-rejections=strict test/instrumentation/modules/@elastic/elasticsearch-canary.test.js > test_output/test-instrumentation-modules--elastic-elasticsearch-canary.test.js.tap 2&>1
...
node_tests_1     | # context-propagation works (HttpConnection client options)
node_tests_1     | ok 206 no currentSpan in sync code after @elastic/elasticsearch client command
node_tests_1     | ok 207 should be truthy
node_tests_1     | not ok 208 esServer request included the expected tracestate header
node_tests_1     |   ---
node_tests_1     |     operator: equal
node_tests_1     |     expected: |-
node_tests_1     |       'es=s:1'
node_tests_1     |     actual: |-
node_tests_1     |       undefined
node_tests_1     |     at: done (/app/test/instrumentation/modules/@elastic/elasticsearch.test.js:854:15)
node_tests_1     |     stack: |-
node_tests_1     |       Error: esServer request included the expected tracestate header
node_tests_1     |           at Test.assert [as _assert] (/app/node_modules/tape/lib/test.js:312:48)
node_tests_1     |           at Test.bound [as _assert] (/app/node_modules/tape/lib/test.js:95:17)
node_tests_1     |           at Test.strictEqual (/app/node_modules/tape/lib/test.js:476:7)
node_tests_1     |           at Test.bound [as equal] (/app/node_modules/tape/lib/test.js:95:17)
node_tests_1     |           at done (/app/test/instrumentation/modules/@elastic/elasticsearch.test.js:854:15)
node_tests_1     |           at Timeout._onTimeout (/app/test/_mock_http_client.js:80:7)
node_tests_1     |           at listOnTimeout (node:internal/timers:573:17)
node_tests_1     |           at process.processTimers (node:internal/timers:514:7)
node_tests_1     |   ...
node_tests_1     | not ok 209 esServer request included a traceparent header
node_tests_1     |   ---
node_tests_1     |     operator: ok
node_tests_1     |     expected: true
node_tests_1     |     actual:   undefined
node_tests_1     |     at: done (/app/test/instrumentation/modules/@elastic/elasticsearch.test.js:855:15)
node_tests_1     |     stack: |-
node_tests_1     |       Error: esServer request included a traceparent header
node_tests_1     |           at Test.assert [as _assert] (/app/node_modules/tape/lib/test.js:312:48)
node_tests_1     |           at Test.bound [as _assert] (/app/node_modules/tape/lib/test.js:95:17)
node_tests_1     |           at Test.assert (/app/node_modules/tape/lib/test.js:431:7)
node_tests_1     |           at Test.bound [as ok] (/app/node_modules/tape/lib/test.js:95:17)
node_tests_1     |           at done (/app/test/instrumentation/modules/@elastic/elasticsearch.test.js:855:15)
node_tests_1     |           at Timeout._onTimeout (/app/test/_mock_http_client.js:80:7)
node_tests_1     |           at listOnTimeout (node:internal/timers:573:17)
node_tests_1     |           at process.processTimers (node:internal/timers:514:7)
node_tests_1     |   ...

The recent v20.0.0-nightly2023030448f99e5f6a changed how http.request() decides if the first argument is a URL instance -- if the object has href and origin fields, then it is considered a URL instance. The result is that other fields then get ignored, like agent and headers. That breaks things, like the 'tracestate'/'traceparent' header propagation, if we hit this case...

And we do hit this case because @elastic/elasticsearch@8 does this here:
https://github.com/elastic/elastic-transport-js/blob/64d6fa2c734ac446e15d384c17f61bf5bb755a76/src/connection/HttpConnection.ts#L344-L345
It shouldn't do that. There is no reason for many of those fields (hash, search, pathname, etc.). It should only be setting fields defined at https://nodejs.org/api/http.html#httprequestoptions-callback
I'll open an issue for that.

I've logged an issue on node for discussion here: nodejs/node#46981
to see if this will be considered a bug. The elasticsearch client should change regardless.

a different failure

Actually there was also an internal node assertion failure when running the nightly v20 test in CI recently:
https://github.com/elastic/apm-agent-nodejs/actions/runs/4328506631/jobs/7558268956

node_tests_1     | # -- dev server tests --
node_tests_1     | # setup: start Next.js dev server (next dev)
node_tests_1     | # [sentinel=10 2023-03-04T01:06:45.055Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [Next.js server stderr] node[1734]: ../src/module_wrap.cc:599:v8::MaybeLocal<v8::Promise> node::loader::ImportModuleDynamically(v8::Local<v8::Context>, v8::Local<v8::Data>, v8::Local<v8::Value>, v8::Local<v8::String>, v8::Local<v8::FixedArray>): Assertion `(it) != (env->id_to_function_map.end())' failed.
node_tests_1     | # [Next.js server stderr]  1: 0xc09cf0 node::Abort() [node]
node_tests_1     | # | 2: 0xc09d6e  [node]
node_tests_1     | # [Next.js server stderr]  3: 0xbbe5b7  [node]
node_tests_1     | # | 4: 0xf7038f v8::internal::Isolate::RunHostImportModuleDynamicallyCallback(v8::internal::MaybeHandle<v8::internal::Script>, v8::internal::Handle<v8::internal::Object>, v8::internal::MaybeHandle<v8::internal::Object>) [node]
node_tests_1     | # | 5: 0x13e127b v8::internal::Runtime_DynamicImportCall(int, unsigned long*, v8::internal::Isolate*) [node]
node_tests_1     | # [Next.js server stderr]  6: 0x1849534  [node]
node_tests_1     | # [sentinel=9 2023-03-04T01:06:46.128Z] wait another 1s for server ready: read ECONNRESET
node_tests_1     | # [sentinel=8 2023-03-04T01:06:47.129Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=7 2023-03-04T01:06:48.131Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=6 2023-03-04T01:06:49.132Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=5 2023-03-04T01:06:50.133Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=4 2023-03-04T01:06:51.135Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=3 2023-03-04T01:06:52.136Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=2 2023-03-04T01:06:53.138Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | # [sentinel=1 2023-03-04T01:06:54.140Z] wait another 1s for server ready: connect ECONNREFUSED 127.0.0.1:3000
node_tests_1     | not ok 6 error waiting for Next.js server to be ready: timed out
node_tests_1     |   ---
node_tests_1     |     operator: fail
node_tests_1     |     at: <anonymous> (/app/test/instrumentation/modules/next/next.test.js:777:13)
node_tests_1     |     stack: |-
node_tests_1     |       Error: error waiting for Next.js server to be ready: timed out
node_tests_1     |           at Test.assert [as _assert] (/app/node_modules/tape/lib/test.js:312:48)

I'm not sure what this one is about, but I'll look out for it again.

@trentm trentm self-assigned this Mar 6, 2023
@github-actions github-actions bot added the agent-nodejs Make available for APM Agents project planning. label Mar 6, 2023
@trentm
Copy link
Member Author

trentm commented Mar 6, 2023

I've opened elastic/elastic-transport-js#59 for how the ES client should change.

@trentm
Copy link
Member Author

trentm commented Mar 9, 2023

Core node issue for this: nodejs/node#46981
and there is a PR that will resolve it, if merged.

@elastic/transport should still update to not emit an object with 'origin' and 'href', IMO.

@trentm
Copy link
Member Author

trentm commented Mar 31, 2023

Node has a fix, so the latest v20 nightlies pass again (https://github.com/elastic/apm-agent-nodejs/actions/workflows/edge.yml).

As well, elastic-transport-js has a fix in that will eventually get into an @elastic/elasticsearch module release. All good now.

@trentm trentm closed this as completed Mar 31, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
agent-nodejs Make available for APM Agents project planning.
Projects
None yet
Development

No branches or pull requests

1 participant