如何使错误日志更加方便排查问题

时间 2019-11-06

标签如何错误日志更加方便排查问题繁體版

原文原文链接

在程序中打错误日志的主要目标是为更好地排查问题和解决问题提供重要线索和指导。可是在实际中打的错误日志内容和格式变化多样，错误提示上可能残缺不全、没有相关背景、不明其义，使得排查解决问题成为很是不方便或者耗时的操做。而实际上，若是编程的时候稍加用心，就会减小排查问题的不少无用功。在阐述如何编写有效的错误日志以前，了解错误是怎么产生的，很是重要。

错误是如何炼成的

对于当前系统来讲，错误的产生由三个地方引入：

1. 上层系统引入的非法参数。对于非法参数引入的错误，能够经过参数校验和前置条件校验来截获错误；

2. 与下层系统交互产生的错误。与下层交互产生的错误，有两种：

a. 下层系统处理成功了，可是通讯出错了，这样会致使子系统之间的数据不一致；

对于这种状况，能够采用超时补偿机制，预先将任务记录下来，经过定时任务在后续将数据订正过来。

更好的设计方案？

b. 通讯成功了，可是下层处理出错了。

对于这种状况，须要与下层开发人员沟通，协调子系统之间的交互；

须要根据下层返回的错误码和错误描述作适当的处理或给予合理的提示信息。

不管哪种状况，都要假设下层系统可靠性通常，作好出错的设计考虑。

3. 本层系统处理出错。

本层系统产生错误的缘由：

缘由一：疏忽致使。疏忽是指程序员能力彻底可避免此类错误但实际上没作到。好比将 && 敲成了 & ， == 敲成了 = ；边界错误，复合逻辑判断错误等。疏忽要么是程序员注意力不够集中，好比处于疲倦状态、加班通宵、边开会边写程序；要么是急着实现功能，没有顾及程序的健壮性等。

改进措施：使用代码静态分析工具，经过单元测试行覆盖可有效避免此类问题。

缘由二：错误与异常处理不够周全致使的。 好比输入问题。计算两个数相加，不只要考虑计算溢出问题，还要考虑输入非法的情形。对于前者，可能经过了解、犯错或经验就能够避免，而对于后者，则必须加以限定，以使之处于咱们的智商可以控制的范围内，好比使用正则表达式过滤掉不合法的输入。对于正则表达式必须进行测试。对于不合法输入，要给出尽量详细、易懂、友好的提示信息、缘由及建议方案。

改进措施：尽量周全地考虑各类错误情形和异常处理。在实现主流程以后，增长一个步骤：仔细推敲可能的各类错误和异常，返回合理错误码和错误描述。每一个接口或模块都有效处理好本身的错误和异常，可有效避免因场景交互复杂致使的bug. 譬如，一个业务用例由场景A.B.C交互完成。实际执行A.B成功了，C失败了，这时B须要根据C返回合理的代码和消息进行回滚并返回给A合理的代码和消息，A根据B的返回进行回滚，并返回给客户端合理的代码和消息。这是一种分段回滚的机制，要求每一个场景都必须考虑异常状况下的回滚。

缘由三：逻辑耦合紧密致使。 因为业务逻辑耦合紧密，随着软件产品一步步发展，各类逻辑关系错综复杂，难以看到全局情况，致使局部修改影响波及到全局范围，形成不可预知的问题。

改进措施：编写短函数和短方法，每一个函数或方法最好不超过 50 行。编写无状态函数和方法，只读全局状态，相同的前提条件老是会输出相同的结果，不会依赖外部状态而变动本身的行为；定义合理的结构、接口和逻辑段，使接口之间的交互尽量正交、低耦合；对于服务层，尽量提供简单、正交的接口；持续重构，保持应用模块化和松耦合，理清逻辑依赖关系。对于有大量业务接口相互影响的状况，必须整理各个业务接口的逻辑流程及相互依赖关系，从总体上进行优化；对于有大量状态的实体，也须要梳理相关的业务接口，整理状态之间的转换关系。

缘由四：算法不正确致使。

改进措施：首先将算法从应用中分离出来。若算法有多种实现，能够经过交叉校验的单元测试找出来，好比排序操做；若是算法具备可逆性质，能够经过可逆校验的单元测试找出来，好比加密解密操做。

缘由五：相同类型的参数，传入顺序错误致使。好比，modifyFlow(int rx, int tx), 实际调用为 modifyFlow(tx,rx)

改进措施：尽量使类型具体化，该用浮点数就用浮点数，该用字符串就用字符串，该用具体对象类型就用具体对象类型；相同类型的参数尽量错开；若是上述都没法知足，就必须经过接口测试来验证，接口参数值务必是不一样的。

