Nei titoli e nei testi troverete qualche rimando cinematografico (ebbene si, sono un cinefilo). Se non vi interessano fate finta di non vederli, già che non sono fondamentali per la comprensione dei post...

Di questo blog ho mandato avanti, fino a Settembre 2018, anche una versione in Spagnolo. Potete trovarla su El arte de la programación en C. Buona lettura.

domenica 22 giugno 2014

Skylog
come scrivere un Syslog in C - pt.3

Rieccoci qua. Spero che non abbiate trattenuto il respiro in attesa di questo post, come vi avevo raccomandato qui. Nel caso l'abbiate fatto dubito che sarete in grado di continuare la lettura... dove eravamo rimasti? (uh, è passato tanto tempo)... Ah si, questo è il seguito di Quantum of Solace (o era Quantum of Syslog?), quindi, per chi non l'avesse visto, il titolo è Skyfall (o Skylog ?).
Ma dove siamo? Ma non era un Blog di programmazione questo?
Nel primo e nel secondo episodio avevamo visto l'header mylog.h, l'utilizzatore main.c e il file di implementazione mylog.c. Per completare quest'ultimo ci mancava solo scrivere la funzione locale getDateUsec(), che è proprio quello che stiamo per fare.

In realtà una versione semplificata del nostro Syslog potrebbe contenere una funzione di questo tipo:
/* getDate()
 * Genera una stringa con data e ora.
 */
static char *getDate(char *dest, size_t size)
{
    // get time
    time_t t = time(NULL);
    struct tm *tmp = localtime(&t);

    // format stringa destinazione dest (deve essere allocata dal chiamante)
    strftime(dest, size, "%Y-%m-%d %H:%M:%S", tmp);

    // return stringa destinazione dest
    return dest;
}
Una funzione così è, nella maggior parte dei casi, più che sufficiente per aggiungere il dato orario alle nostre stringhe di log. Il risultato finale nel file log.log (descritto qui) sarebbe così:
2014-06-22 00:16:48 - questo è un msg di tipo 0 (il livello impostato è 2)
2014-06-22 00:16:48 - questo è un msg di tipo 1 (il livello impostato è 2)
2014-06-22 00:16:48 - questo è un msg di tipo 2 (il livello impostato è 2)
Ma noi siamo come il nostro amico Bond, abbiamo bisogno di mezzi più sofisticati, quindi useremo una funzione così:
/* getDateUsec()
 * Genera una stringa con data e ora (usa i microsecondi).
 */
static char *getDateUsec(char *dest, size_t size)
{
    // get time (con gettimeofday()+localtime() invece di time()+localtime() per ottenere i usec)
    struct timeval tv;
    gettimeofday(&tv, NULL);
    struct tm *tmp = localtime(&tv.tv_sec);

    // format stringa destinazione dest(deve essere allocata dal chiamante) e aggiunge i usec
    char fmt[128];
    strftime(fmt, sizeof(fmt), "%Y-%m-%d %H:%M:%S.%%06u", tmp);
    snprintf(dest, size, fmt, tv.tv_usec);

    // return stringa destinazione dest
    return dest;
}
che è molto simile alla precedente, però ci fornisce anche i microsecondi (come giustamente descritto nei commenti interni alla funzione). L'uscita sul file di log sarà del tipo:
2014-06-22 00:17:16.921026 - questo è un msg di tipo 0 (il livello impostato è 2)
2014-06-22 00:17:16.921150 - questo è un msg di tipo 1 (il livello impostato è 2)
2014-06-22 00:17:16.921170 - questo è un msg di tipo 2 (il livello impostato è 2)
Ok, sento già dei mormorii: "che esagerato, addirittura i microsecondi!". Ribadisco: la versione semplice è più che sufficiente nella maggior parte dei casi, ma, sforzandoci un po', qualche esempio in cui ci può tornare utile una maggior precisione si trova.

Il primo esempio che mi viene in mente, senza scomodare il Software per sistemi hard-realtime, è il seguente: immaginatevi di aver scritto un socket-server e un client di test e di testarli nella stessa macchina (questo è uno scenario reale in cui si approfitta di avere una base dei tempi comune per Server e Client). Durante la fase di debug vi accorgete che in una fase operativa (tipicamente quella iniziale) qualche messaggio si perde per strada. Analizzate i due log disponibili (Server e Client) e non riuscite a capire quale è la prima coppia di messaggi che non sincronizza, perchè vari messaggi sembrano partire nello stesso secondo. Ecco, con la precisione del microsecondo riuscirete a capire meglio quello che sta succedendo (questo è un caso reale che mi è successo sul lavoro, non mi sto inventando niente!).

Uff, finalmente possiamo dare per terminata la trilogia del Syslog. Spero che un po' del Software descritto possa tornarvi utile in futuro. Ah, dimenticavo: "Mi chiamo Log, James Log".

Ciao e al prossimo post!