Merge pull request #103 from zowe/bugfix/wto-component-stall

Fix syslog output

CHANGELOG.md

@@ -4,6 +4,11 @@ All notable changes to the Zowe Launcher package will be documented in this file
 This repo is part of the app-server Zowe Component, and the change logs here may appear on Zowe.org in that section.
 
 ## 2.13.0
+- Bugfix: Changed timestamp to UTC to match the server timestamps (#103)
+- Bugfix: Removed server timestamps from syslog to avoid duplicate logging of time (#103)
+- Bugfix: Avoided hang on components when components were logging messages longer than 1024 characters. (#103)
+- Enhancement: syslog output per line is capped at 512 bytes, extra characters will be omitted (#103)
+- Enhancement: Added milliseconds logging to match the server timestamps (#103)
 - Enhancement: Launcher prints a message at the beginning of startup to alert users whether or not their log output has long enough lines to be readable if sent to support. (#101)
 - Added a wrapper for wtoPrintf3
 

src/main.c

@@ -18,8 +18,9 @@
 #include <string.h>
 #include <strings.h>
 #include <errno.h>
-
+#include <regex.h>
 #include <time.h>
+#include <sys/time.h>
 
 #include <pthread.h>
 #include <fcntl.h>
@@ -65,6 +66,9 @@ extern char ** environ;
 
 #define COMP_LIST_SIZE 1024
 
+#define LAUNCHER_MESSAGE_LENGTH_LIMIT 512
+#define SYSLOG_MESSAGE_LENGTH_LIMIT 126
+
 #ifndef PATH_MAX
 #define PATH_MAX _POSIX_PATH_MAX
 #endif
@@ -89,10 +93,15 @@ static zl_time_t gettime(void) {
   struct tm lt;
   zl_time_t result;
 
-  localtime_r(&t, &lt);
+  gmtime_r(&t, &lt);
 
   strftime(result.value, sizeof(result.value), format, &lt);
 
+  struct timeval now;
+  gettimeofday(&now, NULL);
+  int milli = now.tv_usec / 1000;
+  snprintf(result.value+strlen(result.value), 5, ".%03d", milli);
+
   return result;
 }
 typedef struct zl_int_array_t {
@@ -193,36 +202,18 @@ static void set_sys_messages(ConfigManager *configmgr) {
   }
 }
 
-static void check_for_and_print_sys_message(const char* fmt, ...) {
-
+static void launcher_syslog_on_match(const char* fmt, ...) {
   if (!zl_context.sys_messages) {
     return;
   }
 
   /* All of this stuff here is because I can't do 
   #define INFO(fmt, ...)  check_for_and_print_sys_message(fmt, ...) so let's make a string */
-  char input_string[1024];
+  char input_string[LAUNCHER_MESSAGE_LENGTH_LIMIT+1];
   va_list args;
   va_start(args, fmt);
   vsnprintf(input_string, sizeof(input_string), fmt, args);
   va_end(args);
-
-  /* Uncomment code to try to pull ID from input_string
-  // Extract the ID from input_string
-  char msg_id[256]; // assuming the ID will not exceed 255 characters
-  const char* spacePos = strchr(input_string, ' ');
-  if (spacePos) {
-      int length = spacePos - input_string;
-      strncpy(msg_id, input_string, length);
-      msg_id[length] = '\0';
-  } else {
-      // If no space found, use the whole input_string as the ID
-      //strncpy(msg_id, input_string, sizeof(msg_id) - 1);
-      //msg_id[sizeof(msg_id) - 1] = '\0'; // ensure null termination
-      
-      // If no space found, end
-      return;
-  } */
 
   int count = jsonArrayGetCount(zl_context.sys_messages);
   for (int i = 0; i < count; i++) {
@@ -235,13 +226,71 @@ static void check_for_and_print_sys_message(const char* fmt, ...) {
 
 }
 
-#define INFO(fmt, ...)  check_for_and_print_sys_message(fmt, ##__VA_ARGS__); \
+static int index_of_string_limited(const char *str, int len, const char *search_string, int start_pos, int search_limit){
+  int search_len = strlen(search_string);
+  int last_possible_start = len < search_limit ? len - search_len : search_limit - search_len;
+  int pos = start_pos;
+
+  if (start_pos > last_possible_start){
+    return -1;
+  }
+  while (pos <= last_possible_start){
+    if (!memcmp(str+pos,search_string,search_len)){
+      return pos;
+    }
+    pos++;
+  }
+  return -1;
+}
+
+//size of "ZWE_zowe_sysMessages"
+#define ZWE_SYSMESSAGES_EXCLUDE_LEN 20
+
+// matches YYYY-MM-DD starting with 2xxx.
+// this regex was chosen because other patterns didnt seem to work with LE's regex library.
+#define DATE_PREFIX_REGEXP_PATTERN "^[2-9][0-9][0-9][0-9]-[0-9][0-9]-[0-9][0-9].*"
+
+// zowe standard "YYYY-MM-DD HH-MM-SS.sss "
+#define DATE_PREFIX_LEN 24
+
+static void check_for_and_print_sys_message(const char* input_string) {
+  if (!zl_context.sys_messages) {
+    return;
+  }
+
+  int count = jsonArrayGetCount(zl_context.sys_messages);
+  int input_length = strlen(input_string);
+  for (int i = 0; i < count; i++) {
+    const char *sys_message_id = jsonArrayGetString(zl_context.sys_messages, i);
+    if (sys_message_id && (index_of_string_limited(input_string, input_length, sys_message_id, 0, SYSLOG_MESSAGE_LENGTH_LIMIT) != -1)) {
+
+      //exclude "ZWE_zowe_sysMessages" messages to avoid spam.
+      if (memcmp("ZWE_zowe_sysMessages", input_string, ZWE_SYSMESSAGES_EXCLUDE_LEN)){ 
+
+        //truncate match for reasonable output
+        char syslog_string[SYSLOG_MESSAGE_LENGTH_LIMIT+1] = {0};
+        regex_t time_regex;
+        int regex_rc = regcomp(&time_regex, DATE_PREFIX_REGEXP_PATTERN, 0);
+        int match = regexec(&time_regex, input_string, 0, NULL, 0);
+        int offset = match == 0 ? DATE_PREFIX_LEN : 0;
+        int length = SYSLOG_MESSAGE_LENGTH_LIMIT < (input_length-offset) ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_length-offset;
+        memcpy(syslog_string, input_string+offset, length);  
+        syslog_string[length] = '\0';
+        printf_wto(syslog_string);// Print our match to the syslog
+        break;
+      }
+    }
+  }
+
+}
+
+#define INFO(fmt, ...)  launcher_syslog_on_match(fmt, ##__VA_ARGS__); \
   printf("%s <%s:%d> %s INFO "fmt, gettime().value, COMP_ID, zl_context.pid, zl_context.userid, ##__VA_ARGS__)
-#define WARN(fmt, ...)  check_for_and_print_sys_message(fmt, ##__VA_ARGS__); \
+#define WARN(fmt, ...)  launcher_syslog_on_match(fmt, ##__VA_ARGS__); \
   printf("%s <%s:%d> %s WARN "fmt, gettime().value, COMP_ID, zl_context.pid, zl_context.userid, ##__VA_ARGS__)
 #define DEBUG(fmt, ...) if (zl_context.config.debug_mode) \
   printf("%s <%s:%d> %s DEBUG "fmt, gettime().value, COMP_ID, zl_context.pid, zl_context.userid, ##__VA_ARGS__)
-#define ERROR(fmt, ...) check_for_and_print_sys_message(fmt, ##__VA_ARGS__); \
+#define ERROR(fmt, ...) launcher_syslog_on_match(fmt, ##__VA_ARGS__); \
   printf("%s <%s:%d> %s ERROR "fmt, gettime().value, COMP_ID, zl_context.pid, zl_context.userid, ##__VA_ARGS__)
 
 static int mkdir_all(const char *path, mode_t mode) {