RuntimeTools / appmetrics

Node Application Metrics provides a foundational infrastructure for collecting resource and performance monitoring data for Node.js-based applications.
https://developer.ibm.com/open/node-application-metrics/
Apache License 2.0
970 stars 125 forks source link

Including appmetrics breaks promisified setTimeout #634

Open CherryDT opened 4 years ago

CherryDT commented 4 years ago

node v12.10.0, appmetrics v5.1.1

Test case:

'use strict'

const { promisify } = require('util')
const delay = promisify(setTimeout)

async function main () {
  console.log('Hello...')
  await delay(1000)
  console.log('...world!')
}

main().then(() => process.exit(0), e => { console.error(e); process.exit(1) })

Result without appmetrcis:

david@CHE-X1:~/z/Temp/appmetrics-test $ node index.js 
Hello...
...world!

Result with appmetrics:

david@CHE-X1:~/z/Temp/appmetrics-test $ node --require appmetrics/start index.js
[Sat Mar 14 16:15:16 2020] com.ibm.diagnostics.healthcenter.loader INFO: Node Application Metrics 5.1.1.202003141613 (Agent Core 4.0.5)
[Sat Mar 14 16:15:16 2020] com.ibm.diagnostics.healthcenter.mqtt INFO: Connecting to broker localhost:1883
Hello...
TypeError [ERR_INVALID_CALLBACK]: Callback must be a function. Received 1000
    at setTimeout (timers.js:118:11)
    at fallback (/mnt/c/Users/david/Temp/appmetrics-test/node_modules/async-listener/index.js:621:15)
    at /mnt/c/Users/david/Temp/appmetrics-test/node_modules/async-listener/index.js:651:53
    at internal/util.js:277:30
    at new WrappedPromise (/mnt/c/Users/david/Temp/appmetrics-test/node_modules/async-listener/es6-wrapped-promise.js:13:18)
    at internal/util.js:276:12
    at main (/mnt/c/Users/david/Temp/appmetrics-test/index.js:8:9)
    at Object.<anonymous> (/mnt/c/Users/david/Temp/appmetrics-test/index.js:12:1)
    at Module._compile (internal/modules/cjs/loader.js:936:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:947:10)

It seems as if for some reason promisify would not respect setTimeout's custom util.promisify.custom handler in this case!

EDIT: After further testing, it seems that after including appmetrics/start, for some reason setTimeout and setImmediate are now missing the util.promisify.custom symbol property entirely! Also, confusingly, this does not happen when I do it from a node REPL.

BannerBomb commented 4 years ago

Same here for Node v13.0.1. But it's the async-listener package that's causing this since it's overriding the core Promise class with a custom one WrappedPromise.

`-- appmetrics@5.1.1
  `-- ibmapm-embed@20.3.0
    `-- zipkin-context-cls@0.6.1
      `-- continuation-local-storage@3.2.1
        `-- async-listener@0.6.10

this is the dependency package list for which package requires what ending at the async-listener package.

But as a work around you can try using

const wait = ms => new Promise(_ => setTimeout(_, ms));

instead of the promisify package on setTimeout