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

Getting warning during circuit breaker usage "Warning: Possible perf_hooks memory leak detected." #65

Open
abhinavgoel91 opened this issue Feb 9, 2022 · 2 comments

Comments

@abhinavgoel91
Copy link

abhinavgoel91 commented Feb 9, 2022

Node.js Version: v8.12.0

Operating System: Mac OS 10.14.6

Steps to Produce Error:

  1. Create a new directory mkdir test
  2. cd into the new directory cd test
  3. check if node version is 8.12.0 nvm ls
  4. run npm init npm init, use defaults
  5. Install expressjs npm install --save express
  6. Install opposum npm install --save opossum
  7. Install opposum prometheus npm install --save opossum-prometheus
  8. create a new file circuit_breaker_metrics.js touch circuit_breaker_metrics.js
  9. Add the following content to circuit_breaker_metrics.js -
'use strict'

const PrometheusMetrics = require('opossum-prometheus')
var prometheus = new PrometheusMetrics()

class CircuitBreakerMetrics {
  static registerOpossumCustomMetrics (funcName, circuit) {
    prometheus.add(circuit);
    ['success', 'timeout', 'reject', 'open', 'halfOpen', 'close', 'fallback'].forEach(function (event) {
      circuit.on(event, (result) => {
        console.log(`OPOSSUM_EVENT api: ${funcName} event: ${event} result: ${JSON.stringify(result)}`)
      })
    })
  }
}

module.exports = CircuitBreakerMetrics
  1. Create a new file circuit_breaker_test.js touch circuit_breaker_test.js
  2. Add the following code to circuit_breaker_test.js -
'use strict'

const CircuitBreaker = require('opossum')
var CircuitBreakerMetrics = require('./circuit_breaker_metrics')

async function randomErrorAsync () {
  if (Math.random() < 0.3) {
    console.error('Throwing random error')
    throw new Error('random error')
  } else {
    console.log('Returning a string')
    return 'abcd'
  }
}

let config = {
  timeout: 3600000, // really high timeout
  errorThresholdPercentage: 20, // When 20% of requests fail, trip the circuit
  resetTimeout: 30000, // After 30 seconds, try again.
  rollingCountTimeout: 60, // total number of seconds for which the stats are being maintained,
  rollingCountBuckets: 10 // buckets value is the number of slots in the window
}

var testBreaker = new CircuitBreaker(randomErrorAsync, config)

console.log(`testBreaker = ${testBreaker}`)
CircuitBreakerMetrics.registerOpossumCustomMetrics('circuit_breaker_test', testBreaker)

testBreaker.fallback(function (result) {
  console.error(`result = ${result === undefined ? undefined : JSON.stringify(result)}`)

  if (result === null || result === undefined || result.code === undefined) {
    console.error(`returning new Error('CIRCUIT_BRK')`)
    throw new Error('CIRCUIT_BRK')
  } else {
    console.error(`returning new Error('${result.code}')`)
    throw new Error(result.code)
  }
})

module.exports.testBreaker = testBreaker

module.exports.middleware = function (req, res, next) {
  try {
    testBreaker.fire()
      .then(function (result) {
        res.json({
          'result': result
        })
      })
      .catch(function (err) {
        console.error(err)
        res.json({
          'error': err.message
        })
      })
  } catch (ex) {
    res.json({
      'error': ex
    })
  }
}

process.on('warning', e => console.warn(e.stack))
  1. Create a new file server.js touch server.js
  2. Add the following code to server.js -
'use strict'

const express = require('express')
const app = express()
const port = 3000
const CircuitBreakerTest = require('./circuit_breaker_test')

app.get('/circuit_breaker_test', CircuitBreakerTest.middleware)

