From 52add0a289b8433547c5443b0dfd76e157275b10 Mon Sep 17 00:00:00 2001 From: Aravinda VK Date: Thu, 12 Oct 2017 11:31:34 +0530 Subject: features/libgfchangelog: Structured logging support Structured logging infra is available in logging library with issue #240. Log messages with dynamic content are identified and converted to structured logging format(`gf_msg` to `gf_smsg` and `gf_log` to `gf_slog`) BUG: 1501054 Change-Id: I99b35396455a634f5267eb1379d481ea981e5494 Signed-off-by: Aravinda VK --- .../features/changelog/lib/src/gf-changelog-api.c | 10 +- .../lib/src/gf-changelog-journal-handler.c | 71 ++++++------ .../changelog/lib/src/gf-changelog-reborp.c | 44 +++++--- xlators/features/changelog/lib/src/gf-changelog.c | 10 +- .../changelog/lib/src/gf-history-changelog.c | 119 ++++++++++++--------- 5 files changed, 150 insertions(+), 104 deletions(-) (limited to 'xlators/features') diff --git a/xlators/features/changelog/lib/src/gf-changelog-api.c b/xlators/features/changelog/lib/src/gf-changelog-api.c index 71312f4ce95..372550c7acf 100644 --- a/xlators/features/changelog/lib/src/gf-changelog-api.c +++ b/xlators/features/changelog/lib/src/gf-changelog-api.c @@ -55,10 +55,12 @@ gf_changelog_done (char *file) "moving %s to processed directory", file); ret = sys_rename (buffer, to_path); if (ret) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, - "cannot move %s to %s", - file, to_path); + 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); 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 a2d75cbbbfd..46f9bdae92c 100644 --- a/xlators/features/changelog/lib/src/gf-changelog-journal-handler.c +++ b/xlators/features/changelog/lib/src/gf-changelog-journal-handler.c @@ -555,10 +555,11 @@ gf_changelog_publish (xlator_t *this, ret = sys_rename (to_path, dest); if (ret) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, - "error moving %s to processing dir", - to_path); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_RENAME_FAILED, + "error moving changelog to processing dir", + "path=%s", to_path, + NULL); } out: @@ -581,18 +582,21 @@ gf_changelog_consume (xlator_t *this, ret = sys_stat (from_path, &stbuf); if (ret || !S_ISREG(stbuf.st_mode)) { ret = -1; - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_STAT_FAILED, - "stat failed on changelog file: %s", from_path); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_STAT_FAILED, + "stat failed on changelog file", + "path=%s", from_path, + NULL); goto out; } fd1 = open (from_path, O_RDONLY); if (fd1 < 0) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_OPEN_FAILED, - "cannot open changelog file: %s", - from_path); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_OPEN_FAILED, + "cannot open changelog file", + "path=%s", from_path, + NULL); goto out; } @@ -604,10 +608,11 @@ gf_changelog_consume (xlator_t *this, fd2 = open (to_path, O_CREAT | O_TRUNC | O_RDWR, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); if (fd2 < 0) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_OPEN_FAILED, - "cannot create ascii changelog file %s", - to_path); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_OPEN_FAILED, + "cannot create ascii changelog file", + "path=%s", to_path, + NULL); goto close_fd; } else { ret = gf_changelog_decode (this, jnl, fd1, @@ -622,10 +627,11 @@ gf_changelog_consume (xlator_t *this, goto close_fd; ret = sys_rename (to_path, dest); if (ret) - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, - "error moving %s to processing dir", - to_path); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_RENAME_FAILED, + "error moving changelog to processing dir", + "path=%s", to_path, + NULL); } /* remove it from .current if it's an empty file */ @@ -633,10 +639,11 @@ gf_changelog_consume (xlator_t *this, /* zerob changelogs must be unlinked */ ret = sys_unlink (to_path); if (ret) - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_UNLINK_FAILED, - "could not unlink %s", - to_path); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_UNLINK_FAILED, + "could not unlink empty changelog", + "path=%s", to_path, + NULL); } } @@ -855,10 +862,11 @@ gf_changelog_open_dirs (xlator_t *this, gf_changelog_journal_t *jnl) jnl->jnl_working_dir); ret = recursive_rmdir (jnl->jnl_current_dir); if (ret) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, - "Failed to rmdir: %s", - jnl->jnl_current_dir); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, + "Failed to rmdir", + "path=%s", jnl->jnl_current_dir, + NULL); goto out; } ret = mkdir_p (jnl->jnl_current_dir, 0600, _gf_false); @@ -879,10 +887,11 @@ gf_changelog_open_dirs (xlator_t *this, gf_changelog_journal_t *jnl) jnl->jnl_working_dir); ret = recursive_rmdir (jnl->jnl_processing_dir); if (ret) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, - "Failed to rmdir: %s", - jnl->jnl_processing_dir); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_FAILED_TO_RMDIR, + "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 4337d2575a9..d1b3059a60c 100644 --- a/xlators/features/changelog/lib/src/gf-changelog-reborp.c +++ b/xlators/features/changelog/lib/src/gf-changelog-reborp.c @@ -55,9 +55,11 @@ gf_changelog_connection_janitor (void *arg) drained = 0; ev = &entry->event; - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_CLEANING_BRICK_ENTRY_INFO, - "Cleaning brick entry for brick %s", entry->brick); + 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); /* 0x0: disbale rpc-clnt */ rpc_clnt_disable (RPC_PROBER (entry)); @@ -71,23 +73,29 @@ gf_changelog_connection_janitor (void *arg) while (!list_empty (&ev->events)) { event = list_first_entry (&ev->events, struct gf_event, list); - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, - "Draining event [Seq: %lu, Payload: %d]", - event->seq, event->count); + 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); GF_FREE (event); drained++; } - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, - "Drained %lu events", drained); + gf_smsg (this->name, GF_LOG_INFO, 0, + CHANGELOG_LIB_MSG_DRAINING_EVENT_INFO, + "Drained events", + "num=%lu", drained, + NULL); /* 0x3: freeup brick entry */ - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_FREEING_ENTRY_INFO, - "freeing entry %p", entry); + gf_smsg (this->name, GF_LOG_INFO, 0, + CHANGELOG_LIB_MSG_FREEING_ENTRY_INFO, + "freeing entry", + "entry=%p", entry, + NULL); LOCK_DESTROY (&entry->statelock); GF_FREE (entry); } @@ -114,10 +122,12 @@ gf_changelog_reborp_rpcsvc_notify (rpcsvc_t *rpc, void *mydata, case RPCSVC_EVENT_ACCEPT: ret = sys_unlink (RPC_SOCK(entry)); if (ret != 0) - gf_msg (this->name, GF_LOG_WARNING, errno, - CHANGELOG_LIB_MSG_UNLINK_FAILED, - "failed to unlink " - "reverse socket %s", RPC_SOCK (entry)); + gf_smsg (this->name, GF_LOG_WARNING, errno, + CHANGELOG_LIB_MSG_UNLINK_FAILED, + "failed to unlink " + "reverse socket", + "path=%s", RPC_SOCK (entry), + NULL); if (entry->connected) GF_CHANGELOG_INVOKE_CBK (this, entry->connected, entry->brick, entry->ptr); diff --git a/xlators/features/changelog/lib/src/gf-changelog.c b/xlators/features/changelog/lib/src/gf-changelog.c index e4ad045599a..6ee87b1414e 100644 --- a/xlators/features/changelog/lib/src/gf-changelog.c +++ b/xlators/features/changelog/lib/src/gf-changelog.c @@ -554,10 +554,12 @@ gf_changelog_register_generic (struct gf_brick_spec *bricks, int count, brick = bricks; while (count--) { - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_NOTIFY_REGISTER_INFO, - "Registering brick: %s [notify filter: %d]", - brick->brick_path, brick->filter); + 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); 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 736237219f4..0bf130a0883 100644 --- a/xlators/features/changelog/lib/src/gf-history-changelog.c +++ b/xlators/features/changelog/lib/src/gf-history-changelog.c @@ -77,10 +77,12 @@ gf_history_changelog_done (char *file) "moving %s to processed directory", file); ret = sys_rename (buffer, to_path); if (ret) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_RENAME_FAILED, - "cannot move %s to %s", - file, to_path); + 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); goto out; } @@ -529,10 +531,11 @@ gf_changelog_consume_wrap (void* data) ret = gf_changelog_consume (ccd->this, ccd->jnl, ccd->changelog, _gf_true); if (ret) { - gf_msg (this->name, GF_LOG_ERROR, - 0, CHANGELOG_LIB_MSG_PARSE_ERROR, - "could not parse changelog: %s", - ccd->changelog); + gf_smsg (this->name, GF_LOG_ERROR, + 0, CHANGELOG_LIB_MSG_PARSE_ERROR, + "could not parse changelog", + "name=%s", ccd->changelog, + NULL); goto out; } } @@ -726,10 +729,11 @@ gf_changelog_extract_min_max (const char *dname, const char *htime_dir, ret = sys_stat (htime_file, &stbuf); if (ret) { ret = -1; - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HTIME_ERROR, - "stat() failed on htime file %s", - htime_file); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_HTIME_ERROR, + "stat() failed on htime file", + "path=%s", htime_file, + NULL); goto out; } @@ -742,10 +746,11 @@ gf_changelog_extract_min_max (const char *dname, const char *htime_dir, *fd = open (htime_file, O_RDONLY); if (*fd < 0) { ret = -1; - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HTIME_ERROR, - "open() failed for htime %s", - htime_file); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_HTIME_ERROR, + "open() failed for htime file", + "path=%s", htime_file, + NULL); goto out; } @@ -753,18 +758,22 @@ gf_changelog_extract_min_max (const char *dname, const char *htime_dir, ret = sys_fgetxattr (*fd, HTIME_KEY, x_value, sizeof (x_value)); if (ret < 0) { ret = -1; - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_GET_XATTR_FAILED, - "error extracting max timstamp from htime file" - " %s", htime_file); + 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); goto out; } sscanf (x_value, "%lu:%lu", max_ts, total); - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_TOTAL_LOG_INFO, - "MIN: %lu, MAX: %lu, TOTAL CHANGELOGS: %lu", - *min_ts, *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); ret = 0; @@ -830,10 +839,12 @@ gf_history_changelog (char* changelog_dir, unsigned long start, /* basic sanity check */ if (start > end || n_parallel <= 0) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HIST_FAILED, "Sanity check failed. " - "START - %lu END - %lu THREAD_COUNT - %d", - start, end, n_parallel); + 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); ret = -1; goto out; } @@ -846,10 +857,11 @@ gf_history_changelog (char* changelog_dir, unsigned long start, dirp = sys_opendir (htime_dir); if (dirp == NULL) { - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HTIME_ERROR, - "open dir on htime failed : %s", - htime_dir); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_HTIME_ERROR, + "open dir on htime failed", + "path=%s", htime_dir, + NULL); ret = -1; goto out; } @@ -897,10 +909,12 @@ gf_history_changelog (char* changelog_dir, unsigned long start, /* ensuring correctness of gf_b_search */ if (gf_history_check (fd, from, start, len) != 0) { ret = -1; - gf_msg (this->name, GF_LOG_ERROR, 0, - CHANGELOG_LIB_MSG_GET_TIME_ERROR, - "wrong result for start: %lu idx: %lu", - start, from); + 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); goto out; } @@ -914,10 +928,12 @@ gf_history_changelog (char* changelog_dir, unsigned long start, if (gf_history_check (fd, to, end2, len) != 0) { ret = -1; - gf_msg (this->name, GF_LOG_ERROR, 0, - CHANGELOG_LIB_MSG_GET_TIME_ERROR, - "wrong result for start: %lu idx: %lu", - end2, to); + gf_smsg (this->name, GF_LOG_ERROR, 0, + CHANGELOG_LIB_MSG_GET_TIME_ERROR, + "wrong result for start", + "start=%lu", end2, + "idx=%lu", to, + NULL); goto out; } @@ -929,10 +945,13 @@ gf_history_changelog (char* changelog_dir, unsigned long start, if (ret == -1) goto out; - gf_msg (this->name, GF_LOG_INFO, 0, - CHANGELOG_LIB_MSG_TOTAL_LOG_INFO, - "FINAL: from: %lu, to: %lu, changes: %lu", - ts1, ts2, (to - from + 1)); + 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); hist_data = GF_CALLOC (1, sizeof (gf_changelog_history_data_t), @@ -972,10 +991,14 @@ gf_history_changelog (char* changelog_dir, unsigned long start, goto out; } else {/* end of range check */ - gf_msg (this->name, GF_LOG_ERROR, errno, - CHANGELOG_LIB_MSG_HIST_FAILED, "Requested changelog " - "range is not available. START - %lu CHLOG_MIN - %lu " - "CHLOG_MAX - %lu", start, min_ts, max_ts); + gf_smsg (this->name, GF_LOG_ERROR, errno, + CHANGELOG_LIB_MSG_HIST_FAILED, + "Requested changelog " + "range is not available.", + "start=%lu", start, + "chlog_min=%lu", min_ts, + "chlog_max=%lu", max_ts, + NULL); ret = -2; goto out; } -- cgit