嗯,终于到主角了
1. 概述
上一篇文章JDK研究之Logger中,我们初略了解了JDK中提供的Log实现。而Tomcat是在此基础之上做的改动。
Tomcat内部的日志实现,是使用JULI——这是apache commons logging改名后的一个项目。
2. 配置文件logging.properties
Tomcat中为了增加自定义的Log配置,同时不影响其它使用JDK中的Log的应用,所以指定了自定义的logger配置文件logging.properties
。
2.1 配置文件的配置
Tomcat是通过在启动脚本catalina.bat
中增加参数来自定义配置的加载的。
即启动参数中包含两个-D参数
1. java.util.logging.config.file
2. java.util.logging.manager
这一点可以从下面的《Tomcat启动后的JVM参数图》中得到验证。
2.2 读取位置
logging.properties
配置文件有两个读取位置:
1. 项目的classpath之下(即webapps/{project}/WEB-INF/classes
下)的,注意这里有着相比较于第二个的高优先级。
2. 然后才是Tomcat的默认位置${CATALINA_HOME}/conf
目录下。
2.1.1 衍生技巧
这里就衍生出了一个技巧。如果你的Tomcat在启动时出错,但错误原因又非常晦涩时,往往是因为错误日志太简单。这时候的你就需要降低Tomcat日志的级别,此时 你可以进行如下操作:
- 在项目的
WEB-INF/classes
下添加一个logging.properties
文件。 向第一步添加的
logging.properties
文件中加入如下内容:handlers = org.apache.juli.FileHandler, java.util.logging.ConsoleHandler org.apache.juli.FileHandler.level = FINE org.apache.juli.FileHandler.directory = ${catalina.base}/logs org.apache.juli.FileHandler.prefix = error-debug. java.util.logging.ConsoleHandler.level = FINE java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
至此,我们再启动tomcat时,就会在logs目录下生成一个更详细的日志error-debug.YYYY-MM-dd.log。
- 排错结束后,我们就只需要删除掉该配置文件,就可以将Tomcat恢复到默认状态。
2.2 配置文件解析
然后我们来看看这个配置文件,看看里面的内容都是怎么解析的,我们将默认的配置内容分为三部分。
2.2.1 第一段配置的解析
我们先来看看第一段配置
handlers = 1catalina.org.apache.juli.FileHandler, 2localhost.org.apache.juli.FileHandler, 3manager.org.apache.juli.FileHandler, 4host-manager.org.apache.juli.FileHandler, java.util.logging.ConsoleHandler
.handlers = 1catalina.org.apache.juli.FileHandler, java.util.logging.ConsoleHandler
以上这一段是在 ClassLoaderLogManager.readConfiguration
中完成的
protected synchronized void readConfiguration(InputStream is, ClassLoader classLoader)
throws IOException {
ClassLoaderLogInfo info = classLoaderLoggers.get(classLoader);
// 以下为了节省篇幅,省略了异常处理的代码
// 加载logging.properties 文件
info.props.load(is);
// Create handlers for the root logger of this classloader
// 就是在这里读取上面的两个配置文件节点
String rootHandlers = info.props.getProperty(".handlers");
String handlers = info.props.getProperty("handlers");
Logger localRootLogger = info.rootNode.logger;
if (handlers != null) {
// 按 , 分割
StringTokenizer tok = new StringTokenizer(handlers, ",");
while (tok.hasMoreTokens()) {
String handlerName = (tok.nextToken().trim());
String handlerClassName = handlerName;
String prefix = "";
if (handlerClassName.length() <= 0) {
continue;
}
// Parse and remove a prefix (prefix start with a digit, such as "10WebappFooHanlder.")
// 注意上面的配置信息里, 首字母就是数字的
if (Character.isDigit(handlerClassName.charAt(0))) {
int pos = handlerClassName.indexOf('.');
if (pos >= 0) {
// 这里的prefix形如 1catalina , 2localhost, 3manager, 4host-manager.
prefix = handlerClassName.substring(0, pos + 1);
// 这里的handlerClassName形如 org.apache.juli.FileHandler
handlerClassName = handlerClassName.substring(pos + 1);
}
}
try {
// this.prefix类型为 ThreadLocal<String>
// 使用该prefix的位置位于 ClassLoaderLogManager 覆写的getProperty方法中
this.prefix.set(prefix);
Handler handler =
(Handler) classLoader.loadClass(handlerClassName).newInstance();
// The specification strongly implies all configuration should be done
// during the creation of the handler object.
// This includes setting level, filter, formatter and encoding.
this.prefix.set(null);
// 键值对的形式存入, 这里也体现出了数字前缀的用处
info.handlers.put(handlerName, handler);
if (rootHandlers == null) {
localRootLogger.addHandler(handler);
}
} catch (Exception e) {
// Report error
System.err.println("Handler error");
e.printStackTrace();
}
}
}
}
2.2.2 第二段配置的解析
然后是配置文件中的第二段配置
############################################################
# Handler specific properties.
# Describes specific configuration info for Handlers.
############################################################
1catalina.org.apache.juli.FileHandler.level = FINE
1catalina.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
1catalina.org.apache.juli.FileHandler.prefix = catalina.
2localhost.org.apache.juli.FileHandler.level = FINE
2localhost.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
2localhost.org.apache.juli.FileHandler.prefix = localhost.
3manager.org.apache.juli.FileHandler.level = FINE
3manager.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
3manager.org.apache.juli.FileHandler.prefix = manager.
4host-manager.org.apache.juli.FileHandler.level = FINE
4host-manager.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
4host-manager.org.apache.juli.FileHandler.prefix = host-manager.
java.util.logging.ConsoleHandler.level = FINE
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
以上这段配置文件可以参见 org.apache.juli.FileHandler.configure
方法,以及org.apache.juli.FileHandler.getProperty
方法【其在内部调用了LogManager.getProperty(name)
,而我们的ClassLoaderLogManager
正好是覆写了这个方法的】
// org.apache.juli.FileHandler.configure
/**
* Configure from <code>LogManager</code> properties.
*/
private void configure() {
// 截取出形如 2018-07-01 的日期; 用于组装日志文件名
Timestamp ts = new Timestamp(System.currentTimeMillis());
String tsString = ts.toString().substring(0, 19);
date = tsString.substring(0, 10);
String className = this.getClass().getName(); //allow classes to override
ClassLoader cl = Thread.currentThread().getContextClassLoader();
// Retrieve configuration of logging file name
// 注意这里的getProperty方法有自定义逻辑, 下方贴出具体实现
// rotatable : 日志文件是否自动轮转
rotatable = Boolean.parseBoolean(getProperty(className + ".rotatable", "true"));
// 日志文件所在的目录
if (directory == null)
directory = getProperty(className + ".directory", "logs");
// 日志文件名的前缀
if (prefix == null)
prefix = getProperty(className + ".prefix", "juli.");
// 日志文件名的后缀
if (suffix == null)
suffix = getProperty(className + ".suffix", ".log");
String sBufferSize = getProperty(className + ".bufferSize", String.valueOf(bufferSize));
try {
bufferSize = Integer.parseInt(sBufferSize);
} catch (NumberFormatException ignore) {
//no op
}
// Get encoding for the logging file
String encoding = getProperty(className + ".encoding", null);
if (encoding != null && encoding.length() > 0) {
try {
setEncoding(encoding);
} catch (UnsupportedEncodingException ex) {
// Ignore
}
}
// Get logging level for the handler
setLevel(Level.parse(getProperty(className + ".level", "" + Level.ALL)));
// Get filter configuration
String filterName = getProperty(className + ".filter", null);
if (filterName != null) {
try {
setFilter((Filter) cl.loadClass(filterName).newInstance());
} catch (Exception e) {
// Ignore
}
}
// Set formatter
String formatterName = getProperty(className + ".formatter", null);
if (formatterName != null) {
try {
setFormatter((Formatter) cl.loadClass(formatterName).newInstance());
} catch (Exception e) {
// Ignore and fallback to defaults
setFormatter(new SimpleFormatter());
}
} else {
setFormatter(new SimpleFormatter());
}
// Set error manager
setErrorManager(new ErrorManager());
}
private String getProperty(String name, String defaultValue) {
// 直接回调LogManager的getProperty方法
// 而Tomcat中使用的自定义LogManager【ClassLoaderLogManager】是覆写了这个方法的.
String value = LogManager.getLogManager().getProperty(name);
if (value == null) {
value = defaultValue;
} else {
value = value.trim();
}
return value;
}
我们截取上面配置文件中的一行配置,来进行一番分析,以便于理解。
1catalina.org.apache.juli.FileHandler.level = FINE
// 其中
// 1. 1catalina由 ClassLoaderLogManager.getProperty中的 this.prefix.get() 提供
// 2. org.apache.juli.FileHandler 由 FileHandler.configure中的classname提供
// 3. levle才是真正需要取的属性值对应的属性名
2.2.3 第三段配置的解析
然后是第三段配置
############################################################
# Facility specific properties.
# Provides extra control for each logger.
############################################################
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].level = INFO
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].handlers = 2localhost.org.apache.juli.FileHandler
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager].level = INFO
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager].handlers = 3manager.org.apache.juli.FileHandler
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/host-manager].level = INFO
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/host-manager].handlers = 4host-manager.org.apache.juli.FileHandler
这一段解析逻辑就需要去容器基类ContainerBase
类中
/**
* Return the abbreviated name of this container for logging messages
*/
protected String logName() {
// 返回缓存的 log name
if (logName != null) {
return logName;
}
// 就是这里生成org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager]这样格式的名称,
// 其中被 [ ] 包裹的名字 是在 server.xml中定义的 ; 形如 <Engine defaultHost="localhost" name="Catalina"> ;
String loggerName = null;
Container current = this;
while (current != null) {
String name = current.getName();
if ((name == null) || (name.equals(""))) {
name = "/";
} else if (name.startsWith("##")) {
name = "/" + name;
}
loggerName = "[" + name + "]"
+ ((loggerName != null) ? ("." + loggerName) : "");
current = current.getParent();
}
// 拼装出完整的配置键名, 用于从logging.properties中获取值
logName = ContainerBase.class.getName() + "." + loggerName;
return logName;
}
3. 两类日志
Tomcat中的日志信息被分为两类,分别是:
1. 运行中的日志。 它主要记录运行的一些信息,尤其是一些异常错误日志信息
2. 访问日志信息。 它记录访问的时间、IP、访问的资源等相关信息。
接下来我们将分别针对这两类信息,探索下Tomcat内的相关实现类。
3.1 运行中的日志
这类日志最直接的例子就是Tomcat的启动类BootStrap
了。但凡是Tomcat中,只要涉及到使用log, 并且拥有如下字段定义的,都是在记录运行时日志。
private static final org.apache.juli.logging.Log = org.apache.juli.logging.LogFactory.getLog(Xxxx.class);
接下来我们就以上面这行代码为例,来进行一下稍微深入一些的探讨。
沿着调用链, 经过几次跳转之后我们就会发现最终返回的Log实际类型为
DirectJDKLog
。而跟踪DirectJDKLog
的构造函数就会发现其直接调度给了JDK的java.util.logging.Logger
。这里需要注意下的是
DirectJDKLog
类的静态构造函数块,我们通过JVisualVM查看发现java.util.logging.config.file
不为空,而java.util.logging.config.class
为空。所以这段静态构造块在Tomcat下默认是不会执行的。而涉及到 JDK中的
java.util.logging.Logger
,必然逃不开LogManager
。而按照上篇文章JDK研究之Logger的研究,在LogManager
的静态构造块的逻辑里,会查找系统属性java.util.logging.manager
对应的值,如果发现不为空,则将其实例化作为LogManager
的本次系统中的真正实现者。 而我们可以从JVISUALVM看到了这个键值对的。【下方截图】所以现在让我们看看
org.apache.juli.ClassLoaderLogManager
; 其覆写的readConfiguration
方法,首先在当前的classLoader中查找名为logging.properties
的资源。如果当前classLoader中不存在会使用指定位置的logging.properties
配置文件。这里就与我们上面解释的logging.properties
配置文件读取顺序匹配上了。接下来的逻辑就回到了上面对配置文件的解析,以及在Tomcat的诸多组件中,哪些组件用到了日志组件,并且它们是如何使用的。
另外多提一句的是,我们在
org.apache.juli.logging.LogFactory
的私有构造函数中发现,其使用了SPI来加载了 实现了org.apache.juli.logging.Log
接口的自定义类。 所以我们是可以接管过来的。 注意构造函数必须有一个 String类型参数。(这是Tomcat8.x里的逻辑)
3.2 访问日志信息
此类日志信息默认是不输出的,需要使用者主动进行配置。方式则是在Tomcat的配置文件${catalina}/conf/server.xml
中添加如下节点:
<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs" pattern="%h %l %u %t "%r" %s %b" prefix="localhost_access_log." resolveHosts="false" suffix=".txt"/>
于是我们的关注点顺势就来到了这个AccessLogValve
上。
关于这个AccessLogValve
类,这次我们的关注点主要是如下这些:
1. 其间接实现了Lifecycle
接口,并且覆写了startInternal
方法。而自定义的startInternal
逻辑会按照既定的日志文件名规则,生成一个存放访问日志的日志文件并将该文件打开,准备写入。所以我们平时在启动完毕Tomcat之后,发现日志文件已经生成,并且无法删除。
2. 其直接实现了AccessLog
接口。按照这个接口上的注释说明,这是Tomcat内部使用的接口,继承自该接口则表明该Valve将提供记录访问日志的功能,而且有个比较重要的点是,该接口的实现Valve还能记录被拒绝访问的请求。
3. 内部有个设计小技巧就是, 内部定义了一个接口 AccessLogElement, 需要记录的特定信息只需要继承自该接口,实现自己的专有逻辑即可(例如SessionIdElement,RemoteAddrElement,CookieElement),最终的输出的日志就是这些实现类所记录信息的总和。
4. 其他相关类
Tomcat中与Log有关联的类除了上面提到的AccessLogValve
,ClassLoaderLogManager
外,我们还可以关注以下相关类:
Container
。 作为一个容器必须实现的接口,其契约了一个返回容器相关联的Logger的getLogger
方法,而默认的实现由ContainerBase
完成,而且具体的容器实现类均未对此进行覆写。另外还需要注意的是 其还定义了另外一个getAccessLog
方法,用于记录访问日志。甚至还有一个logAccess
方法。ValveBase
,作为Valve继承链中关键的底层一环,其中定义了containerLog,
这个用来获取相关容器log的字段。
5. 补充
最后我们来看看Tomcat启动后,相应的JVM参数和系统参数。(以下截图和信息都是从JVisualVM中截取而来的)
JVM参数
系统参数
awt.toolkit=sun.awt.windows.WToolkit
catalina.base=D:\apache-tomcat-8.0.33-windows-x64
catalina.home=D:\apache-tomcat-8.0.33-windows-x64
catalina.useNaming=true
common.loader="${catalina.base}/lib","${catalina.base}/lib/*.jar","${catalina.home}/lib","${catalina.home}/lib/*.jar"
file.encoding=GBK
file.encoding.pkg=sun.io
file.separator=\
java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment
java.awt.printerjob=sun.awt.windows.WPrinterJob
java.class.path=D:\apache-tomcat-8.0.33-windows-x64\bin\bootstrap.jar;D:\apache-tomcat-8.0.33-windows-x64\bin\tomcat-juli.jar
java.class.version=52.0
java.endorsed.dirs=D:\apache-tomcat-8.0.33-windows-x64\endorsed
java.ext.dirs=C:\Java\jdk1.8.0_92-64\jre\lib\ext;C:\Windows\Sun\Java\lib\ext
java.home=C:\Java\jdk1.8.0_92-64\jre
java.io.tmpdir=D:\apache-tomcat-8.0.33-windows-x64\temp
java.library.path=C:\Java\jdk1.8.0_92-64\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\ProgramData\Oracle\Java\javapath;C:\Program Files (x86)\Common Files\NetSarang;D:\apps\Oracle11\product\11.2.0\dbhome_1\bin;D:\apps\Oracle10\bin;C:\Program Files (x86)\Intel\iCLS Client\;C:\Program Files\Intel\iCLS Client\;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\Intel\Intel(R) Management Engine Components\DAL;C:\Program Files (x86)\Intel\Intel(R) Management Engine Components\DAL;C:\Program Files\Intel\Intel(R) Management Engine Components\IPT;C:\Program Files (x86)\Intel\Intel(R) Management Engine Components\IPT;C:\Program Files\Intel\WiFi\bin\;C:\Program Files\Common Files\Intel\WirelessCommon\;C:\Program Files (x86)\Common Files\Lenovo;C:\SWTOOLS\ReadyApps;D:\QuickStart;C:\Java\jdk1.8.0_92-64\bin;C:\Java\jdk1.8.0_92-64\jre\bin;E:\Java\_tools\apache-maven-3.3.3\bin;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Windows Kits\8.0\Windows Performance Toolkit\;C:\Program Files\Microsoft SQL Server\110\Tools\Binn\;E:\Java\_tools\gradle-1.6\bin;D:\apps\MySQL_Server_5.5\bin;;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\nodejs\node_global\;C:\Program Files\TortoiseSVN\bin;C:\Users\LQ\AppData\Local\Programs\Python\Python36-32\Scripts\;C:\Users\LQ\AppData\Local\Programs\Python\Python36-32\;C:\Program Files\Microsoft VS Code\bin;C:\Users\LQ\AppData\Roaming\npm;.
java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory
java.naming.factory.url.pkgs=org.apache.naming
java.rmi.server.randomIDs=true
java.runtime.name=Java(TM) SE Runtime Environment
java.runtime.version=1.8.0_92-b14
java.specification.name=Java Platform API Specification
java.specification.vendor=Oracle Corporation
java.specification.version=1.8
java.util.logging.config.file=D:\apache-tomcat-8.0.33-windows-x64\conf\logging.properties
java.util.logging.manager=org.apache.juli.ClassLoaderLogManager
java.vendor=Oracle Corporation
java.vendor.url=http://java.oracle.com/
java.vendor.url.bug=http://bugreport.sun.com/bugreport/
java.version=1.8.0_92
java.vm.info=mixed mode
java.vm.name=Java HotSpot(TM) 64-Bit Server VM
java.vm.specification.name=Java Virtual Machine Specification
java.vm.specification.vendor=Oracle Corporation
java.vm.specification.version=1.8
java.vm.vendor=Oracle Corporation
java.vm.version=25.92-b14
line.separator=\r\n
os.arch=amd64
os.name=Windows 7
os.version=6.1
package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.tomcat.
package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.naming.,org.apache.tomcat.
path.separator=;
server.loader=
shared.loader=
sun.arch.data.model=64
sun.boot.class.path=C:\Java\jdk1.8.0_92-64\jre\lib\resources.jar;C:\Java\jdk1.8.0_92-64\jre\lib\rt.jar;C:\Java\jdk1.8.0_92-64\jre\lib\sunrsasign.jar;C:\Java\jdk1.8.0_92-64\jre\lib\jsse.jar;C:\Java\jdk1.8.0_92-64\jre\lib\jce.jar;C:\Java\jdk1.8.0_92-64\jre\lib\charsets.jar;C:\Java\jdk1.8.0_92-64\jre\lib\jfr.jar;C:\Java\jdk1.8.0_92-64\jre\classes
sun.boot.library.path=C:\Java\jdk1.8.0_92-64\jre\bin
sun.cpu.endian=little
sun.cpu.isalist=amd64
sun.desktop=windows
sun.io.unicode.encoding=UnicodeLittle
sun.java.command=org.apache.catalina.startup.Bootstrap start
sun.java.launcher=SUN_STANDARD
sun.jnu.encoding=GBK
sun.management.compiler=HotSpot 64-Bit Tiered Compilers
sun.os.patch.level=Service Pack 1
sun.stderr.encoding=ms936
sun.stdout.encoding=ms936
tomcat.util.buf.StringCache.byte.enabled=true
tomcat.util.scan.StandardJarScanFilter.jarsToScan=log4j-core*.jar,log4j-l*.jar,log4javascript*.jar
tomcat.util.scan.StandardJarScanFilter.jarsToSkip=bootstrap.jar,commons-daemon.jar,tomcat-juli.jar,annotations-api.jar,el-api.jar,jsp-api.jar,servlet-api.jar,websocket-api.jar,catalina.jar,catalina-ant.jar,catalina-ha.jar,catalina-storeconfig.jar,catalina-tribes.jar,jasper.jar,jasper-el.jar,ecj-*.jar,tomcat-api.jar,tomcat-util.jar,tomcat-util-scan.jar,tomcat-coyote.jar,tomcat-dbcp.jar,tomcat-jni.jar,tomcat-websocket.jar,tomcat-i18n-en.jar,tomcat-i18n-es.jar,tomcat-i18n-fr.jar,tomcat-i18n-ja.jar,tomcat-juli-adapters.jar,catalina-jmx-remote.jar,catalina-ws.jar,tomcat-jdbc.jar,tools.jar,commons-beanutils*.jar,commons-codec*.jar,commons-collections*.jar,commons-dbcp*.jar,commons-digester*.jar,commons-fileupload*.jar,commons-httpclient*.jar,commons-io*.jar,commons-lang*.jar,commons-logging*.jar,commons-math*.jar,commons-pool*.jar,jstl.jar,taglibs-standard-spec-*.jar,geronimo-spec-jaxrpc*.jar,wsdl4j*.jar,ant.jar,ant-junit*.jar,aspectj*.jar,jmx.jar,h2*.jar,hibernate*.jar,httpclient*.jar,jmx-tools.jar,jta*.jar,log4j*.jar,mail*.jar,slf4j*.jar,xercesImpl.jar,xmlParserAPIs.jar,xml-apis.jar,junit.jar,junit-*.jar,ant-launcher.jar,cobertura-*.jar,asm-*.jar,dom4j-*.jar,icu4j-*.jar,jaxen-*.jar,jdom-*.jar,jetty-*.jar,oro-*.jar,servlet-api-*.jar,tagsoup-*.jar,xmlParserAPIs-*.jar,xom-*.jar
user.country=CN
user.dir=D:\apache-tomcat-8.0.33-windows-x64\bin
user.home=C:\Users\LQ
user.language=zh
user.name=LQ
user.script=
user.timezone=Asia/Shanghai
user.variant=
6. Links
- 《How Tomcat Works》 第七章 - P145
- 《Apache Tomcat 7 Essentials》 Chapter 6 - P145 (居然是同一页)
- logging - Office Site
- Tomcat的Logging(1)
- Tomcat的Logging(2)