为何要做日志

对于程序员来说,做日志的习惯是必不可少的。当线上服务有问题的时候,却发现没有日志,那真是不应该。做日志就能解决这些问题,写好日志有助于线上系统发现和解决问题,有助于日后分析问题提供依据,有主意开发时调试和跟踪问题。简而言之,做日志的目的就是“方便找问题”。 几乎每一个有良好技术系统都会有很好的日志,最常见的就是Http的的access log,Nginx和Apache的日志就是很标准的一种。
202.17.8.20 - - [01/May/2012:02:23:22 -0400] "GET /phpMyAdmin/index.php HTTP/1.1" 404 480 "-" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/535.1 (KHTML, like Gecko) Chrome/13.0.782.220 Safari/535.1"
我们可以在Apache配置中找到日志的格式配置
LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" combined

我们今天的主题不是Access Log,所以这里就不再说明,有兴趣的可以去翻阅Apache手册,下面进入正文。

为什么要做日志

收集运行记录和调试信息

很多情况下,在开发应用的时候会有很多逻辑需要分析调试,以保证程序运转逻辑是符合需求和规则。有些老手会去做单元测试,也有很多人通过直接打印的方式输出信息来获得信息。但是去分析一个系统运行信息和调试过程的时候,不管是单元测试或者是跟踪调试都满足不了需求,所以这时候需要去把日志记下来,然后通过tail -f去监控日志的输出,这样程序运行记录一目了然。这是最常见的记录应用程序启动的日志,通过日志很方便看到应用程序的执行过程。
[2012-05-01 22:30:31 111] [4fa935dabaaa2] [info] Initialize ok.
[2012-05-01 22:30:31 342] [4fa935dabaaa2] [info] Application is running.

收集应用警告、错误和崩溃信息

即使再完美的系统也有bug,当应用运行在线上的时候,不能保证每一个应用可以完美的常年正常的运转下去,在运行的过程中,肯定会遇到很多问题,这些问题可能是因为环境、网络、安全漏洞等造成的,但是你在开发情况下无法碰到的。所以这时候我们需要将错误的信息记录下来,通过分析日志,定位到问题并fix掉它们。
[2012-05-01 22:30:32 011] [4fa935dabaaa2] [error] Connect mysql faild. (PDO CONNECT TIMEOUT).
[2012-05-01 22:30:32 082] [4fa935dabaaa2] [error] Catch PDOException on /Library/DB.PHP (111).

收集分析应用性能

对于大型网站应用来说,慢一秒就意味着会损失几个百分点的用户,所以解决性能问题会为网站挽回巨大的利益。如何去优化性能呢?这时候就要靠你的网站慢日志了,尤其是细分的慢日志,比如你应用里面有一套步骤才能完成一个页面的输出,它们是基础框架、连接缓存、连接数据库、模版渲染,在应用中对每个步骤进行耗时记录,最后记录到日志里面,在以后分析的时候会发现他们非常有用。
[2012-05-01 22:30:34 081] [4fa935dabaaa2] [warn] Rpc call is slow (1.85 seconds)
[2012-05-01 22:30:35 124] [4fa935dabaaa2] [warn] App is slow (3.85 seconds).

日志等级

调试

一般用于输出调试信息,一般在Debug模式下启用,举例:
  • 记录一段逻辑的输出
  • 调试不同的适配器(Adapter)
  • 记录Request Pramas
  • 记录一段程序的返回结果数和时间
  • 运行轨迹

信息

用于输出运行信息,举例:
  • 开始或结束一个动作
  • 发送给某人邮件或者调用远程服务的参数
  • 请求方的信息,如IP,参数,HTTP头等
  • 查询一条数据库记录

警告

可能会引起错误的问题。举例:
  • 数据没有成功接收,但依然可以执行
  • 不期待的信息传入
  • 远程调用成功但执行时间较长
  • 非致命异常

错误

造成了某些错误。举例:
  • 请求无法完成或者无法恢复
  • 请求未完成,数据丢失
  • 数据保存失败
  • 接收了不明信息
  • 远程调用超时并且无返回
  • 被捕获的异常
  • 有安全问题

灾难

造成了应用的中断。举例:
  • 应用程序未处理完成并中断
  • 数据库无法访问

记录什么

时间

必要信息,用于记录问题所发生的时间或者时长

错误信息和轨迹

必要信息,用于描述错误和记录造成错误的参数或者文件等

会话ID

必要信息,用于记录信息属于哪个会话。 通常在多个系统调用的时候也可以将会话ID通过某种方式传递给其它依赖系统,在多系统间出现问题的时候就很容易定位。

等级标记

必要信息,用于区分错误的等级,有助于分析日志的过滤,有助于根据等级来做某种通知(比如灾难等级的时候,必须发送邮件通知给负责人)。

版本号

非必要,用于区分程序运行的版本

PHP日志

捕获异常和错误

一般常见的异常和错误捕获后记录下来。
try {
    $user = $service->findById( $id );
} catch (SpecificServiceException $e) {
    $this->getLogger()->logError( $e->getMessage() );
}

统一控制异常和错误

一般的框架会提供自动捕捉框架和handle错误的机制,通过这种机制你只需要配置收集日志即可。这时候就要这么写了。

$app = new App();
set_error_handler(function($no, $message, $file, $line) {
	throw new \ErrorException($message, $no, 0, $file, $line);
}, E_ERROR | E_USER_ERROR);

set_exception_handler(function($exception) use($app) {
	$message = sprintf("Error %s on %s (%d)", $exception->getMessage(), $exception->getFile(), $exception->getLine());
	$app->getLogger()->logError($message);
});
$app->run(include('config.php'));
$app->shutdown();

应用异常中断

当应用中断(强制退出)的时候,可能是由某些错误造成的,这时候你无法在正常的逻辑去捕获到,就要用下面这种方法了。
$app = new App();
register_shutdown_function(function() use($app) {
	if (($error = error_get_last()) && ($error['type'] === E_ERROR || $error['type'] === E_USER_ERROR)) {
	{
		$message = sprintf("Critical error %s on %s (%d)", $error['message'], $error['file'], $error['line']);
		$app->getLogger()->logEmerg($message);
		$app->getMailer->send('admin@zhaogege.com', "[Important!!!] Critical error", $message)
	}
});
$app->run(include('config.php'));
$app->shutdown();

关于日志的开源项目

Facebook Scribe Facebook出品的分布式日志收集服务,采用C++编写,性能很不错,对付各种日志足以,但目前在某些方面还不完善。 Logstash 可以用来统一对应用程序日志进行收集管理,提供 Web 接口用于查询和统计。 Fluent 很强大的日志系统,特点在于其各部分均是可定制化的,你可以通过简单的配置,将日志收集到不同的地方。 Flume Apache出品的一个分布式、可靠以及高可用的日志系统,用于大量日志数据在不同中心化数据存储中心之间的高效的收集、聚合以及移动。 Log4j Apache出品的Java日志操作库,也有PHP版本log4php

写在后面

做日志非常简单,简单的都会让很多人懒得去做,但建议大家千万别这么做,好的日志习惯会无形中带来很多的好处,这一点有经验的人都会明白,做日志应该做为每个程序员日常开发的习惯。 最后,欢迎各位拍砖。

Comments