南京营销网站建设,设计公司算什么企业,做旅行社业务的网站都有哪些,河南住房和城乡建设厅网站特种前言
log4j2是apache在log4j的基础上#xff0c;参考logback架构实现的一套新的日志系统#xff08;我感觉是apache害怕logback了#xff09;。 log4j2的官方文档上写着一些它的优点#xff1a;
在拥有全部logback特性的情况下#xff0c;还修复了一些隐藏问题API 分离参考logback架构实现的一套新的日志系统我感觉是apache害怕logback了。 log4j2的官方文档上写着一些它的优点
在拥有全部logback特性的情况下还修复了一些隐藏问题API 分离现在log4j2也是门面模式使用日志默认的日志实现是log4j2当然你也可以用logback应该没有人会这么做性能提升log4j2包含下一代基于LMAX Disruptor library的异步logger在多线程场景下拥有18倍于log4j和logback的性能多API支持log4j2提供Log4j 1.2, SLF4J, Commons Logging and java.util.logging (JUL) 的API支持避免锁定使用Log4j2 API的应用程序始终可以选择使用任何符合SLF4J的库作为log4j-to-slf4j适配器的记录器实现自动重新加载配置与Logback一样Log4j 2可以在修改时自动重新加载其配置。与Logback不同它会在重新配置发生时不会丢失日志事件。高级过滤 与Logback一样Log4j 2支持基于Log事件中的上下文数据标记正则表达式和其他组件进行过滤。插件架构 Log4j使用插件模式配置组件。因此您无需编写代码来创建和配置AppenderLayoutPattern Converter等。Log4j自动识别插件并在配置引用它们时使用它们。属性支持您可以在配置中引用属性Log4j将直接替换它们或者Log4j将它们传递给将动态解析它们的底层组件。Java 8 Lambda支持自定义日志级别产生垃圾少在稳态日志记录期间Log4j 2 在独立应用程序中是无垃圾的在Web应用程序中是低垃圾。这减少了垃圾收集器的压力并且可以提供更好的响应时间性能。和应用server集成版本2.10.0引入了一个模块log4j-appserver以改进与Apache Tomcat和Eclipse Jetty的集成。
Log4j2类图 这次从四个地方去探索源码启动配置异步插件化
源码探索
启动
log4j2的关键组件
LogManager根据配置指定LogContexFactory初始化对应的LoggerContext LoggerContext1、解析配置文件解析为对应的java对象。 2、通过LoggerRegisty缓存Logger配置 3、Configuration配置信息 4、start方法解析配置文件转化为对应的java对象 5、通过getLogger获取logger对象 Logger
LogManaer
该组件是Log4J启动的入口后续的LoggerContext以及Logger都是通过调用LogManager的静态方法获得。我们可以使用下面的代码获取Logger
Logger logger LogManager.getLogger();
可以看出LogManager是十分关键的组件因此在这个小节中我们详细分析LogManager的启动流程。 LogManager启动的入口是下面的static代码块
/*** Scans the classpath to find all logging implementation. Currently, only one will be used but this could be* extended to allow multiple implementations to be used.*/static {// Shortcut binding to force a specific logging implementation.final PropertiesUtil managerProps PropertiesUtil.getProperties();final String factoryClassName managerProps.getStringProperty(FACTORY_PROPERTY_NAME);if (factoryClassName ! null) {try {factory LoaderUtil.newCheckedInstanceOf(factoryClassName, LoggerContextFactory.class);} catch (final ClassNotFoundException cnfe) {LOGGER.error(Unable to locate configured LoggerContextFactory {}, factoryClassName);} catch (final Exception ex) {LOGGER.error(Unable to create configured LoggerContextFactory {}, factoryClassName, ex);}}if (factory null) {final SortedMapInteger, LoggerContextFactory factories new TreeMap();// note that the following initial call to ProviderUtil may block until a Provider has been installed when// running in an OSGi environmentif (ProviderUtil.hasProviders()) {for (final Provider provider : ProviderUtil.getProviders()) {final Class? extends LoggerContextFactory factoryClass provider.loadLoggerContextFactory();if (factoryClass ! null) {try {factories.put(provider.getPriority(), factoryClass.newInstance());} catch (final Exception e) {LOGGER.error(Unable to create class {} specified in provider URL {}, factoryClass.getName(), provider.getUrl(), e);}}}if (factories.isEmpty()) {LOGGER.error(Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...);factory new SimpleLoggerContextFactory();} else if (factories.size() 1) {factory factories.get(factories.lastKey());} else {final StringBuilder sb new StringBuilder(Multiple logging implementations found: \n);for (final Map.EntryInteger, LoggerContextFactory entry : factories.entrySet()) {sb.append(Factory: ).append(entry.getValue().getClass().getName());sb.append(, Weighting: ).append(entry.getKey()).append(\n);}factory factories.get(factories.lastKey());sb.append(Using factory: ).append(factory.getClass().getName());LOGGER.warn(sb.toString());}} else {LOGGER.error(Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...);factory new SimpleLoggerContextFactory();}}}
这段静态代码段主要分为下面的几个步骤
首先根据特定配置文件的配置信息获取loggerContextFactory如果没有找到对应的Factory的实现类则通过ProviderUtil中的getProviders()方法载入providers随后通过provider的loadLoggerContextFactory方法载入LoggerContextFactory的实现类如果provider中没有获取到LoggerContextFactory的实现类或provider为空则使用SimpleLoggerContextFactory作为LoggerContextFactory。
根据配置文件载入LoggerContextFactory
// Shortcut binding to force a specific logging implementation.final PropertiesUtil managerProps PropertiesUtil.getProperties();final String factoryClassName managerProps.getStringProperty(FACTORY_PROPERTY_NAME);if (factoryClassName ! null) {try {factory LoaderUtil.newCheckedInstanceOf(factoryClassName, LoggerContextFactory.class);} catch (final ClassNotFoundException cnfe) {LOGGER.error(Unable to locate configured LoggerContextFactory {}, factoryClassName);} catch (final Exception ex) {LOGGER.error(Unable to create configured LoggerContextFactory {}, factoryClassName, ex);}}
在这段逻辑中LogManager优先通过配置文件”log4j2.component.properties”通过配置项”log4j2.loggerContextFactory”来获取LoggerContextFactory如果用户做了对应的配置通过newCheckedInstanceOf方法实例化LoggerContextFactory的对象最终的实现方式为
public static T T newInstanceOf(final ClassT clazz)throws InstantiationException, IllegalAccessException, InvocationTargetException {try {return clazz.getConstructor().newInstance();} catch (final NoSuchMethodException ignored) {// FIXME: looking at the code for Class.newInstance(), this seems to do the same thing as abovereturn clazz.newInstance();}}
在默认情况下不存在初始的默认配置文件log4j2.component.properties因此需要从其他途径获取LoggerContextFactory。
通过Provider实例化LoggerContextFactory对象
代码
if (factory null) {final SortedMapInteger, LoggerContextFactory factories new TreeMap();// note that the following initial call to ProviderUtil may block until a Provider has been installed when// running in an OSGi environmentif (ProviderUtil.hasProviders()) {for (final Provider provider : ProviderUtil.getProviders()) {final Class? extends LoggerContextFactory factoryClass provider.loadLoggerContextFactory();if (factoryClass ! null) {try {factories.put(provider.getPriority(), factoryClass.newInstance());} catch (final Exception e) {LOGGER.error(Unable to create class {} specified in provider URL {}, factoryClass.getName(), provider.getUrl(), e);}}}if (factories.isEmpty()) {LOGGER.error(Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...);factory new SimpleLoggerContextFactory();} else if (factories.size() 1) {factory factories.get(factories.lastKey());} else {final StringBuilder sb new StringBuilder(Multiple logging implementations found: \n);for (final Map.EntryInteger, LoggerContextFactory entry : factories.entrySet()) {sb.append(Factory: ).append(entry.getValue().getClass().getName());sb.append(, Weighting: ).append(entry.getKey()).append(\n);}factory factories.get(factories.lastKey());sb.append(Using factory: ).append(factory.getClass().getName());LOGGER.warn(sb.toString());}} else {LOGGER.error(Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...);factory new SimpleLoggerContextFactory();}}
这里比较有意思的是hasProviders和getProviders都会通过线程安全的方式去懒加载ProviderUtil这个对象。跟进lazyInit方法
protected static void lazyInit() {//noinspection DoubleCheckedLockingif (INSTANCE null) {try {STARTUP_LOCK.lockInterruptibly();if (INSTANCE null) {INSTANCE new ProviderUtil();}} catch (final InterruptedException e) {LOGGER.fatal(Interrupted before Log4j Providers could be loaded., e);Thread.currentThread().interrupt();} finally {STARTUP_LOCK.unlock();}}}
再看构造方法
private ProviderUtil() {for (final LoaderUtil.UrlResource resource : LoaderUtil.findUrlResources(PROVIDER_RESOURCE)) {loadProvider(resource.getUrl(), resource.getClassLoader());}}
这里的懒加载其实就是懒加载Provider对象。在创建新的providerUtil实例的过程中就会直接实例化provider对象其过程是先通过getClassLoaders方法获取provider的类加载器然后通过loadProviders(classLoader);加载类。在providerUtil实例化的最后会统一查找”META-INF/log4j-provider.properties”文件中对应的provider的url会考虑从远程加载provider。而loadProviders方法就是在ProviderUtil的PROVIDERS列表中添加对一个的provider。可以看到默认的provider是org.apache.logging.log4j.core.impl.Log4jContextFactory
LoggerContextFactory org.apache.logging.log4j.core.impl.Log4jContextFactory
Log4jAPIVersion 2.1.0
FactoryPriority 10
很有意思的是这里懒加载加上了锁而且使用的是 lockInterruptibly这个方法。lockInterruptibly和lock的区别如下 lock 与 lockInterruptibly比较区别在于 lock 优先考虑获取锁待获取锁成功后才响应中断。 lockInterruptibly 优先考虑响应中断而不是响应锁的普通获取或重入获取。 ReentrantLock.lockInterruptibly允许在等待时由其它线程调用等待线程的 Thread.interrupt 方法来中断等待线程的等待而直接返回这时不用获取锁而会抛出一个InterruptedException。 ReentrantLock.lock方法不允许Thread.interrupt中断,即使检测到Thread.isInterrupted,一样会继续尝试获取锁失败则继续休眠。只是在最后获取锁成功后再把当前线程置为interrupted状态,然后再中断线程。
上面有一句注释值得注意
/*** Guards the ProviderUtil singleton instance from lazy initialization. This is primarily used for OSGi support.** since 2.1*/protected static final Lock STARTUP_LOCK new ReentrantLock();// STARTUP_LOCK guards INSTANCE for lazy initialization; this allows the OSGi Activator to pause the startup and// wait for a Provider to be installed. See LOG4J2-373private static volatile ProviderUtil INSTANCE;
原来这里是为了让osgi可以阻止启动。 再回到logManager 可以看到在加载完Provider之后会做factory的绑定
if (factories.isEmpty()) {LOGGER.error(Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...);factory new SimpleLoggerContextFactory();} else if (factories.size() 1) {factory factories.get(factories.lastKey());} else {final StringBuilder sb new StringBuilder(Multiple logging implementations found: \n);for (final Map.EntryInteger, LoggerContextFactory entry : factories.entrySet()) {sb.append(Factory: ).append(entry.getValue().getClass().getName());sb.append(, Weighting: ).append(entry.getKey()).append(\n);}factory factories.get(factories.lastKey());sb.append(Using factory: ).append(factory.getClass().getName());LOGGER.warn(sb.toString());}
到这里logmanager的启动流程就结束了。
配置
在不使用slf4j的情况下我们获取logger的方式是这样的
Logger logger logManager.getLogger(xx.class)
跟进getLogger方法 public static Logger getLogger(final Class? clazz) {final Class? cls callerClass(clazz);return getContext(cls.getClassLoader(), false).getLogger(toLoggerName(cls));}
这里有一个getContext方法跟进
public static LoggerContext getContext(final ClassLoader loader, final boolean currentContext) {try {return factory.getContext(FQCN, loader, null, currentContext);} catch (final IllegalStateException ex) {LOGGER.warn(ex.getMessage() Using SimpleLogger);return new SimpleLoggerContextFactory().getContext(FQCN, loader, null, currentContext);}}
上文提到factory的具体实现是Log4jContextFactory跟进getContext 方法
public LoggerContext getContext(final String fqcn, final ClassLoader loader, final Object externalContext,final boolean currentContext) {final LoggerContext ctx selector.getContext(fqcn, loader, currentContext);if (externalContext ! null ctx.getExternalContext() null) {ctx.setExternalContext(externalContext);}if (ctx.getState() LifeCycle.State.INITIALIZED) {ctx.start();}return ctx;}
直接看start
public void start() {LOGGER.debug(Starting LoggerContext[name{}, {}]..., getName(), this);if (PropertiesUtil.getProperties().getBooleanProperty(log4j.LoggerContext.stacktrace.on.start, false)) {LOGGER.debug(Stack trace to locate invoker,new Exception(Not a real error, showing stack trace to locate invoker));}if (configLock.tryLock()) {try {if (this.isInitialized() || this.isStopped()) {this.setStarting();reconfigure();if (this.configuration.isShutdownHookEnabled()) {setUpShutdownHook();}this.setStarted();}} finally {configLock.unlock();}}LOGGER.debug(LoggerContext[name{}, {}] started OK., getName(), this);}
发现其中的核心方法是reconfigure方法继续跟进
private void reconfigure(final URI configURI) {final ClassLoader cl ClassLoader.class.isInstance(externalContext) ? (ClassLoader) externalContext : null;LOGGER.debug(Reconfiguration started for context[name{}] at URI {} ({}) with optional ClassLoader: {},contextName, configURI, this, cl);final Configuration instance ConfigurationFactory.getInstance().getConfiguration(this, contextName, configURI, cl);if (instance null) {LOGGER.error(Reconfiguration failed: No configuration found for {} at {} in {}, contextName, configURI, cl);} else {setConfiguration(instance);/** instance.start(); Configuration old setConfiguration(instance); updateLoggers(); if (old ! null) {* old.stop(); }*/final String location configuration null ? ? : String.valueOf(configuration.getConfigurationSource());LOGGER.debug(Reconfiguration complete for context[name{}] at URI {} ({}) with optional ClassLoader: {},contextName, location, this, cl);}}
可以看到每一个configuration都是从ConfigurationFactory拿出来的我们先看看这个类的getInstance看看
public static ConfigurationFactory getInstance() {// volatile works in Java 1.6, so double-checked locking also works properly//noinspection DoubleCheckedLockingif (factories null) {LOCK.lock();try {if (factories null) {final ListConfigurationFactory list new ArrayListConfigurationFactory();final String factoryClass PropertiesUtil.getProperties().getStringProperty(CONFIGURATION_FACTORY_PROPERTY);if (factoryClass ! null) {addFactory(list, factoryClass);}final PluginManager manager new PluginManager(CATEGORY);manager.collectPlugins();final MapString, PluginType? plugins manager.getPlugins();final ListClass? extends ConfigurationFactory ordered new ArrayListClass? extends ConfigurationFactory(plugins.size());for (final PluginType? type : plugins.values()) {try {ordered.add(type.getPluginClass().asSubclass(ConfigurationFactory.class));} catch (final Exception ex) {LOGGER.warn(Unable to add class {}, type.getPluginClass(), ex);}}Collections.sort(ordered, OrderComparator.getInstance());for (final Class? extends ConfigurationFactory clazz : ordered) {addFactory(list, clazz);}// see above comments about double-checked locking//noinspection NonThreadSafeLazyInitializationfactories Collections.unmodifiableList(list);}} finally {LOCK.unlock();}}LOGGER.debug(Using configurationFactory {}, configFactory);return configFactory;}
这里可以看到ConfigurationFactory中利用了PluginManager来进行初始化PluginManager会将ConfigurationFactory的子类加载进来默认使用的XmlConfigurationFactoryJsonConfigurationFactoryYamlConfigurationFactory这三个子类这里插件化加载暂时按下不表。 回到reconfigure这个方法我们看到获取ConfigurationFactory实例之后会去调用getConfiguration方法
public Configuration getConfiguration(final String name, final URI configLocation, final ClassLoader loader) {if (!isActive()) {return null;}if (loader null) {return getConfiguration(name, configLocation);}if (isClassLoaderUri(configLocation)) {final String path extractClassLoaderUriPath(configLocation);final ConfigurationSource source getInputFromResource(path, loader);if (source ! null) {final Configuration configuration getConfiguration(source);if (configuration ! null) {return configuration;}}}return getConfiguration(name, configLocation);}
跟进getConfiguration这里值得注意的是有很多个getConfiguration注意甄别如果不确定的话可以通过debug的方式来确定。
public Configuration getConfiguration(final String name, final URI configLocation) {if (configLocation null) {final String config this.substitutor.replace(PropertiesUtil.getProperties().getStringProperty(CONFIGURATION_FILE_PROPERTY));if (config ! null) {ConfigurationSource source null;try {source getInputFromUri(FileUtils.getCorrectedFilePathUri(config));} catch (final Exception ex) {// Ignore the error and try as a String.LOGGER.catching(Level.DEBUG, ex);}if (source null) {final ClassLoader loader LoaderUtil.getThreadContextClassLoader();source getInputFromString(config, loader);}if (source ! null) {for (final ConfigurationFactory factory : factories) {final String[] types factory.getSupportedTypes();if (types ! null) {for (final String type : types) {if (type.equals(*) || config.endsWith(type)) {final Configuration c factory.getConfiguration(source);if (c ! null) {return c;}}}}}}}} else {for (final ConfigurationFactory factory : factories) {final String[] types factory.getSupportedTypes();if (types ! null) {for (final String type : types) {if (type.equals(*) || configLocation.toString().endsWith(type)) {final Configuration config factory.getConfiguration(name, configLocation);if (config ! null) {return config;}}}}}}Configuration config getConfiguration(true, name);if (config null) {config getConfiguration(true, null);if (config null) {config getConfiguration(false, name);if (config null) {config getConfiguration(false, null);}}}if (config ! null) {return config;}LOGGER.error(No log4j2 configuration file found. Using default configuration: logging only errors to the console.);return new DefaultConfiguration();}
这里就会根据之前加载进来的factory进行配置的获取具体的不再解析。 回到reconfigure之后的步骤就是setConfiguration入参就是刚才获取的config
private synchronized Configuration setConfiguration(final Configuration config) {Assert.requireNonNull(config, No Configuration was provided);final Configuration prev this.config;config.addListener(this);final ConcurrentMapString, String map config.getComponent(Configuration.CONTEXT_PROPERTIES);try { // LOG4J2-719 network access may throw android.os.NetworkOnMainThreadExceptionmap.putIfAbsent(hostName, NetUtils.getLocalHostname());} catch (final Exception ex) {LOGGER.debug(Ignoring {}, setting hostName to unknown, ex.toString());map.putIfAbsent(hostName, unknown);}map.putIfAbsent(contextName, name);config.start();this.config config;updateLoggers();if (prev ! null) {prev.removeListener(this);prev.stop();}firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, prev, config));try {Server.reregisterMBeansAfterReconfigure();} catch (final Throwable t) {// LOG4J2-716: Android has no java.lang.managementLOGGER.error(Could not reconfigure JMX, t);}return prev;}
这个方法最重要的步骤就是config.start,这才是真正做配置解析的
public void start() {LOGGER.debug(Starting configuration {}, this);this.setStarting();pluginManager.collectPlugins(pluginPackages);final PluginManager levelPlugins new PluginManager(Level.CATEGORY);levelPlugins.collectPlugins(pluginPackages);final MapString, PluginType? plugins levelPlugins.getPlugins();if (plugins ! null) {for (final PluginType? type : plugins.values()) {try {// Cause the class to be initialized if it isnt already.Loader.initializeClass(type.getPluginClass().getName(), type.getPluginClass().getClassLoader());} catch (final Exception e) {LOGGER.error(Unable to initialize {} due to {}, type.getPluginClass().getName(), e.getClass().getSimpleName(), e);}}}setup();setupAdvertisement();doConfigure();final SetLoggerConfig alreadyStarted new HashSetLoggerConfig();for (final LoggerConfig logger : loggers.values()) {logger.start();alreadyStarted.add(logger);}for (final Appender appender : appenders.values()) {appender.start();}if (!alreadyStarted.contains(root)) { // LOG4J2-392root.start(); // LOG4J2-336}super.start();LOGGER.debug(Started configuration {} OK., this);}
这里面有如下步骤
获取日志等级的插件初始化初始化Advertiser配置
先看一下初始化也就是setup这个方法setup是一个需要被复写的方法我们以XMLConfiguration作为例子
Overridepublic void setup() {if (rootElement null) {LOGGER.error(No logging configuration);return;}constructHierarchy(rootNode, rootElement);if (status.size() 0) {for (final Status s : status) {LOGGER.error(Error processing element {}: {}, s.name, s.errorType);}return;}rootElement null;}
发现这里面有一个比较重要的方法constructHierarchy跟进
private void constructHierarchy(final Node node, final Element element) {processAttributes(node, element);final StringBuilder buffer new StringBuilder();final NodeList list element.getChildNodes();final ListNode children node.getChildren();for (int i 0; i list.getLength(); i) {final org.w3c.dom.Node w3cNode list.item(i);if (w3cNode instanceof Element) {final Element child (Element) w3cNode;final String name getType(child);final PluginType? type pluginManager.getPluginType(name);final Node childNode new Node(node, name, type);constructHierarchy(childNode, child);if (type null) {final String value childNode.getValue();if (!childNode.hasChildren() value ! null) {node.getAttributes().put(name, value);} else {status.add(new Status(name, element, ErrorType.CLASS_NOT_FOUND));}} else {children.add(childNode);}} else if (w3cNode instanceof Text) {final Text data (Text) w3cNode;buffer.append(data.getData());}}final String text buffer.toString().trim();if (text.length() 0 || (!node.hasChildren() !node.isRoot())) {node.setValue(text);}}
发现这个就是一个树遍历的过程。诚然配置文件是以xml的形式给出的xml的结构就是一个树形结构。回到start方法跟进doConfiguration
protected void doConfigure() {if (rootNode.hasChildren() rootNode.getChildren().get(0).getName().equalsIgnoreCase(Properties)) {final Node first rootNode.getChildren().get(0);createConfiguration(first, null);if (first.getObject() ! null) {subst.setVariableResolver((StrLookup) first.getObject());}} else {final MapString, String map this.getComponent(CONTEXT_PROPERTIES);final StrLookup lookup map null ? null : new MapLookup(map);subst.setVariableResolver(new Interpolator(lookup, pluginPackages));}boolean setLoggers false;boolean setRoot false;for (final Node child : rootNode.getChildren()) {if (child.getName().equalsIgnoreCase(Properties)) {if (tempLookup subst.getVariableResolver()) {LOGGER.error(Properties declaration must be the first element in the configuration);}continue;}createConfiguration(child, null);if (child.getObject() null) {continue;}if (child.getName().equalsIgnoreCase(Appenders)) {appenders child.getObject();} else if (child.isInstanceOf(Filter.class)) {addFilter(child.getObject(Filter.class));} else if (child.getName().equalsIgnoreCase(Loggers)) {final Loggers l child.getObject();loggers l.getMap();setLoggers true;if (l.getRoot() ! null) {root l.getRoot();setRoot true;}} else if (child.getName().equalsIgnoreCase(CustomLevels)) {customLevels child.getObject(CustomLevels.class).getCustomLevels();} else if (child.isInstanceOf(CustomLevelConfig.class)) {final ListCustomLevelConfig copy new ArrayListCustomLevelConfig(customLevels);copy.add(child.getObject(CustomLevelConfig.class));customLevels copy;} else {LOGGER.error(Unknown object \{}\ of type {} is ignored., child.getName(),child.getObject().getClass().getName());}}if (!setLoggers) {LOGGER.warn(No Loggers were configured, using default. Is the Loggers element missing?);setToDefault();return;} else if (!setRoot) {LOGGER.warn(No Root logger was configured, creating default ERROR-level Root logger with Console appender);setToDefault();// return; // LOG4J2-219: creating default rootok, but dont exclude configured Loggers}for (final Map.EntryString, LoggerConfig entry : loggers.entrySet()) {final LoggerConfig l entry.getValue();for (final AppenderRef ref : l.getAppenderRefs()) {final Appender app appenders.get(ref.getRef());if (app ! null) {l.addAppender(app, ref.getLevel(), ref.getFilter());} else {LOGGER.error(Unable to locate appender {} for logger {}, ref.getRef(), l.getName());}}}setParents();}
发现就是对刚刚获取的configuration进行解析然后塞进正确的地方。回到start方法可以看到昨晚配置之后就是开启logger和appender了。
异步
AsyncAppender log4j2突出于其他日志的优势异步日志实现。我们先从日志打印看进去。找到Logger随便找一个log日志的方法。
public void debug(final Marker marker, final Message msg) {logIfEnabled(FQCN, Level.DEBUG, marker, msg, msg ! null ? msg.getThrowable() : null);}
一路跟进
PerformanceSensitive// NOTE: This is a hot method. Current implementation compiles to 29 bytes of byte code.// This is within the 35 byte MaxInlineSize threshold. Modify with care!private void logMessageTrackRecursion(final String fqcn,final Level level,final Marker marker,final Message msg,final Throwable throwable) {try {incrementRecursionDepth(); // LOG4J2-1518, LOG4J2-2031tryLogMessage(fqcn, level, marker, msg, throwable);} finally {decrementRecursionDepth();}}
可以看出这个在打日志之前做了调用次数的记录。跟进tryLogMessage
PerformanceSensitive// NOTE: This is a hot method. Current implementation compiles to 26 bytes of byte code.// This is within the 35 byte MaxInlineSize threshold. Modify with care!private void tryLogMessage(final String fqcn,final Level level,final Marker marker,final Message msg,final Throwable throwable) {try {logMessage(fqcn, level, marker, msg, throwable);} catch (final Exception e) {// LOG4J2-1990 Log4j2 suppresses all exceptions that occur once application called the loggerhandleLogMessageException(e, fqcn, msg);}}
继续跟进
Overridepublic void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,final Throwable t) {final Message msg message null ? new SimpleMessage(Strings.EMPTY) : message;final ReliabilityStrategy strategy privateConfig.loggerConfig.getReliabilityStrategy();strategy.log(this, getName(), fqcn, marker, level, msg, t);}
这里可以看到在实际打日志的时候会从config中获取打日志的策略跟踪ReliabilityStrategy的创建发现默认的实现类为DefaultReliabilityStrategy跟进看实际打日志的方法
Overridepublic void log(final SupplierLoggerConfig reconfigured, final String loggerName, final String fqcn, final Marker marker, final Level level,final Message data, final Throwable t) {loggerConfig.log(loggerName, fqcn, marker, level, data, t);}
这里实际打日志的方法居然是交给一个config去实现的。。。感觉有点奇怪。。跟进看看
PerformanceSensitive(allocation)public void log(final String loggerName, final String fqcn, final Marker marker, final Level level,final Message data, final Throwable t) {ListProperty props null;if (!propertiesRequireLookup) {props properties;} else {if (properties ! null) {props new ArrayList(properties.size());final LogEvent event Log4jLogEvent.newBuilder().setMessage(data).setMarker(marker).setLevel(level).setLoggerName(loggerName).setLoggerFqcn(fqcn).setThrown(t).build();for (int i 0; i properties.size(); i) {final Property prop properties.get(i);final String value prop.isValueNeedsLookup() // since LOG4J2-1575? config.getStrSubstitutor().replace(event, prop.getValue()) //: prop.getValue();props.add(Property.createProperty(prop.getName(), value));}}}final LogEvent logEvent logEventFactory.createEvent(loggerName, marker, fqcn, level, data, props, t);try {log(logEvent, LoggerConfigPredicate.ALL);} finally {// LOG4J2-1583 prevent scrambled logs when logging calls are nested (logging in toString())ReusableLogEventFactory.release(logEvent);}}
可以清楚的看到try之前是在创建LogEventtry里面做的才是真正的log好tm累一路跟进。
private void processLogEvent(final LogEvent event, LoggerConfigPredicate predicate) {event.setIncludeLocation(isIncludeLocation());if (predicate.allow(this)) {callAppenders(event);}logParent(event, predicate);}
接下来就是callAppender了我们直接开始看AsyncAppender的append方法
/*** Actual writing occurs here.** param logEvent The LogEvent.*/Overridepublic void append(final LogEvent logEvent) {if (!isStarted()) {throw new IllegalStateException(AsyncAppender getName() is not active);}final Log4jLogEvent memento Log4jLogEvent.createMemento(logEvent, includeLocation);InternalAsyncUtil.makeMessageImmutable(logEvent.getMessage());if (!transfer(memento)) {if (blocking) {if (AbstractLogger.getRecursionDepth() 1) { // LOG4J2-1518, LOG4J2-2031// If queue is full AND we are in a recursive call, call appender directly to prevent deadlockAsyncQueueFullMessageUtil.logWarningToStatusLogger();logMessageInCurrentThread(logEvent);} else {// delegate to the event router (which may discard, enqueue and block, or log in current thread)final EventRoute route asyncQueueFullPolicy.getRoute(thread.getId(), memento.getLevel());route.logMessage(this, memento);}} else {error(Appender getName() is unable to write primary appenders. queue is full);logToErrorAppenderIfNecessary(false, memento);}}}
这里主要的步骤就是
生成logEvent将logEvent放入BlockingQueue就是transfer方法如果BlockingQueue满了则启用相应的策略
同样的这里也有一个线程用来做异步消费的事情
private class AsyncThread extends Log4jThread {private volatile boolean shutdown false;private final ListAppenderControl appenders;private final BlockingQueueLogEvent queue;public AsyncThread(final ListAppenderControl appenders, final BlockingQueueLogEvent queue) {super(AsyncAppender- THREAD_SEQUENCE.getAndIncrement());this.appenders appenders;this.queue queue;setDaemon(true);}Overridepublic void run() {while (!shutdown) {LogEvent event;try {event queue.take();if (event SHUTDOWN_LOG_EVENT) {shutdown true;continue;}} catch (final InterruptedException ex) {break; // LOG4J2-830}event.setEndOfBatch(queue.isEmpty());final boolean success callAppenders(event);if (!success errorAppender ! null) {try {errorAppender.callAppender(event);} catch (final Exception ex) {// Silently accept the error.}}}// Process any remaining items in the queue.LOGGER.trace(AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.,queue.size());int count 0;int ignored 0;while (!queue.isEmpty()) {try {final LogEvent event queue.take();if (event instanceof Log4jLogEvent) {final Log4jLogEvent logEvent (Log4jLogEvent) event;logEvent.setEndOfBatch(queue.isEmpty());callAppenders(logEvent);count;} else {ignored;LOGGER.trace(Ignoring event of class {}, event.getClass().getName());}} catch (final InterruptedException ex) {// May have been interrupted to shut down.// Here we ignore interrupts and try to process all remaining events.}}LOGGER.trace(AsyncAppender.AsyncThread stopped. Queue has {} events remaining. Processed {} and ignored {} events since shutdown started., queue.size(), count, ignored);}/*** Calls {link AppenderControl#callAppender(LogEvent) callAppender} on all registered {code AppenderControl}* objects, and returns {code true} if at least one appender call was successful, {code false} otherwise. Any* exceptions are silently ignored.** param event the event to forward to the registered appenders* return {code true} if at least one appender call succeeded, {code false} otherwise*/boolean callAppenders(final LogEvent event) {boolean success false;for (final AppenderControl control : appenders) {try {control.callAppender(event);success true;} catch (final Exception ex) {// If no appender is successful the error appender will get it.}}return success;}public void shutdown() {shutdown true;if (queue.isEmpty()) {queue.offer(SHUTDOWN_LOG_EVENT);}if (getState() State.TIMED_WAITING || getState() State.WAITING) {this.interrupt(); // LOG4J2-1422: if underlying appender is stuck in wait/sleep/join/park call}}}
直接看run方法
阻塞获取logEvent将logEvent分发出去如果线程要退出了将blockingQueue里面的event消费完在退出。
AsyncLogger 直接从AsyncLogger的logMessage看进去
public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,final Throwable thrown) {if (loggerDisruptor.isUseThreadLocals()) {logWithThreadLocalTranslator(fqcn, level, marker, message, thrown);} else {// LOG4J2-1172: avoid storing non-JDK classes in ThreadLocals to avoid memory leaks in web appslogWithVarargTranslator(fqcn, level, marker, message, thrown);}}
跟进logWithThreadLocalTranslator
private void logWithThreadLocalTranslator(final String fqcn, final Level level, final Marker marker,final Message message, final Throwable thrown) {// Implementation note: this method is tuned for performance. MODIFY WITH CARE!final RingBufferLogEventTranslator translator getCachedTranslator();initTranslator(translator, fqcn, level, marker, message, thrown);initTranslatorThreadValues(translator);publish(translator);}
这里的逻辑很简单就是将日志相关的信息转换成RingBufferLogEventRingBuffer是Disruptor的无所队列然后将其发布到RingBuffer中。发布到RingBuffer中那肯定也有消费逻辑。这时候有两种方式可以找到这个消费的逻辑。
找disruptor被使用的地方然后查看但是这样做会很容易迷惑按照Log4j2的尿性这种Logger都有对应的start方法我们可以从start方法入手寻找
在start方法中我们找到了一段代码
final RingBufferLogEventHandler[] handlers {new RingBufferLogEventHandler()};disruptor.handleEventsWith(handlers);
直接看看这个RingBufferLogEventHandler的实现
public class RingBufferLogEventHandler implementsSequenceReportingEventHandlerRingBufferLogEvent, LifecycleAware {private static final int NOTIFY_PROGRESS_THRESHOLD 50;private Sequence sequenceCallback;private int counter;private long threadId -1;Overridepublic void setSequenceCallback(final Sequence sequenceCallback) {this.sequenceCallback sequenceCallback;}Overridepublic void onEvent(final RingBufferLogEvent event, final long sequence,final boolean endOfBatch) throws Exception {event.execute(endOfBatch);event.clear();// notify the BatchEventProcessor that the sequence has progressed.// Without this callback the sequence would not be progressed// until the batch has completely finished.if (counter NOTIFY_PROGRESS_THRESHOLD) {sequenceCallback.set(sequence);counter 0;}}/*** Returns the thread ID of the background consumer thread, or {code -1} if the background thread has not started* yet.* return the thread ID of the background consumer thread, or {code -1}*/public long getThreadId() {return threadId;}Overridepublic void onStart() {threadId Thread.currentThread().getId();}Overridepublic void onShutdown() {}
}
顺着接口找上去发现一个接口
/*** Callback interface to be implemented for processing events as they become available in the {link RingBuffer}** param T event implementation storing the data for sharing during exchange or parallel coordination of an event.* see BatchEventProcessor#setExceptionHandler(ExceptionHandler) if you want to handle exceptions propagated out of the handler.*/
public interface EventHandlerT
{/*** Called when a publisher has published an event to the {link RingBuffer}** param event published to the {link RingBuffer}* param sequence of the event being processed* param endOfBatch flag to indicate if this is the last event in a batch from the {link RingBuffer}* throws Exception if the EventHandler would like the exception handled further up the chain.*/void onEvent(T event, long sequence, boolean endOfBatch) throws Exception;
}
通过注释可以发现这个onEvent就是处理逻辑回到RingBufferLogEventHandler的onEvent方法发现里面有一个execute方法跟进
public void execute(final boolean endOfBatch) {this.endOfBatch endOfBatch;asyncLogger.actualAsyncLog(this);}
这个方法就是实际打日志了AsyncLogger看起来还是比较简单的只是使用了一个Disruptor。
插件化
之前在很多代码里面都可以看到
final PluginManager manager new PluginManager(CATEGORY);
manager.collectPlugins(pluginPackages);
其实整个log4j2为了获得更好的扩展性将自己的很多组件都做成了插件然后在配置的时候去加载plugin。 跟进collectPlugins。 public void collectPlugins(final ListString packages) {final String categoryLowerCase category.toLowerCase();final MapString, PluginType? newPlugins new LinkedHashMap();// First, iterate the Log4j2Plugin.dat files found in the main CLASSPATHMapString, ListPluginType? builtInPlugins PluginRegistry.getInstance().loadFromMainClassLoader();if (builtInPlugins.isEmpty()) {// If we didnt find any plugins above, someone must have messed with the log4j-core.jar.// Search the standard package in the hopes we can find our core plugins.builtInPlugins PluginRegistry.getInstance().loadFromPackage(LOG4J_PACKAGES);}mergeByName(newPlugins, builtInPlugins.get(categoryLowerCase));// Next, iterate any Log4j2Plugin.dat files from OSGi Bundlesfor (final MapString, ListPluginType? pluginsByCategory : PluginRegistry.getInstance().getPluginsByCategoryByBundleId().values()) {mergeByName(newPlugins, pluginsByCategory.get(categoryLowerCase));}// Next iterate any packages passed to the static addPackage method.for (final String pkg : PACKAGES) {mergeByName(newPlugins, PluginRegistry.getInstance().loadFromPackage(pkg).get(categoryLowerCase));}// Finally iterate any packages provided in the configuration (note these can be changed at runtime).if (packages ! null) {for (final String pkg : packages) {mergeByName(newPlugins, PluginRegistry.getInstance().loadFromPackage(pkg).get(categoryLowerCase));}}LOGGER.debug(PluginManager {} found {} plugins, category, newPlugins.size());plugins newPlugins;}
处理逻辑如下
从Log4j2Plugin.dat中加载所有的内置的plugin然后将OSGi Bundles中的Log4j2Plugin.dat中的plugin加载进来再加载传入的package路径中的plugin最后加载配置中的plugin
逻辑还是比较简单的但是我在看源码的时候发现了一个很有意思的东西就是在加载log4j2 core插件的时候也就是
PluginRegistry.getInstance().loadFromMainClassLoader()
这个方法跟进到decodeCacheFiles
private MapString, ListPluginType? decodeCacheFiles(final ClassLoader loader) {final long startTime System.nanoTime();final PluginCache cache new PluginCache();try {final EnumerationURL resources loader.getResources(PluginProcessor.PLUGIN_CACHE_FILE);if (resources null) {LOGGER.info(Plugin preloads not available from class loader {}, loader);} else {cache.loadCacheFiles(resources);}} catch (final IOException ioe) {LOGGER.warn(Unable to preload plugins, ioe);}final MapString, ListPluginType? newPluginsByCategory new HashMap();int pluginCount 0;for (final Map.EntryString, MapString, PluginEntry outer : cache.getAllCategories().entrySet()) {final String categoryLowerCase outer.getKey();final ListPluginType? types new ArrayList(outer.getValue().size());newPluginsByCategory.put(categoryLowerCase, types);for (final Map.EntryString, PluginEntry inner : outer.getValue().entrySet()) {final PluginEntry entry inner.getValue();final String className entry.getClassName();try {final Class? clazz loader.loadClass(className);final PluginType? type new PluginType(entry, clazz, entry.getName());types.add(type);pluginCount;} catch (final ClassNotFoundException e) {LOGGER.info(Plugin [{}] could not be loaded due to missing classes., className, e);} catch (final LinkageError e) {LOGGER.info(Plugin [{}] could not be loaded due to linkage error., className, e);}}}final long endTime System.nanoTime();final DecimalFormat numFormat new DecimalFormat(#0.000000);final double seconds (endTime - startTime) * 1e-9;LOGGER.debug(Took {} seconds to load {} plugins from {},numFormat.format(seconds), pluginCount, loader);return newPluginsByCategory;}
可以发现加载时候是从一个文件PLUGIN_CACHE_FILE获取所有要获取的plugin。看到这里的时候我有一个疑惑就是为什么不用反射的方式直接去扫描而是要从文件中加载进来而且文件是写死的很不容易扩展啊。然后我找了一下PLUGIN_CACHE_FILE这个静态变量的用处发现了PluginProcessor这个类这里用到了注解处理器。
/*** Annotation processor for pre-scanning Log4j 2 plugins.*/
SupportedAnnotationTypes(org.apache.logging.log4j.core.config.plugins.*)
public class PluginProcessor extends AbstractProcessor {// TODO: this could be made more abstract to allow for compile-time and run-time plugin processing/*** The location of the plugin cache data file. This file is written to by this processor, and read from by* {link org.apache.logging.log4j.core.config.plugins.util.PluginManager}.*/public static final String PLUGIN_CACHE_FILE META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat;private final PluginCache pluginCache new PluginCache();Overridepublic boolean process(final Set? extends TypeElement annotations, final RoundEnvironment roundEnv) {System.out.println(Processing annotations);try {final Set? extends Element elements roundEnv.getElementsAnnotatedWith(Plugin.class);if (elements.isEmpty()) {System.out.println(No elements to process);return false;}collectPlugins(elements);writeCacheFile(elements.toArray(new Element[elements.size()]));System.out.println(Annotations processed);return true;} catch (final IOException e) {e.printStackTrace();error(e.getMessage());return false;} catch (final Exception ex) {ex.printStackTrace();error(ex.getMessage());return false;}}
}
不太重要的方法省略 我们可以看到在process方法中PluginProcessor会先收集所有的Plugin然后在写入文件。这样做的好处就是可以省去反射时候的开销。 然后我又看了一下Plugin这个注解发现它的RetentionPolicy是RUNTIME一般来说PluginProcessor是搭配RetentionPolicy.SOURCECLASS使用的而且既然你把自己的Plugin扫描之后写在文件中了RetentionPolicy就没有必要是RUNTIME了吧这个是一个很奇怪的地方。
小结
总算是把Log4j2的代码看完了发现它的设计理念很值得借鉴为了灵活性所有的东西都设计成插件式。互联网技术日益发展各种中间件层出不穷而作为工程师的我们更需要做的是去思考代码与代码之间的关系毫无疑问的是解耦是最具有美感的关系。
原文链接 本文为云栖社区原创内容未经允许不得转载。
