APM - Trace elastic query

Hi, I have a nodejs service that performs query to elastic search via the npm elasticsearch module. In such service, an apm agent is started and communicates correctly with the apm server. Metrics are traced correctly as well as transactions.
I expect apm agent to automatically trace query to elastic as transactions. However, this doesn't happen and the only solution seems to manually wrap each query into a custom transaction.

Is this a misconfiguration problem? I couldn't find solutions in docs.

Thanks in advance

Here my system spec:

Kibana version:
6.6.1

Elasticsearch version:
6.x

APM Server version:
6.6.1

APM Agent language and version:
Nodejs 2.x

By default the Node.js agent will only automatically start a new transaction every time a new incoming HTTP request is received by the Node.js application. In case of non-HTTP server based applications, you need to start the transaction manually.

You can read more about this behavior and when to manually start transactions in our Custom Transactions section.

As you correctly discovered, Elasticsearch is automatically instrumented as long as the query is performed in the scope of an active transaction.

Can I ask what type of application you are instrumenting? Is it for instance pulling jobs of a queue, or is it started via a cron job, or run manually?

Great wa7son, I think you spotted the problem.

I have two services, api and data, which communicate via a bus (nats). So the workflow is:

Browser --http--> api --bus--> data --http--> ElasticSearch.

So suppose you perform GET api/books on api service, you'll correctly have a transaction for such request. However, the resulting query will not be traced. I hoped this to happen out-of-the-box, but it's not the case.

I understand now the problem is there's no transaction in the context of data service, so query won't be traced. Should I manually create a transaction for each incoming request to the service? If so, how can I then relate such transaction with the one happening in the upstream api service, thus I will enjoy distributed transaction reports?

Thanks

Ah yes, we could do a much better job of documenting how to continue the trace when for instance pull a job from a queue or processing work on bus.

In short, what you need to do is first serialize the trace context on the api service side and write it to the bus together with the message. Then on the data service side, you need to give that trace context as an argument to the apm.startTransaction() function using the childOf option.

I can also see now that we actually haven't exposed a public API to serialize the trace context either, which obviously is a mistake (This is only exposed in our OpenTracing API, but should obviously also be exposed in our native API - I'll be sure to correct that). I've included a snippet below showing how you can do this using a private API for now (note that this API might change).

In the api service:

const trans = apm.currentTransaction

// guard against if there's no active transaction
// or if `_context` later gets removed
const context = trans && trans._context && trans._context.toString()

// attach the trace context as "metadata" to the
// message before adding it to the bus
const message = {
  data: {...},
  traceparent: context
}

addMessageToBus(message)

In the data service:

const message = getMessageFromBus()
const traceparent = message.traceparent

apm.startTransaction('processing data', 'worker', { childOf: traceparent })

// ...do work...

apm.endTransaction()

What bus are you using? There might be a use-case for the agent to do all this automatically just as we do with HTTP requests.

I've created an issue to ensure a public API to serialize the trace context gets added: https://github.com/elastic/apm-agent-nodejs/issues/890

1 Like

Tanks a lot wa7son! That's quite easy indeed, shame it's not in docs. Do you think we can add this use case here https://www.elastic.co/guide/en/apm/agent/nodejs/current/custom-transactions.html?

a couple of considerations:

  1. We use nats, more specifically its go implementation.
  2. Once I set up the traceparent into the downstream service (data), I had to manually delete transaction from the upstream log in order to see nested transactions in Kibana - I think it's correct, but a bit unexpected.

Thanks!

Yes, once this gets a proper public API, we'll make sure it's documented as well.

Do you use a node module to communicate with nats?

Once I set up the traceparent into the downstream service ( data ), I had to manually delete transaction from the upstream log in order to see nested transactions in Kibana - I think it's correct, but a bit unexpected.

I'm not sure I understand what you mean. Where did you have to delete the transaction and why?

I had an inconsistent view on Kibana regarding transactions before and after applying the fix you proposed. I solved by deleting all transactions in db and starting again (I was in dev environment so I could). I tried to replicate but I failed, so I guess it was just me.

I thought it could be a bug, I'll open a proper issue once I can replicate it.

Thanks!

If you can do that, that would be great. If it's Kibana related then you can open it in this repo: https://github.com/elastic/kibana

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.