app.listen(port, () => {
  console.log(`Example app listening on port ${port}`)
})
  1. Run the app node server.js
  2. Make requests to the app curl -XGET 'http://localhost:3000/circuit_breaker_test'
  3. The code is designed to intentionally trip the circuit breaker by throwing error 30% of the time. Make repeated requests and trip the circuit breaker.
  4. After about 6 minutes, you'll see the issue logs. Here's the request logs -

$ abhinavgoel in ~ 
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"result":"abcd"}%

$ abhinavgoel in ~
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"result":"abcd"}%

$ abhinavgoel in ~
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"error":"CIRCUIT_BRK"}%

$ abhinavgoel in ~
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"error":"EOPENBREAKER"}%

$ abhinavgoel in ~
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"error":"EOPENBREAKER"}%

$ abhinavgoel in ~
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"error":"EOPENBREAKER"}%

$ abhinavgoel in ~
➜ curl -XGET 'http://localhost:3000/circuit_breaker_test'
{"result":"abcd"}%

  1. Here are the application logs -
$ abhinavgoel in ~/Documents/repos/test  C:1
➜ node server.js
testBreaker = [object Object]
Example app listening on port 3000
Returning a string
OPOSSUM_EVENT api: circuit_breaker_test event: success result: "abcd"
Returning a string
OPOSSUM_EVENT api: circuit_breaker_test event: success result: "abcd"
Throwing random error
OPOSSUM_EVENT api: circuit_breaker_test event: open result: undefined
result = {}
returning new Error('CIRCUIT_BRK')
Error: CIRCUIT_BRK
    at Function.<anonymous> (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:34:11)
    at fallback (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:756:10)
    at handleError (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:744:16)
    at promise.then.catch.error (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:630:17)
    at <anonymous>
    at runMicrotasksCallback (internal/process/next_tick.js:122:5)
    at _combinedTickCallback (internal/process/next_tick.js:132:7)
    at process._tickCallback (internal/process/next_tick.js:181:9)
OPOSSUM_EVENT api: circuit_breaker_test event: reject result: {"code":"EOPENBREAKER"}
result = {"code":"EOPENBREAKER"}
returning new Error('EOPENBREAKER')
Error: EOPENBREAKER
    at Function.<anonymous> (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:37:11)
    at fallback (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:756:10)
    at CircuitBreaker.call (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:574:14)
    at CircuitBreaker.fire (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:499:22)
    at module.exports.middleware (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:45:17)
    at Layer.handle [as handle_request] (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/layer.js:95:5)
    at next (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/route.js:137:13)
    at Route.dispatch (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/route.js:112:3)
    at Layer.handle [as handle_request] (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/layer.js:95:5)
    at /Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/index.js:281:22
OPOSSUM_EVENT api: circuit_breaker_test event: reject result: {"code":"EOPENBREAKER"}
result = {"code":"EOPENBREAKER"}
returning new Error('EOPENBREAKER')
Error: EOPENBREAKER
    at Function.<anonymous> (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:37:11)
    at fallback (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:756:10)
    at CircuitBreaker.call (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:574:14)
    at CircuitBreaker.fire (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:499:22)
    at module.exports.middleware (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:45:17)
    at Layer.handle [as handle_request] (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/layer.js:95:5)
    at next (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/route.js:137:13)
    at Route.dispatch (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/route.js:112:3)
    at Layer.handle [as handle_request] (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/layer.js:95:5)
    at /Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/index.js:281:22
OPOSSUM_EVENT api: circuit_breaker_test event: reject result: {"code":"EOPENBREAKER"}
result = {"code":"EOPENBREAKER"}
returning new Error('EOPENBREAKER')
Error: EOPENBREAKER
    at Function.<anonymous> (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:37:11)
    at fallback (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:756:10)
    at CircuitBreaker.call (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:574:14)
    at CircuitBreaker.fire (/Users/abhinavgoel/Documents/repos/test/node_modules/opossum/lib/circuit.js:499:22)
    at module.exports.middleware (/Users/abhinavgoel/Documents/repos/test/circuit_breaker_test.js:45:17)
    at Layer.handle [as handle_request] (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/layer.js:95:5)
    at next (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/route.js:137:13)
    at Route.dispatch (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/route.js:112:3)
    at Layer.handle [as handle_request] (/Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/layer.js:95:5)
    at /Users/abhinavgoel/Documents/repos/test/node_modules/express/lib/router/index.js:281:22
