1

I have webapp using Spring 5.1.10, running on Jetty 9.4.20. Through out the app JCL is used for logging. Jetty is configured by enabling jcl-slf4j (to capture webapp and Spring messages) and logging-logback module and editing corresponding resources/logback.xml. In that configuration file, there is defined a logger that have two MDC's in pattern: %mdc{instance:-internal} and %mdc{user:-default}. MCD key instance is set by a Filter and user by RequestInterceptor. Basically they work, as when logging statements is called by some controller, correct values for instance and user end up in log file.

The problem is that there is controller, that deals with legacy part of the system. It looks up a class file, loads this class using custom class loader, does some setup (setting some properties) then executes a method, that actually does the job. The problem is that all loaded classes that emit log messages have both MDC keys as default values (internal and default respectively) despite both values being set to correct values.

I have added log statements to filter and request interceptor and it looks like they occupy the same thread as the class being loaded. Also I have added a test log statement to controller, which is emitted after custom class is loaded, but before its method execution. The result is that despite all entities being executed within the same thread MCD works in controllers, filters and interceptors and doesn't work with loaded classes. That leads me to believe, that class loading somehow is involved.

The question is: How I can get MDC to work within classes loaded by custom class loader?

Jacek Prucia
  • 1,026
  • 2
  • 12
  • 22
  • Is there any thread-switching involved? MDC are usually implement as ThreadLocal, and unless you do something about it, that won't survive running code on a different thread. If you legacy code maintains its own executors, that could also explain what you are seeing. – Thilo Nov 20 '19 at 12:26
  • 1
    @Thilo Definitely no. I've added `%thread` to pattern and it looks that all log messages are emitted within the same thread. – Jacek Prucia Nov 20 '19 at 12:34
  • Is that custom class loader on top of the normal one or parallel to it? Is it possible that the custom class loader loads its own version of JCL (or SLF4J or Logback) because it cannot see the regular ones? If so, it would not be able to see the MDC from the "alternate universe". – Thilo Nov 24 '19 at 02:07
  • @Thilo It is stacked on top of `WebAppClassLoader`, but I get the feeling that the loader itself might be a problem. Its logic is kinda weird to put it slightly. Oh well... legacy systems. Since it was kinda convenient for me to use `MDC.getCopyOfContextMap()`/`MDC.setContextMap()` I just did that. Is it ok with you if I delete the question? Wouldn't like such unanswerable question to linger around... – Jacek Prucia Nov 26 '19 at 17:03

0 Answers0