Почему системный журнал намного медленнее, чем файловый ввод-вывод?
Я написал простую тестовую программу для измерения производительности функции 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 байтов данных во время каждого вызова.
Почему системный журнал более чем в десять раз медленнее, чем файловый ввод-вывод?
Это программа, которую я использовал для выполнения теста:
#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 ответ
Вызовы системного журнала выдают один send() для сокета AF_UNIX за вызов. Даже если syslogd отбрасывает данные, ему все равно придется сначала их прочитать. Все это требует времени.
Операции записи в /dev/null также выдают одну запись () на вызов, но поскольку данные отбрасываются, ядро может очень быстро их обработать.
Вызовы fprintf() генерируют только одну запись () для каждых 4096 байтов, которые передаются, то есть примерно один раз в восемьдесят вызовов printf. Каждый включает в себя только передачу данных из буфера libc в буферы ядра. Фиксация на диск будет (по крайней мере для сравнения) очень медленной, но при отсутствии каких-либо явных вызовов синхронизации может произойти позже (возможно, даже после завершения процесса).
Вкратце: syslog работает медленнее, чем /dev/null, потому что он выполняет большую работу, и медленнее, чем printf, в файл из-за буферизации.