OPOSSUM_EVENT api: circuit_breaker_test event: halfOpen result: 30000
Returning a string
OPOSSUM_EVENT api: circuit_breaker_test event: close result: undefined
OPOSSUM_EVENT api: circuit_breaker_test event: success result: "abcd"
(node:79589) Warning: Possible perf_hooks memory leak detected. There are 151 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
Warning: Possible perf_hooks memory leak detected. There are 151 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
    at Performance.[index-entry] (perf_hooks.js:444:15)
    at Performance.[insert-entry] (perf_hooks.js:288:22)
    at process.observersCallback (perf_hooks.js:597:28)
(node:79589) Warning: Possible perf_hooks memory leak detected. There are 152 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
Warning: Possible perf_hooks memory leak detected. There are 152 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
    at Performance.[index-entry] (perf_hooks.js:444:15)
    at Performance.[insert-entry] (perf_hooks.js:288:22)
    at process.observersCallback (perf_hooks.js:597:28)
(node:79589) Warning: Possible perf_hooks memory leak detected. There are 153 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
Warning: Possible perf_hooks memory leak detected. There are 153 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
    at Performance.[index-entry] (perf_hooks.js:444:15)
    at Performance.[insert-entry] (perf_hooks.js:288:22)
    at process.observersCallback (perf_hooks.js:597:28)
(node:79589) Warning: Possible perf_hooks memory leak detected. There are 154 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
Warning: Possible perf_hooks memory leak detected. There are 154 entries in the Performance Timeline. Use the clear methods to remove entries that are no longer needed or set performance.maxEntries equal to a higher value (currently the maxEntries is 150).
    at Performance.[index-entry] (perf_hooks.js:444:15)
    at Performance.[insert-entry] (perf_hooks.js:288:22)
    at process.observersCallback (perf_hooks.js:597:28)

The above warning is confusing me. Is it because of some issue opposum or opposum-prometheus ?

@abhinavgoel91
Copy link
Author

Reading about NodeJS Performance Timeline, and searching for "perf_hooks" in the code I get this -