缘由六：空指针异常。 空指针异常一般是对象没有正确初始化，或者使用对象以前没有对对象是否非空作检测。

改进措施：对于配置对象，检测其是否成功初始化；对于普通对象，获取到实体对象使用以前，检测是否非空。

缘由七：网络通讯错误。 网络通讯错误一般是由于网络延迟、阻塞或不通致使的错误。网络通讯错误一般是小几率事件，但小几率事件极可能会致使大面积的故障、难以复现的BUG。

改进措施：在前一个子系统的结束点和后一个子系统的入口点分别打 INFO 日志。经过二者的时间差提供一点线索。

缘由八：事务与并发错误。 事务与并发结合在一块儿，很容易产生很是难以定位的错误。

改进措施：对于程序中的并发操做，涉及到共享变量及重要状态修改的，要加 INFO 日志。更有效的作法？？？

缘由九：配置错误。

改进措施：在启动应用或启动相应配置时，检测全部的配置项，打印相应的INFO日志，确保全部配置都加载成功。

缘由十：业务不熟悉致使的错误。 在中大型系统，部分业务逻辑和业务交互都比较复杂，整个的业务逻辑可能存在于多个开发同窗的大脑里，每一个人的认识都不是完整的。这很容易致使业务编码错误。

改进措施：经过多人讨论和沟通，设计正确的业务用例，根据业务用例来编写和实现业务逻辑；最终的业务逻辑和业务用例必须完整存档；在业务接口中注明该业务的前置条件、处理逻辑、后置校验和注意事项；当业务变化时，须要同步更新业务注释；代码REVIEW。业务注释是业务接口的重要文档，对业务理解起着重要的缓存做用。

缘由十一：设计问题致使的错误。好比同步串行方式会有性能、响应慢的问题，而并发异步方式能够解决性能、响应慢的问题，但会带来安全、正确性的隐患。异步方式会致使编程模型的改变，新增异步消息推送和接收等新的问题。使用缓存可以提升性能，可是又会存在缓存更新的问题。

改进措施：编写和仔细评审设计文档。设计文档必须阐述背景、需求、所知足的业务目标、要达到的业务性能指标、可能的影响、设计整体思路、详细方案、预见该方案的优缺点及可能的影响；经过测试和验收，确保改设计方案确实知足业务目标和业务性能指标。

缘由十二：未知细节问题致使的错误。 好比缓冲区溢出、 SQL 注入攻击。从功能上看是没有问题的，可是从恶意使用上看，是存在漏洞的。再好比，选择 jackson 库作 JSON 字符串解析，默认状况下，当对象新增字段时会致使解析出错。必须在对象上加 @JsonIgnoreProperties(ignoreUnknown = true) 注解才能正确应对变化。若是选用其余 JSON 库就不必定有这个问题。

改进措施：一方面要经过经验积累，另外一方面，考虑安全问题和例外状况，选择成熟的通过严格测试的库。

缘由十三：随时间变化而出现的bug。有些解决方案在过去看来是很不错的，但在当前或者将来的情景中可能变得笨拙甚至不中用，也是常见的事情。好比像加密解密算法，在过去可能认为是完善的，在破解以后就要慎重使用了。

改进措施：关注变化以及漏洞修复消息，及时修正过期的代码、库、行为。

缘由十四：硬件相关的错误。 好比内存泄露，存储空间不足， OutOfMemoryError 等。

改进措施：增长对应用系统的 CPU / 内存 / 网络等重要指标的性能监控。

系统出现的常见错误：

1. 实体在数据库中的记录不存在，必须指明是哪一个实体或实体标识；

2. 实体配置不正确，必须指明是哪一个配置有问题，正确的配置应该是什么；

3. 实体资源不知足条件，必须指明当前资源是什么，资源要求是什么；

4. 实体操做前置条件不知足，必须指明须要知足什么前置条件，当前的状态是什么；

5. 实体操做后置校验不知足，必须指明须要知足什么后置校验，当前的状态是什么；

6. 性能问题致使超时，必须指明是什么致使的性能问题，后续如何优化；

7. 多个子系统交互通讯出错致使之间的状态或数据不一致？

通常难以定位的错误会出如今比较底层的地方。由于底层没法预知具体的业务场景，给出的错误消息都是比较通用的。

这就要求在业务上层提供尽量丰富的线索。错误的产生必定是多个系统或层次交互的过程当中在某一层栈上不知足前置条件致使。在编程时，在每一层栈中尽量确保全部必须的前置条件知足，尽量避免错误的参数传递到底层，尽量地将错误截获在业务层。

大多数错误都是由多种缘由组合产生。但每一种错误一定有其缘由。在解决错误以后，要深刻分析错误是如何发生的，如何避免这些错误再次发生。努力就能成功，可是： 反思才能进步！

