Apm Agent Send Duplicate record in mysql

[Brayan_Alvarez]

Kibana version: 8.5.3

Elasticsearch version: 8.5.3

APM Server version: 8.5.3

APM Agent language and version: Node Js 3.41.0

Browser version: FIrefox

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

Fresh install or upgraded from other version? Fresh install

Is there anything special in your setup? No

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant):
We have worked with version 3.31.0 of the agent for node js, this version works fine, when we update to the latest version we now have a duplicate record of the last sql (mysql) operation executed inside a function, when we add a span in the function.

If we don't add the span in the function, it works fine, but when we add the span it generates the duplicate, this doesn't happen in version 3.31.0.

We tried remove version 3.41.0 and then install version 3.31.0 again and it works fine
Code Steps to reproduce:

// Add this to the VERY top of the first file loaded in your app
const apm = require('elastic-apm-node').start({
    // Override service name from package.json
    // Allowed characters: a-z, A-Z, 0-9, -, _, and space
    serviceName: 'EXPRESS2',
  
    // Set custom APM Server URL (default: http://127.0.0.1:8200)
    serverUrl: 'http://192.168.XX,XX:8200',
  })
  
  async function consulta_1(data) 
  {
    //Creamos el Span
    const span = apm.startSpan('Procedure.subcuentavehiculos',"funcion","m_test","custom",{ exitSpan: false })

    sql = `SELECT privileges FROM gs_users WHERE id =${data.id}`
    resultado = await consulta(sql)

    // Finalizamos el Span
    if (span) span.end()
  }

async function inicio() 
{
    let obj ={"host":"192.168.xx.xx","user":"xxxxxxx","password":"xxxxxxx","database":"xxxxxxx","dateStrings":true,"multipleStatements": true}

    /*Conexion Mysql */
    resultado = await require('./middleware/database')( obj )  
    console.log(resultado)
    const app = require('express')()
  
    app.get('/', async function (req, res) {
        await consulta_1({"user_id":"7","id":32})
      res.send('Hello World!')
    })
    
    app.listen(3020)
}
 inicio()

[trentm (Trent Mick)]

@Brayan_Alvarez Thank you very much for the bug report and especially the sample code.

I can reproduce the issue with this slightly modified code:

// dupe-mysql-spans.example.js
const apm = require('./').start({ // elastic-apm-node
  serviceName: 'dupe-mysql-spans',
  // spanCompressionEnabled: false
  // serverUrl: 'http://192.168.XX,XX:8200'
})

const http = require('http')
const mysql2Promise = require('mysql2/promise')

let conn

async function consulta (sql) {
  return conn.query(sql)
}

async function consulta_1 (data) {
  // Creamos el Span
  const span = apm.startSpan('Procedure.subcuentavehiculos', 'funcion', 'm_test', 'custom', { exitSpan: false })

  var sql = 'SELECT 1 + 1 as solution'
  var resultado = await consulta(sql)
  console.log('resultado: ', resultado)

  // Finalizamos el Span
  if (span) span.end()
}

async function inicio () {
  // Conexion Mysql
  conn = await mysql2Promise.createConnection({ user: 'root' })

  const app = require('express')()

  app.get('/', async function (req, res) {
    await consulta_1({ user_id: '7', id: 32 })
    res.send('Hello World!')
  })

  app.listen(3020, function () {
    http.get('http://127.0.0.1:3020/', res => {
      res.resume()
      res.on('end', () => {
        console.log('done request')
        apm.flush(() => {
          process.exit()
        })
      })
    })
  })
}
inicio()

This issue was introduced in v3.32.0 of elastic-apm-node when the span compression feature was added. As a workaround you can avoid the error by turning off span compression with the spanCompressionEnabled: false config setting.

I have a fix coming. I hope to get a release out soon with that.

[Brayan_Alvarez]

It is a pleasure to be able to support, greetings.

[trentm (Trent Mick)]

elastic-apm-node@3.41.1 is published with a fix for this now.