G:/ScriptBasic/source/logger.c

Go to the documentation of this file.
00001 /*
00002 FILE: logger.c
00003 HEADER: logger.h
00004 
00005 TO_HEADER:
00006 
00007 typedef struct _tLogItem {
00008   char *pszMessage;
00009   long Time;
00010   struct _tLogItem *p,*n;
00011   } tLogItem, *ptLogItem;
00012 
00013 #define FNMAX 256
00014 typedef struct _tLogger {
00015   char *pszFileName;
00016   char szFileName[FNMAX];
00017   FILE *fp;
00018   long LastTime; // the hour of the log was written last time (hour is timestamp/60/60)
00019   long TimeSpan;
00020   void *(*memory_allocating_function)(size_t, void *);
00021   void (*memory_releasing_function)(void *, void *);
00022   void *pMemorySegment;
00023   long MaxItemLen; // the maximal length of a log line
00024   ptLogItem QueueStart,QueueEnd;
00025   MUTEX mxChain;
00026   MUTEX mxRun;
00027   MUTEX mxState;
00028   int type; // 0 normal or 3 synchronous logger
00029   int state; // 0 normal, 1 currently shutting down, 2 finished, closed, dead
00030              // or 3 that means this is a synchronous logger
00031   } tLogger,*ptLogger;
00032 
00033 #define LOGSTATE_NORMAL      0
00034 #define LOGSTATE_SHUTTING    1
00035 #define LOGSTATE_DEAD        2
00036 #define LOGSTATE_SYNCHRONOUS 3
00037 
00038 #define LOGTYPE_SYNCHRONOUS 0
00039 #define LOGTYPE_NORMAL      1
00040 */
00041 #include <time.h>
00042 #include <stdio.h>
00043 #include <stdlib.h>
00044 #include <stdarg.h>
00045 #include <time.h>
00046 #include "filesys.h"
00047 #include "thread.h"
00048 #include "logger.h"
00049 #include "mygmtime.h"
00050 
00051 /*POD
00052 This module can be used to log events. The module implements two type of logs.
00053 
00054 =itemize
00055 =item synchronous logs
00056 =item asynchronous logs
00057 =noitemize
00058 
00059 B<Synchronous> logs are just the normal plain logging technic writing messages to a log file. This
00060 is low performance, because the caller has to wait until the logging is performed and written to a file.
00061 On the other hand this is a safe logging.
00062 
00063 Asynchronous logging is a fast performance logging method. In this case the caller passes
00064 the log item to the logger. The logger puts the item on a queue and sends it to the log file
00065 in another thread when disk I/O bandwith permits. This is high performance, because the caller
00066 does not need to wait for the log item written to the disk. On the other hand this logging is not
00067 safe because the caller can not be sure that the log was written to the disk.
00068 
00069 The program using this module should use asynchronous logging for high volume logs and synchronous
00070 logging for low volume logging. For example a panic log that reports configuration error has to
00071 be written synchronously.
00072 
00073 Using this module you can initialize a log specifying the file where to write the log, send logs and
00074 you can tell the log to shut down. When shutting down all waiting logs are written to the file and no more
00075 log items are accepted. When all logs are written the logging thread terminates.
00076 
00077 CUT*/
00078 
00079 #define ALLOC(X) (pLOG->memory_allocating_function((X),pLOG->pMemorySegment))
00080 #define FREE(X)  (pLOG->memory_releasing_function((X),pLOG->pMemorySegment))
00081 
00082 static void * _mya(size_t x,void *y){
00083   return malloc(x);
00084   }
00085 static void _myf(void *x, void *y){
00086   free(x);
00087   }
00088 
00089 /*
00090 This is the logging thread started for each log file. This
00091 thread waits on the mutex that signals that there is some
00092 item to be written and then writes the log into the text file
00093 specified by the file name.
00094 */
00095 static void log_thread(void *q){
00096   ptLogger pLOG;
00097   ptLogItem pLI;
00098   struct tm gm_time;
00099 
00100   /* The actual log structure is passed as the thread argument. */
00101   pLOG = q;
00102   while( 1 ){
00103     /* This mutex is locked by default and is unlocked whenever there is something to send to file. */
00104     thread_LockMutex(&(pLOG->mxRun));
00105     while( 1 ){/* write all queue items to the file and break loop in the middle*/
00106       thread_LockMutex(&(pLOG->mxChain));
00107       if( pLOG->QueueStart == NULL ){/* if there are no more elements in the queue then we stop the writing loop */
00108         if( pLOG->fp )fflush(pLOG->fp);
00109         thread_UnlockMutex(&(pLOG->mxChain));
00110         if( log_state(pLOG) == LOGSTATE_SHUTTING ){/* if we are shutting down the log */
00111           thread_LockMutex(&(pLOG->mxState));
00112           pLOG->state = LOGSTATE_DEAD; /* signal that we are dead */
00113           thread_UnlockMutex(&(pLOG->mxState));
00114           if( pLOG->fp ){
00115             fclose(pLOG->fp);
00116             pLOG->fp = NULL;
00117             }
00118           return; /* finish the worker thread */
00119           }
00120         break;
00121         }
00122       /* if the queue is not empty */
00123       pLI = pLOG->QueueStart; /* get the first element of the queue and */
00124       pLOG->QueueStart = pLOG->QueueStart->n;/* step the queue head ahead one step */
00125       /* if the queue became empty then the QueueEnd pointer has also to be null */
00126       if( pLOG->QueueStart == NULL )pLOG->QueueEnd = NULL;
00127       thread_UnlockMutex(&(pLOG->mxChain));/* and release the chain so other 
00128                                               threads can add new elements to it 
00129                                               in the meantime */
00130       mygmtime(&(pLI->Time),&gm_time);
00131       /* if there is no file opened or we stepped into a different time interval than the previous log was */
00132       if( (!pLOG->fp) || (pLOG->TimeSpan && (pLOG->LastTime != pLI->Time / pLOG->TimeSpan)) ){
00133         if( pLOG->fp ){
00134           fclose(pLOG->fp);/* close the file if it was opened */
00135           pLOG->fp = NULL;
00136           }
00137         sprintf(pLOG->szFileName,pLOG->pszFileName,gm_time.tm_year+1900,gm_time.tm_mon,gm_time.tm_mday,gm_time.tm_hour);
00138         pLOG->fp = fopen(pLOG->szFileName,"a");
00139         /* store the time interval value of the current log */
00140         if( pLOG->TimeSpan )
00141           pLOG->LastTime = pLI->Time / pLOG->TimeSpan;
00142         }
00143       if( pLOG->fp )
00144         fprintf(pLOG->fp,"%4d.%02d.%02d %02d:%02d:%02d %s\n",gm_time.tm_year+1900,
00145                                                              gm_time.tm_mon+1,
00146                                                              gm_time.tm_mday,
00147                                                              gm_time.tm_hour,
00148                                                              gm_time.tm_min,
00149                                                              gm_time.tm_sec,
00150                                                              pLI->pszMessage);
00151       FREE(pLI->pszMessage);
00152       FREE(pLI);
00153       }
00154     }
00155   }
00156 
00157 /*POD
00158 =H log_state()
00159 
00160 This function safely returns the actual state of the log. This can be:
00161 
00162 =itemize
00163 =item T<LOGSTATE_NORMAL> the log is normal state accepting log items
00164 =item T<LOGSTATE_SHUTTING> the log is currently performing shut down, it does not accept any log item
00165 =item T<LOGSTATE_DEAD> the log is shut down all files are closed
00166 =item T<LOGSTATE_SYNCHRONOUS> the log is synchronous accepting log items
00167 =noitemize
00168 
00169 /*FUNCTION*/
00170 int log_state(ptLogger pLOG
00171   ){
00172 /*noverbatim
00173 CUT*/
00174   int state;
00175 
00176   /* If the calling program ignores the error returned when the log was initialized
00177      but cares the state afterwards it gets the state dead. */
00178   if( pLOG->pszFileName == NULL )return LOGSTATE_DEAD;
00179 
00180   if( pLOG->type == LOGTYPE_SYNCHRONOUS )return LOGSTATE_SYNCHRONOUS;
00181   thread_LockMutex(&(pLOG->mxState));
00182   state = pLOG->state;
00183   thread_UnlockMutex(&(pLOG->mxState));
00184   return state;
00185   }
00186 
00187 /*POD
00188 =H log_init()
00189 
00190 Initialize a log. The function sets the parameters of a logging thread. 
00191 The parameters are the usual memory allocation and deallocation functions
00192 and the log file name format string. This format string can contain at most four
00193 T<%d> as formatting element. This will be passed to T<sprintf> with arguments as
00194 year, month, day and hour in this order. This will ease log rotating.
00195 
00196 Note that log file name calculation is a CPU consuming process and therefore it is not
00197 performed for each log item. The log system recalculates the log file name and closes the
00198 old log file and opens a new one whenever the actual log to be written and the last log wrote
00199 is in a different time interval. The time interval is identified by the time stamp value
00200 divided (integer division) by the time span value. This is 3600 when you want to rotate the log
00201 hourly, 86400 if you want to rotate the log daily. Other rotations, like monthly do not work correctly.
00202 
00203 To do this the caller has to set the T<TimeSpan> field of the log structure. There is no support function
00204 to set this.
00205 
00206 For example:
00207 =verbatim
00208 
00209   if( log_init(&ErrLog,alloc_Alloc,alloc_Free,pM_AppLog,CONFIG("log.err.file"),LOGTYPE_NORMAL) )
00210     return 1;
00211   if( cft_GetEx(&MyCONF,"log.err.span",&ConfNode,NULL,&(ErrLog.TimeSpan),NULL,NULL) )
00212     ErrLog.TimeSpan = 0;
00213 
00214 =noverbatim
00215 
00216 as you can see in the file T<ad.c> Setting TimeSpan to zero results no log rotation.
00217 
00218 Note that it is a good practice to set the TimeSpan value to positive (non zero) even if the
00219 log is not rotated. If you ever delete the log file while the logging application is running
00220 the log is not written anymore until the log file is reopened.
00221 
00222 The log type can be T<LOGTYPE_NORMAL> to perform asynchronous high performance logging and
00223 T<LOGTYPE_SYNCHRONOUS> for syncronous, "panic" logging. Panic logging keeps the file continously
00224 opened until the log is shut down and does not perform log rotation.
00225 /*FUNCTION*/
00226 int log_init(ptLogger pLOG,
00227              void *(*memory_allocating_function)(size_t, void *),
00228              void (*memory_releasing_function)(void *, void *),
00229              void *pMemorySegment,
00230              char *pszLogFileName,
00231              int iLogType
00232   ){
00233 /*noverbatim
00234 CUT*/
00235   THREADHANDLE T;
00236 
00237   pLOG->memory_allocating_function = memory_allocating_function ?
00238                                      memory_allocating_function
00239                                                :
00240                                        _mya;
00241   pLOG->memory_releasing_function = memory_releasing_function ?
00242                                     memory_releasing_function
00243                                                :
00244                                       _myf;
00245   pLOG->pMemorySegment = pMemorySegment;
00246   pLOG->pszFileName = pszLogFileName;
00247   pLOG->MaxItemLen = 256;
00248   pLOG->QueueStart = pLOG->QueueEnd = NULL;
00249   pLOG->state = LOGSTATE_NORMAL;
00250   if( pszLogFileName == NULL )return 1;
00251   if( iLogType == LOGTYPE_SYNCHRONOUS ){
00252     pLOG->type  = LOGTYPE_SYNCHRONOUS;
00253     pLOG->fp = fopen(pszLogFileName,"a");
00254     if( pLOG->fp == NULL )return 1;
00255     return 0;
00256     }else{
00257     pLOG->type  = LOGTYPE_NORMAL;
00258     thread_InitMutex(&(pLOG->mxChain));
00259     thread_InitMutex(&(pLOG->mxRun));
00260     thread_InitMutex(&(pLOG->mxState));
00261     thread_LockMutex(&(pLOG->mxRun));
00262     thread_CreateThread(&T,log_thread,pLOG);
00263     pLOG->LastTime = 0;
00264     pLOG->TimeSpan = 0;
00265     pLOG->fp = NULL;
00266     return 0;
00267     }
00268   }
00269 
00270 /*POD
00271 =H log_printf()
00272 
00273 This function can be used to send a formatted log to the log file. The
00274 function creates the formatted string and then puts it onto the log queue.
00275 The log is actually sent to the log file by the asynchronous logger thread.
00276 
00277 /*FUNCTION*/
00278 int log_printf(ptLogger pLOG,
00279                char *pszFormat,
00280                ...
00281   ){
00282 /*noverbatim
00283 CUT*/
00284   va_list marker;
00285   char *pszMessage;
00286   ptLogItem pLI;
00287   int trigger,iState;
00288   struct tm gm_time;
00289   long Time;
00290 
00291   /* If the callingprogram ignores the error returned when the log was initialized
00292      we do net report this as an error any more. This behaves a /dev/null reporting. */
00293   if( pLOG->pszFileName == NULL )return 0;
00294 
00295   iState = log_state(pLOG);
00296   /* we do not accept more logs when we are shutting down */
00297   if( iState == LOGSTATE_SHUTTING || iState == LOGSTATE_DEAD )return 1;
00298 
00299   pszMessage = ALLOC(pLOG->MaxItemLen);
00300   if( pszMessage == NULL )return 1;
00301 
00302   /* If this is a synchronous logger then simply write the message. */
00303   if( iState == LOGSTATE_SYNCHRONOUS ){
00304     time(&Time);
00305     mygmtime(&Time,&gm_time);
00306     va_start(marker,pszFormat);
00307     vsprintf(pszMessage,pszFormat,marker);
00308     va_end(marker);
00309     if( pLOG->fp )
00310       fprintf(pLOG->fp,"%4d.%02d.%02d %02d:%02d:%02d %s\n",gm_time.tm_year+1900,
00311                                                            gm_time.tm_mon+1,
00312                                                            gm_time.tm_mday,
00313                                                            gm_time.tm_hour,
00314                                                            gm_time.tm_min,
00315                                                            gm_time.tm_sec,
00316                                                            pszMessage);
00317     fflush(pLOG->fp);
00318     FREE(pszMessage);
00319     return 0;
00320     }
00321 
00322   pLI = ALLOC(sizeof(tLogItem));
00323   if( pLI == NULL ){
00324     FREE(pszMessage);
00325     return 1;
00326     }
00327   time(&(pLI->Time));
00328   va_start(marker,pszFormat);
00329   vsprintf(pszMessage,pszFormat,marker);
00330   va_end(marker);
00331   pLI->pszMessage = pszMessage;
00332 
00333   trigger = 0;
00334   /* chain the message into the queue */
00335   thread_LockMutex(&(pLOG->mxChain));
00336   /* append it to the queue end */
00337   if( pLOG->QueueEnd )
00338     pLOG->QueueEnd->n = pLI;
00339   pLI->p = pLOG->QueueEnd;
00340   pLI->n = NULL;
00341   pLOG->QueueEnd = pLI;
00342   if( pLOG->QueueStart == NULL ){
00343     pLOG->QueueStart = pLI;
00344     trigger = 1;
00345     }
00346   thread_UnlockMutex(&(pLOG->mxChain));
00347   if( trigger )thread_UnlockMutex(&(pLOG->mxRun));
00348   return 0;
00349   }
00350 
00351 /*POD
00352 =H log_shutdown()
00353 
00354 Calling this function starts the shutdown of a log queue. This function allways return 0 as success.
00355 When the function returns the log queue does not accept more log items, however the queue is not completely
00356 shut down. If the caller wants to wait for the queue to shut down it has to wait and call the function
00357 R<log_state> to ensure that the shutdown procedure has been finished.
00358 
00359 /*FUNCTION*/
00360 int log_shutdown(ptLogger pLOG
00361   ){
00362 /*noverbatim
00363 CUT*/
00364 
00365   /* If the callingprogram ignores the error returned when the log was initialized
00366      we do net report this as an error any more. This behaves a /dev/null reporting. */
00367   if( pLOG->pszFileName == NULL )return 0;
00368 
00369   log_printf(pLOG,"Shutting down log.");
00370   if( pLOG->type == LOGTYPE_SYNCHRONOUS ){
00371     /* we need not do any sophisticated shut down for synchronous logs */
00372     pLOG->state = LOGSTATE_DEAD;
00373     fclose(pLOG->fp);
00374     pLOG->fp = NULL;
00375     return 0;
00376     }
00377   thread_LockMutex(&(pLOG->mxState));
00378   pLOG->state = LOGSTATE_SHUTTING; /* signal that we are shutting down this prevents
00379                                       further log entries. */
00380   thread_UnlockMutex(&(pLOG->mxState));
00381   /* Trigger the queue to perform final flush and shutdown. */
00382   thread_UnlockMutex(&(pLOG->mxRun));
00383   return 0;
00384   }

Generated on Sun Mar 12 23:56:31 2006 for ScriptBasic by  doxygen 1.4.6-NO