如何编写更容易排查问题的错误日志

打错误日志的基本原则：

1. 尽量完整。每一条错误日志都完整描述了：什么场景下发生了什么错误，什么缘由（或者哪些可能缘由），如何解决（或解决提示）；

2. 尽量具体。好比 NC 资源不足，究竟具体指什么资源不足，是否能够经过程序直接指明；通用错误，好比 VM NOT EXIST ，要指明在什么场景下发生的，可能便于后续统计的工做。

3. 尽量直接。最理想的错误日志应该让人在第一直觉下可以知道是什么缘由致使，该怎么去解决，而不是还要经过若干步骤去查找真正的缘由。

4. 将已有经验集成直接到系统中。全部已经解决过的问题及经验都要尽量以友好的方式集成到系统中，给新进人员更好的提示，而不是埋藏在其余地方。

5. 排版要整洁有序，格式统一化规范化。密密麻麻、随笔式的日志看着就揪心，至关不友好，也不便于排查问题。

6. 采用多个关键字惟一标识请求，突出显示关键字：时间、实体标识（好比vmname）、操做名称。

排查问题的基本步骤：

登陆到应用服务器 -> 打开日志文件 -> 定位到错误日志位置 -> 根据错误日志的线索的指导去排查、确认问题和解决问题。

其中：

1. 从登录到打开日志文件：因为应用服务器有多台，要逐一登陆上去查看实在不方便。须要编写一个工具放在 AG 上直接在 AG 上查看全部服务器日志，甚至直接筛选出所须要的错误日志。

2. 定位错误日志位置。目前日志的排版密密麻麻，不易定位到错误日志。通常能够先采用"时间"来定位到错误日志的附近前面的地方，而后使用实体关键字 / 操做名称组合来锁定错误日志地方。根据 requestId 定位错误日志虽然比较符合传统，可是要先找到 requestId , 而且不具备描述性。最好能直接根据时间/内容关键字来定位错误日志位置。

3. 分析错误日志。错误日志的内容最好可以更加直接明了，可以明确指明与当前要排查的问题特征是吻合的，而且给出重要线索。

一般，程序错误日志的问题就是日志内容是针对当前代码情境才能理解，看上去简洁，但老是写的不全，半英文格式；一旦离开代码情境，就很难知道究竟说的是什么，非要让人思考一下或者去看看代码才能明白日志说的是什么含义。这不是本身给本身罪受？

好比：

if ((storageType == StorageType.dfs1 || storageType == StorageType.dfs2) && (zone.hasStorageType(StorageType.io3) || zone.hasStorageType(StorageType.io4))) { // 进入dfs1 和dfs2 在io3 io4 存储。
} else { log.info("zone storage type not support, zone: " + zone.getZoneId() + ", storageType: "
+ storageType.name()); throw new BizException(DeviceErrorCode.ZONE_STORAGE_TYPE_NOT_SUPPORT); }

zone 要支持什么 storage type 才是正确的? Do Not Let Me Think !

错误日志应该作到：即便离开代码情境，也能清晰地描述发生了什么。

此外，若是可以直接在错误日志中说明清楚缘由，在作巡检日志的时候也能够省些力气。

从某种意义上来讲，错误日志也能够是一种很是有益的文档，记录着各类不合法的运行用例。

目前程序错误日志的内容可能存在以下问题：

1. 错误日志没有指明错误参数和内容：

catch(Exception ex){ log.error("control ip insert failed", ex); return new ResultSet<AddControlIpResponse>( ControlIpErrorCode.ERROR_CONTROL_IP_INSERT_FAILURE); }

没有指明插入失败的 control ip. 若是加上 control ip 关键字，更容易搜索和锁定错误。程序员

相似的还有：

log.error("Get some errors when insert subnet and its IPs into database. Add subnet or IP failure.", e);

没有指明是哪一个 subnet 的它下属的哪些 IP. 值得注意的是，要指明这些要额外作一些事情，可能会稍微影响性能。这时候须要权衡性能和可调试性。

解决方案：使用 String.format("Some msg to ErrorObj: %s", errobj) 方法指明错误参数及内容。

这一般要求对 DO 对象编写可读的 toString 方法。

2. 错误场景不明确：

log.error("nc has exist, nc ip" + request.getIp());

在 createNc 中检测到 NC 已经存在报错。可是日志上没有指明错误场景，让人猜想，为何会报NC已存在错误。

能够改成

log.error("nc has exist when want to create nc, please check nc parameters. Given nc ip: " + request.getIp());

log.error("[create nc] nc has exist, please check nc parameters. Given nc ip: " + request.getIp());

相似的还有：

log.error("not all vm destroyed, nc id " + request.getNcId());

