As a continuation of my previous post about Log4j MDC (Mapped Diagnostic Context), here’s a fully working code sample explaining the concept. This is a simple example where we have a one servlet and one filter. The filter intercepts each and every request and put the user name in the MDC.
The Servlet Class:
package com.veerasundar.code.log4jmdc;
import java.io.IOException;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import org.apache.log4j.Logger;
/**
* A good-for-nothing servlet which is just writing few messages to the logger
* object. Since we've configured in the log4j.properties file to include the
* userName, taken from MDC, every message will be appended with the user name
* that is set from the AuthenticationFilter
*
* @author veerasundar.com/blog
*/
public class Log4jMdcDemo extends HttpServlet {
private static Logger logger = Logger.getLogger(Log4jMdcDemo.class);
public Log4jMdcDemo() {
}
protected void doGet(HttpServletRequest request,
HttpServletResponse response) throws ServletException, IOException {
doService(request, response);
}
protected void doPost(HttpServletRequest request,
HttpServletResponse response) throws ServletException, IOException {
doService(request, response);
}
protected void doService(HttpServletRequest request,
HttpServletResponse response) throws ServletException, IOException {
logger.info("This is demo for the Log4j MDC concept");
logger.info("From Veerasundar.com/blog");
logger.debug("Just some sample messages");
}
}
A Filter to put the user name in MDC for every request call
package com.veerasundar.code.log4jmdc;
import java.io.IOException;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import org.apache.log4j.MDC;
/**
* An example authentication filter which is used to intercept all the requests
* for fetching the user name from it and put the user name to the Log4j Mapped
* Diagnostic Context (MDC), so that the user name could be used for
* differentiating log messages.
*
* @author veerasundar.com/blog
*
*/
public class AuthenticationFilter implements Filter {
@Override
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
try {
/*
* This code puts the value "userName" to the Mapped Diagnostic
* context. Since MDc is a static class, we can directly access it
* with out creating a new object from it. Here, instead of hard
* coding the user name, the value can be retrieved from a HTTP
* Request object.
*/
MDC.put("userName", "veera");
chain.doFilter(request, response);
} finally {
MDC.remove("userName");
}
}
}
Web.xml file to glue together Servlet and Filter
<?xml version="1.0" encoding="UTF-8"?> <web-app id="WebApp_ID" version="2.4" xmlns="http://java.sun.com/xml/ns/j2ee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://java.sun.com/xml/ns/j2ee http://java.sun.com/xml/ns/j2ee/web-app_2_4.xsd"> <servlet> <description> </description> <display-name>Log4jMdcDemo</display-name> <servlet-name>Log4jMdcDemo</servlet-name> <servlet-class>com.veerasundar.code.log4jmdc.Log4jMdcDemo</servlet-class> </servlet> <servlet-mapping> <servlet-name>Log4jMdcDemo</servlet-name> <url-pattern>/Log4jMdcDemo</url-pattern> </servlet-mapping> <filter> <filter-name>AuthFilter</filter-name> <filter-class>com.veerasundar.code.log4jmdc.AuthenticationFilter</filter-class> </filter> <filter-mapping> <filter-name>AuthFilter</filter-name> <url-pattern>/*</url-pattern> </filter-mapping> </web-app>
Log4j.properties file which uses the data present in MDC
# sample log4j.properties file, explaining log4j MDC concept
# author: veerasundar.com/blog
log4j.appender.consoleAppender = org.apache.log4j.ConsoleAppender
log4j.appender.consoleAppender.layout = org.apache.log4j.PatternLayout
#note the %X{userName} - this is how you fetch data from Mapped Diagnostic Context (MDC)
log4j.appender.consoleAppender.layout.ConversionPattern = %-4r [%t] %5p %c %x - %m - %X{userName}%n
log4j.rootLogger = DEBUG, consoleAppender
I hope that code explains the concept of MDC. Do let me know if you have any questions/suggestions in the comments.
…and here is the output from the log file:
0 [http-8084-2] INFO Log4jMDCDemo - This is demo for the Log4j MDC concept - veera 0 [http-8084-2] INFO Log4jMDCDemo - From Veerasundar.com/blog - veera 0 [http-8084-2] DEBUG Log4jMDCDemo - Just some sample messages - veera
and thanks to john jimenez for suggestion.
{ 27 comments… read them below or add one }
The “Mapped Diagnostic Context” implements a “map” into which key/value pair information can be stored. Just like NDC, the context is stored per thread. Values are stored by key name. Each thread could use the same key name but have different stored values. Values are stored/retreived/removed by using the familiar pattern of MDC.put(), MDC.get(), and MDC.remove() methods.
exactly.
The NDC and MDC log4j classes are used to store program/application contextual information that can then be used when logging messages. The NDC class name is org.apache.log4j.NDC. “NDC” stands for “Nested Diagnostic Context”. The MDC class name is org.apache.log4j.MDC. “MDC” stands for “Mapped Diagnostic Context”. NDC has been part of the log4j framework longer than MDC. If you haven't already, you may want to review the javadoc information for each class.
an output of the log file might add value to already a great post.
also, the username may be accessed from the request (i.e., request.getPrincipal().getName())
Just wondering if the functionality allows for grouping of log messages vs the interleaving model? Or is it usually done outside of the log files using a log analysis tool?
I don’t think grouping of log messages is possible at this level. Usually the subsequent log messages are appended to the existing messages.
Third party log analyzers could help to do such grouping and pretty-formatting.
thanks much for sharing.
you use the same key “userName” ,do not the previous values be overwrited by the later one?
No. The userName key will be local to the current thread alone and in the current thread, there will be only one userName present.
I got it ,thanks
Hi Veera,
Excellent blog. Need a clarification – Can we use the “username” pattern to write it to different Logfile (Using Fileappaender). For example log_userA.log and log_userB.log. Could this be directly done by setting the file parameter against the file appender ?
Veera
Username is printing only once and remaining it’s not printing in the logs .Is there any possible way to print the username throughtout the logs?
can you share your code? Without that, I really can’t tell what’s going wrong.
Veera
Web.xml mapping
MDCUserLogingFilter
com.citi.gcgna.cdf.dr.filters.MDCUserLogingFilter
MDCUserLogingFilter
/*
Log4jProperty file:
log4j.rootLogger=DEBUG,DRLOG
log4j.appender.DRLOG=org.apache.log4j.RollingFileAppender
log4j.appender.DRLOG.File=logs/DRLog.log
log4j.appender.DRLOG.MaxFileSize=15306KB
log4j.appender.DRLOG.BufferedIO=false
#Keep 1 old files around.
log4j.appender.DRLOG.MaxBackupIndex=5
log4j.appender.DRLOG.layout=org.apache.log4j.PatternLayout
log4j.appender.DRLOG.layout.ConversionPattern=[%d] %t %X{hostIP} %X{userID} (%F:%L) %-5p – %m%n
Filter file:
public class MDCUserLogingFilter implements Filter {
private static final Logger logger = Logger.getLogger(DRDynamicResponseFilter.class);
private FilterConfig filterConfig = null;
public MDCUserLogingFilter() {
super();
}
public void init(FilterConfig filterConfig) throws ServletException {
this.filterConfig = filterConfig;
}
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
boolean hasUsername = false;
boolean hasHostIP = false;
if ((request instanceof HttpServletRequest) && (response instanceof HttpServletResponse)) {
HttpServletRequest httpServletRequest = (HttpServletRequest) request;
HttpSession session = httpServletRequest.getSession(true);
String userName=(String) session.getAttribute(“SMUSER”);
LoginBackingBean backingBean=(LoginBackingBean) session.getAttribute(DRConstant.LOGIN_BACK_BEAN);
String hostIP=DRConstant.EMPTY;
if(null!=backingBean){
hostIP=backingBean.getEsbProperty().getClientIPAddress();
}
if(userName==null ||userName==DRConstant.EMPTY){
hasUsername=registerUsername(userName);
DRLogUtil.info(logger, “Username in Session Filter:”+userName);
//DRLogUtil.setInMDC(DRConstant.USER_ID, userName);
System.err.println(“Username registered :”+hasUsername +userName);
}else{
hasUsername=registerUsername(backingBean.getSoeid());
}
if (hostIP == null||hostIP==DRConstant.EMPTY) {
DRLogUtil.info(logger, “HostIP in Session Filter:”+hostIP);
//DRLogUtil.setInMDC(DRConstant.HOSTIP_SMALL, hostIP);
hasHostIP = registerClientAddress(hostIP);
System.err.println(“HostIP registered :”+hasUsername +userName);
}
}
try {
chain.doFilter(request, response);
} finally {
if (hasUsername) {
MDC.remove(“userID”);
}
if(hasHostIP){
MDC.remove(DRConstant.HOSTIP_SMALL);
}
}
}
And Log file
[2011-12-16 15:28:25,425] WebContainer : 0 (DRStartUpServlet.java:74) INFO – DRStartUpServlet initilization completed %%%%%%%%%%%^^^^^^^^^%%%%%%%%%%%%%%%
[2011-12-16 15:28:25,456] WebContainer : 0 (DRLogUtil.java:26) DEBUG – The Server Name:server1
[2011-12-16 15:28:25,471] WebContainer : 0 (DRLogUtil.java:32) INFO – *************** The user ID in dr startup servlet ***********************jp78272
[2011-12-16 15:28:25,487] WebContainer : 0 (DRLogUtil.java:26) DEBUG – *************** The user ID in dr startup servlet ***********************jp78272
[2011-12-16 15:28:25,596] WebContainer : 0 (DRLogUtil.java:26) DEBUG – intiateESBProperties:::getClientIPAddress127.0.0.1
[2011-12-16 15:28:25,612] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getClientIPAddress127.0.0.1
[2011-12-16 15:28:25,628] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getIBSRegionEAST
[2011-12-16 15:28:25,659] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getLOBIndicator77
[2011-12-16 15:28:25,690] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getTargetSystemIBS
[2011-12-16 15:28:25,721] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getIBSFetsRelationship1
[2011-12-16 15:28:25,737] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getAWSRelationship1
[2011-12-16 15:28:25,768] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getIBSProductID0
[2011-12-16 15:28:25,784] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getSourceDR
[2011-12-16 15:28:25,800] WebContainer : 0 (DRLogUtil.java:32) INFO – intiateESBProperties:::getServerNamelocalhost
[2011-12-16 15:28:25,815] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – MDC value set Servlet{hostIP=127.0.0.1, userID=jp78272}
[2011-12-16 15:28:25,846] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside userLoginAction() Method
[2011-12-16 15:28:25,862] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – SOEID ——->JP78272
[2011-12-16 15:28:25,909] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside LoginDelegate authenticateUser Method
[2011-12-16 15:28:26,081] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside getUserProperty in CitiSignOnAccessorESBImplgetUserProperty
[2011-12-16 15:28:26,143] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – Path of the Transaction XML file:///Y:/DebtRestructWeb/WebContent/WEB-INF/config/DRInterfaceTransactionDetails.xml
[2011-12-16 15:28:26,222] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – Size of the Transaction Map 64
[2011-12-16 15:28:26,253] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Service Name:::GetUserProperty][BindingType:::xmlbean][Cache Key:::null]For[TransactionName::::GetUserProperty ]
[2011-12-16 15:28:26,284] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ If Connection Type is:0- Eager Synchronous call is made to end point ]
[2011-12-16 15:28:26,300] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking XMLBean Request Class:::com.citigroup.sawgrass.getUserProperty.crd.req.RequestDocument for TransactionName:::GetUserProperty ]
[2011-12-16 15:28:26,393] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking RequestMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.signon.GetUserPropertyRequestMapper for TransactionName:::GetUserProperty ]
[2011-12-16 15:28:26,425] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in GetUserPropertyRequestMappermapData_o[]_o[]
[2011-12-16 15:28:28,237] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ESB Response:com.citi.gcgna.cdf.shared.common.esb.endpoint.impl.EsbResponseBase@18d818d8][For BindingType:xmlbean][ TransactionName:GetUserProperty][ ServiceName:GetUserProperty]
[2011-12-16 15:28:28,284] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking ResponseMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.signon.GetUserPropertyResponseMapper for TransactionName:::GetUserProperty ]
[2011-12-16 15:28:28,300] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in GetUserPropertyResponseMappermapData_o[]_o[]
[2011-12-16 15:28:28,347] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [End of ExecuteTransaction for TransactionName::::GetUserProperty ]
[2011-12-16 15:28:28,362] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:26) DEBUG – *** NAIT ROLE ***[Ljava.lang.String;@20502050
[2011-12-16 15:28:28,394] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside upsertuserprofile in DRHostAccessorImplupsertuserprofile
[2011-12-16 15:28:28,409] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Service Name:::upsertUserProfile][BindingType:::xmlbean][Cache Key:::null]For[TransactionName::::upsertUserProfile ]
[2011-12-16 15:28:28,440] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ If Connection Type is:0- Eager Synchronous call is made to end point ]
[2011-12-16 15:28:28,456] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking XMLBean Request Class:::com.citigroup.sawgrass.upsertUserProfile.crd.req.RequestDocument for TransactionName:::upsertUserProfile ]
[2011-12-16 15:28:28,487] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking RequestMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.upsertuserprofile.UpsertUserProfileRequestMapper for TransactionName:::upsertUserProfile ]
[2011-12-16 15:28:28,519] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in UpsertUserProfileRequestMappermapData_o[]_o[]
[2011-12-16 15:29:24,867] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ESB Response:com.citi.gcgna.cdf.shared.common.esb.endpoint.impl.EsbResponseBase@2ea22ea2][For BindingType:xmlbean][ TransactionName:upsertUserProfile][ ServiceName:upsertUserProfile]
[2011-12-16 15:29:24,882] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking ResponseMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.upsertuserprofile.UpsertUserProfileResponseMapper for TransactionName:::upsertUserProfile ]
[2011-12-16 15:29:24,898] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in UpsertUserProfileResponseMappermapData_o[]_o[]
[2011-12-16 15:29:24,929] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [End of ExecuteTransaction for TransactionName::::upsertUserProfile ]
[2011-12-16 15:29:24,960] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside createTPROProfile in DRHostAccessorImplcreateTPROProfile
[2011-12-16 15:29:24,976] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Service Name:::CreateTPROProfile][BindingType:::xmlbean][Cache Key:::null]For[TransactionName::::CreateTPROProfile ]
[2011-12-16 15:29:24,992] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ If Connection Type is:0- Eager Synchronous call is made to end point ]
[2011-12-16 15:29:25,023] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking XMLBean Request Class:::com.citigroup.sawgrass.createTPROProfile.crd.req.RequestDocument for TransactionName:::CreateTPROProfile ]
[2011-12-16 15:29:25,117] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking RequestMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.createtproprofile.CreateTPROProfileRequestMapper for TransactionName:::CreateTPROProfile ]
[2011-12-16 15:29:25,148] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in CreateTPROProfileRequestMappermapData_o[]_o[]
[2011-12-16 15:29:25,960] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ESB Response:com.citi.gcgna.cdf.shared.common.esb.endpoint.impl.EsbResponseBase@40da40da][For BindingType:xmlbean][ TransactionName:CreateTPROProfile][ ServiceName:CreateTPROProfile]
[2011-12-16 15:29:25,992] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking ResponseMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.createtproprofile.CreateTPROProfileResponseMapper for TransactionName:::CreateTPROProfile ]
[2011-12-16 15:29:26,023] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in CreateTPROProfileResponseMappermapData_o[]_o[]
[2011-12-16 15:29:26,085] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [End of ExecuteTransaction for TransactionName::::CreateTPROProfile ]
[2011-12-16 15:29:26,101] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside getTellerInfo in DRHostAccessorImplgetTellerInfo
[2011-12-16 15:29:26,148] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Service Name:::getTellerInfo][BindingType:::xmlbean][Cache Key:::null]For[TransactionName::::getTellerInfo ]
[2011-12-16 15:29:26,164] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ If Connection Type is:0- Eager Synchronous call is made to end point ]
[2011-12-16 15:29:26,195] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking XMLBean Request Class:::com.citigroup.sawgrass.getTellerInfo.crd.req.RequestDocument for TransactionName:::getTellerInfo ]
[2011-12-16 15:29:26,226] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking RequestMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.gettellerinfo.GetTellerInfoRequestMapper for TransactionName:::getTellerInfo ]
[2011-12-16 15:29:26,257] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in CreateTPROProfileRequestMapper
[2011-12-16 15:30:14,543] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [ESB Response:com.citi.gcgna.cdf.shared.common.esb.endpoint.impl.EsbResponseBase@226e226e][For BindingType:xmlbean][ TransactionName:getTellerInfo][ ServiceName:getTellerInfo]
[2011-12-16 15:30:14,558] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [Invoking ResponseMapper Class:::com.citi.gcgna.cdf.dr.dataaccess.esb.mappers.gettellerinfo.GetTellerInfoResponseMapper for TransactionName:::getTellerInfo ]
[2011-12-16 15:30:14,589] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside mapData in GetTellerInfoResponseMapper
[2011-12-16 15:30:14,621] WebContainer : 0 127.0.0.1 jp78272 (AccessorLoggerUtil.java:73) INFO – [End of ExecuteTransaction for TransactionName::::getTellerInfo ]
[2011-12-16 15:30:14,636] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside userLoginAction():DR_C or DR_S
[2011-12-16 15:30:14,668] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside LoginDelegate searchAndInsert Method
[2011-12-16 15:30:14,683] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside LoginDAO
[2011-12-16 15:30:14,715] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Query select * from LOCAL_LOGIN where upper(login_soeid)=upper(?)
[2011-12-16 15:30:15,340] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside LoginDelegate UpdateLastLogin Method
[2011-12-16 15:30:15,355] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Inside UpdateLastLogin
[2011-12-16 15:30:15,371] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Query UPDATE local_login SET Date_Last_Login = SYSDATE,LST_ENTITLE=’DR_S’ WHERE LOGIN_GEID = ?
[2011-12-16 15:30:15,699] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Login information Updated1
[2011-12-16 15:30:16,011] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Supervisor Entitlements true
[2011-12-16 15:30:16,043] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – DRAUDIT Entitlements false
[2011-12-16 15:30:16,058] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – CDBAdmin Entitlements false
[2011-12-16 15:30:16,074] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – CDB Entitlements false
[2011-12-16 15:30:16,105] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Collector Entitlements false
[2011-12-16 15:30:16,121] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – DRAdmin Entitlements false
[2011-12-16 15:30:16,136] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – ISA Entitlements false
[2011-12-16 15:30:16,168] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – MAU_Rep Entitlements false
[2011-12-16 15:30:16,183] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Phoenix_Rep Entitlements false
[2011-12-16 15:30:16,199] WebContainer : 0 127.0.0.1 jp78272 (DRLogUtil.java:32) INFO – Executive Entitlements false
[2011-12-16 15:30:18,887] WebContainer : 0 (DRLogUtil.java:32) INFO – MDC value removed from Servlet
[2011-12-16 15:30:21,981] WebContainer : 2 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:22,012] WebContainer : 2 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:30:22,059] WebContainer : 2 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:22,090] WebContainer : 2 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:30:22,121] WebContainer : 2 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:22,153] WebContainer : 2 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:30:22,184] WebContainer : 2 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:22,215] WebContainer : 2 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:30:23,715] WebContainer : 1 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:23,715] WebContainer : 2 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:23,747] WebContainer : 1 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:30:23,778] WebContainer : 3 (DRLogUtil.java:26) DEBUG – In DynamicResponseFilter
[2011-12-16 15:30:23,840] WebContainer : 3 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:30:23,778] WebContainer : 2 (DRLogUtil.java:32) INFO – DynamicResponseFilter in Debt Restruct executed!!
[2011-12-16 15:33:35,325] WebContainer : 3 (DRSessionKillerServlet.java:53) INFO – Inside DRSessionKillerServlet => soeId ***** JP78272
Here UserID and IP are printing in the log only for the thread(Webcontainer 0) and it not prining for next thread. Can you please suggest how to proceed further in this
When to remove the stored key? You are removing it in finally block. When this will happen ?
The finally block will be executed when the request completes its processing.
Good Blog, can we use this for a clustered environment? if so then what are the necessary settings, it will be great if you can details on this.
I never tried it in clustered environment.. But I assume there’s no need for any additional settings… the default options should work fine.
Hi Veera
do I need to set MDC parameters every time a request is sent ?
Isn’t there a way to set MDC only once, say, when user has just logged in and keep these values accessible for any class until session expires or user logs out ?
What if I don’t remove the variable from MDC ? Add same value again because web application make lots of other calls within that session and assigns the same user name again in the filter.
We are using Weblogic Integration 9.2 and Log4j for logging the application logs
We have a commonLogger Class which extends Log4j Logger and return a static instance of Log4j Logger for each Weblogic JPD class.
In Our Application , Each JPD class is using CommonLogger Class to return the static instance of the Logger object such as private static CommonLogger logger = CommonLogger.getInstance(ClassX.class);
Our Application is used by Multiple testers.
All the Application Logs go to common Log file APP.log
So each tester have to scroll down through the file to find his/her each piece of log.
Our goal is to generate dynamic log for each and every tester so as to save time.
For Weblogic 9.2 Server We have file called “config.xml” , This File gets updated when anything is changed or updated from the Weblogic Console.
In this config.xml File , We have a Server setting like below :
-Dlog4j.configuration=file:/path/apacheLog4jCfg.xml
This Setting is referring to File called apacheLog4jCfg.xml Which means that Weblogic Server is using apache Log4j to do the logging.
In apacheLog4jCfg.xml File , We have the setting like below :
I am using KeyFileAppender to achieve this where In ApacheLog4jcfg.xml , I have the setting like below :
<!—->
<!—->
In this Setting where appender name is APPLOGFILE class is mypackage.KeyFileAppender
param name is File and value is APP.log , this will log all the application logs to the File APP.log
i.e All the testers will hit the application and all the logs will get stored in the File “APP.log”
To generate the dynamic logs we define the following setting in Apachelog4jcfg.xml
We have ContextKey defined in the ApacheLog4jcfg.xml setting whose value is requestID.
This requestID we are using as key in MDC as MDC.put(“requestID”, RuntimeStringValue);
this RuntimeStringValue will get Appended to the APP.log file.
Suppose the Runtime value is X123
So log file should get generated like APP.X123.log
We are using MDC.put(“requestID”, RuntimeStringValue); in CommonLogger Class in the getInstance Method as below :
public static CommonLogger getInstance(Object className) {
CommonLogger CommonLogger = new CommonLogger();
if (className instanceof String) {
CommonLogger.logger = Logger.getLogger((String) className);
} else {
CommonLogger.logger = Logger.getLogger((Class) className);
}
if(RuntimeStringValue != null){
MDC.put(“requestID”,RuntimeStringValue);
}
return CommonLogger;
}
But the problem, which we are facing is that we are able to generate the Log File for first User request.
In the Second User request the logs are going to previously created log file only.
I feel it is due to static keyword present in CommonLogger getInstance(Object className) Method.
The another issue is if we remove static keyword from this method , then all the classes in the application will get affected as they are using the java syntax like private static CommonLogger logger = CommonLogger.getInstance(SomeClassX.class);
I have a questions below :
Q1 : So Using log4j , Is it possible that for each Tester testing the application , a separate log file should be created, So that he/she can see their own set of logs ?
Q2 : Can we use MDC.put for entire application or we have to provide MDC.put for each and every java class file in the application ?
The Setting in ApacheLog4jcfg.xml is
appender name=”APPLOGFILE” class=”mypackage.KeyFileAppender
param name=”File” value=”APP.log”
param name=”Append” value=”true”
param name=”ContextKey” value=”requestID”
param name=”MaxFileSize” value=”20MB”
param name=”MaxBackupIndex” value=”30″
layout class=”org.apache.log4j.PatternLayout”
param name=”ConversionPattern” value=”%d;%r;%p;[%c] — %m%n”
layout
appender
Hi veera,
if i modified my_log4j.xml while running the application. the MDC list values are cleared..how to reset it without restarting my application
Do you have any idea for this
Thanks in advance
It don’t work and cannot work dues to static method !
care to explain?
hello Veera,
I used the MDC concept as u said in standalone application.But somehow its not printing the username..i used MDC.put(“userName”,”srkth”); in main program. then modified xml file as below..am i doing something wrong..i have blown my head off..cant figure out wht the problem is
i forget to mention tht i am setting MDC.put(“userName”,”srkth”); inside public staic void main()…so can it be done inside static methods..is tht the problem
{ 1 trackback }