From d687cc5ee75e2c48103cb10c47177003c594bce0 Mon Sep 17 00:00:00 2001 From: 1000TurquoisePogs Date: Mon, 23 Oct 2023 08:29:47 -0400 Subject: [PATCH 1/6] Print out a long line to check log length Signed-off-by: 1000TurquoisePogs --- CHANGELOG.md | 1 + src/main.c | 1 + src/msg.h | 1 + 3 files changed, 3 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 75d492b..26341d9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,4 +4,5 @@ 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 +- 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. - Added a wrapper for wtoPrintf3 \ No newline at end of file diff --git a/src/main.c b/src/main.c index f59b52e..deb7899 100644 --- a/src/main.c +++ b/src/main.c @@ -1627,6 +1627,7 @@ int main(int argc, char **argv) { } INFO(MSG_LAUNCHER_START); + INFO(MSG_LINE_LENGTH); printf_wto(MSG_LAUNCHER_START); // Manual sys log print (messages not set here yet) zl_config_t config = read_config(argc, argv); diff --git a/src/msg.h b/src/msg.h index db2f15d..a862cc6 100644 --- a/src/msg.h +++ b/src/msg.h @@ -88,6 +88,7 @@ #define MSG_CFG_LOAD_FAIL MSG_PREFIX "0072E" " Launcher Could not load configurations\n" #define MSG_CFG_SCHEMA_FAIL MSG_PREFIX "0073E" " Launcher Could not load schemas, status=%d\n" #define MSG_NO_LOG_CONTEXT MSG_PREFIX "0074E" " Log context was not created\n" +#define MSG_LINE_LENGTH "-- If you cant see '500' at the end of the line, your log is too short to read!80--------90------ 100----------------------125----------------------150----------------------175----------------------200----------------------225----------------------250----------------------275----------------------300----------------------325----------------------350----------------------375----------------------400----------------------425----------------------450----------------------475----------------------500\n" #endif // MSG_H From 591ccd73008a3ff263835e172b32c83c4d67efbf Mon Sep 17 00:00:00 2001 From: 1000TurquoisePogs Date: Thu, 2 Nov 2023 11:02:58 -0400 Subject: [PATCH 2/6] Split component log checking into its own function with a 512 char truncation to improve syslog readability Signed-off-by: 1000TurquoisePogs --- src/main.c | 69 ++++++++++++++++++++++++++++++++++++------------------ 1 file changed, 46 insertions(+), 23 deletions(-) diff --git a/src/main.c b/src/main.c index 1d6d4c7..9848a82 100644 --- a/src/main.c +++ b/src/main.c @@ -65,6 +65,8 @@ extern char ** environ; #define COMP_LIST_SIZE 1024 +#define SYSLOG_MESSAGE_LENGTH_LIMIT 512 + #ifndef PATH_MAX #define PATH_MAX _POSIX_PATH_MAX #endif @@ -193,36 +195,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[SYSLOG_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 +219,52 @@ 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(char *str, int len, char *search_string, int start_pos, int search_limit){ + int last_possible_start = len-search_limit; + int pos = start_pos; + + if (startPos > last_possible_start){ + return -1; + } + while (pos <= last_possible_start){ + if (!memcmp(str+pos,search_string,search_limit)){ + return pos; + } + pos++; + } + return -1; +} + +static void check_for_and_print_sys_message(const char* line) { + 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)) { + //truncate match for reasonable output + char syslog_string[SYSLOG_MESSAGE_LENGTH_LIMIT+1] = {0}; + int length = SYSLOG_MESSAGE_LENGTH_LIMIT < input_length ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_lenth; + memcpy(syslog_string, input_string, 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) { From fdf7e60549a17b719b1f6c600d6a3862267dc424 Mon Sep 17 00:00:00 2001 From: 1000TurquoisePogs Date: Thu, 2 Nov 2023 11:18:31 -0400 Subject: [PATCH 3/6] Compile fixes Signed-off-by: 1000TurquoisePogs --- src/main.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/main.c b/src/main.c index 9848a82..b6edf70 100644 --- a/src/main.c +++ b/src/main.c @@ -223,7 +223,7 @@ static int index_of_string_limited(char *str, int len, char *search_string, int int last_possible_start = len-search_limit; int pos = start_pos; - if (startPos > last_possible_start){ + if (start_pos > last_possible_start){ return -1; } while (pos <= last_possible_start){ @@ -235,7 +235,7 @@ static int index_of_string_limited(char *str, int len, char *search_string, int return -1; } -static void check_for_and_print_sys_message(const char* line) { +static void check_for_and_print_sys_message(const char* input_string) { if (!zl_context.sys_messages) { return; } @@ -247,7 +247,7 @@ static void check_for_and_print_sys_message(const char* line) { if (sys_message_id && (index_of_string_limited(input_string, input_length, sys_message_id, 0, SYSLOG_MESSAGE_LENGTH_LIMIT) != -1)) { //truncate match for reasonable output char syslog_string[SYSLOG_MESSAGE_LENGTH_LIMIT+1] = {0}; - int length = SYSLOG_MESSAGE_LENGTH_LIMIT < input_length ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_lenth; + int length = SYSLOG_MESSAGE_LENGTH_LIMIT < input_length ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_length; memcpy(syslog_string, input_string, length); syslog_string[length] = '\0'; From 88f279dab415b8b4a83419144c1814d403dc97e4 Mon Sep 17 00:00:00 2001 From: 1000TurquoisePogs Date: Wed, 8 Nov 2023 12:03:20 -0500 Subject: [PATCH 4/6] Avoid spam from ZWE_ env vars Signed-off-by: 1000TurquoisePogs --- src/main.c | 28 +++++++++++++++++----------- 1 file changed, 17 insertions(+), 11 deletions(-) diff --git a/src/main.c b/src/main.c index b6edf70..dcf7d52 100644 --- a/src/main.c +++ b/src/main.c @@ -219,15 +219,16 @@ static void launcher_syslog_on_match(const char* fmt, ...) { } -static int index_of_string_limited(char *str, int len, char *search_string, int start_pos, int search_limit){ - int last_possible_start = len-search_limit; +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_limit)){ + if (!memcmp(str+pos,search_string,search_len)){ return pos; } pos++; @@ -235,6 +236,9 @@ static int index_of_string_limited(char *str, int len, char *search_string, int return -1; } +//size of "ZWE_zowe_sysMessages" +#define ZWE_SYSMESSAGES_EXCLUDE_LEN 20 + static void check_for_and_print_sys_message(const char* input_string) { if (!zl_context.sys_messages) { return; @@ -245,14 +249,16 @@ static void check_for_and_print_sys_message(const char* 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)) { - //truncate match for reasonable output - char syslog_string[SYSLOG_MESSAGE_LENGTH_LIMIT+1] = {0}; - int length = SYSLOG_MESSAGE_LENGTH_LIMIT < input_length ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_length; - memcpy(syslog_string, input_string, length); - syslog_string[length] = '\0'; - - printf_wto(syslog_string);// Print our match to the syslog - break; + //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}; + int length = SYSLOG_MESSAGE_LENGTH_LIMIT < input_length ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_length; + memcpy(syslog_string, input_string, length); + syslog_string[length] = '\0'; + printf_wto(syslog_string);// Print our match to the syslog + break; + } } } From f0e9d6622b55b269fa97dcfc0aa90465ca82b010 Mon Sep 17 00:00:00 2001 From: 1000TurquoisePogs Date: Thu, 9 Nov 2023 07:52:48 -0500 Subject: [PATCH 5/6] Fixed syslog output Signed-off-by: 1000TurquoisePogs --- CHANGELOG.md | 8 ++++++++ src/main.c | 27 +++++++++++++++++++++++---- 2 files changed, 31 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 24e6953..64c98c6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,14 @@ 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) + ## 2.12.0 - Added a wrapper for wtoPrintf3 - Bugfix: Fixed a gap in WTO syslog checking \ No newline at end of file diff --git a/src/main.c b/src/main.c index dcf7d52..e3996c6 100644 --- a/src/main.c +++ b/src/main.c @@ -18,8 +18,9 @@ #include #include #include - +#include #include +#include #include #include @@ -91,10 +92,15 @@ static zl_time_t gettime(void) { struct tm lt; zl_time_t result; - localtime_r(&t, <); + gmtime_r(&t, <); strftime(result.value, sizeof(result.value), format, <); + 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 { @@ -239,6 +245,12 @@ static int index_of_string_limited(const char *str, int len, const char *search_ //size of "ZWE_zowe_sysMessages" #define ZWE_SYSMESSAGES_EXCLUDE_LEN 20 +// matches YYYY-MM-DD starting with 2xxx. +#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; @@ -253,8 +265,15 @@ static void check_for_and_print_sys_message(const char* input_string) { 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}; - int length = SYSLOG_MESSAGE_LENGTH_LIMIT < input_length ? SYSLOG_MESSAGE_LENGTH_LIMIT : input_length; - memcpy(syslog_string, input_string, length); + regex_t time_regex; + int regex_rc = regcomp(&time_regex, DATE_PREFIX_REGEXP_PATTERN, 0); + printf("regex rc=%d\n", regex_rc); + int match = regexec(&time_regex, input_string, 0, NULL, 0); + printf("match =%d, %d\n", match, REG_NOMATCH); + int offset = match == 0 ? DATE_PREFIX_LEN : 0; + printf("offset = %d\n", offset); + 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; From fe03e15e1476a54657e201cc1aff8edc08cc8e33 Mon Sep 17 00:00:00 2001 From: 1000TurquoisePogs Date: Wed, 15 Nov 2023 11:37:58 -0500 Subject: [PATCH 6/6] Shrink launcher truncation to 126 to match syslog limit: Signed-off-by: 1000TurquoisePogs --- src/main.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/main.c b/src/main.c index 4dd5730..1e46cca 100644 --- a/src/main.c +++ b/src/main.c @@ -66,7 +66,8 @@ extern char ** environ; #define COMP_LIST_SIZE 1024 -#define SYSLOG_MESSAGE_LENGTH_LIMIT 512 +#define LAUNCHER_MESSAGE_LENGTH_LIMIT 512 +#define SYSLOG_MESSAGE_LENGTH_LIMIT 126 #ifndef PATH_MAX #define PATH_MAX _POSIX_PATH_MAX @@ -208,7 +209,7 @@ static void launcher_syslog_on_match(const char* fmt, ...) { /* 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[SYSLOG_MESSAGE_LENGTH_LIMIT+1]; + char input_string[LAUNCHER_MESSAGE_LENGTH_LIMIT+1]; va_list args; va_start(args, fmt); vsnprintf(input_string, sizeof(input_string), fmt, args);