在我们的项目里,需要实时采集web服务器产生的日志,进行分析。由于PV较高,且每个PV会产生多条日志,故系统整体吞吐量较大。由于第一手日志的读写都是由web服务器完成的,故本文主要关注PHP程序写日志,以及logagent进程实时读和网络推送日志,是否会对性能产生影响。

C函数与缓存

PHP内核是由C实现的,所以要理解其写日志的性能,首先需要了解相关的C函数。C函数与缓存的关系如下图,其中application memory和clib buffer都是在当前进程的用户内存空间,而page cache是内核内存空间,为多进程共享。

需要关注的几个Notes:

  • Note that fclose only flushes the user space buffers provided by the C library. To ensure that the data is physically  stored  on disk the kernel buffers must be flushed too, e.g. with sync(2) or fsync(2).
  • Note  that  fflush() only flushes the user space buffers provided by the C library.  To ensure that the data is physically stored on disk the kernel buffers must be flushed too, e.g. with sync(2) or fsync(2).
  • fsync  copies  all  in-core parts of a file to disk, and waits until the device reports that all parts are on stable storage.  It also updates metadata stat information. It does not necessarily ensure that the entry in the directory containing  the  file  has also reached disk.  For that an explicit fsync on the file descriptor of the directory is also needed.
  • In case the hard disk has write cache enabled, the data may not really be on permanent storage when fsync/fdatasync return.When an ext2 file system is mounted with the sync option, directory entries are also implicitly synced by fsync. On kernels before 2.4, fsync on big files can be inefficient.  An alternative might be to use the O_SYNC flag to open(2).
  • A successful return from write does not make any guarantee that data has been committed to disk.  In fact, on some  buggy  implementations(注:一种针对较大块内存分配算法),  it  does  not  even guarantee that space has successfully been reserved for the data(注:可能会被LRU掉).  The only way to be sure is to call fsync(2) after you are done writing all your data.
  • Opening a file with O_APPEND set causes each write on the file to be appended to the end. (注:对于单次写,有原子性保证)

 PHP对C函数调用

通过对PHP的fwrite源码和gdb跟入,确定针对普通本地文件的调用链如上图所示,即并未使用标准Lib库的IO函数,而是直接调用了系统函数open、write,每次调用都需要经历用户态与内核态的切换,有一定的资源消耗,而且也没用使用到C lib库的cache层。

同时,还需要注意的是,虽然系统write函数保证了原子性,但PHP对其进行了封装,根据stream的chunk_size拆分为多个write调用。故在buf字节数超过chunk_size的情况下,无法保证原子性。其中chunk_size在main/php_network.h中定义:#define PHP_SOCK_CHUNK_SIZE 8192。

再看下file_put_contents如下图,多次调用系统函数进行open、可选的flock、write、fflush和close操作。其中可能破坏原子性的地方有两处:

  • 若传入一维数组,会针对每一行调用php_stream_write方法
  • 每次php_stream_write方法,若待写入数据超过chunk_size,会分多次调用write()

另外,常用的error_log方法,在目标文件是普通本地文件时,也只是对php_stream_open_wrapper、php_stream_write、php_stream_close的封装。

写日志实现方式

基本思路见 封装php的Log类,考虑3种方式:

  • 每次直接调用file_put_contents
  • 每次直接调用fwrite
  • 每次先写入应用层缓存,触发条件或request结束时批量file_put_contents

完整实现代码已上传至:https://github.com/flykobe/php-log

性能测试

小块日志写入

3种调用方式,分别调用10w次,每行日志1024B,总体写入1GB数据。在mac本上,php 5.3.24,多次运行,平均测试结果:

_fwrite 2647.6ms

_write_with_buf 2659.9ms

_file_put_contents 10322.6ms

可以看到 耗时:_file_put_contents > _write_with_buf > _fwrite。

大块日志写入

3种调用方式,分别调用10w次,每行日志8192B,总体写入8GB数据。在mac本上,php 5.3.24,多次运行,平均测试结果:

_fwrite 4300

_write_with_buf 5575

_file_put_contents 11600

_fwrite和_write_with_buf的耗时上涨比例都较大。且两者差距拉大,主要由于此时_write_with_buf会加锁,以保证原子性。_file_put_contents反而变化比例不大。

优化_write_with_buf如下:

  • self::$_arrBuf[$strType][] = &$strMsg; // 将buf数组改为引用的方式,以避免PHP内核进行数据copy。没啥效果,甚至耗时还略微上涨
  • self::$_intBufMaxNum = $arrConfig[‘writebufmax’]; // 传入writebufmax = 100, 默认值是20行。略微有效果,下降200ms左右,但多次运行波动较大。增大该值,还会获得微小提升,但对于web系统而言,不太实用。

原子性测试

同时运行两个./atomic_test.php 100000 8196  脚本,分别写入8196个a或b。使用perl进行验证,a和b不能同时出现在一行里:

perl -ne ‘$ma = m#1234567\t.*a#; $mb = m#1234567\t.*b#; if ($ma && $mb){print;}’ log/20150317/notice.log | wc -l

发现有大量错行的情况!而如果将写入字符串大小改为1024、4096等,即使加上自动添加的日志信息,也远小于chunk_size,则没有错行情况。

使用_write_with_buf,写入大小为8196B的日志,没有错行!改为4096,同样没有错行。

使用_file_put_contents,写入大小为8196B的日志,也有错行!改为4096B,同样没有错行。

即,如果日志大小(包括填充的前后数据)超过chunk_size,则仅依赖PHP底层无法保证原子性!而_write_with_buf在应用层按需向file_put_contents传入LOCK_EX参数加锁,故保证了原子性。

持久化考虑

在默认情况下,系统调用write()仅是写入到内核的page cache,等待调度被刷到磁盘上。如果在此期间出现系统或硬件故障,可能会导致数据丢失。如果在单机情况下,要保证100%的可靠,则需要手工调用fsync(),或在open()时,设置O_DIRECT flag。但这两者,无疑都是较为耗时的,因为写入耗时里真正包含了到磁盘的时间。在log类里,一般不会达到这么高的要求,所以不予开启。

参考资料

http://www.ibm.com/developerworks/cn/linux/l-cn-directio/

http://www.dbabeta.com/2009/io-performence-02_cache-and-raid.html

http://php.net/manual/zh/function.stream-set-write-buffer.php

http://blog.chinaunix.net/uid-27105712-id-3270102.html

Leave a Reply