bit-rot : New logging framework for bit-rot log message

Change-Id: I83c494f2bb60d29495cd643659774d430325af0a
BUG: 1194640
Signed-off-by: Mohamed Ashiq <ashiq333@gmail.com>
Reviewed-on: http://review.gluster.org/10297
Tested-by: Venky Shankar <vshankar@redhat.com>
Reviewed-by: Raghavendra Bhat <raghavendra@redhat.com>
Reviewed-by: Gaurav Kumar Garg <ggarg@redhat.com>
Tested-by: NetBSD Build System <jenkins@build.gluster.org>
Reviewed-by: Venky Shankar <vshankar@redhat.com>

4 files changed, 230 insertions, 53 deletions

diff --git a/xlators/features/bit-rot/src/stub/Makefile.am b/xlators/features/bit-rot/src/stub/Makefile.am
index 579dd1c02b6..30e7ca72cb6 100644
--- a/xlators/features/bit-rot/src/stub/Makefile.am
+++ b/xlators/features/bit-rot/src/stub/Makefile.am
@@ -7,7 +7,7 @@ bitrot_stub_la_SOURCES = bit-rot-stub.c
 bitrot_stub_la_LIBADD = $(top_builddir)/libglusterfs/src/libglusterfs.la
 
 noinst_HEADERS = bit-rot-stub.h bit-rot-common.h bit-rot-stub-mem-types.h \
-                 bit-rot-object-version.h
+                 bit-rot-object-version.h bit-rot-stub-messages.h
 
 AM_CPPFLAGS = $(GF_CPPFLAGS) -I$(top_srcdir)/libglusterfs/src
 
diff --git a/xlators/features/bit-rot/src/stub/bit-rot-stub-messages.h b/xlators/features/bit-rot/src/stub/bit-rot-stub-messages.h
new file mode 100644
index 00000000000..d940b653cc8
--- /dev/null
+++ b/xlators/features/bit-rot/src/stub/bit-rot-stub-messages.h
@@ -0,0 +1,158 @@
+/*
+ Copyright (c) 2015 Red Hat, Inc. <http://www.redhat.com>
+ This file is part of GlusterFS.
+
+ This file is licensed to you under your choice of the GNU Lesser
+ General Public License, version 3 or any later version (LGPLv3 or
+ later), or the GNU General Public License, version 2 (GPLv2), in all
+ cases as published by the Free Software Foundation.
+ */
+
+#ifndef _BITROT_STUB_MESSAGES_H_
+#define _BITROT_STUB_MESSAGES_H_
+
+#include "glfs-message-id.h"
+
+/* file bit-rot-stub-messages.h
+ * brief BIT-ROT log-message IDs and their descriptions
+ */
+
+/* NOTE: Rules for message additions
+ * 1) Each instance of a message is _better_ left with a unique message ID, even
+ *    if the message format is the same. Reasoning is that, if the message
+ *    format needs to change in one instance, the other instances are not
+ *    impacted or the new change does not change the ID of the instance being
+ *    modified.
+ * 2) Addition of a message,
+ *       - Should increment the GLFS_NUM_MESSAGES
+ *       - Append to the list of messages defined, towards the end
+ *       - Retain macro naming as glfs_msg_X (for redability across developers)
+ * NOTE: Rules for message format modifications
+ * 3) Check acorss the code if the message ID macro in question is reused
+ *    anywhere. If reused then then the modifications should ensure correctness
+ *    everywhere, or needs a new message ID as (1) above was not adhered to. If
+ *    not used anywhere, proceed with the required modification.
+ * NOTE: Rules for message deletion
+ * 4) Check (3) and if used anywhere else, then cannot be deleted. If not used
+ *    anywhere, then can be deleted, but will leave a hole by design, as
+ *    addition rules specify modification to the end of the list and not filling
+ *    holes.
+ */
+
+#define GLFS_BITROT_STUB_BASE                   GLFS_MSGID_COMP_BITROT_STUB
+#define GLFS_BITROT_STUB_NUM_MESSAGES           15
+#define GLFS_MSGID_END         (GLFS_BITROT_STUB_BASE + \
+                                GLFS_BITROT_STUB_NUM_MESSAGES + 1)
+/* Messaged with message IDs */
+#define glfs_msg_start_x   GLFS_BITROT_STUB_BASE, "Invalid: Start of messages"
+/*------------*/
+
+
+#define BRS_MSG_NO_MEMORY                   (GLFS_BITROT_STUB_BASE + 1)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_SET_EVENT_FAILED            (GLFS_BITROT_STUB_BASE + 2)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_MEM_ACNT_FAILED             (GLFS_BITROT_STUB_BASE + 3)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_CREATE_FRAME_FAILED         (GLFS_BITROT_STUB_BASE + 4)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_SET_CONTEXT_FAILED          (GLFS_BITROT_STUB_BASE + 5)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_CHANGE_VERSION_FAILED       (GLFS_BITROT_STUB_BASE + 6)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_ADD_FD_TO_LIST_FAILED       (GLFS_BITROT_STUB_BASE + 7)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_SET_FD_CONTEXT_FAILED       (GLFS_BITROT_STUB_BASE + 8)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_CREATE_ANONYMOUS_FD_FAILED  (GLFS_BITROT_STUB_BASE + 9)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_NO_CHILD                    (GLFS_BITROT_STUB_BASE + 10)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_STUB_ALLOC_FAILED           (GLFS_BITROT_STUB_BASE + 11)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_GET_INODE_CONTEXT_FAILED    (GLFS_BITROT_STUB_BASE + 12)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_CANCEL_SIGN_THREAD_FAILED   (GLFS_BITROT_STUB_BASE + 13)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_ADD_FD_TO_INODE             (GLFS_BITROT_STUB_BASE + 14)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+#define BRS_MSG_SIGN_VERSION_ERROR          (GLFS_BITROT_STUB_BASE + 15)
+/*!
+ * @messageid
+ * @diagnosis
+ * @recommendedaction
+ *
+ */
+/*------------*/
+#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages"
+#endif /* !_BITROT_STUB_MESSAGES_H_ */
diff --git a/xlators/features/bit-rot/src/stub/bit-rot-stub.c b/xlators/features/bit-rot/src/stub/bit-rot-stub.c
index 5238f4333bb..fe019f452c9 100644
--- a/xlators/features/bit-rot/src/stub/bit-rot-stub.c
+++ b/xlators/features/bit-rot/src/stub/bit-rot-stub.c
@@ -20,7 +20,7 @@
 
 #include "bit-rot-stub.h"
 #include "bit-rot-stub-mem-types.h"
