Is Log4J MDC thread safe with servlets ?

Discussions

Web tier: servlets, JSP, Web frameworks: Is Log4J MDC thread safe with servlets ?

  1. Hi All, We have a web application running on Weblogic 8.1.3.0 with JDK 1.4. This Web application has a servlet. In the “service” method of the servlet we declare and initialize a local variable type org.apache.log4j.Logger. We use this logger to log messages for the servlet. We use the log4J “MDC” (Mapped Diagnostic Context) to log custom information in our logs. We save our application info in the MDC and log4J automatically log this info for log messages posted in the servlet thread pertinent to the hit received by the servlet. The log4J documentation guarantees that the MDC is thread safe and that can be used in servlets and handle multiple client simultaneously. Each custom data saved in the MDC is distinct to the thread the MDC was invoked. When using loadRunner to perform “multiple client simultaneously hit” test we notice that the MDC is not honoring the custom data stored in the MDC for the particular thread. For instance, our log4j layout ConversionPattern is… %d{MM/dd/yyyy HH:mm:ss} %p %X{LOG_TYPE} %X{SERVER_NAME} %X{CLASS_NAME} %X{METHOD_NAME} %r %X{ID} %X{SESSION_ID} %m%n As we can see in the two log records below, our logs show that different hits to our servlet are sharing the same ID and SESSION_ID even though they were stored in the MDC in different servlet “service” method invokations (different threads)… 05/22/2006 17:05:29 INFO 1 erappstg02 ErrorReportReceiver service 481559 4675119 erappstg02_c5211851-5839-4fc3-9ced-7e8c040461f5_1148342728742:1148342728742 This is my message. 05/22/2006 17:05:29 INFO 1 erappstg02 ErrorReportReceiver service 481560 4675119 erappstg02_c5211851-5839-4fc3-9ced-7e8c040461f5_1148342728742:1148342728742 This is my message. The IDs and SESSION_ID above are generated in the servlet “service” method from database sequences and are unique for every servlet “service” method invocation. This is only noticed when we run “multiple client simultaneously hit” test or when we receive multiple client exact simultaneous hit on a same server in our production environment. We notice that the number of log records we have for the “This is my message” message with the same ID and session_ID is equal to the number of missing log records with the “This is my message” message for other hits, which means that the MDC is not passing the right data to the logger for the thread of these hits. It seems that either I am doing something wrong or there is a bug with MDCs. Anyone has a clue ? Thanks in advace, Eduardo.

    Threaded Messages (2)

  2. Hi - Was this issue resolved?

    I'm seeing similar issue in my application running on WebLogic application server.

     

  3. same here[ Go to top ]

    Did anyone got some result/fix with eduardo's scenario?