APM java agent not capturing background process

Kibana version: 7.13.3

Elasticsearch version: 7.13.3

APM Server version: 7.13.3

APM Agent language and version: Java 1.25.0

Browser version: Chrome Version 93.0.4577.63

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

Fresh install or upgraded from other version? Fresh install

Is there anything special in your setup? For example, are you using the Logstash or Kafka outputs? Are you using a load balancer in front of the APM Servers? Have you changed index pattern, generated custom templates, changed agent configuration etc.

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant): We are using spring quartz as a scheduler. But somehow we are unable to get background span/transaction for this quartz. I know from ES APM documentation that by default ES APM should be able to trace background task/process such as spring quartz. But somehow we are not getting any. And, when we try to search on apm logs, we only able to get "request" and "messaging" type. image

Is this expected? If not, any idea how to trace background tasks?

Hi @Ilham_Sulaksono , welcome to the forum !

We do have support for Quartz scheduled tasks, can you tell us a bit more about the following:

  • What are the version of your dependencies for quartz, spring and spring-quartz ?
  • How do you define your jobs ? code (or pseudo-code) samples might help here.
  • Can you capture the agent debug logs using the following procedure ?

Capturing agent debug logs

Ideally this should be done outside of production:

  • it requires to restart the application
  • debug logs can be verbose
  • ideally having only a few transactions in the log help for investigation as there is less noise due to production traffic
  • if not possible, we can still use it for a few minutes in production, when using an external configuration file (doc) the log_level can be changed at runtime.

Here, we will refer to the agent log file as /tmp/agent.log, but any other location could be used.

  1. configure the agent with log_level=debug (doc) and log_file=/tmp/agent.log (doc)
  2. truncate the /tmp/agent.log file and restart the application
  3. execute a few transactions which aren't properly captured by the agent
  4. copy the /tmp/agent.log file and send it back for investigation

Hi Sylvain,
Looks like agent able to trace background job because we can see the job name in the apm agent debug log. But I'm not sure why we can't see it in Kibana

Here is the log from apm agent

{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"increment references to 'DEFAULT.revokeAuthorizationCodeJobDetail' 00-9ad7d6113718f1d2e651efeaeb6d1daf-678700d2f355f8c9-01 (63e9955a) (3)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"increment references to '' 00-9ad7d6113718f1d2e651efeaeb6d1daf-202d4d433270b29d-01 (1e0ca4e8) (1)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"increment references to 'DEFAULT.revokeAuthorizationCodeJobDetail' 00-9ad7d6113718f1d2e651efeaeb6d1daf-678700d2f355f8c9-01 (63e9955a) (4)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"Activating '' 00-9ad7d6113718f1d2e651efeaeb6d1daf-202d4d433270b29d-01 (1e0ca4e8) on thread 47", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.ElasticApmTracer"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"increment references to 'DEFAULT.revokeAuthorizationCodeJobDetail' 00-9ad7d6113718f1d2e651efeaeb6d1daf-678700d2f355f8c9-01 (63e9955a) (5)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"increment references to '' 00-9ad7d6113718f1d2e651efeaeb6d1daf-202d4d433270b29d-01 (1e0ca4e8) (2)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"Deactivating 'RabbitMQ SEND to revoke-authorization-code-scheduler' 00-9ad7d6113718f1d2e651efeaeb6d1daf-202d4d433270b29d-01 (1e0ca4e8) on thread 47", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.ElasticApmTracer"}
{"@timestamp":"2021-09-16T08:56:09.673Z", "log.level":"DEBUG", "message":"decrement references to 'DEFAULT.revokeAuthorizationCodeJobDetail' 00-9ad7d6113718f1d2e651efeaeb6d1daf-678700d2f355f8c9-01 (63e9955a) (4)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.674Z", "log.level":"DEBUG", "message":"decrement references to 'RabbitMQ SEND to revoke-authorization-code-scheduler' 00-9ad7d6113718f1d2e651efeaeb6d1daf-202d4d433270b29d-01 (1e0ca4e8) (1)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.AbstractSpan"}
{"@timestamp":"2021-09-16T08:56:09.674Z", "log.level":"DEBUG", "message":"endSpan 'RabbitMQ SEND to revoke-authorization-code-scheduler' 00-9ad7d6113718f1d2e651efeaeb6d1daf-202d4d433270b29d-01 (1e0ca4e8)", "ecs.version": "1.2.0","event.dataset":"scheduler.apm","process.thread.name":"quartzScheduler_Worker-5","log.logger":"co.elastic.apm.agent.impl.transaction.Span"}

Can you find log events starting with endTransaction ... for Quartz-related transactions?
If not, please provide a full debug log, not too long (meaning - from startup and until after a couple of jobs are fully executed) so we can see why. You can share such through gist.
If you do find such log events, try to capture log with trace level for a short period. In this level, the agent would print all documents sent to APM Server, so we can see whether such transactions are sent.