How should span references work?

[xnog]

Hello, I am propagating the spans and when I call startSpan passing the property childOf I have no problem. But when I pass references, it creates another row in the datadog APM dashboard and I don't know how to trace it. I thought this should be in the same trace, isn't it?

I start an span, send a message to a queue (should I finish this span after sending the message?), consume the message and start a new span referencing the one I opened before.

Thanks

[rochdev]

@xnog Can you share a code snippet, or otherwise provide the minimal code to reproduce?

[xnog]

Sure.

const amqp = require('amqplib')
const opentracing = require('opentracing')
const namespace = require('continuation-local-storage').getNamespace('default')

const url = 'amqp://localhost'
const queue = 'hello'

withTrace = (span, config = {}) => {
    config.headers = config.headers || {}

    opentracing.globalTracer().inject(
        namespace.get('current_span'), opentracing.FORMAT_TEXT_MAP, config.headers)

    return config
}

getConnection = (url, options = {}) => {
    return amqp.connect(url, options)
}

getChannel = (connection) => {
    return getConnection(url).then(connection => {
        return connection.createChannel()
    })
}

exports.produce = (message) => {
    const span = opentracing.globalTracer().startSpan('produce_queue', {
        childOf: namespace.get('current_span')
    })

    span.addTags({
        'resource': queue,
        'type': 'queue',
    })

    getChannel().then(channel => {
        channel.assertQueue(queue, { durable: false })
        channel.sendToQueue(queue, new Buffer(JSON.stringify(message)), withTrace(span))

        // should I finish?
        span.log(message)
        span.finish()
    }).catch(err => {
        console.log(err)

        // should I finish?
        span.setTag(Tags.ERROR, true)
        span.finish()
    });
}

exports.consume = () => {
    getChannel().then(channel => {
        channel.assertQueue(queue, { durable: false })
        channel.consume(queue, message => {
            console.log
            const span = opentracing.globalTracer().startSpan('consume_queue', {
                // references is not following
                references: opentracing.globalTracer().extract(opentracing.FORMAT_TEXT_MAP, message.properties.headers)
            })

            span.addTags({
                'resource': queue,
                'type': 'queue',
            })

            span.log(message.content)
            span.finish()
        }, { noAck: true })
    })
}

exports.publish = (url, config) => {
    throw new Error('Not implemented yet')
}

exports.subscribe = (url, config) => {
    throw new Error('Not implemented yet')
}

exports.register = (url, config) => {
    throw new Error('Not implemented yet')
}

[xnog]

if I don't finish the produce_queue, it doen't appear in the graph

[rochdev]

The references options should be an array of Reference instances.

Can you try:

const referencedContext = opentracing.globalTracer().extract(opentracing.FORMAT_TEXT_MAP, message.properties.headers)
const span = opentracing.globalTracer().startSpan('consume_queue', {
  references: [
    new opentracing.Reference(opentracing.REFERENCE_FOLLOWS_FROM, referencedContext)
  ]
})

Reference: https://doc.esdoc.org/github.com/opentracing/opentracing-javascript/class/src/tracer.js~Tracer.html#instance-method-startSpan

[xnog]

It work but the bar is still detached. How should be the behavior?

[rochdev]

Does it work if you use childOf instead? Both childOf and references should have the same behaviour since the Datadog API only has the notion of a parent span.

[xnog]

With childOf the chart is the same. I am thinking if I had a topic instead of a queue, how the chart would be.

[xnog]

with more than one subscriber..

[rochdev]

The then method of a promise runs in the current context and not in the context of where the promise is resolved. This means that in this case both calls to namespace.get('current_span') will return the same span, which is why both produce_queue and consume_queue are at the same level.

[xnog]

Humm.. interesting. So, you're saying that when I produce the message and call the method withTrace, he is sending the context of the http_request before? How can I get the context of the produce_queue?

[rochdev]

Can the span parameter that is passed to withTrace be used instead of calling namespace.get('current_span')?

[xnog]

Thanks, it worked! My bad in refactoring, I forgot to replace the variable. I found a thread about the promise problem you said, but it wasn't what happened. Maybe I should use cls-bluebird.

Another doubt maybe you can help me, I am calling some span.log but can't see the data in datadog's dashboard, should it be where?

Thanks!

[rochdev]

If you are using bluebird with continuation-local-storage you should definitely use cls-bluebird.

About span.log(), it is not currently implemented. It may be implemented in the future now that Datadog has a logging solution, but there is no such plan at the moment.

You can add metadata information however by using span.addTags() and it will be displayed in the dashboard. Some of them are supported by Datadog and will change UI elements, and the others will just display as text.

[rochdev]

@xnog Can this issue be closed?

[xnog]

Sorry my friend, I forgot to thank you here for the help. I used bluebird and cls-bluebird to keep the namespace through promises and solved my problem. Thank you very much.

[rochdev]

@xnog Just wanted to mention that if you weren't using bluebird before, it's not necessary to switch. Native promises have the same behaviour as bluebird + cls-bluebird.

cls-bluebird is actually used to get the same behaviour as native promises with bluebird.