刨根问底Java日志

日志对于日常开发、问题解决的重要性不言而喻,工作中由于接触各种类型的项目和框架,看到很多日志的不同用法,造成项目依赖和代码的混乱,故梳理总结。本文包括Java日志体系的发展历史、推荐应用方式和部分底层原理;运维层面的日志系统搭建及不同组件的对比;及常用的查询日志的Linux命令,方便Linux机器上日志的查询。

@[TOC]

一. Java日志体系

Java日志体系伴随着Java语言的发展,同时也夹杂着开发者之间、组织之间的较量,一直至今。

1.1. Java日志体系发展历史及相互关联

1.1.1. System.out 和 System.err

Java语言自1995年向互联网公开,作为一门编程语言,就如C语言的 printf("Hello, World!"); 一样,Java当然也有内置的输出方式,即 System.out.println()System.err.println(),前者指向标准输出,后者指向标准错误输出。在日志工具出现之前,大部分是用这种原始的方式打印查看日志的。

1.1.2. Log4j

Apache Log4j 是一个基于Java的日志记录工具。它是由 Ceki Gülcü 首创的,于2001年初推出后备受欢迎,后来成为 Apache 基金会项目中的一员,一度成为 Java 日志的标杆。传言 Apache 基金会曾建议 Sun 将 Log4j 引入 Java 标准类库,但是被拒绝了。

1.1.3. JUL

2002年2月发布的 JDK1.4 中,Sun 推出了自己的日志库,java.util.logging,很多实现方法都是仿照 Log4j,虽然不太有风度,但是此后打日志有了两种方式。

1.1.4. JCL

JCL全称 Apache Commons Logging,据说之前叫 Jakarta Commons Logging,于2002年8月由 Apache 发布。不同于 Log4j 和 JUL,JCL是一种日志门面(Logging Facade),只提供 Log API,不提供实现。

理想上是很优雅的,大家记录日志都使用 JCL 的接口,运行时可以按照自己的需求(或者喜好)来选择使用合适的Log Implementation。如果用Log4j,就添加 Log4j 的 jar 包进去,然后写一个 Log4j 的配置文件;如果喜欢用JUL,就只需要写个 JUL 的配置文件。如果有其他的新的日志库出现,也只需要它提供一个Adapter,运行的时候把这个日志库的 jar 包加进去。这也是面向接口编程思想的体现,但是由于运行时动态绑定等原因,实际使用中出现了性能问题及类加载等问题。


image.png

1.1.5. SLF4J

SLF4J 全称 Simple Logging Facade for Java。虽然 JCL 在设计上想法很好,但是由于其造成的一系列问题,Ceki Gülcü 大神表示强烈不满,此时他已经离开了 Apache,于是在2005年推出了自创的日志门面,即SLF4J。但是由于 Log4j 和 JUL 已经在那里了,而且不是按照 SLF4J 的 API 实现的,所以存在兼容性的问题,SLF4J 面临了只有 API 没有实现的局面。此时 Ceki Gülcü 推出了 桥接包,如果需要使用某一种日志实现,那么选择相对应的 SLF4J 的桥接包即可。比如使用 log4j 日志组件,就加入 slf4j-log4j12 桥接包。

不得不说 Ceki Gülcü 野心很大,为了一统江湖甚至推出了 slf4j-jcl 桥接包,把作为日志门面的 JCL 也视为了他可以匹配的“实现”。

现在江湖变成了这样的:


image.png

但是还存在一个问题,

1.1.6. Logback

1.2. Java日志相关部分原理

1.2.1. System.out.println()

初学时会像记公式一样背下来这一串代码,没有按照Java方法调用的角度去理解,先来刨一刨这个方法。

  • System 是 java.lang 包中的一个 final 类:/classes/java/lang/System.java。根据 JavaDoc,“ System 类提供的包括:标准输入,标准输出和错误输出流;访问外部定义的属性和环境变量;一种加载文件和库的方法;以及用于快速复制阵列的一部分的实用方法。”
  • out 是 System 类的静态成员字段,类型为 PrintStream。它在启动时就会被实例化,并与主机的标准输出控制台进行映射。该流在实例化之后立即打开,并准备接受数据。其在 System 类中的定义语句如下:
/**
 * The "standard" output stream. This stream is already
 * open and ready to accept output data. Typically this stream
 * corresponds to display output or another output destination
 * specified by the host environment or user.
 */
public final static PrintStream out = null;
  • println 是 PrintStream 类的一个方法。println 打印(参数内容 + 换行符)到控制台。PrintStream 类中有多个重载的 println 方法。每个 println 是通过调用 print 方法并添加一个换行符实现的。print 方法是通过调用流的 write 方法实现的。

了解了 System.out.println() 的表层原理,System.err.println() 和其几乎相同,err 也是System 类的一个 PrintStream 类型成员。

但是不解的问题仍然存在。

  • System.out 这个变量被 final 修饰,初始化为 null,为何执行 println() 方法不报空指针异常?
  • System.out 是如何被指向标准输出(默认控制台)的;
  • out 变量被声明为 final,是否意味着 System.out.println() 方法只能向控制台打印;

