fix: ensure correct run context for 'mongodb-core' instrumentation

[trentm]

Refs: #2430

Checklist

• Implement code
• Add tests
• Add CHANGELOG.asciidoc entry
• Commit message follows commit guidelines

[trentm]

Here are the test failures before the fix (but with the additions to the test file):

% node test/instrumentation/modules/mongodb-core.test.js
TAP version 13
# instrument simple command
not ok 1 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: Server.<anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:138:7)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Server.<anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:138:7)
          at Server.emit (events.js:314:20)
          at Pool.<anonymous> (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/topologies/server.js:377:12)
          at Pool.emit (events.js:314:20)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:602:10
          at callback (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/connect.js:109:5)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/connect.js:172:5
          at Connection.messageHandler (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/connect.js:334:5)
          at Connection.emit (events.js:314:20)
          at processMessage (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/connection.js:364:10)
          at Socket.<anonymous> (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/connection.js:533:15)
          at Socket.emit (events.js:314:20)
          at addChunk (_stream_readable.js:297:12)
          at readableAddChunk (_stream_readable.js:272:9)
          at Socket.Readable.push (_stream_readable.js:213:10)
          at TCP.onStreamRead (internal/stream_base_commons.js:188:23)
          at TCP.callbackTrampoline (internal/async_hooks.js:126:14)
  ...
ok 2 no error from system.$cmd
ok 3 result.ismaster
not ok 4 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: <anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:136:9)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:136:9
          at wrappedCallback (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:64:19)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:397:18
          at processTicksAndRejections (internal/process/task_queues.js:79:11)
  ...
ok 5 no error from insert
ok 6 should be strictly equal
not ok 7 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: <anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:134:11)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:134:11
          at wrappedCallback (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:93:19)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:397:18
          at processTicksAndRejections (internal/process/task_queues.js:79:11)
  ...
ok 8 no error from update
ok 9 should be strictly equal
not ok 10 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: <anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:132:13)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:132:13
          at wrappedCallback (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:93:19)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:397:18
          at processTicksAndRejections (internal/process/task_queues.js:79:11)
  ...
ok 11 no error from remove
ok 12 should be strictly equal
not ok 13 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: <anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:130:15)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:130:15
          at wrappedCallback (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:93:19)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:397:18
          at processTicksAndRejections (internal/process/task_queues.js:79:11)
  ...
ok 14 no error from cursor.next
ok 15 doc.a
ok 16 no error from cursor.next
ok 17 doc.a
not ok 18 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: <anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:126:19)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:126:19
          at handleCallback (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:204:5)
          at nextFunction (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:578:5)
          at Cursor.next (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:766:3)
          at Cursor.wrappedFunction [as next] (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:121:19)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:111:22
          at wrappedCallback (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:126:19)
          at handleCallback (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:204:5)
          at nextFunction (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:578:5)
          at done (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:653:7)
          at queryCallback (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:701:18)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:397:18
          at processTicksAndRejections (internal/process/task_queues.js:79:11)
  ...
not ok 19 no currentSpan in sync code after mongodb-core client command
  ---
    operator: ok
    expected: true
    actual:   false
    at: <anonymous> (/Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:128:17)
    stack: |-
      Error: no currentSpan in sync code after mongodb-core client command
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:314:54)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at Test.assert (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:433:10)
          at Test.bound [as ok] (/Users/trentm/el/apm-agent-nodejs6/node_modules/tape/lib/test.js:99:32)
          at /Users/trentm/el/apm-agent-nodejs6/test/instrumentation/modules/mongodb-core.test.js:128:17
          at wrappedCallback (/Users/trentm/el/apm-agent-nodejs6/lib/instrumentation/modules/mongodb-core.js:126:19)
          at handleCallback (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:204:5)
          at nextFunction (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:578:5)
          at done (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:653:7)
          at queryCallback (/Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/cursor.js:701:18)
          at /Users/trentm/el/apm-agent-nodejs6/node_modules/mongodb-core/lib/connection/pool.js:397:18
          at processTicksAndRejections (internal/process/task_queues.js:79:11)
  ...
ok 20 no error from system.$cmd
ok 21 no currentSpan in sync code after mongodb-core client command
ok 22 should be strictly equal
ok 23 transaction.name
ok 24 transaction.type
ok 25 transaction.result
ok 26 captured span has expected name: system.$cmd.ismaster
ok 27 span has expected type
ok 28 span has expected subtype
ok 29 span has expected action
ok 30 span is a direct child of transaction
ok 31 span ends (1643152423185.186ms) before the transaction (1643152423210.584ms)
ok 32 captured span has expected name: elasticapm.test.insert
ok 33 span has expected type
ok 34 span has expected subtype
ok 35 span has expected action
ok 36 span is a direct child of transaction
ok 37 span ends (1643152423190.626ms) before the transaction (1643152423210.584ms)
ok 38 captured span has expected name: elasticapm.test.update
ok 39 span has expected type
ok 40 span has expected subtype
ok 41 span has expected action
ok 42 span is a direct child of transaction
ok 43 span ends (1643152423194.829ms) before the transaction (1643152423210.584ms)
ok 44 captured span has expected name: elasticapm.test.remove
ok 45 span has expected type
ok 46 span has expected subtype
ok 47 span has expected action
ok 48 span is a direct child of transaction
ok 49 span ends (1643152423198.1ms) before the transaction (1643152423210.584ms)
ok 50 captured span has expected name: elasticapm.test.find
ok 51 span has expected type
ok 52 span has expected subtype
ok 53 span has expected action
ok 54 span is a direct child of transaction
ok 55 span ends (1643152423203.271ms) before the transaction (1643152423210.584ms)
ok 56 captured span has expected name: system.$cmd.ismaster
ok 57 span has expected type
ok 58 span has expected subtype
ok 59 span has expected action
ok 60 span is a direct child of transaction
ok 61 span ends (1643152423210.336ms) before the transaction (1643152423210.584ms)

1..61
# tests 61
# pass  54
# fail  7

[apmmachine]

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

• Reason: null

• Start Time: 2022-01-26T01:08:06.529+0000

• Duration: 68 min 46 sec

• Commit: 519b4d4

Test stats 🧪

Test	Results
Failed	0
Passed	243379
Skipped	0
Total	243379

🤖 GitHub comments

To re-run your PR in the CI, just comment with:

• /test : Re-trigger the build.

• run module tests for <modules> : Run TAV tests for one or more modules, where <modules> can be either a comma separated list of modules (e.g. memcached,redis) or the string literal ALL to test all modules

• run benchmark tests : Run the benchmark test only.

• run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

[trentm]

run module tests for mongodb-core