Giter Club home page Giter Club logo

pinpoint-node-agent's People

Contributors

beanmilk avatar feelform avatar upgle avatar wormslab avatar

Stargazers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

Watchers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

pinpoint-node-agent's Issues

http params (query string) not visible

Hi.
I'm testing several things to apply Pinpoint Node Agent to my company's project.
It wasn't a problem because I fully understood what some functions didn't do.

However, not seeing the request parameter is a big problem for me.
As with JVM monitoring, how do I see the request parameter at the pinpoint?
I would like to ask if a separate setting work is needed or if feature development is necessary.

Expected Behavior

image

Current Behavior

image

gRPC large scale Message OOM issue Test

  • Test for OOM issues when sending a large number of messages to the gRPC stream.

  • Change gRPC library on Node.js from C-based Client to Pure JavaScript Client.

https://github.com/feelform/pinpoint-node-agent/blob/5ffd5f7d2f27decb8d7877df61671395762a1281/test/client/grpc-stream.test.js#L27
node: v12.18.2

~/.nodenv/shims/node ./test/client/grpc-stream.test.js
TAP version 13
node_modules/tape/lib/default_stream.js:25
# client side streaming
node_modules/tape/lib/default_stream.js:25
968522 dealy
test/client/grpc-stream.test.js:28
ok 1 Message count is 1000000
node_modules/tape/lib/default_stream.js:25
31478 dealy
test/client/grpc-stream.test.js:28

node_modules/tape/lib/default_stream.js:25
1..1
node_modules/tape/lib/default_stream.js:25
# tests 1
node_modules/tape/lib/default_stream.js:25
# pass  1
node_modules/tape/lib/default_stream.js:25

node_modules/tape/lib/default_stream.js:25
# ok

Implement profiler.node.excludeurl

Hello, is there any way to exclude some urls from profiling, in the same way it can be done for instance with profiler.tomcat.excludeurl on the Java agent?

If not, do you plan to implement such a feature in the near future?

Thank you very much for your work

Unable to see MongoDB connection and traces

Hi There,

