Made all sub systems for logging lower case

Log filtering is now based on an array of severitys per subsystem
Added a LogIS call which takes an integer for the subsystem
Added a LogTS call which allows to specify a user supplied time stamp
This commit is contained in:
2016-03-08 11:36:29 +01:00
parent 40382b2b8c
commit 5a388ab741
6 changed files with 347 additions and 152 deletions

View File

@ -81,7 +81,7 @@ int defaultPrepareTxn(pAsyncProtocol p, pAsyncTxn txn, const char *cmd,
/* outgoing command is correctly terminated */ /* outgoing command is correctly terminated */
txn->out_buf = malloc(cmd_len + 1); txn->out_buf = malloc(cmd_len + 1);
if (txn->out_buf == NULL) { 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; return 0;
} }
memcpy(txn->out_buf, cmd, cmd_len + 1); 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); int tlen = strlen(term);
txn->out_buf = malloc(cmd_len + tlen + 1); txn->out_buf = malloc(cmd_len + tlen + 1);
if (txn->out_buf == NULL) { 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); eError);
return 0; return 0;
} }
@ -173,7 +173,7 @@ static char *decodeTerminator(char *code)
count = strlen(code); count = strlen(code);
pResult = (char *) malloc(count + 1); pResult = (char *) malloc(count + 1);
if (!pResult) { if (!pResult) {
Log(ERROR,"ASQUIO","%s","Out of memory in AsyncProtocol::decodeTerminator", Log(ERROR,"asquio","%s","Out of memory in AsyncProtocol::decodeTerminator",
eError); eError);
return NULL; return NULL;
} }
@ -328,7 +328,7 @@ pAsyncProtocol AsyncProtocolCreate(SicsInterp * pSics,
self = (pAsyncProtocol) malloc(sizeof(AsyncProtocol)); self = (pAsyncProtocol) malloc(sizeof(AsyncProtocol));
if (self == NULL) { if (self == NULL) {
Log(ERROR,"ASQUIO","%s","Out of memory in AsyncProtocolCreate"); Log(ERROR,"asquio","%s","Out of memory in AsyncProtocolCreate");
return NULL; return NULL;
} }
memset(self, 0, sizeof(AsyncProtocol)); memset(self, 0, sizeof(AsyncProtocol));
@ -339,7 +339,7 @@ pAsyncProtocol AsyncProtocolCreate(SicsInterp * pSics,
pKFunc = AsyncProtocolKill; pKFunc = AsyncProtocolKill;
iRet = AddCommand(pSics, (char *) protocolName, pFunc, pKFunc, self); iRet = AddCommand(pSics, (char *) protocolName, pFunc, pKFunc, self);
if (!iRet) { if (!iRet) {
Log(ERROR,"ASQUIO","%s","AddCommand failed in AsyncProtocolCreate"); Log(ERROR,"asquio","%s","AddCommand failed in AsyncProtocolCreate");
AsyncProtocolKill(self); AsyncProtocolKill(self);
return NULL; return NULL;
} }

View File

@ -207,7 +207,7 @@ static void AQ_Notify(pAsyncQueue self, int event)
{ {
pAsyncUnit unit; pAsyncUnit unit;
if (self->state != eAsyncConnected) if (self->state != eAsyncConnected)
Log(DEBUG,"ASQUIO", "Function:%s:%s", self->queue_name, Log(DEBUG,"asquio", "Function:%s:%s", self->queue_name,
__func__); __func__);
for (unit = self->units; unit; unit = unit->next) for (unit = self->units; unit; unit = unit->next)
if (unit->notify_func != NULL) if (unit->notify_func != NULL)
@ -222,7 +222,7 @@ static int TimedReconnect(void *cntx, int mode)
self->nw_tmr = 0; self->nw_tmr = 0;
if (self->state != eAsyncConnected) 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__); __func__);
AQ_Purge(self); AQ_Purge(self);
@ -240,7 +240,7 @@ static int TimedReconnect(void *cntx, int mode)
if (iRet < 0) { if (iRet < 0) {
snprintf(line, 132, "Failed reconnect on AsyncQueue '%s'", snprintf(line, 132, "Failed reconnect on AsyncQueue '%s'",
self->queue_name); self->queue_name);
Log(DEBUG,"ASQUIO","%s",line); Log(DEBUG,"asquio","%s",line);
/* Timer for retry */ /* Timer for retry */
NetWatchSetMode(self->nw_ctx, 0); NetWatchSetMode(self->nw_ctx, 0);
/* implement an exponential backoff within limits */ /* implement an exponential backoff within limits */
@ -251,12 +251,12 @@ static int TimedReconnect(void *cntx, int mode)
self->retryTimer = 16000; self->retryTimer = 16000;
AQ_SetTimer(self, self->retryTimer, AQ_SetTimer(self, self->retryTimer,
TimedReconnect, self); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncWaiting; self->state = eAsyncWaiting;
} else { } else {
NetWatchSetMode(self->nw_ctx, nwatch_write); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncConnecting; self->state = eAsyncConnecting;
/* await reconnect result in MyCallback */ /* await reconnect result in MyCallback */
@ -264,11 +264,11 @@ static int TimedReconnect(void *cntx, int mode)
return 1; return 1;
} }
NetWatchSetMode(self->nw_ctx, nwatch_read); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncConnected; self->state = eAsyncConnected;
snprintf(line, 132, "Reconnect on AsyncQueue '%s'", self->queue_name); snprintf(line, 132, "Reconnect on AsyncQueue '%s'", self->queue_name);
Log(DEBUG,"ASQUIO","%s",line); Log(DEBUG,"asquio","%s",line);
AQ_Purge(self); AQ_Purge(self);
AQ_Notify(self, AQU_RECONNECT); AQ_Notify(self, AQU_RECONNECT);
return 1; return 1;
@ -280,7 +280,7 @@ static int AQ_Reconnect(pAsyncQueue self)
char line[132]; char line[132];
if (self->state != eAsyncConnected) 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__); __func__);
/* /*
* Remove any old timer * Remove any old timer
@ -290,7 +290,7 @@ static int AQ_Reconnect(pAsyncQueue self)
if (self->state == eAsyncConnected) { if (self->state == eAsyncConnected) {
self->state = eAsyncIdle; 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_Notify(self, AQU_DISCONNECT);
AQ_Purge(self); AQ_Purge(self);
} }
@ -310,12 +310,12 @@ static int AQ_Reconnect(pAsyncQueue self)
self->retryTimer = 125; /* initial delay */ self->retryTimer = 125; /* initial delay */
AQ_SetTimer(self, self->retryTimer, AQ_SetTimer(self, self->retryTimer,
TimedReconnect, self); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncWaiting; self->state = eAsyncWaiting;
} else { } else {
NetWatchSetMode(self->nw_ctx, nwatch_write); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncConnecting; self->state = eAsyncConnecting;
/* await reconnect result in MyCallback */ /* await reconnect result in MyCallback */
@ -323,11 +323,11 @@ static int AQ_Reconnect(pAsyncQueue self)
return iRet; return iRet;
} }
NetWatchSetMode(self->nw_ctx, nwatch_read); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncConnected; self->state = eAsyncConnected;
snprintf(line, 132, "Reconnect on AsyncQueue '%s'", self->queue_name); snprintf(line, 132, "Reconnect on AsyncQueue '%s'", self->queue_name);
Log(DEBUG,"ASQUIO",line); Log(DEBUG,"asquio",line);
AQ_Purge(self); AQ_Purge(self);
AQ_Notify(self, AQU_RECONNECT); AQ_Notify(self, AQU_RECONNECT);
return 1; return 1;
@ -344,7 +344,7 @@ static int StartCommand(pAsyncQueue self)
int iRet = 0; int iRet = 0;
if (self->state != eAsyncConnected) 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__); __func__);
if (myCmd == NULL) if (myCmd == NULL)
return OKOK; return OKOK;
@ -393,7 +393,7 @@ static int StartCommand(pAsyncQueue self)
} else if (iRet > 0) { } else if (iRet > 0) {
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); 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) { if (self->trace) {
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); 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) { if (myCmd->retries > 0) {
--myCmd->retries; --myCmd->retries;
@ -525,7 +525,7 @@ static int DelayedStart(void *cntx, int mode)
{ {
pAsyncQueue self = (pAsyncQueue) cntx; pAsyncQueue self = (pAsyncQueue) cntx;
if (self->state != eAsyncConnected) 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__); __func__);
self->nw_tmr = 0; self->nw_tmr = 0;
StartCommand(self); StartCommand(self);
@ -537,7 +537,7 @@ static int MyCallback(void *context, int mode)
pAsyncQueue self = (pAsyncQueue) context; pAsyncQueue self = (pAsyncQueue) context;
if (self->state != eAsyncConnected) 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__); __func__);
if (mode & nwatch_read) { if (mode & nwatch_read) {
int iRet; int iRet;
@ -567,7 +567,7 @@ static int MyCallback(void *context, int mode)
if (self->trace) { if (self->trace) {
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(INFO, "ASQUIO", Log(INFO, "asquio",
"Received:%s:%s", self->queue_name,myCmd->tran->inp_buf); "Received:%s:%s", self->queue_name,myCmd->tran->inp_buf);
} }
PopCommand(self); PopCommand(self);
@ -576,10 +576,10 @@ static int MyCallback(void *context, int mode)
int excess = nchars - 1 - i; int excess = nchars - 1 - i;
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(ERROR,"ASQUIO", Log(ERROR,"asquio",
"Protocol error %d in AsyncQueue %s", "Protocol error %d in AsyncQueue %s",
iRet, self->queue_name); 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; break;
} }
} }
@ -587,7 +587,7 @@ static int MyCallback(void *context, int mode)
int excess = nchars - 1 - i; int excess = nchars - 1 - i;
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); 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); excess, self->queue_name);
/* TODO: handle unsolicited */ /* TODO: handle unsolicited */
} }
@ -595,7 +595,7 @@ static int MyCallback(void *context, int mode)
int excess = nchars - 1 - i; int excess = nchars - 1 - i;
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); 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); excess, self->queue_name);
/* TODO: handle unsolicited input */ /* TODO: handle unsolicited input */
} }
@ -603,10 +603,10 @@ static int MyCallback(void *context, int mode)
} }
if (mode & nwatch_write) { if (mode & nwatch_write) {
char line[132]; char line[132];
Log(DEBUG,"ASQUIO", "Writeable socket callback on AsyncQueue %s", Log(DEBUG,"asquio", "Writeable socket callback on AsyncQueue %s",
self->queue_name); self->queue_name);
NetWatchSetMode(self->nw_ctx, nwatch_read); 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->queue_name, __func__, state_name(self->state));
self->state = eAsyncConnected; self->state = eAsyncConnected;
} }
@ -620,7 +620,7 @@ int AsyncUnitEnqueueHead(pAsyncUnit unit, pAsyncTxn context)
assert(unit && unit->queue && unit->queue->protocol); assert(unit && unit->queue && unit->queue->protocol);
myCmd = (pAQ_Cmd) malloc(sizeof(AQ_Cmd)); myCmd = (pAQ_Cmd) malloc(sizeof(AQ_Cmd));
if (myCmd == NULL) { if (myCmd == NULL) {
Log(ERROR,"ASQUIO","Out of memory in AsyncUnitEnqueHead", eError); Log(ERROR,"asquio","Out of memory in AsyncUnitEnqueHead", eError);
return 0; return 0;
} }
memset(myCmd, 0, sizeof(AQ_Cmd)); memset(myCmd, 0, sizeof(AQ_Cmd));
@ -639,7 +639,7 @@ int AsyncUnitEnqueueTxn(pAsyncUnit unit, pAsyncTxn pTxn)
assert(unit && unit->queue && unit->queue->protocol); assert(unit && unit->queue && unit->queue->protocol);
myCmd = (pAQ_Cmd) malloc(sizeof(AQ_Cmd)); myCmd = (pAQ_Cmd) malloc(sizeof(AQ_Cmd));
if (myCmd == NULL) { if (myCmd == NULL) {
Log(ERROR,"ASQUIO","%s","Out of memory in AsyncUnitEnqueueTxn"); Log(ERROR,"asquio","%s","Out of memory in AsyncUnitEnqueueTxn");
return 0; return 0;
} }
memset(myCmd, 0, sizeof(AQ_Cmd)); memset(myCmd, 0, sizeof(AQ_Cmd));
@ -661,7 +661,7 @@ pAsyncTxn AsyncUnitPrepareTxn(pAsyncUnit unit,
assert(unit); assert(unit);
myTxn = (pAsyncTxn) malloc(sizeof(AsyncTxn)); myTxn = (pAsyncTxn) malloc(sizeof(AsyncTxn));
if (myTxn == NULL) { 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; return NULL;
} }
memset(myTxn, 0, sizeof(AsyncTxn)); memset(myTxn, 0, sizeof(AsyncTxn));
@ -696,7 +696,7 @@ pAsyncTxn AsyncUnitPrepareTxn(pAsyncUnit unit,
} else { } else {
myTxn->out_buf = (char *) malloc(cmd_len + 5); myTxn->out_buf = (char *) malloc(cmd_len + 5);
if (myTxn->out_buf == NULL) { 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); free(myTxn);
return NULL; return NULL;
} }
@ -715,7 +715,7 @@ pAsyncTxn AsyncUnitPrepareTxn(pAsyncUnit unit,
else { else {
myTxn->inp_buf = malloc(rsp_len + 1); myTxn->inp_buf = malloc(rsp_len + 1);
if (myTxn->inp_buf == NULL) { 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->out_buf);
free(myTxn); free(myTxn);
return NULL; return NULL;
@ -813,7 +813,7 @@ int AsyncUnitWrite(pAsyncUnit unit, void *buffer, int buflen)
if (unit->queue->trace) { if (unit->queue->trace) {
struct timeval tv; struct timeval tv;
gettimeofday(&tv, NULL); gettimeofday(&tv, NULL);
Log(DEBUG,"ASQUIO" Log(DEBUG,"asquio"
"Output Trace on AsyncQueue %s:%s", unit->queue->queue_name, buffer); "Output Trace on AsyncQueue %s:%s", unit->queue->queue_name, buffer);
} }
sock = AsyncUnitGetSocket(unit); sock = AsyncUnitGetSocket(unit);
@ -1380,7 +1380,7 @@ int AsyncUnitCreateHost(const char *host, const char *port,
unit = (pAsyncUnit) malloc(sizeof(AsyncUnit)); unit = (pAsyncUnit) malloc(sizeof(AsyncUnit));
if (unit == NULL) { 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; *handle = NULL;
return 0; return 0;
} }

View File

@ -829,7 +829,7 @@ static void testAndWriteLog(SConnection * self, char *buffer, int iOut)
Log(ERROR,"dev","%s",buffer); Log(ERROR,"dev","%s",buffer);
break; break;
case eStatus: case eStatus:
Log(DEBUG,"IO","%s",buffer); Log(DEBUG,"io","%s",buffer);
break; break;
case eEvent: case eEvent:
if(strstr(buffer,"ERROR") != NULL){ if(strstr(buffer,"ERROR") != NULL){
@ -1707,11 +1707,16 @@ int SCInvoke(SConnection * self, SicsInterp * pInter, char *pCommand)
return 0; return 0;
} }
strlcpy(pCopy->deviceID, pBueffel, SCDEVIDLEN); strlcpy(pCopy->deviceID, pBueffel, SCDEVIDLEN);
/*
do not log the log command; defeats log control
*/
if(strstr(pCommand,"log ") == NULL) {
if(SCGetRights(self) > usUser){ if(SCGetRights(self) > usUser){
Log(DEBUG,"com","%s:in:%s", ConID(self),pCommand); Log(DEBUG,"com","%s:in:%s", ConID(self),pCommand);
} else { } else {
Log(INFO,"com", "%s:in:%s", ConID(self),pCommand); Log(INFO,"com", "%s:in:%s", ConID(self),pCommand);
} }
}
iRet = InterpExecute(pInter, pCopy, pCommand); iRet = InterpExecute(pInter, pCopy, pCommand);
SCDeleteConnection(pCopy); SCDeleteConnection(pCopy);
StatusFileTask(NULL); /* save changed parameters */ StatusFileTask(NULL); /* save changed parameters */

342
logv2.c
View File

@ -28,9 +28,11 @@ static unsigned int logDisabled = 0;
static int unsigned logConfigured = 0; static int unsigned logConfigured = 0;
/*================ The default log level =======================================*/ /*================ 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 ==========*/ /*========= The list of sub systems for which full logging is enabled ==========*/
static int subList; unsigned int logEnabledArray[MAXSUB ];
/*================== Callback management =======================================*/ /*================== Callback management =======================================*/
typedef struct { typedef struct {
LogCallback func; LogCallback func;
@ -94,6 +96,8 @@ void LogClose(void *data)
static void checkLogFile(void) static void checkLogFile(void)
{ {
char *filename = NULL; char *filename = NULL;
char *oldLogFile = NULL;
char timeStamp[132];
if(logDisabled || logConfigured == 0){ if(logDisabled || logConfigured == 0){
return; return;
@ -103,6 +107,10 @@ static void checkLogFile(void)
close when full close when full
*/ */
if(logFile != NULL && lineCount >= MAXFILELINES){ 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); LogClose(NULL);
} }
@ -110,10 +118,16 @@ static void checkLogFile(void)
start a new log file start a new log file
*/ */
if(logFile == NULL){ if(logFile == NULL){
if(filename == NULL){
filename = makeLogFileName(); filename = makeLogFileName();
}
if(filename != NULL){ if(filename != NULL){
logFile = fopen(filename,"w"); logFile = fopen(filename,"w");
strncpy(logFilename,filename,sizeof(logFilename)); strncpy(logFilename,filename,sizeof(logFilename));
if(oldLogFile != NULL){
fprintf(logFile,"%s:sys:%d:Previous logfile %s\n",timeStamp,INFO,oldLogFile);
free(oldLogFile);
}
free(filename); 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) 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); 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 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 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, static void notifyListeners(unsigned int severity, const char *subsystem,
char *timeStamp, char *logData) const char *timeStamp, char *logData)
{ {
int status; int status;
LogCBData lcb; 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 timeStamp[132];
char logData[2024], logLine[3072], *pPtr = NULL; char subText[30];
char *dynMessage = NULL, *logMessage, *fullMessage = NULL; char logData[2024], *logMessage = NULL;
char *dynMessage = NULL;
va_list ap; va_list ap;
int dataLength; int dataLength;
formatSeverity(severity,severityTXT,sizeof(severityTXT)); formatSubsystem(subsystem,subText,sizeof(subText));
formatTimeStamp(timeStamp,sizeof(timeStamp),0); formatTimeStamp(timeStamp,sizeof(timeStamp),0);
checkLogFile();
/* /*
If we have enough space put the logData into our generous buffer. Else 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 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){ if(dynMessage != NULL){
free(dynMessage); free(dynMessage);
} }
return;
} }
/*-------------------------------------------------------------------------------*/
void LogTS(const char *timeStamp, unsigned int severity, unsigned int subsystem,const char *format,...)
{
char subText[30];
char logData[2024], *logMessage = NULL;
char *dynMessage = NULL;
va_list ap;
int dataLength;
fullMessage = formatLogLine(timeStamp,severityTXT,subsystem,
logMessage, logLine, sizeof(logLine));
writeLog(fullMessage);
formatSubsystem(subsystem,subText,sizeof(subText));
/* /*
clean up 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((char *)timeStamp, severity, subText,logMessage);
if(dynMessage != NULL){ if(dynMessage != NULL){
free(dynMessage); free(dynMessage);
} }
if(fullMessage != logLine){
free(fullMessage);
}
} }
/*--------------------------------------------------------------------------------*/ /*----------------------------------------------------------------------------*/
static unsigned int sevFromText(const char *txt) void Log(unsigned int severity, const char *subsystem,const char *format,...)
{ {
static const char *severityText[] = {"fatal", char timeStamp[132];
"error", char logData[2024], *logMessage = NULL;
"warn", char *dynMessage = NULL;
"info", va_list ap;
"verbose", int dataLength;
"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) { formatTimeStamp(timeStamp,sizeof(timeStamp),0);
LLDstringData(subList, buffer);
if(strcmp(buffer,sub) == 0) { /*
LLDstringDelete(subList); 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;
} }
status = LLDnodePtr2Next(subList);
} }
LogInternal(timeStamp, severity, subsystem,logMessage);
if(dynMessage != NULL){
free(dynMessage);
}
} }
/*------------------------------------------------------------------------------*/ /*------------------------------------------------------------------------------*/
static pDynString ListEnabled(void) static pDynString ListEnabled(void)
{ {
int status; int status, i;
char buffer[1024]; char buffer[1024], sub[30], sev[30];
pDynString result = CreateDynString(64,64); pDynString result = CreateDynString(64,64);
if(result == NULL){ if(result == NULL){
return NULL; return NULL;
} }
status = LLDnodePtr2First(subList); for(i = 0; i < MAXSUB; i++){
while (status == 1) { formatSeverity(logEnabledArray[i],sev,sizeof(sev));
LLDstringData(subList, buffer); formatSubsystem(i,sub,sizeof(sub));
DynStringConcat(result,buffer); DynStringConcat(result,sub);
DynStringConcatChar(result,':'); DynStringConcatChar(result,':');
status = LLDnodePtr2Next(subList); DynStringConcat(result,sev);
DynStringConcatChar(result,'\n');
} }
return result; return result;
} }
/*============================================================================ /*============================================================================
The Interpreter Interface The Interpreter Interface
==============================================================================*/ ==============================================================================*/
@ -417,7 +549,7 @@ static int LogAction(SConnection * pCon, SicsInterp * pSics,
static int LogConfigAction(SConnection * pCon, SicsInterp * pSics, static int LogConfigAction(SConnection * pCon, SicsInterp * pSics,
void *pData, int argc, char *argv[]) void *pData, int argc, char *argv[])
{ {
unsigned int sev; unsigned int sev, sub;
char buffer[64]; char buffer[64];
pDynString result = NULL; pDynString result = NULL;
@ -470,7 +602,13 @@ static int LogConfigAction(SConnection * pCon, SicsInterp * pSics,
SCWrite(pCon,"ERROR: subsystem name to long",eError); SCWrite(pCon,"ERROR: subsystem name to long",eError);
return 0; 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); SCSendOK(pCon);
} else { } else {
SCWrite(pCon,"ERROR: need subsystem argument for enable",eError); 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) { }else if (strcmp(argv[1],"disable") == 0) {
if(argc > 2){ 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); SCSendOK(pCon);
} else { } else {
SCWrite(pCon,"ERROR: need subsystem argument for disable",eError); SCWrite(pCon,"ERROR: need subsystem argument for disable",eError);
@ -505,11 +648,16 @@ void DisableLog(void)
/*-----------------------------------------------------------------------------*/ /*-----------------------------------------------------------------------------*/
void Logv2Init(void) void Logv2Init(void)
{ {
subList = LLDstringCreate(); int i;
callbackList = LLDcreate(sizeof(LogCBData)); callbackList = LLDcreate(sizeof(LogCBData));
strcpy(logTemplate,"unconfiguredLogTemplate"); strcpy(logTemplate,"unconfiguredLogTemplate");
AddCmd("log", LogAction); AddCmd("log", LogAction);
AddCommand(pServ->pSics,"logconfig", LogConfigAction, AddCommand(pServ->pSics,"logconfig", LogConfigAction,
LogClose, NULL); LogClose, NULL);
for(i = 0; i < MAXSUB; i++){
logEnabledArray[i] = ERROR;
}
} }

42
logv2.h
View File

@ -12,6 +12,9 @@
#define __LOGV2 #define __LOGV2
#include <stdarg.h> #include <stdarg.h>
/*
severity codes
*/
#define FATAL 1 #define FATAL 1
#define ERROR 2 #define ERROR 2
#define WARN 3 #define WARN 3
@ -20,6 +23,23 @@
#define DEBUG 6 #define DEBUG 6
#define INVALID 7 /* internal olny, do not use, means invalid severity passed */ #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 /* write a log message
* \param severity The message severity. Must be one of the defines given above * \param severity The message severity. Must be one of the defines given above
* \param subsystem The subsystem reporting the log messages * \param subsystem The subsystem reporting the log messages
@ -28,6 +48,24 @@
*/ */
void Log(unsigned int severity, const char *subsystem,const char *format,...); 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 /* The callback functio which is called by the logging system on log events
* \param severity The message severity * \param severity The message severity
* \param timeStamp The time stamp of the log message * \param timeStamp The time stamp of the log message
@ -82,4 +120,8 @@ void LogClose(void *data);
void formatSeverity(unsigned int severity, void formatSeverity(unsigned int severity,
char *buffer, unsigned int bufferLength); char *buffer, unsigned int bufferLength);
extern unsigned int logEnabledArray[];
#define logEnabled(subsystem,severity) (severity <= logEnabledArray[subsystem])
#endif #endif

View File

@ -75,7 +75,7 @@ static void NetError(const char pText[])
severity = WARN; severity = WARN;
} }
Log(severity,"IO","%s", pText); Log(severity,"io","%s", pText);
} }
/* ---------------------------- Local ------------------------------------ /* ---------------------------- Local ------------------------------------