diff options
author | Aravinda VK <avishwan@redhat.com> | 2019-07-03 15:08:31 +0530 |
---|---|---|
committer | Amar Tumballi <amarts@gmail.com> | 2019-08-20 09:32:44 +0000 |
commit | 2fe243d0561c19009964003aa2ced7c695a46d17 (patch) | |
tree | b0400a0bb998abf584da149493be5a760d150768 /xlators/features/changelog/lib | |
parent | 25cf0d24caa11bdfefe10c93541da07c635d4cfe (diff) |
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 <avishwan@redhat.com>
Diffstat (limited to 'xlators/features/changelog/lib')
6 files changed, 79 insertions, 72 deletions
diff --git a/xlators/features/changelog/lib/src/changelog-lib-messages.h b/xlators/features/changelog/lib/src/changelog-lib-messages.h index 7695944b676..d7fe7274353 100644 --- a/xlators/features/changelog/lib/src/changelog-lib-messages.h +++ b/xlators/features/changelog/lib/src/changelog-lib-messages.h @@ -34,7 +34,7 @@ GLFS_MSGID( CHANGELOG_LIB_MSG_MMAP_FAILED, CHANGELOG_LIB_MSG_MUNMAP_FAILED, CHANGELOG_LIB_MSG_ASCII_ERROR, CHANGELOG_LIB_MSG_STAT_FAILED, CHANGELOG_LIB_MSG_GET_XATTR_FAILED, CHANGELOG_LIB_MSG_PUBLISH_ERROR, - CHANGELOG_LIB_MSG_PARSE_ERROR, CHANGELOG_LIB_MSG_TOTAL_LOG_INFO, + CHANGELOG_LIB_MSG_PARSE_ERROR, CHANGELOG_LIB_MSG_MIN_MAX_INFO, CHANGELOG_LIB_MSG_CLEANUP_ERROR, CHANGELOG_LIB_MSG_UNLINK_FAILED, CHANGELOG_LIB_MSG_NOTIFY_REGISTER_FAILED, CHANGELOG_LIB_MSG_INVOKE_RPC_FAILED, CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, @@ -43,6 +43,32 @@ GLFS_MSGID( CHANGELOG_LIB_MSG_NOTIFY_REGISTER_INFO, CHANGELOG_LIB_MSG_THREAD_CLEANUP_WARNING, CHANGELOG_LIB_MSG_COPY_FROM_BUFFER_FAILED, - CHANGELOG_LIB_MSG_PTHREAD_JOIN_FAILED, CHANGELOG_LIB_MSG_HIST_FAILED); + CHANGELOG_LIB_MSG_PTHREAD_JOIN_FAILED, CHANGELOG_LIB_MSG_HIST_FAILED, + CHANGELOG_LIB_MSG_DRAINED_EVENT_INFO, CHANGELOG_LIB_MSG_PARSE_ERROR_CEASED, + CHANGELOG_LIB_MSG_REQUESTING_INFO, CHANGELOG_LIB_MSG_FINAL_INFO); + +#define CHANGELOG_LIB_MSG_NOTIFY_REGISTER_INFO_STR "Registering brick" +#define CHANGELOG_LIB_MSG_RENAME_FAILED_STR "error moving changelog file" +#define CHANGELOG_LIB_MSG_OPEN_FAILED_STR "cannot open changelog file" +#define CHANGELOG_LIB_MSG_UNLINK_FAILED_STR "failed to unlink" +#define CHANGELOG_LIB_MSG_FAILED_TO_RMDIR_STR "failed to rmdir" +#define CHANGELOG_LIB_MSG_STAT_FAILED_STR "stat failed on changelog file" +#define CHANGELOG_LIB_MSG_PARSE_ERROR_STR "could not parse changelog" +#define CHANGELOG_LIB_MSG_PARSE_ERROR_CEASED_STR \ + "parsing error, ceased publishing..." +#define CHANGELOG_LIB_MSG_HTIME_ERROR_STR "fop failed on htime file" +#define CHANGELOG_LIB_MSG_GET_XATTR_FAILED_STR \ + "error extracting max timstamp from htime file" +#define CHANGELOG_LIB_MSG_MIN_MAX_INFO_STR "changelogs min max" +#define CHANGELOG_LIB_MSG_REQUESTING_INFO_STR "Requesting historical changelogs" +#define CHANGELOG_LIB_MSG_FINAL_INFO_STR "FINAL" +#define CHANGELOG_LIB_MSG_HIST_FAILED_STR \ + "Requested changelog range is not available" +#define CHANGELOG_LIB_MSG_GET_TIME_ERROR_STR "wrong result" +#define CHANGELOG_LIB_MSG_CLEANING_BRICK_ENTRY_INFO_STR \ + "Cleaning brick entry for brick" +#define CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO_STR "Draining event" +#define CHANGELOG_LIB_MSG_DRAINED_EVENT_INFO_STR "Drained event" +#define CHANGELOG_LIB_MSG_FREEING_ENTRY_INFO_STR "freeing entry" #endif /* !_CHANGELOG_MESSAGES_H_ */ diff --git a/xlators/features/changelog/lib/src/gf-changelog-api.c b/xlators/features/changelog/lib/src/gf-changelog-api.c index 219ce7d560a..81a5cbfec10 100644 --- a/xlators/features/changelog/lib/src/gf-changelog-api.c +++ b/xlators/features/changelog/lib/src/gf-changelog-api.c @@ -56,8 +56,8 @@ gf_changelog_done(char *file) ret = sys_rename(buffer, to_path); if (ret) { gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, "cannot move changelog file", - "from=%s", file, "to=%s", to_path, NULL); + CHANGELOG_LIB_MSG_RENAME_FAILED, "from=%s", file, "to=%s", + to_path, NULL); goto out; } diff --git a/xlators/features/changelog/lib/src/gf-changelog-journal-handler.c b/xlators/features/changelog/lib/src/gf-changelog-journal-handler.c index d2ac7efd7c7..7f6e2329e71 100644 --- a/xlators/features/changelog/lib/src/gf-changelog-journal-handler.c +++ b/xlators/features/changelog/lib/src/gf-changelog-journal-handler.c @@ -526,9 +526,8 @@ gf_changelog_publish(xlator_t *this, gf_changelog_journal_t *jnl, ret = sys_rename(to_path, dest); if (ret) { gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, - "error moving changelog to processing dir", "path=%s", to_path, - NULL); + CHANGELOG_LIB_MSG_RENAME_FAILED, "from=%s", to_path, "to=%s", + dest, NULL); } out: @@ -564,14 +563,14 @@ gf_changelog_consume(xlator_t *this, gf_changelog_journal_t *jnl, if (ret || !S_ISREG(stbuf.st_mode)) { ret = -1; gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_STAT_FAILED, - "stat failed on changelog file", "path=%s", from_path, NULL); + "path=%s", from_path, NULL); goto out; } fd1 = open(from_path, O_RDONLY); if (fd1 < 0) { gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_OPEN_FAILED, - "cannot open changelog file", "path=%s", from_path, NULL); + "path=%s", from_path, NULL); goto out; } @@ -579,7 +578,7 @@ gf_changelog_consume(xlator_t *this, gf_changelog_journal_t *jnl, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); if (fd2 < 0) { gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_OPEN_FAILED, - "cannot create ascii changelog file", "path=%s", to_path, NULL); + "path=%s", to_path, NULL); goto close_fd; } else { ret = gf_changelog_decode(this, jnl, fd1, fd2, &stbuf, &zerob); @@ -594,9 +593,8 @@ gf_changelog_consume(xlator_t *this, gf_changelog_journal_t *jnl, ret = sys_rename(to_path, dest); if (ret) gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, - "error moving changelog to processing dir", "path=%s", - to_path, NULL); + CHANGELOG_LIB_MSG_RENAME_FAILED, "from=%s", to_path, + "to=%s", dest, NULL); } /* remove it from .current if it's an empty file */ @@ -605,9 +603,8 @@ gf_changelog_consume(xlator_t *this, gf_changelog_journal_t *jnl, ret = sys_unlink(to_path); if (ret) gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_UNLINK_FAILED, - "could not unlink empty changelog", "path=%s", to_path, - NULL); + CHANGELOG_LIB_MSG_UNLINK_FAILED, "name=empty changelog", + "path=%s", to_path, NULL); } } @@ -828,7 +825,7 @@ gf_changelog_open_dirs(xlator_t *this, gf_changelog_journal_t *jnl) ret = recursive_rmdir(jnl->jnl_current_dir); if (ret) { gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, "Failed to rmdir", "path=%s", + CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, "path=%s", jnl->jnl_current_dir, NULL); goto out; } @@ -849,7 +846,7 @@ gf_changelog_open_dirs(xlator_t *this, gf_changelog_journal_t *jnl) ret = recursive_rmdir(jnl->jnl_processing_dir); if (ret) { gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, "Failed to rmdir", "path=%s", + CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, "path=%s", jnl->jnl_processing_dir, NULL); goto out; } diff --git a/xlators/features/changelog/lib/src/gf-changelog-reborp.c b/xlators/features/changelog/lib/src/gf-changelog-reborp.c index 91f189d13ab..4ccf042cc92 100644 --- a/xlators/features/changelog/lib/src/gf-changelog-reborp.c +++ b/xlators/features/changelog/lib/src/gf-changelog-reborp.c @@ -55,9 +55,8 @@ gf_changelog_connection_janitor(void *arg) ev = &entry->event; gf_smsg(this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_CLEANING_BRICK_ENTRY_INFO, - "Cleaning brick entry for brick", "brick=%s", entry->brick, - NULL); + CHANGELOG_LIB_MSG_CLEANING_BRICK_ENTRY_INFO, "brick=%s", + entry->brick, NULL); /* 0x0: disable rpc-clnt */ rpc_clnt_disable(RPC_PROBER(entry)); @@ -71,21 +70,19 @@ gf_changelog_connection_janitor(void *arg) while (!list_empty(&ev->events)) { event = list_first_entry(&ev->events, struct gf_event, list); gf_smsg(this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, "Draining event", - "seq=%lu", event->seq, "payload=%d", event->count, NULL); + CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, "seq=%lu", + event->seq, "payload=%d", event->count, NULL); GF_FREE(event); drained++; } gf_smsg(this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, "Drained events", - "num=%lu", drained, NULL); + CHANGELOG_LIB_MSG_DRAINED_EVENT_INFO, "num=%lu", drained, NULL); /* 0x3: freeup brick entry */ gf_smsg(this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_FREEING_ENTRY_INFO, "freeing entry", - "entry=%p", entry, NULL); + CHANGELOG_LIB_MSG_FREEING_ENTRY_INFO, "entry=%p", entry, NULL); LOCK_DESTROY(&entry->statelock); GF_FREE(entry); } @@ -112,9 +109,7 @@ gf_changelog_reborp_rpcsvc_notify(rpcsvc_t *rpc, void *mydata, ret = sys_unlink(RPC_SOCK(entry)); if (ret != 0) gf_smsg(this->name, GF_LOG_WARNING, errno, - CHANGELOG_LIB_MSG_UNLINK_FAILED, - "failed to unlink " - "reverse socket", + CHANGELOG_LIB_MSG_UNLINK_FAILED, "name=reverse socket", "path=%s", RPC_SOCK(entry), NULL); if (entry->connected) GF_CHANGELOG_INVOKE_CBK(this, entry->connected, entry->brick, diff --git a/xlators/features/changelog/lib/src/gf-changelog.c b/xlators/features/changelog/lib/src/gf-changelog.c index 59c98975cf5..57c3d39ef76 100644 --- a/xlators/features/changelog/lib/src/gf-changelog.c +++ b/xlators/features/changelog/lib/src/gf-changelog.c @@ -573,9 +573,8 @@ gf_changelog_register_generic(struct gf_brick_spec *bricks, int count, brick = bricks; while (count--) { gf_smsg(this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_NOTIFY_REGISTER_INFO, "Registering brick", - "brick=%s", brick->brick_path, "notify_filter=%d", - brick->filter, NULL); + CHANGELOG_LIB_MSG_NOTIFY_REGISTER_INFO, "brick=%s", + brick->brick_path, "notify_filter=%d", brick->filter, NULL); ret = gf_changelog_register_brick(this, brick, need_order, xl); if (ret != 0) { diff --git a/xlators/features/changelog/lib/src/gf-history-changelog.c b/xlators/features/changelog/lib/src/gf-history-changelog.c index e98cdbde327..a16219f3664 100644 --- a/xlators/features/changelog/lib/src/gf-history-changelog.c +++ b/xlators/features/changelog/lib/src/gf-history-changelog.c @@ -79,8 +79,8 @@ gf_history_changelog_done(char *file) ret = sys_rename(buffer, to_path); if (ret) { gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, "cannot move changelog file", - "from=%s", file, "to=%s", to_path, NULL); + CHANGELOG_LIB_MSG_RENAME_FAILED, "from=%s", file, "to=%s", + to_path, NULL); goto out; } @@ -522,8 +522,7 @@ gf_changelog_consume_wrap(void *data) _gf_true); if (ret) { gf_smsg(this->name, GF_LOG_ERROR, 0, CHANGELOG_LIB_MSG_PARSE_ERROR, - "could not parse changelog", "name=%s", ccd->changelog, - NULL); + "name=%s", ccd->changelog, NULL); goto out; } } @@ -642,9 +641,8 @@ gf_history_consume(void *data) curr = &ccd[iter]; if (ccd->retval) { publish = _gf_false; - gf_msg(this->name, GF_LOG_ERROR, 0, - CHANGELOG_LIB_MSG_PARSE_ERROR, - "parsing error, ceased publishing..."); + gf_smsg(this->name, GF_LOG_ERROR, 0, + CHANGELOG_LIB_MSG_PARSE_ERROR_CEASED, NULL); continue; } @@ -723,7 +721,7 @@ gf_changelog_extract_min_max(const char *dname, const char *htime_dir, int *fd, if (ret) { ret = -1; gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_HTIME_ERROR, - "stat() failed on htime file", "path=%s", htime_file, NULL); + "op=stat", "path=%s", htime_file, NULL); goto out; } @@ -737,7 +735,7 @@ gf_changelog_extract_min_max(const char *dname, const char *htime_dir, int *fd, if (*fd < 0) { ret = -1; gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_HTIME_ERROR, - "open() failed for htime file", "path=%s", htime_file, NULL); + "op=open", "path=%s", htime_file, NULL); goto out; } @@ -746,17 +744,15 @@ gf_changelog_extract_min_max(const char *dname, const char *htime_dir, int *fd, if (ret < 0) { ret = -1; gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_GET_XATTR_FAILED, - "error extracting max timstamp from htime file" - "path=%s", - htime_file, NULL); + CHANGELOG_LIB_MSG_GET_XATTR_FAILED, "path=%s", htime_file, + NULL); goto out; } sscanf(x_value, "%lu:%lu", max_ts, total); - gf_smsg(this->name, GF_LOG_INFO, 0, CHANGELOG_LIB_MSG_TOTAL_LOG_INFO, - "changelogs min max", "min=%lu", *min_ts, "max=%lu", *max_ts, - "total_changelogs=%lu", *total, NULL); + gf_smsg(this->name, GF_LOG_INFO, 0, CHANGELOG_LIB_MSG_MIN_MAX_INFO, + "min=%lu", *min_ts, "max=%lu", *max_ts, "total_changelogs=%lu", + *total, NULL); ret = 0; @@ -837,15 +833,14 @@ gf_history_changelog(char *changelog_dir, unsigned long start, goto out; } - gf_smsg(this->name, GF_LOG_INFO, 0, CHANGELOG_LIB_MSG_TOTAL_LOG_INFO, - "Requesting historical changelogs", "start=%lu", start, "end=%lu", - end, NULL); + gf_smsg(this->name, GF_LOG_INFO, 0, CHANGELOG_LIB_MSG_REQUESTING_INFO, + "start=%lu", start, "end=%lu", end, NULL); /* basic sanity check */ if (start > end || n_parallel <= 0) { gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_HIST_FAILED, - "Sanity check failed", "start=%lu", start, "end=%lu", end, - "thread_count=%d", n_parallel, NULL); + "start=%lu", start, "end=%lu", end, "thread_count=%d", + n_parallel, NULL); ret = -1; goto out; } @@ -859,7 +854,7 @@ gf_history_changelog(char *changelog_dir, unsigned long start, dirp = sys_opendir(htime_dir); if (dirp == NULL) { gf_smsg(this->name, GF_LOG_ERROR, errno, CHANGELOG_LIB_MSG_HTIME_ERROR, - "open dir on htime failed", "path=%s", htime_dir, NULL); + "op=opendir", "path=%s", htime_dir, NULL); ret = -1; goto out; } @@ -871,9 +866,8 @@ gf_history_changelog(char *changelog_dir, unsigned long start, if (!entry || errno != 0) { gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HIST_FAILED, - "Requested changelog range is not available", "start=%lu", - start, "end=%lu", end, NULL); + CHANGELOG_LIB_MSG_HIST_FAILED, "start=%lu", start, + "end=%lu", end, NULL); ret = -2; break; } @@ -911,9 +905,8 @@ gf_history_changelog(char *changelog_dir, unsigned long start, if (gf_history_check(fd, from, start, len) != 0) { ret = -1; gf_smsg(this->name, GF_LOG_ERROR, 0, - CHANGELOG_LIB_MSG_GET_TIME_ERROR, - "wrong result for start", "start=%lu", start, "idx=%lu", - from, NULL); + CHANGELOG_LIB_MSG_GET_TIME_ERROR, "for=start", + "start=%lu", start, "idx=%lu", from, NULL); goto out; } @@ -944,9 +937,8 @@ gf_history_changelog(char *changelog_dir, unsigned long start, if (gf_history_check(fd, to, end2, len) != 0) { ret = -1; gf_smsg(this->name, GF_LOG_ERROR, 0, - CHANGELOG_LIB_MSG_GET_TIME_ERROR, - "wrong result for end", "start=%lu", end2, "idx=%lu", - to, NULL); + CHANGELOG_LIB_MSG_GET_TIME_ERROR, "for=end", + "start=%lu", end2, "idx=%lu", to, NULL); goto out; } @@ -958,9 +950,9 @@ gf_history_changelog(char *changelog_dir, unsigned long start, if (ret == -1) goto out; - gf_smsg(this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_TOTAL_LOG_INFO, "FINAL", "from=%lu", ts1, - "to=%lu", ts2, "changes=%lu", (to - from + 1), NULL); + gf_smsg(this->name, GF_LOG_INFO, 0, CHANGELOG_LIB_MSG_FINAL_INFO, + "from=%lu", ts1, "to=%lu", ts2, "changes=%lu", + (to - from + 1), NULL); hist_data = GF_CALLOC(1, sizeof(gf_changelog_history_data_t), gf_changelog_mt_history_data_t); @@ -998,11 +990,9 @@ gf_history_changelog(char *changelog_dir, unsigned long start, } else { /* end of range check */ gf_smsg(this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HIST_FAILED, - "Requested changelog range is not " - "available. Retrying next HTIME", - "start=%lu", start, "end=%lu", end, "chlog_min=%lu", min_ts, - "chlog_max=%lu", max_ts, NULL); + CHANGELOG_LIB_MSG_HIST_FAILED, "start=%lu", start, + "end=%lu", end, "chlog_min=%lu", min_ts, "chlog_max=%lu", + max_ts, NULL); } } /* end of readdir() */ |