mysql2 seems to put the first query in it's own span when using a pool

[mbrevda]

What version of OpenTelemetry are you using?

"@opentelemetry/instrumentation-dns": "0.28.0",
"@opentelemetry/instrumentation-express": "0.29.0",
"@opentelemetry/instrumentation-fs": "0.3.0",
"@opentelemetry/instrumentation-grpc": "0.29.2",
"@opentelemetry/instrumentation-http": "0.29.2",
"@opentelemetry/instrumentation-mysql2": "0.30.0",

What version of Node are you using?

v16.12.0

What did you do?

My Config

import opentelemetry from '@opentelemetry/sdk-node'
import {diag, DiagConsoleLogger, DiagLogLevel} from '@opentelemetry/api'
import {Resource} from '@opentelemetry/resources'
import {SemanticResourceAttributes} from '@opentelemetry/semantic-conventions'
import {DnsInstrumentation} from '@opentelemetry/instrumentation-dns'
import {MySQL2Instrumentation} from '@opentelemetry/instrumentation-mysql2'
import {ExpressInstrumentation} from '@opentelemetry/instrumentation-express'
import {HttpInstrumentation} from '@opentelemetry/instrumentation-http'
import {GrpcInstrumentation} from '@opentelemetry/instrumentation-grpc'
import {WinstonInstrumentation} from '@opentelemetry/instrumentation-winston'
// import {FsInstrumentation} from '@opentelemetry/instrumentation-fs'
import {TraceExporter} from '@google-cloud/opentelemetry-cloud-trace-exporter'

// For troubleshooting, set the log level to DiagLogLevel.DEBUG
diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.INFO)

const traceExporter = process.env.K_CONFIGURATION
  ? new TraceExporter()
  : new opentelemetry.tracing.ConsoleSpanExporter()

const sdk = new opentelemetry.NodeSDK({
  resource: new Resource({
    [SemanticResourceAttributes.SERVICE_NAME]: 'segops-api'
  }),
  traceExporter,
  instrumentations: [
    // new FsInstrumentation({createHook: console.log}),
    new DnsInstrumentation(),
    new MySQL2Instrumentation(),
    new ExpressInstrumentation(),
    new GrpcInstrumentation(),
    new HttpInstrumentation(),
    new WinstonInstrumentation()
  ]
})

sdk.start()

process.on('SIGTERM', () => {
  sdk.shutdown().finally(() => process.exit(0))
})

What did you expect to see?

I expected all traces to have the same traceId

What did you see instead?

I noticed that the first MySQL query trace uses it's own id. FWIW, were using pools

Additional context

First call

debug /v1/foo  {     // <--- from logger
  "timestamp": "2022-06-07T12:33:42.320Z",
  "trace_id": "7f21606ebea9e9def4ebc66a35a76eff", // <--- ✅
  "span_id": "66e861f32ea7b8ee",
  "trace_flags": "01"
}
{
  traceId: '50177912b0a568f6c90e685395e78bd8',  // <--- 🤔
  parentId: undefined,
  name: 'SELECT',
  id: '42e1e1079bc997d9',
  kind: 2,
  timestamp: 1654605222339837,
  duration: 2799,
  attributes: {
    'db.system': 'mysql',
    'net.peer.name': 'localhost',
    'net.peer.port': 3306,
    'db.connection_string': 'jdbc:mysql://localhost:3306/myDb',
    'db.name': 'myDb',
    'db.user': 'root',
    'db.statement': "SELECT * FROM ..."
  },
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: '7f21606ebea9e9def4ebc66a35a76eff', // <--- ✅
  parentId: undefined,
  name: 'HTTP GET',
  id: '66e861f32ea7b8ee',
  kind: 1,
  timestamp: 1654605222309705,
  duration: 34959,
  attributes: {
    'http.url': 'http://127.0.0.1:3000/v1/foo',
    'http.host': '127.0.0.1:3000',
    'net.host.name': '127.0.0.1',
    'http.method': 'GET',
    'http.target': '/v1/foo',
    'http.flavor': '1.1',
    'net.transport': 'ip_tcp',
    'net.host.ip': '::ffff:127.0.0.1',
    'net.host.port': 3000,
    'net.peer.ip': '::ffff:127.0.0.1',
    'net.peer.port': 52724,
    'http.status_code': 200,
    'http.status_text': 'OK'
  },
  status: { code: 0 },
  events: [],
  links: []
}

Second call

debug /v1/foo  {
  "timestamp": "2022-06-07T12:37:57.505Z",
  "trace_id": "2d78fcc700426218f758e3b4153f65c4", // <--- ✅
  "span_id": "6f80f4662161f7b6",
  "trace_flags": "01"
}
{
  traceId: '2d78fcc700426218f758e3b4153f65c4', // <--- ✅
  parentId: '6f80f4662161f7b6',
  name: 'SELECT',
  id: 'cd0f7e5eb95562c2',
  kind: 2,
  timestamp: 1654605477492792,
  duration: 7623,
  attributes: {
    'db.system': 'mysql',
    'net.peer.name': 'localhost',
    'net.peer.port': 3306,
    'db.connection_string': 'jdbc:mysql://localhost:3306/myDb',
    'db.name': 'myDb',
    'db.user': 'root',
    'db.statement': "SELECT * FROM ..."
  },
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: '2d78fcc700426218f758e3b4153f65c4', // <--- ✅
  parentId: undefined,
  name: 'HTTP GET',
  id: '6f80f4662161f7b6',
  kind: 1,
  timestamp: 1654605477480136,
  duration: 21166,
  attributes: {
    'http.url': 'http://127.0.0.1:3000/v1/foo',
    'http.host': '127.0.0.1:3000',
    'net.host.name': '127.0.0.1',
    'http.method': 'GET',
    'http.target': '/v1/foo',
    'http.flavor': '1.1',
    'net.transport': 'ip_tcp',
    'net.host.ip': '::ffff:127.0.0.1',
    'net.host.port': 3000,
    'net.peer.ip': '::ffff:127.0.0.1',
    'net.peer.port': 53752,
    'http.status_code': 200,
    'http.status_text': 'OK'
  },
  status: { code: 0 },
  events: [],
  links: []
}
<details>

[github-actions]

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

[mbrevda]

unstale

[github-actions]

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

[mbrevda]

Really?

[github-actions]

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

[mbrevda]

.

[github-actions]

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

[mbrevda]

🫥