➜ grep -rn "perf_hooks" .
./node_modules/prom-client/lib/metrics/gc.js:4:let perf_hooks;
./node_modules/prom-client/lib/metrics/gc.js:8:	perf_hooks = require('perf_hooks');
./node_modules/prom-client/lib/metrics/gc.js:17:kinds[perf_hooks.constants.NODE_PERFORMANCE_GC_MAJOR] = 'major';
./node_modules/prom-client/lib/metrics/gc.js:18:kinds[perf_hooks.constants.NODE_PERFORMANCE_GC_MINOR] = 'minor';
./node_modules/prom-client/lib/metrics/gc.js:19:kinds[perf_hooks.constants.NODE_PERFORMANCE_GC_INCREMENTAL] = 'incremental';
./node_modules/prom-client/lib/metrics/gc.js:20:kinds[perf_hooks.constants.NODE_PERFORMANCE_GC_WEAKCB] = 'weakcb';
./node_modules/prom-client/lib/metrics/gc.js:23:	if (!perf_hooks) {
./node_modules/prom-client/lib/metrics/gc.js:40:	const obs = new perf_hooks.PerformanceObserver(list => {
./node_modules/prom-client/lib/metrics/eventLoopLag.js:5:// Check if perf_hooks module is available
./node_modules/prom-client/lib/metrics/eventLoopLag.js:6:let perf_hooks;
./node_modules/prom-client/lib/metrics/eventLoopLag.js:9:	perf_hooks = require('perf_hooks');
./node_modules/prom-client/lib/metrics/eventLoopLag.js:18:// Reported only when perf_hooks is available.
./node_modules/prom-client/lib/metrics/eventLoopLag.js:80:	if (!perf_hooks || !perf_hooks.monitorEventLoopDelay) {
./node_modules/prom-client/lib/metrics/eventLoopLag.js:87:	const histogram = perf_hooks.monitorEventLoopDelay({

And searching for "prom-client" gives this -

➜ grep -rn "prom-client" .
./node_modules/tdigest/package.json:19:    "/prom-client"
./node_modules/tdigest/package.json:24:  "_where": "/Users/abhinavgoel/Documents/repos/test/node_modules/prom-client",
./node_modules/opossum-prometheus/test/prometheus-test.js:6:const client = require('prom-client');
./node_modules/opossum-prometheus/test/prometheus-test.js:64:test('The factory function uses a custom prom-client registry', async t => {
./node_modules/opossum-prometheus/index.js:3:const client = require('prom-client');
./node_modules/opossum-prometheus/README.md:45:[prom-client](https://github.com/siimon/prom-client) registry.
./node_modules/opossum-prometheus/README.md:48:The [default metrics](https://github.com/siimon/prom-client#default-metrics)
./node_modules/opossum-prometheus/README.md:54:const { Registry } = require('prom-client');
./node_modules/opossum-prometheus/package.json:31:    "prom-client": "^12.0.0"
./node_modules/prom-client/CHANGELOG.md:276:[unreleased]: https://github.com/siimon/prom-client/compare/v10.2.2...HEAD
./node_modules/prom-client/CHANGELOG.md:277:[10.2.2]: https://github.com/siimon/prom-client/compare/v10.2.1...v10.2.2
./node_modules/prom-client/CHANGELOG.md:278:[10.2.1]: https://github.com/siimon/prom-client/compare/v10.2.0...v10.2.1
./node_modules/prom-client/CHANGELOG.md:279:[10.2.0]: https://github.com/siimon/prom-client/compare/v10.1.1...v10.2.0
./node_modules/prom-client/CHANGELOG.md:280:[10.1.1]: https://github.com/siimon/prom-client/compare/v10.1.0...v10.1.1
./node_modules/prom-client/CHANGELOG.md:281:[10.1.0]: https://github.com/siimon/prom-client/compare/v10.0.4...v10.1.0
./node_modules/prom-client/CHANGELOG.md:282:[10.0.4]: https://github.com/siimon/prom-client/compare/v10.0.3...v10.0.4
./node_modules/prom-client/CHANGELOG.md:283:[10.0.3]: https://github.com/siimon/prom-client/compare/v10.0.2...v10.0.3
./node_modules/prom-client/CHANGELOG.md:284:[10.0.2]: https://github.com/siimon/prom-client/compare/v10.0.1...v10.0.2
./node_modules/prom-client/CHANGELOG.md:285:[10.0.1]: https://github.com/siimon/prom-client/compare/v10.0.0...v10.0.1
./node_modules/prom-client/CHANGELOG.md:286:[10.0.0]: https://github.com/siimon/prom-client/compare/v9.1.1...v10.0.0
./node_modules/prom-client/CHANGELOG.md:287:[9.1.1]: https://github.com/siimon/prom-client/compare/v9.1.0...v9.1.1
./node_modules/prom-client/CHANGELOG.md:288:[9.1.0]: https://github.com/siimon/prom-client/compare/v9.0.0...v9.1.0
./node_modules/prom-client/CHANGELOG.md:289:[9.0.0]: https://github.com/siimon/prom-client/commit/1ef835f908e1a5032f228bbc754479fe7ccf5201
./node_modules/prom-client/README.md:1:# Prometheus client for node.js [![Build Status](https://travis-ci.org/siimon/prom-client.svg?branch=master)](https://travis-ci.org/siimon/prom-client) [![Build status](https://ci.appveyor.com/api/projects/status/k2e0gwonkcee3lp9/branch/master?svg=true)](https://ci.appveyor.com/project/siimon/prom-client/branch/master) [![Actions Status](https://github.com/siimon/prom-client/workflows/Node.js%20CI/badge.svg?branch=master)](https://github.com/siimon/prom-client/actions)
./node_modules/prom-client/README.md:64:const client = require('prom-client');
./node_modules/prom-client/README.md:75:const client = require('prom-client');
./node_modules/prom-client/README.md:85:const client = require('prom-client');
./node_modules/prom-client/README.md:102:const client = require('prom-client');
./node_modules/prom-client/README.md:123:const client = require('prom-client');
./node_modules/prom-client/README.md:136:const client = require('prom-client');
./node_modules/prom-client/README.md:150:const client = require('prom-client');
./node_modules/prom-client/README.md:180:const client = require('prom-client');
./node_modules/prom-client/README.md:191:const client = require('prom-client');
./node_modules/prom-client/README.md:203:const client = require('prom-client');
./node_modules/prom-client/README.md:230:const client = require('prom-client');
./node_modules/prom-client/README.md:242:const client = require('prom-client');
./node_modules/prom-client/README.md:258:const client = require('prom-client');
./node_modules/prom-client/README.md:282:const client = require('prom-client');
./node_modules/prom-client/README.md:312:const client = require('prom-client');
./node_modules/prom-client/README.md:332:at `require('prom-client').register`). You can prevent this by setting last
./node_modules/prom-client/README.md:345:const client = require('prom-client');
./node_modules/prom-client/README.md:430:const client = require('prom-client');
./node_modules/prom-client/README.md:454:const client = require('prom-client');
./node_modules/prom-client/package.json:2:  "_from": "prom-client@^12.0.0",
./node_modules/prom-client/package.json:3:  "_id": "[email protected]",
./node_modules/prom-client/package.json:6:  "_location": "/prom-client",
./node_modules/prom-client/package.json:11:    "raw": "prom-client@^12.0.0",
./node_modules/prom-client/package.json:12:    "name": "prom-client",
./node_modules/prom-client/package.json:13:    "escapedName": "prom-client",
./node_modules/prom-client/package.json:21:  "_resolved": "https://registry.npmjs.org/prom-client/-/prom-client-12.0.0.tgz",
./node_modules/prom-client/package.json:23:  "_spec": "prom-client@^12.0.0",
./node_modules/prom-client/package.json:29:    "url": "https://github.com/siimon/prom-client/issues"
./node_modules/prom-client/package.json:59:  "homepage": "https://github.com/siimon/prom-client",
./node_modules/prom-client/package.json:81:  "name": "prom-client",
./node_modules/prom-client/package.json:102:    "url": "git+ssh://[email protected]/siimon/prom-client.git"
./node_modules/prom-client/package.json:119:      "pkgid": "[email protected]"
./node_modules/prom-client/lib/cluster.js:22:const GET_METRICS_REQ = 'prom-client:getMetricsReq';
./node_modules/prom-client/lib/cluster.js:23:const GET_METRICS_RES = 'prom-client:getMetricsRes';
./node_modules/prom-client/index.d.ts:1:// Type definitions for prom-client
./package-lock.json:261:        "prom-client": "^12.0.0"
./package-lock.json:274:    "prom-client": {
./package-lock.json:276:      "resolved": "https://registry.npmjs.org/prom-client/-/prom-client-12.0.0.tgz",

So it's the opposum-prometheus library which is using prom-client, which uses NodeJS Performance Timeline. Why is is this warning being printed? Because metrics haven't been collected from the timeline?

@abhinavgoel91
Copy link
Author

After reading this issue - siimon/prom-client#429
& this issue - bfmatei/apollo-prometheus-exporter#17

It's seems like something related to Node 8.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant