Почему системный журнал намного медленнее, чем файловый ввод-вывод?

3302
ceving

Я написал простую тестовую программу для измерения производительности функции 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 (); }
9
Presumably, syslog calls are more complex, with a "message & response" mechanism, have more overhead, travel between multiple user-space processes (unlike writing to a device or the console), and won't return until the message has been successfully accepted. afrazier 12 лет назад 0
Согласно ответу Ричарда, будут ли цифры похожи, если вы добавите fflush (fp) после fprintf ()? sep332 11 лет назад 1
@ sep3332 После добавления флага `O_SYNC` в функцию` open () `и` fflush (fp) `после каждого вызова` fprintf () `результаты становятся` [3.86, 3.63, 151.53, 23.00] МБ / с` в мой компьютер (Lenovo T61, тестирование Debian). Сейчас это выглядит лучше, но, проверьте `/ etc / rsyslog.conf`, он уже находится в несинхронном режиме для системных журналов. Xiè Jìléi 10 лет назад 0

1 ответ на вопрос

11
Richard Kettlewell

Оба системных вызова выдают один send () для сокета AF_UNIX за вызов. Даже если syslogd отбрасывает данные, ему все равно придется сначала их прочитать. Все это требует времени.

Операции записи в / dev / null также выдают одну запись () на вызов, но поскольку данные отбрасываются, ядро ​​может очень быстро их обработать.

Вызовы fprintf () генерируют только одну запись () для каждых 4096 байтов, которые передаются, т.е. примерно один раз в восемьдесят вызовов printf. Каждый из них включает только передачу данных из буфера libc в буферы ядра. Фиксация на диск будет (по крайней мере, по сравнению) очень медленной, но при отсутствии каких-либо явных вызовов синхронизации могут произойти позже (возможно, даже после завершения процесса).

Вкратце: syslog работает медленнее, чем / dev / null, потому что он выполняет большую работу, и медленнее, чем printf, в файл из-за буферизации.

Похожие вопросы