# Trace.id and transaction.id not being added to log entry

**URL:** <https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838>\
**Category:** Logs\
**Tags:** java\
**Created:** [March 30, 2021, 8:49pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838 "2021-03-30T20:49:10Z")\
**Posts on this page:** 15\
**Page:** 1

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [March 30, 2021, 8:49pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/1 "2021-03-30T20:49:10Z")

</div>

Good evening everyone,

I was able to set up the APM Java Agent and activated the log\_correlation option without further issues.

Next, I got the tool to log into a file by using the ECS Java Logging tool and its standard settings for log4j (configure a file and log appender and add those to the rootLogger).

My Java tool is able to execute Groovy Scripts, which can be configured on runtime. As the Groovy framework has not been implemented yet, I added a monitored method to the APM Java Agent `org.groovyrunner.AbstracScript#runScript`, so now I am able to see the span from within APM.

Now I’d like to see any log entries generated within this span. For this, I instantiate a Logger within my Groovy code and log an info message. Right after, I see how the entry gets sent to Elasticsearch but the fields trace.id and transaction.id are nowhere to be found.

Is there anything else I can do on my side to get this running? I have no possibility to modify the source code of the Java app or Groovy library. I can only edit the Scripts and change the configuration of the Elastic Stack.

I’d appreciate any hints and I can also provide configuration files upon request.

Thanks,  
Pablo

P.S. in case you wonder the Java app is Jira and the Groovy tool is called ScriptRunner for Jira.

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [March 31, 2021, 6:47am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/2 "2021-03-31T06:47:56Z")

</div>

Hi @pculebras and welcome to our forum!

