diff --git a/logv2.c b/logv2.c new file mode 100644 index 00000000..93cc567d --- /dev/null +++ b/logv2.c @@ -0,0 +1,486 @@ +/* + This is a reimplementation of SICS logging. The aim is to + merge all the different logs within SICS to the new logging + system + + COPYRIGHT: see file COPYRIGHT + + Mark Koennecke, February 2016 + */ +#include +#include +#include +#include +#include +#include +#include +#include +#include +/*============================================================================== + some static fields which control log file rotation +===============================================================================*/ +static FILE *logFile = NULL; +static unsigned int MAXFILELINES = 100000; +static unsigned int lineCount = 0; +static char logTemplate[1024]; +static char logFilename[1024]; + +/*================ The default log level =======================================*/ +static unsigned int globalLogLevel = 7; +/*========= The list of sub systems for which full logging is enabled ==========*/ +static int subList; +/*================== Callback management =======================================*/ +typedef struct { + LogCallback func; + void *userData; +} LogCBData; + +static int callbackList; +/*----------------------------------------------------------------------------*/ +static void formatTimeStamp(char *buffer, unsigned int bufferLength, unsigned int small) +{ + struct timeval tv; + struct tm *time; + int year, month, day, hour, min, sec, usec; + char delim = '-'; + + gettimeofday(&tv, NULL); + time = localtime(&tv.tv_sec); + time = localtime(&tv.tv_sec); + year = 1900 + time->tm_year; + month = time->tm_mon + 1; + day = time->tm_mday; + hour = time->tm_hour; + min = time->tm_min; + sec = time->tm_sec; + usec = (int) tv.tv_usec; + if(small == 1){ + snprintf(buffer,bufferLength, "%04d-%02d-%02dT%02d%c%02d%c%02d", + year, month, day, hour, delim, min, delim, sec); + } else { + snprintf(buffer,bufferLength, "%04d-%02d-%02dT%02d%c%02d%c%02d.%06d", + year, month, day, hour, delim, min, delim, sec, usec); + } +} +/*----------------------------------------------------------------------------*/ +static char *makeLogFileName(void) +{ + char timeStamp[256]; + char *filename = NULL; + unsigned int length; + + formatTimeStamp(timeStamp,sizeof(timeStamp),1); + length = strlen(logTemplate) + strlen(timeStamp) + 30; + filename = malloc(length*sizeof(char)); + if(filename != NULL){ + sprintf(filename,"%s-%s.log",logTemplate,timeStamp); + } + + return filename; +} +/*----------------------------------------------------------------------------*/ +static void LogClose(void *data) +{ + if(logFile != NULL){ + fclose(logFile); + } + logFile = NULL; + lineCount = 0; + strcpy(logFilename,"undefined"); +} +/*----------------------------------------------------------------------------*/ +static void checkLogFile(void) +{ + char *filename = NULL; + + /* + close when full + */ + if(logFile != NULL && lineCount >= MAXFILELINES){ + LogClose(NULL); + } + + /* + start a new log file + */ + if(logFile == NULL){ + filename = makeLogFileName(); + if(filename != NULL){ + logFile = fopen(filename,"w"); + strncpy(logFilename,filename,sizeof(logFilename)); + free(filename); + } + } +} +/*----------------------------------------------------------------------------*/ +static void writeLog(char *logMessage) +{ + int nChar; + + if(logMessage == NULL){ + return; + } + + + if(logFile != NULL){ + nChar = fprintf(logFile,"%s\n",logMessage); + lineCount++; + } + +} +/*----------------------------------------------------------------------------*/ +static unsigned int logFilter(unsigned int severity, const char *subsystem) +{ + int status; + char buffer[1024]; + + /* + If it is in the list of enabled subsystems, everything is logged + */ + status = LLDnodePtr2First(subList); + while (status == 1) { + LLDstringData(subList, buffer); + if(strcmp(buffer,subsystem) == 0) { + return 0; + } + status = LLDnodePtr2Next(subList); + } + + /* + test against the global log level + */ + if(severity >= globalLogLevel){ + return 1; + } + return 0; +} +/*=============================================================================*/ +static void formatSeverity(unsigned int severity, char *buffer, unsigned int bufferLength) +{ + static const char *severityText[] = {"FATAL", + "ERROR", + "WARNING", + "INFO", + "VERBOSE", + "DEBUG", + "INVALID" + }; + + if(severity > DEBUG){ + severity = INVALID; + } + strncpy(buffer,severityText[severity-1],bufferLength); +} +/*---------------------------------------------------------------------------- +I wish to avoid excessive dynamic memory allocation in logging. Thus I pass +in generous preallocated buffers and allocate only when the passed in buffer +is not big enough. This trick is used througout this code. + ------------------------------------------------------------------------------*/ +static char *formatLogLine(char *timeStamp,char *severityTXT, + const char* subsystem, + char *logData, char *logLine, + unsigned int logLineLength) +{ + unsigned int totalLength; + char *lineTxt = NULL; + + totalLength = strlen(timeStamp) + strlen(severityTXT) + strlen(subsystem) + + strlen(logData) + 10; + + if(totalLength > logLineLength){ + lineTxt = malloc((totalLength+1)*sizeof(char)); + } else { + lineTxt = logLine; + } + if(lineTxt != NULL){ + sprintf(lineTxt,"%s:%s:%s:%s", + timeStamp, + subsystem, + severityTXT, + logData); + } + return lineTxt; +} +/*----------------------------------------------------------------------------*/ +void RegisterLogCallback(LogCallback func, void *userData) +{ + LogCBData lcb; + + lcb.func = func; + lcb.userData = userData; + LLDnodeAppendFrom(callbackList,&lcb); +} +/*---------------------------------------------------------------------------*/ +void RemoveLogCallback(LogCallback func) +{ + int status; + LogCBData lcb; + + status = LLDnodePtr2First(callbackList); + while(status == 1){ + LLDnodeDataTo(callbackList,&lcb); + if(lcb.func == func){ + LLDnodeDelete(callbackList); + return; + } + status = LLDnodePtr2Next(callbackList); + } +} +/*----------------------------------------------------------------------------*/ +static void notifyListeners(unsigned int severity, const char *subsystem, + char *timeStamp, char *logData) +{ + int status; + LogCBData lcb; + + status = LLDnodePtr2First(callbackList); + while(status == 1){ + LLDnodeDataTo(callbackList,&lcb); + lcb.func(severity, timeStamp, subsystem,logData,lcb.userData); + status = LLDnodePtr2Next(callbackList); + } + +} +/*----------------------------------------------------------------------------*/ +void Log(unsigned int severity, const char *subsystem,const char *format,...) +{ + char severityTXT[60]; + char timeStamp[132]; + char logData[2024], logLine[3072]; + char *dynMessage = NULL, *logMessage, *fullMessage = NULL; + va_list ap; + int dataLength; + + + formatSeverity(severity,severityTXT,sizeof(severityTXT)); + formatTimeStamp(timeStamp,sizeof(timeStamp),0); + + checkLogFile(); + + /* + If we have enough space put the logData into our generous buffer. Else + allocate a dynamic buffer. I cannot do this in a subroutine as I need to + restart the vararg stuff. + */ + va_start(ap,format); + dataLength = vsnprintf(logData,sizeof(logData),format,ap); + logMessage = logData; + va_end(ap); + if(dataLength > sizeof(logData)){ + dynMessage = malloc((dataLength+1)*sizeof(char)); + if(dynMessage != NULL){ + va_start(ap,format); + vsnprintf(dynMessage,(dataLength+1)*sizeof(char),format,ap); + va_end(ap); + logMessage = dynMessage; + } + } + + notifyListeners(severity,subsystem,timeStamp, logMessage); + + + if(logFilter(severity,subsystem) == 1){ + if(dynMessage != NULL){ + free(dynMessage); + } + return; + } + + fullMessage = formatLogLine(timeStamp,severityTXT,subsystem, + logMessage, logLine, sizeof(logLine)); + + writeLog(fullMessage); + + + /* + clean up + */ + if(dynMessage != NULL){ + free(dynMessage); + } + if(fullMessage != logLine){ + free(fullMessage); + } + +} +/*--------------------------------------------------------------------------------*/ +static unsigned int sevFromText(const char *txt) +{ + static const char *severityText[] = {"fatal", + "error", + "warn", + "info", + "verbose", + "debug", + NULL + }; + int sev = 0; + while(severityText[sev] != NULL){ + if(strcmp(txt,severityText[sev]) == 0){ + break; + } + sev++; + } + sev++; /* starting at 1 rather then 0 */ + return sev; +} +/*------------------------------------------------------------------------------*/ +static void DisableSub(char *sub) +{ + int status; + char buffer[1024]; + + status = LLDnodePtr2First(subList); + while (status == 1) { + LLDstringData(subList, buffer); + if(strcmp(buffer,sub) == 0) { + LLDstringDelete(subList); + } + status = LLDnodePtr2Next(subList); + } +} +/*------------------------------------------------------------------------------*/ +static pDynString ListEnabled(void) +{ + int status; + char buffer[1024]; + pDynString result = CreateDynString(64,64); + + if(result == NULL){ + return NULL; + } + + status = LLDnodePtr2First(subList); + while (status == 1) { + LLDstringData(subList, buffer); + DynStringConcat(result,buffer); + DynStringConcatChar(result,':'); + status = LLDnodePtr2Next(subList); + } + return result; +} +/*============================================================================ + The Interpreter Interface + ==============================================================================*/ +static int LogAction(SConnection * pCon, SicsInterp * pSics, + void *pData, int argc, char *argv[]) +{ + char message[1024]; + unsigned int sev; + + if(argc < 4) { + SCWrite(pCon,"ERROR: need severity subsystem message parameters", eError); + return 0; + } + + /* + interpret severity + */ + strtolower(argv[1]); + sev = sevFromText(argv[1]); + if(sev >= INVALID){ + SCPrintf(pCon,eError,"ERROR: %s is no valid severity code", argv[1]); + return 0; + } + + Arg2Text(argc-3,&argv[3],message,sizeof(message)); + + Log(sev,argv[2],"%s",message); + + + return 1; +} +/*----------------------------------------------------------------------------*/ +static int LogConfigAction(SConnection * pCon, SicsInterp * pSics, + void *pData, int argc, char *argv[]) +{ + unsigned int sev; + char buffer[64]; + pDynString result = NULL; + + if(argc < 2) { + SCWrite(pCon,"ERROR: need keyword", eError); + return 0; + } + + strtolower(argv[1]); + + if(strcmp(argv[1],"maxlines") == 0){ + if(argc > 2){ + MAXFILELINES = atoi(argv[2]); + SCSendOK(pCon); + } else { + SCPrintf(pCon,eValue,"logconfig.maxlines = %d", MAXFILELINES); + } + } else if(strcmp(argv[1],"logtemplate") == 0){ + if(argc > 2){ + strncpy(logTemplate,argv[2],sizeof(logTemplate)); + SCSendOK(pCon); + } else { + SCPrintf(pCon,eValue,"logconfig.logtemplate = %s", logTemplate); + } + }else if(strcmp(argv[1],"flush") == 0){ + fflush(logFile); + SCSendOK(pCon); + } else if(strcmp(argv[1],"filename") == 0) { + SCPrintf(pCon,eValue,"logconfig.filename = %s", logFilename); + } else if(strcmp(argv[1],"close") == 0) { + LogClose(NULL); + SCSendOK(pCon); + }else if(strcmp(argv[1],"level") == 0 ) { + if(argc > 2) { + sev = sevFromText(argv[2]); + if(sev >= INVALID) { + SCPrintf(pCon,eError,"ERROR: %s is no valid log level", argv[2]); + return 0; + } + globalLogLevel = sev; + SCSendOK(pCon); + } else { + formatSeverity(globalLogLevel,buffer,sizeof(buffer)); + SCPrintf(pCon,eValue,"logconfig.level = %s", buffer); + } + }else if (strcmp(argv[1],"enable") == 0) { + if(argc > 2){ + if(strlen(argv[2]) >= 1024) { + SCWrite(pCon,"ERROR: subsystem name to long",eError); + return 0; + } + LLDstringAppend(subList,argv[2]); + SCSendOK(pCon); + } else { + SCWrite(pCon,"ERROR: need subsystem argument for enable",eError); + return 0; + } + }else if (strcmp(argv[1],"disable") == 0) { + if(argc > 2){ + DisableSub(argv[2]); + SCSendOK(pCon); + } else { + SCWrite(pCon,"ERROR: need subsystem argument for disable",eError); + return 0; + } + } else if(strcmp(argv[1],"listenabled") == 0) { + result = ListEnabled(); + if(result != NULL){ + SCWrite(pCon,GetCharArray(result),eValue); + DeleteDynString(result); + } + } else { + SCPrintf(pCon,eError,"ERROR: unknown keyword %s",argv[1]); + return 0; + } + + return 1; +} +/*-----------------------------------------------------------------------------*/ +void Logv2Init(void) +{ + subList = LLDstringCreate(); + callbackList = LLDcreate(sizeof(LogCBData)); + strcpy(logTemplate,"unconfiguredLogTemplate"); + + AddCmd("log", LogAction); + AddCommand(pServ->pSics,"logconfig", LogConfigAction, + LogClose, NULL); +} diff --git a/logv2.h b/logv2.h new file mode 100644 index 00000000..f8779bf6 --- /dev/null +++ b/logv2.h @@ -0,0 +1,60 @@ +/* + This is a reimplementation of SICS logging. The aim is to + merge all the different logs within SICS to the new logging + system + + COPYRIGHT: see file COPYRIGHT + + Mark Koennecke, February 2016 + */ + +#ifndef __LOGV2 +#define __LOGV2 +#include + +#define FATAL 1 +#define ERROR 2 +#define WARN 3 +#define INFO 4 +#define VERBOSE 5 +#define DEBUG 6 +#define INVALID 7 /* internal olny, do not use, means invalid severity passed */ + +/* write a log message + * \param severity The message severity. Must be one of the defines given above + * \param subsystem The subsystem reporting the log messages + * \param format The format string for the message + * \param ... The data to format + */ +void Log(unsigned int severity, const char *subsystem,const char *format,...); + +/* The callback functio which is called by the logging system on log events + * \param severity The message severity + * \param timeStamp The time stamp of the log message + * \param subsystem The subsystem of the log message + * \param message The log message + * \param userData A pointer to a user define ddata structure passed through + * transparantly from RegisterLogCallback +*/ + +/* +At this time LogCallback do not do any filtering. Thus, they see every message. +The idea is that suitable filtering functions ought to be implemented as helper +functions once the exact usage of the log \callbacks becomes clearer. + */ + +typedef void (*LogCallback)(unsigned int severity, const char *timeStamp, + const char *subsystem, + const char *message, void *userData); + +/* register a LogCallback + * \param func The function to call whena suitable log message has been found + * \param userData A pointer to user defined data which is passed through to the + * callback function. The log system does not free that pointer; this is up to the caller + * \return An callback ID which can be used for RemoveLogCallback + */ + +void RegisterLogCallback(LogCallback func, void *userData); +void RemoveLogCallback(LogCallback func); + +#endif diff --git a/make_gen b/make_gen index f44212af..b69e32c9 100644 --- a/make_gen +++ b/make_gen @@ -47,7 +47,7 @@ SOBJ = network.o ifile.o conman.o SCinter.o splitter.o passwd.o \ histmemsec.o sansbc.o sicsutil.o strlutil.o genbinprot.o trace.o\ singlebinb.o taskobj.o sctcomtask.o tasmono.o multicountersec.o \ messagepipe.o sicsget.o remoteobject.o pmacprot.o charbychar.o binprot.o \ - cnvrt.o tclClock.o tclDate.o tclUnixTime.o stack_trace.o + cnvrt.o tclClock.o tclDate.o tclUnixTime.o stack_trace.o logv2.o MOTOROBJ = motor.o simdriv.o COUNTEROBJ = countdriv.o simcter.o counter.o diff --git a/ofac.c b/ofac.c index ad08da80..e6bcdec5 100644 --- a/ofac.c +++ b/ofac.c @@ -55,6 +55,7 @@ static void InitGeneral(void) INIT(MakeTrace); INIT(InitTaskOBJ); INIT(RemoteObjectInit); + INIT(Logv2Init); INIT(SiteInit); /* site specific initializations */ }