From 2fe243d0561c19009964003aa2ced7c695a46d17 Mon Sep 17 00:00:00 2001 From: Aravinda VK Date: Wed, 3 Jul 2019 15:08:31 +0530 Subject: logging: Structured logging reference PR To convert the existing `gf_msg` to `gf_smsg`: - Define `_STR` of respective Message ID as below(In `*-messages.h`) #define PC_MSG_REMOTE_OP_FAILED_STR "remote operation failed." - Change `gf_msg` to use `gf_smsg`. Convert values into fields and add any missing fields. Note: `errno` and `error` fields will be added automatically to log message in case errnum is specified. Example: gf_smsg( this->name, // Name or log domain GF_LOG_WARNING, // Log Level rsp.op_errno, // Error number PC_MSG_REMOTE_OP_FAILED, // Message ID "path=%s", local->loc.path, // Key Value 1 "gfid=%s", loc_gfid_utoa(&local->loc), // Key Value 2 NULL // Log End ); Key value pairs formatting Help: gf_slog( this->name, // Name or log domain GF_LOG_WARNING, // Log Level rsp.op_errno, // Error number PC_MSG_REMOTE_OP_FAILED, // Message ID "op=CREATE", // Static Key and Value "path=%s", local->loc.path, // Format for Value "brick-%d-status=%s", brkidx, brkstatus, // Use format for key and val NULL // Log End ); Before: [2019-07-03 08:16:18.226819] W [MSGID: 114031] [client-rpc-fops_v2.c \ :2633:client4_0_lookup_cbk] 0-gv3-client-0: remote operation failed. \ Path: / (00000000-0000-0000-0000-000000000001) [Transport endpoint \ is not connected] After: [2019-07-29 07:50:15.773765] W [MSGID: 114031] \ [client-rpc-fops_v2.c:2633:client4_0_lookup_cbk] 0-gv1-client-0: \ remote operation failed. [{path=/f1}, \ {gfid=00000000-0000-0000-0000-000000000000}, \ {errno=107}, {error=Transport endpoint is not connected}] To add new `gf_smsg`, Add a Message ID in respective `*-messages.h` file and the follow the steps mentioned above. Change-Id: I4e7d37f27f106ab398e991d931ba2ac7841a44b1 Updates: #657 Signed-off-by: Aravinda VK --- libglusterfs/src/glusterfs/logging.h | 11 +----- libglusterfs/src/logging.c | 69 ++++++++++++++++++------------------ 2 files changed, 36 insertions(+), 44 deletions(-) (limited to 'libglusterfs/src') diff --git a/libglusterfs/src/glusterfs/logging.h b/libglusterfs/src/glusterfs/logging.h index 31ecbfcbdb6..b3a6ac191f0 100644 --- a/libglusterfs/src/glusterfs/logging.h +++ b/libglusterfs/src/glusterfs/logging.h @@ -368,10 +368,6 @@ gf_log_disable_suppression_before_exit(struct _glusterfs_ctx *ctx); #define GF_ERROR(xl, format, args...) \ gf_log((xl)->name, GF_LOG_ERROR, format, ##args) -int -_gf_slog(const char *domain, const char *file, const char *function, int line, - gf_loglevel_t level, const char *event, ...); - int _gf_smsg(const char *domain, const char *file, const char *function, int32_t line, gf_loglevel_t level, int errnum, int trace, @@ -381,12 +377,7 @@ _gf_smsg(const char *domain, const char *file, const char *function, #define gf_smsg(dom, level, errnum, msgid, event...) \ do { \ _gf_smsg(dom, __FILE__, __FUNCTION__, __LINE__, level, errnum, 0, \ - msgid, ##event); \ - } while (0) - -#define gf_slog(dom, level, event...) \ - do { \ - _gf_slog(dom, __FILE__, __FUNCTION__, __LINE__, level, ##event); \ + msgid, msgid##_STR, ##event); \ } while (0) #endif /* __LOGGING_H__ */ diff --git a/libglusterfs/src/logging.c b/libglusterfs/src/logging.c index 85bfaf0b3ef..a0f501ec739 100644 --- a/libglusterfs/src/logging.c +++ b/libglusterfs/src/logging.c @@ -2337,7 +2337,7 @@ out: } static int -_do_slog_format(const char *event, va_list inp, char **msg) +_do_slog_format(int errnum, const char *event, va_list inp, char **msg) { va_list valist_tmp; int i = 0; @@ -2350,10 +2350,13 @@ _do_slog_format(const char *event, va_list inp, char **msg) char format_char = '%'; char *tmp1 = NULL; char *tmp2 = NULL; + char temp_sep[3] = ""; - ret = gf_asprintf(&tmp2, "%s", event); - if (ret == -1) + tmp2 = gf_strdup(""); + if (!tmp2) { + ret = -1; goto out; + } /* Hardcoded value for max key value pairs, exits early */ /* from loop if found NULL */ @@ -2401,22 +2404,45 @@ _do_slog_format(const char *event, va_list inp, char **msg) (void)va_arg(inp, void *); } - ret = gf_asprintf(&tmp2, "%s\t%s", tmp1, buffer); + ret = gf_asprintf(&tmp2, "%s%s{%s}", tmp1, temp_sep, buffer); if (ret < 0) goto out; GF_FREE(buffer); buffer = NULL; } else { - ret = gf_asprintf(&tmp2, "%s\t%s", tmp1, fmt); + ret = gf_asprintf(&tmp2, "%s%s{%s}", tmp1, temp_sep, fmt); if (ret < 0) goto out; } + /* Set seperator for next iteration */ + temp_sep[0] = ','; + temp_sep[1] = ' '; + temp_sep[2] = 0; + GF_FREE(tmp1); tmp1 = NULL; } + tmp1 = gf_strdup(tmp2); + if (!tmp1) { + ret = -1; + goto out; + } + GF_FREE(tmp2); + tmp2 = NULL; + + if (errnum) { + ret = gf_asprintf(&tmp2, "%s [%s%s{errno=%d}, {error=%s}]", event, tmp1, + temp_sep, errnum, strerror(errnum)); + } else { + ret = gf_asprintf(&tmp2, "%s [%s]", event, tmp1); + } + + if (ret == -1) + goto out; + *msg = gf_strdup(tmp2); if (!*msg) ret = -1; @@ -2448,38 +2474,13 @@ _gf_smsg(const char *domain, const char *file, const char *function, return ret; va_start(valist, event); - ret = _do_slog_format(event, valist, &msg); - if (ret == -1) - goto out; - - ret = _gf_msg(domain, file, function, line, level, errnum, trace, msgid, - "%s", msg); - -out: - va_end(valist); - if (msg) - GF_FREE(msg); - return ret; -} - -int -_gf_slog(const char *domain, const char *file, const char *function, int line, - gf_loglevel_t level, const char *event, ...) -{ - va_list valist; - char *msg = NULL; - int ret = 0; - xlator_t *this = THIS; - - if (skip_logging(this, level)) - return ret; - - va_start(valist, event); - ret = _do_slog_format(event, valist, &msg); + ret = _do_slog_format(errnum, event, valist, &msg); if (ret == -1) goto out; - ret = _gf_log(domain, file, function, line, level, "%s", msg); + /* Pass errnum as zero since it is already formated as required */ + ret = _gf_msg(domain, file, function, line, level, 0, trace, msgid, "%s", + msg); out: va_end(valist); -- cgit