Start with this log Logger creation to see the source code:org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger(Test.class);
perhapsorg.slf4j.LoggerFactory.getLogger(String name){ ILoggerFactory iLoggerFactory = getILoggerFactory(); //1 places return iLoggerFactory.getLogger(name); }
The getLogger(String name) method is also called in two places.public static Logger getLogger(Class<?> clazz) { Logger logger = getLogger(clazz.getName()); //2 places if (DETECT_LOGGER_NAME_MISMATCH) { Class<?> autoComputedCallingClass = Util.getCallingClass(); if (autoComputedCallingClass != null && nonMatchingClasses(clazz, autoComputedCallingClass)) { Util.report(String.format("Detected logger name mismatch. Given name: \"%s\"; computed name: \"%s\".", logger.getName(), autoComputedCallingClass.getName())); Util.report("See " + LOGGER_NAME_MISMATCH_URL + " for an explanation"); } } return logger; }
Look back at the getILoggerFactory() method at 1 and call the getLogget method, knowing that the Logger object is created using the factory pattern.
In three places, if the state is not initialized, the initialization is carried out first. After successful initialization, the StaticLoggerBinder object is obtained by using the singleton mode in four places, and the factory object of Logger is obtained.public static ILoggerFactory getILoggerFactory() { if (INITIALIZATION_STATE == UNINITIALIZED) { synchronized (LoggerFactory.class) { if (INITIALIZATION_STATE == UNINITIALIZED) { //3 places INITIALIZATION_STATE = ONGOING_INITIALIZATION; performInitialization(); } } } switch (INITIALIZATION_STATE) { case SUCCESSFUL_INITIALIZATION: //4 places return StaticLoggerBinder.getSingleton().getLoggerFactory(); case NOP_FALLBACK_INITIALIZATION: return NOP_FALLBACK_FACTORY; case FAILED_INITIALIZATION: throw new IllegalStateException(UNSUCCESSFUL_INIT_MSG); case ONGOING_INITIALIZATION: // support re-entrant behavior. // See also http://jira.qos.ch/browse/SLF4J-97 return SUBST_FACTORY; } throw new IllegalStateException("Unreachable code"); }
The following source code, StaticLoggerBinder, constructs the new factory object Log4jLoggerFactory
So knowing that the ILoggerFactory object taken at "1" in the source code above is an example of org.slf4j.impl.Log4jLoggerFactory, then look at Log4jLoggerFactory.getLogger(String name)private StaticLoggerBinder() { loggerFactory = new Log4jLoggerFactory(); try { @SuppressWarnings("unused") Level level = Level.TRACE; } catch (NoSuchFieldError nsfe) { Util.report("This version of SLF4J requires log4j version 1.2.12 or later. See also http://www.slf4j.org/codes.html#log4j_version"); } }
Map loggerMap of Log4jLogger Facotry stores the key-value mapping relationship of org.slf4j.Logger.public class Log4jLoggerFactory implements ILoggerFactory { // key: name (String), value: a Log4jLoggerAdapter; ConcurrentMap<String, Logger> loggerMap; public Log4jLoggerFactory() { loggerMap = new ConcurrentHashMap<String, Logger>(); } public Logger getLogger(String name) { Logger slf4jLogger = loggerMap.get(name); if (slf4jLogger != null) { return slf4jLogger; } else { org.apache.log4j.Logger log4jLogger; if (name.equalsIgnoreCase(Logger.ROOT_LOGGER_NAME)) //ROOT_LOGGER_NAME = "ROOT" log4jLogger = LogManager.getRootLogger(); else log4jLogger = LogManager.getLogger(name); //5 places Logger newInstance = new Log4jLoggerAdapter(log4jLogger); //51 places Logger oldInstance = loggerMap.putIfAbsent(name, newInstance); return oldInstance == null ? newInstance : oldInstance; } } }
"Five places" for source code, where LogManager first get s Logger log4jLogger objects to log4j
In LogManager, first look at - Dlog4j.configuration=log4j.properties to specify the log4j configuration file. If no log4j configuration file is specified, first load log4j.xml, and then load log4j.properties without log4j.xml.public class LogManager { /** * @deprecated This variable is for internal use only. It will * become package protected in future versions. * */ static public final String DEFAULT_CONFIGURATION_FILE = "log4j.properties"; static final String DEFAULT_XML_CONFIGURATION_FILE = "log4j.xml"; /** * @deprecated This variable is for internal use only. It will * become private in future versions. * */ static final public String DEFAULT_CONFIGURATION_KEY="log4j.configuration"; /** * @deprecated This variable is for internal use only. It will * become private in future versions. * */ static final public String CONFIGURATOR_CLASS_KEY="log4j.configuratorClass"; /** * @deprecated This variable is for internal use only. It will * become private in future versions. */ public static final String DEFAULT_INIT_OVERRIDE_KEY = "log4j.defaultInitOverride"; static private RepositorySelector repositorySelector; static { // By default we use a DefaultRepositorySelector which always returns 'h'. Hierarchy h = new Hierarchy(new RootLogger((Level) Level.DEBUG)); //61 places repositorySelector = new DefaultRepositorySelector(h); //6 places /** Search for the properties file log4j.properties in the CLASSPATH. */ String override = OptionConverter.getSystemProperty(DEFAULT_INIT_OVERRIDE_KEY, null); // if there is no default init override, then get the resource // specified by the user or the default config file. if(override == null || "false".equalsIgnoreCase(override)) { //Use - Dlog4j.configuration=log4j.properties to specify the log4j configuration file String configurationOptionStr = OptionConverter.getSystemProperty(DEFAULT_CONFIGURATION_KEY, null); String configuratorClassName = OptionConverter.getSystemProperty(CONFIGURATOR_CLASS_KEY, null); URL url = null; // if the user has not specified the log4j.configuration // property, we search first for the file "log4j.xml" and then // "log4j.properties" if(configurationOptionStr == null) { //If no log4j configuration file is specified, load log4j.xml first url = Loader.getResource(DEFAULT_XML_CONFIGURATION_FILE); if(url == null) { //Without log4j.xml, the log4j.properties are loaded url = Loader.getResource(DEFAULT_CONFIGURATION_FILE); } } else { try { url = new URL(configurationOptionStr); } catch (MalformedURLException ex) { // so, resource is not a URL: // attempt to get the resource from the class path url = Loader.getResource(configurationOptionStr); } } // If we have a non-null url, then delegate the rest of the // configuration to the OptionConverter.selectAndConfigure // method. if(url != null) { LogLog.debug("Using URL ["+url+"] for automatic log4j configuration."); try { //Configure log4j logs OptionConverter.selectAndConfigure(url, configuratorClassName, LogManager.getLoggerRepository()); //62 places } catch (NoClassDefFoundError e) { LogLog.warn("Error during default initialization", e); } } else { LogLog.debug("Could not find resource: ["+configurationOptionStr+"]."); } } else { LogLog.debug("Default initialization of overridden by " + DEFAULT_INIT_OVERRIDE_KEY + "property."); } } static public LoggerRepository getLoggerRepository() { if (repositorySelector == null) { //7 places repositorySelector = new DefaultRepositorySelector(new NOPLoggerRepository()); guard = null; Exception ex = new IllegalStateException("Class invariant violation"); String msg = "log4j called after unloading, see http://logging.apache.org/log4j/1.2/faq.html#unload."; if (isLikelySafeScenario(ex)) { LogLog.debug(msg, ex); } else { LogLog.error(msg, ex); } } return repositorySelector.getLoggerRepository(); //8 places } public static Logger getLogger(final String name) { // Delegate the actual manufacturing of the logger to the logger repository. return getLoggerRepository().getLogger(name); } }
Look at the getLogger method of LogManager, which actually calls getLoggerRepository(), gets the LoggerRepository object, and gets the Logger object by getLogger(name).
Let's first look at the getLoggerRepository() method
Repository Selector at 7 locations has a DefaultRepository Selector object at 6 locations when the LogManager class is loaded. The LoggerRepository-Hierarchy object is set and the DEBUG level of the log is set.
Look at 61 new Hierarchy objects:
The set Hierarchy (Logger Repository repository) method at 62 is Category's method, while log4j.Logger inherits Category:public class Hierarchy implements LoggerRepository, RendererSupport, ThrowableRendererSupport { private LoggerFactory defaultFactory; private Vector listeners; Hashtable ht; Logger root; RendererMap rendererMap; int thresholdInt; Level threshold; boolean emittedNoAppenderWarning = false; boolean emittedNoResourceBundleWarning = false; private ThrowableRenderer throwableRenderer = null; public Hierarchy(Logger root) { ht = new Hashtable(); listeners = new Vector(1); this.root = root; //log4j.Logger // Enable all level levels by default. setThreshold(Level.ALL); this.root.setHierarchy(this); //62 places rendererMap = new RendererMap(); defaultFactory = new DefaultCategoryFactory(); }
So getLoggerRepository().getLogger(name) calls Hierarchy's getLogger(String name) method. Look at the following nine// Categories need to know what Hierarchy they are in protected LoggerRepository repository; final void setHierarchy(LoggerRepository repository) { this.repository = repository; } //So eight getLoggerRepository() get Hierarchy objects. public class DefaultRepositorySelector implements RepositorySelector { final LoggerRepository repository; public DefaultRepositorySelector(LoggerRepository repository) { this.repository = repository; } }
Create an org.apache.log4j.Logger object in 10 places and save it in Hashtable ht <name, org.apache.log4j.Logger>.public class Hierarchy implements LoggerRepository, RendererSupport, ThrowableRendererSupport { private Vector listeners; Hashtable ht; Logger root; public Hierarchy(Logger root) { ht = new Hashtable(); listeners = new Vector(1); this.root = root; // Enable all level levels by default. setThreshold(Level.ALL); this.root.setHierarchy(this); rendererMap = new RendererMap(); defaultFactory = new DefaultCategoryFactory(); } public Logger getLogger(String name) { //9 places return getLogger(name, defaultFactory); } public Logger getLogger(String name, LoggerFactory factory) { //System.out.println("getInstance("+name+") called."); CategoryKey key = new CategoryKey(name); // Synchronize to prevent write conflicts. Read conflicts (in // getChainedLevel method) are possible only if variable // assignments are non-atomic. Logger logger; synchronized(ht) { Object o = ht.get(key); if(o == null) { logger = factory.makeNewLoggerInstance(name); //10 places logger.setHierarchy(this); ht.put(key, logger); updateParents(logger); //11 places return logger; } else if(o instanceof Logger) { return (Logger) o; } else if (o instanceof ProvisionNode) { //System.out.println("("+name+") ht.get(this) returned ProvisionNode"); logger = factory.makeNewLoggerInstance(name); logger.setHierarchy(this); ht.put(key, logger); updateChildren((ProvisionNode) o, logger); updateParents(logger); return logger; } else { // It should be impossible to arrive here return null; // but let's keep the compiler happy. } } }
In 11 updateParents methods:
Look at the source code here, such as Logger created for the w.x.y.z.Foo class, and then its parent w.x.y...private void updateParents(Logger cat) { String name = cat.name; int length = name.length(); boolean parentFound = false; //System.out.println("UpdateParents called for " + name); // if name = "w.x.y.z", loop thourgh "w.x.y", "w.x" and "w", but not "w.x.y.z" for(int i = name.lastIndexOf('.', length-1); i >= 0; i = name.lastIndexOf('.', i-1)) { String substr = name.substring(0, i); //System.out.println("Updating parent : " + substr); CategoryKey key = new CategoryKey(substr); // simple constructor Object o = ht.get(key); // Create a provision node for a future parent. if(o == null) { //System.out.println("No parent "+substr+" found. Creating ProvisionNode."); ProvisionNode pn = new ProvisionNode(cat); ht.put(key, pn); } else if(o instanceof Category) { parentFound = true; cat.parent = (Category) o; //System.out.println("Linking " + cat.name + " -> " + ((Category) o).name); break; // no need to update the ancestors of the closest ancestor } else if(o instanceof ProvisionNode) { ((ProvisionNode) o).addElement(cat); } else { Exception e = new IllegalStateException("unexpected object type " + o.getClass() + " in ht."); e.printStackTrace(); } } // If we could not find any existing parents, then link with root. if(!parentFound) cat.parent = root; }
Everywhere, even if the log4j Logger object log4jLogger has been created.
Back to "51" of the source code, use log4jLogger to create an adapter => slf4j Logger object and save it in the Concurrent HashMap object loggerMap of org.slf4j.impl.Log4jLoggerFactory. Next time, use it directly instead of new.
When the Log4jLoggerAdapter object newInstance is first published by new, it contains the relevant attributes of org.apache.log4j.Logger logger:public final class Log4jLoggerAdapter extends MarkerIgnoringBase implements LocationAwareLogger, Serializable { private static final long serialVersionUID = 6182834493563598289L; final transient org.apache.log4j.Logger logger; /** * Following the pattern discussed in pages 162 through 168 of "The complete * log4j manual". */ final static String FQCN = Log4jLoggerAdapter.class.getName(); // Does the log4j version in use recognize the TRACE level? // The trace level was introduced in log4j 1.2.12. final boolean traceCapable; // WARN: Log4jLoggerAdapter constructor should have only package access so // that // only Log4jLoggerFactory be able to create one. Log4jLoggerAdapter(org.apache.log4j.Logger logger) { this.logger = logger; this.name = logger.getName(); traceCapable = isTraceCapable(); } //Other omissions... }
Look at Category's call Appenders method:{ aai = null; additve = true; level = null; parent = org.apache.log4j.spi.RootLogger; repository = org.apache.log4j.Hierarchy; resourceBundle = null; }
For 11 locations, the current aai of log4j.Logger is null, which loops back to its parent, RootLogger, while the Appender Attachable Impl aai of RootLogger is not empty.public void callAppenders(LoggingEvent event) { int writes = 0; for(Category c = this; c != null; c=c.parent) { // Protected against simultaneous call to addAppender, removeAppender,... synchronized(c) { if(c.aai != null) { //11 places writes += c.aai.appendLoopOnAppenders(event); } if(!c.additive) { break; } } } if(writes == 0) { repository.emitNoAppenderWarning(this); } }
[org.apache.log4j.ConsoleAppender, org.apache.log4j.DailyRollingFileAppender]
In fact, the focus is on how log4j is initialized. Here we look at the configuration file as log4j.properties.
For example, log4j.properties content:
The info of log4j.rootLogger represents the log level, while stdout and D indicate that the log needs to be exported to the corresponding Appender.log4j.rootLogger = info, stdout, D log4j.appender.stdout = org.apache.log4j.ConsoleAppender log4j.appender.stdout.layout = org.apache.log4j.PatternLayout log4j.appender.stdout.layout.ConversionPattern = %d{MM-dd HH:mm:ss}:%p(%L) %c - %m%n log4j.appender.D = org.apache.log4j.DailyRollingFileAppender log4j.appender.D.File = logs/stdout.log log4j.appender.D.DatePattern = '.'yyyy-MM-dd log4j.appender.D.Append = true log4j.appender.D.Encoding=UTF-8 log4j.appender.D.Threshold = INFO log4j.appender.D.layout = org.apache.log4j.PatternLayout log4j.appender.D.layout.ConversionPattern = %d{MM-dd HH:mm:ss}:%p(%L) %c - %m%n
At the source code "62" of LogManager above, the OptionConverter.selectAndConfigure(...) method is called to configure log4j, and the PropertyConfigurator.doConfigure method is called here.
The doConfigure method configures the Appender of RootLogger:
Take RootLogger at 12 places and call the parseCategory method to add the configuration Appender class of log4j.properties to RootLogger. From the log4j.properties file above, you can see that two Appenders will be loaded.void configureRootCategory(Properties props, LoggerRepository hierarchy) { String effectiveFrefix = ROOT_LOGGER_PREFIX; String value = OptionConverter.findAndSubst(ROOT_LOGGER_PREFIX, props); if(value == null) { value = OptionConverter.findAndSubst(ROOT_CATEGORY_PREFIX, props); effectiveFrefix = ROOT_CATEGORY_PREFIX; } if(value == null) LogLog.debug("Could not find root logger information. Is this OK?"); else { Logger root = hierarchy.getRootLogger(); //12 places synchronized(root) { parseCategory(props, root, effectiveFrefix, INTERNAL_ROOT_NAME, value); } } }
Org. apache. log4j. Console Appender and org. apache. log4j. Daily Rolling File Appender.
So back to 11 of Category's call Appenders methods
When printing logs, Appenders are called iteratively, the two Appenders that call the log4j.properties configurationif(c.aai != null) { writes += c.aai.appendLoopOnAppenders(event); } appendLoopOnAppenders Method: public int appendLoopOnAppenders(LoggingEvent event) { int size = 0; Appender appender; if(appenderList != null) { size = appenderList.size(); for(int i = 0; i < size; i++) { appender = (Appender) appenderList.elementAt(i); appender.doAppend(event); //13 places } } return size; }
Appender's doAppend method is called in 13 places. Appender Skeleton is the abstract class of Appender's implementation.
So the doAppend method of AppenderSkeleton is called first:
In AppenderSkeleton's doAppend method above, "14 places" look for the chain Filter (equivalent to the responsibility chain mode), according to the return status of the Filter:public abstract class AppenderSkeleton implements Appender, OptionHandler { public synchronized void doAppend(LoggingEvent event) { if(closed) { LogLog.error("Attempted to append to closed appender named ["+name+"]."); return; } if(!isAsSevereAsThreshold(event.getLevel())) { return; } Filter f = this.headFilter; FILTER_LOOP: while(f != null) { //14 places switch(f.decide(event)) { case Filter.DENY: return; case Filter.ACCEPT: break FILTER_LOOP; case Filter.NEUTRAL: f = f.getNext(); } } this.append(event); //15 places } abstract protected void append(LoggingEvent event); }
1.Filter.DENY, no log printing, method end;
2.Filter.ACCEPT, can print logs, exit the cycle;
3.Filter.NEUTRAL, neutral state, left to the next Filter to decide.
Finally, Appender Skeleton's inheritance class implements the append method by calling the append abstract method at "15 places".
Print to console:
public class ConsoleAppender extends WriterAppender {}
Print to file (date scroll):
public class DailyRollingFileAppender extends FileAppender {}
public class FileAppender extends WriterAppender {}
public class WriterAppender extends AppenderSkeleton {}
If you use asynchronous logs, log4j configuration files need to use log4j.xml, and the Appender used for asynchronous logs is org.apache.log4j.AsyncAppender.
public class AsyncAppender extends AppenderSkeleton implements AppenderAttachable {}
It can be seen that the asynchronous log Appender also inherits Appender Skeleton.
Next I rewrote Appender for the asynchronous log myself:
https://github.com/jjavaboy/lam-nio/blob/master/lam-nio-core/src/main/java/lam/log/LamScheduleAsyncAppender.java
log4j.xml configuration file:
https://github.com/jjavaboy/lam-nio/blob/master/lam-schedule/src/main/resources/log4j.xml