/** * This is a means to listen into the stream of log messages from the logv2 * logging system. * * Mark Koennecke, May 2016 * * added more useful stuff like the old "config listen" and "commandlog tail" * features. Markus Zolliker April 2017 */ #include #include #include #include #include #include /* From logv2.c */ extern int subsystemFromText(const char *text); /*=============================================================================*/ static int listenerList; static int callbackRegistered = 0; typedef struct { SConnection *pCon; char subsystem[64]; } ListenEntry; /*-----------------------------------------------------------------------------*/ /* NEW STUFF */ static int newCallbackRegistered = 0; static char timestampMode = 'h'; typedef struct ListenerItem_s { struct ListenerItem_s *next; SConnection *pCon; } ListenerItem; ListenerItem *listeners = NULL; typedef struct { int len; int pos; int size; char **history; } Commandlog; static Commandlog *commandlog = NULL; /*-----------------------------------------------------------------------------*/ Commandlog *CommandlogMake(int size) { Commandlog *c; int i; c = malloc(sizeof(*commandlog)); if (c) { c->size = size; c->pos = 0; c->len = 0; c->history = calloc(size, sizeof(char *)); if (!c->history) { free(c); return NULL; } for (i = 0; i < size; i++) { c->history[i] = NULL; } } return c; } /*-----------------------------------------------------------------------------*/ void CommandlogFree(Commandlog *c) { int i; for (i = 0; i < c->size; i++) { if (c->history[i]) free(c->history[i]); } free(c->history); free(c); } /*-----------------------------------------------------------------------------*/ void CommandlogAdd(Commandlog *c, char *line) { int l=strlen(line); line = strdup(line); if (l > 0 && line[l-1] == '\n') { line[l-1] = 0; } if (c->len < c->size) { c->len++; } if (c->history[c->pos]) free(c->history[c->pos]); c->history[c->pos] = line; c->pos++; if (c->pos >= c->size) c->pos = 0; } /*-----------------------------------------------------------------------------*/ char *CommandlogTail(Commandlog *c, int maxlen) { int len; pDynString dyn = CreateDynString(1000,1000); int pos; if (maxlen > c->len) { maxlen = c->len; } pos = c->pos - maxlen; if (pos < 0) { pos += c->size; } for (len = maxlen; len > 0; len--) { if (c->history[pos]) { DynStringConcat(dyn, c->history[pos]); DynStringConcatChar(dyn , '\n'); } pos++; if (pos >= c->size) pos = 0; } return Dyn2Cstring(dyn); } /*-----------------------------------------------------------------------------*/ int AnalyzeCommand(char *command) { /* guess if a command does modify anything. returns 1 if yes, 0 else */ int writable = 1; CONST char * CONST *argv; char *endptr; int argc; int arg0; pObjectDescriptor pDes; Tcl_SplitList(NULL, command, &argc, &argv); arg0 = 0; if (argc > 0 && (strcasecmp(argv[0], "fulltransact") == 0 || strcasecmp(argv[0], "transact") == 0)) { arg0 = 1; } if (argc <= arg0 + 1) { writable = 0; /* single word -> guess read only */ goto Free; } if (strcmp(argv[arg0], "hval") == 0 || strcmp(argv[arg0], "sicsdescriptor") == 0 || strcmp(argv[arg0], "_tcl") == 0) { writable = 0; goto Free; } pDes = FindCommandDescriptor(pServ->pSics, argv[arg0]); if (pDes == NULL) goto Free; if (pDes->parNode == NULL && GetDescriptorKey(pDes, "pardef") == NULL) goto Free; if (argc == arg0 + 2) { strtof(argv[arg0+1], &endptr); if (endptr == argv[arg0+1]) { /* second word of two is not a number */ writable = 0; } } Free: Tcl_Free((char *)argv); return writable; } /*-----------------------------------------------------------------------------*/ static void LogListenCallbackNew( unsigned int severity, const char *timeStamp, const char *subsystem, const char *message, void *userData) { ListenerItem *item, **endp; char *command = NULL; int sockHandle; static char lastDate[12]="", lastTime[24]=""; static int lastHandle=0; static int readonlySocket = 0; char buffer[80]; char conn[12]; static char lastTag=0; int lcmp; if (strncmp(timeStamp, lastDate, 10) != 0) { /* force new log file at midnight */ if (lastDate[0] != 0) { LogClose(NULL); } strncpy(lastDate, timeStamp, 10); lastDate[10] = 0; } if (severity <= INFO) { if (strcmp(subsystem, "com") == 0) { command = strstr((char *)message, "sock"); if (command) { sockHandle = atoi(command+4); if (command == message) { /* it is a response */ command = strchr(command, ':'); if (command) { command++; if (*command == 0) command = NULL; } if (command && sockHandle != readonlySocket) { readonlySocket = 0; } } else { /* it is a command */ command = strstr(command, ":in:"); if (command) { command += 4; if (*command == 0) command = NULL; } if (command) { if (AnalyzeCommand(command)) { readonlySocket = 0; } else { readonlySocket = sockHandle; /* do not show commands probably not changing anything */ } } } } if (command && sockHandle != readonlySocket) { /* do not show commands probably not changing anything */ switch (tolower(timestampMode)) { case 'h': lcmp = 13; break; case 'm': lcmp = 16; break; case 's': lcmp = 19; break; default: lcmp = 10; break; } if (strncmp(timeStamp, lastTime, lcmp) != 0 || (sockHandle >=0 && sockHandle != lastHandle)) { /* make a timestamp for every changed socket and at least all 10 mins. */ strncpy(lastTime, timeStamp, 19); lastTime[19] = 0; if (sockHandle >= 0) lastHandle = sockHandle; if (sockHandle > 0) { snprintf(conn, sizeof conn, " con%d", sockHandle); } else { conn[0] = 0; } snprintf(buffer, sizeof buffer, "=== %.10s %.2s:%.2s:%.2s ===%s", lastTime, lastTime+11, lastTime+14, lastTime+17, conn); if (commandlog) { CommandlogAdd(commandlog, buffer); } } else { buffer[0] = 0; } if (commandlog) { CommandlogAdd(commandlog, command); } endp = &listeners; item = listeners; while (item) { if (item->pCon && SCisConnected(item->pCon)) { if (item->pCon->listening) { if (buffer[0]) { SCPureSockWrite(item->pCon, buffer, eValue); } if (item->pCon->sockHandle != sockHandle) { SCPureSockWrite(item->pCon, (char *)command, eValue); } } endp = &item->next; } else { SCDeleteConnection(item->pCon); *endp = item->next; free(item); } item = *endp; } } } } } /*-----------------------------------------------------------------------------*/ ListenerItem *LogListenRegister(SConnection * pCon) { ListenerItem *item; /* find registered */ for (item = listeners; item != NULL; item=item->next) { if (item->pCon->sockHandle == pCon->sockHandle) { item->pCon->listening = pCon->listening; return item; } } item = malloc(sizeof *item); if (!item) return NULL; item->next = listeners; item->pCon = SCCopyConnection(pCon); listeners = item; if(!newCallbackRegistered){ RegisterLogCallback(LogListenCallbackNew,NULL); newCallbackRegistered = 1; } return item; } /* old stuff */ /*-----------------------------------------------------------------------------*/ static void LogListenCallback(unsigned int severity, const char *timeStamp, const char *subsystem, const char *message, void *userData) { ListenEntry current; int status, cleanupNeeded = 0; if(logFilter(severity,subsystem,message) == 1) { return; } status = LLDnodePtr2First(listenerList); while(status != 0){ LLDnodeDataTo(listenerList,¤t); if(strcmp(current.subsystem,subsystem) == 0) { if(SCisConnected(current.pCon)){ SCPureSockWrite(current.pCon,(char *)message,eValue); } else { cleanupNeeded = 1; } } status = LLDnodePtr2Next(listenerList); } /* lld lists sometimes get confused when deleting nodes on the fly. This is why this has been put into a separate loop */ if(cleanupNeeded){ status = LLDnodePtr2First(listenerList); while(status != 0){ LLDnodeDataTo(listenerList,¤t); if(!SCisConnected(current.pCon)){ SCDeleteConnection(current.pCon); LLDnodeDelete(listenerList); } status = LLDnodePtr2Next(listenerList); } } } /* modified stuff */ /*-----------------------------------------------------------------------------*/ static int LogListenAction(SConnection * pCon, SicsInterp * pSics, void *pData, int argc, char *argv[]) { ListenEntry listLog, current; int status; pDynString dyn; int size; char *tail; if (argc < 2) goto Error; if (strcmp(argv[1], "1") == 0) { pCon->listening = 1; LogListenRegister(pCon); SCSendOK(pCon); return 1; } if (strcmp(argv[1], "0") == 0) { pCon->listening = 0; LogListenRegister(pCon); SCSendOK(pCon); return 1; } if (strcmp(argv[1], "commandlog") == 0) { if(!newCallbackRegistered){ RegisterLogCallback(LogListenCallbackNew,NULL); newCallbackRegistered = 1; } if (commandlog) CommandlogFree(commandlog); if (argc >= 3) { size = atoi(argv[2]); } else { size = 1000; } commandlog = CommandlogMake(size); SCSendOK(pCon); return 1; } if (strcmp(argv[1], "tail") == 0) { if (commandlog) { if (argc >= 3) { size = atoi(argv[2]); } else { size = commandlog->size; } tail = CommandlogTail(commandlog, size); SCDoSockWrite(pCon,tail); free(tail); } else { SCWrite(pCon,"ERROR: commandlog not initialized",eError); } return 1; } if (strcmp(argv[1], "timestamps") == 0) { /* LogListenRegister(pCon); */ if (argc > 2) { timestampMode = argv[2][0]; } SCPrintf(pCon, eValue, "loglisten timestamps = %c", timestampMode); return 1; } if (subsystemFromText(argv[1]) < 0){ strncpy(listLog.subsystem,argv[1],sizeof(listLog.subsystem)); listLog.pCon = SCCopyConnection(pCon); strncpy(listLog.subsystem,argv[1],sizeof(listLog.subsystem)); LLDnodeAppendFrom(listenerList,&listLog); if(!callbackRegistered){ RegisterLogCallback(LogListenCallback,NULL); callbackRegistered = 1; } SCSendOK(pCon); return 1; } Error: SCPrintf(pCon,eError, "ERROR: Usage:"); SCPrintf(pCon,eError, "ERROR: loglisten 1 | 0 "); SCPrintf(pCon,eError, "ERROR: loglisten "); SCPrintf(pCon,eError, "ERROR: loglisten commandlog "); SCPrintf(pCon,eError, "ERROR: loglisten tail "); SCPrintf(pCon,eError, "ERROR: loglisten timestamps d | h | m | s"); return 0; } /*-----------------------------------------------------------------------------*/ void LogListenInit(void) { listenerList = LLDcreate(sizeof(ListenEntry)); AddCmd("loglisten", LogListenAction); }