Skip to content

Commit

Permalink
fix: ensure run-context for mysql span does not spill into user code
Browse files Browse the repository at this point in the history 
This fixes the 'mysql' instrumentation to not have the mysql span
context be active in user code. This ensures that user code cannot
create a child span of the mysql span, which would (a) be misleading
and (b) cause problems for coming exit span and compressed span work.

Refs: #2430
  • Loading branch information
@trentm
trentm committed Nov 23, 2021
1 parent 3b0b9d1 commit 7b528e9
Show file tree
Hide file tree
Showing 3 changed files with 67 additions and 46 deletions.
4 changes: 2 additions & 2 deletions examples/trace-mysql.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,14 +26,14 @@ client.connect(function (err) {
// 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
apm.startTransaction('t1')
const t1 = apm.startTransaction('t1')
client.query('SELECT 1 + 1 AS solution', (err, res) => {
if (err) {
console.log('[t1] Failure: err is', err)
} else {
console.log('[t1] Success: solution is %s', res[0].solution)
}
apm.endTransaction()
t1.end()
})

// 2. Event emitter style
Expand Down
90 changes: 46 additions & 44 deletions lib/instrumentation/modules/mysql.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -98,59 +98,61 @@ function wrapQueryable (connection, objType, agent) {

function wrapQuery (original) {
return function wrappedQuery (sql, values, cb) {
var span = agent.startSpan(null, 'db', 'mysql', 'query')
var id = span && span.transaction.id
agent.logger.debug('intercepted call to mysql %s.query', objType)

var span = ins.createSpan(null, 'db', 'mysql', 'query')
if (!span) {
return original.apply(this, arguments)
}

var hasCallback = false
var sqlStr

agent.logger.debug('intercepted call to mysql %s.query %o', objType, { id: id })

if (span) {
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
}

const wrapCallback = function (origCallback) {
hasCallback = true
return ins.bindFunction(function wrappedCallback (_err) {
span.end()
return origCallback.apply(this, arguments)
})
}
const wrapCallback = function (origCallback) {
hasCallback = true
return ins.bindFunction(function wrappedCallback (_err) {
span.end()
return origCallback.apply(this, arguments)
})
}

switch (typeof sql) {
case 'string':
sqlStr = sql
break
case 'object':
if (typeof sql._callback === 'function') {
sql._callback = wrapCallback(sql._callback)
}
sqlStr = sql.sql
break
case 'function':
arguments[0] = wrapCallback(sql)
break
}
switch (typeof sql) {
case 'string':
sqlStr = sql
break
case 'object':
if (typeof sql._callback === 'function') {
sql._callback = wrapCallback(sql._callback)
}
sqlStr = sql.sql
break
case 'function':
arguments[0] = wrapCallback(sql)
break
}

if (sqlStr) {
agent.logger.debug('extracted sql from mysql query %o', { id: id, sql: sqlStr })
span.setDbContext({ statement: sqlStr, type: 'sql' })
span.name = sqlSummary(sqlStr)
}
span.setDestinationContext(getDBDestination(span, host, port))
if (sqlStr) {
agent.logger.debug({ sql: sqlStr }, 'extracted sql from mysql query')
span.setDbContext({ statement: sqlStr, type: 'sql' })
span.name = sqlSummary(sqlStr)
}
span.setDestinationContext(getDBDestination(span, host, port))

if (typeof values === 'function') {
arguments[1] = wrapCallback(values)
} else if (typeof cb === 'function') {
arguments[2] = wrapCallback(cb)
}
if (typeof values === 'function') {
arguments[1] = wrapCallback(values)
} else if (typeof cb === 'function') {
arguments[2] = wrapCallback(cb)
}

var result = original.apply(this, arguments)
const spanRunContext = ins.currRunContext().enterSpan(span)
const result = ins.withRunContext(spanRunContext, original, this, ...arguments)

if (span && !hasCallback && result instanceof EventEmitter) {
if (!hasCallback && result instanceof EventEmitter) {
// Wrap `result.emit` instead of `result.once('error', ...)` to avoid
// changing app behaviour by possibly setting the only 'error' handler.
shimmer.wrap(result, 'emit', function (origEmit) {
Expand All @@ -166,7 +168,7 @@ function wrapQueryable (connection, objType, agent) {
return origEmit.apply(this, arguments)
}
})
// Ensure event handlers execute in this run context.
// Ensure event handlers execute in the caller run context.
ins.bindEmitter(result)
}

Expand Down
19 changes: 19 additions & 0 deletions test/instrumentation/modules/mysql/mysql.test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
queryable.query(sql, basicQueryCallback(t))
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
})
})

Expand All @@ -63,6 +64,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
queryable.query(sql, [1], basicQueryCallback(t))
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
})
})