改为 log.error("[delete nc] some vms [%s] in the nc are not destroyed. nc id: %s", vmNames, request.getNcId());

解决方案：错误消息加上 when 字句，或者错误消息前加上【接口名】, 指明错误场景，直接从错误日志就知道明白了。

通常可以知道 executor 的能够加上【接口名】， service 加上 when 字句。

3. 内容不明确, 或不明其义：

if(aliMonitorReporter == null) { log.error("aliMonitorReporter is null!"); } else { aliMonitorReporter.attach(new ThreadPoolMonitor(namePrefix, asynTaskThreadPool.getThreadPoolExecutor())); }

改成：log.error("aliMonitorReporter is null, probably not initialized properly, please check configuration in file xxx.");正则表达式

相似的还有：

if (diskWbps == null && diskRbps == null && diskWiops == null    && diskRiops == null) { log.error("none of attribute is specified for modifying"); throw new BizException(DeviceErrorCode.NO_ATTRIBUTE_FOR_MODIFY); }

改成 log.error("[modify disk attribute] None of [diskWbps,diskRbps,diskWiops,diskRiops] is specified for disk id:" + diskId);

解决方案：更清晰贴切地描述错误内容。

4. 排查问题的引导内容不明确：

log.error("get gw group ip segment failed. zkPath: " + LockResource.getGwGroupIpSegmnetLockPath(request.getGwGroupId()));

zkPath ? 如何去排查这个问题？我该去找谁？到哪里去查找更具体的线索？

解决方案：加上相应的背景知识和引导排查措施。

5. 错误内容不够具体细致：

if (!ncResourceService.isNcResourceEnough(ncResourceDO, vmResourceCondition)) { log.error("disk space is not enough at vm's nc, nc id:" + vmDO.getNcId()); throw new BizException(ResourceErrorCode.ERROR_RESOURCE_NOT_ENOUGH); }

到底是什么资源不够？目前剩余多少？如今须要多少？值得注意的是，要指明这些要额外作一些事情，可能会稍微影响性能。这时候须要权衡性能和可调试性。算法

解决方案：经过改进程序或程序技巧，尽量揭示出具体的差别所在，减小人工比对的操做。

6. 半英文句式读起来不够清晰明白，须要思考来拼凑起完整的意思：

log.warn("cache status conflict, device id "+deviceDO.getId()+" db status "+deviceDO.getStatus() +", nc status "+ status);

改成:

log.warn(String.format("[query cache status] device cache status conflicts between regiondb and nc, status of device '%s' in regiondb is %s , but is %s in nc.", deviceDO.getId(), deviceDO.getStatus(), status));

解决方案：改成天然可读的英文句式。

总结起来，错误日志格式能够为：

log.error("[接口名或操做名] [Some Error Msg] happens. [params] [Probably Because]. [Probably need to do].");

log.error(String.format("[接口名或操做名] [Some Error Msg] happens. [%s]. [Probably Because]. [Probably need to do].", params));

或

log.error("[Some Error Msg] happens to 错误参数或内容 when [in some condition]. [Probably Because]. [Probably need to do].");

log.error(String.format("[Some Error Msg] happens to %s when [in some condition]. [Probably Because]. [Probably need to do].", parameters));

[Probably Reason]. [Probably need to do]. 在某些状况下能够省略；在一些重要接口和场景下最好能说明一下。

每一条错误日志都是独立的，尽量完整、具体、直接说明何种场景下发生了什么错误，由什么缘由致使，要采用什么措施或步骤。

问题：

1. String.format 的性能会影响打日志吗？通常来讲，错误日志应该是比较少的，使用 String.format 的频度并不会过高，不会对应用和日志形成影响。

2. 开发时间很是紧张时，有时间去斟酌字句吗？创建一个标准化的内容格式，将内容往格式套，能够节省斟酌字句的时间。

3. 何时使用 info, warn , error ?

info 用于打印程序应该出现的正常状态信息，便于追踪定位；

warn 代表系统出现轻微的不合理但不影响运行和使用；

error 代表出现了系统错误和异常，没法正常完成目标操做。

http://stackoverflow.com/questions/2031163/when-to-use-log-level-warn-vs-error

错误日志是排查问题的重要手段之一。当咱们编程实现一项功能时，一般会考虑可能发生的各类错误及相应缘由：

要排查出相应的缘由，就须要一些关键描述来定位缘由。这就会造成三元组：

错误现象 -> 错误关键描述 -> 最终的错误缘由。

须要针对每一种错误尽量提供相应的错误关键描述，从而定位到相应的错误缘由。

也就是说，编程的时候，要仔细思考，哪些描述是很是有利于定位错误缘由的，尽量将这些描述添加到错误日志中。

文中没有指出的问题或困难，请提出你的建议。