php error_log函数使用性能区别

php自带error_log函数可以方便开发者将自定义的报错信息通过Mail、PHP error log或者指定文件的形式输出。
这个函数是挺方便的,省去了开发者自己使用fopen fwrite来输出log,而且还是C的,我一直好奇这个函数的实现会不会是每次使用都在打开文件,关闭文件来操作…
对C不是很了解,查php源代码,error_log函数在缺省投放到php.ini设置的error_log中去,3是调用_php_error_log函数完成自定义输出文件。

0是缺省输出到error_log中的代码,似乎是使用缓存不会每次操作都要重复打开资源…由于对C一知半解..而且这部分也挺复杂的,所以没搞明白。
3是输出到指定文件,这里调用_php_error_log函数完成的,可以看到是直接的open write close

今天为多进程采集写了一个任务调度的程序,然后写了一个测试代码,取得任务之后用error_log写下进程号、任务ID就继续取下一个任务。

开了10个进程进行测试,每次100000条任务,实际上打出来的error_log总是不到100000,大概差10-30条。我尝试着在每两个任务之间sleep几毫秒,丢失的任务记录会少一些,但是也会丢失10几条。

进程调度程序本身怎么找都找不到问题,最后我把怀疑的目光投向了error_log这个函数。这次我不用调度程序,10个进程,每个都直接error_log输出1-10000,结果一看,同样会丢失20条左右的记录。

我自己写了一段写log的代码,再次通过进程调度,这次就一条也不少了。

实践证明:error_log()这个函数在高并发同时写入一个文件时会丢失部分内容。

然后我又写了一个测试脚本,测试10000次写入的速度:

error_log:

7.39、6.97、7.28、8.99、7.02、7.30、7.26、7.39、7.35(平均耗时:7.44秒)

fwrite(不锁定):

8.19、8.15、7.36、7.49、9.96、7.27、7.51、6.93、7.29(平均耗时:7.79秒)

fwrite(锁定):

7.88、7.91、8.44、8.99、8.44、8.56、7.84、7.93、7.93(平均耗时:8.21秒)

通过测试数据可以看出三种方法的速度相差不大,error_log最快,fopen之后锁定写入最慢。大部分情况下error_log都能够满足要求,只有当写入特别频繁而且数据可靠性要求比较高的情况下才需要用第三种方法。

另又测试,测试代码是输出一万次日志信息,分别通过error_log缺省输出到error log中,通过error_log 3模式输出到指定文件,通过将1万次日志信息分100次打开文件写入的速度对比,代码如下
01    <!--
02    1 <?php
03    2
04    3 function microtime_float()
05    4 {
06    5    list($usec, $sec) = explode(" ", microtime());
07    6    return ((float)$usec + (float)$sec);
08    7 }
09    8 $i=0;
10    9 $error = array();
11    10 $flag=0;
12    11 $time_start = microtime_float();
13    12 while($i<10000)
14    13 {
15    14 /*      if($flag<100)//这部分注释是测试php收集一批数据一次打开写入
16    15         {
17    16                 $error[] = "hi,let test speed\r\n";
18    17                 $flag++;
19    18         }
20    19         else
21    20         {
22    21                 $h = fopen("error2.log","a+");
23    22                 foreach($error as $k=>$v)
24    23                 {
25    24                         fwrite($h,$v);
26    25                 }
27    26                 fclose($h);
28    27                 $error = array();
29    28         }*/
30    29         error_log("hi,let test speed",0);//使用error_log函数缺省
31    30         //error_log("hi,let test speed", 3, "errors.log");//指定输出文件
32    31         $i++;
33    32 }
34    33 $time_end = microtime_float();
35    34 $time = $time_end - $time_start;
36    35 echo $time;
37    36
38    37 ?> -->

结果
php分100次打开文件写入
0.082275867462158
php_error_log 3模式
0.11562013626099
error_log 0模式
0.095598936080933

根据测试结果,一目了然,这件事说明,如果php的error log增长很快,不管里面是notice还是fata error至少从性能上是肯定要有影响的,在一个请求运行下来,如果要投放的log很多的话,使用error_log 3的模式不划算,不如将log积累,一起投放….

有话要说