MDC Logging from methods called with Spring expression

[jritter]

Hi everybody

I am wondering whether it is possible to log the Activiti MDC Attributes in Log messages which are generated by our own code which is called by a Service Task. I've followed the instructions in the Activiti User Guide (http://www.activiti.org/userguide/#MDC), and the keys are showing up in the logfile. The value of these 3 attributes always seems to be empty though.

Here an example:

18:20:39,796 [pool-13-thread-1] INFO  my.package.MyClass ProcessDefinitionId= executionId= mdcProcessInstanceID= mdcBusinessKey=  - endEvent started: End‍‍‍

my Appender configuration looks as follows:

log4j.appender.CA.layout.ConversionPattern= %d{HH:mm:ss,SSS} [%t] %-5p %c{1.} ProcessDefinitionId=%X{mdcProcessDefinitionID} executionId=%X{mdcExecutionId} mdcProcessInstanceID=%X{mdcProcessInstanceID} mdcBusinessKey=%X{mdcBusinessKey} %x - %m%n‍‍‍

In the code which is called by the Service Task by an expression or delegate expression, I do the following:

 logger.info("my Message")‍‍‍

The logger instances is obtained by the following call:

static final Log logger = LogFactory.getLog(MyClass.class.getName());‍‍‍

What do I have to do so that these MDC attributes show up in my custom log messages? Do I miss something?

Any help is appreciated.

Thanks and regards,
Juerg

[warper]

Hi Juerg!
Activiti engine sources (I scanned community edition version 5.20)  contain only 1 file file directly working with MDC: org\activiti\engine\logging\LogMDC.java
It's used in few cases of exception handling. Something like this appears in catch blocks:
LogMDC.putMDCExecution(execution);
There are no calls of MDC, LogMDC in engine apart from exceptions…
There is also MDC context clearing function - LogMDC.clear(), which simply clears the whole MDC context (for current thread due to MDC context nature, but still the whole context instead of only activiti-related values).

You can set up MDC context directly calling LogMDC.putMDCExecution with current execution in your every delegate(listener).
As you probably know, you should also clean up MDC context, since it is thread-local variable and threads will be reused by executioners or web-service engine.

[jritter]

Hi Warper

Thanks a lot for your pointers, that really helped. I've set up a listener which invokes the puMDCExecution according to the event which has been triggered the listener. That seems to work, but I'm not sure yet whether this also holds when multiple workflows are running in parallel. I'll yet have to figure that out.

Thanks again and regards,
Juerg

[mmalczewski]

Putting a listener is one solution, but you can (and you will) forget about it. I'm experimenting with CommandContextFactory, which can be set in ProcessEngineConfigurationImpl:
<code>
class MDCCommandContextFactory extends CommandContextFactory {

@Override
public CommandContext createCommandContext(Command<?> cmd) {
  return new MDCCommandContext(cmd, processEngineConfiguration);
}
}

class MDCCommandContext extends CommandContext {

public MDCCommandContext(Command<?> command, ProcessEngineConfigurationImpl processEngineConfiguration) {
  super(command, processEngineConfiguration);
}

@Override
public void performOperation(AtomicOperation executionOperation, InterpretableExecution execution) {
  LogMDC.putMDCExecution(execution);
  try {
   super.performOperation(executionOperation, execution);
  }
  finally {
   LogMDC.clear();
  }
}
}
</code>

This should set MDC information for each and every action, shouldn't it?

[jritter]

Thanks for your comment featur, that looks like a promising solution as well! I'll surely have a look at this too.

I'm curious, what kind of problems have you had with listeners?

[mmalczewski]

> I'm curious, what kind of problems have you had with listeners?
You must remember to use them. Somebody will forget about it at some point, that's more than sure in larger projects.