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!
domenica 19 gennaio 2014
Syslog Royale come scrivere un Syslog in C - pt.1
Quando si scrive Software bisogna sempre cercare di essere professionali, qualunque sia l'uso del Software che stiamo scrivendo. Ad esempio non ci si può dimenticare di prevedere un buon sistema di log (ci sono, poi, alcuni professionisti della programmazione che non sanno neanche cosa è un buon sistema di log... ma questa è un altra storia).
Per aggiungere un log al nostro Software possiamo aiutarci col sistema operativo, ad esempio in UNIX e Linux abbiamo Syslog che è molto flessibile e ci semplifica la vita. Nel caso di non potere (o non volere) usare i mezzi forniti dal OS si può pensare di scriversi un proprio sistema di log, come vedremo nel seguito di questo post. Cercheremo di emulare, più o meno, sintassi e funzionamento di Syslog, cercando di realizzare un prodotto semplice ma di qualità, cioè un prodotto professionale, perché noi cerchiamo sempre di essere professionali, magari senza arrivare agli eccessi di professionalità di quello del titolo.
Sia perché non voglio fare un post troppo lungo (diventerebbe noioso), sia per seguire una specie di approccio specifica+implementazione (adattato a un C-Blog), ho diviso il post in due puntate: nella prima descriverò, a mo' di specifica funzionale, l'header file (mylog.h) e un esempio di uso (main.c). Nella seconda puntata descriverò la vera e propria implementazione.
Vediamo l'header file, mylog.h:
Vediamo ora l'esempio d'uso, main.c:
Per oggi abbiamo finito. I più volenterosi potranno, nell'attesa della seconda parte, scrivere una propria implementazione, e poi confrontarla con la mia, ma la mia sarà sicuramente meglio... (si allontana sghignazzando).
Ciao e al prossimo post!
Per aggiungere un log al nostro Software possiamo aiutarci col sistema operativo, ad esempio in UNIX e Linux abbiamo Syslog che è molto flessibile e ci semplifica la vita. Nel caso di non potere (o non volere) usare i mezzi forniti dal OS si può pensare di scriversi un proprio sistema di log, come vedremo nel seguito di questo post. Cercheremo di emulare, più o meno, sintassi e funzionamento di Syslog, cercando di realizzare un prodotto semplice ma di qualità, cioè un prodotto professionale, perché noi cerchiamo sempre di essere professionali, magari senza arrivare agli eccessi di professionalità di quello del titolo.
 |
| Mi chiamo Log, James Log |
Vediamo l'header file, mylog.h:
Semplice e auto-esplicativo, no? Il nostro prodotto è formato da tre funzioni canoniche (apri, usa, chiudi), e lavora a livelli di gravità (per il momento quattro). Quasi inutile spiegare che, settando un livello, nel logfile appariranno tutti i messaggi di uguale o maggiore gravità del livello selezionato. Il livello NOLOG, poi, è in pratica un flag di disabilitazione che ci permette di avviare l'applicazione senza logfile, per alleggerire l'esecuzione: è scontato che deve essere una disabilitazione vera, cioè la CPU e il sistema di I/O devono veramente lavorare meno senza log attivato.// livelli di mylog #define MYLOG_NOLOG -1 // nessun messaggio di log #define MYLOG_ERROR 0 // condizione di errore #define MYLOG_WARNING 1 // condizione di warning #define MYLOG_DEBUG 2 // messaggi di debug // prototipi globali void myOpenLog(const char *fname, int level); void myLog(int level, const char *format, ...); void myCloseLog();
Vediamo ora l'esempio d'uso, main.c:
Semplice, no? Eseguo un test argomenti con esempio di lancio (usage...), e poi apro, uso, chiudo, esco. Usando una linea di comando del tipo "mylog log.log 1" quale sarà il risultato? Verrà creato un file "log.log" che conterrà le seguenti due linee:#include <stdio.h> #include <stdlib.h> #include "mylog.h" int main(int argc, char* argv[]) { // test argomenti if (argc != 3) { printf("mylog: wrong arguments counts\n"); printf("usage: mylog logfile loglevel [e.g.: mylog log.txt 1]\n"); return EXIT_FAILURE; } // open log: set logfname e loglevel (0=error/1=warning/2=debug; -1=nolog) myOpenLog(argv[1], atoi(argv[2])); // test mylog() myLog(MYLOG_ERROR, "questo è un msg di tipo %d (il livello impostato è %d)", MYLOG_ERROR, atoi(argv[2])); myLog(MYLOG_WARNING, "questo è un msg di tipo %d (il livello impostato è %d)", MYLOG_WARNING, atoi(argv[2])); myLog(MYLOG_DEBUG, "questo è un msg di tipo %d (il livello impostato è %d)", MYLOG_DEBUG, atoi(argv[2])); // close log myCloseLog(); // exit return EXIT_SUCCESS; }
Aggiungiamo dettagli alla specifica: successivi lanci dell'applicazione devono appendere linee al logfile, perché una dote fondamentale di un log è mantenere informazioni dell'accaduto (e se ogni volta resettiamo il file le perdiamo). E se vogliamo ripartire da zero possiamo usare un altro filename oppure cancellare il vecchio logfile prima di eseguire. Un altro dettaglio che si nota è che ci servono, oltre alle nostre scritte di traccia, anche delle informazioni orarie, magari molto precise (nell'esempio ci sono i microsecondi: nella prossima puntata spiegherò il perché).2014-01-18 18:39:33.890271 - questo è un msg di tipo 0 (il livello impostato è 1) 2014-01-18 18:39:33.890407 - questo è un msg di tipo 1 (il livello impostato è 1)
Per oggi abbiamo finito. I più volenterosi potranno, nell'attesa della seconda parte, scrivere una propria implementazione, e poi confrontarla con la mia, ma la mia sarà sicuramente meglio... (si allontana sghignazzando).
Ciao e al prossimo post!
Iscriviti a:
Post (Atom)