sabato 27 dicembre 2014
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 ?).
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:
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!
 |
| Ma dove siamo? Ma non era un Blog di programmazione questo? |
In realtà una versione semplificata del nostro Syslog potrebbe contenere una funzione di questo tipo:
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ì:/* 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; }
Ma noi siamo come il nostro amico Bond, abbiamo bisogno di mezzi più sofisticati, quindi useremo una funzione 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)
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:/* 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; }
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.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)
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!
domenica 16 febbraio 2014
Quantum of Syslog come scrivere un Syslog in C - pt.2
Ok, a grande richiesta pubblichiamo il seguito di Casino Royale (oops... Syslog Royale), dove il gioco si fa veramente duro. Ci eravamo lasciati con una pseudo-specifica di un sistema syslog-like, con tanto di anticipazione dei dati da ottenere. Adesso è venuto il momento della implementazione vera e propria, e spero che qualcuno abbia raccolto il mio invito a scriverne una versione propria aspettando questo nuovo post (non potete certo dire che non vi ho lasciato il tempo...).
Nello scorso post avevamo visto l'header mylog.h e l'utilizzatore main.c, quindi, con grande originalità, il file di implementazione lo chiameremo mylog.c. Vediamolo e analizziamolo per sezioni:
La seconda sezione che troviamo è quella dei "prototipi locali", che descrive le funzioni statiche di questo file, quelle che non devono essere esportate agli utilizzatori del mylog. In questo caso c'è getDateUsec(), che descriveremo più avanti.
Poi abbiamo la sezione "variabili locali", che sono, però, globali al file: so che le globali sono una maledizione (come già descritto qui), ma in alcuni casi (ad esempio in questo) è difficile farne a meno. E poi sono statiche al file, quindi ci sentiremo meno in colpa. Le variabili locali sono due: una è un FILE* che descrive il file di log (mylog_fp), mentre l'altra (mylog_level) è un int che serve per gestire il livello di log (che, come visto nel post introduttivo è impostato su quattro valori).
Dopodichè passiamo alla vera e propria implementazione, e incontriamo le prime due delle tre funzioni della nostra libreria, myOpenLog() e myCloseLog():
L'altra funzione, myCloseLog(), si limita, semplicemente, a rilasciare con fclose() il descrittore ottenuto con myOpenLog().
E adesso veniamo al cuore del sistema di log: la funzione myLog():
Dopodiché, usando le funzione della famiglia stdarg, possiamo gestire il messaggio da visualizzare (vedi dopo il commento "compone logstr con argomenti multipli") che usa una formattazione tipo printf() (come usato in main.c). Non sto a spiegarvi come funzionano stdarg e printf() (non è l'argomento di questo post) comunque potremmo tornarci su in futuro... per il momento vi rimando alla amplissima documentazione rintracciabile con San Google.
A questo punto, la funzione termina scrivendo nel file di log (vedi dopo il commento "scrive logstr con data+ora e flush dati") usando fprintf().
L'ultima istruzione è fflush(): perchè? Ok, aggiunge un overhead di I/O, ma un buon sistema di log deve garantire la scrittura immediata del messaggio appena composto, altrimenti in caso di crash del programma, o, più semplicemente, in applicazioni multi-processo, potremmo, stranamente, leggere messaggi con ordine temporale sbagliato, il che in fase di debug, sperimentazione o analisi di risultati potrebbe confonderci le idee.
Cosa ve ne sembra dell'implementazione? Non è male, no? Beh, ovviamente, ho fatto delle semplificazioni, perché l'idea base è sempre quella di proporre esempi che abbiano stile e funzionalità e che, poi, si possono perfezionare aggiungendo i controlli che mancano (tipo controllare se il descrittore FILE* è valido prima di usarlo, ecc.). L'importante è che l'idea di base sia corretta e si possa usare come traccia per prodotti reali. Provate a copiare e compilare il tutto, vi assicuro che funziona (come tutti gli esempi che propongo nel blog, eh!).
In una prossima puntata parleremo della funzione locale getDateUsec(), per terminare in bellezza l'argomento. Come sempre vi invito a non trattenere il respiro nell'attesa...
Ciao e al prossimo post!
 |
| La nostra implementazione è meglio della tua... |
#include <time.h> #include <sys/time.h> #include <stdarg.h> #include <stdio.h> #include "mylog.h" // prototipi locali static char *getDateUsec(char *dest, size_t size); // variabili locali static FILE *mylog_fp; static int mylog_level;Non starò a descrivere gli include-files, che sono, ne più ne meno, solo quelli che servono. Sembra lapalissiano, ma è normale trovare sorgenti con molti più include del necessario: non fanno danni ma complicano l'interpretazione visiva del codice. Ricordatevi di mettere solo quelli che servono.
La seconda sezione che troviamo è quella dei "prototipi locali", che descrive le funzioni statiche di questo file, quelle che non devono essere esportate agli utilizzatori del mylog. In questo caso c'è getDateUsec(), che descriveremo più avanti.
Poi abbiamo la sezione "variabili locali", che sono, però, globali al file: so che le globali sono una maledizione (come già descritto qui), ma in alcuni casi (ad esempio in questo) è difficile farne a meno. E poi sono statiche al file, quindi ci sentiremo meno in colpa. Le variabili locali sono due: una è un FILE* che descrive il file di log (mylog_fp), mentre l'altra (mylog_level) è un int che serve per gestire il livello di log (che, come visto nel post introduttivo è impostato su quattro valori).
Dopodichè passiamo alla vera e propria implementazione, e incontriamo le prime due delle tre funzioni della nostra libreria, myOpenLog() e myCloseLog():
Come vedete sono molto semplici: myOpenLog() apre con fopen() il file che passiamo in argomento (la stringa fname), e setta il loglevel con il valore passato col secondo argomento (l'int level). Il file lo apriremo in modo append, visto che vogliamo un logfile incrementale, riservandoci di azzerarlo quando ci sarà necessario./* myOpenLog() * Apre una connessione al logger myLog per un programma. */ void myOpenLog(const char *fname, int level) { // apre il logfile e set level mylog_fp = fopen(fname, "a"); mylog_level = level; } /* myCloseLog() * Chiude il descrittore usato per scrivere al logger myLog. */ void myCloseLog() { // chiude il logfile fclose(mylog_fp); }
L'altra funzione, myCloseLog(), si limita, semplicemente, a rilasciare con fclose() il descrittore ottenuto con myOpenLog().
E adesso veniamo al cuore del sistema di log: la funzione myLog():
La prima operazione che esegue myLog() è il test del livello di log: questo è fondamentale, perché ci permette generare solo i messaggi di livello minore o uguale a quello settato con myOpenLog(), il che include anche la non-generazione di messaggi, se mylog_level è MYLOG_NOLOG. E in quest'ultimo caso l'unica operazione eseguita è il test nel if, per cui, se decidiamo di non usare il sistema di log, il carico per la CPU e il sistema di I/O è praticamente nullo (era nelle specifiche di progetto!)./* myLog() * Genera un messaggio di log per il logger myLog. */ void myLog(int level, const char *format, ...) { // test livello di log if (level <= mylog_level) { // compone logstr con argomenti multipli va_list arglist; va_start(arglist, format); char logstr[128]; vsnprintf(logstr, sizeof(logstr), format, arglist); va_end(arglist); // scrive logstr con data+ora e flush dati char date[128]; fprintf(mylog_fp, "%s - %s\n", getDateUsec(date, sizeof(date)), logstr); fflush(mylog_fp); } }
Dopodiché, usando le funzione della famiglia stdarg, possiamo gestire il messaggio da visualizzare (vedi dopo il commento "compone logstr con argomenti multipli") che usa una formattazione tipo printf() (come usato in main.c). Non sto a spiegarvi come funzionano stdarg e printf() (non è l'argomento di questo post) comunque potremmo tornarci su in futuro... per il momento vi rimando alla amplissima documentazione rintracciabile con San Google.
A questo punto, la funzione termina scrivendo nel file di log (vedi dopo il commento "scrive logstr con data+ora e flush dati") usando fprintf().
L'ultima istruzione è fflush(): perchè? Ok, aggiunge un overhead di I/O, ma un buon sistema di log deve garantire la scrittura immediata del messaggio appena composto, altrimenti in caso di crash del programma, o, più semplicemente, in applicazioni multi-processo, potremmo, stranamente, leggere messaggi con ordine temporale sbagliato, il che in fase di debug, sperimentazione o analisi di risultati potrebbe confonderci le idee.
Cosa ve ne sembra dell'implementazione? Non è male, no? Beh, ovviamente, ho fatto delle semplificazioni, perché l'idea base è sempre quella di proporre esempi che abbiano stile e funzionalità e che, poi, si possono perfezionare aggiungendo i controlli che mancano (tipo controllare se il descrittore FILE* è valido prima di usarlo, ecc.). L'importante è che l'idea di base sia corretta e si possa usare come traccia per prodotti reali. Provate a copiare e compilare il tutto, vi assicuro che funziona (come tutti gli esempi che propongo nel blog, eh!).
In una prossima puntata parleremo della funzione locale getDateUsec(), per terminare in bellezza l'argomento. Come sempre vi invito a non trattenere il respiro nell'attesa...
Ciao e al prossimo post!
Iscriviti a:
Post (Atom)