Skylog cómo escribir un Syslog en C - pt.3

Estamos de vuelta aquí. Espero que no hayáis contenido el aliento esperando este post, como os había recomendado aquí. En caso de que lo hayáis hecho dudo que estéis en condición de seguir leyendo... ¿dónde nos habíamos quedado? (Uh, ha pasado mucho tiempo)... Ah, sí, ésta es la secuela de Quantum of Solace (¿o era Quantum of Syslog?), Así que para aquellos que no lo han visto, el título es Skyfall (¿o Skylog?).

Pero, ¿dónde estamos? ¿Esto no era un Blog de programación?

En el primer y segundo episodio vimos el header mylog.h, el utilizador main.c y el file de implementación mylog.c. Para completar este ultimo, sólo faltaba escribir la función local getDateUsec(), que es exactamente lo que vamos a hacer.

De hecho, una versión simplificada de nuestro Syslog podría contener una función como esta:

/* getDate()
 * Genera un string con fecha y hora.
 */
static char *getDate(char *dest, size_t size)
{
    // get time
    time_t t = time(NULL);
    struct tm *tmp = localtime(&t);

    // format cadena de destino dest (alocada por el que llama la función) 
    strftime(dest, size, "%Y-%m-%d %H:%M:%S", tmp);

    // return cadena de destino dest
    return dest;
}

Una función así es, en la mayoría de los casos, más que suficiente para añadir la hora a nuestras lineas de log. El resultado final en el file log.log (descrito aquí) sería así:

2014-06-22 00:16:48 - esto es un msg de tipo 0 (el nivel impostado es 2)
2014-06-22 00:16:48 - esto es un msg de tipo 1 (el nivel impostado es 2)
2014-06-22 00:16:48 - esto es un msg de tipo 2 (el nivel impostado es 2)

Pero nosotros somos como nuestro amigo Bond, necesitamos medios más sofisticados, por lo que vamos a utilizar una función como esta:

/* getDateUsec()
 * Genera un string con fecha y hora (usa los microsegundos).
 */
static char *getDateUsec(char *dest, size_t size)
{
    // get time (con gettimeofday()+localtime() en lugar de time()+localtime() para obtener los usec)
    struct timeval tv;
    gettimeofday(&tv, NULL);
    struct tm *tmp = localtime(&tv.tv_sec);

    // format cadena de destino dest (alocada por el que llama la función) y añade usec
    char fmt[128];
    strftime(fmt, sizeof(fmt), "%Y-%m-%d %H:%M:%S.%%06u", tmp);
    snprintf(dest, size, fmt, tv.tv_usec);

    // return cadena de destino dest
    return dest;
}

que es muy similar a la anterior, pero también nos proporciona los microsegundos (como se describe justamente en los comentarios dentro de la función). La salida del file de log será de este tipo:

2014-06-22 00:17:16.921026 - esto es un msg de tipo 0 (el nivel impostado es 2)
2014-06-22 00:17:16.921150 - esto es un msg de tipo 1 (el nivel impostado es 2)
2014-06-22 00:17:16.921170 - esto es un msg de tipo 2 (el nivel impostado es 2)

Vale, ya puedo oír los murmullos: "que exagerado, ¡hasta los microsegundos!" Repito: la versión simple es más que suficiente en la mayoría de los casos, pero, esforzándonos un poco, algún ejemplo en el que no puede ser útil una mayor precisión se encuentra.

El primer ejemplo que me viene a la mente, sin necesidad de recurrir al Software para sistemas hard-realtime, es el siguiente: imaginaros haber escrito un socket-server y un client de prueba y probarlos en la misma máquina (éste es un escenario real en el que se aprovecha el echo de contar con una base de tiempo común para servidor y cliente). Durante la etapa de depuración os dais cuenta de que en una fase operativa (típicamente la inicial) algún mensaje se pierde en el camino. Analizáis los dos log disponibles (servidor y cliente) y no conseguís averiguar cuál es el primer par de mensajes que no se sincroniza, ya que muchos mensajes parecen empezar en el mismo segundo. Ahí está: con la precisión del microsegundo podréis entender mejor lo que está pasando (este es un caso real que me ha pasado en el trabajo, ¡no me estoy inventando nada!).

Uff, por fin podemos dar por acabada la trilogía de Syslog. Espero que algo del Software descrito os pueda ser útil en el futuro. Ah, se me olvidaba: "Me llamo Log, James Log".

¡Hasta el próximo post!