工程实践：如何规范地打印程序日志？

工程实践：如何规范地打印程序日志？

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

今天就让我们一起来聊一聊如何把项目程序日志打“好”。以下是本文大纲目录：

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

二.如何规范地打印程序日志？

若有不正之处请多多谅解，并欢迎批评指正。

请尊重作者劳动成果，转载请标明原文链接：

http://www.dolphin0520.com/archives/2018/11/26/176.html

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

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

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请求失败，然后查看日志，发现了大量的“post request error!!!”错误，此时假如看到这样的日志你可能完全不知道究竟是什么原因导致的，还得继续通过一些其他的手段来定位具体原因。

假如打印的错误日志是这样的：

post request error!!!, url:[http://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)

那么便能很快地断定是下游http服务问题导致的，且下游http服务域名为www.123.test.com(Connection refused通常是由于下游服务端口未启动引起的)，可以迅速找相应的人员进行止损，避免在故障定位阶段耗费大量的时间。

上面举的例子只是一个非常小的例子，实际日常开发中可能碰到的线上问题比这个更加复杂和棘手，总结来看，日志的主要作用有以下几点：

1）日志是系统运行的“照妖镜”，通过它能够实时反映系统的运行状态；

如上图所示，系统A中producer不断产生数据放入到data queue中，sender不断从data queue中取数据发送给下游系统B的receiver，那么对于系统A来说，data queue中的待发送数据量便是一个非常关键的指标，它能够从侧面真实反应当前系统的运行状况，如果data queue中的element个数超过容量的90%了，那么标志着此时系统可能运行不正常了，会有队列堵塞的风险；如果data queue中的element个数不到容量的10%，那么标志着此时系统运行比较正常，出现队列堵塞的风险较低。

如果这个指标没有输出到日志中，开发和运维人员是无法确切知道当前系统A的运行状态的(当然也有其他的方式来获取这个指标，比如通过http接口暴露出来也是一种方式之一)。

2）良好的日志便于后期运维和开发人员迅速定位线上问题，加快止损速度，减少系统故障带来的损失；

3）日志还有另外一个作用便是能够无缝与监控系统结合，通过监控系统进行日志采集，拿到系统运行的相关性能指标，有利于分析系统的性能瓶颈、提前规避风险；

举例说明：

假如有一个商城系统，在初期，数据库通过2台服务器提供服务(1台master，1台slave)，此时大部分接口能在秒级内响应用户请求。随着时间的推移，商城系统的用户量逐渐增多，并发查询和写入量都出现了一定的增长，数据库中的数据量也慢慢增多，导致部分sql语句查询越来越慢，突然有一天，数据库的slave机器由于过多的慢查询导致被拖垮，彻底宕机了，导致商城服务不可用。

如果商城系统在日志中记录了每个http请求的耗时情况，通过监控系统配置日志采集，同时配置相应的报警，那么便能提前发现由于业务增长带来的系统性能瓶颈，提前进行系统优化(如机器扩容、sql语句优化、分库分表等)，规避风险。

4）便于统计与业务相关的指标数据，进行相关业务分析和功能优化。

举例说明：

比如一个搜索系统，想统计过去一周不同地域(如南北地域)的搜索使用占比，如果日志中本身打印了每个搜索query请求的ip，则很容易统计，否则需要重新上线加日志才能统计。

因此，大家在日常编写代码过程中要注重日志书写的规范性，让它发挥出它应有的价值，在辅助保障我们服务稳定运行的同时，能够有效提升后期系统维护效率。

二.如何规范地打印程序日志？

接下来，我们从以下几个方面来谈谈如何规范地打印日志。

2.1 日志文件命名

通常来说日志文件的命名可包括以下几个关键信息：

类型标识(logTypeName)
日志级别(logLevel)
日志生成时间(logCreateTime)
日志备份编号(logBackupNum)

    类型标识：指此日志文件的功能或者用途，比如一个web服务，记录http请求的日志通常命名为request.log或者access.log，request、access就是类型标识，而java的gc日志通常命名为gc.log，这样看一目了然；而通常用来记录服务的整体运行的日志一般用服务名称(serviceName、appKey)或者机器名(hostName)来命名，如 nginx.log；

日志级别：打印日志的时候直接通过文件来区分级别是一种比较推荐的方式，如果把所有级别的日志打到同一个日志文件中，在定位问题时，还需要去文件中进行查找操作，相对繁琐。日志级别一般包括DEBUG、INFO、WARN、ERROR、FATAL这五个级别，在实际编写代码中，可以采取严格匹配模式或者非严格匹配模式，严格匹配模式即INFO日志文件中只打印INFO日志，ERROR日志文件只打印ERROR日志；非严格匹配模式即INFO日志文件可以打印INFO日志、WARN日志、ERROR日志、FATAL日志，WARN日志文件可以打印WARN日志、ERROR日志、FATAL日志，以此类推。

日志生成时间：即在日志文件名称中附带上日志文件创建的时间，方便在查找日志文件时进行排序；

日志备份编号：当进行日志切割时，如果是以文件大小进行滚动，此时可以在日志文件名称末尾加上编号；

2.2 日志滚动

　　虽然日志中能够保存系统运行时的关键信息，但是由于磁盘空间有限，所以我们不能无限制地保留日志，因此必须有日志滚动策略。日志滚动通常有以下几种模式：

　　第一种：按照时间滚动

　　第二种：按照单个日志文件大小滚动

　　第三种：同时按照时间和单个日志文件大小滚动。

  • 按照时间滚动，即每隔一定的时间建立一个新的日志文件，通常可以按照小时级别滚动或者天级别滚动，具体采取哪种方式取决于系统日志的打印量。如果系统日志比较少，可以采取天级别滚动；而如果系统日常量比较大，则建议采取小时级别滚动。
  • 按照单个日志文件大小滚动，即每当日志文件达到一定大小则建立一个新的日志文件，通常建议单个日志文件大小不要超过500M，日志文件过大的话，对于日志监控或者问题定位排查都可能会造成一定影响。
  • 按照时间和单个日志文件大小滚动，这种模式通常适用于希望保留一定时间的日志，但是又不希望单个日志文件过大的场景。比如logback就提供了这种配置模式，可参考：https://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，以便跟踪每个请求后续所有的执行路径。

　　

参考文章：

https://zhuanlan.zhihu.com/p/27363484

https://blog.csdn.net/zollty/article/details/53958428

https://www.jianshu.com/p/59cd61eb93c2

https://www.jianshu.com/p/6149463aec94

http://blog.jobbole.com/56574/

https://www.cnblogs.com/kofxxf/p/3713472.html

https://gitbook.cn/books/5ae6883ce9a7f01a861df619/index.html

https://www.cnblogs.com/xybaby/p/7954610.html

http://blog.didispace.com/cxy-wsm-zml-4/

https://www.kancloud.cn/digest/javabug/138401

https://blog.csdn.net/bad_yu/article/details/81035862

原文地址：https://www.cnblogs.com/dolphin0520/p/10396894.html

时间： 2024-10-10 23:50:09

工程实践：如何规范地打印程序日志？的相关文章

Git工程开发实践（六）——Git工程实践扩展

Git工程开发实践(六)--Git工程实践扩展 一.Git提交日志规范 1.Git提交日志模板 Git支持对每次提交的日志信息进行规范,可以通过设置提交模板实现.建立一个gitCommitTemplate文件,内容为: #commit message包含三部分,header, body和footer,其中header必选,body和footer可选. # type(<scope>): <subject> #<body> #<footer> #type字段包含

GAEA Pollute v7.13 1CD（经过实践证明的污染物运动分析程序，被广泛用于垃圾填埋设计和环境补救领域）

GAEA产品: GAEA Winfence v2.30 1CD(创建详细,彩色地质截面图的工具) GAEA Winlog v4.50 1CD(创建钻井日志和测井曲线的工具) GAEA Winsieve v1.2 1CD(快速输入和打印结晶粒度分析曲线) ■□■□■□■□■□■□■□■□■□■□■□■□■□■□■□■□■□■□ +  诚信合作,保证质量!!!长期有效:                                                             + 电.话

结合工程实践选题调研分析同类软件

首先我的工程实践题目是“风扇调度”.主要内容是IO板卡温度监控与风扇调度,我曾经在网上搜索过相关论文和代码,但是很不幸,这只是一个很冷门的问题,并没有人关心.业内虽然有着一些解决方案,但是并没有成型的软件出现,都是内置于操作系统的.因此我只能选择几个相关的软件进行介绍,linux操作系统,DPTF(Dynamic Platform and Thermal Framework)和Kubernetes. 一.linux操作系统 类似于windows,linux也是一个操作系统,负责分配和调度系统资源

Vue3都要上的TypeScript之工程实践

0. 前言 怎么上... 咳咳,大家别想歪,这是一篇纯技♂术文章. 0.1 Why TypeScript 什么?尤大要把Vue 3.0全部改成用Typescript来写?这不是逗我吗,那我是不是要用TypeScript来写Vue应用了? 好吧,Vue3.0可能最快也要19年年末才出来,Vue3.0是会对Ts使用者更友好,而不是只能用ts了,尤大使用ts的原因也是因为ts的静态类型检测以及ts的表现比flow越来越好了.自从巨硬大步迈向开源,前端圈子多了很多新工具比如VS Code.TypeScr

c++ STL 工程实践的15条建议

STL是c++非常重要的一部分,它是很多大神的杰作,高效,稳定,可扩展性好,虽然STL确实存在难以调试,内存碎片的问题(现在机器的内存越来越大,内存碎片的问题基本不太可能成为系统瓶颈,但只要你使用恰当,它能显著提高生产力,并使代码更短,更易维护. 而在工程中,如果不养成好的使用习惯,也容易造成一些问题! 而自己在工程实践中,总结了一些建议 1.  vector, map, set, list, queue, dequeue, stack 等容器存放的对象必须是可拷贝的,尤其注意深拷贝的情况,必须

使用LogMaster4Net实现应用程序日志的集中管理

日志在软件系统中的重要性我在此也不赘述了,几乎所有程序员每天都会更日志打交道. 那么你是否曾今为这样的一些事情而困扰过: - 远程登录到不同的服务器,找到应用程序目然后查看应用日志: - 来回切换于不同服务器并使用tail来实时监控日志输出信息; - 解决在各个服务器上各个应用日积月累生成的大量日志文件造成的磁盘空间不足的问题: 如果在你的系统中存在着很多个不同的进程并且运行在多个服务器上,上面的问题将会显得尤为突出.很不幸是,笔者所在的公司的系统中,有数十个windows服务,控制台程序,计划

GNU开发工具——CMake工程实践

GNU开发工具--CMake工程实践 一.CMake构建Qt工程 1.Qt工程源码 创建Migration目录,在目录下创建main.cpp文件: #include <QApplication> #include <QLabel> int main(int argc, char *argv[]) { QApplication app(argc, argv); QLabel label(QString("Hello Qt%1!").arg(int(QT_VERSI

结合工程实践选题分析调研同类软件产品

我的工程实践题目是基于大数据问答训练的中文自然语言理解系统设计,因,学习知识工程的构建方法,研究学习WordNet.frameNet等常用语义网络,使用机器学习算法研究中文自然语言理解,构建一套特定知识库的智能语音应答系统.因此基于智能语音应答系统,我选择了3款同类软件的分析: 1.微软小冰小娜:都基于必应搜索和深度神经网络等技术,属于2C产品.微软小娜如今可以在iOS.Android.Window 10系统中使用,她更像一个秘书,可以打电话.发短信.发邮件以及查询上一场曼联的比分.但是微软小娜

结合工程实践选题调研分析相关技术背景

我的工程实践题目由于比较少见,因此市面上并没有大规模的软件出现.故我选择来仔细分析一下我的工程实践的技术背景. 我的工程实践的题目是基于量子密钥分发的云计算安全保障研究,这里有三个关键词,分别是量子密钥分发.云计算以及云计算安全保障,接下来我将就这三个关键词分别阐述其技术. 首先介绍的是量子密钥分发技术.量子密钥分发,顾名思义,就是利用量子力学的技术进行密钥分发的技术.那么什么又是密钥分发呢?在保密通信的过程中,如果通信双方采用的是对称加密方式,那么双方需要在通信前协商好加密密钥,而这个过程通常