I am trying to setup node pinpoint agent in our application and installed it using NPM module (https://www.npmjs.com/package/pinpoint-node-agent ).

The environment variable in Node container looks like this.

PINPOINT_COLLECTOR_IP=XX.XX.XX.XX
YARN_VERSION=1.22.5
PINPOINT_LOG_LEVEL=DEBUG
TZ=Europe/London
HOSTNAME=d61295eec157
PINPOINT_SAMPLING_RATE=10
NODE_DIR=/opt/node-server
NODE_ENV=production
PWD=/opt/node-server
HOME=/home/node
PINPOINT_APPLICATION_NAME=NODE-APP
PORT=3001
PINPOINT_ENABLE=true
NODE_VERSION=14.16.0
PINPOINT_CONTAINER=true
PINPOINT_AGENT_ID=NODEJS-V3

Now, I can see the node container in pinpoint web GUI and can see the user connections coming to the node server, But I am unable to trace those connections afterward ( like where it's connecting Example - MongoDB ) and how much time it is taking there,etc.

I have used pinpoint with other Java applications and I usually see if it's connected to DB node and how much time it is taking for each call, and I am expecting the same with Node module, So I wanted to check is it supported?

Many thanks,

Inspector issue with CPU usage

Hello,
We have 2 agents running on the same machine: one is the classic Java Agent, the other one is the new Node Agent. We noticed in the inspector that the CPU usage data is not properly "merged".

In the inspector of the Java application, this is the CPU usage:
image
Very low, but not zero for both System and JVM.

In the inspector of the Node application, installed on the very same machine, this is the CPU usage:
image
Constantly 0.0%.

To my understanding, at least the CPU usage of the Java application should have been shown in the Node application CPU usage diagram as "System" CPU usage. This does not happens and the CPU usage in the Node application shows a flat 0.0%, despite having for sure some usage on the CPU by the other monitored Java application.

Am i misunderstanding something or this could possibly be a bug (or maybe just a feature that still needs to be implemented)?

fix a npm audit security report

❯ npm audit
                                                                                
                       === npm audit security report ===                        
                                                                                
# Run  npm install [email protected]  to resolve 1 vulnerability
SEMVER WARNING: Recommended action is a potentially breaking change
┌───────────────┬──────────────────────────────────────────────────────────────┐
│ Low           │ Regular Expression Denial of Service                         │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ Package       │ braces                                                       │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ Dependency of │ find-node-modules                                            │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ Path          │ find-node-modules > findup-sync > micromatch > braces        │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ More info     │ https://npmjs.com/advisories/786                             │
└───────────────┴──────────────────────────────────────────────────────────────┘


found 1 low severity vulnerability in 644 scanned packages
  1 vulnerability requires semver-major dependency updates.

Ping logs validation


2021.03.18 17:02:03 +09:00 | Agent shutdown |  
2021.03.18 18:25:52 +09:00 | Agent connected |  
2021.03.18 18:25:52 +09:00 | Agent connected |  
2021.03.18 19:53:58 +09:00 | Agent shutdown |  
2021.03.18 19:54:56 +09:00 | Agent connected |  
2021.03.18 19:54:56 +09:00 | Agent connected |  
2021.03.18 19:58:30 +09:00 | Agent shutdown |  
2021.03.18 19:58:31 +09:00 | Agent connected |  
2021.03.18 19:58:31 +09:00 | Agent connected

HTTP param

Fix config.js load modules error

cause: f46a878

Fixed:

$ npm info pinpoint-node-agent

[email protected] | Apache-2.0 | deps: 12 | versions: 2
Pinpoint node agent provided by NAVER
https://github.com/pinpoint-apm/pinpoint-node-agent

keywords: pinpoint, log, logging, bug, bugs, error, errors, exception, exceptions, catch, monitor, monitoring, alert, alerts, performance, apm, ops, devops, stacktrace, trace, tracing, distributedtracing, distributed-tracing

dist
.tarball: https://registry.npmjs.org/pinpoint-node-agent/-/pinpoint-node-agent-0.7.1.tgz
.shasum: 3bfc58927ed146b1b4b347ee88ca0d9808c5b148
.integrity: sha512-3Vq9qncgVeib/Gfrh+RJnV/gmKNBjynaT26LQugCVfcppRUs4TdywfdJCQmoQ0MKNQepOX6tNBkA8qgWh/ysTQ==
.unpackedSize: 663.3 kB

dependencies:
end-of-stream: ^1.4.1         google-protobuf: ^3.13.0      int64-buffer: ^0.99.1007      loglevel: ^1.6.1              require-in-the-middle: ^5.0.3 shimmer: ^1.2.0               
find-node-modules: ^1.0.4     grpc: ^1.24.3                 internal-ip: ^3.0.1           methods: ^1.1.2               semver: ^5.6.0                utf-8-validate: ^5.0.2        

maintainers:
- feelform <[email protected]>
- npm.pinpoint.naver <[email protected]>

dist-tags:
latest: 0.7.1   rc: 0.7.0-rc.0  

published 19 minutes ago by feelform <[email protected]>

express error handler depth and error messages

11.30 Integration Test

  • 1. Error is include Error

Screen Shot 2021-11-30 at 6 51 07 PM

  • 2. Error call stack show in arguments

Screen Shot 2021-11-30 at 6 51 20 PM

Resolved

Representing all callstacks is out of specification. So, the location where the exception occurred was modified to be delivered along with the error message.
Screen Shot 2021-12-03 at 10 50 17 PM

Support Ant style excludeurl

Issue

Issue: #1
Pinpoint Ant-style excludeURL: pinpoint-apm/pinpoint#138

Ant Path Matcher: https://www.npmjs.com/package/ant-path-matcher

  • Ant path matcher is well implemented, but there is no test and pattern cache function implementation is needed.

Spring framework

Spring framework's ant path matcher was verifiable by unit test of Java language, and regular expression-based logic is easy to transfer to Node.js.

spring framework: https://github.com/spring-projects/spring-framework/blob/master/spring-core/src/main/java/org/springframework/util/AntPathMatcher.java
test: https://github.com/spring-projects/spring-framework/blob/master/spring-core/src/test/java/org/springframework/util/AntPathMatcherTests.java

Performance

In an application that does not include a query string in the pathname of the URL, the same pathname is matched each time.

Reduce RegExp match count

Map in Node.js has a Iterator object that contains an array of [key, value] for each element in the Map object in insertion order. However, rather than adding a cache-dependent library, we examined whether the built-in module can be used as a cache.
ref: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Map

Map Insertion order learning test

test('map insertion order learning test', (t) => {
    const map1 = new Map();

    map1.set('0', 'foo');
    map1.set(1, 'bar');

    let iterator1 = map1[Symbol.iterator]();

    let index = 0
    for (const item of iterator1) {
        if (index == 0) {
            t.equal(item[0], '0', 'key match')
            t.equal(item[1], 'foo', 'value match')
        }
        if (index == 1) {
            t.equal(item[0], 1, 'key match')
            t.equal(item[1], 'bar', 'value match')
        }
        index++
    }

    map1.set('0', 'foo');
    map1.set(1, 'bar');
    map1.delete('0')
    map1.set('0', 'foo2');
    iterator1 = map1[Symbol.iterator]();
    index = 0
    for (const item of iterator1) {
        if (index == 0) {
            t.equal(item[0], 1, 'key match')
            t.equal(item[1], 'bar', 'value match')
        }
        if (index == 1) {
            t.equal(item[0], '0', 'key match')
            t.equal(item[1], 'foo2', 'value match')
        }
        index++
    }

    // get order
    const cache = Array.from(map1)
    t.deepEqual(cache[0], [1, 'bar'], 'key match')
    t.deepEqual(cache[1], ['0', 'foo2'], 'key match')

    // remove low hit count
    map1.delete(1)
    t.equal(map1.size, 1)

    iterator1 = map1[Symbol.iterator]();
    index = 0
    for (const item of iterator1) {
        if (index == 0) {
            t.equal(item[0], '0', 'key match')
            t.equal(item[1], 'foo2', 'value match')
        }
        index++
    }

    t.end()
})

To fix

for ENV

PINPOINT_TRACE_EXCLUSION_URL_PATTERN=/health_check,/health_check/***
PINPOINT_TRACE_EXCLUSION_URL_CACHE_SIZE=100

for JSON

    "trace-exclusion-url": {
        "pattern": ["/heath_check?/**", "/api"],
        "cache-size": 100
    }

Fix ERR_STREAM_WRITE_AFTER_END on Node v14

There is an uncatch exception on Node v14.15.3.

Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at ClientHttp2Stream.Writable.write (internal/streams/writable.js:292:11)

Node v14.15.3
https://github.com/nodejs/node/blob/e725355e5cdd77ac9287dea9c0d2958c994e8c27/lib/internal/streams/writable.js#L292

Backpressuring in Streams: https://nodejs.org/en/docs/guides/backpressuring-in-streams/

at Apr 6 2:46 PM

pinpoint-node-agent> npm test
ok 209 index: 1 call.write in call.write callback 
node_modules/tape/lib/default_stream.js:25
statStream callback err: Error: 4 DEADLINE_EXCEEDED: Deadline exceeded in statClient.sendAgentStat callback
lib/utils/logger.js:59
ok 210 error code grpc.status.DEADLINE_EXCEEDED in statClient.sendAgentStat callback
node_modules/tape/lib/default_stream.js:25
ok 211 index: 2 call.write in call.write callback 
node_modules/tape/lib/default_stream.js:25
Uncaught Error [ERR_STREAM_WRITE_AFTER_END]: write after end
Process exited with code 1

when stream emit error event, EventEmitter object should listen on('error') event.

EventEmitter.prototype.emit = function emit(type, ...args) {
  let doError = (type === 'error');

  const events = this._events;
  if (events !== undefined) {
    if (doError && events[kErrorMonitor] !== undefined)
      this.emit(kErrorMonitor, ...args);
    doError = (doError && events.error === undefined);
  } else if (!doError)
    return false;

  // If there is no 'error' event listener then throw.
  if (doError) {
    let er;
    if (args.length > 0)
      er = args[0];
    if (er instanceof Error) {
      try {
        const capture = {};
        // eslint-disable-next-line no-restricted-syntax
        Error.captureStackTrace(capture, EventEmitter.prototype.emit);
        ObjectDefineProperty(er, kEnhanceStackBeforeInspector, {
          value: enhanceStackTrace.bind(this, er, capture),
          configurable: true
        });
      } catch {}

      // Note: The comments on the `throw` lines are intentional, they show
      // up in Node's output if this results in an unhandled exception.
      throw er; // Unhandled 'error' event
    }

If it detects that the app is using core-js v2.4 or lower, disable the function using the v8 module.

Issue

When the Node agent is initialized in an app that uses core-js v2.4 or lower, a crash occurs when the ArrayBuffer is initialized in the request('v8') statement.

RangeError: Wrong length!
 at validateArrayBufferArguments
 at new ArrayBuffer
 at v8.js:132:17

Cause

Node v8.16.0 v8 module

{
  const dummy = new ArrayBuffer(); <===  v8.js:132:17 new ArrayBuffer();
  for (const [i, ctor] of arrayBufferViewTypes.entries()) {
    const tag = objectToString(new ctor(dummy));
    arrayBufferViewTypeToIndex.set(tag, i);
  }
}

ECMA 2016 7ᵗʰ Edition / June 2016 Language specification
http://www.ecma-international.org/ecma-262/7.0/#sec-arraybuffer-length

24.1.2.1ArrayBuffer ( length )#

ArrayBuffer called with argument length performs the following steps:

If NewTarget is undefined, throw a TypeError exception.
Let numberLength be ? ToNumber(length).
Let byteLength be ToLength(numberLength).
If SameValueZero(numberLength, byteLength) is false, throw a RangeError exception.
Return ? AllocateArrayBuffer(NewTarget, byteLength).

https://github.com/tc39/ecma262/releases/tag/es2016-draft-201607-25

Normative Changes
TypedArray, ArrayBuffer, and DataView now have unified, consistent handling of index and offset parameters (https://github.com/tc39/ecma262/pull/410)

core-js patch
zloirock/core-js@1392087#diff-7deab69eb25571172ae510e655a30cc0396947274d759414898ff616f23046baL2704
Screen Shot 2020-11-02 at 3 15 25 PM

fixed bug task: zloirock/core-js#293 (comment)

To fix

If it detects that the node agent is using core-js v2.4 or lower, disable the function related to the v8 module and do not call require('v8').

webpack compatibility

In Node with Webpack, if the Pinpoint Node agent cannot hook the HTTP module, it is the case that http.createServer is called first in the JS code compiled by webpack.

❯ node -r pinpoint-node-agent src/bin/www.js
/pinpoint/pinpoint-node-agent/lib/config.js:14
const ROOT_PATH = path.dirname(require.main.filename || process.mainModule.filename)
                                            ^

TypeError: Cannot read property 'filename' of undefined
    at Object.<anonymous> (/pinpoint/pinpoint-node-agent/lib/config.js:14:45)
    at Module._compile (internal/modules/cjs/loader.js:1138:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1158:10)
    at Module.load (internal/modules/cjs/loader.js:986:32)
    at Function.Module._load (internal/modules/cjs/loader.js:879:14)
    at Module.require (internal/modules/cjs/loader.js:1026:19)
    at require (internal/modules/cjs/helpers.js:72:18)
    at Object.<anonymous> (/pinpoint/pinpoint-node-agent/lib/agent.js:16:19)
    at Module._compile (internal/modules/cjs/loader.js:1138:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:1158:10)

require.main: https://nodejs.org/api/modules.html#modules_require_main

Module {id: '.', path: '/pinpoint/pinpoint-agent-node/samples/express/src/bin', exports: {…}, parent: null, filename: '/pinpoint/pinpoint-agent-node/samples/express/src/bin/www.js', …}

requestAgentInfo err: Error: 14 UNAVAILABLE: No connection established

Getting below error while running demo app
Node version: v14.15.4
NPM version: v6.14.10
Pinpoint node agent: v0.8.2

Error: 14 UNAVAILABLE: No connection established
at Object.callErrorFromStatus (/Users/workspace/demo/node_modules/pinpoint-node-agent/node_modules/@grpc/grpc-js/src/call.ts:81:24)
at Object.onReceiveStatus (/Users/workspace/demo/node_modules/pinpoint-node-agent/node_modules/@grpc/grpc-js/src/client.ts:338:36)
at Object.onReceiveStatus (/Users/workspace/demo/node_modules/pinpoint-node-agent/node_modules/@grpc/grpc-js/src/client-interceptors.ts:426:34)
at Object.onReceiveStatus (/Users/workspace/demo/node_modules/pinpoint-node-agent/node_modules/@grpc/grpc-js/src/client-interceptors.ts:389:48)
at /Users/workspace/demo/node_modules/pinpoint-node-agent/node_modules/@grpc/grpc-js/src/call-stream.ts:276:24
at processTicksAndRejections (internal/process/task_queues.js:75:11) {
code: 14,
details: 'No connection established',
metadata: Metadata { internalRepr: Map(0) {}, options: {} }
}

0.7.0 release checking

  • dependency warning => #19

  • Use only PINPOINT_TRACE_EXCLUSION_URL_PATTERN with JSON

  • Use PINPOINT_TRACE_EXCLUSION_URL_PATTERN and PINPOINT_TRACE_EXCLUSION_URL_CACHE_SIZE with JSON

  • check warning PINPOINT_TRACE_EXCLUSION_URL_CACHE_SIZE without PINPOINT_TRACE_EXCLUSION_URL_PATTERN and JSON

You have to set the PINPOINT_TRACE_EXCLUSION_URL_PATTERN, PINPOINT_TRACE_EXCLUSION_URL_CACHE_SIZE or trace-exclusion-url{ pattern: 'pattern', 'cache-size': 100} for using excludsion url cache.

var client = redis.createClient({
  port: 6379,
  db: 3,
});
router.get('/', async function (req, res, next) {
  callcount++

  client.select(2)

  client.set("key", "value", function (error) {
    console.log(`${callcount} redis set `)
  })

  client.get("key", function (error, data) {
    console.log(`${callcount} redis data ${data}`)
  })
});

  • outgoing request which is "s0" in exclusion url => next release version needs to check outgoing request rules.

Transition to gRPC Pure JavaScript Client

Node write callback lexical scoped stream end

to be

           const stream = this.stream
            stream.write(data, (error) => {
                if (error) {
                    this.endWithStream(stream)
                    if (rewriteAfterStreamEnd) {
                        this.write(data, false)
                    }
                    log.error(`grpc-stream.js write error in write's callback: ${error}`)
                }
            })

Modify to close the stream called by callback by error

Retry unary stream

Unary stream

  • requestAgentInfo

No schedule sub channel connection is closed

2021-03-12T03:32:43.683Z | server_call | Request to method /v1.Agent/RequestAgentInfo ended with status code: DEADLINE_EXCEEDED details: Deadline exceeded
2021-03-12T03:32:43.685Z | call_stream | [5] HTTP/2 stream closed with code 8
2021-03-12T03:32:43.688Z | server_call | Request to method /v1.Agent/RequestAgentInfo stream closed with rstCode 8
2021-03-12T03:32:43.689Z | subchannel | ::1:62287 connection closed by GOAWAY with code 0
2021-03-12T03:32:43.690Z | subchannel | ::1:62287 READY -> IDLE
2021-03-12T03:32:43.691Z | subchannel_refcount | ::1:62287 refcount 4 -> 3
2021-03-12T03:32:43.693Z | pick_first | READY -> IDLE
2021-03-12T03:32:43.694Z | resolving_load_balancer | dns:localhost:62287 READY -> IDLE
2021-03-12T03:32:43.696Z | connectivity_state | dns:localhost:62287 READY -> IDLE
2021-03-12T03:32:43.697Z | subchannel_refcount | ::1:62287 refcount 3 -> 2
2021-03-12T03:32:43.698Z | pick_first | READY -> IDLE
2021-03-12T03:32:43.699Z | resolving_load_balancer | dns:localhost:62287 READY -> IDLE
2021-03-12T03:32:43.701Z | connectivity_state | dns:localhost:62287 READY -> IDLE
2021-03-12T03:32:43.702Z | subchannel_refcount | ::1:62287 refcount 2 -> 1
2021-03-12T03:32:43.703Z | pick_first | READY -> IDLE
2021-03-12T03:32:43.704Z | resolving_load_balancer | dns:localhost:62287 READY -> IDLE
2021-03-12T03:32:43.706Z | connectivity_state | dns:localhost:62287 READY -> IDLE
2021-03-12T03:32:43.707Z | subchannel | 127.0.0.1:62287 connection closed by GOAWAY with code 0
2021-03-12T03:32:43.709Z | subchannel | 127.0.0.1:62287 READY -> IDLE

sub channel connection doesn't closed with schedule

this.removeJobForAgentInfo = this.agentInfoDailyScheduler.addJob(() => { this.sendAgentInfo(agentInfo, callback) })
this.agentInfoDailyScheduler.start()

2021-03-12T03:35:45.432Z | server_call | Request to method /v1.Agent/RequestAgentInfo ended with status code: DEADLINE_EXCEEDED details: Deadline exceeded
2021-03-12T03:35:45.433Z | call_stream | [5] HTTP/2 stream closed with code 8
2021-03-12T03:35:45.437Z | server_call | Request to method /v1.Agent/RequestAgentInfo stream closed with rstCode 8
2021-03-12T03:35:45.437Z | subchannel | ::1:62563 connection closed by GOAWAY with code 0
2021-03-12T03:35:45.438Z | subchannel | ::1:62563 READY -> IDLE
2021-03-12T03:35:45.439Z | subchannel_refcount | ::1:62563 refcount 4 -> 3
2021-03-12T03:35:45.440Z | pick_first | READY -> IDLE
2021-03-12T03:35:45.441Z | resolving_load_balancer | dns:localhost:62563 READY -> IDLE
2021-03-12T03:35:45.443Z | connectivity_state | dns:localhost:62563 READY -> IDLE
2021-03-12T03:35:45.444Z | subchannel_refcount | ::1:62563 refcount 3 -> 2
2021-03-12T03:35:45.445Z | pick_first | READY -> IDLE
2021-03-12T03:35:45.446Z | resolving_load_balancer | dns:localhost:62563 READY -> IDLE
2021-03-12T03:35:45.447Z | connectivity_state | dns:localhost:62563 READY -> IDLE
2021-03-12T03:35:45.448Z | subchannel_refcount | ::1:62563 refcount 2 -> 1
2021-03-12T03:35:45.449Z | pick_first | READY -> IDLE
2021-03-12T03:35:45.450Z | resolving_load_balancer | dns:localhost:62563 READY -> IDLE
2021-03-12T03:35:45.451Z | connectivity_state | dns:localhost:62563 READY -> IDLE
2021-03-12T03:35:45.452Z | subchannel | 127.0.0.1:62563 connection closed by GOAWAY with code 0
2021-03-12T03:35:45.453Z | subchannel | 127.0.0.1:62563 READY -> IDLE
  • requestApiMetaData
  • requestStringMetaData

express with method name

Module

https://expressjs.com/en/guide/routing.html

method name

express internal

path = '/express1'
this.stack[0] = 'query'
this.stack[1] = 'expressInit'
this.stack[2] = 'bound dispatch'
this.stack[3] = 'bound dispatch'
proto.route = function route(path) {
  var route = new Route(path);

  var layer = new Layer(path, {
    sensitive: this.caseSensitive,
    strict: this.strict,
    end: true
  }, route.dispatch.bind(route));

  layer.route = route;

  this.stack.push(layer);
  return route;
};

https://v8.dev/docs/stack-trace-api#appendix%3A-stack-trace-format

as-is
Screen Shot 2021-06-22 at 1 21 56 PM

Error

sync get method handler error

Screen Shot 2021-07-27 at 3 46 05 PM

Screen Shot 2021-07-27 at 3 42 36 PM

async get method handler next error

Screen Shot 2021-07-27 at 3 42 19 PM

not working on PM2 (not working properly detect outgoing request)

Hi there.

There is a problem that outgoing requests are not properly detected when the process is run as pm2.
It seems that outgoing request hooking does not work in pm2 environment.
I tried to find the problem myself, but failed to determine the cause.

To check the problem, I modified the code below to run the debug console.

lib/instrumentation/http-shared.js#L65

      log.debug('start traceOutgoingRequest')
      const req = original.apply(this, arguments)
      const trace = agent.traceContext.currentTraceObject()
      log.debug('trace', trace)  // added code

      if (!trace) return req

      if (!trace.canSampled()) {
        RequestHeaderUtils.writeHTTPSampled(req)
        return req
      }

lib/context/context-manager.js#L14

const init = (asyncId, type, triggerAsyncId, resource) => {
  if (type === 'TIMERWRAP') return
  if (traceObjectMap.has(triggerAsyncId)) {
    log.debug(triggerAsyncId, 'set OK') // added code
    traceObjectMap.set(asyncId, traceObjectMap.get(triggerAsyncId))
  } else {
    log.debug(triggerAsyncId, 'set NOT OK') // added code
  }
}

And there was a difference between the node process running the vanilla node command and the node process running using pm2.

In the pm2 execution environment, trace(agent.traceContext.currentTraceObject()) is undefined even if outgoing request is detected. and all traceObjectMap.set judgments (contextManager.init()) are false.

Process execution result with pm2 command

trace undefined # << trace is undefined
1673 set NOT OK
1674 set NOT OK
1675 set NOT OK
1676 set NOT OK
// ...
// everything is NOT OK
// ...
1808 set NOT OK
1809 set NOT OK
sendStats pStatMessage: {"agentId":"i-03bb7c559654ce686_f1ee","agentStartTime":1604034700967,"timestamp":1604034726991,"collectInterval":1000,"memory":{"heapUsed":105577776,"heapTotal":113004544},"cpu":{"user":0.19677778390364023,"system":0},"activeTrace":{"schema":{"typeCode":2,"fast":1000,"normal":3000,"slow":5000},"typeCode":2,"fastCount":0,"normalCount":0,"slowCount":0,"verySlowCount":0}}
1810 set NOT OK
1811 set NOT OK
send full stats at1604034726991

But, process executed by the node command seems to work correctly.

Process execution result with node command

trace Trace {
  traceId: TraceId {
    transactionId: TransactionId {
      agentId: 'i-03bb7c559654ce686_cd24',
      agentStartTime: '1604034795756',
      sequence: '0'
    },
    spanId: '7560621802209459',
    parentSpanId: '-1',
    flag: 0
  },
  agentInfo: {
    agentId: 'i-03bb7c559654ce686_cd24',
    applicationName: 'test-dev',
    agentStartTime: 1604034795756,
    serviceType: 1400
  },
 // ... skip
  storage: BufferedStorage {
    dataSender: DataSender {
      enabledDataSending: true,
      dataSender: [GrpcDataSender]
    },
    createSpanChunk: [Function],
    bufferSize: 10,
    storage: [ [SpanEvent] ]
  },
  callStack: [],
  sequence: 1,
  sampling: true
}
{
  getObject: [Function: getObject],
  setObject: [Function: setObject],
  getAllObject: [Function: getAllObject],
  start: [Function: start]
}
>> GETTER ASYNC ID: 1609
>> MAP LENGTH: undefined
>> Writer http header
 [Object: null prototype] {
  'user-agent': 'axios/0.18.1',
  host: 'test.test.in',
  'pinpoint-traceid': 'i-03bb7c559654ce686_cd24^1604034795756^0',
  'pinpoint-spanid': 7506321793742509,
  'pinpoint-pspanid': '7560621802209459',
  'pinpoint-pappname': 'test',
  'pinpoint-papptype': 1400,
  'pinpoint-flags': 0,
  'pinpoint-host': 'test.test.in'
}
1621 set OK
1622 set OK
1623 set OK
1624 set OK
1625 set OK
1626 set OK
1627 set OK
1628 set OK
1629 set OK
1630 set OK
1631 set OK
intercepted http.ClientcRequest response event { id: '*.com/members//list' }
1632 set OK
1633 set OK
1634 set OK
1635 set OK
intercepted http.IncomingMessage end event { id: 'test.test.in/members/1/list' }
1636 set OK
sendSpanChunk pSpanChunk: {"spanchunk":{"version":1,"transactionid":{"agentid":"i-03bb7c559654ce686_cd24","agentstarttime":"1604034795756","sequence":"0"},"spanid":"7560621802209459","endpoint":"","spaneventList":[{"sequence":0,"depth":1,"startelapsed":0,"endelapsed":0,"servicetype":100,"annotationList":[],"apiid":2,"exceptioninfo":null,"nextevent":{"messageevent":{"nextspanid":-1,"endpoint":"","destinationid":""}},"asyncevent":0},{"sequence":1,"depth":2,"startelapsed":0,"endelapsed":0,"servicetype":9056,"annotationList":[{"key":12,"value":{"stringvalue":"GET","boolvalue":false,"intvalue":0,"longvalue":0,"shortvalue":0,"doublevalue":0,"binaryvalue":"","bytevalue":0}},{"key":40,"value":{"stringvalue":"test.test.in/members/1/list","boolvalue":false,"intvalue":0,"longvalue":0,"shortvalue":0,"doublevalue":0,"binaryvalue":"","bytevalue":0}},{"key":46,"value":{"stringvalue":"","boolvalue":false,"intvalue":200,"longvalue":0,"shortvalue":0,"doublevalue":0,"binaryvalue":"","bytevalue":0}}],"apiid":0,"exceptioninfo":null,"nextevent":{"messageevent":{"nextspanid":7506321793742509,"endpoint":"localhost:7777","destinationid":"test.test.in"}},"asyncevent":0}],"applicationservicetype":1400,"keytime":1604034799385,"localasyncid":{"asyncid":2,"sequence":0}}}
1637 set OK
1638 set OK
1639 set OK
// ... everything set OK
1675 set OK
1676 set OK
1677 set OK
sendSpan pSpan: {"span":{"version":1,"transactionid":{"agentid":"i-03bb7c559654ce686_cd24","agentstarttime":"1604034795756","sequence":"0"},"spanid":"7560621802209459","parentspanid":"-1","starttime":1604034799292,"elapsed":193,"apiid":1,"servicetype":1400,"acceptevent":{"rpc":"/v6-6/event/calendar_2020/hit","endpoint":"localhost:7777","remoteaddr":"127.0.0.1","parentinfo":{"parentapplicationname":"","parentapplicationtype":0,"acceptorhost":""}},"annotationList":[{"key":46,"value":{"stringvalue":"","boolvalue":false,"intvalue":200,"longvalue":0,"shortvalue":0,"doublevalue":0,"binaryvalue":"","bytevalue":0}}],"flag":0,"err":0,"spaneventList":[{"sequence":0,"depth":1,"startelapsed":50,"endelapsed":0,"servicetype":9057,"annotationList":[{"key":12,"value":{"stringvalue":"http.request","boolvalue":false,"intvalue":0,"longvalue":0,"shortvalue":0,"doublevalue":0,"binaryvalue":"","bytevalue":0}}],"apiid":0,"exceptioninfo":null,"nextevent":{"messageevent":{"nextspanid":-1,"endpoint":"localhost:7777","destinationid":"localhost:7777"}},"asyncevent":1},{"sequence":1,"depth":1,"startelapsed":42,"endelapsed":0,"servicetype":9057,"annotationList":[{"key":12,"value":{"stringvalue":"http.request","boolvalue":false,"intvalue":0,"longvalue":0,"shortvalue":0,"doublevalue":0,"binaryvalue":"","bytevalue":0}}],"apiid":0,"exceptioninfo":null,"nextevent":{"messageevent":{"nextspanid":-1,"endpoint":"localhost:7777","destinationid":"localhost:7777"}},"asyncevent":2}],"exceptioninfo":null,"applicationservicetype":1400,"loggingtransactioninfo":0}}
1678 set OK
// ... everything set OK
1700 set OK
1701 set NOT OK
1702 set NOT OK
1703 set OK
1704 set OK

I don't know where to check to see this problem. can I check another?

please feedback. Thank you.

Fix Agent ID length validator

actuals
PINPOINT_APPLICATION_NAME=express-node-sample-name-
PINPOINT_AGENT_ID=express-node-sample-id--

/Users/xx/.nodenv/shims/node ./src/bin/www
You have to set Application Name to less 24 characters.
/Users/xx/workspace/pinpoint/pinpoint-node-agent/lib/utils/logger.js:59
[Pinpoint Agent] Configuration {serviceType: 1400, collectorIp: 'dev.collector.pinpoint.navercorp.com', collectorTcpPort: 9991, collectorStatPort: 9992, collectorSpanPort: 9993, …}
[Pinpoint Agent][express-node-sample-id--] Disabled
/Users/feelform/workspace/pinpoint/pinpoint-node-agent/lib/utils/logger.js:55

actuals
PINPOINT_APPLICATION_NAME=express-node-sample-name
PINPOINT_AGENT_ID=express-node-sample-id--x

/Users/feelform/.nodenv/shims/node ./src/bin/www
You have to set Agent ID to less 24 characters.
/Users/feelform/workspace/pinpoint/pinpoint-node-agent/lib/utils/logger.js:59
[Pinpoint Agent] Configuration {serviceType: 1400, collectorIp: 'dev.collector.pinpoint.navercorp.com', collectorTcpPort: 9991, collectorStatPort: 9992, collectorSpanPort: 9993, …}
[Pinpoint Agent][express-node-sample-id--x] Disabled
/Users/feelform/workspace/pinpoint/pinpoint-node-agent/lib/utils/logger.js:55

gRPC JS v8.13.0 error

ok 48 when server throw error, 2st event call an end event
94
_stream_duplex.js:81
95
  if (this.allowHalfOpen || this._writableState.ended)
96
           ^
97

98
TypeError: Cannot read property 'allowHalfOpen' of undefined
99
    at onend (_stream_duplex.js:81:12)
100
    at ClientDuplexStreamImpl.grpcDataSender.pingStream.grpcStream.stream.on (/home/runner/work/pinpoint-node-agent/pinpoint-node-agent/test/client/grpc-data-sender-bidirectional-stream.test.js:92:21)
101
    at emitNone (events.js:111:20)
102
    at ClientDuplexStreamImpl.emit (events.js:208:7)
103
    at endReadableNT (_stream_readable.js:1064:12)
104
    at _combinedTickCallback (internal/process/next_tick.js:139:11)
105
    at process._tickCallback (internal/process/next_tick.js:181:9)
106
npm ERR! Test failed.  See above for more details.
107
Error: Process completed with exit code 1.

urijs npm audit security report

❯ npm audit
                                                                                
                       === npm audit security report ===                        
                                                                                
# Run  npm update urijs --depth 2  to resolve 1 vulnerability
┌───────────────┬──────────────────────────────────────────────────────────────┐
│ Moderate      │ Hostname spoofing via backslashes in URL                     │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ Package       │ urijs                                                        │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ Dependency of │ koa-router [dev]                                             │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ Path          │ koa-router > urijs                                           │
├───────────────┼──────────────────────────────────────────────────────────────┤
│ More info     │ https://npmjs.com/advisories/1595                            │
└───────────────┴──────────────────────────────────────────────────────────────┘


found 1 moderate severity vulnerability in 631 scanned packages
  run `npm audit fix` to fix 1 of them.



Function unit callstack is not exposed

Function unit callstack is not exposed -
When multiple functions are executed, it is not tracked which function took a long time to process or whether an error occurred.

Callstack like JVM agent

https://github.com/pinpoint-apm/pinpoint/tree/master/agent-testweb
Get name and line of calling function in node.js : https://stackoverflow.com/questions/14172455/get-name-and-line-of-calling-function-in-node-js/14172822

Error.prepareStackTrace changes

Stack trace API: https://v8.dev/docs/stack-trace-api
vm: Error.prepareStackTrace behaves inconsistently across versions: nodejs/node#21270

  • V8 is making upstream changes to Error.prepareStackTrace which scope it per-context and can't land those until we fix how we handle Error.prepareStackTrace in repl: nodejs/node#23926

express

TODO

  • call stack cache
  • API METADATA
  • Query String: #85

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.