We just merged a [bug fix](https://github.com/elastic/apm-agent-java/pull/1720) yesterday that prevented log correlation from working when log4j2 is used without slf4j. We currently have hard time deploying a daily snapshot, but if you are quick enough, you can download the latest master build [artefact](https://apm-ci.elastic.co/blue/organizations/jenkins/apm-agent-java%2Fapm-agent-java-mbp/detail/master/828/artifacts) and try it out.

Please let us know if that solved the issue.

---

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [March 31, 2021, 9:03am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/3 "2021-03-31T09:03:59Z")

</div>

Did this bug also affect log4j (without the 2)?

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [March 31, 2021, 9:41am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/4 "2021-03-31T09:41:31Z")

</div>

No... What exact version are you using?

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [March 31, 2021, 12:51pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/5 "2021-03-31T12:51:36Z")

</div>

Try setting `log_level` to `debug` and see if logs provide any hint on that.  
Even better, if you can, try to debug [`MdcActivationListener#before()`](https://github.com/elastic/apm-agent-java/blob/14117139e9893a0d1e11975c7ea219399274e8c2/apm-agent-plugins/apm-log-correlation-plugin/src/main/java/co/elastic/apm/agent/mdc/MdcActivationListener.java#L159) and see if things work as expected.

---

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [April 13, 2021, 9:51am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/6 "2021-04-13T09:51:02Z")

</div>

Sorry for the delayed response Eyal, I was OoO.

Jira provides us with log4j 1.2.17.

I'll turn on debugging and report back to you.

Kind regards,  
Pablo

---

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [April 13, 2021, 3:00pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/7 "2021-04-13T15:00:41Z")

</div>

Hi Eyal,

I set the `log_level` to `debug` and also tried debugging the jvm, but I have no clue what I should be looking for.

Could you please give me a hint?

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [April 20, 2021, 12:28pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/8 "2021-04-20T12:28:28Z")

</div>

Sorry for my delay, I was OOO as well 😃

Maybe you already know that, but worth explaining anyway: when you enable the log correlation, this means that when the span **gets activated** , the `trace.id` and `transaction.id` will be added to the MDC map. So the two things to be aware are:

1. There must be a transaction or span active in order for a logging event to be able to see the related APM trace IDs
2. If you do not update your logging configuration to include these MDC entries in the log messages, they won't show up. Normally, in log4j this is done through the `%X` placeholder in the pattern configuration.

If you carefully follow our [log correlation guide](https://www.elastic.co/guide/en/apm/agent/java/current/log-correlation.html) and still can't figure it out, please let us know and we'll see how we proceed.

---

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [April 26, 2021, 12:51pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/9 "2021-04-26T12:51:53Z")

</div>

Hi Eyal,

The APM Agent Property `enable_log_correlation` is set to true and I also set `trace_methods=com.onresolve.scriptrunner.runner.AbstractScriptRunner#runScript`, which I can find using APM Observability.

In addition to that, I added `ecs-logging-core-1.0.1.jar` and `log4j-ecs-layout-1.0.1.jar` to Tomcat's `lib` folder.

Also I included the appenders to the `log4j.properties` file:  
#####################################################  
# LOGGING LEVELS  
#####################################################  
# To turn more verbose logging on - change "WARN" to "DEBUG"  
log4j.rootLogger=INFO, filelog, ecslog, ecsconsolelog

```
#####################################################
# ECS LOG FILE LOCATIONS
#####################################################
log4j.appender.ecslog=org.apache.log4j.RollingFileAppender
log4j.appender.ecslog.File=/var/atlassian/application-data/jira/log/ecs-atlassian-jira.log
log4j.appender.ecslog.layout=co.elastic.logging.log4j.EcsLayout
log4j.appender.ecslog.layout.serviceName=jira-apm-java-agent-ecs

# ecs appender console
log4j.appender.ecsconsolelog=org.apache.log4j.ConsoleAppender
log4j.appender.ecsconsolelog.Target=System.out
log4j.appender.ecsconsolelog.layout=co.elastic.logging.log4j.EcsLayout
log4j.appender.ecsconsolelog.layout.serviceName=jira-apm-java-agent-ecs-console

```

I can also activate the span directly within my script using the API methods, but no matter what I log from within the same code, it does not receive the previously mentioned ids.

Do you have any other suggestions? Can it be because it is Groovy code and not Java?

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [April 27, 2021, 4:36am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/10 "2021-04-27T04:36:25Z")

</div>

> [@pculebras](#):
>
> Can it be because it is Groovy code and not Java?

If there is a span and it is activated on the thread that runs the script, then any logging event done on that thread should be able to find these IDs in the MDC.

Two things to try out:

1. try the new (and experimental) [`log_ecs_reformatting`](https://www.elastic.co/guide/en/apm/agent/java/current/config-logging.html#config-log-ecs-reformatting) config. It should automatically reformat your existing logs to ECS-JSON format in a new log file (you can keep or replace the original log). You should remove any ECS-logging dependency and configuration if you try it out, the agent will apply it automatically.
2. Download the latest agent [built from master](https://apm-ci.elastic.co/blue/organizations/jenkins/apm-agent-java%2Fapm-agent-java-mbp/detail/master/883/artifacts), and set `log_level=debug`, a valid `log_file` and `log_format_file=JSON`. See details about all of those in the [logging config docs](https://www.elastic.co/guide/en/apm/agent/java/current/config-logging.html#config-logging). With these, **the agent log** will be ECS-formatted, and it will include the transaction/trace IDs, so it can provide us hints with what's going on.

You can try both together.

Looking forward to get your feedback.

---

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [May 10, 2021, 12:51pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/11 "2021-05-10T12:51:30Z")

</div>

Hello again Eyal,

I recently had time to test the new `log_ecs_reformatting`. After enabling it, every single log that was being generated got an reformatted `ecs.json` file. I also turned on the debugging option as suggested by you.

Sadly, we are still unable to correlate log entries generated from within our scripts to the transaction being executed. Here is the Groovy script which is executed at runtime:

```auto
@Grapes([ 
    @Grab("co.elastic.apm:apm-agent-api:1.23.0")
])

import co.elastic.apm.api.ElasticApm
import co.elastic.apm.api.Span
import org.apache.log4j.Level
import org.apache.log4j.Logger

// this variable is binded through script properties
log.setLevel(Level.DEBUG)

// adding span
Span transaction = ElasticApm.currentSpan().setName("Script - Add delay")

// logging transaction id
log.info("transaction.id: " + transaction.id)

// logging appender info
log.info("log.appenders: ${log.getParent().getAllAppenders().collect{ it.name }}")

// this should have a transaction.id appended
log.info("Sleeping 3000ms.")
sleep(3000)

```

And here are some results:

### I can locate the span from within APM

 ![span-within-apm](https://us1.discourse-cdn.com/elastic/original/3X/3/1/31f806ce1c68ddcbb838f263f27ac855bc5a446b.png)

### It's metadata

 ![Screenshot 2021-05-10 at 14.47.21](https://us1.discourse-cdn.com/elastic/original/3X/c/b/cbac0a81ecbe5295fcf44a0df436853997de76fc.png)

### Transaction.id and trace.id do were not correlated with the log entries from the same code

 ![kibana-no-transaction-id-or-trace-id](https://us1.discourse-cdn.com/elastic/original/3X/b/4/b4d7fd5789d9a33a521bdc7b3100ad96589fdb35.png)

@Eyal_Koren, do you have any other ideas?

Kind regards,  
Pablo

---

<div class="post-metadata">

**Author:** ![pculebras](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/pculebras/32/86354_2.png) [@pculebras](https://discuss.elastic.co/u/pculebras)\
**Post date:** [May 19, 2021, 8:54am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/12 "2021-05-19T08:54:03Z")

</div>

Hello @Eyal_Koren,

did you have time by chance to check my previous post?

I am sadly currently stacked and I'd love seeing this work properly.

Thanks,  
Pablo

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [May 19, 2021, 10:08am UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/13 "2021-05-19T10:08:38Z")

</div>

Sorry, I didn't get the chance yet, it may have to wait to next week...

---

<div class="post-metadata">

**Author:** ![Eyal\_Koren](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/eyal_koren/32/36830_2.png) [@Eyal\_Koren](https://discuss.elastic.co/u/Eyal_Koren)\
**Post date:** [May 26, 2021, 4:21pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/14 "2021-05-26T16:21:51Z")

</div>

Sorry, I was quite busy lately with other stuff. So, when you tried the `log_ecs_reformatting` option, didn't the related log messages in the `ecs.json` file contain the trace and transaction IDs? Can you provide the related log lines that are produced when using it? Can you share the agent debug log?

If the `ecs.json` file entries did not contain these IDs, then the best thing I can propose at this point is to setup a dev env with our agent code and set a breakpoint at [`MdcActivationListener#before()`](https://github.com/elastic/apm-agent-java/blob/14117139e9893a0d1e11975c7ea219399274e8c2/apm-agent-plugins/apm-log-correlation-plugin/src/main/java/co/elastic/apm/agent/mdc/MdcActivationListener.java#L159). Try to see why the IDs are not added to the MDC as expected.

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [June 23, 2021, 4:22pm UTC](https://discuss.elastic.co/t/trace-id-and-transaction-id-not-being-added-to-log-entry/268838/15 "2021-06-23T16:22:08Z")

</div>

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