APM agent crashes NodeJs after reporting exception in tedious instrumentation code

Kibana version: 7.8.1 (flavor:default, type:docker)

Elasticsearch version: 7.8.1 (flavor:default, type:docker)

APM Server version: 7.8.1 (flavor:default, type:docker)

APM Agent language and version: Elastic-apm-node v3.9.0

NodeJs version: 12.16.2

Browser version: Not relevant as server side

Original install method (e.g. download page, yum, deb, from source, etc.) and version:

Fresh install or upgraded from other version? : Fresh install

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant):
Elastic-apm-node v3.9.0 crashes NodeJs running NestJs server after sending report due to exception in tedious instrumentation while executing bulk insert in MS.Sql DB
Last log I get is Sending error to Elastic APM { id: '17a9b49682b3da680437918195822005' }
NodeJs stopped just after that

NodeJs always stop due to the same error when the application execute the bulk.
And, just in case you are wondering, it works just fine when APM agent is disabled.

Fortunately the error is sent to APM and can see the detail in Kibana
We can see that root cause of the exception is an Null reference on the request params

Steps to reproduce:
There is only one bulk insert in the all application so easy to spot
Below is a code extract

    const connection: Promise<mssql.ConnectionPool> = getConnection();
    //Prepare table  insert into Temp table data for current Session and list ids
    const tmpSessionIds = new mssql.Table("tmp_list");
    tmpSessionIds.create = false;
    tmpSessionIds.columns.add("sessionId", mssql.NVarChar(80), { nullable: false });
    tmpSessionIds.columns.add("identifier", mssql.NVarChar(50), { nullable: false });
    for (let i = 0; i < positions.length; i++) {
      tmpSessionIds.rows.add(sessionId, identifiers[i]);
    }
    const InsertResult = await new Promise((resolve, reject) => {
      connection.then((x) =>
        x.request().bulk(tmpSessionIds, function (err, rowCount) {
          if (err) {
            reject(err);
          } else {
            resolve(rowCount);
          }
        })
      );
    });

Provide logs and/or server output (if relevant):

Exception stack trace

Cannot read property 'statement' of undefined

node_modules\elastic-apm-node\lib\instrumentation\modules\tedious.js in makeRequest at line 75
node_modules\tedious\lib\connection.js in Request.<anonymous> at line 1619
node_modules\elastic-apm-node\lib\instrumentation\modules\tedious.js in Request.userCallback at line 93
node_modules\tedious\lib\request.js in Request.callback at line 56
node_modules\tedious\lib\connection.js in endOfMessageMarkerReceived at line 2407
node_modules\tedious\lib\connection.js in dispatchEvent at line 1279
node_modules\tedious\lib\connection.js in Parser.<anonymous> at line 1072
events.js in emit at line 310
node_modules\tedious\lib\token\token-stream-parser.js in Parser.<anonymous> at line 37
events.js in emit at line 310
node_modules\tedious\node_modules\readable-stream\lib\_stream_readable.js in addChunk at line 298
node_modules\tedious\node_modules\readable-stream\lib\_stream_readable.js in readableAddChunk at line 280
node_modules\tedious\node_modules\readable-stream\lib\_stream_readable.js in Readable.push at line 241
node_modules\tedious\node_modules\readable-stream\lib\_stream_transform.js in Transform.push at line 139
node_modules\tedious\node_modules\readable-stream\lib\_stream_transform.js in afterTransform at line 88
node_modules\tedious\lib\token\stream-parser.js in _transform at line 88
node_modules\tedious\node_modules\readable-stream\lib\_stream_transform.js in Transform._read at line 177
node_modules\tedious\node_modules\readable-stream\lib\_stream_transform.js in Transform._write at line 164
node_modules\tedious\node_modules\readable-stream\lib\_stream_writable.js in doWrite at line 409
node_modules\tedious\node_modules\readable-stream\lib\_stream_writable.js in writeOrBuffer at line 398
node_modules\tedious\node_modules\readable-stream\lib\_stream_writable.js in Writable.write at line 307
node_modules\tedious\lib\token\token-stream-parser.js in addEndOfMessageMarker at line 55
node_modules\tedious\lib\connection.js in message at line 2396
node_modules\tedious\lib\connection.js in dispatchEvent at line 1279
node_modules\tedious\lib\connection.js in MessageIO.<anonymous> at line 1139
events.js in emit at line 310
node_modules\tedious\lib\message-io.js in Message.<anonymous> at line 46
events.js in emit at line 322
node_modules\tedious\node_modules\readable-stream\lib\_stream_readable.js in endReadableNT at line 1094
internal/process/task_queues.js in processTicksAndRejections at line 84

Environment NodeJs : v12.16.2
Extract of package.json

    "@elastic/elasticsearch": "^7.10.0",
    "@nestjs/common": "^7.0.8",
    "@nestjs/core": "^7.0.8",
    "@nestjs/platform-express": "^7.0.8",
    "@nestjs/serve-static": "^2.1.0",
    "@nestjs/swagger": "^4.5.1",
    "@nestjs/typeorm": "^7.0.0",
    "@types/express-session": "^1.17.0",,
    "@types/mssql": "^6.0.0",
    "elastic-apm-node": "^3.9.0",
    "express-session": "^1.17.0",
    "log4js": "^6.2.0",
    "mssql": "^6.2.0",
    "typeorm": "^0.2.24"

@rodbil Thanks for the excellent bug report! This is definitely a bug in the agent's tedious instrumentation. We've opened an issue in the agent to address this: https://github.com/elastic/apm-agent-nodejs/issues/1934

and we have a quick fix PR up: https://github.com/elastic/apm-agent-nodejs/pull/1935

Are you in a position where you could install the agent via the PR branch and see if it resolves your issue? This isn't mandatory (obviously) but we haven't been able to reproduce the exact conditions of this error yet. Your repro helped us identify the problem, but it's not 100% clear how your getConnection method creates the connection pool promise that will resolve to an object with a request() method. We'll be able to proceed without your testing -- but the fix may be a bit slower as we get more familiar with the tedious and mssql drivers.

Regardless -- thanks again for the bug report. Every one helps our agent get a little better :slight_smile:

Hi @alanstorm

I am ok to test the fix
Would you have the agent installation process documented somewhere for a PR branch

Thanks and regards

@rodbil You should be able to use your package manager to install the agent directly from a github branch.

That is -- normally you install the agent with the following command

npm install elastic-apm-node

which adds something like the following to your package.json file.

  "dependencies": {
    "elastic-apm-node": "^3.10.0"
  },

To install from a github branch you can use NPM in the form

    npm install git://github.com/org/repo#branch-name

So, for PR branch that would be

npm install git://github.com/elastic/apm-agent-nodejs#astorm/tedious-bulk-crash

which should add the following to your package.json file

    "dependencies": {
        "elastic-apm-node": "git://github.com/elastic/apm-agent-nodejs.git#astorm/tedious-bulk-crash"
    },    

Let us know how that goes and whether it fixes your problem. If it fixes things we'll get the PR landed and into a future agent release.

Hi @alanstorm

I could install the fix and confirm that it solve the crash. Please go forward with the release.

However I don’t think the bulk operation is properly captured in APM. Seeing a gap in the timeline...

Thanks

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.