为了解决这些疑惑,深入理解 System.out.println() 调用的原理:

  1. System 类在 vm 启动后优先初始化,比 out 对象的类型 PrintStream 靠前,而 out 对象是 static final 修饰的,定义的时候必须初始化,故在定义时初始化为 null ;

  2. 想修改已经被赋值的 final 变量,可用的一种方法是在没有内联优化的情况下利用反射将 final 修饰符去掉再设置新值,但是这对 System 类不可行。故 Java 采用更底层的方法绕过 final 限制;

  3. 绝大部分博客,包括所有笔者浏览过的中文博客中都陈述:System 类有唯一一个 static 代码段执行的方法:registerNatives(),源码见 /native/java/lang/System.c#l47。此方法中调用了该类的 initializeSystemClass() 方法做一些初始化工作,依据是 Java 源码这个方法上的注释内容,如下图。但是此解释是完全错误的。

    image.png

    笔者翻看了和 registerNatives() 方法有关的所有 hotspot 源码,没有找到 initializeSystemClass() 方法的调用逻辑。registerNatives() 方法是一个常见于各种类中的,用于初始化该类的 native 方法的方法。如在 System 类中,有三个 native 方法需要初始化,如下图。
    image.png

    这里的 *env 为 JNI 环境, 方法进入 jni_RegisterNatives():/vm/prims/jni.cpp#l4050,代码逻辑就是遍历了上图中的 methods 数组,注册了 native 方法。和我们所关心的 out 对象一点关系都没有,不多说。

  4. 实际上 initializeSystemClass() 方法是在 /vm/runtime/thread.cpp#l3529 中被调用的,在初始化 System 类的同时也初始化了很多其他基础类,如 Class、Method、Finalizer 等,只不过初始化 System 类用了一个专门的方法。

    image.png

    此方法内逻辑是,先解析出 System 类元数据 Klass,再用 call_static 调用已被编译的 initializeSystemClass() 方法。整体在 thread 初始化后进行。

  5. 破案了。回到 Java 中的 initializeSystemClass() 方法,该方法对 in、out、err 三个流进行了初始化:


    image.png

    其中,FileDescriptor 是文件描述符,对于每个打开的文件,操作系统都会分配一个文件描述符,0、1、2 文件描述符分别预留给标准输入、标准输出、错误输出,System.out.println() 最终是在标准输出文件描述符上执行 write() 操作,in 和 err 同理,故在初始化的时候传入了参数0、1、2:

public static final FileDescriptor in = new FileDescriptor(0);
public static final FileDescriptor out = new FileDescriptor(1);
public static final FileDescriptor err = new FileDescriptor(2);
  1. 注意,这里 setOut0() 方法也是 native 方法,实现在 /native/java/lang/System.c#l464。首先 (*env)->GetStaticFieldID(env,cla,"out","Ljava/io/PrintStream;") 获取 System.java 的静态成员 out 的 jfieldID,(*env)->SetStaticObjectField(env,cla,fid,stream) 设置 fid(即 out 的 jfieldID)对应的静态成员的值为传入的 stream。源码在注释中也大方说明了这么做的原因:

    image.png

  2. System 类中提供了 setOut() 方法用于修改标准输出,setOut() 方法也是调用了 setOut0() 才得以实现,在此之前还会先检查是否有 setIO 的权限:


    image.png

    故只要在 Java 代码中调用 setOut() 方法即可修改 System.out.println() 的输出目标,举例如下:


    image.png
  3. 至此知道了 out 对象的来龙去脉。关于那个大家都误解的注释,个人认为那个注释应该是加在 System 类上的,但被加在了方法上,不仔细研究很容易跑偏。再后来,Java 改变了 System 类初始化的逻辑,变为了三个步骤,方法分别取名为 initPhase1initPhase2initPhase3,负责不同的功能,out 的初始化在 call_initPhase1() 方法中,详见 /vm/runtime/thread.cpp#l3376。但是 Java 的开发者依旧忘记了更新那段令人迷惑的注释,后来在被提 issue 后进行了 update,可以借此看看 Java 的 issue 流程,也是趣事:https://bugs.openjdk.java.net/browse/JDK-8232617

  4. 如果想给控制台输出自定义一些格式,也不是不可以,如下图。但是这个格式的设定和 Java 没什么关系,参考:ANSI转义序列

    image.png

1.3. 常见框架中的日志应用(以springboot和mybatis为例)

二. Java日志推荐方式

三. 日志收集处理分析平台

四. 常用于日志查询的Linux命令

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 206,839评论 6 482
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 88,543评论 2 382
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 153,116评论 0 344
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 55,371评论 1 279
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 64,384评论 5 374
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,111评论 1 285
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,416评论 3 400
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,053评论 0 259
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 43,558评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,007评论 2 325
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,117评论 1 334
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,756评论 4 324
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,324评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,315评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,539评论 1 262
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,578评论 2 355
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,877评论 2 345

推荐阅读更多精彩内容

  • 一、日志简介 1.1 日志是什么(WHAT) 日志:记录程序的运行轨迹,方便查找关键信息,也方便快速定位解决问题。...
    GeekerLou阅读 27,266评论 6 20
  • JAVA日志系统的演变史 我们先看一个故事。项目经理A带着一帮兄弟开发了一套复杂的企业ERP系统,这个系统一连开发...
    糖宝_阅读 638评论 0 4
  • idea 添加注释/** 然后回车 选中代码块 Ctrl+Shift+/ 重点推荐阅读:https://www....
    Helen_Cat阅读 19,754评论 0 37
  • 最近准备看一下各个日志框架能否以及如何实现多线程下写入自定义文件。同时深入的整理并学习一下这些日志框架。 一、 目...
    ZMSunrise阅读 2,902评论 2 7
  • 看了一本书,叫做《java工程师修炼之道》,第107页讲了各种日志框架及其配置。平时我们开发,都是在控制台输出日志...
    呼噜噜睡阅读 156评论 0 0