diff options
author | Krutika Dhananjay <kdhananj@redhat.com> | 2014-02-07 11:02:10 +0530 |
---|---|---|
committer | Vijay Bellur <vbellur@redhat.com> | 2014-04-30 23:52:28 -0700 |
commit | 630d46d714a233919664c035f2c5c48c028777e8 (patch) | |
tree | e7e79b240e23fde447989a4e1adc625b1858d17d | |
parent | f63fbca7540a4c9ce090e1ed5941ed8777ff6316 (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.h | 2 | ||||
-rw-r--r-- | api/src/glfs.c | 11 | ||||
-rw-r--r-- | glusterfsd/src/glusterfsd.c | 74 | ||||
-rw-r--r-- | glusterfsd/src/glusterfsd.h | 4 | ||||
-rw-r--r-- | libglusterfs/src/common-utils.c | 3 | ||||
-rw-r--r-- | libglusterfs/src/glusterfs.h | 16 | ||||
-rw-r--r-- | libglusterfs/src/logging.c | 793 | ||||
-rw-r--r-- | libglusterfs/src/logging.h | 72 | ||||
-rw-r--r-- | xlators/debug/io-stats/src/io-stats.c | 65 | ||||
-rw-r--r-- | xlators/mgmt/glusterd/src/glusterd-volgen.c | 76 | ||||
-rw-r--r-- | xlators/mgmt/glusterd/src/glusterd-volume-set.c | 22 |
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 (©); + + pthread_mutex_lock (&ctx->log.log_buf_lock); + { + list_splice_init (&ctx->log.lru_queue, ©); + ctx->log.lru_cur_size = 0; + } + pthread_mutex_unlock (&ctx->log.log_buf_lock); + + gf_log_flush_list (©, 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 (©); + + /* 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, ©); + 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 (©)) + return; + + // ... and then flush them outside the lock. + gf_log_flush_list (©, 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", |