summaryrefslogtreecommitdiffstats
path: root/tests/basic
diff options
context:
space:
mode:
authorShyamsundarR <srangana@redhat.com>2013-12-20 13:19:00 +0530
committerVijay Bellur <vbellur@redhat.com>2014-03-28 04:53:37 -0700
commit31e34cfd72712c76c127509d14d50eb008743fd5 (patch)
tree9d70b7768cb705215f7054df6069cb626ce4b189 /tests/basic
parent326b77695f15444f79cea9822e35361e6bd167d5 (diff)
log: enhance gluster log format with message ID and standardize errno reporting
Currently there are quite a slew of logs in Gluster that do not lend themselves to trivial analysis by various tools that help collect and monitor logs, due to the textual nature of the logs. This FEAT is to make this better by giving logs message IDs so that the tools do not have to do complex log parsing to break it down to problem areas and suggest troubleshooting options. With this patch, a new set of logging APIs are introduced that take additionally a message ID and an error number, so as to print the message ID and the descriptive string for the error. New APIs: - gf_msg, gf_msg_debug/trace, gf_msg_nomem, gf_msg_callingfn These APIs follow the functionality of the previous gf_log* counterparts, and hence are 1:1 replacements, with the delta that, gf_msg, gf_msg_callingfn take additional parameters as specified above. Defining the log messages: Each invocation of gf_msg/gf_msg_callingfn, should provide an ID and an errnum (if available). Towards this, a common message id file is provided, which contains defines to various messages and their respective strings. As other messages are changed to the new infrastructure APIs, it is intended that this file is edited to add these messages as well. Framework enhanced: The logging framework is also enhanced to be able to support different logging backends in the future. Hence new configuration options for logging framework and logging formats are introduced. Backward compatibility: Currently the framework supports logging in the traditional format, with the inclusion of an error string based on the errnum passed in. Hence the shift to these new APIs would retain the log file names, locations, and format with the exception of an additional error string where applicable. Testing done: Tested the new APIs with different messages in normal code paths Tested with configurations set to gluster logs (syslog pending) Tested nomem variants, inducing the message in normal code paths Tested ident generation for normal code paths (other paths pending) Tested with sample gfapi program for gfapi messages Test code is stripped from the commit Pending work (not to be addressed in this patch (future)): - Logging framework should be configurable - Logging format should be configurable - Once all messages move to the new APIs deprecate/delete older APIs to prevent misuse/abuse using the same - Repeated log messages should be suppressed (as a configurable option) - Logging framework assumes that only one init is possible, but there is no protection around the same (in existing code) - gf_log_fini is not invoked anywhere and does very little cleanup (in existing code) - DOxygen comments to message id headers for each message Change-Id: Ia043fda99a1c6cf7817517ef9e279bfcf35dcc24 BUG: 1075611 Signed-off-by: ShyamsundarR <srangana@redhat.com> Reviewed-on: http://review.gluster.org/6547 Reviewed-by: Krutika Dhananjay <kdhananj@redhat.com> Tested-by: Gluster Build System <jenkins@build.gluster.com> Reviewed-by: Raghavendra G <rgowdapp@redhat.com> Reviewed-by: Pranith Kumar Karampuri <pkarampu@redhat.com> Reviewed-by: Vijay Bellur <vbellur@redhat.com>
Diffstat (limited to 'tests/basic')
-rw-r--r--tests/basic/logchecks-messages.h84
-rw-r--r--tests/basic/logchecks.c208
2 files changed, 292 insertions, 0 deletions
diff --git a/tests/basic/logchecks-messages.h b/tests/basic/logchecks-messages.h
new file mode 100644
index 000000000..50efe9dfa
--- /dev/null
+++ b/tests/basic/logchecks-messages.h
@@ -0,0 +1,84 @@
+/*
+ Copyright (c) 2013 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 _LOGCHECKS_MESSAGES_H_
+#define _LOGCHECKS_MESSAGES_H_
+
+#ifndef _CONFIG_H
+#define _CONFIG_H
+#include "config.h"
+#endif
+
+#include "glfs-message-id.h"
+
+/* 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_COMP_BASE 1000
+#define GLFS_NUM_MESSAGES 19
+#define GLFS_MSGID_END (GLFS_COMP_BASE + GLFS_NUM_MESSAGES + 1)
+/* Messaged with message IDs */
+#define glfs_msg_start_x GLFS_COMP_BASE, "Invalid: Start of messages"
+/*------------*/
+#define logchecks_msg_1 (GLFS_COMP_BASE + 1), "Informational: Testing logging" \
+ " in gluster"
+#define logchecks_msg_2 (GLFS_COMP_BASE + 2), "Informational: Format testing:" \
+ " %d:%s:%x"
+#define logchecks_msg_3 (GLFS_COMP_BASE + 3), "Critical: Testing logging" \
+ " in gluster"
+#define logchecks_msg_4 (GLFS_COMP_BASE + 4), "Critical: Format testing:" \
+ " %d:%s:%x"
+#define logchecks_msg_5 (GLFS_COMP_BASE + 5), "Critical: Rotated the log"
+#define logchecks_msg_6 (GLFS_COMP_BASE + 6), "Critical: Flushed the log"
+#define logchecks_msg_7 (GLFS_COMP_BASE + 7), "Informational: gf_msg_callingfn"
+#define logchecks_msg_8 (GLFS_COMP_BASE + 8), "Informational: " \
+ "gf_msg_callingfn: Format testing: %d:%s:%x"
+#define logchecks_msg_9 (GLFS_COMP_BASE + 9), "Critical: gf_msg_callingfn"
+#define logchecks_msg_10 (GLFS_COMP_BASE + 10), "Critical: " \
+ "gf_msg_callingfn: Format testing: %d:%s:%x"
+#define logchecks_msg_11 (GLFS_COMP_BASE + 11), "=========================="
+#define logchecks_msg_12 (GLFS_COMP_BASE + 12), "Test 1: Only stderr and" \
+ " partial syslog"
+#define logchecks_msg_13 (GLFS_COMP_BASE + 13), "Test 2: Only checklog and" \
+ " partial syslog"
+#define logchecks_msg_14 (GLFS_COMP_BASE + 14), "Test 5: Changing to" \
+ " traditional format"
+#define logchecks_msg_15 (GLFS_COMP_BASE + 15), "Test 6: Changing log level" \
+ " to critical and above"
+#define logchecks_msg_16 (GLFS_COMP_BASE + 16), "Test 7: Only to syslog"
+#define logchecks_msg_17 (GLFS_COMP_BASE + 17), "Test 8: Only to syslog," \
+ " traditional format"
+#define logchecks_msg_18 (GLFS_COMP_BASE + 18), "Test 9: Only to syslog," \
+ " only critical and above"
+#define logchecks_msg_19 (GLFS_COMP_BASE + 19), "Pre init message, not to be" \
+ " seen in logs"
+/*------------*/
+#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages"
+
+#endif /* !_component_MESSAGES_H_ */ \ No newline at end of file
diff --git a/tests/basic/logchecks.c b/tests/basic/logchecks.c
new file mode 100644
index 000000000..4f858a7fc
--- /dev/null
+++ b/tests/basic/logchecks.c
@@ -0,0 +1,208 @@
+/*
+ * Copyright (c) 2013 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.
+ */
+
+#include <stdio.h>
+#include <unistd.h>
+
+#include "glusterfs.h"
+#include "globals.h"
+#include "logging.h"
+
+#include "logchecks-messages.h"
+#include "../../libglusterfs/src/logging.h"
+
+glusterfs_ctx_t *ctx = NULL;
+
+#define TEST_FILENAME "/tmp/logchecks.log"
+#define GF_LOG_CONTROL_FILE "/etc/glusterfs/logger.conf"
+
+int
+go_log_vargs(gf_loglevel_t level, const char *fmt, ...)
+{
+ va_list ap;
+
+ va_start (ap, fmt);
+ gf_msg_vplain (level, fmt, ap);
+ va_end (ap);
+
+ return 0;
+}
+
+int
+go_log (void)
+{
+ /*** gf_msg ***/
+ gf_msg ("logchecks", GF_LOG_INFO, 0, logchecks_msg_1);
+ gf_msg ("logchecks", GF_LOG_INFO, 22, logchecks_msg_2, 42, "Forty-Two",
+ 42);
+ /* change criticality */
+ gf_msg ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_3);
+ gf_msg ("logchecks", GF_LOG_CRITICAL, 22, logchecks_msg_4, 42,
+ "Forty-Two", 42);
+
+ /*** msg_nomem ***/
+ gf_msg_nomem ("logchecks", GF_LOG_ALERT, 555);
+ gf_msg_nomem ("logchecks", GF_LOG_INFO, 555);
+
+ /*** msg_plain ***/
+ gf_msg_plain (GF_LOG_INFO, "Informational: gf_msg_plain with"
+ " args %d:%s:%x", 42, "Forty-Two", 42);
+ gf_msg_plain (GF_LOG_ALERT, "Alert: gf_msg_plain with"
+ " args %d:%s:%x", 42, "Forty-Two", 42);
+
+ /*** msg_vplain ***/
+ go_log_vargs (GF_LOG_INFO, "Informational: gf_msg_vplain: No args!!!");
+ go_log_vargs (GF_LOG_INFO, "Informational: gf_msg_vplain: Some"
+ " args %d:%s:%x", 42, "Forty-Two", 42);
+ go_log_vargs (GF_LOG_INFO, "Critical: gf_msg_vplain: No args!!!");
+ go_log_vargs (GF_LOG_INFO, "Critical: gf_msg_vplain: Some"
+ " args %d:%s:%x", 42, "Forty-Two", 42);
+
+ /*** msg_plain_nomem ***/
+ gf_msg_plain_nomem (GF_LOG_INFO, "Informational: gf_msg_plain_nomem");
+ gf_msg_plain_nomem (GF_LOG_ALERT, "Alert: gf_msg_plain_nomem");
+
+ /*** msg_backtrace_nomem ***/
+ // TODO: Need to create a stack depth and then call
+ gf_msg_backtrace_nomem (GF_LOG_INFO, 5);
+ gf_msg_backtrace_nomem (GF_LOG_ALERT, 5);
+
+ /*** gf_msg_callingfn ***/
+ // TODO: Need to create a stack depth and then call
+ gf_msg_callingfn ("logchecks", GF_LOG_INFO, 0, logchecks_msg_7);
+ gf_msg_callingfn ("logchecks", GF_LOG_INFO, 0, logchecks_msg_8, 42,
+ "Forty-Two", 42);
+ gf_msg_callingfn ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_9);
+ gf_msg_callingfn ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_10, 42,
+ "Forty-Two", 42);
+
+ /*** gf_msg_debug ***/
+ gf_msg_debug ("logchecks", 0, "Debug: Hello World!!!");
+ gf_msg_debug ("logchecks", 22, "Debug: With args %d:%s:%x", 42,
+ "Forty-Two", 42);
+
+ /*** gf_msg_trace ***/
+ gf_msg_trace ("logchecks", 0, "Trace: Hello World!!!");
+ gf_msg_trace ("logchecks", 22, "Trace: With args %d:%s:%x", 42,
+ "Forty-Two", 42);
+
+ /*** gf_msg_backtrace ***/
+ // TODO: Test with lower callstr values to check truncation
+
+ return 0;
+}
+
+int
+main (int argc, char *argv[])
+{
+ int ret = -1;
+
+ unlink (GF_LOG_CONTROL_FILE);
+ creat (GF_LOG_CONTROL_FILE, O_RDONLY);
+ ctx = glusterfs_ctx_new ();
+ if (!ctx)
+ return -1;
+
+ ret = glusterfs_globals_init (ctx);
+ if (ret) {
+ printf ("Error from glusterfs_globals_init [%s]\n",
+ strerror (errno));
+ return ret;
+ }
+
+ /* Pre init test, message should not be printed */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_19);
+
+ THIS->ctx = ctx;
+
+ /* TEST 1: messages before initializing the log, goes to stderr
+ * and syslog based on criticality */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_12);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 2: messages post initialization, goes to glusterlog and
+ * syslog based on severity */
+ ret = gf_log_init(ctx, TEST_FILENAME, "logchecks");
+ if (ret != 0) {
+ printf ("Error from gf_log_init [%s]\n", strerror (errno));
+ return -1;
+ }
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_13);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 3: Test rotation */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_logrotate (0);
+ gf_msg ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_5);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 4: Check flush, nothing noticable should occur :) */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_flush ();
+ gf_msg ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_6);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 5: Change format */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_set_logformat (gf_logformat_traditional);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_14);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 6: Change level */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_set_loglevel (GF_LOG_CRITICAL);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_15);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* Reset to run with syslog */
+ gf_log_set_logformat (gf_logformat_withmsgid);
+ gf_log_set_loglevel (GF_LOG_INFO);
+
+ /* Run tests with logger changed to syslog */
+ /* TEST 7: No more gluster logs */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_set_logger (gf_logger_syslog);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_16);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 8: Change format */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_set_logformat (gf_logformat_traditional);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_14);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ /* TEST 9: Change level */
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+ gf_log_set_loglevel (GF_LOG_CRITICAL);
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_15);
+ go_log ();
+ gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11);
+
+ // TODO: signal crash prints, but not yet feasible here
+ // TODO: Graph printing
+ // TODO: Multi threaded logging
+
+ /* Close out the logging */
+ gf_log_fini (ctx);
+ gf_log_globals_fini ();
+
+ unlink (GF_LOG_CONTROL_FILE);
+ unlink (TEST_FILENAME);
+
+ return 0;
+} \ No newline at end of file