-
+#include "bit-rot-stub-messages.h"
 #include "bit-rot-common.h"
 
 #define BR_STUB_REQUEST_COOKIE  0x1
@@ -46,8 +46,8 @@ mem_acct_init (xlator_t *this)
         ret = xlator_mem_acct_init (this, gf_br_stub_mt_end + 1);
 
         if (ret != 0) {
-                gf_log (this->name, GF_LOG_WARNING, "Memory accounting"
-                        " init failed");
+                gf_msg (this->name, GF_LOG_WARNING, 0, BRS_MSG_MEM_ACNT_FAILED,
+                        "Memory accounting init failed");
                 return ret;
         }
 
@@ -60,12 +60,13 @@ init (xlator_t *this)
         int32_t ret = 0;
         char *tmp = NULL;
         struct timeval tv = {0,};
-	br_stub_private_t *priv = NULL;
+        br_stub_private_t *priv = NULL;
 
-	if (!this->children) {
-		gf_log (this->name, GF_LOG_ERROR, "FATAL: no children");
-		goto error_return;
-	}
+        if (!this->children) {
+                gf_msg (this->name, GF_LOG_ERROR, 0, BRS_MSG_NO_CHILD,
+                        "FATAL: no children");
+                goto error_return;
+        }
 
         priv = GF_CALLOC (1, sizeof (*priv), gf_br_stub_mt_private_t);
         if (!priv)
@@ -94,7 +95,7 @@ init (xlator_t *this)
         if (ret != 0)
                 goto cleanup_lock;
 
-        gf_log (this->name, GF_LOG_DEBUG, "bit-rot stub loaded");
+        gf_msg_debug (this->name, 0, "bit-rot stub loaded");
 	this->private = priv;
 
         return 0;
