Comments (11)
Vectarian-Jorge
commented on September 27, 2024
Added a minimal example. Those 3 files. Just run node index.js with any of the throws uncommented. It'll crash and the agent won't report it.
from apm-agent-nodejs.
Vectarian-Jorge
commented on September 27, 2024
Tried with require instead of ES modules too. Nothing.
from apm-agent-nodejs.
david-luna
commented on September 27, 2024
I've run you example uncommenting the li within the request handler but haven't been able to reproduce. I can see the error in Kibana.
Are you able to get the initial line of log output from the APM agent? It looks something like this:
{"log.level":"info","@timestamp":"2024-04-25T14:35:50.282Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","agentVersion":"4.5.3","env":{"pid":30004,"proctitle":"node","os":"darwin 23.4.0","arch":"arm64","host":"moonlocal.local","timezone":"UTC+0200","runtime":"Node.js v18.16.0"},"config":{"environment":{"source":"start","value":"local"},"logLevel":{"source":"environment","value":"trace","commonName":"log_level"},"serverUrl":{"source":"environment","value":"https://eah-demo-testing.apm.us-central1.gcp.cloud.es.io/","commonName":"server_url"},"secretToken":{"source":"environment","value":"[REDACTED]","commonName":"secret_token"},"serviceName":{"source":"environment","value":"expresscmp-elastic1","commonName":"service_name"},"serviceVersion":{"source":"default","value":"1.0.0","commonName":"service_version"}},"activationMethod":"import","dependencies":{"elastic-apm-node":"^4.5.0","express":"^4.19.2"},"startTrace":["at Agent.start (/Users/david/Documents/repos/issues/el-apm-node-3960/node_modules/elastic-apm-node/lib/agent.js:294:11)","at file:///Users/david/Documents/repos/issues/el-apm-node-3960/apm.js:3:5","at ModuleJob.run (node:internal/modules/esm/module_job:194:25)"],"message":"Elastic APM Node.js Agent v4.5.3"}
If so, check if the line contains something like
"config": { "captureExceptions": { "source": "start", "value": false }
This is to check there is no other source setting the configuration option.
from apm-agent-nodejs.
david-luna
commented on September 27, 2024
Also if you can make local edits, you can apply this change to log if the agent's exception handler is properly attached to the process.
diff --git a/lib/agent.js b/lib/agent.js
index 2a1e26df..64fe1c59 100644
--- a/lib/agent.js
+++ b/lib/agent.js
@@ -776,6 +776,8 @@ Agent.prototype.handleUncaughtExceptions = function (cb) {
});
};
+ console.log('XXX attaching uncaughtException handler to process')
+
process.on('uncaughtException', this._uncaughtExceptionListener);
};to "node_modules/elastic-apm-node/lib/agent.js", restart, and reproduce. Then post here full log to check if this new line appears
from apm-agent-nodejs.
Vectarian-Jorge
commented on September 27, 2024
This is the initial log line:
{"log.level":"info","@timestamp":"2024-04-29T07:49:31.180Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","agentVersion":"4.5.0","env":{"pid":99719,"proctitle":"node","os":"darwin 23.4.0","arch":"arm64","host":"REDACTED","timezone":"UTC+0100","runtime":"Node.js v20.11.0"},"config":{"captureExceptions":{"source":"start","value":true},"environment":{"source":"start","value":"local"},"logLevel":{"source":"default","value":"info","commonName":"log_level"},"serverUrl":{"source":"start","value":"REDACTED","commonName":"server_url"},"serviceName":{"source":"default","value":"experiment","commonName":"service_name"},"serviceVersion":{"source":"default","value":"1.0.0","commonName":"service_version"}},"activationMethod":"import","message":"Elastic APM Node.js Agent v4.5.0"}
This is with captureExceptions: true explicitly defined in the APM start options. If I remove the property "captureExceptions": { "source": "start", "value": true } does not show up in the log line.
With the file node_modules/elastic-apm-node/lib/agent.js modified as instructed the first 3 lines printed to console are:
{"log.level":"info","@timestamp":"2024-04-29T07:55:22.430Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","agentVersion":"4.5.0","env":{"pid":99904,"proctitle":"node","os":"darwin 23.4.0","arch":"arm64","host":"REDACTED","timezone":"UTC+0100","runtime":"Node.js v20.11.0"},"config":{"captureExceptions":{"source":"start","value":true},"environment":{"source":"start","value":"local"},"logLevel":{"source":"default","value":"info","commonName":"log_level"},"serverUrl":{"source":"start","value":"REDACTED","commonName":"server_url"},"serviceName":{"source":"default","value":"experiment","commonName":"service_name"},"serviceVersion":{"source":"default","value":"1.0.0","commonName":"service_version"}},"activationMethod":"import","message":"Elastic APM Node.js Agent v4.5.0"}
XXX attaching uncaughtException handler to process
Example app listening on port 3000
The following line would be the error Error: Kaboom and its stacktrace if I triggered it.
If I'm not mistaken. These outputs are what they should be, yet still no errors show on the APM panel.
I think I read somewhere that the agent prints something to console whenever it captures a fatal error and sends it to ELK. Is that correct? If that's the case I don't see that log either.
from apm-agent-nodejs.
david-luna
commented on September 27, 2024
as your logs show the exception handler is set when the agent starts so we can assume the agent starts correctly. Next thing to try is to set the log level to trace to see if there are any issues related to other components.
You can start you example with the defined log level like this
ELASTIC_APM_LOG_LEVEL=trace node index.jsRef: https://www.elastic.co/guide/en/apm/agent/nodejs/current/configuration.html#log-level
once you got the logs please paste them here :)
from apm-agent-nodejs.
Vectarian-Jorge
commented on September 27, 2024
Sorry for the delay. These are the logs:
{"log.level":"info","@timestamp":"2024-05-03T12:05:15.887Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","agentVersion":"4.5.0","env":{"pid":35372,"proctitle":"node","os":"darwin 23.4.0","arch":"arm64","host":"Vectarys-MacBook-Pro-2.local","timezone":"UTC+0100","runtime":"Node.js v20.11.0"},"config":{"environment":{"source":"start","value":"local"},"logLevel":{"source":"environment","value":"trace","commonName":"log_level"},"serverUrl":{"source":"start","value":"REDACTED","commonName":"server_url"},"serviceName":{"source":"default","value":"experiment","commonName":"service_name"},"serviceVersion":{"source":"default","value":"1.0.0","commonName":"service_version"}},"activationMethod":"import","dependencies":{"elastic-apm-node":"^4.5.0","express":"^4.19.2"},"startTrace":["at Agent.start (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/elastic-apm-node/lib/agent.js:294:11)","at file:///Users/REDACTED/Documents/GitHub/REDACTED/experiment/apm.js:3:5","at ModuleJob.run (node:internal/modules/esm/module_job:218:25)","at async ModuleLoader.import (node:internal/modules/esm/loader:329:24)","at async loadESM (node:internal/process/esm_loader:28:7)","at async handleMainPromise (node:internal/modules/run_main:113:12)"],"message":"Elastic APM Node.js Agent v4.5.0"}
XXX attaching uncaughtException handler to process
Example app listening on port 3000
{"log.level":"trace","@timestamp":"2024-05-03T12:05:15.936Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","message":"corking (cloudMetadataFetcher)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:15.937Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"adding Node.js module loader hooks"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:15.938Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"instrumenting fetch"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.025Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"instrumenting [email protected] module (enabled=true, isImportMod=false)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.055Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"instrumenting [email protected] module (enabled=true, isImportMod=false)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.062Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"shimming http.Server.prototype.emit function"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.063Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"shimming http.ServerResponse.prototype.writeHead function"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.063Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"shimming http.request function"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.063Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"shimming http.get function"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.516Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"no cloud metadata servers responded"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.517Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","message":"getCloudMetadata err: Error: no response from any callback, no cloud metadata will be set (normal outside of cloud env.)"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.518Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","_encodedMetadata":"{\"metadata\":{\"service\":{\"name\":\"experiment\",\"environment\":\"local\",\"runtime\":{\"name\":\"node\",\"version\":\"20.11.0\"},\"language\":{\"name\":\"javascript\"},\"agent\":{\"name\":\"nodejs\",\"version\":\"4.5.0\",\"activation_method\":\"import\"},\"version\":\"1.0.0\"},\"process\":{\"pid\":35372,\"ppid\":35371,\"title\":\"node\",\"argv\":[\"/Users/REDACTED/.volta/tools/image/node/20.11.0/bin/node\",\"/Users/REDACTED/Documents/GitHub/REDACTED/experiment/index.js\"]},\"system\":{\"architecture\":\"arm64\",\"platform\":\"darwin\",\"detected_hostname\":\"vectarys-macbook-pro-2.local\"}}}\n","message":"_resetEncodedMetadata"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.518Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","message":"uncorked (cloudMetadataFetcher)"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.520Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","message":"intake request start"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.521Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","fullTimeMs":2.910459,"numEvents":1,"numBytes":848,"message":"_write: encode object"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.521Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","message":"intakeReq \"socket\": unref it"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:16.705Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","_encodedMetadata":"{\"metadata\":{\"service\":{\"name\":\"experiment\",\"environment\":\"local\",\"runtime\":{\"name\":\"node\",\"version\":\"20.11.0\"},\"language\":{\"name\":\"javascript\"},\"agent\":{\"name\":\"nodejs\",\"version\":\"4.5.0\"},\"version\":\"1.0.0\"},\"process\":{\"pid\":35372,\"ppid\":35371,\"title\":\"node\",\"argv\":[\"/Users/REDACTED/.volta/tools/image/node/20.11.0/bin/node\",\"/Users/REDACTED/Documents/GitHub/REDACTED/experiment/index.js\"]},\"system\":{\"architecture\":\"arm64\",\"platform\":\"darwin\",\"detected_hostname\":\"vectarys-macbook-pro-2.local\"}}}\n","message":"_resetEncodedMetadata"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.705Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","apmServerVersion":"7.17.8","message":"fetched APM Server version"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:16.788Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","remoteConf":{},"message":"central config received"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.523Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","message":"gzipStream \"finish\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.523Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","timeout":10000,"message":"start intakeResTimer"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.524Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","message":"gzipStream \"end\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.524Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","concluded":false,"message":"completePart gzipStream"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.525Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","message":"intakeReq \"finish\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.525Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","concluded":false,"message":"completePart intakeReq"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.741Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","statusCode":202,"reqFinished":true,"message":"intakeReq \"response\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.742Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","message":"intakeRes \"end\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.742Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","concluded":false,"message":"completePart intakeRes"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:26.742Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"d1ccfe910a8c43a330ed20c0b21fd021","timeline":[[10004.787334,"completePart gzipStream",null],[10005.435417,"completePart intakeReq",null],[10222.505709,"completePart intakeRes",null]],"bytesWritten":689,"backoffDelayMs":0,"message":"conclude intake request: success"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.441Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"intercepted request event call to http.Server.prototype.emit for /"}
Error: Kaboom
at file:///Users/REDACTED/Documents/GitHub/REDACTED/experiment/index.js:8:17
at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)
at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/route.js:149:13)
at Route.dispatch (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/route.js:119:3)
at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)
at /Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:284:15
at Function.process_params (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:346:12)
at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:280:10)
at expressInit (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/middleware/init.js:40:5)
at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)
at trim_prefix (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:328:13)
at /Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:286:9
at Function.process_params (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:346:12)
at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:280:10)
at query (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/middleware/query.js:45:5)
at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)
at trim_prefix (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:328:13)
at /Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:286:9
at Function.process_params (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:346:12)
at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:280:10)
at Function.handle (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:175:3)
at Function.handle (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/application.js:181:10)
at Server.app (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/express.js:39:9)
at Server.emit (node:events:518:28)
at Server.emit (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/elastic-apm-node/lib/instrumentation/http-shared.js:162:19)
at parserOnIncoming (node:_http_server:1143:12)
at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17)
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.443Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"start trace {\"trans\":\"a5911165e833e6d5\",\"trace\":\"b5a867d9f885ed3b1fb893999295692c\",\"name\":\"unnamed\",\"type\":\"custom\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.443Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","ctxmgr":"AsyncLocalStorageRunContextManager( RunContext(Transaction(a5911165e833e6d5, 'unnamed')) )","message":"supersedeWithTransRunContext(<Trans a5911165e833e6d5>)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.447Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"setting transaction result {\"trans\":\"a5911165e833e6d5\",\"trace\":\"b5a867d9f885ed3b1fb893999295692c\",\"result\":\"HTTP 2xx\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.450Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"setting default transaction name: GET / {\"trans\":\"a5911165e833e6d5\",\"trace\":\"b5a867d9f885ed3b1fb893999295692c\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.450Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","ctxmgr":"AsyncLocalStorageRunContextManager( RunContext() )","message":"addEndedTransaction(GET /)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.471Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"sending transaction {\"trans\":\"a5911165e833e6d5\",\"trace\":\"b5a867d9f885ed3b1fb893999295692c\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.472Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","trans":"a5911165e833e6d5","name":"GET /","trace":"b5a867d9f885ed3b1fb893999295692c","type":"request","result":"HTTP 2xx","duration":8.322,"message":"ended transaction"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.473Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","error":{"type":"Error","message":"Kaboom","stack_trace":"Error: Kaboom\n at file:///Users/REDACTED/Documents/GitHub/REDACTED/experiment/index.js:8:17\n at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)\n at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/route.js:149:13)\n at Route.dispatch (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/route.js:119:3)\n at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)\n at /Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:284:15\n at Function.process_params (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:346:12)\n at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:280:10)\n at expressInit (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/middleware/init.js:40:5)\n at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)\n at trim_prefix (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:328:13)\n at /Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:286:9\n at Function.process_params (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:346:12)\n at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:280:10)\n at query (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/middleware/query.js:45:5)\n at Layer.handle [as handle_request] (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/layer.js:95:5)\n at trim_prefix (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:328:13)\n at /Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:286:9\n at Function.process_params (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:346:12)\n at next (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:280:10)\n at Function.handle (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/router/index.js:175:3)\n at Function.handle (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/application.js:181:10)\n at Server.app (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/express/lib/express.js:39:9)\n at Server.emit (node:events:518:28)\n at Server.emit (/Users/REDACTED/Documents/GitHub/REDACTED/experiment/node_modules/elastic-apm-node/lib/instrumentation/http-shared.js:162:19)\n at parserOnIncoming (node:_http_server:1143:12)\n at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17)"},"message":"Elastic APM caught unhandled exception"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.487Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"Sending error to Elastic APM: {\"id\":\"3e27eb0c4421460c747a227e7bd63cb2\"}"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.488Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","message":"intake request start"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.488Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","encodeTimeMs":0.509208,"fullTimeMs":0.911917,"numEvents":2,"numBytes":11425,"message":"_writeBatch"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.488Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","message":"intakeReq \"socket\": unref it"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.488Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","activeIntakeReq":true,"lambdaEnd":false,"message":"_writeFlush"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.489Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","message":"gzipStream \"finish\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.489Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","timeout":10000,"message":"start intakeResTimer"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.489Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","message":"gzipStream \"end\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.489Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","concluded":false,"message":"completePart gzipStream"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.489Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","message":"intakeReq \"finish\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.489Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","concluded":false,"message":"completePart intakeReq"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.545Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"intercepted request event call to http.Server.prototype.emit for /favicon.ico"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.545Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"start trace {\"trans\":\"a10c68672ac1eb8d\",\"trace\":\"978e2fefc32f12abe8caa754a76a913d\",\"name\":\"unnamed\",\"type\":\"custom\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.545Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","ctxmgr":"AsyncLocalStorageRunContextManager( RunContext(Transaction(a10c68672ac1eb8d, 'unnamed')) )","message":"supersedeWithTransRunContext(<Trans a10c68672ac1eb8d>)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.547Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"setting transaction result {\"trans\":\"a10c68672ac1eb8d\",\"trace\":\"978e2fefc32f12abe8caa754a76a913d\",\"result\":\"HTTP 4xx\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.547Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"could not extract route name from request {\"url\":\"/favicon.ico\",\"type\":\"undefined\",\"null\":false,\"route\":false,\"regex\":false,\"mountstack\":false,\"trans\":\"a10c68672ac1eb8d\",\"trace\":\"978e2fefc32f12abe8caa754a76a913d\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.547Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"setting default transaction name: GET unknown route {\"trans\":\"a10c68672ac1eb8d\",\"trace\":\"978e2fefc32f12abe8caa754a76a913d\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.548Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","ctxmgr":"AsyncLocalStorageRunContextManager( RunContext() )","message":"addEndedTransaction(GET unknown route)"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.548Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","message":"sending transaction {\"trans\":\"a10c68672ac1eb8d\",\"trace\":\"978e2fefc32f12abe8caa754a76a913d\"}"}
{"log.level":"debug","@timestamp":"2024-05-03T12:05:28.548Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","trans":"a10c68672ac1eb8d","name":"GET unknown route","trace":"978e2fefc32f12abe8caa754a76a913d","type":"request","result":"HTTP 4xx","duration":2.794,"message":"ended transaction"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.577Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","statusCode":202,"reqFinished":true,"message":"intakeReq \"response\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.577Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","message":"intakeRes \"end\""}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.577Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","concluded":false,"message":"completePart intakeRes"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.577Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","timeline":[[1.202958,"completePart gzipStream",null],[1.588833,"completePart intakeReq",null],[89.3285,"completePart intakeRes",null]],"bytesWritten":2373,"backoffDelayMs":0,"message":"conclude intake request: success"}
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.578Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","fullTimeMs":0.407,"numEvents":1,"numBytes":1301,"message":"_write: encode object"}
from apm-agent-nodejs.
Vectarian-Jorge
commented on September 27, 2024
I see the line that says Sending error to Elastic APM: {"id":"3e27eb0c4421460c747a227e7bd63cb2"} yet I still see nothing in the APM Web UI. I'm going to try to look for the ID 3e27eb0c4421460c747a227e7bd63cb2 somewhere. I'll post again if I find it anywhere.
from apm-agent-nodejs.
david-luna
commented on September 27, 2024
I do not see anything wrong in this log
this line
{"log.level":"trace","@timestamp":"2024-05-03T12:05:28.577Z","log.logger":"elastic-apm-node","ecs.version":"8.10.0","event.module":"apmclient","reqId":"08a56d5d3e89749ce116dd30188cd1f5","timeline":[[1.202958,"completePart gzipStream",null],[1.588833,"completePart intakeReq",null],[89.3285,"completePart intakeRes",null]],"bytesWritten":2373,"backoffDelayMs":0,"message":"conclude intake request: success"}
reveals that the http client received a successful response from the endpoint.
To discard any other communication issue we should check if the URL configured in the agent is pointing to the APM server or any other component like a proxy. @Vectarian-Jorge could you please check it?
I ran my tests with the same node and agent version specified in the issue but a different APM server version (8.12.1). I'll try to run the tests with same APM server 7.17.8 to discard any version incompatibility
from apm-agent-nodejs.
david-luna
commented on September 27, 2024
Ran the test with
- Elastic cloud stack 7.17.8
[email protected]
slight modification of the server script to test more cases
import './apm.js'; // Must go first
import express from 'express';
const port = 3000;
const app = express();
app.get('/reject', (_req, res) => {
Promise.reject(new Error('Rejection')); // 1. This is unhandled so ti should be reported
res.send('Hello World!');
});
app.get('/error', (_req, res) => {
throw new Error('Exception'); // 2. This is handled by express, no error
});
app.listen(port, () => {
console.log(`Example app listening on port ${port}`);
});
throw new Error('Boom'); // 3. This should also be reported, comment to test rejection (1)The service errors appear in Kibana
@Vectarian-Jorge I'm inclined to check the transit from the agent to the APM server. Have you checked for any proxy/nodes in between the app and the APM server?
from apm-agent-nodejs.
Vectarian-Jorge
commented on September 27, 2024
Thanks for checking all this @david-luna.
@PeterBero, you may need to check with Tomas about any possible proxy.
from apm-agent-nodejs.
Related Issues (20)
- opentelemetry-bridge should use the ELASTIC_APM_API_KEY HOT 1
- Any plans to support hyper-express please? HOT 4
- Support for Azure OpenAI
- nightly test with Node.js v23 failing in `elasticsearch` module
- add support for synchronous gauge to OTel Bridge metrics support
- Is there any plan to add a way to customize trace.id ？ HOT 2
- Nested labels are indexed as `[object Object]` HOT 1
- "active" config not being respected when the agent is started with -r or top level import HOT 3
- TypeError: Cannot read properties of null (reading 'propagateTraceContextHeaders') HOT 1
- integrate with Nuxtjs but cannot see any transaction in APM HOT 11
- mssql tests are failing in CI because a recent `mcr.microsoft.com/mssql/server` docker image release breaks our healthcheck HOT 10
- Dependency Dashboard
- do a new minor release for `process.getBuiltinModule` RITM hooking HOT 1
- Support aws EventBridge instrumentation HOT 2
- [META 882] Check classic and OTel agents against serverless HOT 2
- Version v4.7.1 Lambda Layer Misconfigured: All Regions Pointing to us-east-1 HOT 3
- use IITM wrap-only-hooked support for ESM
- Add support for `koa@13`
- [META 888] Update AWS ECS Fargate container ID regex.
- Add support for tedious@19
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
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.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from apm-agent-nodejs.