9 votes

Pourquoi le syslog est-il tellement plus lent que le fichier IO ?

J'ai écrit un programme de test simple pour mesurer les performances de la fonction syslog. Voici les résultats de mon système de test : (Debian 6.0.2 avec Linux 2.6.32-5-amd64)

Test Case             Calls       Payload     Duration    Thoughput 
                      \[\]          \[MB\]        \[s\]         \[MB/s\]    
--------------------  ----------  ----------  ----------  ----------
syslog                200000      10.00       7.81        1.28      
syslog %s             200000      10.00       9.94        1.01      
write /dev/null       200000      10.00       0.03        343.93    
printf %s             200000      10.00       0.13        76.29     

Le programme de test a effectué 200 000 appels système en écrivant 50 octets de données à chaque appel.

Pourquoi Syslog est-il plus de dix fois plus lent que les fichiers IO ?

Voici le programme que j'ai utilisé pour effectuer le test :

#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 ();
}

11voto

Richard Kettlewell Points 806

Les appels syslog émettent tous deux un send() vers une socket AF_UNIX par appel. Même si le syslogd rejette les données, il devra d'abord les lire. Tout cela prend du temps.

Les écritures sur /dev/null émettent également un write() par appel mais comme les données sont rejetées, elles peuvent être traitées très rapidement par le noyau.

Les appels fprintf() ne génèrent qu'un write() pour chaque 4096 octets transférés, soit environ un appel printf tous les quatre-vingts. Chacun d'eux n'implique que le transfert de données du tampon de la libc vers les tampons du noyau. Le commit sur le disque sera (en comparaison au moins) très lent, mais en l'absence de tout appel de synchronisation explicite peut se produire plus tard (peut-être même après la fin du processus).

En résumé, syslog est plus lent que /dev/null parce qu'il fait beaucoup de travail et plus lent que printf vers un fichier à cause de la mise en mémoire tampon.

SistemesEz.com

SystemesEZ est une communauté de sysadmins où vous pouvez résoudre vos problèmes et vos doutes. Vous pouvez consulter les questions des autres sysadmins, poser vos propres questions ou résoudre celles des autres.

Powered by:

X