Skip to content

Commit

Permalink
Merge branch 'master' into trentm/run-context-mongodb
Browse files Browse the repository at this point in the history
  • Loading branch information
@trentm
trentm committed Jan 5, 2022
2 parents 814d2c4 + 7a2a312 commit 8b4466d
Show file tree
Hide file tree
Showing 7 changed files with 181 additions and 103 deletions.
5 changes: 5 additions & 0 deletions CHANGELOG.asciidoc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,12 +39,17 @@ Notes:
[float]
===== Bug fixes
* Fixes for run context handling for 'graphql' instrumentation.
({issues}2430[#2430])
* Fixes for run context handling for DynamoDB instrumentation ('aws-sdk'
package) so that a span created after an AWS client command (in the same
tick, in the command callback, or promise) is not a child of the automatic
AWS span. This change also ensures captured errors from failing client
commands are a child of the AWS span. ({issues}2430[#2430])
* Fixes for run context handling for 'pg' instrumentation. ({issues}2430[#2430])
[[release-notes-3.26.0]]
==== 3.26.0 2021/12/07
Expand Down
41 changes: 41 additions & 0 deletions examples/trace-graphql.js
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,41 @@
// A small example showing Elastic APM tracing of a script using `graphql`.
// Adapted from https://graphql.org/graphql-js/#writing-code

const apm = require('../').start({ // elastic-apm-node
serviceName: 'example-trace-graphql'
})
var { graphql, buildSchema } = require('graphql')

// Construct a schema, using GraphQL schema language
var schema = buildSchema(`
type Query {
hello: String
bye: String
}
`)

// The root provides a resolver function for each API endpoint
var root = {
hello: () => {
return 'Hello world!'
},
bye: () => {
return 'Farewell!'
}
}

// For tracing spans to be created, there must be an active transaction.
// Typically, a transaction is automatically started for incoming HTTP
// requests to a Node.js server. However, because this script is not running
// an HTTP server, we manually start a transaction. More details at:
// https://www.elastic.co/guide/en/apm/agent/nodejs/current/custom-transactions.html
const t1 = apm.startTransaction('t1')

// Run the GraphQL query '{ hello }' and print out the response
graphql(schema, '{ hello }', root).then((response) => {
console.log('hello response:', response)
})
graphql(schema, '{ bye }', root).then((response) => {
console.log('bye response:', response)
t1.end()
})
16 changes: 7 additions & 9 deletions examples/trace-pg.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,9 +3,8 @@
//
// By default this will use a Postgres on localhost with user 'postgres'.
// You can use:
// npm run docker:start
// to start a Postgres container (and other containers used for testing of
// this project).
// npm run docker:start postgres
// to start a Postgres container. Then `npm run docker:stop` to stop it.

const apm = require('../').start({ // elastic-apm-node
serviceName: 'example-trace-pg'
Expand All @@ -27,12 +26,11 @@ client.connect(function (err) {
// an HTTP server, we manually start a transaction. More details at:
// https://www.elastic.co/guide/en/apm/agent/nodejs/current/custom-transactions.html
apm.startTransaction('t1')
client.query('SELECT $1::text as message', ['Hello world!'], (err, res) => {
if (err) {
console.log('[t1] Failure: err is', err)
} else {
console.log('[t1] Success: message is %s', res.rows[0].message)
}
client.query('SELECT $1::text as message', ['hi'], (err, res) => {
console.log('[t1] err=%s res=%s', err && err.message, !err && res.rows[0].message)
})
client.query('SELECT $1::text as message', ['bye'], (err, res) => {
console.log('[t1] err=%s res=%s', err && err.message, !err && res.rows[0].message)
apm.endTransaction()
})

Expand Down
38 changes: 16 additions & 22 deletions lib/instrumentation/modules/graphql.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@ module.exports = function (graphql, agent, { version, enabled }) {
return graphql
}

const ins = agent._instrumentation

return clone({}, graphql, {
graphql (descriptor) {
const getter = descriptor.get
Expand All @@ -40,16 +42,9 @@ module.exports = function (graphql, agent, { version, enabled }) {

function wrapGraphql (orig) {
return function wrappedGraphql (schema, requestString, rootValue, contextValue, variableValues, operationName) {
var trans = agent._instrumentation.currTransaction()
var span = agent.startSpan('GraphQL: Unknown Query', 'db', 'graphql', 'execute')
var id = span && span.transaction.id
agent.logger.debug('intercepted call to graphql.graphql %o', { id: id })

// As of now, the only reason why there might be a transaction but no
// span is if the transaction have ended. But just to be sure this
// doesn't break in the future we add the extra `!span` guard as well
if (!trans || trans.ended || !span) {
agent.logger.debug('no active transaction found - skipping graphql tracing')
agent.logger.debug('intercepted call to graphql.graphql')
const span = ins.createSpan('GraphQL: Unknown Query', 'db', 'graphql', 'execute')
if (!span) {
return orig.apply(this, arguments)
}

Expand All @@ -74,7 +69,8 @@ module.exports = function (graphql, agent, { version, enabled }) {
agent.logger.debug('graphql.Source(query) failed - skipping graphql query extraction')
}

var p = orig.apply(this, arguments)
const spanRunContext = ins.currRunContext().enterSpan(span)
const p = ins.withRunContext(spanRunContext, orig, this, ...arguments)
p.then(function () {
span.end()
})
Expand All @@ -84,24 +80,21 @@ module.exports = function (graphql, agent, { version, enabled }) {

function wrapExecute (orig) {
function wrappedExecuteImpl (schema, document, rootValue, contextValue, variableValues, operationName) {
var trans = agent._instrumentation.currTransaction()
var span = agent.startSpan('GraphQL: Unknown Query', 'db', 'graphql', 'execute')
var id = span && span.transaction.id
agent.logger.debug('intercepted call to graphql.execute %o', { id: id })

// As of now, the only reason why there might be a transaction but no
// span is if the transaction have ended. But just to be sure this
// doesn't break in the future we add the extra `!span` guard as well
if (!trans || trans.ended || !span) {
agent.logger.debug('intercepted call to graphql.execute')
const span = ins.createSpan('GraphQL: Unknown Query', 'db', 'graphql', 'execute')
if (!span) {
agent.logger.debug('no active transaction found - skipping graphql tracing')
return orig.apply(this, arguments)
}

var details = extractDetails(document, operationName)
var queries = details.queries
operationName = operationName || (details.operation && details.operation.name && details.operation.name.value)
if (queries.length > 0) span.name = 'GraphQL: ' + (operationName ? operationName + ' ' : '') + queries.join(', ')
if (queries.length > 0) {
span.name = 'GraphQL: ' + (operationName ? operationName + ' ' : '') + queries.join(', ')
}

const trans = span.transaction
if (trans._graphqlRoute) {
var name = queries.length > 0 ? queries.join(', ') : 'Unknown GraphQL query'
if (trans.req) var path = getPathFromRequest(trans.req, true)
Expand All @@ -112,7 +105,8 @@ module.exports = function (graphql, agent, { version, enabled }) {
trans.type = 'graphql'
}

var p = orig.apply(this, arguments)
const spanRunContext = ins.currRunContext().enterSpan(span)
const p = ins.withRunContext(spanRunContext, orig, this, ...arguments)
if (typeof p.then === 'function') {
p.then(function () {
span.end()
Expand Down
138 changes: 69 additions & 69 deletions lib/instrumentation/modules/pg.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,12 +10,15 @@ var symbols = require('../../symbols')
var { getDBDestination } = require('../context')

module.exports = function (pg, agent, { version, enabled }) {
if (!enabled) {
return pg
}
if (!semver.satisfies(version, '>=4.0.0 <9.0.0')) {
agent.logger.debug('pg version %s not supported - aborting...', version)
return pg
}

patchClient(pg.Client, 'pg.Client', agent, enabled)
patchClient(pg.Client, 'pg.Client', agent)

// Trying to access the pg.native getter will trigger and log the warning
// "Cannot find module 'pg-native'" to STDERR if the module isn't installed.
Expand All @@ -29,7 +32,7 @@ module.exports = function (pg, agent, { version, enabled }) {
pg.__defineGetter__('native', function () {
var native = getter()
if (native && native.Client) {
patchClient(native.Client, 'pg.native.Client', agent, enabled)
patchClient(native.Client, 'pg.native.Client', agent)
}
return native
})
Expand All @@ -38,86 +41,83 @@ module.exports = function (pg, agent, { version, enabled }) {
return pg
}

function patchClient (Client, klass, agent, enabled) {
if (!enabled) return

function patchClient (Client, klass, agent) {
agent.logger.debug('shimming %s.prototype.query', klass)
shimmer.wrap(Client.prototype, 'query', wrapQuery)

function wrapQuery (orig, name) {
return function wrappedFunction (sql) {
var span = agent.startSpan('SQL', 'db', 'postgresql', 'query')
var id = span && span.transaction.id

if (sql && typeof sql.text === 'string') sql = sql.text

agent.logger.debug('intercepted call to %s.prototype.%s %o', klass, name, { id: id, sql: sql })
agent.logger.debug('intercepted call to %s.prototype.%s', klass, name)
const ins = agent._instrumentation
const span = ins.createSpan('SQL', 'db', 'postgresql', 'query')
if (!span) {
return orig.apply(this, arguments)
}

if (span) {
// get connection parameters from Client
let host, port
if (typeof this.connectionParameters === 'object') {
({ host, port } = this.connectionParameters)
}
span.setDestinationContext(getDBDestination(span, host, port))
let sqlText = sql
if (sql && typeof sql.text === 'string') {
sqlText = sql.text
}
if (typeof sqlText === 'string') {
span.setDbContext({ statement: sqlText, type: 'sql' })
span.name = sqlSummary(sqlText)
} else {
agent.logger.debug('unable to parse sql form pg module (type: %s)', typeof sqlText)
}

var args = arguments
var index = args.length - 1
var cb = args[index]
// Get connection parameters from Client.
let host, port
if (typeof this.connectionParameters === 'object') {
({ host, port } = this.connectionParameters)
}
span.setDestinationContext(getDBDestination(span, host, port))

if (this[symbols.knexStackObj]) {
span.customStackTrace(this[symbols.knexStackObj])
this[symbols.knexStackObj] = null
}
if (this[symbols.knexStackObj]) {
span.customStackTrace(this[symbols.knexStackObj])
this[symbols.knexStackObj] = null
}

if (Array.isArray(cb)) {
index = cb.length - 1
cb = cb[index]
}
let index = arguments.length - 1
let cb = arguments[index]
if (Array.isArray(cb)) {
index = cb.length - 1
cb = cb[index]
}

if (typeof sql === 'string') {
span.setDbContext({ statement: sql, type: 'sql' })
span.name = sqlSummary(sql)
const spanRunContext = ins.currRunContext().enterSpan(span)
const onQueryEnd = ins.bindFunctionToRunContext(spanRunContext, (_err) => {
agent.logger.debug('intercepted end of %s.prototype.%s', klass, name)
span.end()
})

if (typeof cb === 'function') {
arguments[index] = ins.bindFunction((err, res) => {
onQueryEnd(err)
return cb(err, res)
})
return orig.apply(this, arguments)
} else {
var queryOrPromise = orig.apply(this, arguments)

// It is important to prefer `.on` to `.then` for pg <7 >=6.3.0, because
// `query.then` is broken in those versions. See
// https://github.com/brianc/node-postgres/commit/b5b49eb895727e01290e90d08292c0d61ab86322#r23267714
if (typeof queryOrPromise.on === 'function') {
queryOrPromise.on('end', onQueryEnd)
queryOrPromise.on('error', onQueryEnd)
if (queryOrPromise instanceof EventEmitter) {
ins.bindEmitter(queryOrPromise)
}
} else if (typeof queryOrPromise.then === 'function') {
queryOrPromise.then(
() => { onQueryEnd() },
onQueryEnd
)
} else {
agent.logger.debug('unable to parse sql form pg module (type: %s)', typeof sql)
}

const onQueryEnd = (_err) => {
agent.logger.debug('intercepted end of %s.prototype.%s %o', klass, name, { id: id })
span.end()
agent.logger.debug('ERROR: unknown pg query type: %s', typeof queryOrPromise)
}

if (typeof cb === 'function') {
args[index] = agent._instrumentation.bindFunction((err, res) => {
onQueryEnd(err)
return cb(err, res)
})
return orig.apply(this, arguments)
} else {
var queryOrPromise = orig.apply(this, arguments)

// It is import to prefer `.on` to `.then` for pg <7 >=6.3.0, because
// `query.then` is broken in those versions. See
// https://github.com/brianc/node-postgres/commit/b5b49eb895727e01290e90d08292c0d61ab86322#r23267714
if (typeof queryOrPromise.on === 'function') {
queryOrPromise.on('end', onQueryEnd)
queryOrPromise.on('error', onQueryEnd)
if (queryOrPromise instanceof EventEmitter) {
agent._instrumentation.bindEmitter(queryOrPromise)
}
} else if (typeof queryOrPromise.then === 'function') {
queryOrPromise.then(
() => { onQueryEnd() },
onQueryEnd
)
} else {
agent.logger.debug('ERROR: unknown pg query type: %s %o', typeof queryOrPromise, { id: id })
}

return queryOrPromise
}
} else {
return orig.apply(this, arguments)
return queryOrPromise
}
}
}
Expand Down
Loading

0 comments on commit 8b4466d

Please sign in to comment.