Java项目中如何详细解析日志打印步骤？

本文共计2589个文字，预计阅读时间需要11分钟。

很久以前，有个朋友问我，如果有个老项目让你接手后持续维护，你会先从哪里入手、快速上手项目？我当时没有特别正面地回答这个问题，只是说：一个老项目是与否...

很久之前，有个朋友问我，如果一个老项目让你接手去进行后续维护，你会先从哪里入手、让自己更快地上手项目？当时我没有特别正面去回答这个朋友的问题，我说：一个老项目是否容易上手，一个非常关键的地方就是这个项目的日志是否打得足够好。因为通常来说，一个老项目相对比较稳定了，后续大概率不会有比较大的变更和改动，那么对于这样的项目，核心就是“维稳”。但是任何人都无法保证项目在线上运行时不会出线上故障，在出现线上问题或者故障时，如何快速止损就是第一要义，而日志在止损过程中就扮演着非常重要的角色。日志打的足够明了清晰，可以帮助开发和运维人员快速定位问题，继而决定采取何种方案进行止损。

今天就让我们一起来聊一聊如何把项目程序日志打“好”。

一.为何需要规范地打印程序日志？

我们平时在写程序代码过程中，一般会把主要精力集中在功能实现上，往往会忽视日志的重要性，然而日志在系统上线后是极其重要的，因为系统上线后，只有通过日志才能了解当前系统的运行状态，在出现线上故障时，日志是否足够清晰明了决定了是否能够快速找到止损方案。我们可以看一下下面这段代码：

public class HttpClient { private static final Logger LOG = LoggerFactory.getLogger(HttpClient.class); private static int CONNECT_TIMEOUT = 5000; // unit ms private static int READ_TIMEOUT = 10000; // unit ms public static String sendPost(String url, String param) { OutputStream out = null; BufferedReader in = null; String result = ""; try { URL realUrl = new URL(url); URLConnection conn = realUrl.openConnection(); conn.setDoInput(true); conn.setDoOutput(true); conn.setConnectTimeout(CONNECT_TIMEOUT); conn.setReadTimeout(READ_TIMEOUT); conn.setRequestProperty("charset", "UTF-8"); out = new PrintWriter(conn.getOutputStream()); out.print(parm); out.flush(); in = new BufferedReader(new InputStreamReader(conn.getInputStream())); String line; while ((line = in.readLine()) != null) { result += line; } } catch (Exception ex) { LOG.error("post request error!!!"); } finally { try { if (out != null) { out.close(); } if (in != null) { in.close(); } } catch (IOException ex) { LOG.error("close stream error!!!"); } return result; } } }

某一天线上突然大量www.123.test.com], param:[name=jack]
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:579)

那么便能很快地断定是下游logback.qos.ch/manual/appenders.html#SizeAndTimeBasedFNATP
　　对于日志滚动策略来说，有2个比较关键的参数：最大保留日志数量和最大磁盘占用空间。这2个参数切记一定要设置，如果没有设置，则很有可能会出现把线上机器磁盘打满的情况。

2.3 日志级别

　　日志的级别通常有以下几种：

　　debug/trace、info、warning、error、fatal

　　这几种日志级别的严重程序依次递增：

　　debug/trace：debug和trace级别的日志由于打印内容较多，所以通常情况下不适用于线上生产环境使用，一般使用于前期线下环境调试。即使线上环境要使用，也需要通过开关来控制，只在定位追踪线上问题时才开启；

　　info：info日志一般用来记录系统运行的关键状态、关键业务逻辑或者关键执行节点。但切记一点，info日志绝不可滥用，如果info日志滥用，则和debug/trace日志没有太大区别了。

　　warning：warning日志一般用来记录系统运行时的一些非预期情况，顾名思义，是作为一种警示，提醒开发和运维人员需要关注，但是不用人为介入立刻去处理的。

　　error：error日志一般用来记录系统运行时的一些普通错误，这些错误一旦出现，则表示已经影响了用户的正常访问或者使用，通常意味着需要人为介入处理。但很多时候在生产环境中，也不一定是出现error日志就需要人工立即介入处理的，通常会结合error日志的数量以及持续时间来进行综合判断。

　　fatal：属于系统致命错误，一般出现意味着系统基本等于挂掉了，需要人工立即介入处理。

　　下面举个简单的例子来说明，假如我们有这样一个场景，我们有一个工资计算系统，每隔月1号需要从员工考勤系统获取公司所有员工的考勤数据，然后根据考勤数据来计算上月应发工资，那么需要有一个函数从考勤系统获取员工考勤数据：

