Java技术点
1.stackLocation获取
2.获取指定文件的修改时间,使用JDK中File的方法java.io.File#lastModified
Java日志框架
根据是否为具体实现这个标准,可以大致将主流的日志框架分为以下两类:
- 日志实现(日志实现框架):JUL(java util logging)、logback、log4j、log4j2
- 日志门面(日志标准接口框架):JCL(Jakarta Commons Logging)、slf4j(Simple Logging Facade for Java)
较主流的日志组合是SLF4F
+log4j2。
log4j2 在目前JAVA中的日志框架里,异步日志的性能是最高的。
log4j2
官网优点说明Log4j – Apache Log4j 2
log4j2是apache在log4j的基础上
- 在拥有全部logback特性的情况下,还修复了一些隐藏问题
- API 分离
- 性能提升
- 多API支持
- 避免锁定
- 自动重新加载配置
- 高级过滤
- 插件架构
- 属性支持
- Java 8 Lambda支持
- 自定义日志级别
- 产生垃圾少
- 和应用server集成
Log4j2由如下几部分构成:
Logger:负责捕获日志记录,并传递给 Appender,他是日志行为的发起者
Appender:负责将日志事件进行分类处理,将日志发往他应该去的目标去向,因此也可以称为 Handler。大多继承AbstractAppender,同时支持 Lifecycle 和Filterable功能。
AsyncAppender:使用另外的线程来处理LogEvents。默认使用ArrayBlockingQueue,
includeLocation是一个很重型的操作。(it can make logging 5 - 20 times slower)
Layout:Layout 负责在日志输出前决定日志的格式,因此也可以称为 Fomatter
Filter:是可选的组件,每一个 Logger、Appender 甚至全局都可以配置若干个 Filter,来决定相应的组件对当前的日志时间是否关心
有BurstFilter,CompositeFilter,DynamicThresholdFilter,MapFilter,MarkerFilter,NoMarkerFilter,RegexFilter,Script,StructuredDataFilter,ThreadContextMapFilter ,ThresholdFilter,TimeFilter
Level:日志级别有:OFF、FATAL、ERROR、WARN、INFO、DEBUG、ALL(默认为:ERROR)源码:org.apache.logging.log4j.Level
@Component
public class TestServiceImpl implements TestService {
private Logger logger = LoggerFactory.getLogger(this.getClass());
@Override
public String businessFlow() throws Exception {
logger.info("==test logger==");
System.out.println("================ TestServiceImpl businessFlow = processed .....");
return "businessFlow finished";
}
}
源码跟踪实例
Mixing Synchronous and Asynchronous Loggers
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="error" monitorInterval="5">
<!-- <Properties>-->
<!-- <Property name="baseDir" value="E:\projects\project\SpringBoot E-commerce\logs"/>-->
<!-- </Properties>-->
<Filters>
<MarkerFilter marker="EVENT" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
<DynamicThresholdFilter key="loginId" defaultThreshold="ERROR"
onMatch="ACCEPT" onMismatch="NEUTRAL">
<KeyValuePair key="User1" value="DEBUG"/>
</DynamicThresholdFilter>
</Filters>
<Appenders>
<Console name="Console" target="SYSTEM_OUT" immediateFlush="false">
<!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch) -->
<!-- <ThresholdFilter level="error" onMatch="ACCEPT"-->
<!-- onMismatch="ACCEPT"/>-->
<PatternLayout
pattern="[%d{HH:mm:ss.SSS}] [%level] [%logger{36}] - %msg%n"/>
</Console>
</Appenders>
<Loggers>
<AsyncLogger name="com.example.sourcecodelearning.service" level="debug" includeLocation="true">
<Appender-Ref ref="Console" />
</AsyncLogger>
<Root level="info">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
初始化logger
StaticLoggerBinder构造方法创建Log4jLoggerFactory。
LoggerContext
LoggerContext是日志系统的上下文。维护了一系列的应用请求的logger和Configuration。Configuration包含了configured loggers, appenders, filters和其他,
AsyncLoggerContext是使用创建AsyncLogger的。
Log4jLoggerFactory
/**
* Log4j implementation of SLF4J ILoggerFactory interface.
*/
public class Log4jLoggerFactory extends AbstractLoggerAdapter<Logger> implements ILoggerFactory {
private static final StatusLogger LOGGER = StatusLogger.getLogger();
private static final String SLF4J_PACKAGE = "org.slf4j";
private static final String TO_SLF4J_CONTEXT = "org.apache.logging.slf4j.SLF4JLoggerContext";
private static final Predicate<Class<?>> CALLER_PREDICATE = clazz ->
!AbstractLoggerAdapter.class.equals(clazz) && !clazz.getName().startsWith(SLF4J_PACKAGE);
}
可见框架用的logger是StatusLogger来打印框架启动的log。
LoggerContext创建logger
logger构造方法,可以看到Log4jLogger是使用构造方法来获取对应logger功能的!
public AbstractLogger(final String name, final MessageFactory messageFactory) {
this.name = name;
this.messageFactory = messageFactory == null ? createDefaultMessageFactory() : narrow(messageFactory);
this.flowMessageFactory = createDefaultFlowMessageFactory();
this.logBuilder = new LocalLogBuilder(this);
}
protected Logger(final LoggerContext context, final String name, final MessageFactory messageFactory) {
super(name, messageFactory);
this.context = context;
privateConfig = new PrivateConfig(context.getConfiguration(), this);
}
public AsyncLogger(final LoggerContext context, final String name, final MessageFactory messageFactory,
final AsyncLoggerDisruptor loggerDisruptor) {
super(context, name, messageFactory);
this.loggerDisruptor = loggerDisruptor;
includeLocation = privateConfig.loggerConfig.isIncludeLocation();
nanoClock = context.getConfiguration().getNanoClock();
}
public class Log4jLogger implements LocationAwareLogger, Serializable {
public Log4jLogger(final ExtendedLogger logger, final String name) {
this.logger = logger;
this.eventLogger = "EventLogger".equals(name);
this.name = name;
}
public boolean isDebugEnabled(final Marker marker) {
return logger.isEnabled(Level.DEBUG, getMarker(marker), null);
}
public void debug(final String format, final Throwable t) {
logger.logIfEnabled(FQCN, Level.DEBUG, null, format, t);
}
}
Configuration
Configuration of Log4j 2 can be accomplished in 1 of 4 ways:
- Through a configuration file written in XML, JSON, YAML, or properties format.
- Programmatically, by creating a ConfigurationFactory and Configuration implementation.
- Programmatically, by calling the APIs exposed in the Configuration interface to add components to the default configuration.
- Programmatically, by calling methods on the internal Logger class.
xml文件解析成树,每个node对应一个xml的element。一个node包含一系列的attributes,一系列的childnode,和一个PluginType。注意,每个node都必须对应一个PluginType。
设置configuraton的核心方法是setConfiguration
public Configuration setConfiguration(final Configuration config) {
if (config == null) {
LOGGER.error("No configuration found for context '{}'.", contextName);
// No change, return the current configuration.
return this.configuration;
}
configLock.lock();
try {
final Configuration prev = this.configuration;
config.addListener(this);
final ConcurrentMap<String, String> map = config.getComponent(Configuration.CONTEXT_PROPERTIES);
try { // LOG4J2-719 network access may throw android.os.NetworkOnMainThreadException
// LOG4J2-2808 don't block unless necessary
map.computeIfAbsent("hostName", s -> NetUtils.getLocalHostname());
} catch (final Exception ex) {
LOGGER.debug("Ignoring {}, setting hostName to 'unknown'", ex.toString());
map.putIfAbsent("hostName", "unknown");
}
map.putIfAbsent("contextName", contextName);
config.start();
this.configuration = config;
updateLoggers();
if (prev != null) {
prev.removeListener(this);
prev.stop();
}
firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, prev, config));
try {
Server.reregisterMBeansAfterReconfigure();
} catch (final LinkageError | Exception e) {
// LOG4J2-716: Android has no java.lang.management
LOGGER.error("Could not reconfigure JMX", e);
}
// AsyncLoggers update their nanoClock when the configuration changes
Log4jLogEvent.setNanoClock(configuration.getNanoClock());
return prev;
} finally {
configLock.unlock();
}
}
1.使用ReentrantLock
2.config.addListener(LoggerContext)
3.config.start(),这里是重点
4.LoggerContext#updateLoggers(config),这里将循环所有的已经在loggerRegistry的logger重新生成新的 new PrivateConfig(newConfig, this);
然后发出firePropertyChangeEvent
4.stop previous configuration
5.firePropertyChangeEvent
6.Server.reregisterMBeansAfterReconfigure()
AsyncAppender
Log4j的AsyncAppender能否提升性能?什么场景用比较好?_luckykapok918的博客-CSDN博客_asyncappender
Asynchronous Loggers
二者的关系如图。使用AsyncLogger生成LogEvent,放入disruptor中,然后异步线程进行消费。
AsyncLoggerConfig
会先执行同步的一次,再执行异步的
org.apache.logging.log4j.core.async.AsyncLoggerConfig#log
protected void log(final LogEvent event, final LoggerConfigPredicate predicate) {
// See LOG4J2-2301
if (predicate == LoggerConfigPredicate.ALL &&
ASYNC_LOGGER_ENTERED.get() == Boolean.FALSE &&
// Optimization: AsyncLoggerConfig is identical to LoggerConfig
// when no appenders are present. Avoid splitting for synchronous
// and asynchronous execution paths until encountering an
// AsyncLoggerConfig with appenders.
hasAppenders()) {
// This is the first AsnycLoggerConfig encountered by this LogEvent
ASYNC_LOGGER_ENTERED.set(Boolean.TRUE);
try {
// Detect the first time we encounter an AsyncLoggerConfig. We must log
// to all non-async loggers first.
super.log(event, LoggerConfigPredicate.SYNCHRONOUS_ONLY);
// Then pass the event to the background thread where
// all async logging is executed. It is important this
// happens at most once and after all synchronous loggers
// have been invoked, because we lose parameter references
// from reusable messages.
logToAsyncDelegate(event);
} finally {
ASYNC_LOGGER_ENTERED.set(Boolean.FALSE);
}
} else {
super.log(event, predicate);
}
}
异步输出会先生成一个logEvent,然后放入disruptor的RingBuffer中
disruptor.getRingBuffer().tryPublishEvent(translator, logEvent, asyncLoggerConfig);
RingBuffer这里比较复杂了。。。。
参考张哈希的文章吧。。。或是log4j的有文章介绍
https://blog.csdn.net/zhxdick/category_6121943.html
waitStrategy
有这么好几种 Strategy。
??插件化
stackLocation获取
Now with JDK 9 & 10, you can use StackWalker, which is not an expensive call.
java - How Expensive is Thread.getStackTrace()? - Stack Overflow
private void invoke006() {
var stack = StackWalker.getInstance(StackWalker.Option.SHOW_HIDDEN_FRAMES).walk((s) -> s.collect(Collectors.toList()));
stack.forEach(stackFrame -> {
if (stackFrame.getMethodName().equals("masterInvoker")) {
System.err.println("master called !!");
System.err.println(StackWalker.getInstance().walk((s) -> s.collect(Collectors.toList())).get(0).getMethodName() + ", line: " + StackWalker.getInstance().walk((s) -> s.collect(Collectors.toList())).get(0).getLineNumber());
}
});
}
org.apache.logging.log4j.util.StackLocator#calcLocation
注意 //LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
[LOG4J2-1029] Performance improvement when gathering Location Information - ASF JIRA
public StackTraceElement calcLocation(final String fqcnOfLogger) {
if (fqcnOfLogger == null) {
return null;
}
// LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
StackTraceElement last = null;
for (int i = stackTrace.length - 1; i > 0; i--) {
final String className = stackTrace[i].getClassName();
if (fqcnOfLogger.equals(className)) {
return last;
}
last = stackTrace[i];
}
return null;
}
public StackTraceElement[] getStackTrace() {
return getOurStackTrace().clone();
}
private synchronized StackTraceElement[] getOurStackTrace() {
//初始化栈信息
if (stackTrace == UNASSIGNED_STACK ||
(stackTrace == null && backtrace != null) /* Out of protocol state */) {
int depth = getStackTraceDepth();
stackTrace = new StackTraceElement[depth];
//填充栈信息
for (int i=0; i < depth; i++)
stackTrace[i] = getStackTraceElement(i);
} else if (stackTrace == null) {
return UNASSIGNED_STACK;
}
return stackTrace;
}
//每一层的栈信息是通过本地方法来调用的
native StackTraceElement getStackTraceElement(int index);
monitorInterval原理
开始,是在AbstractConfiguration中创建WatchManager和ConfigurationScheduler。WatchManager实现了AbstractLifeCycle,在LoggerContext的INITIALIZED时候,执行start方法,通知各个监听context的状态的监听者。
ConfigurationScheduler是使用了JDK的ScheduledExecutorService的scheduleWithFixedDelay方法,定时执行!
private final ConfigurationScheduler configurationScheduler = new ConfigurationScheduler();
private final WatchManager watchManager = new WatchManager(configurationScheduler);
public interface LifeCycle {
enum State {
/** Object is in its initial state and not yet initialized. */
INITIALIZING,
/** Initialized but not yet started. */
INITIALIZED,
/** In the process of starting. */
STARTING,
/** Has started. */
STARTED,
/** Stopping is in progress. */
STOPPING,
/** Has stopped. */
STOPPED
}
使用了监听模式。这里需要注意下监听器模式和观察者模式_Chen4852010的博客-CSDN博客_监听器模式 观察者模式
几个重要相关的类:
WatchManager
ConfigurationMonitorConfigurationListener
ConfigurationScheduler
WatchRunnable
Watcher ---- ConfigurationFileWatcher
WatchEventService----subscribe
看这几个类名,就知道这几个的关系了。首先是WatchManager用于管理这几个类之间的关系,用于是否添加监听。如监听文件:
/**
* Watches the given file.
*
* @param file the file to watch.
* @param fileWatcher the watcher to notify of file changes.
*/
public void watchFile(final File file, final FileWatcher fileWatcher) {
Watcher watcher;
if (fileWatcher instanceof Watcher) {
watcher = (Watcher) fileWatcher;
} else {
watcher = new WrappedFileWatcher(fileWatcher);
}
Source source = new Source(file);
watch(source, watcher);
}
public void watch(final Source source, final Watcher watcher) {
watcher.watching(source);
final long lastModified = watcher.getLastModified();
if (logger.isDebugEnabled()) {
logger.debug("Watching configuration '{}' for lastModified {} ({})", source, millisToString(lastModified),
lastModified);
}
watchers.put(source, new ConfigurationMonitor(lastModified, watcher));
}
监听文件最终是创建一个ConfigurationMonitor监听器。引用watcher和lastModifiedMillis。
public ConfigurationMonitor(final long lastModifiedMillis, final Watcher watcher) {
this.watcher = watcher;
this.lastModifiedMillis = lastModifiedMillis;
}
watcher是观察者的抽象。这里ConfigurationFileWatcher是个具体的实现。
public abstract class AbstractWatcher implements Watcher {
public AbstractWatcher(final Configuration configuration, final Reconfigurable reconfigurable,
final List<ConfigurationListener> configurationListeners) {
this.configuration = configuration;
this.reconfigurable = reconfigurable;
this.configurationListeners = configurationListeners;
this.threadFactory = configurationListeners != null ?
Log4jThreadFactory.createDaemonThreadFactory("ConfiguratonFileWatcher") : null;
}
@Override
public List<ConfigurationListener> getListeners() {
return configurationListeners;
}
@Override
public void modified() {
for (final ConfigurationListener configurationListener : configurationListeners) {
final Thread thread = threadFactory.newThread(new ReconfigurationRunnable(configurationListener, reconfigurable));
thread.start();
}
}
}
public ConfigurationFileWatcher(final Configuration configuration, final Reconfigurable reconfigurable,
final List<ConfigurationListener> configurationListeners, long lastModifiedMillis) {
super(configuration, reconfigurable, configurationListeners);
this.lastModifiedMillis = lastModifiedMillis;
}
这里可看出,Abstract类是封闭了获取监听者getListeners和执行观察者的动作modified!这里是很典型的面向对象设计。
观察者观察到设定的结果后,使用Log4jThreadFactory生成Log4jThread执行监听者的reconfigure方法!
补充下,JDK有个File的方法,可直接获取指定文件的修改时间java.io.File#lastModified
XmlConfiguration初始化Watchers
在XmlConfiguration构造方法,读入xml配置文件,解析,根据配置属性如status,dest等添加特性;
后执行方法,初始化Watchers。根据monitorIntervalSeconds是否大于0,创建ConfigurationFileWatcher并添加监听。
initializeWatchers(this, configSource, monitorIntervalSeconds)
AbstractConfiguration
protected void initializeWatchers(Reconfigurable reconfigurable, ConfigurationSource configSource,
int monitorIntervalSeconds) {
if (configSource.getFile() != null || configSource.getURL() != null) {
if (monitorIntervalSeconds > 0) {
watchManager.setIntervalSeconds(monitorIntervalSeconds);
if (configSource.getFile() != null) {
final Source cfgSource = new Source(configSource);
final long lastModifeid = configSource.getFile().lastModified();
final ConfigurationFileWatcher watcher = new ConfigurationFileWatcher(this, reconfigurable,
listeners, lastModifeid);
watchManager.watch(cfgSource, watcher);
} else if (configSource.getURL() != null) {
monitorSource(reconfigurable, configSource);
}
} else if (watchManager.hasEventListeners() && configSource.getURL() != null
&& monitorIntervalSeconds >= 0) {
monitorSource(reconfigurable, configSource);
}
}
}
开始监听xml文件
在LoggerContext执行生命周期的STARTING后,执行方法
reconfigure
org.apache.logging.log4j.core.LoggerContext#reconfigure();这里实现比较复杂!
全局只有LoggerContext实现了接口ConfigurationListener。
/**
* Interface used to allow components to be notified when the configuration changes.
*/
public interface ConfigurationListener {
void onChange(Reconfigurable reconfigurable);
}
这里是整个更新xml配置文件的起点!每次轮询后,如果文件修改时间不同了,就会刷新一遍configuration!
public synchronized void onChange(final Reconfigurable reconfigurable) {
final long startMillis = System.currentTimeMillis();
LOGGER.debug("Reconfiguration started for context {} ({})", contextName, this);
initApiModule();
final Configuration newConfig = reconfigurable.reconfigure();
if (newConfig != null) {
setConfiguration(newConfig);
LOGGER.debug("Reconfiguration completed for {} ({}) in {} milliseconds.", contextName, this,
System.currentTimeMillis() - startMillis);
} else {
LOGGER.debug("Reconfiguration failed for {} ({}) in {} milliseconds.", contextName, this,
System.currentTimeMillis() - startMillis);
}
}
获取新的配置文件,如果是xml文件,返回的就是XmlConfiguration
重点是setConfiguration
XmlConfiguration
public XmlConfiguration(final LoggerContext loggerContext, final ConfigurationSource configSource) {
super(loggerContext, configSource);
final File configFile = configSource.getFile();
byte[] buffer = null;
try {
final InputStream configStream = configSource.getInputStream();
try {
buffer = toByteArray(configStream);
} finally {
Closer.closeSilently(configStream);
}
final InputSource source = new InputSource(new ByteArrayInputStream(buffer));
source.setSystemId(configSource.getLocation());
final DocumentBuilder documentBuilder = newDocumentBuilder(true);
Document document;
try {
document = documentBuilder.parse(source);
} catch (final Exception e) {
// LOG4J2-1127
final Throwable throwable = Throwables.getRootCause(e);
if (throwable instanceof UnsupportedOperationException) {
LOGGER.warn(
"The DocumentBuilder {} does not support an operation: {}."
+ "Trying again without XInclude...",
documentBuilder, e);
document = newDocumentBuilder(false).parse(source);
} else {
throw e;
}
}
rootElement = document.getDocumentElement();
final Map<String, String> attrs = processAttributes(rootNode, rootElement);
final StatusConfiguration statusConfig = new StatusConfiguration().withVerboseClasses(VERBOSE_CLASSES)
.withStatus(getDefaultStatus());
int monitorIntervalSeconds = 0;
for (final Map.Entry<String, String> entry : attrs.entrySet()) {
final String key = entry.getKey();
final String value = getConfigurationStrSubstitutor().replace(entry.getValue());
if ("status".equalsIgnoreCase(key)) {
statusConfig.withStatus(value);
} else if ("dest".equalsIgnoreCase(key)) {
statusConfig.withDestination(value);
} else if ("shutdownHook".equalsIgnoreCase(key)) {
isShutdownHookEnabled = !"disable".equalsIgnoreCase(value);
} else if ("shutdownTimeout".equalsIgnoreCase(key)) {
shutdownTimeoutMillis = Long.parseLong(value);
} else if ("verbose".equalsIgnoreCase(key)) {
statusConfig.withVerbosity(value);
} else if ("packages".equalsIgnoreCase(key)) {
pluginPackages.addAll(Arrays.asList(value.split(Patterns.COMMA_SEPARATOR)));
} else if ("name".equalsIgnoreCase(key)) {
setName(value);
} else if ("strict".equalsIgnoreCase(key)) {
strict = Boolean.parseBoolean(value);
} else if ("schema".equalsIgnoreCase(key)) {
schemaResource = value;
} else if ("monitorInterval".equalsIgnoreCase(key)) {
monitorIntervalSeconds = Integer.parseInt(value);
} else if ("advertiser".equalsIgnoreCase(key)) {
createAdvertiser(value, configSource, buffer, "text/xml");
}
}
initializeWatchers(this, configSource, monitorIntervalSeconds);
statusConfig.initialize();
} catch (final SAXException | IOException | ParserConfigurationException e) {
LOGGER.error("Error parsing " + configSource.getLocation(), e);
}
if (strict && schemaResource != null && buffer != null) {
try (InputStream is = Loader.getResourceAsStream(schemaResource, XmlConfiguration.class.getClassLoader())) {
if (is != null) {
final javax.xml.transform.Source src = new StreamSource(is, LOG4J_XSD);
final SchemaFactory factory = SchemaFactory.newInstance(XMLConstants.W3C_XML_SCHEMA_NS_URI);
Schema schema = null;
try {
schema = factory.newSchema(src);
} catch (final SAXException ex) {
LOGGER.error("Error parsing Log4j schema", ex);
}
if (schema != null) {
final Validator validator = schema.newValidator();
try {
validator.validate(new StreamSource(new ByteArrayInputStream(buffer)));
} catch (final IOException ioe) {
LOGGER.error("Error reading configuration for validation", ioe);
} catch (final SAXException ex) {
LOGGER.error("Error validating configuration", ex);
}
}
}
} catch (final Exception ex) {
LOGGER.error("Unable to access schema {}", this.schemaResource, ex);
}
}
if (getName() == null) {
setName(configSource.getLocation());
}
}
构造方法里主要是读取xml文件的属性,
initializeWatchers
statusConfig.initialize()
LoggerContext.setConfiguration
参考上面
这里会有好几种不同的Strategy实现。接口是抽象的目的是确保logEvent(包含location)发送到合适的appender。
好文
一次鞭辟入里的 Log4j2 异步日志输出阻塞问题的定位 - 云+社区 - 腾讯云
从零到一带你深入 log4j2 Jndi RCE CVE-2021-44228漏洞 - FreeBuf网络安全行业门户
参考:
1.日志实现框架(6):log4j2_·梅花十三的博客-CSDN博客_log4j2
2.Log4j2日志框架_路面烧卖的博客-CSDN博客_log4j2架构
3.https://blog.csdn.net/sweetyi/category_9810165.html
重点:
阿里日志规约
====