diff --git a/.ci/.jenkins_tav.yml b/.ci/.jenkins_tav.yml index 005a36dfad..2c2e1bd274 100644 --- a/.ci/.jenkins_tav.yml +++ b/.ci/.jenkins_tav.yml @@ -1,4 +1,5 @@ TAV: + - '@elastic/elasticsearch' - '@hapi/hapi' - '@koa/router' - apollo-server-express diff --git a/.ci/docker/docker-compose.yml b/.ci/docker/docker-compose.yml index cb98466f28..c18847b987 100644 --- a/.ci/docker/docker-compose.yml +++ b/.ci/docker/docker-compose.yml @@ -71,7 +71,7 @@ services: retries: 30 elasticsearch: - image: docker.elastic.co/elasticsearch/elasticsearch:6.6.0 + image: docker.elastic.co/elasticsearch/elasticsearch:7.10.1 environment: - "ES_JAVA_OPTS=-Xms512m -Xmx512m" - "network.host=" diff --git a/.tav.yml b/.tav.yml index a32aa0071d..8179a55ce0 100644 --- a/.tav.yml +++ b/.tav.yml @@ -242,6 +242,15 @@ koa-router: elasticsearch: versions: '>=8.0.0' commands: node test/instrumentation/modules/elasticsearch.js + +# @elastic/elasticsearch +# - Version 7.7.0 included a change that broke usage with Node.js < 10. +# Fixed in 7.7.1: https://www.elastic.co/guide/en/elasticsearch/client/javascript-api/current/changelog-client.html#_7_7_1 +# Note: When Node.js v8 support is dropped, `versions` can be simplified. +'@elastic/elasticsearch': + versions: '>=7.0.0 <7.7.0 || >7.7.0 <8.0.0' + commands: node test/instrumentation/modules/@elastic/elasticsearch.js + handlebars: versions: '*' commands: node test/instrumentation/modules/handlebars.js diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index 6986abef83..131e92e612 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -38,11 +38,24 @@ Notes: [float] ===== Features +* feat: Add automatic instrumentation of the https://github.com/elastic/elasticsearch-js[@elastic/elasticsearch] package {pull}1877[#1870] ++ +The instrumentation of the legacy "elasticsearch" package has also changed +slightly to commonalize: ++ +** "span.context.destination" is set on all Elasticsearch spans, not just a + subset of query-like API endpoints. +** For query-like API endpoints (e.g. `/_search`), the capturing of query details + on "span.context.db.statement" has changed (a) to include *both* the + query params and the request body if both exist (separated by `\n\n`) and + (b) to *URL encode* the query params, rather than JSON encoding. + * feat: Add `captureAttributes` boolean option to `apm.captureError()` to allow *disabling* the automatic capture of Error object properties. This is useful for cases where those properties should not be sent to the APM Server, e.g. for performance (large string fields) or security (PII data). {pull}1912[#1912] + * feat: Add `log_level` central config support. {pull}1908[#1908] + Spec: https://github.com/elastic/apm/blob/master/specs/agents/logging.md diff --git a/docs/supported-technologies.asciidoc b/docs/supported-technologies.asciidoc index c910cdf0ce..aa4f0cdf45 100644 --- a/docs/supported-technologies.asciidoc +++ b/docs/supported-technologies.asciidoc @@ -74,6 +74,7 @@ The Node.js agent will automatically instrument the following modules to give yo |Module |Version |Note |https://www.npmjs.com/package/cassandra-driver[cassandra-driver] |>=3.0.0 |Will instrument all queries |https://www.npmjs.com/package/elasticsearch[elasticsearch] |>=8.0.0 |Will instrument all queries +|https://www.npmjs.com/package/@elastic/elasticsearch[@elastic/elasticsearch] |>=7.0.0 <8.0.0 |Will instrument all queries |https://www.npmjs.com/package/graphql[graphql] |>=0.7.0 <16.0.0 |Will instrument all queries |https://www.npmjs.com/package/handlebars[handlebars] |* |Will instrument compile and render calls |https://www.npmjs.com/package/jade[jade] |>=0.5.6 |Will instrument compile and render calls diff --git a/lib/instrumentation/elasticsearch-shared.js b/lib/instrumentation/elasticsearch-shared.js new file mode 100644 index 0000000000..37ba4f3c1f --- /dev/null +++ b/lib/instrumentation/elasticsearch-shared.js @@ -0,0 +1,63 @@ +'use strict' + +// Shared functionality between the instrumentations of: +// - elasticsearch - the legacy Elasticsearch JS client +// - @elastic/elasticsearch - the new Elasticsearch JS client + +const querystring = require('querystring') + +// URL paths matching the following pattern will have their query params and +// request body captured in the span (as `context.db.statement`). We match +// a complete URL path component to attempt to avoid accidental matches of +// user data, like `GET /my_index_search/...`. +const pathIsAQuery = /\/(_search|_msearch|_count|_async_search|_sql|_eql)(\/|$)/ + +// (This is exported for testing.) +exports.pathIsAQuery = pathIsAQuery + +// Set the span's `context.db` from the Elasticsearch request querystring and +// body, if the request path looks like it is a query API. +// +// Some ES endpoints, e.g. '_search', support both query params and a body. +// We encode both into 'span.context.db.statement', separated by '\n\n' +// if both are present. E.g. for a possible msearch: +// +// search_type=query_then_fetch&typed_keys=false +// +// {} +// {"query":{"query_string":{"query":"pants"}}} +exports.setElasticsearchDbContext = function (span, path, query, body) { + if (pathIsAQuery.test(path)) { + // From @elastic/elasticsearch: A read of Transport.js suggests query and + // body will always be serialized strings, however the documented + // `TransportRequestParams` allows for non-strings, so we will be defensive. + // + // From legacy elasticsearch: query will be an object and body will be an + // object, or an array of objects, e.g. for bulk endpoints. + const parts = [] + if (query) { + if (typeof (query) === 'string') { + parts.push(query) + } else if (typeof (query) === 'object') { + const encodedQuery = querystring.encode(query) + if (encodedQuery) { + parts.push(encodedQuery) + } + } + } + if (body) { + if (typeof (body) === 'string') { + parts.push(body) + } else if (Array.isArray(body)) { + parts.push(body.map(JSON.stringify).join('\n')) // ndjson + } else if (typeof (body) === 'object') { + parts.push(JSON.stringify(body)) + } + } + + span.setDbContext({ + type: 'elasticsearch', + statement: parts.join('\n\n') + }) + } +} diff --git a/lib/instrumentation/index.js b/lib/instrumentation/index.js index 1dcd822e65..2c197625d0 100644 --- a/lib/instrumentation/index.js +++ b/lib/instrumentation/index.js @@ -11,6 +11,7 @@ var shimmer = require('./shimmer') var Transaction = require('./transaction') var MODULES = [ + '@elastic/elasticsearch', 'apollo-server-core', 'bluebird', 'cassandra-driver', diff --git a/lib/instrumentation/modules/@elastic/elasticsearch.js b/lib/instrumentation/modules/@elastic/elasticsearch.js new file mode 100644 index 0000000000..3846641e5d --- /dev/null +++ b/lib/instrumentation/modules/@elastic/elasticsearch.js @@ -0,0 +1,123 @@ +'use strict' + +// Instrument the @elastic/elasticsearch module. +// +// This uses to 'request' and 'response' events from the Client (documented at +// https://www.elastic.co/guide/en/elasticsearch/client/javascript-api/current/observability.html) +// to hook into all ES server interactions. + +const { getDBDestination } = require('../../context') +const { setElasticsearchDbContext } = require('../../elasticsearch-shared') + +module.exports = function (elasticsearch, agent, { version, enabled }) { + if (!enabled) { + return elasticsearch + } + if (!elasticsearch.Client) { + agent.logger.debug('@elastic/elasticsearch@%s is not supported (no `elasticsearch.Client`) - aborting...', version) + return elasticsearch + } + + function generateSpan (params) { + const span = agent.startSpan(null, 'db', 'elasticsearch', 'request') + if (span === null) { + return null + } + + span.name = `Elasticsearch: ${params.method} ${params.path}` + return span + } + + class ApmClient extends elasticsearch.Client { + constructor (...args) { + super(...args) + + // Mapping an ES client event `result` to its active span. + // - Use WeakMap to avoid a leak from possible spans that don't end. + // - WeakMap allows us to key off the ES client `request` object itself, + // which means we don't need to rely on `request.id`, which might be + // unreliable because it is user-settable (see `generateRequestId` at + // https://www.elastic.co/guide/en/elasticsearch/client/javascript-api/current/observability.html) + const spanFromEsResult = new WeakMap() + + this.on('request', (err, result) => { + const request = result.meta.request + agent.logger.debug('intercepted call to @elastic/elasticsearch "request" event %o', + { id: request.id, method: request.params.method, path: request.params.path }) + + let span = spanFromEsResult.get(result) + + // As of @elastic/elasticsearch@7.10.0-rc.1 this event's `err` will + // always be null, but we'll be future-proof. + if (err) { + agent.captureError(err) + if (span !== undefined) { + span.end() + spanFromEsResult.delete(result) + } + return + } + + // With retries (see `makeRequest` in Transport.js) each attempt will + // emit this "request" event using the same `result` object. The + // intent is to have one Elasticsearch span plus an HTTP span for each + // attempt. + if (!span) { + span = generateSpan(request.params) + if (span) { + spanFromEsResult.set(result, span) + } + } + if (!span) { + return + } + + setElasticsearchDbContext(span, request.params.path, + request.params.querystring, request.params.body) + + const { hostname, port } = result.meta.connection.url + span.setDestinationContext( + getDBDestination(span, hostname, port)) + }) + + this.on('response', (err, result) => { + // TODO set "span.outcome" (from err and result.statusCode) + + if (err) { + // Error properties are specified here: + // https://github.com/elastic/elasticsearch-js/blob/master/lib/errors.d.ts + // - We capture some data from ResponseError, which is for + // Elasticsearch API errors: + // https://www.elastic.co/guide/en/elasticsearch/reference/current/common-options.html#common-options-error-options + // - Otherwise we explicitly turn off `captureAttributes` to avoid + // grabbing potentially large and sensitive properties like + // `err.data` on DeserializationError. + const errOpts = { + captureAttributes: false + } + if (err.name === 'ResponseError' && err.body && err.body.error) { + // Include some data from the Elasticsearch API response body: + // https://www.elastic.co/guide/en/elasticsearch/reference/current/common-options.html#common-options-error-options + errOpts.custom = { + type: err.body.error.type, + reason: err.body.error.reason, + caused_by: err.body.error.caused_by, + status: err.body.status + } + } + + agent.captureError(err, errOpts) + } + + const span = spanFromEsResult.get(result) + if (span !== undefined) { + span.end() + spanFromEsResult.delete(result) + } + }) + } + } + + agent.logger.debug('subclassing @elastic/elasticsearch.Client') + return Object.assign(elasticsearch, { Client: ApmClient }) +} diff --git a/lib/instrumentation/modules/elasticsearch.js b/lib/instrumentation/modules/elasticsearch.js index 705e76c6d2..b09793fd29 100644 --- a/lib/instrumentation/modules/elasticsearch.js +++ b/lib/instrumentation/modules/elasticsearch.js @@ -2,8 +2,7 @@ var shimmer = require('../shimmer') var { getDBDestination } = require('../context') - -var queryRegexp = /_((search|msearch)(\/template)?|count)$/ +const { setElasticsearchDbContext } = require('../elasticsearch-shared') module.exports = function (elasticsearch, agent, { enabled }) { if (!enabled) return elasticsearch @@ -19,33 +18,22 @@ module.exports = function (elasticsearch, agent, { enabled }) { var id = span && span.transaction.id var method = params && params.method var path = params && params.path - var query = params && params.query - var body = params && params.body agent.logger.debug('intercepted call to elasticsearch.Transport.prototype.request %o', { id: id, method: method, path: path }) if (span && method && path) { span.name = `Elasticsearch: ${method} ${path}` - if (queryRegexp.test(path)) { - const statement = Array.isArray(body) - ? body.map(JSON.stringify).join('\n') - : JSON.stringify(body || query) + setElasticsearchDbContext(span, path, params && params.query, + params && params.body) - if (statement) { - span.setDbContext({ - type: 'elasticsearch', - statement - }) - } - // get the remote host information from elasticsearch Transport options - const transportConfig = this._config - let host, port - if (typeof transportConfig === 'object' && transportConfig.host) { - [host, port] = transportConfig.host.split(':') - } - span.setDestinationContext(getDBDestination(span, host, port)) + // Get the remote host information from elasticsearch Transport options. + const transportConfig = this._config + let host, port + if (typeof transportConfig === 'object' && transportConfig.host) { + [host, port] = transportConfig.host.split(':') } + span.setDestinationContext(getDBDestination(span, host, port)) if (typeof cb === 'function') { var args = Array.prototype.slice.call(arguments) diff --git a/lib/parsers.js b/lib/parsers.js index 1e74d8058e..45b8508051 100644 --- a/lib/parsers.js +++ b/lib/parsers.js @@ -279,13 +279,32 @@ function getCulprit (frames) { return filename ? fnName + ' (' + filename + ')' : fnName } +// Infer the node.js module name from the top frame filename, if possible. +// Examples: +// /home/bob/.../node_modules/mymodule/index.js +// ^^^^^^^^ +// /home/bob/.../node_modules/@myorg/mymodule/index.js +// ^^^^^^^^^^^^^^^ +// or on Windows: +// C:\Users\bob\...\node_modules\@myorg\mymodule\lib\subpath\index.js +// ^^^^^^^^^^^^^^^ +let SEP = path.sep +if (SEP === '\\') { + SEP = '\\' + SEP // Escape this for use in a regex. +} +const MODULE_NAME_REGEX = new RegExp(`node_modules${SEP}([^${SEP}]*)(${SEP}([^${SEP}]*))?`) function getModule (frames) { if (frames.length === 0) return var frame = frames[0] if (!frame.library_frame) return - var match = frame.filename.match(/node_modules\/([^/]*)/) + var match = frame.filename.match(MODULE_NAME_REGEX) if (!match) return - return match[1] + var moduleName = match[1] + if (moduleName && moduleName[0] === '@' && match[3]) { + // Normalize the module name separator to '/', even on Windows. + moduleName += '/' + match[3] + } + return moduleName } function tryJsonStringify (obj) { diff --git a/package.json b/package.json index 3a759cf781..ecde3b3a8f 100644 --- a/package.json +++ b/package.json @@ -117,6 +117,7 @@ "@babel/cli": "^7.8.4", "@babel/core": "^7.8.4", "@babel/preset-env": "^7.8.4", + "@elastic/elasticsearch": "^7.10.0", "@hapi/hapi": "^18.4.1", "@koa/router": "^9.0.1", "@types/node": "^13.7.4", diff --git a/test/instrumentation/modules/@elastic/elasticsearch.js b/test/instrumentation/modules/@elastic/elasticsearch.js new file mode 100644 index 0000000000..1c37aff952 --- /dev/null +++ b/test/instrumentation/modules/@elastic/elasticsearch.js @@ -0,0 +1,490 @@ +'use strict' + +process.env.ELASTIC_APM_TEST = true +const agent = require('../../../..').start({ + serviceName: 'test', + secretToken: 'test', + captureExceptions: false, + metricsInterval: 0, + centralConfig: false +}) + +// Silence deprecation warning from @elastic/elasticsearch when using a Node.js +// version that is *soon* to be EOL'd, but isn't yet. +process.noDeprecation = true +const { Client } = require('@elastic/elasticsearch') + +const { Readable } = require('stream') +const semver = require('semver') +const test = require('tape') + +const findObjInArray = require('../../../_utils').findObjInArray +const mockClient = require('../../../_mock_http_client') +const shimmer = require('../../../../lib/instrumentation/shimmer') + +const host = (process.env.ES_HOST || 'localhost') + ':9200' +const node = 'http://' + host +const pkgVersion = require('@elastic/elasticsearch/package.json').version + +test('client.ping with promise', function userLandCode (t) { + resetAgent(checkDataAndEnd(t, 'HEAD', '/', null)) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.ping().then(function () { + agent.endTransaction() + agent.flush() + }).catch(t.error) +}) + +test('client.ping with callback', function userLandCode (t) { + resetAgent(checkDataAndEnd(t, 'HEAD', '/', null)) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.ping(function (err, _result) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +test('client.search with promise', function userLandCode (t) { + const searchOpts = { q: 'pants' } + + resetAgent(checkDataAndEnd(t, 'GET', '/_search', 'q=pants')) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client + .search(searchOpts) + .then(function () { + agent.endTransaction() + agent.flush() + }) + .catch(t.error) +}) + +test('client.child', function userLandCode (t) { + const searchOpts = { q: 'pants' } + + resetAgent(checkDataAndEnd(t, 'GET', '/_search', 'q=pants')) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + const child = client.child({ + headers: { 'x-foo': 'bar' } + }) + child.search(searchOpts, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +test('client.search with queryparam', function userLandCode (t) { + const searchOpts = { q: 'pants' } + + resetAgent(checkDataAndEnd(t, 'GET', '/_search', 'q=pants')) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.search(searchOpts, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +test('client.search with body', function userLandCode (t) { + const body = { + query: { + match: { + request: 'bar' + } + } + } + const searchOpts = { + index: 'myIndex*', + body: body + } + + resetAgent(checkDataAndEnd(t, 'POST', `/${searchOpts.index}/_search`, JSON.stringify(body))) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.search(searchOpts, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +// Test `span.context.db.statement` format when the client request includes +// both a body *and* queryparam. +test('client.search with body & queryparams', function userLandCode (t) { + const body = { + query: { + match: { + request: 'bar' + } + } + } + const searchOpts = { + index: 'myIndex*', + body: body, + size: 2, + sort: 'myField:asc' + } + const statement = `size=2&sort=myField%3Aasc + +${JSON.stringify(body)}` + + resetAgent(checkDataAndEnd(t, 'POST', `/${searchOpts.index}/_search`, statement)) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.search(searchOpts, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +test('client.searchTemplate', function userLandCode (t) { + const body = { + source: { + query: { + query_string: { + query: '{{q}}' + } + } + }, + params: { + q: 'pants' + } + } + + resetAgent(checkDataAndEnd(t, 'POST', '/_search/template', JSON.stringify(body))) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.searchTemplate({ body }, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +test('client.msearch', function userLandCode (t) { + const body = [ + {}, + { + query: { + query_string: { + query: 'pants' + } + } + } + ] + const searchOpts = { + search_type: 'query_then_fetch', + typed_keys: false, + body: body + } + const statement = `search_type=query_then_fetch&typed_keys=false + +${body.map(JSON.stringify).join('\n')} +` + + resetAgent(checkDataAndEnd(t, 'POST', '/_msearch', statement)) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.msearch(searchOpts, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +test('client.msearchTempate', function userLandCode (t) { + const body = [ + {}, + { + source: { + query: { + query_string: { + query: '{{q}}' + } + } + }, + params: { + q: 'pants' + } + } + ] + const statement = body.map(JSON.stringify).join('\n') + '\n' + + resetAgent(checkDataAndEnd(t, 'POST', '/_msearch/template', statement)) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + client.msearchTemplate({ body }, function (err) { + t.error(err) + agent.endTransaction() + agent.flush() + }) +}) + +// Test some error scenarios. + +// 'ResponseError' is the client's way of passing back an Elasticsearch API +// error. Some interesting parts of that error response body should be +// included in `err.context.custom`. +test('ResponseError', function (t) { + resetAgent( + function done (data) { + const err = data.errors[0] + t.ok(err, 'sent an error to APM server') + t.ok(err.id, 'err.id') + t.equal(err.exception.module, '@elastic/elasticsearch') + t.ok(err.exception.message, 'err.exception.message') + t.equal(err.exception.type, 'ResponseError', + 'err.exception.type is ResponseError') + t.deepEqual(err.context.custom, { + type: 'illegal_argument_exception', + reason: 'Failed to parse int parameter [size] with value [surprise_me]', + caused_by: { + type: 'number_format_exception', + reason: 'For input string: "surprise_me"' + }, + status: 400 + }) + t.end() + } + ) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + + client.search({ size: 'surprise_me', q: 'pants' }, function (err, _result) { + t.ok(err, 'got an error from search callback') + t.equal(err.name, 'ResponseError', 'error name is "ResponseError"') + agent.endTransaction() + agent.flush() + }) +}) + +// Ensure that `captureError` serialization does *not* include the possibly +// large `data` field from a deserialization error. +test('DeserializationError', function (t) { + resetAgent( + function done (data) { + const err = data.errors[0] + t.ok(err, 'sent an error to APM server') + t.ok(err.id, 'err.id') + t.ok(err.exception.message, 'err.exception.message') + t.equal(err.exception.type, 'DeserializationError', + 'err.exception.type is DeserializationError') + t.notOk(err.exception.attributes && err.exception.attributes.data, + 'captured error should NOT include "data" attribute') + t.end() + } + ) + + agent.startTransaction('myTrans') + + const client = new Client({ node }) + + // To simulate an error we monkey patch the client's Serializer such that + // deserialization of the response body fails. + shimmer.wrap(client.transport.serializer, 'deserialize', function wrapDeserialize (origDeserialize) { + return function wrappedDeserialize (json) { + return origDeserialize.call(this, json + 'THIS_WILL_BREAK_JSON_DESERIALIZATION') + } + }) + + client.search({ q: 'pants' }, function (err, _result) { + t.ok(err, 'got an error from search callback') + t.equal(err.name, 'DeserializationError', 'error name is "DeserializationError"') + agent.endTransaction() + agent.flush() + }) +}) + +if (semver.gte(pkgVersion, '7.7.0')) { + // Abort handling was added to @elastic/elasticsearch@7.7.0. + + test('request.abort() works', function (t) { + resetAgent( + function done (data) { + // We expect to get: + // - 1 elasticsearch span + // - 1 abort error (and possibly another error due to the double-callback + // bug mentioned below) + const esSpan = findObjInArray(data.spans, 'subtype', 'elasticsearch') + t.ok(esSpan, 'have an elasticsearch span') + + const err = data.errors + .filter((e) => e.exception.type === 'RequestAbortedError')[0] + t.ok(err, 'sent an error to APM server') + t.ok(err.id, 'err.id') + t.equal(err.exception.message, 'Request aborted', 'err.exception.message') + t.equal(err.exception.type, 'RequestAbortedError', + 'err.exception.type is RequestAbortedError') + + t.end() + } + ) + + agent.startTransaction('myTrans') + + // Start a request that we expect to *not* succeed quickly (artificially + // make getting the request body slow via `slowBody`) then abort as soon + // as possible. + const slowBody = new Readable({ + read (size) { + setTimeout(() => { + this.push('{"query":{"match_all":{}}}') + this.push(null) // EOF + }, 1000).unref() + } + }) + let gotCallbackAlready = false + const client = new Client({ node }) + const req = client.search({ body: slowBody }, function (err, _result) { + // Use gotCallbackAlready to avoid double-callback bug + // https://github.com/elastic/elasticsearch-js/issues/1374 + if (!gotCallbackAlready) { + gotCallbackAlready = true + t.ok(err, 'got error') + t.equal(err.name, 'RequestAbortedError', 'error is RequestAbortedError') + agent.endTransaction() + agent.flush() + } + }) + setImmediate(function () { + req.abort() + }) + }) + + test('promise.abort() works', function (t) { + resetAgent( + function done (data) { + // We expect to get: + // - 1 elasticsearch span + // - 1 abort error (and possibly another error due to a double-callback + // bug https://github.com/elastic/elasticsearch-js/issues/1374) + + const esSpan = findObjInArray(data.spans, 'subtype', 'elasticsearch') + t.ok(esSpan, 'have an elasticsearch span') + + const err = data.errors + .filter((e) => e.exception.type === 'RequestAbortedError')[0] + t.ok(err, 'sent an error to APM server') + t.ok(err.id, 'err.id') + t.ok(err.exception.message, 'err.exception.message') + t.equal(err.exception.type, 'RequestAbortedError', + 'err.exception.type is RequestAbortedError') + + t.end() + } + ) + + agent.startTransaction('myTrans') + + // Start a request that we expect to *not* succeed quickly (artificially + // make getting the request body slow via `slowBody`) then abort as soon + // as possible. + const slowBody = new Readable({ + read (size) { + setTimeout(() => { + this.push('{"query":{"match_all":{}}}') + this.push(null) // EOF + }, 1000).unref() + } + }) + const client = new Client({ node }) + const promise = client.search({ body: slowBody }) + promise + .then(_result => {}) + .catch(err => { + t.ok(err, 'got error') + t.equal(err.name, 'RequestAbortedError', 'error is RequestAbortedError') + agent.endTransaction() + agent.flush() + }) + setImmediate(function () { + promise.abort() + }) + }) +} + +// Utility functions. + +function checkDataAndEnd (t, method, path, dbStatement) { + return function (data) { + t.equal(data.transactions.length, 1, 'should have 1 transaction') + t.equal(data.spans.length, 2, 'should have 2 spans') + + const trans = data.transactions[0] + t.equal(trans.name, 'myTrans', 'should have expected transaction name') + t.equal(trans.type, 'custom', 'should have expected transaction type') + + const esSpan = findObjInArray(data.spans, 'subtype', 'elasticsearch') + t.ok(esSpan, 'have an elasticsearch span') + t.strictEqual(esSpan.type, 'db') + t.strictEqual(esSpan.subtype, 'elasticsearch') + t.strictEqual(esSpan.action, 'request') + + const httpSpan = findObjInArray(data.spans, 'subtype', 'http') + t.ok(httpSpan, 'have an http span') + t.strictEqual(httpSpan.type, 'external') + t.strictEqual(httpSpan.subtype, 'http') + t.strictEqual(httpSpan.action, 'http') + + t.equal(httpSpan.name, method + ' ' + host + path, 'http span should have expected name') + t.equal(esSpan.name, 'Elasticsearch: ' + method + ' ' + path, 'elasticsearch span should have expected name') + + t.ok(esSpan.stacktrace.some(function (frame) { + return frame.function === 'userLandCode' + }), 'esSpan.stacktrace includes "userLandCode" frame') + + // Iff the test case provided a `dbStatement`, then we expect `.context.db`. + if (dbStatement) { + t.deepEqual(esSpan.context.db, + { type: 'elasticsearch', statement: dbStatement }, + 'elasticsearch span has correct .context.db') + } else { + t.notOk(esSpan.context.db, 'elasticsearch span should not have .context.db') + } + + // Ensure "destination" context is set. + t.equal(esSpan.context.destination.service.name, 'elasticsearch', + 'elasticsearch span.context.destination.service.name=="elasticsearch"') + + t.ok(httpSpan.timestamp > esSpan.timestamp, + 'http span should start after elasticsearch span') + t.ok(httpSpan.timestamp + httpSpan.duration * 1000 < esSpan.timestamp + esSpan.duration * 1000, + 'http span should end before elasticsearch span') + + t.end() + } +} + +function resetAgent (cb) { + agent._instrumentation.currentTransaction = null + agent._transport = mockClient(cb) +} diff --git a/test/instrumentation/modules/elasticsearch.js b/test/instrumentation/modules/elasticsearch.js index 9b93d05af2..088c8b2fa8 100644 --- a/test/instrumentation/modules/elasticsearch.js +++ b/test/instrumentation/modules/elasticsearch.js @@ -1,5 +1,7 @@ 'use strict' +const { pathIsAQuery } = require('../../../lib/instrumentation/elasticsearch-shared') + process.env.ELASTIC_APM_TEST = true var host = (process.env.ES_HOST || 'localhost') + ':9200' @@ -49,7 +51,7 @@ test('client.ping with promise', function userLandCode (t) { }) test('client.search with callback', function userLandCode (t) { - resetAgent(done(t, 'POST', '/_search', '{"q":"pants"}')) + resetAgent(done(t, 'POST', '/_search', 'q=pants')) agent.startTransaction('foo') @@ -64,7 +66,7 @@ test('client.search with callback', function userLandCode (t) { }) test('client.search with abort', function userLandCode (t) { - resetAgent(3, done(t, 'POST', '/_search', '{"q":"pants"}', true)) + resetAgent(3, done(t, 'POST', '/_search', 'q=pants', true)) agent.startTransaction('foo') @@ -171,7 +173,7 @@ if (semver.satisfies(pkg.version, '>= 13')) { } test('client.count with callback', function userLandCode (t) { - resetAgent(done(t, 'POST', '/_count')) + resetAgent(done(t, 'POST', '/_count', '')) agent.startTransaction('foo') @@ -183,16 +185,15 @@ test('client.count with callback', function userLandCode (t) { }) }) -var queryRegexp = /_((search|msearch)(\/template)?|count)$/ function done (t, method, path, query, abort = false) { return function (data, cb) { - t.strictEqual(data.transactions.length, 1) - t.strictEqual(data.spans.length, 2) + t.strictEqual(data.transactions.length, 1, 'should have 1 transaction') + t.strictEqual(data.spans.length, 2, 'should have 2 spans') var trans = data.transactions[0] - t.strictEqual(trans.name, 'foo') - t.strictEqual(trans.type, 'custom') + t.strictEqual(trans.name, 'foo', 'transaction name should be "foo"') + t.strictEqual(trans.type, 'custom', 'transaction type should be "custom"') let span1, span2 { @@ -222,20 +223,21 @@ function done (t, method, path, query, abort = false) { return frame.function === 'userLandCode' }), 'include user-land code frame') - if (queryRegexp.test(path)) { - t.deepEqual(span2.context.db, { statement: query || '{}', type: 'elasticsearch' }) - const [address, port] = host.split(':') - t.deepEqual(span2.context.destination, { - service: { - name: 'elasticsearch', resource: 'elasticsearch', type: 'db' - }, - port: Number(port), - address - }) + if (pathIsAQuery.test(path)) { + t.deepEqual(span2.context.db, { statement: query, type: 'elasticsearch' }) } else { - t.notOk(span2.context) + t.notOk(span2.context.db, 'span2 should not have "context.db"') } + const [address, port] = host.split(':') + t.deepEqual(span2.context.destination, { + service: { + name: 'elasticsearch', resource: 'elasticsearch', type: 'db' + }, + port: Number(port), + address + }) + t.ok(span1.timestamp > span2.timestamp, 'http span should start after elasticsearch span') if (abort) { t.ok(span1.timestamp + span1.duration * 1000 > span2.timestamp + span2.duration * 1000, 'http span should end after elasticsearch span when req is aborted') diff --git a/test/test.js b/test/test.js index 933d0ca2f1..de81675397 100644 --- a/test/test.js +++ b/test/test.js @@ -75,6 +75,7 @@ var directories = [ 'test', 'test/instrumentation', 'test/instrumentation/modules', + 'test/instrumentation/modules/@elastic', 'test/instrumentation/modules/bluebird', 'test/instrumentation/modules/cassandra-driver', 'test/instrumentation/modules/express',