![为什么 syslog 比文件 IO 慢这么多?](https://linux22.com/image/1281549/%E4%B8%BA%E4%BB%80%E4%B9%88%20syslog%20%E6%AF%94%E6%96%87%E4%BB%B6%20IO%20%E6%85%A2%E8%BF%99%E4%B9%88%E5%A4%9A%EF%BC%9F.png)
我写了一个简单的测试程序来测量 syslog 功能的性能。这是我的测试系统的结果:(Debian 6.0.2 和 Linux 2.6.32-5-amd64)
测试用例调用有效负载持续时间吞吐量 [] [兆] [秒] [兆/秒] -------------------- ---------- ---------- ---------- ---------- 系统日志 200000 10.00 7.81 1.28 系统日志 %s 200000 10.00 9.94 1.01 写入/dev/null 200000 10.00 0.03 343.93 printf %s 200000 10.00 0.13 76.29
测试程序进行了 200000 次系统调用,每次调用写入 50 字节的数据。
为什么 Syslog 比文件 IO 慢十倍以上?
这是我用来执行测试的程序:
#include <fcntl.h>
#include <stdio.h>
#include <string.h>
#include <sys/stat.h>
#include <sys/time.h>
#include <sys/types.h>
#include <syslog.h>
#include <unistd.h>
const int iter = 200000;
const char msg[] = "123456789 123456789 123456789 123456789 123456789";
struct timeval t0;
struct timeval t1;
void start ()
{
gettimeofday (&t0, (void*)0);
}
void stop ()
{
gettimeofday (&t1, (void*)0);
}
void report (char *action)
{
double dt = (double)t1.tv_sec - (double)t0.tv_sec +
1e-6 * ((double)t1.tv_usec - (double)t0.tv_usec);
double mb = 1e-6 * sizeof (msg) * iter;
if (action == NULL)
printf ("Test Case Calls Payload Duration Thoughput \n"
" [] [MB] [s] [MB/s] \n"
"-------------------- ---------- ---------- ---------- ----------\n");
else {
if (strlen (action) > 20) action[20] = 0;
printf ("%-20s %-10d %-10.2f %-10.2f %-10.2f\n",
action, iter, mb, dt, mb / dt);
}
}
void test_syslog ()
{
int i;
openlog ("test_syslog", LOG_PID | LOG_NDELAY, LOG_LOCAL0);
start ();
for (i = 0; i < iter; i++)
syslog (LOG_DEBUG, msg);
stop ();
closelog ();
report ("syslog");
}
void test_syslog_format ()
{
int i;
openlog ("test_syslog", LOG_PID | LOG_NDELAY, LOG_LOCAL0);
start ();
for (i = 0; i < iter; i++)
syslog (LOG_DEBUG, "%s", msg);
stop ();
closelog ();
report ("syslog %s");
}
void test_write_devnull ()
{
int i, fd;
fd = open ("/dev/null", O_WRONLY);
start ();
for (i = 0; i < iter; i++)
write (fd, msg, sizeof(msg));
stop ();
close (fd);
report ("write /dev/null");
}
void test_printf ()
{
int i;
FILE *fp;
fp = fopen ("/tmp/test_printf", "w");
start ();
for (i = 0; i < iter; i++)
fprintf (fp, "%s", msg);
stop ();
fclose (fp);
report ("printf %s");
}
int main (int argc, char **argv)
{
report (NULL);
test_syslog ();
test_syslog_format ();
test_write_devnull ();
test_printf ();
}
答案1
syslog 调用每次都会向 AF_UNIX 套接字发出一个 send()。即使 syslogd 丢弃数据,它仍然必须先读取数据。所有这些都需要时间。
对 /dev/null 的写入也会在每次调用时发出一个 write(),但由于数据被丢弃,内核可以非常快速地处理它。
fprintf() 调用每传输 4096 个字节仅生成一个 write(),即大约每 80 个 printf 调用生成一个 write()。每个调用仅涉及将数据从 libc 的缓冲区传输到内核的缓冲区。提交到磁盘(至少相比之下)会非常慢,但在没有任何显式同步调用的情况下,可能会在稍后发生(甚至在进程终止后)。
简而言之:syslog 比 /dev/null 慢,因为它要做大量工作,并且由于缓冲,它比 printf 到文件的速度慢。