@@ -122,7 +123,8 @@ fini (xlator_t *this)
 
         ret = gf_thread_cleanup_xint (priv->signth);
         if (ret) {
-                gf_log (this->name, GF_LOG_ERROR,
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_CANCEL_SIGN_THREAD_FAILED,
                         "Could not cancel sign serializer thread");
                 goto out;
         }
@@ -335,8 +337,9 @@ br_stub_need_versioning (xlator_t *this,
 
         ret = br_stub_get_inode_ctx (this, fd->inode, &ctx_addr);
         if (ret < 0) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to get the inode "
-                        "context for the inode %s",
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_GET_INODE_CONTEXT_FAILED, "failed to get the "
+                        "inode context for the inode %s",
                         uuid_utoa (fd->inode->gfid));
                 goto error_return;
         }
@@ -370,8 +373,9 @@ br_stub_anon_fd_ctx (xlator_t *this, fd_t *fd, br_stub_inode_ctx_t *ctx)
         if (!br_stub_fd) {
                 ret = br_stub_add_fd_to_inode (this, fd, ctx);
                 if (ret) {
-                        gf_log (this->name, GF_LOG_ERROR, "failed to "
-                                "add fd to the inode (gfid: %s)",
+                        gf_msg (this->name, GF_LOG_ERROR, 0,
+                                BRS_MSG_ADD_FD_TO_INODE, "failed to add fd to "
+                                "the inode (gfid: %s)",
                                 uuid_utoa (fd->inode->gfid));
                         goto out;
                 }
@@ -392,8 +396,9 @@ br_stub_versioning_prep (call_frame_t *frame,
 
         local = br_stub_alloc_local (this);
         if (!local) {
-                gf_log (this->name, GF_LOG_ERROR, "local allocation failed "
-                        "(gfid: %s)", uuid_utoa (fd->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, ENOMEM, BRS_MSG_NO_MEMORY,
+                        "local allocation failed (gfid: %s)",
+                        uuid_utoa (fd->inode->gfid));
                 goto error_return;
         }
 
@@ -688,9 +693,10 @@ br_stub_compare_sign_version (xlator_t *this,
                 if (ctx->currentversion < sbuf->signedversion) {
                         invalid = _gf_true;
                 } else if (ctx->currentversion > sbuf->signedversion) {
-                        gf_log (this->name, GF_LOG_DEBUG, "\"Signing version\" "
-                                "(%lu) lower than \"Current version \" (%lu)",
-                                ctx->currentversion, sbuf->signedversion);
+                        gf_msg_debug (this->name, 0, "\"Signing version\" "
+                                      "(%lu) lower than \"Current version \" "
+                                      "(%lu)", ctx->currentversion,
+                                      sbuf->signedversion);
                         *fakesuccess = 1;
                 }
         }
@@ -698,9 +704,10 @@ br_stub_compare_sign_version (xlator_t *this,
 
         if (invalid) {
                 ret = -1;
-                gf_log (this->name, GF_LOG_WARNING,
-                        "Signing version exceeds current version [%lu > %lu]",
-                        sbuf->signedversion, ctx->currentversion);
+                gf_msg (this->name, GF_LOG_WARNING, 0,
+                        BRS_MSG_SIGN_VERSION_ERROR, "Signing version exceeds "
+                        "current version [%lu > %lu]", sbuf->signedversion,
+                        ctx->currentversion);
         }
 
  out:
@@ -870,9 +877,9 @@ br_stub_handle_object_reopen (call_frame_t *frame,
         stub = fop_fsetxattr_cbk_stub (frame, br_stub_fsetxattr_resume,
                                        0, 0, NULL);
         if (!stub) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to allocate stub for "
-                        "fsetxattr fop (gfid: %s), unwinding",
-                        uuid_utoa (fd->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0, BRS_MSG_STUB_ALLOC_FAILED,
+                        "failed to allocate stub for fsetxattr fop (gfid: %s),"
+                        " unwinding", uuid_utoa (fd->inode->gfid));
                 goto cleanup_local;
         }
 
@@ -998,8 +1005,9 @@ br_stub_is_object_stale (xlator_t *this, call_frame_t *frame, inode_t *inode,
 
         ret = br_stub_get_inode_ctx (this, inode, &ctx_addr);
         if (ret) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to get the inode "
-                        "context for %s", uuid_utoa (inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_GET_INODE_CONTEXT_FAILED, "failed to get the "
+                        "inode context for %s", uuid_utoa (inode->gfid));
                 goto out;
         }
 
@@ -1384,9 +1392,9 @@ br_stub_writev (call_frame_t *frame, xlator_t *this, fd_t *fd,
                                 offset, flags, iobref, xdata);
 
         if (!stub) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to allocate stub for "
-                        "write fop (gfid: %s), unwinding",
-                        uuid_utoa (fd->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0, BRS_MSG_STUB_ALLOC_FAILED,
+                        "failed to allocate stub for write fop (gfid: %s), "
+                        "unwinding", uuid_utoa (fd->inode->gfid));
                 goto cleanup_local;
         }
 
@@ -1491,9 +1499,9 @@ br_stub_ftruncate (call_frame_t *frame, xlator_t *this, fd_t *fd,
         stub = fop_ftruncate_stub (frame, br_stub_ftruncate_resume, fd, offset,
                                    xdata);
         if (!stub) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to allocate stub for "
-                        "ftruncate fop (gfid: %s), unwinding",
-                        uuid_utoa (fd->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0, BRS_MSG_STUB_ALLOC_FAILED,
+                        "failed to allocate stub for ftruncate fop (gfid: %s),"
+                        " unwinding", uuid_utoa (fd->inode->gfid));
                 goto cleanup_local;
         }
 
@@ -1592,8 +1600,10 @@ br_stub_truncate (call_frame_t *frame, xlator_t *this, loc_t *loc,
 
         fd = fd_anonymous (loc->inode);
         if (!fd) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to create anonymous "
-                        "fd for the inode %s", uuid_utoa (loc->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_CREATE_ANONYMOUS_FD_FAILED, "failed to create "
+                        "anonymous fd for the inode %s",
+                        uuid_utoa (loc->inode->gfid));
                 goto unwind;
         }
 
@@ -1619,9 +1629,9 @@ br_stub_truncate (call_frame_t *frame, xlator_t *this, loc_t *loc,
         stub = fop_truncate_stub (frame, br_stub_truncate_resume, loc, offset,
                                   xdata);
         if (!stub) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to allocate stub for "
-                        "truncate fop (gfid: %s), unwinding",
-                        uuid_utoa (fd->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0, BRS_MSG_STUB_ALLOC_FAILED,
+                        "failed to allocate stub for truncate fop (gfid: %s), "
+                        "unwinding", uuid_utoa (fd->inode->gfid));
                 goto cleanup_local;
         }
 
@@ -1685,8 +1695,9 @@ br_stub_open (call_frame_t *frame, xlator_t *this,
 
         ret = br_stub_get_inode_ctx (this, fd->inode, &ctx_addr);
         if (ret) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to get the inode "
-                        "context for the file %s (gfid: %s)", loc->path,
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_GET_INODE_CONTEXT_FAILED, "failed to get the "
+                        "inode context for the file %s (gfid: %s)", loc->path,
                         uuid_utoa (fd->inode->gfid));
                 goto unwind;
         }
@@ -1697,8 +1708,10 @@ br_stub_open (call_frame_t *frame, xlator_t *this,
 
         ret = br_stub_add_fd_to_inode (this, fd, ctx);
         if (ret) {
-                gf_log (this->name, GF_LOG_ERROR, "failed add fd to the list "
-                        "(gfid: %s)", uuid_utoa (fd->inode->gfid));
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_ADD_FD_TO_LIST_FAILED,
+                        "failed add fd to the list (gfid: %s)",
+                        uuid_utoa (fd->inode->gfid));
                 goto unwind;
         }
 
@@ -1730,7 +1743,8 @@ br_stub_add_fd_to_inode (xlator_t *this, fd_t *fd, br_stub_inode_ctx_t *ctx)
 
         ret = br_stub_require_release_call (this, fd, &br_stub_fd);
         if (ret) {
-                gf_log (this->name, GF_LOG_ERROR, "failed to set the fd "
+                gf_msg (this->name, GF_LOG_ERROR, 0,
+                        BRS_MSG_SET_FD_CONTEXT_FAILED, "failed to set the fd "
                         "context for the file (gfid: %s)",
                         uuid_utoa (fd->inode->gfid));
                 goto out;
@@ -2118,7 +2132,7 @@ br_stub_send_ipc_fop (xlator_t *this, fd_t *fd, unsigned long releaseversion,
 
         xdata = dict_new ();
         if (!xdata) {
-                gf_log (this->name, GF_LOG_WARNING,
+                gf_msg (this->name, GF_LOG_WARNING, ENOMEM, BRS_MSG_NO_MEMORY,
                         "dict allocation failed: cannot send IPC FOP "
                         "to changelog");
                 goto out;
@@ -2127,14 +2141,16 @@ br_stub_send_ipc_fop (xlator_t *this, fd_t *fd, unsigned long releaseversion,
         ret = dict_set_static_bin (xdata,
                                    "RELEASE-EVENT", &ev, CHANGELOG_EV_SIZE);
         if (ret) {
-                gf_log (this->name, GF_LOG_WARNING,
+                gf_msg (this->name, GF_LOG_WARNING, 0, BRS_MSG_SET_EVENT_FAILED,
                         "cannot set release event in dict");
                 goto dealloc_dict;
         }
 
         frame = create_frame (this, this->ctx->pool);
         if (!frame) {
-                gf_log (this->name, GF_LOG_WARNING, "create_frame() failure");
+                gf_msg (this->name, GF_LOG_WARNING, 0,
+                        BRS_MSG_CREATE_FRAME_FAILED,
+                        "create_frame() failure");
                 goto dealloc_dict;
         }
 
@@ -2240,10 +2256,10 @@ br_stub_release (xlator_t *this, fd_t *fd)
         UNLOCK (&inode->lock);
 
         if (ret) {
-                gf_log (this->name, GF_LOG_DEBUG,
-                        "releaseversion: %lu | flags: %d | signinfo: %d",
-                        (unsigned long) ntohl (releaseversion),
-                        flags, ntohl(signinfo));
+                gf_msg_debug (this->name, 0, "releaseversion: %lu | flags: %d "
+                              "| signinfo: %d",
+                              (unsigned long) ntohl (releaseversion), flags,
+                              ntohl(signinfo));
                 br_stub_send_ipc_fop (this, fd, releaseversion, signinfo);
         }
 
diff --git a/xlators/features/bit-rot/src/stub/bit-rot-stub.h b/xlators/features/bit-rot/src/stub/bit-rot-stub.h
index 43be68b26a0..4747cc816a7 100644
--- a/xlators/features/bit-rot/src/stub/bit-rot-stub.h
+++ b/xlators/features/bit-rot/src/stub/bit-rot-stub.h
@@ -19,6 +19,7 @@
 #include "bit-rot-stub-mem-types.h"
 
 #include "bit-rot-common.h"
+#include "bit-rot-stub-messages.h"
 
 typedef int (br_stub_version_cbk) (call_frame_t *, void *,
                                    xlator_t *, int32_t, int32_t, dict_t *);
@@ -218,7 +219,8 @@ br_stub_require_release_call (xlator_t *this, fd_t *fd, br_stub_fd_t **fd_ctx)
 
         ret = br_stub_fd_ctx_set (this, fd, br_stub_fd);
         if (ret)
-                gf_log (this->name, GF_LOG_WARNING,
+                gf_msg (this->name, GF_LOG_WARNING, 0,
+                        BRS_MSG_SET_CONTEXT_FAILED,
                         "could not set fd context (for release callback");
         else
                 *fd_ctx = br_stub_fd;
@@ -272,7 +274,8 @@ __br_stub_set_ongoing_version (br_stub_inode_ctx_t *ctx, unsigned long version)
         if (ctx->currentversion < version)
                 ctx->currentversion = version;
         else
-                gf_log ("bit-rot-stub", GF_LOG_WARNING, "current version: %lu"
+                gf_msg ("bit-rot-stub", GF_LOG_WARNING, 0,
+                        BRS_MSG_CHANGE_VERSION_FAILED, "current version: %lu"
                         "new version: %lu", ctx->currentversion, version);
 }