探讨php中error_log函数输出内容的原子性问题

探讨php中error_log函数输出内容的原子性问题

前几天跟同事讨论如何在一次login php调用中保证error_log输出的日志都有唯一的标识头，结论是玩家帐号+当前时间+随机数，在我们当前用户量级条件下应该是满足需求的，当然，这并不是本文讨论的重点。

在确定这个简单的方案之后，我在想两个问题，也是今天本文讨论的重点：

1.error_log调用是否可以保证输出内容是完整的？

2.如果是完整的，那么是怎样保证的？

求证开始了，起初以为error_log调用中会对目标文件加文件锁，直接看源码（php5.6.12）：

from: basic_functions.c

 

PHPAPI int _php_error_log_ex(int opt_err, char *message, int message_len, char *opt, char *headers TSRMLS_DC) /* {{{ */
{
	php_stream *stream = NULL;

	switch (opt_err)
	{
		case 1:		/*send an email */
			if (!php_mail(opt, PHP error_log message, message, headers, NULL TSRMLS_CC)) {
				return FAILURE;
			}
			break;

		case 2:		/*send to an address */
			php_error_docref(NULL TSRMLS_CC, E_WARNING, TCP/IP option not available!);
			return FAILURE;
			break;

		case 3:		/*save to a file */
			stream = php_stream_open_wrapper(opt, a, IGNORE_URL_WIN | REPORT_ERRORS, NULL);
			if (!stream) {
				return FAILURE;
			}
			php_stream_write(stream, message, message_len);
			php_stream_close(stream);
			break;

		case 4: /* send to SAPI */
			if (sapi_module.log_message) {
				sapi_module.log_message(message TSRMLS_CC);
			} else {
				return FAILURE;
			}
			break;

		default:
			php_log_err(message TSRMLS_CC);
			break;
	}
	return SUCCESS;
}
/* }}} */

from: streams.c

 

 

/* Writes a buffer directly to a stream, using multiple of the chunk size */
static size_t _php_stream_write_buffer(php_stream *stream, const char *buf, size_t count TSRMLS_DC)
{
	size_t didwrite = 0, towrite, justwrote;

 	/* if we have a seekable stream we need to ensure that data is written at the
 	 * current stream->position. This means invalidating the read buffer and then
	 * performing a low-level seek */
	if (stream->ops->seek && (stream->flags & PHP_STREAM_FLAG_NO_SEEK) == 0 && stream->readpos != stream->writepos) {
		stream->readpos = stream->writepos = 0;

		stream->ops->seek(stream, stream->position, SEEK_SET, &stream->position TSRMLS_CC);
	}


	while (count > 0) {
		towrite = count;
		if (towrite > stream->chunk_size)
			towrite = stream->chunk_size;

		justwrote = stream->ops->write(stream, buf, towrite TSRMLS_CC);

		/* convert justwrote to an integer, since normally it is unsigned */
		if ((int)justwrote > 0) {
			buf += justwrote;
			count -= justwrote;
			didwrite += justwrote;

			/* Only screw with the buffer if we can seek, otherwise we lose data
			 * buffered from fifos and sockets */
			if (stream->ops->seek && (stream->flags & PHP_STREAM_FLAG_NO_SEEK) == 0) {
				stream->position += justwrote;
			}
		} else {
			break;
		}
	}
	return didwrite;

}

通过看源码文件，error_log只是以O_APPEND模式打开文件，然后就是write buf，好吧，没有看到文件锁的影子。而问题也很明显，write可能会调用多次，那么也就基本认定msg并不保证被原子输出，多次的write使得这个问题更严重。

 

多次write不能保证原子操作，那么单次呢？

1.from：man write

 If the file was open(2)ed with <strong>O_APPEND</strong>, the file
       offset is first set to the end of the file before writing.  The
       adjustment of the file offset and the write operation are performed
       as an atomic step.

 

2.from：man write

Atomic/non-atomic: A write is atomic if the whole amount written in one operation is not interleaved with data from any other process. This is useful when there are multiple writers sending data to a single reader. Applications need to know how large a write request can be expected to be performed atomically. This maximum is called {PIPE_BUF}. This volume of IEEE Std 1003.1-2001 does not say whether write requests for more than {PIPE_BUF} bytes are atomic, but requires that writes of {PIPE_BUF} or fewer bytes shall be atomic.

 

man说的大概意思就是如果是O_APPEND模式，文件尾的定位与write调用是原子操作，不会存在write时文件尾还需要再调整，导致错位。当前这个原子性，只保证open和之后的第一次write，后续的write就不保证了。像error_log那样如果buf过长导致了多次write肯定就不保证buf一次完整输出。

继续深究，那么单一次write是原子的吗？man也给出了答案，不是的，只有要写出的数据小于等于PIPE_BUF时才保证原子操作。

问题得到了理论上的解答，下面开始实验验证：

test_error_log.php

 

<!--?php

$str = ;
for($i = 0; $i < (int)$argv[2]; $i++)
{
    $str = $str.$argv[1];
}

for($i = 0; $i < (int)$argv[3]; $i++)
{
    error_log($str.
, 3, ./append.txt);
}

?-->

check_line.py

 

 

filename = ./append.txt

for line in open(filename):
    print len(line)

test.sh

 

 

#!/bin/bash 

rm -f append.txt

for ((counter=0; counter < 10; ++counter))
do
    php test_error_log.php $counter $1 $2 &
done

sleep 2

#python check_line.py > a.txt

python check_line.py | sort | uniq -c

验证思路：在输出msg最后加换行符，如果输出的每行与初始buf大小相同，说明本次error_log完整输出，经验证，内核3.5.0-23上PIPE_BUF是8K，8K以内的error_log输出都可以保证完整，否则会存在错乱的风险