diff --git a/asyncprotocol.c b/asyncprotocol.c index f9aa909b..4c3db696 100644 --- a/asyncprotocol.c +++ b/asyncprotocol.c @@ -81,7 +81,7 @@ int defaultPrepareTxn(pAsyncProtocol p, pAsyncTxn txn, const char *cmd, /* outgoing command is correctly terminated */ txn->out_buf = malloc(cmd_len + 1); if (txn->out_buf == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncProtocol::defaultPrepareTxn"); + Log(ERROR,"asquio","%s","Out of memory in AsyncProtocol::defaultPrepareTxn"); return 0; } memcpy(txn->out_buf, cmd, cmd_len + 1); @@ -90,7 +90,7 @@ int defaultPrepareTxn(pAsyncProtocol p, pAsyncTxn txn, const char *cmd, int tlen = strlen(term); txn->out_buf = malloc(cmd_len + tlen + 1); if (txn->out_buf == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncProtocol::defaultPrepareTxn", + Log(ERROR,"asquio","%s","Out of memory in AsyncProtocol::defaultPrepareTxn", eError); return 0; } @@ -173,7 +173,7 @@ static char *decodeTerminator(char *code) count = strlen(code); pResult = (char *) malloc(count + 1); if (!pResult) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncProtocol::decodeTerminator", + Log(ERROR,"asquio","%s","Out of memory in AsyncProtocol::decodeTerminator", eError); return NULL; } @@ -328,7 +328,7 @@ pAsyncProtocol AsyncProtocolCreate(SicsInterp * pSics, self = (pAsyncProtocol) malloc(sizeof(AsyncProtocol)); if (self == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncProtocolCreate"); + Log(ERROR,"asquio","%s","Out of memory in AsyncProtocolCreate"); return NULL; } memset(self, 0, sizeof(AsyncProtocol)); @@ -339,7 +339,7 @@ pAsyncProtocol AsyncProtocolCreate(SicsInterp * pSics, pKFunc = AsyncProtocolKill; iRet = AddCommand(pSics, (char *) protocolName, pFunc, pKFunc, self); if (!iRet) { - Log(ERROR,"ASQUIO","%s","AddCommand failed in AsyncProtocolCreate"); + Log(ERROR,"asquio","%s","AddCommand failed in AsyncProtocolCreate"); AsyncProtocolKill(self); return NULL; } diff --git a/asyncqueue.c b/asyncqueue.c index ed16849f..74b18538 100644 --- a/asyncqueue.c +++ b/asyncqueue.c @@ -207,7 +207,7 @@ static void AQ_Notify(pAsyncQueue self, int event) { pAsyncUnit unit; if (self->state != eAsyncConnected) - Log(DEBUG,"ASQUIO", "Function:%s:%s", self->queue_name, + Log(DEBUG,"asquio", "Function:%s:%s", self->queue_name, __func__); for (unit = self->units; unit; unit = unit->next) if (unit->notify_func != NULL) @@ -222,7 +222,7 @@ static int TimedReconnect(void *cntx, int mode) self->nw_tmr = 0; if (self->state != eAsyncConnected) - Log(DEBUG,"ASQUIO", "Function: %s:%s\n", self->queue_name, + Log(DEBUG,"asquio", "Function: %s:%s\n", self->queue_name, __func__); AQ_Purge(self); @@ -240,7 +240,7 @@ static int TimedReconnect(void *cntx, int mode) if (iRet < 0) { snprintf(line, 132, "Failed reconnect on AsyncQueue '%s'", self->queue_name); - Log(DEBUG,"ASQUIO","%s",line); + Log(DEBUG,"asquio","%s",line); /* Timer for retry */ NetWatchSetMode(self->nw_ctx, 0); /* implement an exponential backoff within limits */ @@ -251,12 +251,12 @@ static int TimedReconnect(void *cntx, int mode) self->retryTimer = 16000; AQ_SetTimer(self, self->retryTimer, TimedReconnect, self); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncWaiting", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncWaiting", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncWaiting; } else { NetWatchSetMode(self->nw_ctx, nwatch_write); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncConnecting\n", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncConnecting\n", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncConnecting; /* await reconnect result in MyCallback */ @@ -264,11 +264,11 @@ static int TimedReconnect(void *cntx, int mode) return 1; } NetWatchSetMode(self->nw_ctx, nwatch_read); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncConnected\n", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncConnected\n", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncConnected; snprintf(line, 132, "Reconnect on AsyncQueue '%s'", self->queue_name); - Log(DEBUG,"ASQUIO","%s",line); + Log(DEBUG,"asquio","%s",line); AQ_Purge(self); AQ_Notify(self, AQU_RECONNECT); return 1; @@ -280,7 +280,7 @@ static int AQ_Reconnect(pAsyncQueue self) char line[132]; if (self->state != eAsyncConnected) - Log(DEBUG,"ASQUIO", "Function: %s:%s\n", self->queue_name, + Log(DEBUG,"asquio", "Function: %s:%s\n", self->queue_name, __func__); /* * Remove any old timer @@ -290,7 +290,7 @@ static int AQ_Reconnect(pAsyncQueue self) if (self->state == eAsyncConnected) { self->state = eAsyncIdle; - Log(DEBUG,"ASQUIO", "Disconnect on AsyncQueue '%s'", self->queue_name); + Log(DEBUG,"asquio", "Disconnect on AsyncQueue '%s'", self->queue_name); AQ_Notify(self, AQU_DISCONNECT); AQ_Purge(self); } @@ -310,12 +310,12 @@ static int AQ_Reconnect(pAsyncQueue self) self->retryTimer = 125; /* initial delay */ AQ_SetTimer(self, self->retryTimer, TimedReconnect, self); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncWaiting\n", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncWaiting\n", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncWaiting; } else { NetWatchSetMode(self->nw_ctx, nwatch_write); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncConnecting\n", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncConnecting\n", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncConnecting; /* await reconnect result in MyCallback */ @@ -323,11 +323,11 @@ static int AQ_Reconnect(pAsyncQueue self) return iRet; } NetWatchSetMode(self->nw_ctx, nwatch_read); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncConnected\n", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncConnected\n", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncConnected; snprintf(line, 132, "Reconnect on AsyncQueue '%s'", self->queue_name); - Log(DEBUG,"ASQUIO",line); + Log(DEBUG,"asquio",line); AQ_Purge(self); AQ_Notify(self, AQU_RECONNECT); return 1; @@ -344,7 +344,7 @@ static int StartCommand(pAsyncQueue self) int iRet = 0; if (self->state != eAsyncConnected) - Log(DEBUG,"ASQUIO", "Function: %s:%s\n", self->queue_name, + Log(DEBUG,"asquio", "Function: %s:%s\n", self->queue_name, __func__); if (myCmd == NULL) return OKOK; @@ -393,7 +393,7 @@ static int StartCommand(pAsyncQueue self) } else if (iRet > 0) { struct timeval tv; gettimeofday(&tv, NULL); - Log(ERROR, "ASQUIO","%d unsolicited chars in AsyncQueue %s",iRet, self->queue_name); + Log(ERROR, "asquio","%d unsolicited chars in AsyncQueue %s",iRet, self->queue_name); } } } @@ -501,7 +501,7 @@ static int CommandTimeout(void *cntx, int mode) if (self->trace) { struct timeval tv; gettimeofday(&tv, NULL); - Log(DEBUG,"ASQUIO", "Timeout Trace on AsyncQueue %s", self->queue_name); + Log(DEBUG,"asquio", "Timeout Trace on AsyncQueue %s", self->queue_name); } if (myCmd->retries > 0) { --myCmd->retries; @@ -525,7 +525,7 @@ static int DelayedStart(void *cntx, int mode) { pAsyncQueue self = (pAsyncQueue) cntx; if (self->state != eAsyncConnected) - Log(DEBUG,"ASQUIO", "Function: %s:%s\n", self->queue_name, + Log(DEBUG,"asquio", "Function: %s:%s\n", self->queue_name, __func__); self->nw_tmr = 0; StartCommand(self); @@ -537,7 +537,7 @@ static int MyCallback(void *context, int mode) pAsyncQueue self = (pAsyncQueue) context; if (self->state != eAsyncConnected) - Log(DEBUG,"ASQUIO", "Function: %s:%s\n", self->queue_name, + Log(DEBUG,"asquio", "Function: %s:%s\n", self->queue_name, __func__); if (mode & nwatch_read) { int iRet; @@ -567,7 +567,7 @@ static int MyCallback(void *context, int mode) if (self->trace) { struct timeval tv; gettimeofday(&tv, NULL); - Log(INFO, "ASQUIO", + Log(INFO, "asquio", "Received:%s:%s", self->queue_name,myCmd->tran->inp_buf); } PopCommand(self); @@ -576,10 +576,10 @@ static int MyCallback(void *context, int mode) int excess = nchars - 1 - i; struct timeval tv; gettimeofday(&tv, NULL); - Log(ERROR,"ASQUIO", + Log(ERROR,"asquio", "Protocol error %d in AsyncQueue %s", iRet, self->queue_name); - Log(ERROR,"ASQUIO","SENT:%s:Received:%s",myCmd->tran->out_buf, myCmd->tran->inp_buf); + Log(ERROR,"asquio","SENT:%s:Received:%s",myCmd->tran->out_buf, myCmd->tran->inp_buf); break; } } @@ -587,7 +587,7 @@ static int MyCallback(void *context, int mode) int excess = nchars - 1 - i; struct timeval tv; gettimeofday(&tv, NULL); - Log(ERROR, "ASQUIO", "%d excess chars in AsyncQueue %s", + Log(ERROR, "asquio", "%d excess chars in AsyncQueue %s", excess, self->queue_name); /* TODO: handle unsolicited */ } @@ -595,7 +595,7 @@ static int MyCallback(void *context, int mode) int excess = nchars - 1 - i; struct timeval tv; gettimeofday(&tv, NULL); - Log(ERROR, "ASQUIO", "%d unsolicited chars in AsyncQueue %s", + Log(ERROR, "asquio", "%d unsolicited chars in AsyncQueue %s", excess, self->queue_name); /* TODO: handle unsolicited input */ } @@ -603,10 +603,10 @@ static int MyCallback(void *context, int mode) } if (mode & nwatch_write) { char line[132]; - Log(DEBUG,"ASQUIO", "Writeable socket callback on AsyncQueue %s", + Log(DEBUG,"asquio", "Writeable socket callback on AsyncQueue %s", self->queue_name); NetWatchSetMode(self->nw_ctx, nwatch_read); - Log(DEBUG,"ASQUIO", "In %s:%s: state %s => eAsyncConnected\n", + Log(DEBUG,"asquio", "In %s:%s: state %s => eAsyncConnected\n", self->queue_name, __func__, state_name(self->state)); self->state = eAsyncConnected; } @@ -620,7 +620,7 @@ int AsyncUnitEnqueueHead(pAsyncUnit unit, pAsyncTxn context) assert(unit && unit->queue && unit->queue->protocol); myCmd = (pAQ_Cmd) malloc(sizeof(AQ_Cmd)); if (myCmd == NULL) { - Log(ERROR,"ASQUIO","Out of memory in AsyncUnitEnqueHead", eError); + Log(ERROR,"asquio","Out of memory in AsyncUnitEnqueHead", eError); return 0; } memset(myCmd, 0, sizeof(AQ_Cmd)); @@ -639,7 +639,7 @@ int AsyncUnitEnqueueTxn(pAsyncUnit unit, pAsyncTxn pTxn) assert(unit && unit->queue && unit->queue->protocol); myCmd = (pAQ_Cmd) malloc(sizeof(AQ_Cmd)); if (myCmd == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncUnitEnqueueTxn"); + Log(ERROR,"asquio","%s","Out of memory in AsyncUnitEnqueueTxn"); return 0; } memset(myCmd, 0, sizeof(AQ_Cmd)); @@ -661,7 +661,7 @@ pAsyncTxn AsyncUnitPrepareTxn(pAsyncUnit unit, assert(unit); myTxn = (pAsyncTxn) malloc(sizeof(AsyncTxn)); if (myTxn == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncUnitPrepareTxn", eError); + Log(ERROR,"asquio","%s","Out of memory in AsyncUnitPrepareTxn", eError); return NULL; } memset(myTxn, 0, sizeof(AsyncTxn)); @@ -696,7 +696,7 @@ pAsyncTxn AsyncUnitPrepareTxn(pAsyncUnit unit, } else { myTxn->out_buf = (char *) malloc(cmd_len + 5); if (myTxn->out_buf == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncUnitPrepareTxn"); + Log(ERROR,"asquio","%s","Out of memory in AsyncUnitPrepareTxn"); free(myTxn); return NULL; } @@ -715,7 +715,7 @@ pAsyncTxn AsyncUnitPrepareTxn(pAsyncUnit unit, else { myTxn->inp_buf = malloc(rsp_len + 1); if (myTxn->inp_buf == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncUnitPrepareTxn", eError); + Log(ERROR,"asquio","%s","Out of memory in AsyncUnitPrepareTxn", eError); free(myTxn->out_buf); free(myTxn); return NULL; @@ -813,7 +813,7 @@ int AsyncUnitWrite(pAsyncUnit unit, void *buffer, int buflen) if (unit->queue->trace) { struct timeval tv; gettimeofday(&tv, NULL); - Log(DEBUG,"ASQUIO" + Log(DEBUG,"asquio" "Output Trace on AsyncQueue %s:%s", unit->queue->queue_name, buffer); } sock = AsyncUnitGetSocket(unit); @@ -1380,7 +1380,7 @@ int AsyncUnitCreateHost(const char *host, const char *port, unit = (pAsyncUnit) malloc(sizeof(AsyncUnit)); if (unit == NULL) { - Log(ERROR,"ASQUIO","%s","Out of memory in AsyncUnitCreateHost", eError); + Log(ERROR,"asquio","%s","Out of memory in AsyncUnitCreateHost", eError); *handle = NULL; return 0; } diff --git a/conman.c b/conman.c index 6bb165c9..0932bcfa 100644 --- a/conman.c +++ b/conman.c @@ -829,7 +829,7 @@ static void testAndWriteLog(SConnection * self, char *buffer, int iOut) Log(ERROR,"dev","%s",buffer); break; case eStatus: - Log(DEBUG,"IO","%s",buffer); + Log(DEBUG,"io","%s",buffer); break; case eEvent: if(strstr(buffer,"ERROR") != NULL){ @@ -1707,10 +1707,15 @@ int SCInvoke(SConnection * self, SicsInterp * pInter, char *pCommand) return 0; } strlcpy(pCopy->deviceID, pBueffel, SCDEVIDLEN); - if(SCGetRights(self) > usUser){ - Log(DEBUG,"com","%s:in:%s", ConID(self),pCommand); - } else { - Log(INFO,"com", "%s:in:%s", ConID(self),pCommand); + /* + do not log the log command; defeats log control + */ + if(strstr(pCommand,"log ") == NULL) { + if(SCGetRights(self) > usUser){ + Log(DEBUG,"com","%s:in:%s", ConID(self),pCommand); + } else { + Log(INFO,"com", "%s:in:%s", ConID(self),pCommand); + } } iRet = InterpExecute(pInter, pCopy, pCommand); SCDeleteConnection(pCopy); diff --git a/logv2.c b/logv2.c index 891f1ea7..ed62131b 100644 --- a/logv2.c +++ b/logv2.c @@ -28,9 +28,11 @@ static unsigned int logDisabled = 0; static int unsigned logConfigured = 0; /*================ The default log level =======================================*/ -static unsigned int globalLogLevel = 4; +static unsigned int globalLogLevel = INFO; + /*========= The list of sub systems for which full logging is enabled ==========*/ -static int subList; +unsigned int logEnabledArray[MAXSUB ]; + /*================== Callback management =======================================*/ typedef struct { LogCallback func; @@ -94,6 +96,8 @@ void LogClose(void *data) static void checkLogFile(void) { char *filename = NULL; + char *oldLogFile = NULL; + char timeStamp[132]; if(logDisabled || logConfigured == 0){ return; @@ -103,6 +107,10 @@ static void checkLogFile(void) close when full */ if(logFile != NULL && lineCount >= MAXFILELINES){ + oldLogFile = strdup(logFilename); + filename = makeLogFileName(); + formatTimeStamp(timeStamp,sizeof(timeStamp),0); + fprintf(logFile,"%s:sys:%d:Next logfile %s\n",timeStamp,INFO,filename); LogClose(NULL); } @@ -110,10 +118,16 @@ static void checkLogFile(void) start a new log file */ if(logFile == NULL){ - filename = makeLogFileName(); + if(filename == NULL){ + filename = makeLogFileName(); + } if(filename != NULL){ logFile = fopen(filename,"w"); strncpy(logFilename,filename,sizeof(logFilename)); + if(oldLogFile != NULL){ + fprintf(logFile,"%s:sys:%d:Previous logfile %s\n",timeStamp,INFO,oldLogFile); + free(oldLogFile); + } free(filename); } } @@ -144,39 +158,6 @@ static void writeLog(char *logMessage) } } -/*----------------------------------------------------------------------------*/ -unsigned int logFilter(unsigned int severity, const char *subsystem) -{ - int status; - char buffer[1024]; - - if(logDisabled || logConfigured == 0){ - return 1; - } - - - /* - 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; -} /*=============================================================================*/ void formatSeverity(unsigned int severity, char *buffer, unsigned int bufferLength) { @@ -194,6 +175,99 @@ void formatSeverity(unsigned int severity, char *buffer, unsigned int bufferLeng } strncpy(buffer,severityText[severity-1],bufferLength); } +/*--------------------------------------------------------------------------------*/ +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 unsigned int subsystemFromText(const char *text) +{ + int i; + static const char *subText[] = {"sys", + "com", + "asquio", + "io", + "dev", + "par", + "notify", + "history", + "INVALID", + }; + + for(i = 0; i < MAXSUB; i++){ + if(strcmp(subText[i],text) == 0){ + return i; + } + } + return -1; +} +/*----------------------------------------------------------------------------*/ +void formatSubsystem(unsigned int sub, char *buffer, unsigned int bufferLength) +{ + static const char *subText[] = {"sys", + "com", + "asquio", + "io", + "dev", + "par", + "notify", + "history", + "INVALID", + }; + + if(sub > SPAR){ + sub = SINVALID; + } + strncpy(buffer,subText[sub],bufferLength); +} +/*----------------------------------------------------------------------------*/ +unsigned int logFilter(unsigned int severity, const char *subsystem) +{ + int status; + char buffer[1024]; + unsigned int sub; + + if(logDisabled || logConfigured == 0){ + return 1; + } + + + /* + If it is in the list of enabled subsystems, everything is logged + */ + sub = subsystemFromText(subsystem); + if(sub >= 0 && severity <= logEnabledArray[sub]){ + return 0; + } + + + /* + test against the global log level + */ + if(severity > globalLogLevel){ + return 1; + } + + return 0; +} + /*---------------------------------------------------------------------------- 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 @@ -251,7 +325,7 @@ void RemoveLogCallback(LogCallback func) } /*----------------------------------------------------------------------------*/ static void notifyListeners(unsigned int severity, const char *subsystem, - char *timeStamp, char *logData) + const char *timeStamp, char *logData) { int status; LogCBData lcb; @@ -264,22 +338,52 @@ static void notifyListeners(unsigned int severity, const char *subsystem, } } -/*----------------------------------------------------------------------------*/ -void Log(unsigned int severity, const char *subsystem,const char *format,...) +/*-------------------------------------------------------------------------------*/ +static void LogInternal(char *timeText, unsigned int severity, const char *subsystem, + char *logMessage) +{ + char severityTXT[60], logLine[3072], *fullMessage = NULL; + + checkLogFile(); + + formatSeverity(severity,severityTXT,sizeof(severityTXT)); + + notifyListeners(severity,subsystem,timeText, logMessage); + + + if(logFilter(severity,subsystem) == 1){ + return; + } + + fullMessage = formatLogLine(timeText,severityTXT,subsystem, + logMessage, logLine, sizeof(logLine)); + + writeLog(fullMessage); + + + /* + clean up + */ + if(fullMessage != logLine){ + free(fullMessage); + } + + +} +/*-------------------------------------------------------------------------------*/ +void LogIS(unsigned int severity, unsigned int subsystem,const char *format,...) { - char severityTXT[60]; char timeStamp[132]; - char logData[2024], logLine[3072], *pPtr = NULL; - char *dynMessage = NULL, *logMessage, *fullMessage = NULL; + char subText[30]; + char logData[2024], *logMessage = NULL; + char *dynMessage = NULL; va_list ap; int dataLength; - formatSeverity(severity,severityTXT,sizeof(severityTXT)); + formatSubsystem(subsystem,subText,sizeof(subText)); 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 @@ -299,89 +403,117 @@ void Log(unsigned int severity, const char *subsystem,const char *format,...) } } - notifyListeners(severity,subsystem,timeStamp, logMessage); + LogInternal(timeStamp, severity, subText,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) +/*-------------------------------------------------------------------------------*/ +void LogTS(const char *timeStamp, unsigned int severity, unsigned int subsystem,const char *format,...) { - 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; + char subText[30]; + char logData[2024], *logMessage = NULL; + char *dynMessage = NULL; + va_list ap; + int dataLength; + + + formatSubsystem(subsystem,subText,sizeof(subText)); + + /* + 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; } - sev++; } - sev++; /* starting at 1 rather then 0 */ - return sev; -} -/*------------------------------------------------------------------------------*/ -static void DisableSub(char *sub) -{ - int status; - char buffer[1024]; + + LogInternal((char *)timeStamp, severity, subText,logMessage); - status = LLDnodePtr2First(subList); - while (status == 1) { - LLDstringData(subList, buffer); - if(strcmp(buffer,sub) == 0) { - LLDstringDelete(subList); - } - status = LLDnodePtr2Next(subList); + + if(dynMessage != NULL){ + free(dynMessage); } + + +} +/*----------------------------------------------------------------------------*/ +void Log(unsigned int severity, const char *subsystem,const char *format,...) +{ + char timeStamp[132]; + char logData[2024], *logMessage = NULL; + char *dynMessage = NULL; + va_list ap; + int dataLength; + + + formatTimeStamp(timeStamp,sizeof(timeStamp),0); + + /* + 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; + } + } + + LogInternal(timeStamp, severity, subsystem,logMessage); + + + if(dynMessage != NULL){ + free(dynMessage); + } + + } /*------------------------------------------------------------------------------*/ static pDynString ListEnabled(void) { - int status; - char buffer[1024]; + int status, i; + char buffer[1024], sub[30], sev[30]; pDynString result = CreateDynString(64,64); if(result == NULL){ return NULL; } - - status = LLDnodePtr2First(subList); - while (status == 1) { - LLDstringData(subList, buffer); - DynStringConcat(result,buffer); + + for(i = 0; i < MAXSUB; i++){ + formatSeverity(logEnabledArray[i],sev,sizeof(sev)); + formatSubsystem(i,sub,sizeof(sub)); + DynStringConcat(result,sub); DynStringConcatChar(result,':'); - status = LLDnodePtr2Next(subList); + DynStringConcat(result,sev); + DynStringConcatChar(result,'\n'); } return result; } + /*============================================================================ The Interpreter Interface ==============================================================================*/ @@ -417,7 +549,7 @@ static int LogAction(SConnection * pCon, SicsInterp * pSics, static int LogConfigAction(SConnection * pCon, SicsInterp * pSics, void *pData, int argc, char *argv[]) { - unsigned int sev; + unsigned int sev, sub; char buffer[64]; pDynString result = NULL; @@ -470,7 +602,13 @@ static int LogConfigAction(SConnection * pCon, SicsInterp * pSics, SCWrite(pCon,"ERROR: subsystem name to long",eError); return 0; } - LLDstringAppend(subList,argv[2]); + sub = subsystemFromText(argv[2]); + if(sub >= 0){ + logEnabledArray[sub] = DEBUG; + } else { + SCPrintf(pCon,eError,"ERROR: invalid subsystem %s requested", argv[2]); + return 0; + } SCSendOK(pCon); } else { SCWrite(pCon,"ERROR: need subsystem argument for enable",eError); @@ -478,7 +616,12 @@ static int LogConfigAction(SConnection * pCon, SicsInterp * pSics, } }else if (strcmp(argv[1],"disable") == 0) { if(argc > 2){ - DisableSub(argv[2]); + sub = subsystemFromText(argv[2]); + if(sub >= 0){ + logEnabledArray[sub] = ERROR; + } else { + SCPrintf(pCon,eError,"ERROR: invalid subsystem %s requested", argv[2]); + } SCSendOK(pCon); } else { SCWrite(pCon,"ERROR: need subsystem argument for disable",eError); @@ -505,11 +648,16 @@ void DisableLog(void) /*-----------------------------------------------------------------------------*/ void Logv2Init(void) { - subList = LLDstringCreate(); - callbackList = LLDcreate(sizeof(LogCBData)); + int i; + + callbackList = LLDcreate(sizeof(LogCBData)); strcpy(logTemplate,"unconfiguredLogTemplate"); AddCmd("log", LogAction); AddCommand(pServ->pSics,"logconfig", LogConfigAction, LogClose, NULL); + + for(i = 0; i < MAXSUB; i++){ + logEnabledArray[i] = ERROR; + } } diff --git a/logv2.h b/logv2.h index ebd05881..fb60c6dd 100644 --- a/logv2.h +++ b/logv2.h @@ -12,6 +12,9 @@ #define __LOGV2 #include +/* + severity codes +*/ #define FATAL 1 #define ERROR 2 #define WARN 3 @@ -20,6 +23,23 @@ #define DEBUG 6 #define INVALID 7 /* internal olny, do not use, means invalid severity passed */ + +/* + subsystem codes +*/ +#define SSYS 0 +#define SCOM 1 +#define SASQIO 2 +#define SIO 3 +#define SDEV 4 +#define SPAR 5 +#define SNOTIFY 6 +#define SHISTORY 7 +#define SINVALID 8 + +#define MAXSUB 7 + + /* 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 @@ -28,6 +48,24 @@ */ void Log(unsigned int severity, const char *subsystem,const char *format,...); +/* write a log message, but with the subsystem specified by an integer + * \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 LogIS(unsigned int severity, unsigned int subsystem,const char *format,...); +/* write a log message, but with the subsystem specified by an integer and user supplied timestamp + * \param timeStamp A user supplied timestamp + * \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 LogTS(const char *timeStamp, unsigned int severity, unsigned int 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 @@ -82,4 +120,8 @@ void LogClose(void *data); void formatSeverity(unsigned int severity, char *buffer, unsigned int bufferLength); + +extern unsigned int logEnabledArray[]; +#define logEnabled(subsystem,severity) (severity <= logEnabledArray[subsystem]) + #endif diff --git a/network.c b/network.c index b77e382a..f0d75550 100644 --- a/network.c +++ b/network.c @@ -75,7 +75,7 @@ static void NetError(const char pText[]) severity = WARN; } - Log(severity,"IO","%s", pText); + Log(severity,"io","%s", pText); } /* ---------------------------- Local ------------------------------------