ZSS Logging Improvements

c/logging.c

@@ -26,7 +26,7 @@
 #include <string.h>
 #include <stdarg.h>
 #include <sys/stat.h>
-
+#include <time.h>
 #endif
 
 #include "zowetypes.h"
@@ -457,29 +457,119 @@ LoggingDestination *logConfigureDestination2(LoggingContext *context,
   return destination;
 }
 
-void printStdout(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList){
+static char *logLevelToString(int level) {
+  switch (level) {
+    case ZOWE_LOG_SEVERE: return "severe";
+    case ZOWE_LOG_WARNING: return "warning";
+    case ZOWE_LOG_INFO: return "info";
+    case ZOWE_LOG_DEBUG: return "debug";
+    case ZOWE_LOG_DEBUG2: return "debug";
+    case ZOWE_LOG_DEBUG3: return "debug";
+    default: return "";
+  }
+}
+
+static void getCurrentTime(char *timeStamp, unsigned int timeStampSize) {
+  ISOTime isoTime = {0};
+  time_t unixTime = time(NULL);
+  convertUnixToISO((int) unixTime, &isoTime);
+  strncpy(timeStamp, isoTime.data, timeStampSize);
+}
+
+static void prependMetadata(int logLevel,
+                            char *fullMessage,
+                            unsigned int fullMessageSize,
+                            char *formatString,
+                            va_list argList,
+                            char *fileName,
+                            char *functionName,
+                            unsigned int lineNumber) {
+  char time[64] = {0};
+  getCurrentTime((char *) &time, sizeof(time));
+  char message[256] = {0};
+  vsnprintf(message, sizeof(message), formatString, argList);
+  pthread_t pThread = pthread_self();
+  if (!fileName || !functionName || lineNumber == 0) {
+    snprintf(fullMessage,
+            fullMessageSize,
+            "<%s|tcb=%p|thread=%d|pid=%d|%s>: %s",
+            time,
+            getTCB(),
+            &pThread,
+            getpid(),
+            logLevelToString(logLevel),
+            message);
+  } else {
+    snprintf(fullMessage,
+             fullMessageSize,
+             "<%s|tcb=%p|thread=%d|pid=%d|%s:%s():%d|%s>: %s",
+             time,
+             getTCB(),
+             &pThread,
+             getpid(),
+             basename(fileName),
+             functionName,
+             lineNumber,
+             logLevelToString(logLevel),
+             message);
+  }
+}
+
+void printToLog(FILE *destination,
+                char *formatString,
+                va_list argList,
+                int logLevel,
+                char *fileName,
+                char *functionName,
+                unsigned int lineNumber) {
 #ifdef METTLE 
   printf("broken printf in logging.c\n");
-#else 
-  vfprintf(stdout,formatString,argList);
+#else
+  char fullMessage[1024] = {0};
+  prependMetadata(logLevel, (char *) &fullMessage, sizeof(fullMessage), formatString, argList, fileName, functionName, lineNumber);
+  fprintf(destination, "%s\n", fullMessage);
 #endif
 }
 
+void printStdout2(LoggingContext *context,
+                  LoggingComponent *component,
+                  void *data,
+                  char *formatString,
+                  va_list argList,
+                  int logLevel,
+                  char *fileName,
+                  char *functionName,
+                  unsigned int lineNumber) {
+  printToLog(stdout, formatString, argList, logLevel, fileName, functionName, lineNumber);
+}
+
+void printStdout(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList){
+  printStdout2(context, component, data, formatString, argList, ZOWE_LOG_NA, "", "", 0);
+}
+
+void printStderr2(LoggingContext *context,
+                  LoggingComponent *component,
+                  void *data,
+                  char *formatString,
+                  va_list argList,
+                  int logLevel,
+                  char *fileName,
+                  char *functionName,
+                  unsigned int lineNumber) {
+  printToLog(stderr, formatString, argList, logLevel, fileName, functionName, lineNumber);
+}
+
 void printStderr(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList){
-#ifdef METTLE 
-  printf("broken printf in logging.c\n");
-#else 
-  vfprintf(stderr,formatString,argList);
-#endif
+  printStderr2(context, component, data, formatString, argList, ZOWE_LOG_NA, "", "", 0);
 }
 
 void logConfigureStandardDestinations(LoggingContext *context){
   if (context == NULL) {
     context = getLoggingContext();
   }
   logConfigureDestination(context,LOG_DEST_DEV_NULL,"/dev/null",NULL,NULL);
-  logConfigureDestination(context,LOG_DEST_PRINTF_STDOUT,"printf(stdout)",NULL,printStdout);
-  logConfigureDestination(context,LOG_DEST_PRINTF_STDERR,"printf(stderr)",NULL,printStderr);
+  logConfigureDestination(context,LOG_DEST_PRINTF_STDOUT,"printf(stdout)",NULL,printStdout2);
+  logConfigureDestination(context,LOG_DEST_PRINTF_STDERR,"printf(stderr)",NULL,printStderr2);
 }
 
 void logConfigureComponent(LoggingContext *context, uint64 compID, char *compName, int destination, int level){
@@ -649,7 +739,14 @@ int logGetLevel(LoggingContext *context, uint64 compID){
   return component ? component->currentDetailLevel : ZOWE_LOG_NA;
 }
 
-void zowelog(LoggingContext *context, uint64 compID, int level, char *formatString, ...){
+void zowelogInner(LoggingContext *context,
+                  uint64 compID,
+                  int level,
+                  char *fileName,
+                  char *functionName,
+                  unsigned int lineNumber,
+                  char *formatString,
+                  va_list argPointer) {
 
   if (logShouldTrace(context, compID, level) == FALSE) {
     return;
@@ -666,8 +763,6 @@ void zowelog(LoggingContext *context, uint64 compID, int level, char *formatStri
   }
 
   if (maxDetailLevel >= level){
-    va_list argPointer;
-
     LoggingDestination *destination = &getDestinationTable(context, compID)[component->destination];
 //    printf("log.2 comp.dest=%d\n",component->destination);fflush(stdout);
     if (component->destination >= MAX_LOGGING_DESTINATIONS){
@@ -687,27 +782,44 @@ void zowelog(LoggingContext *context, uint64 compID, int level, char *formatStri
       lastResortLog(message);
       return;
     }
-    /* here, pass to a var-args handler */
-    va_start(argPointer, formatString);
-
-    destination->handler(context,component,destination->data,formatString,argPointer);
-
-    va_end(argPointer);
+    destination->handler(context,component,destination->data,formatString,argPointer,level,fileName,functionName,lineNumber);
   }
+}
+
+void zowelog2(LoggingContext *context, uint64 compID, int level, char *fileName, char *functionName, unsigned int lineNumber, char *formatString, ...) {
+  va_list argPointer;
+  va_start(argPointer, formatString);
+  zowelogInner(context, compID, level, fileName, functionName, lineNumber, formatString, argPointer);
+  va_end(argPointer);
+}
 
+void zowelog(LoggingContext *context, uint64 compID, int level, char *formatString, ...){
+  va_list argPointer;
+  va_start(argPointer, formatString);
+  zowelogInner(context, compID, level, "", "", 0, formatString, argPointer);
+  va_end(argPointer);
 }
 
 static void printToDestination(LoggingDestination *destination,
                                struct LoggingContext_tag *context,
                                LoggingComponent *component,
+                               int level, char *fileName,
+                               char *functionName, unsigned int lineNumber,
                                void *data, char *formatString, ...){
   va_list argPointer;
   va_start(argPointer, formatString);
-  destination->handler(context,component,destination->data,formatString,argPointer);
+  destination->handler(context,component,destination->data,formatString,argPointer,level,fileName,functionName,lineNumber);
   va_end(argPointer);
 }
 
-void zowedump(LoggingContext *context, uint64 compID, int level, void *data, int dataSize){
+void zowedumpInner(LoggingContext *context,
+                   uint64 compID,
+                   int level,
+                   void *data,
+                   int dataSize,
+                   char *fileName,
+                   char *functionName,
+                   unsigned int lineNumber) {
 
   if (logShouldTrace(context, compID, level) == FALSE) {
     return;
@@ -748,15 +860,22 @@ void zowedump(LoggingContext *context, uint64 compID, int level, void *data, int
     for (int i = 0; ; i++){
       char *result = destination->dumper(workBuffer, sizeof(workBuffer), data, dataSize, i);
       if (result != NULL){
-        printToDestination(destination, context, component, destination->data, "%s\n", result);
+        printToDestination(destination, context, component, level, fileName, functionName, lineNumber, destination->data, "%s\n", result);
       }
       else {
         break;
       }
     }
 
   }
+}
+
+void zowedump2(LoggingContext *context, uint64 compID, int level, void *data, int dataSize, char *fileName, char *functionName, unsigned int lineNumber) {
+  zowedumpInner(context, compID, level, data, dataSize, fileName, functionName, lineNumber);
+}
 
+void zowedump(LoggingContext *context, uint64 compID, int level, void *data, int dataSize){
+  zowedumpInner(context, compID, level, data, dataSize, "", "", 0);
 }
 
 bool logShouldTraceInternal(LoggingContext *context, uint64 componentID, int level) {

h/logging.h

@@ -22,6 +22,30 @@
 #include "collections.h"
 #include "le.h"
 
+#define ZOWELOG_SEVERE($id, $fmt, ...) \
+  zowelog2(NULL, $id, ZOWE_LOG_SEVERE, \
+          ___FILE__, __FUNCTION__, __LINE__, $fmt, ##__VA_ARGS__)
+
+#define ZOWELOG_WARNING($id, $fmt, ...) \
+  zowelog2(NULL, $id, ZOWE_LOG_WARNING, \
+          ___FILE__, __FUNCTION__, __LINE__, $fmt, ##__VA_ARGS__)
+
+#define ZOWELOG_INFO($id, $fmt, ...) \
+  zowelog2(NULL, $id, ZOWE_LOG_INFO, \
+          ___FILE__, __FUNCTION__, __LINE__, $fmt, ##__VA_ARGS__)
+
+#define ZOWELOG_DEBUG($id, $fmt, ...) \
+  zowelog2(NULL, $id, ZOWE_LOG_DEBUG, \
+          ___FILE__, __FUNCTION__, __LINE__, $fmt, ##__VA_ARGS__)
+
+#define ZOWELOG_DEBUG2($id, $fmt, ...) \
+  zowelog2(NULL, $id, ZOWE_LOG_DEBUG2, \
+          ___FILE__, __FUNCTION__, __LINE__, $fmt, ##__VA_ARGS__)
+
+#define ZOWELOG_DEBUG3($id, $fmt, ...) \
+  zowelog2(NULL, $id, ZOWE_LOG_DEBUG3, \
+          ___FILE__, __FUNCTION__, __LINE__, $fmt, ##__VA_ARGS__)
+
 /** \file
  *  \brief logging.h defines a platform-independent logging facility that echoes some of Java logging.
  *  
@@ -135,7 +159,11 @@ typedef void (*LogHandler)(struct LoggingContext_tag *context,
                            LoggingComponent *component, 
                            void *data, 
                            char *formatString,
-                           va_list argList);
+                           va_list argList,
+                           int logLevel,
+                           char *fileName,
+                           char *functionName,
+                           unsigned int lineNumber);
 typedef char *(*DataDumper)(char *workBuffer, int workBufferSize, void *data, int dataSize, int lineNumber);
 
 ZOWE_PRAGMA_PACK
@@ -369,7 +397,9 @@ extern int logSetExternalContext(LoggingContext *context);
 extern LoggingContext *logGetExternalContext();
 
 void printStdout(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList);
+void printStdout2(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList, int logLevel, char *fileName, char *functionName, unsigned int lineNumber);
 void printStderr(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList);
+void printStderr2(LoggingContext *context, LoggingComponent *component, void *data, char *formatString, va_list argList, int logLevel, char *fileName, char *functionName, unsigned int lineNumber);
 
 #endif