写日志

为什么记日志

日志记录是否完备，直接影响到软件产品维护和问题定位的难易程度。这主要源自以下几个因素：

第一、开发人员自己的环境无法覆盖100%的应用场景，某项功能在开发者的机器上一切正常，但是到了测试人员或用户的机器上就不能满足预期。

第二、当在用户现场出现问题时，往往无法再单步调试。如果要到用户现场架设一套开发环境成本太高。

第三、有些问题存在一定概率，并不能100%复现。而日志可以记录系统运行的行为，帮助分析问题。

因此，记录有效的日志对于一款成熟的软件产品而言不可或缺。一个优秀的软件设计师可以通过日志来分析定位问题，而一个普通的开发人员往往要依赖IDE的单步调试功能。

当然，每一个开发人员的学习过程几乎都是从单独调试开始的，它能让程序“慢”下来，让你清楚程序每一步的行为，能方便的查看系统中每一个状态。这当然是一种最方便直接的方法，也让开发人员对此产生了很大的依赖。但是在真实应用场景中，当程序的行为不符合预期时，我们无法通过这种方法去分析问题。日志就成为了一个有效的辅助手段。

另外单步调试在某些多线程的系统中往往会带来另外一些问题。你也许碰到过程序在单步调试时的运行结果和正常运行结果不一致，令人一头雾水。这主要时因为单步调试的引入破坏了系统的正常运行流程。断点只是让一个线程停了下来，而系统中的其它线程还照样在正常运行，此时的被测系统已经不是“正常状态”下的那个系统了。

再补充一点，在系统异常的大部分情况下，我不太赞成使用断言（assert）。因为断言会让系统停止运行，用户点击“确定”后还得重新运行系统，这样的体验很糟糕。而我们的软件需要在大部分异常场景进行容错或者自愈，以便系统能够继续运行，完成用户的预期要求。实际上日志和断言是异常处理的两个有效手段，它们各有所用，断言主要用在“不可能”出错的地方，这将在“代码看护”一节中进行讨论。

日志框架

物理学的测量体系中有一个基本原则：测量方法的引入不能对被测系统造成影响。比如我们可以用一根竹竿去测量一个游泳池中水的深度：把竹竿垂直插入水中并触及池底，然后再取出竹竿量一下其被水浸湿部分的长度。但是我们却不能用竹竿去测量一个玻璃杯中的水的深度。当竹竿插入玻璃杯时，竹竿本身对玻璃杯里的水会造成很大影响，会导致水面明显上升。而竹竿对游泳池中的水影响就可以忽略。

在软件系统中记录日志时，同样需要遵循此原则。本章中列举的日志框架会在每一次调用日志接口时将日志信息保存到硬盘上的一个日志文件中。在写文件时会有一次磁盘I/O，这个方法对于大多数应用场景不会造成太大影响。但如果你的系统对实时性要求很高，或者工作在系统内核层，那么就要充分评估这类磁盘I/O对系统带来的影响。也许需要考虑其它方法，比如只是将日志信息保存在内存块中，而不是将其写入磁盘文件。当然，如果你的系统中已经有了自己的日志框架，那么请忽略以下内容。

该框架是基于C++开发的，只有两个文件：Log.cpp和Log.h，可以在附件中进行下载（LodDemeo.rar提供了一个vs2008的demo工程），然后加入到你的工程中。其提供了两个日志接口logstr和logmem，前者用于记录一个字符串信息，用法和C语言的printf类似，可以支持若干个参数；后者则用于将一段内存信息打印为二进制码流的形式。

由于使用了C/C++宏__FILE__和__LINE__，在输出日志时可以同时打印出该行代码所在的文件名和行号，这样对于分析问题会带来很大的方便。比如OpSystem.cpp的第355行有一行写日志的代码：

logstr(“MyData = %d”, GetMyData() );

对应的日志文件中内容将是这样（在日志txt文件中）：

FILE:.\OpSystem.cpp

LINE:355

MyData = 1

很直观的把日志和对应的代码关联起来，方便问题定位。

对于JAVA开发者，JAVA框架也提供了相应的日志功能。比如Andriod系统中的android.util.Log包就提供了这类日志接口，你只需要定义好系统的标签，方便日志过滤：

Log.e(“MySystem”, logContent);

如何记日志

日志不能太多也不能太少。这听起来像是一句废话，但的确如此L。

日志太多的话会导致很多无效的信息，影响有效信息的获取。比如在一个执行频率很高的地方输出日志，有时甚至会很快把日志文件写满；日志太少的话缺乏足够的定位信息导致问题无法准确定位。

在所有要求对“度”进行把握的地方，往往总是要更多的依赖经验。你也许会常碰到类似的问题：在分析日志的过程中需要知道某个变的值，却发现日志中没有对该变量进行记录，令人沮丧。这种时候往往只能再添加日志，重新出新的临时版本到用户现场再次运行并进行定位。

如果你平时主要是依赖断点调试程序，当断点走到某处代码时，你可以很容易的就查看其中的变量，很容易的知道程序执行的轨迹。因此往往忽略了对关键信息进行日志记录的重要性。针对这种情况，你需要常常提醒自己：如果程序在这里运行失败了，我需要哪些信息才能足以分析失败的原因？然后把相应的信息记录到日志中。当然要做好这一点还是取决于你的经验，但只要你在日常编码时养成这样的习惯，情况就会向好的方向发展。

另一个办法来自日常的工作方式。当测试人员向你提交问题时，不要先急于在自己的环境上复现并定位问题。而是先尝试在测试人员的环境上通过日志进行定位。如果发现这样无法定位问题时，你就能知道是哪些日志信息不足，然后进行相应的补充。

除此之外，平时写代码时还有需要注意以下几点：

l  在错误分支增加日志

当用户点击一个按钮开始执行某个流程时，如果程序能正确的执行完成，并输出预期的结果，那么一切表现良好。但是如果程序出错并给用户弹出一个执行失败的窗口时，问题就随之而来了。在哪里失败？为何失败？如何修复？……当你打开代码开始查看时，会发现异常分支有很多个，如果没有日志的话，很难判断是哪一个分支出的问题。

一个函数的执行过程很长，当函数返回失败时，如果不能知道具体是哪一个分支失败，那么后续的问题分析就无法再继续了。因此如果能在每一个错误分支都增加日志，那当函数执行失败时，日志能够准确的告诉你失败在哪。

l  在程序运行的关键节点增加日志

程序80%的问题出在接口上，因此在模块的入口和出口和处增加日志，并记录足够的信息，这样能记录整个程序的执行流程，方便问题定位。