Expand All @@ -75,6 +77,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
queryable.query({ sql: sql }, basicQueryCallback(t))
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
})
})

Expand All @@ -87,6 +90,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
queryable.query({ sql: sql }, [1], basicQueryCallback(t))
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
})
})

Expand All @@ -100,6 +104,7 @@ factories.forEach(function (f) {
agent.startTransaction('foo')
var query = mysql.createQuery(sql, basicQueryCallback(t))
queryable.query(query)
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
})
})

Expand All @@ -113,6 +118,7 @@ factories.forEach(function (f) {
agent.startTransaction('foo')
var query = mysql.createQuery(sql, [1], basicQueryCallback(t))
queryable.query(query)
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
})
})

Expand All @@ -127,6 +133,7 @@ factories.forEach(function (f) {
factory(function () {
var trans = agent.startTransaction('foo')
queryable.query(sql)
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
setTimeout(function () {
trans.end()
}, 250)
Expand All @@ -146,6 +153,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
var stream = queryable.query(sql)
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
basicQueryStream(stream, t)
})
})
Expand All @@ -159,6 +167,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
var stream = queryable.query(sql, [1])
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
basicQueryStream(stream, t)
})
})
Expand All @@ -172,6 +181,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
var stream = queryable.query({ sql: sql })
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
basicQueryStream(stream, t)
})
})
Expand All @@ -185,6 +195,7 @@ factories.forEach(function (f) {
factory(function () {
agent.startTransaction('foo')
var stream = queryable.query({ sql: sql }, [1])
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
basicQueryStream(stream, t)
})
})
Expand All @@ -199,6 +210,7 @@ factories.forEach(function (f) {
agent.startTransaction('foo')
var query = mysql.createQuery(sql)
var stream = queryable.query(query)
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
basicQueryStream(stream, t)
})
})
Expand All @@ -213,6 +225,7 @@ factories.forEach(function (f) {
agent.startTransaction('foo')
var query = mysql.createQuery(sql, [1])
var stream = queryable.query(query)
t.equal(agent.currentSpan, null, 'mysql span should not bleed into calling code')
basicQueryStream(stream, t)
})
})
Expand All @@ -230,6 +243,7 @@ factories.forEach(function (f) {

data.spans.forEach(function (span) {
assertSpan(t, span, sql)
t.equal(span.parent_id, trans.id, 'each mysql span is a child of the transaction')
})

t.end()
Expand Down Expand Up @@ -274,6 +288,7 @@ factories.forEach(function (f) {

data.spans.forEach(function (span) {
assertSpan(t, span, sql)
t.equal(span.parent_id, trans.id, 'each mysql span is a child of the transaction')
})

t.end()
Expand Down Expand Up @@ -397,6 +412,7 @@ factories.forEach(function (f) {

function basicQueryCallback (t) {
return function (err, rows, fields) {
t.equal(agent.currentSpan, null, 'mysql span should not bleed into user callback')
t.error(err)
t.strictEqual(rows[0].solution, 2)
agent.endTransaction()
Expand All @@ -406,13 +422,16 @@ function basicQueryCallback (t) {
function basicQueryStream (stream, t) {
var results = 0
stream.on('error', function (err) {
t.equal(agent.currentSpan, null, 'mysql span should not be active in user code')
t.error(err)
})
stream.on('result', function (row) {
t.equal(agent.currentSpan, null, 'mysql span should not be active in user code')
results++
t.strictEqual(row.solution, 2)
})
stream.on('end', function () {
t.equal(agent.currentSpan, null, 'mysql span should not be active in user code')
t.strictEqual(results, 1)
agent.endTransaction()
})
Expand Down

0 comments on commit 7b528e9

Please sign in to comment.