summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorKrutika Dhananjay <kdhananj@redhat.com>2014-02-07 11:02:10 +0530
committerVijay Bellur <vbellur@redhat.com>2014-04-30 23:52:28 -0700
commit630d46d714a233919664c035f2c5c48c028777e8 (patch)
treee7e79b240e23fde447989a4e1adc625b1858d17d
parentf63fbca7540a4c9ce090e1ed5941ed8777ff6316 (diff)
logging: Introduce suppression of repetitive log messages
Change-Id: I8efa08cc9832ad509fba65a88bb0cddbaf056404 BUG: 1075611 Signed-off-by: Krutika Dhananjay <kdhananj@redhat.com> Reviewed-on: http://review.gluster.org/7475 Tested-by: Gluster Build System <jenkins@build.gluster.com> Reviewed-by: Vijay Bellur <vbellur@redhat.com>
-rw-r--r--api/src/glfs-internal.h2
-rw-r--r--api/src/glfs.c11
-rw-r--r--glusterfsd/src/glusterfsd.c74
-rw-r--r--glusterfsd/src/glusterfsd.h4
-rw-r--r--libglusterfs/src/common-utils.c3
-rw-r--r--libglusterfs/src/glusterfs.h16
-rw-r--r--libglusterfs/src/logging.c793
-rw-r--r--libglusterfs/src/logging.h72
-rw-r--r--xlators/debug/io-stats/src/io-stats.c65
-rw-r--r--xlators/mgmt/glusterd/src/glusterd-volgen.c76
-rw-r--r--xlators/mgmt/glusterd/src/glusterd-volume-set.c22
11 files changed, 1030 insertions, 108 deletions
diff --git a/api/src/glfs-internal.h b/api/src/glfs-internal.h
index d7d675e81b1..14e94e2116f 100644
--- a/api/src/glfs-internal.h
+++ b/api/src/glfs-internal.h
@@ -131,6 +131,8 @@ struct glfs_object {
#define GF_MEMPOOL_COUNT_OF_DATA_T (GF_MEMPOOL_COUNT_OF_DICT_T * 4)
#define GF_MEMPOOL_COUNT_OF_DATA_PAIR_T (GF_MEMPOOL_COUNT_OF_DICT_T * 4)
+#define GF_MEMPOOL_COUNT_OF_LRU_BUF_T 256
+
int glfs_mgmt_init (struct glfs *fs);
void glfs_init_done (struct glfs *fs, int ret);
int glfs_process_volfp (struct glfs *fs, FILE *fp);
diff --git a/api/src/glfs.c b/api/src/glfs.c
index 73c46517dad..b69d785a8ab 100644
--- a/api/src/glfs.c
+++ b/api/src/glfs.c
@@ -129,6 +129,11 @@ glusterfs_ctx_defaults_init (glusterfs_ctx_t *ctx)
if (!ctx->dict_data_pool)
goto err;
+ ctx->logbuf_pool = mem_pool_new (log_buf_t,
+ GF_MEMPOOL_COUNT_OF_LRU_BUF_T);
+ if (!ctx->logbuf_pool)
+ goto err;
+
INIT_LIST_HEAD (&pool->all_frames);
INIT_LIST_HEAD (&ctx->cmd_args.xlator_options);
INIT_LIST_HEAD (&ctx->cmd_args.volfile_servers);
@@ -157,6 +162,8 @@ err:
mem_pool_destroy (ctx->dict_data_pool);
if (ctx->dict_pair_pool)
mem_pool_destroy (ctx->dict_pair_pool);
+ if (ctx->logbuf_pool)
+ mem_pool_destroy (ctx->logbuf_pool);
}
return ret;
@@ -590,6 +597,10 @@ glfs_set_logging (struct glfs *fs, const char *logfile, int loglevel)
if (ret)
goto out;
+ ret = gf_log_inject_timer_event (fs->ctx);
+ if (ret)
+ goto out;
+
out:
return ret;
}
diff --git a/glusterfsd/src/glusterfsd.c b/glusterfsd/src/glusterfsd.c
index 219088025a0..e971426da93 100644
--- a/glusterfsd/src/glusterfsd.c
+++ b/glusterfsd/src/glusterfsd.c
@@ -115,6 +115,10 @@ static struct argp_option gf_options[] = {
"[default: \"gluster-log\"]"},
{"log-format", ARGP_LOG_FORMAT, "LOG-FORMAT", 0, "Set log format, valid"
" options are: no-msg-id and with-msg-id, [default: \"with-msg-id\"]"},
+ {"log-buf-size", ARGP_LOG_BUF_SIZE, "LOG-BUF-SIZE", 0, "Set logging "
+ "buffer size, [default: 5]"},
+ {"log-flush-timeout", ARGP_LOG_FLUSH_TIMEOUT, "LOG-FLUSH-TIMEOUT", 0,
+ "Set log flush timeout, [default: 2 minutes]"},
{0, 0, 0, 0, "Advanced Options:"},
{"volfile-server-port", ARGP_VOLFILE_SERVER_PORT_KEY, "PORT", 0,
@@ -1110,6 +1114,37 @@ parse_opts (int key, char *arg, struct argp_state *state)
break;
+ case ARGP_LOG_BUF_SIZE:
+ if (gf_string2uint32 (arg, &cmd_args->log_buf_size)) {
+ argp_failure (state, -1, 0,
+ "unknown log buf size option %s", arg);
+ } else if ((cmd_args->log_buf_size < GF_LOG_LRU_BUFSIZE_MIN) ||
+ (cmd_args->log_buf_size > GF_LOG_LRU_BUFSIZE_MAX)) {
+ argp_failure (state, -1, 0,
+ "Invalid log buf size %s. "
+ "Valid range: ["
+ GF_LOG_LRU_BUFSIZE_MIN_STR","
+ GF_LOG_LRU_BUFSIZE_MAX_STR"]", arg);
+ }
+
+ break;
+
+ case ARGP_LOG_FLUSH_TIMEOUT:
+ if (gf_string2uint32 (arg, &cmd_args->log_flush_timeout)) {
+ argp_failure (state, -1, 0,
+ "unknown log flush timeout option %s", arg);
+ } else if ((cmd_args->log_flush_timeout <
+ GF_LOG_FLUSH_TIMEOUT_MIN) ||
+ (cmd_args->log_flush_timeout >
+ GF_LOG_FLUSH_TIMEOUT_MAX)) {
+ argp_failure (state, -1, 0,
+ "Invalid log flush timeout %s. "
+ "Valid range: ["
+ GF_LOG_FLUSH_TIMEOUT_MIN_STR","
+ GF_LOG_FLUSH_TIMEOUT_MAX_STR"]", arg);
+ }
+
+ break;
}
return 0;
@@ -1127,6 +1162,23 @@ cleanup_and_exit (int signum)
if (!ctx)
return;
+ /* To take or not to take the mutex here and in the other
+ * signal handler - gf_print_trace() - is the big question here.
+ *
+ * Taking mutex in signal handler would mean that if the process
+ * receives a fatal signal while another thread is holding
+ * ctx->log.log_buf_lock to perhaps log a message in _gf_msg_internal(),
+ * the offending thread hangs on the mutex lock forever without letting
+ * the process exit.
+ *
+ * On the other hand. not taking the mutex in signal handler would cause
+ * it to modify the lru_list of buffered log messages in a racy manner,
+ * corrupt the list and potentially give rise to an unending
+ * cascade of SIGSEGVs and other re-entrancy issues.
+ */
+
+ gf_log_disable_suppression_before_exit (ctx);
+
gf_msg_callingfn ("", GF_LOG_WARNING, 0, glusterfsd_msg_32, signum);
if (ctx->cleanup_started)
@@ -1313,6 +1365,11 @@ glusterfs_ctx_defaults_init (glusterfs_ctx_t *ctx)
if (!ctx->dict_data_pool)
goto out;
+ ctx->logbuf_pool = mem_pool_new (log_buf_t,
+ GF_MEMPOOL_COUNT_OF_LRU_BUF_T);
+ if (!ctx->logbuf_pool)
+ goto out;
+
pthread_mutex_init (&(ctx->lock), NULL);
ctx->clienttable = gf_clienttable_alloc();
@@ -1325,6 +1382,8 @@ glusterfs_ctx_defaults_init (glusterfs_ctx_t *ctx)
cmd_args->log_level = DEFAULT_LOG_LEVEL;
cmd_args->logger = gf_logger_glusterlog;
cmd_args->log_format = gf_logformat_withmsgid;
+ cmd_args->log_buf_size = GF_LOG_LRU_BUFSIZE_DEFAULT;
+ cmd_args->log_flush_timeout = GF_LOG_FLUSH_TIMEOUT_DEFAULT;
cmd_args->mac_compat = GF_OPTION_DISABLE;
#ifdef GF_DARWIN_HOST_OS
@@ -1359,6 +1418,7 @@ out:
mem_pool_destroy (ctx->dict_pool);
mem_pool_destroy (ctx->dict_data_pool);
mem_pool_destroy (ctx->dict_pair_pool);
+ mem_pool_destroy (ctx->logbuf_pool);
}
return ret;
@@ -1397,12 +1457,24 @@ logging_init (glusterfs_ctx_t *ctx, const char *progpath)
gf_log_set_logformat (cmd_args->log_format);
+ gf_log_set_log_buf_size (cmd_args->log_buf_size);
+
+ gf_log_set_log_flush_timeout (cmd_args->log_flush_timeout);
+
if (gf_log_init (ctx, cmd_args->log_file, cmd_args->log_ident) == -1) {
fprintf (stderr, "ERROR: failed to open logfile %s\n",
cmd_args->log_file);
return -1;
}
+ /* At this point, all the logging related parameters are initialised
+ * except for the log flush timer, which will be injected post fork(2)
+ * in daemonize() . During this time, any log message that is logged
+ * will be kept buffered. And if the list that holds these messages
+ * overflows, then the same lru policy is used to drive out the least
+ * recently used message and displace it with the message just logged.
+ */
+
return 0;
}
@@ -1792,6 +1864,8 @@ postfork:
if (ret)
goto out;
+ ret = gf_log_inject_timer_event (ctx);
+
glusterfs_signals_setup (ctx);
out:
return ret;
diff --git a/glusterfsd/src/glusterfsd.h b/glusterfsd/src/glusterfsd.h
index 24487b4d461..a75369a24f5 100644
--- a/glusterfsd/src/glusterfsd.h
+++ b/glusterfsd/src/glusterfsd.h
@@ -39,6 +39,8 @@
#define GF_MEMPOOL_COUNT_OF_DATA_T (GF_MEMPOOL_COUNT_OF_DICT_T * 4)
#define GF_MEMPOOL_COUNT_OF_DATA_PAIR_T (GF_MEMPOOL_COUNT_OF_DICT_T * 4)
+#define GF_MEMPOOL_COUNT_OF_LRU_BUF_T 256
+
enum argp_option_keys {
ARGP_VOLFILE_SERVER_KEY = 's',
ARGP_VOLUME_FILE_KEY = 'f',
@@ -87,6 +89,8 @@ enum argp_option_keys {
ARGP_FUSE_NO_ROOT_SQUASH_KEY = 167,
ARGP_LOGGER = 168,
ARGP_LOG_FORMAT = 169,
+ ARGP_LOG_BUF_SIZE = 170,
+ ARGP_LOG_FLUSH_TIMEOUT = 171,
};
struct _gfd_vol_top_priv_t {
diff --git a/libglusterfs/src/common-utils.c b/libglusterfs/src/common-utils.c
index e63ffa1420a..0ba803dcd80 100644
--- a/libglusterfs/src/common-utils.c
+++ b/libglusterfs/src/common-utils.c
@@ -488,6 +488,9 @@ gf_print_trace (int32_t signum, glusterfs_ctx_t *ctx)
* which helps in debugging.
*/
gf_log_flush();
+
+ gf_log_disable_suppression_before_exit (ctx);
+
/* Pending frames, (if any), list them in order */
gf_msg_plain_nomem (GF_LOG_ALERT, "pending frames:");
{
diff --git a/libglusterfs/src/glusterfs.h b/libglusterfs/src/glusterfs.h
index 96a203770e6..70df63eebbc 100644
--- a/libglusterfs/src/glusterfs.h
+++ b/libglusterfs/src/glusterfs.h
@@ -187,6 +187,19 @@
== DHT_LINKFILE_MODE)
#define DHT_LINKFILE_STR "linkto"
+#define GF_LOG_LRU_BUFSIZE_DEFAULT 5
+#define GF_LOG_LRU_BUFSIZE_MIN 0
+#define GF_LOG_LRU_BUFSIZE_MAX 20
+#define GF_LOG_LRU_BUFSIZE_MIN_STR "0"
+#define GF_LOG_LRU_BUFSIZE_MAX_STR "20"
+
+#define GF_LOG_FLUSH_TIMEOUT_DEFAULT 120
+#define GF_LOG_FLUSH_TIMEOUT_MIN 30
+#define GF_LOG_FLUSH_TIMEOUT_MAX 300
+#define GF_LOG_FLUSH_TIMEOUT_MIN_STR "30"
+#define GF_LOG_FLUSH_TIMEOUT_MAX_STR "300"
+
+
/* NOTE: add members ONLY at the end (just before _MAXVALUE) */
typedef enum {
GF_FOP_NULL = 0,
@@ -348,6 +361,8 @@ struct _cmd_args {
char *log_ident;
gf_log_logger_t logger;
gf_log_format_t log_format;
+ uint32_t log_buf_size;
+ uint32_t log_flush_timeout;
int32_t max_connect_attempts;
/* advanced options */
uint32_t volfile_server_port;
@@ -428,6 +443,7 @@ struct _glusterfs_ctx {
struct call_pool *pool;
void *event_pool;
void *iobuf_pool;
+ void *logbuf_pool;
pthread_mutex_t lock;
size_t page_size;
struct list_head graphs; /* double linked list of graphs - one per volfile parse */
diff --git a/libglusterfs/src/logging.c b/libglusterfs/src/logging.c
index 2afa2f35431..c7afbdd661c 100644
--- a/libglusterfs/src/logging.c
+++ b/libglusterfs/src/logging.c
@@ -46,6 +46,16 @@
#include "logging.h"
#include "defaults.h"
#include "glusterfs.h"
+#include "timer.h"
+
+void
+gf_log_flush_timeout_cbk (void *data);
+
+int
+gf_log_inject_timer_event (glusterfs_ctx_t *ctx);
+
+static void
+gf_log_flush_extra_msgs (glusterfs_ctx_t *ctx, uint32_t new);
static char *gf_level_strings[] = {"", /* NONE */
"M", /* EMERGENCY */
@@ -232,6 +242,107 @@ gf_log_get_xl_loglevel (void *this)
return xl->loglevel;
}
+void
+gf_log_set_log_buf_size (uint32_t buf_size)
+{
+ uint32_t old = 0;
+ glusterfs_ctx_t *ctx = THIS->ctx;
+
+ pthread_mutex_lock (&ctx->log.log_buf_lock);
+ {
+ old = ctx->log.lru_size;
+ ctx->log.lru_size = buf_size;
+ }
+ pthread_mutex_unlock (&ctx->log.log_buf_lock);
+
+ /* If the old size is less than/equal to the new size, then do nothing.
+ *
+ * But if the new size is less than the old size, then
+ * a. If the cur size of the buf is less than or equal the new size,
+ * then do nothing.
+ * b. But if the current size of the buf is greater than the new size,
+ * then flush the least recently used (cur size - new_size) msgs
+ * to disk.
+ */
+ if (buf_size < old)
+ gf_log_flush_extra_msgs (ctx, buf_size);
+}
+
+void
+gf_log_set_log_flush_timeout (uint32_t timeout)
+{
+ THIS->ctx->log.timeout = timeout;
+}
+
+log_buf_t *
+log_buf_new ()
+{
+ log_buf_t *buf = NULL;
+
+ buf = mem_get0 (THIS->ctx->logbuf_pool);
+
+ return buf;
+}
+
+/* If log_buf_init() fails (indicated by a return value of -1),
+ * call log_buf_destroy() to clean up memory allocated in heap and to return
+ * the log_buf_t object back to its memory pool.
+ */
+int
+log_buf_init (log_buf_t *buf, const char *domain, const char *file,
+ const char *function, int32_t line, gf_loglevel_t level,
+ int errnum, uint64_t msgid, char **appmsgstr, int graph_id)
+{
+ int ret = -1;
+
+ if (!buf || !domain || !file || !function || !appmsgstr || !*appmsgstr)
+ goto out;
+
+ buf->msg = gf_strdup (*appmsgstr);
+ if (!buf->msg)
+ goto out;
+
+ buf->msg_id = msgid;
+ buf->errnum = errnum;
+ buf->domain = gf_strdup (domain);
+ if (!buf->domain)
+ goto out;
+
+ buf->file = gf_strdup (file);
+ if (!buf->file)
+ goto out;
+
+ buf->function = gf_strdup (function);
+ if (!buf->function)
+ goto out;
+
+ buf->line = line;
+ buf->level = level;
+ buf->refcount = 0;
+ buf->graph_id = graph_id;
+ INIT_LIST_HEAD (&buf->msg_list);
+
+ ret = 0;
+out:
+ return ret;
+}
+
+int
+log_buf_destroy (log_buf_t *buf)
+{
+
+ if (!buf)
+ return -1;
+
+ GF_FREE (buf->msg);
+ GF_FREE (buf->domain);
+ GF_FREE (buf->file);
+ GF_FREE (buf->function);
+
+ mem_put (buf);
+ return 0;
+}
+
static void
gf_log_rotate(glusterfs_ctx_t *ctx)
{
@@ -293,6 +404,31 @@ gf_log_globals_fini (void)
* needs cleanup for, log.ident, log.filename, closelog, log file close
* rotate state, possibly under a lock */
pthread_mutex_destroy (&THIS->ctx->log.logfile_mutex);
+ pthread_mutex_destroy (&THIS->ctx->log.log_buf_lock);
+}
+
+void
+gf_log_disable_suppression_before_exit (glusterfs_ctx_t *ctx)
+{
+ /*
+ * First set log buf size to 0. This would ensure two things:
+ * i. that all outstanding log messages are flushed to disk, and
+ * ii. all subsequent calls to gf_msg will result in the logs getting
+ * directly flushed to disk without being buffered.
+ *
+ * Then, cancel the current log timer event.
+ */
+
+ gf_log_set_log_buf_size (0);
+ pthread_mutex_lock (&ctx->log.log_buf_lock);
+ {
+ if (ctx->log.log_flush_timer) {
+ gf_timer_call_cancel (ctx, ctx->log.log_flush_timer);
+ ctx->log.log_flush_timer = NULL;
+ }
+ }
+ pthread_mutex_unlock (&ctx->log.log_buf_lock);
+
}
/** gf_log_fini - function to perform the cleanup of the log information
@@ -312,6 +448,8 @@ gf_log_fini (void *data)
goto out;
}
+ gf_log_disable_suppression_before_exit (ctx);
+
pthread_mutex_lock (&ctx->log.logfile_mutex);
{
if (ctx->log.logfile) {
@@ -549,6 +687,12 @@ gf_log_globals_init (void *data)
ctx->log.sys_log_level = GF_LOG_CRITICAL;
ctx->log.logger = gf_logger_glusterlog;
ctx->log.logformat = gf_logformat_withmsgid;
+ ctx->log.lru_size = GF_LOG_LRU_BUFSIZE_DEFAULT;
+ ctx->log.timeout = GF_LOG_FLUSH_TIMEOUT_DEFAULT;
+
+ pthread_mutex_init (&ctx->log.log_buf_lock, NULL);
+
+ INIT_LIST_HEAD (&ctx->log.lru_queue);
#ifdef GF_LINUX_HOST_OS
/* For the 'syslog' output. one can grep 'GlusterFS' in syslog
@@ -587,7 +731,7 @@ gf_log_init (void *data, const char *file, const char *ident)
ctx->log.log_control_file_found = 0;
}
- if (!file){
+ if (!file) {
fprintf (stderr, "ERROR: no filename specified\n");
return -1;
}
@@ -612,7 +756,7 @@ gf_log_init (void *data, const char *file, const char *ident)
close (fd);
ctx->log.logfile = fopen (file, "a");
- if (!ctx->log.logfile){
+ if (!ctx->log.logfile) {
fprintf (stderr, "ERROR: failed to open logfile \"%s\" (%s)\n",
file, strerror (errno));
return -1;
@@ -1144,86 +1288,75 @@ out:
}
static int
-gf_log_syslog (const char *domain, const char *file, const char *function,
- int32_t line, gf_loglevel_t level, int errnum,
- uint64_t msgid, char **appmsgstr, char *callstr)
+gf_log_syslog (glusterfs_ctx_t *ctx, const char *domain, const char *file,
+ const char *function, int32_t line, gf_loglevel_t level,
+ int errnum, uint64_t msgid, char **appmsgstr, char *callstr,
+ int graph_id, gf_log_format_t fmt)
{
int priority;
- xlator_t *this = NULL;
- glusterfs_ctx_t *ctx = NULL;
-
- this = THIS;
- ctx = this->ctx;
SET_LOG_PRIO (level, priority);
/* log with appropriate format */
- if (ctx->log.logformat == gf_logformat_traditional) {
+ switch (fmt) {
+ case gf_logformat_traditional:
if (!callstr) {
- if (errnum) {
+ if (errnum)
syslog (priority, "[%s:%d:%s] %d-%s: %s [%s]",
- file, line, function,
- ((this->graph)?this->graph->id:0),
- domain, *appmsgstr, strerror(errnum));
- } else {
+ file, line, function, graph_id, domain,
+ *appmsgstr, strerror(errnum));
+ else
syslog (priority, "[%s:%d:%s] %d-%s: %s",
- file, line, function,
- ((this->graph)?this->graph->id:0),
- domain, *appmsgstr);
- }
+ file, line, function, graph_id, domain,
+ *appmsgstr);
} else {
- if (errnum) {
+ if (errnum)
syslog (priority, "[%s:%d:%s] %s %d-%s:"
" %s [%s]",
- file, line, function, callstr,
- ((this->graph)?this->graph->id:0),
+ file, line, function, callstr, graph_id,
domain, *appmsgstr, strerror(errnum));
- } else {
+ else
syslog (priority, "[%s:%d:%s] %s %d-%s: %s",
- file, line, function, callstr,
- ((this->graph)?this->graph->id:0),
+ file, line, function, callstr, graph_id,
domain, *appmsgstr);
- }
}
- } else if (ctx->log.logformat == gf_logformat_withmsgid) {
+ break;
+ case gf_logformat_withmsgid:
if (!callstr) {
- if (errnum) {
+ if (errnum)
syslog (priority, "[MSGID: %"PRIu64"]"
- " [%s:%d:%s] %d-%s: %s [%s]",
- msgid, file, line, function,
- ((this->graph)?this->graph->id:0),
- domain, *appmsgstr, strerror(errnum));
- } else {
+ " [%s:%d:%s] %d-%s: %s [%s]", msgid,
+ file, line, function, graph_id, domain,
+ *appmsgstr, strerror(errnum));
+ else
syslog (priority, "[MSGID: %"PRIu64"]"
" [%s:%d:%s] %d-%s: %s",
- msgid, file, line, function,
- ((this->graph)?this->graph->id:0),
+ msgid, file, line, function, graph_id,
domain, *appmsgstr);
- }
} else {
- if (errnum) {
+ if (errnum)
syslog (priority, "[MSGID: %"PRIu64"]"
" [%s:%d:%s] %s %d-%s: %s [%s]",
msgid, file, line, function, callstr,
- ((this->graph)?this->graph->id:0),
- domain, *appmsgstr, strerror(errnum));
- } else {
+ graph_id, domain, *appmsgstr,
+ strerror(errnum));
+ else
syslog (priority, "[MSGID: %"PRIu64"]"
" [%s:%d:%s] %s %d-%s: %s",
msgid, file, line, function, callstr,
- ((this->graph)?this->graph->id:0),
- domain, *appmsgstr);
- }
+ graph_id, domain, *appmsgstr);
}
- } else if (ctx->log.logformat == gf_logformat_cee) {
+ break;
+ case gf_logformat_cee:
/* TODO: Enhance CEE with additional parameters */
gf_syslog (GF_ERR_DEV, priority,
"[%s:%d:%s] %d-%s: %s",
- file, line, function,
- ((this->graph) ? this->graph->id:0),
- domain, *appmsgstr);
- } else {
+ file, line, function, graph_id, domain, *appmsgstr);
+ break;
+
+ default:
/* NOTE: should not get here without logging */
+ break;
}
/* TODO: There can be no errors from gf_syslog? */
@@ -1231,50 +1364,40 @@ gf_log_syslog (const char *domain, const char *file, const char *function,
}
static int
-gf_log_glusterlog (const char *domain, const char *file, const char *function,
- int32_t line, gf_loglevel_t level, int errnum,
- uint64_t msgid, char **appmsgstr, char *callstr)
+gf_log_glusterlog (glusterfs_ctx_t *ctx, const char *domain, const char *file,
+ const char *function, int32_t line, gf_loglevel_t level,
+ int errnum, uint64_t msgid, char **appmsgstr, char *callstr,
+ struct timeval tv, int graph_id, gf_log_format_t fmt)
{
char timestr[GF_LOG_TIMESTR_SIZE] = {0,};
- struct timeval tv = {0,};
char *header = NULL;
char *footer = NULL;
char *msg = NULL;
size_t hlen = 0, flen = 0, mlen = 0;
int ret = 0;
- xlator_t *this = NULL;
- glusterfs_ctx_t *ctx = NULL;
-
- this = THIS;
- ctx = this->ctx;
/* rotate if required */
gf_log_rotate(ctx);
- /* format the time stanp */
- ret = gettimeofday (&tv, NULL);
- if (-1 == ret)
- goto out;
+ /* format the time stamp */
gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
snprintf (timestr + strlen (timestr), sizeof timestr - strlen (timestr),
".%"GF_PRI_SUSECONDS, tv.tv_usec);
/* generate header and footer */
- if (ctx->log.logformat == gf_logformat_traditional) {
+ if (fmt == gf_logformat_traditional) {
if (!callstr) {
ret = gf_asprintf (&header, "[%s] %s [%s:%d:%s]"
" %d-%s: ",
timestr, gf_level_strings[level],
- file, line, function,
- ((this->graph)?this->graph->id:0),
+ file, line, function, graph_id,
domain);
} else {
ret = gf_asprintf (&header, "[%s] %s [%s:%d:%s] %s"
" %d-%s: ",
timestr, gf_level_strings[level],
file, line, function, callstr,
- ((this->graph)?this->graph->id:0),
- domain);
+ graph_id, domain);
}
if (-1 == ret) {
goto err;
@@ -1287,15 +1410,13 @@ gf_log_glusterlog (const char *domain, const char *file, const char *function,
" [%s:%d:%s] %d-%s: ",
timestr, gf_level_strings[level],
msgid, file, line, function,
- ((this->graph)?this->graph->id:0),
- domain);
+ graph_id, domain);
} else {
ret = gf_asprintf (&header, "[%s] %s [MSGID: %"PRIu64"]"
" [%s:%d:%s] %s %d-%s: ",
timestr, gf_level_strings[level],
msgid, file, line, function, callstr,
- ((this->graph)?this->graph->id:0),
- domain);
+ graph_id, domain);
}
if (-1 == ret) {
goto err;
@@ -1343,42 +1464,205 @@ gf_log_glusterlog (const char *domain, const char *file, const char *function,
* flushed during cores, it would be useful to retain some of the last
* few messages in memory */
pthread_mutex_unlock (&ctx->log.logfile_mutex);
+ ret = 0;
err:
GF_FREE (msg);
GF_FREE (header);
GF_FREE (footer);
-out:
return ret;
}
static int
-_gf_msg_internal (const char *domain, const char *file, const char *function,
- int32_t line, gf_loglevel_t level, int errnum, uint64_t msgid,
- char **appmsgstr, char *callstr)
+gf_syslog_log_repetitions (const char *domain, const char *file,
+ const char *function, int32_t line,
+ gf_loglevel_t level, int errnum, uint64_t msgid,
+ char **appmsgstr, char *callstr, int refcount,
+ struct timeval oldest, struct timeval latest,
+ int graph_id)
{
- const char *basename = NULL;
- int ret = -1;
- xlator_t *this = NULL;
- glusterfs_ctx_t *ctx = NULL;
+ int priority;
+ char timestr_latest[256] = {0,};
+ char timestr_oldest[256] = {0,};
- this = THIS;
- ctx = this->ctx;
+ SET_LOG_PRIO (level, priority);
- GET_FILE_NAME_TO_LOG (file, basename);
+ gf_time_fmt (timestr_latest, sizeof timestr_latest, latest.tv_sec,
+ gf_timefmt_FT);
+ snprintf (timestr_latest + strlen (timestr_latest),
+ sizeof (timestr_latest) - strlen (timestr_latest),
+ ".%"GF_PRI_SUSECONDS, latest.tv_usec);
+
+ gf_time_fmt (timestr_oldest, sizeof timestr_oldest, oldest.tv_sec,
+ gf_timefmt_FT);
+ snprintf (timestr_oldest + strlen (timestr_oldest),
+ sizeof (timestr_oldest) - strlen (timestr_oldest),
+ ".%"GF_PRI_SUSECONDS, oldest.tv_usec);
+
+ if (errnum) {
+ syslog (priority, "The message \"[MSGID: %"PRIu64"] [%s:%d:%s] "
+ "%d-%s: %s [%s] \" repeated %d times between %s and %s",
+ msgid, file, line, function, graph_id, domain,
+ *appmsgstr, strerror(errnum), refcount, timestr_oldest,
+ timestr_latest);
+ } else {
+ syslog (priority, "The message \"[MSGID: %"PRIu64"] [%s:%d:%s] "
+ "%d-%s: %s \" repeated %d times between %s and %s",
+ msgid, file, line, function, graph_id, domain,
+ *appmsgstr, refcount, timestr_oldest, timestr_latest);
+ }
+ return 0;
+}
+
+static int
+gf_glusterlog_log_repetitions (glusterfs_ctx_t *ctx, const char *domain,
+ const char *file, const char *function,
+ int32_t line, gf_loglevel_t level, int errnum,
+ uint64_t msgid, char **appmsgstr, char *callstr,
+ int refcount, struct timeval oldest,
+ struct timeval latest, int graph_id)
+{
+ int ret = 0;
+ size_t hlen = 0;
+ size_t flen = 0;
+ size_t mlen = 0;
+ char timestr_latest[256] = {0,};
+ char timestr_oldest[256] = {0,};
+ char errstr[256] = {0,};
+ char *header = NULL;
+ char *footer = NULL;
+ char *msg = NULL;
+
+ gf_log_rotate (ctx);
+
+ gf_time_fmt (timestr_latest, sizeof timestr_latest, latest.tv_sec,
+ gf_timefmt_FT);
+ snprintf (timestr_latest + strlen (timestr_latest),
+ sizeof (timestr_latest) - strlen (timestr_latest),
+ ".%"GF_PRI_SUSECONDS, latest.tv_usec);
+
+ gf_time_fmt (timestr_oldest, sizeof timestr_oldest, oldest.tv_sec,
+ gf_timefmt_FT);
+ snprintf (timestr_oldest + strlen (timestr_oldest),
+ sizeof (timestr_oldest) - strlen (timestr_oldest),
+ ".%"GF_PRI_SUSECONDS, oldest.tv_usec);
+
+ ret = gf_asprintf (&header, "The message \"%s [MSGID: %"PRIu64"]"
+ " [%s:%d:%s] %d-%s: ", gf_level_strings[level],
+ msgid, file, line, function, graph_id, domain);
+ if (-1 == ret)
+ goto err;
+
+ if (errnum)
+ snprintf (errstr, sizeof (errstr) - 1, " [%s]",
+ strerror (errnum));
+
+ ret = gf_asprintf (&footer, "%s\" repeated %d times between"
+ " [%s] and [%s]", errstr, refcount, timestr_oldest,
+ timestr_latest);
+ if (-1 == ret)
+ goto err;
+
+ /* generate the full message to log */
+ hlen = strlen (header);
+ flen = strlen (footer);
+ mlen = strlen (*appmsgstr);
+ msg = GF_MALLOC (hlen + flen + mlen + 1, gf_common_mt_char);
+
+ strcpy (msg, header);
+ strcpy (msg + hlen, *appmsgstr);
+ strcpy (msg + hlen + mlen, footer);
+
+ pthread_mutex_lock (&ctx->log.logfile_mutex);
+ {
+ if (ctx->log.logfile) {
+ fprintf (ctx->log.logfile, "%s\n", msg);
+ fflush (ctx->log.logfile);
+ } else if (ctx->log.loglevel >= level) {
+ fprintf (stderr, "%s\n", msg);
+ fflush (stderr);
+ }
- /* TODO: Plug in repeated message suppression for gluster logs here.
- * Comparison of last few messages stored based on, appmsgstr, errnum
- * msgid. */
+#ifdef GF_LINUX_HOST_OS
+ /* We want only serious logs in 'syslog', not our debug
+ * and trace logs */
+ if (ctx->log.gf_log_syslog && level &&
+ (level <= ctx->log.sys_log_level))
+ syslog ((level-1), "%s\n", msg);
+#endif
+ }
+
+ /* TODO: Plugin in memory log buffer retention here. For logs not
+ * flushed during cores, it would be useful to retain some of the last
+ * few messages in memory */
+ pthread_mutex_unlock (&ctx->log.logfile_mutex);
+ ret = 0;
+
+err:
+ GF_FREE (msg);
+ GF_FREE (header);
+ GF_FREE (footer);
+
+ return ret;
+}
+
+static int
+gf_log_print_with_repetitions (glusterfs_ctx_t *ctx, const char *domain,
+ const char *file, const char *function,
+ int32_t line, gf_loglevel_t level, int errnum,
+ uint64_t msgid, char **appmsgstr, char *callstr,
+ int refcount, struct timeval oldest,
+ struct timeval latest, int graph_id)
+{
+ int ret = -1;
+ gf_log_logger_t logger = 0;
+
+ logger = ctx->log.logger;
+
+
+ switch (logger) {
+ case gf_logger_syslog:
+ if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) {
+ ret = gf_syslog_log_repetitions (domain, file, function,
+ line, level, errnum,
+ msgid, appmsgstr,
+ callstr, refcount,
+ oldest, latest,
+ graph_id);
+ break;
+ }
+ case gf_logger_glusterlog:
+ ret = gf_glusterlog_log_repetitions (ctx, domain, file,
+ function, line, level,
+ errnum, msgid, appmsgstr,
+ callstr, refcount, oldest,
+ latest, graph_id);
+ break;
+ }
+
+ return ret;
+}
+
+static int
+gf_log_print_plain_fmt (glusterfs_ctx_t *ctx, const char *domain,
+ const char *file, const char *function, int32_t line,
+ gf_loglevel_t level, int errnum, uint64_t msgid,
+ char **appmsgstr, char *callstr, struct timeval tv,
+ int graph_id, gf_log_format_t fmt)
+{
+ int ret = -1;
+ gf_log_logger_t logger = 0;
+
+ logger = ctx->log.logger;
/* log to the configured logging service */
- switch (ctx->log.logger) {
+ switch (logger) {
case gf_logger_syslog:
if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) {
- ret = gf_log_syslog (domain, basename, function, line,
+ ret = gf_log_syslog (ctx, domain, file, function, line,
level, errnum, msgid, appmsgstr,
- callstr);
+ callstr, graph_id, fmt);
break;
}
/* NOTE: If syslog control file is absent, which is another
@@ -1386,15 +1670,335 @@ _gf_msg_internal (const char *domain, const char *file, const char *function,
* to the gluster log. The ideal way to do things would be to
* not have the extra control file check */
case gf_logger_glusterlog:
- ret = gf_log_glusterlog (domain, basename, function, line,
+ ret = gf_log_glusterlog (ctx, domain, file, function, line,
level, errnum, msgid, appmsgstr,
- callstr);
+ callstr, tv, graph_id, fmt);
break;
}
return ret;
}
+void
+gf_log_flush_message (log_buf_t *buf, glusterfs_ctx_t *ctx)
+{
+ if (buf->refcount == 1) {
+ (void) gf_log_print_plain_fmt (ctx, buf->domain, buf->file,
+ buf->function, buf->line,
+ buf->level, buf->errnum,
+ buf->msg_id, &buf->msg, NULL,
+ buf->latest, buf->graph_id,
+ gf_logformat_withmsgid);
+ }
+
+ if (buf->refcount > 1) {
+ gf_log_print_with_repetitions (ctx, buf->domain, buf->file,
+ buf->function, buf->line,
+ buf->level, buf->errnum,
+ buf->msg_id, &buf->msg, NULL,
+ buf->refcount, buf->oldest,
+ buf->latest, buf->graph_id);
+ }
+ return;
+}
+
+static void
+gf_log_flush_list (struct list_head *copy, glusterfs_ctx_t *ctx)
+{
+ log_buf_t *iter = NULL;
+ log_buf_t *tmp = NULL;
+
+ list_for_each_entry_safe (iter, tmp, copy, msg_list) {
+ gf_log_flush_message (iter, ctx);
+ list_del_init (&iter->msg_list);
+ log_buf_destroy (iter);
+ }
+}
+
+void
+gf_log_flush_msgs (glusterfs_ctx_t *ctx)
+{
+ struct list_head copy;
+
+ INIT_LIST_HEAD (&copy);
+
+ pthread_mutex_lock (&ctx->log.log_buf_lock);
+ {
+ list_splice_init (&ctx->log.lru_queue, &copy);
+ ctx->log.lru_cur_size = 0;
+ }
+ pthread_mutex_unlock (&ctx->log.log_buf_lock);
+
+ gf_log_flush_list (&copy, ctx);
+
+ return;
+}
+
+static void
+gf_log_flush_extra_msgs (glusterfs_ctx_t *ctx, uint32_t new)
+{
+ int count = 0;
+ int i = 0;
+ log_buf_t *iter = NULL;
+ log_buf_t *tmp = NULL;
+ struct list_head copy;
+
+ INIT_LIST_HEAD (&copy);
+
+ /* If the number of outstanding log messages does not cause list
+ * overflow even after reducing the size of the list, then do nothing.
+ * Otherwise (that is if there are more items in the list than there
+ * need to be after reducing its size), move the least recently used
+ * 'diff' elements to be flushed into a separate list...
+ */
+
+ pthread_mutex_lock (&ctx->log.log_buf_lock);
+ {
+ if (ctx->log.lru_cur_size <= new)
+ goto unlock;
+ count = ctx->log.lru_cur_size - new;
+ list_for_each_entry_safe (iter, tmp, &ctx->log.lru_queue,
+ msg_list) {
+ if (i == count)
+ break;
+
+ list_del_init (&iter->msg_list);
+ list_add_tail (&iter->msg_list, &copy);
+ i++;
+ }
+ ctx->log.lru_cur_size = ctx->log.lru_cur_size - count;
+ }
+ // ... quickly unlock ...
+unlock:
+ pthread_mutex_unlock (&ctx->log.log_buf_lock);
+ if (list_empty (&copy))
+ return;
+
+ // ... and then flush them outside the lock.
+ gf_log_flush_list (&copy, ctx);
+
+ return;
+}
+
+static int
+__gf_log_inject_timer_event (glusterfs_ctx_t *ctx)
+{
+ int ret = -1;
+ struct timespec timeout = {0,};
+
+ if (ctx->log.log_flush_timer) {
+ gf_timer_call_cancel (ctx, ctx->log.log_flush_timer);
+ ctx->log.log_flush_timer = NULL;
+ }
+
+ timeout.tv_sec = ctx->log.timeout;
+ timeout.tv_nsec = 0;
+
+ ctx->log.log_flush_timer = gf_timer_call_after (ctx, timeout,
+ gf_log_flush_timeout_cbk,
+ (void *)ctx);
+ if (!ctx->log.log_flush_timer)
+ goto out;
+
+ ret = 0;
+
+out:
+ return ret;
+}
+
+int
+gf_log_inject_timer_event (glusterfs_ctx_t *ctx)
+{
+ int ret = -1;
+
+ pthread_mutex_lock (&ctx->log.log_buf_lock);
+ {
+ ret = __gf_log_inject_timer_event (ctx);
+ }
+ pthread_mutex_unlock (&ctx->log.log_buf_lock);
+
+ return ret;
+}
+
+void
+gf_log_flush_timeout_cbk (void *data)
+{
+ glusterfs_ctx_t *ctx = NULL;
+
+ ctx = (glusterfs_ctx_t *) data;
+
+ gf_log_flush_msgs (ctx);
+
+ (void) gf_log_inject_timer_event (ctx);
+
+ return;
+}
+
+static int
+_gf_msg_internal (const char *domain, const char *file, const char *function,
+ int32_t line, gf_loglevel_t level, int errnum, uint64_t msgid,
+ char **appmsgstr, char *callstr, int graph_id)
+{
+ int ret = -1;
+ uint32_t size = 0;
+ const char *basename = NULL;
+ xlator_t *this = NULL;
+ glusterfs_ctx_t *ctx = NULL;
+ log_buf_t *iter = NULL;
+ log_buf_t *buf_tmp = NULL;
+ log_buf_t *buf_new = NULL;
+ log_buf_t *first = NULL;
+ struct timeval tv = {0,};
+ gf_boolean_t found = _gf_false;
+ gf_boolean_t flush_lru = _gf_false;
+ gf_boolean_t flush_logged_msg = _gf_false;
+
+ this = THIS;
+ ctx = this->ctx;
+
+ GET_FILE_NAME_TO_LOG (file, basename);
+
+ ret = gettimeofday (&tv, NULL);
+ if (ret)
+ goto out;
+
+ /* If this function is called via _gf_msg_callingfn () (indicated by a
+ * non-NULL callstr), or if the logformat is traditional, flush the
+ * message directly to disk.
+ */
+
+ if ((callstr) || (ctx->log.logformat == gf_logformat_traditional)) {
+ ret = gf_log_print_plain_fmt (ctx, domain, basename, function,
+ line, level, errnum, msgid,
+ appmsgstr, callstr, tv, graph_id,
+ gf_logformat_traditional);
+ goto out;
+ }
+
+ pthread_mutex_lock (&ctx->log.log_buf_lock);
+ {
+ /* Check if the msg being logged is already part of the list */
+ list_for_each_entry_safe_reverse (iter, buf_tmp,
+ &ctx->log.lru_queue,
+ msg_list) {
+ if (first == NULL)
+ // Remember the first (lru) element in first ptr
+ first = iter;
+
+ /* Try to fail the search early on by doing the less
+ * expensive integer comparisons and continue to string
+ * parameter comparisons only after all int parameters
+ * are found to be matching.
+ */
+ if (line != iter->line)
+ continue;
+
+ if (errnum != iter->errnum)
+ continue;
+
+ if (msgid != iter->msg_id)
+ continue;
+
+ if (level != iter->level)
+ continue;
+
+ if (graph_id != iter->graph_id)
+ continue;
+
+ if (strcmp (domain, iter->domain))
+ continue;
+
+ if (strcmp (basename, iter->file))
+ continue;
+
+ if (strcmp (function, iter->function))
+ continue;
+
+ if (strcmp (*appmsgstr, iter->msg))
+ continue;
+
+ //Ah! Found a match!
+ list_move_tail (&iter->msg_list, &ctx->log.lru_queue);
+ iter->refcount++;
+ found = _gf_true;
+ //Update the 'latest' timestamp.
+ memcpy ((void *)&(iter->latest), (void *)&tv,
+ sizeof (struct timeval));
+ break;
+ }
+ if (found) {
+ ret = 0;
+ goto unlock;
+ }
+ // else ...
+
+ size = ctx->log.lru_size;
+ /* If the upper limit on the log buf size is 0, flush the msg to
+ * disk directly after unlock. There's no need to buffer the
+ * msg here.
+ */
+ if (size == 0) {
+ flush_logged_msg = _gf_true;
+ goto unlock;
+ } else if ((ctx->log.lru_cur_size + 1) > size) {
+ /* If the list is full, flush the lru msg to disk and also
+ * release it after unlock, and ...
+ * */
+ list_del_init (&first->msg_list);
+ ctx->log.lru_cur_size--;
+ flush_lru = _gf_true;
+ }
+ /* create a new list element, initialise and enqueue it.
+ * Additionally, this being the first occurrence of the msg,
+ * log it directly to disk after unlock. */
+ buf_new = log_buf_new ();
+ if (!buf_new) {
+ ret = -1;
+ goto unlock;
+ }
+ ret = log_buf_init (buf_new, domain, basename, function, line,
+ level, errnum, msgid, appmsgstr, graph_id);
+ if (ret) {
+ log_buf_destroy (buf_new);
+ goto unlock;
+ }
+
+ memcpy ((void *)&(buf_new->latest), (void *)&tv,
+ sizeof (struct timeval));
+ memcpy ((void *)&(buf_new->oldest), (void *)&tv,
+ sizeof (struct timeval));
+
+ list_add_tail (&buf_new->msg_list, &ctx->log.lru_queue);
+ ctx->log.lru_cur_size++;
+ flush_logged_msg = _gf_true;
+ ret = 0;
+ }
+unlock:
+ pthread_mutex_unlock (&ctx->log.log_buf_lock);
+
+ /* Value of @ret is a don't-care below since irrespective of success or
+ * failure post setting of @flush_lru, @first must be flushed and freed.
+ */
+ if (flush_lru) {
+ gf_log_flush_message (first, ctx);
+ log_buf_destroy (first);
+ }
+ /* Similarly, irrespective of whether all operations since setting of
+ * @flush_logged_msg were successful or not, flush the message being
+ * logged to disk in the plain format.
+ */
+ if (flush_logged_msg) {
+ ret = gf_log_print_plain_fmt (ctx, domain, basename,
+ function, line, level,
+ errnum, msgid, appmsgstr,
+ callstr, tv, graph_id,
+ gf_logformat_withmsgid);
+ }
+
+out:
+ return ret;
+}
+
int
_gf_msg (const char *domain, const char *file, const char *function,
int32_t line, gf_loglevel_t level, int errnum, int trace,
@@ -1417,6 +2021,10 @@ _gf_msg (const char *domain, const char *file, const char *function,
}
this = THIS;
+
+ if (this == NULL)
+ return -1;
+
ctx = this->ctx;
if (ctx == NULL) {
/* messages before context initialization are ignored */
@@ -1449,9 +2057,10 @@ _gf_msg (const char *domain, const char *file, const char *function,
/* log */
if (ret != -1)
- ret = _gf_msg_internal(domain, file, function, line, level,
+ ret = _gf_msg_internal (domain, file, function, line, level,
errnum, msgid, &msgstr,
- (passcallstr? callstr : NULL));
+ (passcallstr? callstr : NULL),
+ (this->graph)? this->graph->id : 0);
else
/* man (3) vasprintf states on error strp contents
* are undefined, be safe */
diff --git a/libglusterfs/src/logging.h b/libglusterfs/src/logging.h
index 0c5c3b4c41c..f19fe9e1002 100644
--- a/libglusterfs/src/logging.h
+++ b/libglusterfs/src/logging.h
@@ -16,10 +16,12 @@
#include "config.h"
#endif
+#include <sys/time.h>
#include <stdint.h>
#include <stdio.h>
#include <stdarg.h>
#include <pthread.h>
+#include "list.h"
#ifdef GF_DARWIN_HOST_OS
#define GF_PRI_FSBLK "u"
@@ -96,23 +98,46 @@ typedef enum {
#define DEFAULT_LOG_LEVEL GF_LOG_INFO
typedef struct gf_log_handle_ {
- pthread_mutex_t logfile_mutex;
- uint8_t logrotate;
- gf_loglevel_t loglevel;
- int gf_log_syslog;
- gf_loglevel_t sys_log_level;
- char gf_log_xl_log_set;
- char *filename;
- FILE *logfile;
- FILE *gf_log_logfile;
- char *cmd_log_filename;
- FILE *cmdlogfile;
- gf_log_logger_t logger;
- gf_log_format_t logformat;
- char *ident;
- int log_control_file_found;
+ pthread_mutex_t logfile_mutex;
+ uint8_t logrotate;
+ gf_loglevel_t loglevel;
+ int gf_log_syslog;
+ gf_loglevel_t sys_log_level;
+ char gf_log_xl_log_set;
+ char *filename;
+ FILE *logfile;
+ FILE *gf_log_logfile;
+ char *cmd_log_filename;
+ FILE *cmdlogfile;
+ gf_log_logger_t logger;
+ gf_log_format_t logformat;
+ char *ident;
+ int log_control_file_found;
+ struct list_head lru_queue;
+ uint32_t lru_size;
+ uint32_t lru_cur_size;
+ uint32_t timeout;
+ pthread_mutex_t log_buf_lock;
+ struct _gf_timer *log_flush_timer;
} gf_log_handle_t;
+
+typedef struct log_buf_ {
+ char *msg;
+ uint64_t msg_id;
+ int errnum;
+ struct timeval oldest;
+ struct timeval latest;
+ char *domain;
+ char *file;
+ char *function;
+ int32_t line;
+ gf_loglevel_t level;
+ int refcount;
+ int graph_id;
+ struct list_head msg_list;
+} log_buf_t;
+
void gf_log_globals_init (void *ctx);
int gf_log_init (void *data, const char *filename, const char *ident);
@@ -277,6 +302,23 @@ gf_log_set_logger (gf_log_logger_t logger);
void
gf_log_set_logformat (gf_log_format_t format);
+void
+gf_log_set_log_buf_size (uint32_t buf_size);
+
+void
+gf_log_set_log_flush_timeout (uint32_t timeout);
+
+struct _glusterfs_ctx;
+
+void
+gf_log_flush_msgs (struct _glusterfs_ctx *ctx);
+
+int
+gf_log_inject_timer_event (struct _glusterfs_ctx *ctx);
+
+void
+gf_log_disable_suppression_before_exit (struct _glusterfs_ctx *ctx);
+
#define GF_DEBUG(xl, format, args...) \
gf_log ((xl)->name, GF_LOG_DEBUG, format, ##args)
#define GF_INFO(xl, format, args...) \
diff --git a/xlators/debug/io-stats/src/io-stats.c b/xlators/debug/io-stats/src/io-stats.c
index 5b4c833fbc0..2a5eedefbd3 100644
--- a/xlators/debug/io-stats/src/io-stats.c
+++ b/xlators/debug/io-stats/src/io-stats.c
@@ -2673,6 +2673,8 @@ reconfigure (xlator_t *this, dict_t *options)
int log_level = -1;
int log_format = -1;
int logger = -1;
+ uint32_t log_buf_size = 0;
+ uint32_t log_flush_timeout = 0;
if (!this || !this->private)
goto out;
@@ -2712,6 +2714,13 @@ reconfigure (xlator_t *this, dict_t *options)
gf_log_set_logformat (log_format);
}
+ GF_OPTION_RECONF ("log-buf-size", log_buf_size, options, uint32, out);
+ gf_log_set_log_buf_size (log_buf_size);
+
+ GF_OPTION_RECONF ("log-flush-timeout", log_flush_timeout, options,
+ time, out);
+ gf_log_set_log_flush_timeout (log_flush_timeout);
+
ret = 0;
out:
gf_log (this->name, GF_LOG_DEBUG, "reconfigure returning %d", ret);
@@ -2751,6 +2760,8 @@ init (xlator_t *this)
char *log_str = NULL;
int log_level = -1;
int ret = -1;
+ uint32_t log_buf_size = 0;
+ uint32_t log_flush_timeout = 0;
if (!this)
return -1;
@@ -2817,6 +2828,12 @@ init (xlator_t *this)
gf_log_set_logformat (log_format);
}
+ GF_OPTION_INIT ("log-buf-size", log_buf_size, uint32, out);
+ gf_log_set_log_buf_size (log_buf_size);
+
+ GF_OPTION_INIT ("log-flush-timeout", log_flush_timeout, time, out);
+ gf_log_set_log_flush_timeout (log_flush_timeout);
+
this->private = conf;
ret = 0;
@@ -3094,6 +3111,54 @@ struct volume_options options[] = {
.description = "Changes the log format for the bricks",
.value = { GF_LOG_FORMAT_NO_MSG_ID, GF_LOG_FORMAT_WITH_MSG_ID}
},
+ { .key = {"log-buf-size"},
+ .type = GF_OPTION_TYPE_INT,
+ .min = GF_LOG_LRU_BUFSIZE_MIN,
+ .max = GF_LOG_LRU_BUFSIZE_MAX,
+ .default_value = "5",
+ },
+ { .key = {"client-log-buf-size"},
+ .type = GF_OPTION_TYPE_INT,
+ .min = GF_LOG_LRU_BUFSIZE_MIN,
+ .max = GF_LOG_LRU_BUFSIZE_MAX,
+ .default_value = "5",
+ .description = "This option determines the maximum number of unique "
+ "log messages that can be buffered for a time equal to"
+ " the value of the option client-log-flush-timeout."
+ },
+ { .key = {"brick-log-buf-size"},
+ .type = GF_OPTION_TYPE_INT,
+ .min = GF_LOG_LRU_BUFSIZE_MIN,
+ .max = GF_LOG_LRU_BUFSIZE_MAX,
+ .default_value = "5",
+ .description = "This option determines the maximum number of unique "
+ "log messages that can be buffered for a time equal to"
+ " the value of the option brick-log-flush-timeout."
+ },
+ { .key = {"log-flush-timeout"},
+ .type = GF_OPTION_TYPE_TIME,
+ .min = GF_LOG_FLUSH_TIMEOUT_MIN,
+ .max = GF_LOG_FLUSH_TIMEOUT_MAX,
+ .default_value = "120",
+ },
+ { .key = {"client-log-flush-timeout"},
+ .type = GF_OPTION_TYPE_TIME,
+ .min = GF_LOG_FLUSH_TIMEOUT_MIN,
+ .max = GF_LOG_FLUSH_TIMEOUT_MAX,
+ .default_value = "120",
+ .description = "This option determines the maximum number of unique "
+ "log messages that can be buffered for a time equal to"
+ " the value of the option client-log-flush-timeout."
+ },
+ { .key = {"brick-log-flush-timeout"},
+ .type = GF_OPTION_TYPE_TIME,
+ .min = GF_LOG_FLUSH_TIMEOUT_MIN,
+ .max = GF_LOG_FLUSH_TIMEOUT_MAX,
+ .default_value = "120",
+ .description = "This option determines the maximum number of unique "
+ "log messages that can be buffered for a time equal to"
+ " the value of the option brick-log-flush-timeout."
+ },
{ .key = {NULL} },
};
diff --git a/xlators/mgmt/glusterd/src/glusterd-volgen.c b/xlators/mgmt/glusterd/src/glusterd-volgen.c
index 6ce38e91b5b..197e4b9ecdb 100644
--- a/xlators/mgmt/glusterd/src/glusterd-volgen.c
+++ b/xlators/mgmt/glusterd/src/glusterd-volgen.c
@@ -1366,6 +1366,46 @@ log_format_option_handler (volgen_graph_t *graph, struct volopt_map_entry *vme,
}
static int
+log_buf_size_option_handler (volgen_graph_t *graph,
+ struct volopt_map_entry *vme,
+ void *param)
+{
+ char *role = NULL;
+ struct volopt_map_entry vme2 = {0,};
+
+ role = (char *) param;
+
+ if (strcmp (vme->option, "!log-buf-size") != 0 ||
+ !strstr (vme->key, role))
+ return 0;
+
+ memcpy (&vme2, vme, sizeof (vme2));
+ vme2.option = "log-buf-size";
+
+ return basic_option_handler (graph, &vme2, NULL);
+}
+
+static int
+log_flush_timeout_option_handler (volgen_graph_t *graph,
+ struct volopt_map_entry *vme,
+ void *param)
+{
+ char *role = NULL;
+ struct volopt_map_entry vme2 = {0,};
+
+ role = (char *) param;
+
+ if (strcmp (vme->option, "!log-flush-timeout") != 0 ||
+ !strstr (vme->key, role))
+ return 0;
+
+ memcpy (&vme2, vme, sizeof (vme2));
+ vme2.option = "log-flush-timeout";
+
+ return basic_option_handler (graph, &vme2, NULL);
+}
+
+static int
volgen_graph_set_xl_options (volgen_graph_t *graph, dict_t *dict)
{
int32_t ret = -1;
@@ -1423,6 +1463,12 @@ server_spec_option_handler (volgen_graph_t *graph,
if (!ret)
ret = log_format_option_handler (graph, vme, "brick");
+ if (!ret)
+ ret = log_buf_size_option_handler (graph, vme, "brick");
+
+ if (!ret)
+ ret = log_flush_timeout_option_handler (graph, vme, "brick");
+
return ret;
}
@@ -2780,6 +2826,18 @@ client_graph_builder (volgen_graph_t *graph, glusterd_volinfo_t *volinfo,
gf_log (this->name, GF_LOG_WARNING, "changing client log format"
" failed");
+ ret = volgen_graph_set_options_generic (graph, set_dict, "client",
+ &log_buf_size_option_handler);
+ if (ret)
+ gf_log (this->name, GF_LOG_WARNING, "Failed to change "
+ "log-buf-size option");
+
+ ret = volgen_graph_set_options_generic (graph, set_dict, "client",
+ &log_flush_timeout_option_handler);
+ if (ret)
+ gf_log (this->name, GF_LOG_WARNING, "Failed to change "
+ "log-flush-timeout option");
+
out:
return ret;
}
@@ -3139,7 +3197,23 @@ build_shd_graph (volgen_graph_t *graph, dict_t *mod_dict)
&log_format_option_handler);
if (ret)
gf_log (this->name, GF_LOG_WARNING, "changing log "
- "format level of self-heal daemon failed");
+ "format of self-heal daemon failed");
+
+ ret = volgen_graph_set_options_generic (graph, set_dict,
+ "client",
+ &log_buf_size_option_handler);
+ if (ret)
+ gf_log (this->name, GF_LOG_WARNING, "changing "
+ "log-buf-size for self-heal daemon failed");
+
+ ret = volgen_graph_set_options_generic (graph, set_dict,
+ "client",
+ &log_flush_timeout_option_handler);
+ if (ret)
+ gf_log (this->name, GF_LOG_WARNING, "changing "
+ "log-flush-timeout for self-heal daemon "
+ "failed");
+
ret = dict_reset (set_dict);
if (ret)
diff --git a/xlators/mgmt/glusterd/src/glusterd-volume-set.c b/xlators/mgmt/glusterd/src/glusterd-volume-set.c
index 9ad808bedbc..8998d8478d0 100644
--- a/xlators/mgmt/glusterd/src/glusterd-volume-set.c
+++ b/xlators/mgmt/glusterd/src/glusterd-volume-set.c
@@ -632,6 +632,28 @@ struct volopt_map_entry glusterd_volopt_map[] = {
.op_version = 4,
.flags = OPT_FLAG_CLIENT_OPT
},
+ { .key = "diagnostics.brick-log-buf-size",
+ .voltype = "debug/io-stats",
+ .option = "!log-buf-size",
+ .op_version = 4
+ },
+ { .key = "diagnostics.client-log-buf-size",
+ .voltype = "debug/io-stats",
+ .option = "!log-buf-size",
+ .op_version = 4,
+ .flags = OPT_FLAG_CLIENT_OPT
+ },
+ { .key = "diagnostics.brick-log-flush-timeout",
+ .voltype = "debug/io-stats",
+ .option = "!log-flush-timeout",
+ .op_version = 4
+ },
+ { .key = "diagnostics.client-log-flush-timeout",
+ .voltype = "debug/io-stats",
+ .option = "!log-flush-timeout",
+ .op_version = 4,
+ .flags = OPT_FLAG_CLIENT_OPT
+ },
/* IO-cache xlator options */
{ .key = "performance.cache-max-file-size",