public Map<Long, Double> getEmployeeWorkDaysFromAttendance(int year, int month, Set<Long> employeeList) throws BusiessException { // 入口关键日志，需要打印关键的参数，因为employeeList可能数量较大，所以次数没有直接打印employeeList列表内容，只打印了size logger.info("get employee work days, year:{}, month:{}, employeeList.size:{}", year, month, employeeList.size()); // 如果需要临时检验员工列表，可以把debug日志开关打开 if (debugOpen()) { logger.debug("employ list content:{}", JSON.toJsonString(employeeList)); } int retry = 1; while (retry <= MAX_RETRY_TIMES) { try { Map<Long, Double> employeeWorkDays = employeeAttendanceRPC.getEmployeeWorkDays(year, month, employeeList); logger.info("get employee work days success, year:{}, month:{}, employeeList.size:{}, employeeWorkDays.size:{}", year, month, employeeList.size(), employeeWorkDays.size()); return employeeWorkDays; } catch (Exception ex) { logger.warning("rpc invoke failed(employeeAttendanceRPC.getEmployeeWorkDays), retry times:{}, year：{}, month:{}, employeeList.size:{}", retry, year, month, employeeList.size(), ex); // 连续重试失败之后，向上跑出异常 // 对于没有异常机制的语言，此处应该打印error日志 if (retry == MAX_RETRY_TIMES) { throw new BusiessException(ex, "rpc invoke failed(employeeAttendanceRPC.getEmployeeWorkDays)"); } } retry++; } }

2.4 日志打印时机的选择
　　由于日志是为了方便我们了解系统当前的运行状况以及定位线上问题，所以日志打印的时机非常重要，如果滥用日志，则会导致日志内容过多，影响问题定位的效率；如果日志打印过少，则容易导致缺少关键日志，导致在线上定位问题时找不到问题根音。因此把握日志打印的时机至关重要，以下是常见的适合打印日志的时机：

1）http调用或者rpc接口调用

　　在程序调用其他服务或者系统的时候，需要打印接口调用参数和调用结果(成功/失败)。

2）程序异常

　　在程序出现exception的时候，要么选择向上抛出异常，要么必须在catch块中打印异常堆栈信息。不过需要注意的是，最好不要重复打印异常日志，比如在catch块里既向上抛出了异常，又去打印错误日志(对外rpc接口函数入口处除外)。

3）特殊的条件分支

　　程序进入到一些特殊的条件分支时，比如特殊的else或者switch分支。比如我们根据工龄计算薪资：

public double calSalaryByWorkingAge(int age) { if (age < 0) { logger.error("wrong age value, age:{}", age); return 0; } // .. }

　　理论上工龄不可能小于0，所以需要打印出这种非预期情况，当然通过抛出异常的方式也是可行的。

4）关键执行路径及中间状态

　　在一些关键的执行路径以及中间状态也需要记录下关键日志信息，比如一个算法可能分为很多步骤，每隔步骤的中间输出结果是什么，需要记录下来，以方便后续定位跟踪算法执行状态。

5）请求入口和出口

　　在函数或者对外接口的入口/出口处需要打印入口/出口日志，一来方便后续进行日志统计，同时也更加方便进行系统运行状态的监控。

2.5 日志内容与格式

　　日志打印时机决定了能够根据日志去进行问题定位，而日志的内容决定了是否能够根据日志快速找出问题原因，因此日志内容也是至关重要的。通常来说，一行日志应该至少包括以下几个组成部分：

　　logTag、param、exceptionStacktrace

　　logTag为日志标识，用来标识此日志输出的场景或者原因，param为函数调用参数，exceptionStacktrace为异常堆栈。举例说明：

good case

public class HttpClient { private static final Logger LOG = LoggerFactory.getLogger(HttpClient.class); private static int CONNECT_TIMEOUT = 5000; // unit ms private static int READ_TIMEOUT = 10000; // unit ms public static String sendPost(String url, String param) { OutputStream out = null; BufferedReader in = null; String result = ""; try { URL realUrl = new URL(url); URLConnection conn = realUrl.openConnection(); conn.setDoInput(true); conn.setDoOutput(true); conn.setConnectTimeout(CONNECT_TIMEOUT); conn.setReadTimeout(READ_TIMEOUT); conn.setRequestProperty("charset", "UTF-8"); out = new PrintWriter(conn.getOutputStream()); out.print(parm); out.flush(); in = new BufferedReader(new InputStreamReader(conn.getInputStream())); String line; while ((line = in.readLine()) != null) { result += line; } } catch (Exception ex) { // 有关键logTag，有参数信息，有错误堆栈 LOG.error("post request error!!!, url:[[}], param:[{}]", url, param, ex); } finally { try { if (out != null) { out.close(); } if (in != null) { in.close(); } } catch (IOException ex) { LOG.error("close stream error!!!, url:[[}], param:[{}]", url, param, ex); } return result; } } }

bad case

public class HttpClient { private static final Logger LOG = LoggerFactory.getLogger(HttpClient.class); private static int CONNECT_TIMEOUT = 5000; // unit ms private static int READ_TIMEOUT = 10000; // unit ms public static String sendPost(String url, String param) { OutputStream out = null; BufferedReader in = null; String result = ""; try { URL realUrl = new URL(url); URLConnection conn = realUrl.openConnection(); conn.setDoInput(true); conn.setDoOutput(true); conn.setConnectTimeout(CONNECT_TIMEOUT); conn.setReadTimeout(READ_TIMEOUT); conn.setRequestProperty("charset", "UTF-8"); out = new PrintWriter(conn.getOutputStream()); out.print(parm); out.flush(); in = new BufferedReader(new InputStreamReader(conn.getInputStream())); String line; while ((line = in.readLine()) != null) { result += line; } } catch (Exception ex) { // 没有任何错误信息 LOG.error("post request error!!!"); } finally { try { if (out != null) { out.close(); } if (in != null) { in.close(); } } catch (IOException ex) { LOG.error("close stream error!!!"); } return result; } } }

　　另外，对于对外http接口或者rpc接口，最好对于每个请求都有requestId，以便跟踪每个请求后续所有的执行路径。

以上就是本文的全部内容，希望对大家的学习有所帮助，也希望大家多多支持易盾网络。