"Fossies" - the Fresh Open Source Software Archive

Member "glusterfs-8.2/libglusterfs/src/logging.c" (16 Sep 2020, 68982 Bytes) of package /linux/misc/glusterfs-8.2.tar.gz:


As a special service "Fossies" has tried to format the requested source page into HTML format using (guessed) C and C++ source code syntax highlighting (style: standard) with prefixed line numbers and code folding option. Alternatively you can here view or download the uninterpreted source code file. For more information about "logging.c" see the Fossies "Dox" file reference documentation.

    1 /*
    2   Copyright (c) 2008-2012 Red Hat, Inc. <http://www.redhat.com>
    3   This file is part of GlusterFS.
    4 
    5   This file is licensed to you under your choice of the GNU Lesser
    6   General Public License, version 3 or any later version (LGPLv3 or
    7   later), or the GNU General Public License, version 2 (GPLv2), in all
    8   cases as published by the Free Software Foundation.
    9 */
   10 
   11 #include <errno.h>
   12 #include <pthread.h>
   13 #include <stdio.h>
   14 #include <stdarg.h>
   15 #include <time.h>
   16 #include <locale.h>
   17 #include <string.h>
   18 #include <stdlib.h>
   19 #include <syslog.h>
   20 #include <sys/resource.h>
   21 
   22 #ifdef HAVE_BACKTRACE
   23 #include <execinfo.h>
   24 #else
   25 #include "execinfo_compat.h"
   26 #endif
   27 
   28 #include <sys/stat.h>
   29 
   30 #include "glusterfs/syscall.h"
   31 
   32 #define GF_JSON_MSG_LENGTH 8192
   33 #define GF_SYSLOG_CEE_FORMAT                                                   \
   34     "@cee: {\"msg\": \"%s\", \"gf_code\": \"%u\", \"gf_message\": \"%s\"}"
   35 #define GF_LOG_CONTROL_FILE "/etc/glusterfs/logger.conf"
   36 #define GF_LOG_BACKTRACE_DEPTH 5
   37 #define GF_LOG_BACKTRACE_SIZE 4096
   38 #define GF_LOG_TIMESTR_SIZE 256
   39 #define GF_MAX_SLOG_PAIR_COUNT 100
   40 
   41 #include "glusterfs/logging.h"
   42 #include "glusterfs/glusterfs.h"
   43 #include "glusterfs/timer.h"
   44 #include "glusterfs/libglusterfs-messages.h"
   45 
   46 /* Do not replace gf_log in TEST_LOG with gf_msg, as there is a slight chance
   47  * that it could lead to an infinite recursion.*/
   48 #define TEST_LOG(__msg, __args...)                                             \
   49     gf_log("logging-infra", GF_LOG_DEBUG, __msg, ##__args);
   50 
   51 static void
   52 gf_log_flush_timeout_cbk(void *data);
   53 
   54 int
   55 gf_log_inject_timer_event(glusterfs_ctx_t *ctx);
   56 
   57 static void
   58 gf_log_flush_extra_msgs(glusterfs_ctx_t *ctx, uint32_t new);
   59 
   60 static int
   61 log_buf_init(log_buf_t *buf, const char *domain, const char *file,
   62              const char *function, int32_t line, gf_loglevel_t level,
   63              int errnum, uint64_t msgid, char **appmsgstr, int graph_id);
   64 static void
   65 gf_log_rotate(glusterfs_ctx_t *ctx);
   66 
   67 static char gf_level_strings[] = {
   68     ' ', /* NONE */
   69     'M', /* EMERGENCY */
   70     'A', /* ALERT */
   71     'C', /* CRITICAL */
   72     'E', /* ERROR */
   73     'W', /* WARNING */
   74     'N', /* NOTICE */
   75     'I', /* INFO */
   76     'D', /* DEBUG */
   77     'T', /* TRACE */
   78 };
   79 
   80 void
   81 gf_log_logrotate(int signum)
   82 {
   83     if (THIS->ctx) {
   84         THIS->ctx->log.logrotate = 1;
   85         THIS->ctx->log.cmd_history_logrotate = 1;
   86     }
   87 }
   88 
   89 void
   90 gf_log_enable_syslog(void)
   91 {
   92     if (THIS->ctx)
   93         THIS->ctx->log.gf_log_syslog = 1;
   94 }
   95 
   96 void
   97 gf_log_disable_syslog(void)
   98 {
   99     if (THIS->ctx)
  100         THIS->ctx->log.gf_log_syslog = 0;
  101 }
  102 
  103 gf_loglevel_t
  104 gf_log_get_loglevel(void)
  105 {
  106     if (THIS->ctx)
  107         return THIS->ctx->log.loglevel;
  108     else
  109         /* return global defaults (see gf_log_globals_init) */
  110         return GF_LOG_INFO;
  111 }
  112 
  113 void
  114 gf_log_set_loglevel(glusterfs_ctx_t *ctx, gf_loglevel_t level)
  115 {
  116     if (ctx)
  117         ctx->log.loglevel = level;
  118 }
  119 
  120 int
  121 gf_log_get_localtime(void)
  122 {
  123     if (THIS->ctx)
  124         return THIS->ctx->log.localtime;
  125     else
  126         /* return global defaults (see gf_log_globals_init) */
  127         return 0;
  128 }
  129 
  130 void
  131 gf_log_set_localtime(int on_off)
  132 {
  133     if (THIS->ctx)
  134         THIS->ctx->log.localtime = on_off;
  135 }
  136 
  137 void
  138 gf_log_flush(void)
  139 {
  140     xlator_t *this = THIS;
  141     glusterfs_ctx_t *ctx = this->ctx;
  142 
  143     if (ctx && ctx->log.logger == gf_logger_glusterlog) {
  144         pthread_mutex_lock(&ctx->log.logfile_mutex);
  145         fflush(ctx->log.gf_log_logfile);
  146         pthread_mutex_unlock(&ctx->log.logfile_mutex);
  147     }
  148 
  149     return;
  150 }
  151 
  152 void
  153 gf_log_set_xl_loglevel(void *this, gf_loglevel_t level)
  154 {
  155     xlator_t *xl = this;
  156     if (!xl)
  157         return;
  158     xl->loglevel = level;
  159 }
  160 
  161 /* TODO: The following get/set functions are yet not invoked from anywhere
  162  * in the code. The _intention_ is to pass CLI arguments to various daemons
  163  * that are started, which would then invoke these set APIs as required.
  164  *
  165  * glusterd would read the defaults from its .vol file configuration shipped
  166  * as a part of the packages distributed.
  167  *
  168  * For any gluster* daemon that is started the shipped configuration becomes the
  169  * default, if a volume has to change its logging format or logger, then a
  170  * gluster CLI is invoked to set this property for the volume in question.
  171  *
  172  * The property is maintained by glusterd, and passed to the daemon as a CLI
  173  * option, IOW persistence of the option is maintained by glusterd persistent
  174  * storage (i.e .vol file) only
  175  *
  176  * care needs to be taken to configure and start daemons based on the versions
  177  * that supports these features */
  178 
  179 void
  180 gf_log_set_logformat(gf_log_format_t format)
  181 {
  182     if (THIS->ctx)
  183         THIS->ctx->log.logformat = format;
  184 }
  185 
  186 void
  187 gf_log_set_logger(gf_log_logger_t logger)
  188 {
  189     if (THIS->ctx)
  190         THIS->ctx->log.logger = logger;
  191 }
  192 
  193 gf_loglevel_t
  194 gf_log_get_xl_loglevel(void *this)
  195 {
  196     xlator_t *xl = this;
  197     if (!xl)
  198         return 0;
  199     return xl->loglevel;
  200 }
  201 
  202 void
  203 gf_log_set_log_buf_size(uint32_t buf_size)
  204 {
  205     uint32_t old = 0;
  206     glusterfs_ctx_t *ctx = THIS->ctx;
  207 
  208     pthread_mutex_lock(&ctx->log.log_buf_lock);
  209     {
  210         old = ctx->log.lru_size;
  211         ctx->log.lru_size = buf_size;
  212     }
  213     pthread_mutex_unlock(&ctx->log.log_buf_lock);
  214 
  215     /* If the old size is less than/equal to the new size, then do nothing.
  216      *
  217      * But if the new size is less than the old size, then
  218      *   a. If the cur size of the buf is less than or equal the new size,
  219      *      then do nothing.
  220      *   b. But if the current size of the buf is greater than the new size,
  221      *      then flush the least recently used (cur size - new_size) msgs
  222      *      to disk.
  223      */
  224     if (buf_size < old)
  225         gf_log_flush_extra_msgs(ctx, buf_size);
  226 }
  227 
  228 void
  229 gf_log_set_log_flush_timeout(uint32_t timeout)
  230 {
  231     THIS->ctx->log.timeout = timeout;
  232 }
  233 
  234 /* If log_buf_init() fails (indicated by a return value of -1),
  235  * call log_buf_destroy() to clean up memory allocated in heap and to return
  236  * the log_buf_t object back to its memory pool.
  237  */
  238 static int
  239 log_buf_init(log_buf_t *buf, const char *domain, const char *file,
  240              const char *function, int32_t line, gf_loglevel_t level,
  241              int errnum, uint64_t msgid, char **appmsgstr, int graph_id)
  242 {
  243     int ret = -1;
  244 
  245     if (!buf || !domain || !file || !function || !appmsgstr || !*appmsgstr)
  246         goto out;
  247 
  248     buf->msg = gf_strdup(*appmsgstr);
  249     if (!buf->msg)
  250         goto out;
  251 
  252     buf->msg_id = msgid;
  253     buf->errnum = errnum;
  254     buf->domain = gf_strdup(domain);
  255     if (!buf->domain)
  256         goto out;
  257 
  258     buf->file = gf_strdup(file);
  259     if (!buf->file)
  260         goto out;
  261 
  262     buf->function = gf_strdup(function);
  263     if (!buf->function)
  264         goto out;
  265 
  266     buf->line = line;
  267     buf->level = level;
  268     buf->refcount = 0;
  269     buf->graph_id = graph_id;
  270     INIT_LIST_HEAD(&buf->msg_list);
  271 
  272     ret = 0;
  273 out:
  274     return ret;
  275 }
  276 
  277 static int
  278 log_buf_destroy(log_buf_t *buf)
  279 {
  280     if (!buf)
  281         return -1;
  282 
  283     GF_FREE(buf->msg);
  284     GF_FREE(buf->domain);
  285     GF_FREE(buf->file);
  286     GF_FREE(buf->function);
  287 
  288     mem_put(buf);
  289     return 0;
  290 }
  291 
  292 static void
  293 gf_log_rotate(glusterfs_ctx_t *ctx)
  294 {
  295     int fd = -1;
  296     FILE *new_logfile = NULL;
  297     FILE *old_logfile = NULL;
  298 
  299     /* not involving locks on initial check to speed it up */
  300     if (ctx->log.logrotate) {
  301         /* let only one winner through on races */
  302         pthread_mutex_lock(&ctx->log.logfile_mutex);
  303 
  304         if (!ctx->log.logrotate) {
  305             pthread_mutex_unlock(&ctx->log.logfile_mutex);
  306             return;
  307         } else {
  308             ctx->log.logrotate = 0;
  309             pthread_mutex_unlock(&ctx->log.logfile_mutex);
  310         }
  311 
  312         fd = sys_open(ctx->log.filename, O_CREAT | O_WRONLY | O_APPEND,
  313                       S_IRUSR | S_IWUSR);
  314         if (fd < 0) {
  315             gf_smsg("logrotate", GF_LOG_ERROR, errno,
  316                     LG_MSG_OPEN_LOGFILE_FAILED, NULL);
  317             return;
  318         }
  319 
  320         new_logfile = fdopen(fd, "a");
  321         if (!new_logfile) {
  322             gf_smsg("logrotate", GF_LOG_CRITICAL, errno,
  323                     LG_MSG_OPEN_LOGFILE_FAILED, "filename=%s",
  324                     ctx->log.filename, NULL);
  325             sys_close(fd);
  326             return;
  327         }
  328 
  329         pthread_mutex_lock(&ctx->log.logfile_mutex);
  330         {
  331             if (ctx->log.logfile)
  332                 old_logfile = ctx->log.logfile;
  333 
  334             ctx->log.gf_log_logfile = ctx->log.logfile = new_logfile;
  335         }
  336         pthread_mutex_unlock(&ctx->log.logfile_mutex);
  337 
  338         if (old_logfile != NULL)
  339             fclose(old_logfile);
  340     }
  341 
  342     return;
  343 }
  344 
  345 void
  346 gf_log_globals_fini(void)
  347 {
  348     /* TODO: Nobody is invoking the fini, but cleanup needs to happen here,
  349      * needs cleanup for, log.ident, log.filename, closelog, log file close
  350      * rotate state, possibly under a lock */
  351     pthread_mutex_destroy(&THIS->ctx->log.logfile_mutex);
  352     pthread_mutex_destroy(&THIS->ctx->log.log_buf_lock);
  353 }
  354 
  355 void
  356 gf_log_disable_suppression_before_exit(glusterfs_ctx_t *ctx)
  357 {
  358     /*
  359      * First set log buf size to 0. This would ensure two things:
  360      * i. that all outstanding log messages are flushed to disk, and
  361      * ii. all subsequent calls to gf_msg will result in the logs getting
  362      *     directly flushed to disk without being buffered.
  363      *
  364      * Then, cancel the current log timer event.
  365      */
  366 
  367     gf_log_set_log_buf_size(0);
  368     pthread_mutex_lock(&ctx->log.log_buf_lock);
  369     {
  370         if (ctx->log.log_flush_timer) {
  371             gf_timer_call_cancel(ctx, ctx->log.log_flush_timer);
  372             ctx->log.log_flush_timer = NULL;
  373         }
  374     }
  375     pthread_mutex_unlock(&ctx->log.log_buf_lock);
  376 }
  377 
  378 /** gf_log_fini - function to perform the cleanup of the log information
  379  * @data - glusterfs context
  380  * @return: success: 0
  381  *          failure: -1
  382  */
  383 int
  384 gf_log_fini(void *data)
  385 {
  386     glusterfs_ctx_t *ctx = data;
  387     int ret = 0;
  388     FILE *old_logfile = NULL;
  389 
  390     if (ctx == NULL) {
  391         ret = -1;
  392         goto out;
  393     }
  394 
  395     gf_log_disable_suppression_before_exit(ctx);
  396 
  397     pthread_mutex_lock(&ctx->log.logfile_mutex);
  398     {
  399         if (ctx->log.logfile) {
  400             old_logfile = ctx->log.logfile;
  401 
  402             /* Logfile needs to be set to NULL, so that any
  403                call to gf_log after calling gf_log_fini, will
  404                log the message to stderr.
  405             */
  406             ctx->log.loglevel = GF_LOG_NONE;
  407             ctx->log.logfile = NULL;
  408         }
  409     }
  410     pthread_mutex_unlock(&ctx->log.logfile_mutex);
  411 
  412     if (old_logfile && (fclose(old_logfile) != 0))
  413         ret = -1;
  414 
  415     GF_FREE(ctx->log.ident);
  416     GF_FREE(ctx->log.filename);
  417 
  418 out:
  419     return ret;
  420 }
  421 
  422 /**
  423  * gf_openlog -function to open syslog specific to gluster based on
  424  *             existence of file /etc/glusterfs/logger.conf
  425  * @ident:    optional identification string similar to openlog()
  426  * @option:   optional value to option to openlog().  Passing -1 uses
  427  *            'LOG_PID | LOG_NDELAY' as default
  428  * @facility: optional facility code similar to openlog().  Passing -1
  429  *            uses LOG_DAEMON as default
  430  *
  431  * @return: void
  432  */
  433 static void
  434 gf_openlog(const char *ident, int option, int facility)
  435 {
  436     int _option = option;
  437     int _facility = facility;
  438 
  439     if (-1 == _option) {
  440         _option = LOG_PID | LOG_NDELAY;
  441     }
  442     if (-1 == _facility) {
  443         _facility = LOG_LOCAL1;
  444     }
  445 
  446     /* TODO: Should check for errors here and return appropriately */
  447     setlocale(LC_ALL, "");
  448     setlocale(LC_NUMERIC, "C"); /* C-locale for strtod, ... */
  449     /* close the previous syslog if open as we are changing settings */
  450     closelog();
  451     openlog(ident, _option, _facility);
  452 }
  453 
  454 /**
  455  * _json_escape -function to convert string to json encoded string
  456  * @str: input string
  457  * @buf: buffer to store encoded string
  458  * @len: length of @buf
  459  *
  460  * @return: success: last unprocessed character position by pointer in @str
  461  *          failure: NULL
  462  *
  463  * Internal function. Heavily inspired by _ul_str_escape() function in
  464  * libumberlog
  465  *
  466  * Sample output:
  467  * [1] str = "devel error"
  468  *     buf = "devel error"
  469  * [2] str = "devel error"
  470  *     buf = "devel\terror"
  471  * [3] str = "I/O error on "/tmp/foo" file"
  472  *     buf = "I/O error on \"/tmp/foo\" file"
  473  * [4] str = "I/O erroron /tmp/bar file"
  474  *     buf = "I/O error\u001bon /tmp/bar file"
  475  *
  476  */
  477 static char *
  478 _json_escape(const char *str, char *buf, size_t len)
  479 {
  480     static const unsigned char json_exceptions[UCHAR_MAX + 1] = {
  481         [0x01] = 1, [0x02] = 1, [0x03] = 1, [0x04] = 1, [0x05] = 1, [0x06] = 1,
  482         [0x07] = 1, [0x08] = 1, [0x09] = 1, [0x0a] = 1, [0x0b] = 1, [0x0c] = 1,
  483         [0x0d] = 1, [0x0e] = 1, [0x0f] = 1, [0x10] = 1, [0x11] = 1, [0x12] = 1,
  484         [0x13] = 1, [0x14] = 1, [0x15] = 1, [0x16] = 1, [0x17] = 1, [0x18] = 1,
  485         [0x19] = 1, [0x1a] = 1, [0x1b] = 1, [0x1c] = 1, [0x1d] = 1, [0x1e] = 1,
  486         [0x1f] = 1, ['\\'] = 1, ['"'] = 1};
  487     static const char json_hex_chars[16] = "0123456789abcdef";
  488     unsigned char *p = NULL;
  489     size_t pos = 0;
  490 
  491     if (!str || !buf || len <= 0) {
  492         return NULL;
  493     }
  494 
  495     for (p = (unsigned char *)str; *p && (pos + 1) < len; p++) {
  496         if (json_exceptions[*p] == 0) {
  497             buf[pos++] = *p;
  498             continue;
  499         }
  500 
  501         if ((pos + 2) >= len) {
  502             break;
  503         }
  504 
  505         switch (*p) {
  506             case '\b':
  507                 buf[pos++] = '\\';
  508                 buf[pos++] = 'b';
  509                 break;
  510             case '\n':
  511                 buf[pos++] = '\\';
  512                 buf[pos++] = 'n';
  513                 break;
  514             case '\r':
  515                 buf[pos++] = '\\';
  516                 buf[pos++] = 'r';
  517                 break;
  518             case '\t':
  519                 buf[pos++] = '\\';
  520                 buf[pos++] = 't';
  521                 break;
  522             case '\\':
  523                 buf[pos++] = '\\';
  524                 buf[pos++] = '\\';
  525                 break;
  526             case '"':
  527                 buf[pos++] = '\\';
  528                 buf[pos++] = '"';
  529                 break;
  530             default:
  531                 if ((pos + 6) >= len) {
  532                     buf[pos] = '\0';
  533                     return (char *)p;
  534                 }
  535                 buf[pos++] = '\\';
  536                 buf[pos++] = 'u';
  537                 buf[pos++] = '0';
  538                 buf[pos++] = '0';
  539                 buf[pos++] = json_hex_chars[(*p) >> 4];
  540                 buf[pos++] = json_hex_chars[(*p) & 0xf];
  541                 break;
  542         }
  543     }
  544 
  545     buf[pos] = '\0';
  546     return (char *)p;
  547 }
  548 
  549 /**
  550  * gf_syslog -function to submit message to syslog specific to gluster
  551  * @facility_priority: facility_priority of syslog()
  552  * @format:            optional format string to syslog()
  553  *
  554  * @return: void
  555  */
  556 static void
  557 gf_syslog(int facility_priority, char *format, ...)
  558 {
  559     char *msg = NULL;
  560     char json_msg[GF_JSON_MSG_LENGTH];
  561     GF_UNUSED char *p = NULL;
  562     va_list ap;
  563 
  564     GF_ASSERT(format);
  565 
  566     va_start(ap, format);
  567     if (vasprintf(&msg, format, ap) != -1) {
  568         p = _json_escape(msg, json_msg, GF_JSON_MSG_LENGTH);
  569         syslog(facility_priority, "%s", msg);
  570         free(msg);
  571     } else
  572         syslog(GF_LOG_CRITICAL, "vasprintf() failed, out of memory?");
  573     va_end(ap);
  574 }
  575 
  576 void
  577 gf_log_globals_init(void *data, gf_loglevel_t level)
  578 {
  579     glusterfs_ctx_t *ctx = data;
  580 
  581     pthread_mutex_init(&ctx->log.logfile_mutex, NULL);
  582 
  583     ctx->log.loglevel = level;
  584     ctx->log.gf_log_syslog = 1;
  585     ctx->log.sys_log_level = GF_LOG_CRITICAL;
  586     ctx->log.logger = gf_logger_glusterlog;
  587     ctx->log.logformat = gf_logformat_withmsgid;
  588     ctx->log.lru_size = GF_LOG_LRU_BUFSIZE_DEFAULT;
  589     ctx->log.timeout = GF_LOG_FLUSH_TIMEOUT_DEFAULT;
  590     ctx->log.localtime = GF_LOG_LOCALTIME_DEFAULT;
  591 
  592     pthread_mutex_init(&ctx->log.log_buf_lock, NULL);
  593 
  594     INIT_LIST_HEAD(&ctx->log.lru_queue);
  595 
  596 #ifdef GF_LINUX_HOST_OS
  597     /* For the 'syslog' output. one can grep 'GlusterFS' in syslog
  598        for serious logs */
  599     openlog("GlusterFS", LOG_PID, LOG_DAEMON);
  600 #endif
  601 }
  602 
  603 int
  604 gf_log_init(void *data, const char *file, const char *ident)
  605 {
  606     glusterfs_ctx_t *ctx = data;
  607     int fd = -1;
  608     struct stat buf;
  609 
  610     if (ctx == NULL) {
  611         fprintf(stderr, "ERROR: ctx is NULL\n");
  612         return -1;
  613     }
  614     if (ident) {
  615         GF_FREE(ctx->log.ident);
  616         ctx->log.ident = gf_strdup(ident);
  617     }
  618 
  619     /* we keep the files and the syslog open, so that on logger change, we
  620      * are ready to log anywhere, that the new value specifies */
  621     if (ctx->log.ident) {
  622         gf_openlog(ctx->log.ident, -1, LOG_DAEMON);
  623     } else {
  624         gf_openlog(NULL, -1, LOG_DAEMON);
  625     }
  626     /* TODO: make FACILITY configurable than LOG_DAEMON */
  627     if (sys_stat(GF_LOG_CONTROL_FILE, &buf) == 0) {
  628         /* use syslog logging */
  629         ctx->log.log_control_file_found = 1;
  630     } else {
  631         /* use old style logging */
  632         ctx->log.log_control_file_found = 0;
  633     }
  634 
  635     if (!file) {
  636         fprintf(stderr, "ERROR: no filename specified\n");
  637         return -1;
  638     }
  639 
  640     /* free the (possible) previous filename */
  641     GF_FREE(ctx->log.filename);
  642     ctx->log.filename = NULL;
  643 
  644     /* close and reopen logfile for log rotate */
  645     if (ctx->log.logfile) {
  646         fclose(ctx->log.logfile);
  647         ctx->log.logfile = NULL;
  648         ctx->log.gf_log_logfile = NULL;
  649     }
  650 
  651     if (strcmp(file, "-") == 0) {
  652         int dupfd = -1;
  653 
  654         ctx->log.filename = gf_strdup("/dev/stderr");
  655         if (!ctx->log.filename) {
  656             fprintf(stderr, "ERROR: strdup failed\n");
  657             return -1;
  658         }
  659 
  660         dupfd = dup(fileno(stderr));
  661         if (dupfd == -1) {
  662             fprintf(stderr, "ERROR: could not dup %d (%s)\n", fileno(stderr),
  663                     strerror(errno));
  664             return -1;
  665         }
  666 
  667         ctx->log.logfile = fdopen(dupfd, "a");
  668         if (!ctx->log.logfile) {
  669             fprintf(stderr, "ERROR: could not fdopen on %d (%s)\n", dupfd,
  670                     strerror(errno));
  671             sys_close(dupfd);
  672             return -1;
  673         }
  674     } else {
  675         /* Also create parent dir */
  676         char *logdir = gf_strdup(file);
  677         if (!logdir) {
  678             return -1;
  679         }
  680         char *tmp_index = rindex(logdir, '/');
  681         if (tmp_index) {
  682             tmp_index[0] = '\0';
  683         }
  684         if (mkdir_p(logdir, 0755, true)) {
  685             /* EEXIST is handled in mkdir_p() itself */
  686             gf_smsg("logging", GF_LOG_ERROR, 0, LG_MSG_STRDUP_ERROR,
  687                     "logdir=%s", logdir, "errno=%s", strerror(errno), NULL);
  688             GF_FREE(logdir);
  689             return -1;
  690         }
  691         /* no need of this variable */
  692         GF_FREE(logdir);
  693 
  694         ctx->log.filename = gf_strdup(file);
  695         if (!ctx->log.filename) {
  696             fprintf(stderr,
  697                     "ERROR: updating log-filename failed: "
  698                     "%s\n",
  699                     strerror(errno));
  700             return -1;
  701         }
  702 
  703         fd = sys_open(file, O_CREAT | O_WRONLY | O_APPEND, S_IRUSR | S_IWUSR);
  704         if (fd < 0) {
  705             fprintf(stderr,
  706                     "ERROR: failed to create logfile"
  707                     " \"%s\" (%s)\n",
  708                     file, strerror(errno));
  709             return -1;
  710         }
  711 
  712         ctx->log.logfile = fdopen(fd, "a");
  713         if (!ctx->log.logfile) {
  714             fprintf(stderr,
  715                     "ERROR: failed to open logfile \"%s\" "
  716                     "(%s)\n",
  717                     file, strerror(errno));
  718             sys_close(fd);
  719             return -1;
  720         }
  721     }
  722 
  723     ctx->log.gf_log_logfile = ctx->log.logfile;
  724 
  725     return 0;
  726 }
  727 
  728 void
  729 set_sys_log_level(gf_loglevel_t level)
  730 {
  731     if (THIS->ctx)
  732         THIS->ctx->log.sys_log_level = level;
  733 }
  734 
  735 /* Check if we should be logging
  736  * Return value: _gf_false : Print the log
  737  *               _gf_true : Do not Print the log
  738  */
  739 static gf_boolean_t
  740 skip_logging(xlator_t *this, gf_loglevel_t level)
  741 {
  742     gf_loglevel_t existing_level = this->loglevel ? this->loglevel
  743                                                   : this->ctx->log.loglevel;
  744     if (level > existing_level) {
  745         return _gf_true;
  746     }
  747 
  748     if (level == GF_LOG_NONE) {
  749         return _gf_true;
  750     }
  751 
  752     return _gf_false;
  753 }
  754 
  755 int
  756 _gf_log_callingfn(const char *domain, const char *file, const char *function,
  757                   int line, gf_loglevel_t level, const char *fmt, ...)
  758 {
  759     const char *basename = NULL;
  760     xlator_t *this = THIS;
  761     char *logline = NULL;
  762     char *msg = NULL;
  763     char timestr[GF_LOG_TIMESTR_SIZE] = {
  764         0,
  765     };
  766     char *callstr = NULL;
  767     struct timeval tv = {
  768         0,
  769     };
  770     int ret = 0;
  771     va_list ap;
  772     glusterfs_ctx_t *ctx = this->ctx;
  773 
  774     if (!ctx)
  775         goto out;
  776 
  777     if (skip_logging(this, level))
  778         goto out;
  779 
  780     if (!domain || !file || !function || !fmt) {
  781         fprintf(stderr, "logging: %s:%s():%d: invalid argument\n", __FILE__,
  782                 __PRETTY_FUNCTION__, __LINE__);
  783         return -1;
  784     }
  785 
  786     basename = strrchr(file, '/');
  787     if (basename)
  788         basename++;
  789     else
  790         basename = file;
  791 
  792     /*Saving the backtrace to pre-allocated ctx->btbuf
  793      * to avoid allocating memory from the heap*/
  794     callstr = gf_backtrace_save(NULL);
  795 
  796     va_start(ap, fmt);
  797     ret = vasprintf(&msg, fmt, ap);
  798     va_end(ap);
  799     if (-1 == ret) {
  800         goto out;
  801     }
  802 
  803     if (ctx->log.log_control_file_found) {
  804         int priority;
  805         /* treat GF_LOG_TRACE and GF_LOG_NONE as LOG_DEBUG and
  806            other level as is */
  807         if (GF_LOG_TRACE == level || GF_LOG_NONE == level) {
  808             priority = LOG_DEBUG;
  809         } else {
  810             priority = level - 1;
  811         }
  812 
  813         gf_syslog(priority, "[%s:%d:%s] %s %d-%s: %s", basename, line, function,
  814                   callstr, ((this->graph) ? this->graph->id : 0), domain, msg);
  815 
  816         goto out;
  817     }
  818 
  819     ret = gettimeofday(&tv, NULL);
  820     if (-1 == ret)
  821         goto out;
  822 
  823     gf_time_fmt(timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
  824 
  825     ret = gf_asprintf(
  826         &logline, "[%s.%" GF_PRI_SUSECONDS "] %c [%s:%d:%s] %s %d-%s: %s\n",
  827         timestr, tv.tv_usec, gf_level_strings[level], basename, line, function,
  828         callstr, ((this->graph) ? this->graph->id : 0), domain, msg);
  829     if (-1 == ret) {
  830         goto out;
  831     }
  832 
  833     pthread_mutex_lock(&ctx->log.logfile_mutex);
  834     {
  835         if (ctx->log.logfile) {
  836             fputs(logline, ctx->log.logfile);
  837             fflush(ctx->log.logfile);
  838         } else if (ctx->log.loglevel >= level) {
  839             fputs(logline, stderr);
  840             fflush(stderr);
  841         }
  842 
  843 #ifdef GF_LINUX_HOST_OS
  844         /* We want only serious log in 'syslog', not our debug
  845            and trace logs */
  846         if (ctx->log.gf_log_syslog && level &&
  847             (level <= ctx->log.sys_log_level))
  848             syslog((level - 1), "%s", logline);
  849 #endif
  850     }
  851 
  852     pthread_mutex_unlock(&ctx->log.logfile_mutex);
  853 
  854 out:
  855 
  856     GF_FREE(logline);
  857 
  858     FREE(msg);
  859 
  860     return ret;
  861 }
  862 
  863 static int
  864 _gf_msg_plain_internal(gf_loglevel_t level, const char *msg)
  865 {
  866     xlator_t *this = NULL;
  867     glusterfs_ctx_t *ctx = NULL;
  868     int priority;
  869 
  870     this = THIS;
  871     ctx = this->ctx;
  872 
  873     /* log to the configured logging service */
  874     switch (ctx->log.logger) {
  875         case gf_logger_syslog:
  876             if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) {
  877                 SET_LOG_PRIO(level, priority);
  878 
  879                 syslog(priority, "%s", msg);
  880                 break;
  881             }
  882             /* NOTE: If syslog control file is absent, which is another
  883              * way to control logging to syslog, then we will fall through
  884              * to the gluster log. The ideal way to do things would be to
  885              * not have the extra control file check */
  886         case gf_logger_glusterlog:
  887             pthread_mutex_lock(&ctx->log.logfile_mutex);
  888             {
  889                 if (ctx->log.logfile) {
  890                     fprintf(ctx->log.logfile, "%s\n", msg);
  891                     fflush(ctx->log.logfile);
  892                 } else {
  893                     fprintf(stderr, "%s\n", msg);
  894                     fflush(stderr);
  895                 }
  896 
  897 #ifdef GF_LINUX_HOST_OS
  898                 /* We want only serious logs in 'syslog', not our debug
  899                  * and trace logs */
  900                 if (ctx->log.gf_log_syslog && level &&
  901                     (level <= ctx->log.sys_log_level))
  902                     syslog((level - 1), "%s\n", msg);
  903 #endif
  904             }
  905             pthread_mutex_unlock(&ctx->log.logfile_mutex);
  906 
  907             break;
  908     }
  909 
  910     return 0;
  911 }
  912 
  913 int
  914 _gf_msg_plain(gf_loglevel_t level, const char *fmt, ...)
  915 {
  916     xlator_t *this = NULL;
  917     int ret = 0;
  918     va_list ap;
  919     char *msg = NULL;
  920     glusterfs_ctx_t *ctx = NULL;
  921 
  922     this = THIS;
  923     ctx = this->ctx;
  924 
  925     if (!ctx)
  926         goto out;
  927 
  928     if (skip_logging(this, level))
  929         goto out;
  930 
  931     va_start(ap, fmt);
  932     ret = vasprintf(&msg, fmt, ap);
  933     va_end(ap);
  934     if (-1 == ret) {
  935         goto out;
  936     }
  937 
  938     ret = _gf_msg_plain_internal(level, msg);
  939 
  940     FREE(msg);
  941 
  942 out:
  943     return ret;
  944 }
  945 
  946 int
  947 _gf_msg_vplain(gf_loglevel_t level, const char *fmt, va_list ap)
  948 {
  949     xlator_t *this = NULL;
  950     int ret = 0;
  951     char *msg = NULL;
  952     glusterfs_ctx_t *ctx = NULL;
  953 
  954     this = THIS;
  955     ctx = this->ctx;
  956 
  957     if (!ctx)
  958         goto out;
  959 
  960     if (skip_logging(this, level))
  961         goto out;
  962 
  963     ret = vasprintf(&msg, fmt, ap);
  964     if (-1 == ret) {
  965         goto out;
  966     }
  967 
  968     ret = _gf_msg_plain_internal(level, msg);
  969 
  970     FREE(msg);
  971 out:
  972     return ret;
  973 }
  974 
  975 int
  976 _gf_msg_plain_nomem(gf_loglevel_t level, const char *msg)
  977 {
  978     xlator_t *this = NULL;
  979     int ret = 0;
  980     glusterfs_ctx_t *ctx = NULL;
  981 
  982     this = THIS;
  983     ctx = this->ctx;
  984 
  985     if (!ctx)
  986         goto out;
  987 
  988     if (skip_logging(this, level))
  989         goto out;
  990 
  991     ret = _gf_msg_plain_internal(level, msg);
  992 
  993 out:
  994     return ret;
  995 }
  996 
  997 void
  998 _gf_msg_backtrace_nomem(gf_loglevel_t level, int stacksize)
  999 {
 1000     xlator_t *this = NULL;
 1001     glusterfs_ctx_t *ctx = NULL;
 1002     void *array[200];
 1003     size_t bt_size = 0;
 1004     int fd = -1;
 1005 
 1006     this = THIS;
 1007     ctx = this->ctx;
 1008 
 1009     if (!ctx)
 1010         goto out;
 1011 
 1012     /* syslog does not have fd support, hence no no-mem variant */
 1013     if (ctx->log.logger != gf_logger_glusterlog)
 1014         goto out;
 1015 
 1016     if (skip_logging(this, level))
 1017         goto out;
 1018 
 1019     bt_size = backtrace(array, ((stacksize <= 200) ? stacksize : 200));
 1020     if (!bt_size)
 1021         goto out;
 1022     pthread_mutex_lock(&ctx->log.logfile_mutex);
 1023     {
 1024         fd = ctx->log.logfile ? fileno(ctx->log.logfile) : fileno(stderr);
 1025         if (fd != -1) {
 1026             /* print to the file fd, to prevent any
 1027                allocations from backtrace_symbols
 1028              */
 1029             backtrace_symbols_fd(&array[0], bt_size, fd);
 1030         }
 1031     }
 1032     pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1033 
 1034 out:
 1035     return;
 1036 }
 1037 
 1038 int
 1039 _gf_msg_backtrace(int stacksize, char *callstr, size_t strsize)
 1040 {
 1041     int ret = -1;
 1042     int i = 0;
 1043     int size = 0;
 1044     int savstrsize = strsize;
 1045     void *array[200];
 1046     char **callingfn = NULL;
 1047 
 1048     /* We chop off last 2 anyway, so if request is less than tolerance
 1049      * nothing to do */
 1050     if (stacksize < 3)
 1051         goto out;
 1052 
 1053     size = backtrace(array, ((stacksize <= 200) ? stacksize : 200));
 1054     if ((size - 3) < 0)
 1055         goto out;
 1056     if (size)
 1057         callingfn = backtrace_symbols(&array[2], size - 2);
 1058     if (!callingfn)
 1059         goto out;
 1060 
 1061     ret = snprintf(callstr, strsize, "(");
 1062     PRINT_SIZE_CHECK(ret, out, strsize);
 1063 
 1064     for ((i = size - 3); i >= 0; i--) {
 1065         ret = snprintf(callstr + savstrsize - strsize, strsize, "-->%s ",
 1066                        callingfn[i]);
 1067         PRINT_SIZE_CHECK(ret, out, strsize);
 1068     }
 1069 
 1070     ret = snprintf(callstr + savstrsize - strsize, strsize, ")");
 1071     PRINT_SIZE_CHECK(ret, out, strsize);
 1072 out:
 1073     FREE(callingfn);
 1074     return ret;
 1075 }
 1076 
 1077 int
 1078 _gf_msg_nomem(const char *domain, const char *file, const char *function,
 1079               int line, gf_loglevel_t level, size_t size)
 1080 {
 1081     const char *basename = NULL;
 1082     xlator_t *this = NULL;
 1083     struct timeval tv = {
 1084         0,
 1085     };
 1086     int ret = 0;
 1087     int fd = -1;
 1088     char msg[2048] = {
 1089         0,
 1090     };
 1091     char timestr[GF_LOG_TIMESTR_SIZE] = {
 1092         0,
 1093     };
 1094     glusterfs_ctx_t *ctx = NULL;
 1095     int wlen = 0;
 1096     int priority;
 1097     struct rusage r_usage;
 1098 
 1099     this = THIS;
 1100     ctx = this->ctx;
 1101 
 1102     if (!ctx)
 1103         goto out;
 1104 
 1105     if (skip_logging(this, level))
 1106         goto out;
 1107 
 1108     if (!domain || !file || !function) {
 1109         fprintf(stderr, "logging: %s:%s():%d: invalid argument\n", __FILE__,
 1110                 __PRETTY_FUNCTION__, __LINE__);
 1111         return -1;
 1112     }
 1113 
 1114     GET_FILE_NAME_TO_LOG(file, basename);
 1115 
 1116     ret = gettimeofday(&tv, NULL);
 1117     if (-1 == ret)
 1118         goto out;
 1119     gf_time_fmt(timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
 1120 
 1121     /* TODO: Currently we print in the enhanced format, with a message ID
 1122      * of 0. Need to enhance this to support format as configured */
 1123     wlen = snprintf(
 1124         msg, sizeof msg,
 1125         "[%s.%" GF_PRI_SUSECONDS "] %c [MSGID: %" PRIu64
 1126         "]"
 1127         " [%s:%d:%s] %s: no memory "
 1128         "available for size (%" GF_PRI_SIZET
 1129         ") current memory usage in kilobytes %ld"
 1130         " [call stack follows]\n",
 1131         timestr, tv.tv_usec, gf_level_strings[level], (uint64_t)0, basename,
 1132         line, function, domain, size,
 1133         (!getrusage(RUSAGE_SELF, &r_usage) ? r_usage.ru_maxrss : 0));
 1134     if (-1 == wlen) {
 1135         ret = -1;
 1136         goto out;
 1137     }
 1138 
 1139     /* log to the configured logging service */
 1140     switch (ctx->log.logger) {
 1141         case gf_logger_syslog:
 1142             if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) {
 1143                 SET_LOG_PRIO(level, priority);
 1144 
 1145                 /* if syslog allocates, then this may fail, but we
 1146                  * cannot do much about it at the moment */
 1147                 /* There is no fd for syslog, hence no stack printed */
 1148                 syslog(priority, "%s", msg);
 1149                 break;
 1150             }
 1151             /* NOTE: If syslog control file is absent, which is another
 1152              * way to control logging to syslog, then we will fall through
 1153              * to the gluster log. The ideal way to do things would be to
 1154              * not have the extra control file check */
 1155         case gf_logger_glusterlog:
 1156             pthread_mutex_lock(&ctx->log.logfile_mutex);
 1157             {
 1158                 fd = ctx->log.logfile ? fileno(ctx->log.logfile)
 1159                                       : fileno(stderr);
 1160                 if (fd == -1) {
 1161                     pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1162                     goto out;
 1163                 }
 1164 
 1165                 /* write directly to the fd to prevent out of order
 1166                  * message and stack */
 1167                 ret = sys_write(fd, msg, wlen);
 1168                 if (ret == -1) {
 1169                     pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1170                     goto out;
 1171                 }
 1172 #ifdef GF_LINUX_HOST_OS
 1173                 /* We want only serious log in 'syslog', not our debug
 1174                  * and trace logs */
 1175                 if (ctx->log.gf_log_syslog && level &&
 1176                     (level <= ctx->log.sys_log_level))
 1177                     syslog((level - 1), "%s\n", msg);
 1178 #endif
 1179             }
 1180             pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1181 
 1182             _gf_msg_backtrace_nomem(level, GF_LOG_BACKTRACE_DEPTH);
 1183 
 1184             break;
 1185     }
 1186 
 1187 out:
 1188     return ret;
 1189 }
 1190 
 1191 static int
 1192 gf_log_syslog(glusterfs_ctx_t *ctx, const char *domain, const char *file,
 1193               const char *function, int32_t line, gf_loglevel_t level,
 1194               int errnum, uint64_t msgid, char **appmsgstr, char *callstr,
 1195               int graph_id, gf_log_format_t fmt)
 1196 {
 1197     int priority;
 1198 
 1199     SET_LOG_PRIO(level, priority);
 1200 
 1201     /* log with appropriate format */
 1202     switch (fmt) {
 1203         case gf_logformat_traditional:
 1204             if (!callstr) {
 1205                 if (errnum)
 1206                     syslog(priority, "[%s:%d:%s] %d-%s: %s [%s]", file, line,
 1207                            function, graph_id, domain, *appmsgstr,
 1208                            strerror(errnum));
 1209                 else
 1210                     syslog(priority, "[%s:%d:%s] %d-%s: %s", file, line,
 1211                            function, graph_id, domain, *appmsgstr);
 1212             } else {
 1213                 if (errnum)
 1214                     syslog(priority,
 1215                            "[%s:%d:%s] %s %d-%s:"
 1216                            " %s [%s]",
 1217                            file, line, function, callstr, graph_id, domain,
 1218                            *appmsgstr, strerror(errnum));
 1219                 else
 1220                     syslog(priority, "[%s:%d:%s] %s %d-%s: %s", file, line,
 1221                            function, callstr, graph_id, domain, *appmsgstr);
 1222             }
 1223             break;
 1224         case gf_logformat_withmsgid:
 1225             if (!callstr) {
 1226                 if (errnum)
 1227                     syslog(priority,
 1228                            "[MSGID: %" PRIu64
 1229                            "]"
 1230                            " [%s:%d:%s] %d-%s: %s [%s]",
 1231                            msgid, file, line, function, graph_id, domain,
 1232                            *appmsgstr, strerror(errnum));
 1233                 else
 1234                     syslog(priority,
 1235                            "[MSGID: %" PRIu64
 1236                            "]"
 1237                            " [%s:%d:%s] %d-%s: %s",
 1238                            msgid, file, line, function, graph_id, domain,
 1239                            *appmsgstr);
 1240             } else {
 1241                 if (errnum)
 1242                     syslog(priority,
 1243                            "[MSGID: %" PRIu64
 1244                            "]"
 1245                            " [%s:%d:%s] %s %d-%s: %s [%s]",
 1246                            msgid, file, line, function, callstr, graph_id,
 1247                            domain, *appmsgstr, strerror(errnum));
 1248                 else
 1249                     syslog(priority,
 1250                            "[MSGID: %" PRIu64
 1251                            "]"
 1252                            " [%s:%d:%s] %s %d-%s: %s",
 1253                            msgid, file, line, function, callstr, graph_id,
 1254                            domain, *appmsgstr);
 1255             }
 1256             break;
 1257         case gf_logformat_cee:
 1258             /* TODO: Enhance CEE with additional parameters */
 1259             gf_syslog(priority, "[%s:%d:%s] %d-%s: %s", file, line, function,
 1260                       graph_id, domain, *appmsgstr);
 1261             break;
 1262 
 1263         default:
 1264             /* NOTE: should not get here without logging */
 1265             break;
 1266     }
 1267 
 1268     /* TODO: There can be no errors from gf_syslog? */
 1269     return 0;
 1270 }
 1271 
 1272 static int
 1273 gf_log_glusterlog(glusterfs_ctx_t *ctx, const char *domain, const char *file,
 1274                   const char *function, int32_t line, gf_loglevel_t level,
 1275                   int errnum, uint64_t msgid, char **appmsgstr, char *callstr,
 1276                   struct timeval tv, int graph_id, gf_log_format_t fmt)
 1277 {
 1278     char timestr[GF_LOG_TIMESTR_SIZE] = {
 1279         0,
 1280     };
 1281     char *header = NULL;
 1282     char *footer = NULL;
 1283     int ret = 0;
 1284 
 1285     /* rotate if required */
 1286     gf_log_rotate(ctx);
 1287 
 1288     /* format the time stamp */
 1289     gf_time_fmt(timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
 1290 
 1291     /* generate footer */
 1292     if (errnum) {
 1293         ret = gf_asprintf(&footer, " [%s]\n", strerror(errnum));
 1294     } else {
 1295         ret = gf_asprintf(&footer, " \n");
 1296     }
 1297     if (-1 == ret) {
 1298         goto err;
 1299     }
 1300 
 1301     /* generate message, inc. the header */
 1302     if (fmt == gf_logformat_traditional) {
 1303         if (!callstr) {
 1304             ret = gf_asprintf(&header,
 1305                               "[%s.%" GF_PRI_SUSECONDS
 1306                               "] %c [%s:%d:%s]"
 1307                               " %d-%s: %s",
 1308                               timestr, tv.tv_usec, gf_level_strings[level],
 1309                               file, line, function, graph_id, domain,
 1310                               *appmsgstr);
 1311         } else {
 1312             ret = gf_asprintf(&header,
 1313                               "[%s.%" GF_PRI_SUSECONDS
 1314                               "] %c [%s:%d:%s] %s"
 1315                               " %d-%s: %s",
 1316                               timestr, tv.tv_usec, gf_level_strings[level],
 1317                               file, line, function, callstr, graph_id, domain,
 1318                               *appmsgstr);
 1319         }
 1320     } else { /* gf_logformat_withmsgid */
 1321         /* CEE log format unsupported in logger_glusterlog, so just
 1322          * print enhanced log format */
 1323         if (!callstr) {
 1324             ret = gf_asprintf(&header,
 1325                               "[%s.%" GF_PRI_SUSECONDS "] %c [MSGID: %" PRIu64
 1326                               "]"
 1327                               " [%s:%d:%s] %d-%s: %s",
 1328                               timestr, tv.tv_usec, gf_level_strings[level],
 1329                               msgid, file, line, function, graph_id, domain,
 1330                               *appmsgstr);
 1331         } else {
 1332             ret = gf_asprintf(&header,
 1333                               "[%s.%" GF_PRI_SUSECONDS "] %c [MSGID: %" PRIu64
 1334                               "]"
 1335                               " [%s:%d:%s] %s %d-%s: %s",
 1336                               timestr, tv.tv_usec, gf_level_strings[level],
 1337                               msgid, file, line, function, callstr, graph_id,
 1338                               domain, *appmsgstr);
 1339         }
 1340     }
 1341     if (-1 == ret) {
 1342         goto err;
 1343     }
 1344 
 1345     /* send the full message to log */
 1346 
 1347     pthread_mutex_lock(&ctx->log.logfile_mutex);
 1348     {
 1349         if (ctx->log.logfile) {
 1350             fprintf(ctx->log.logfile, "%s%s", header, footer);
 1351             fflush(ctx->log.logfile);
 1352         } else if (ctx->log.loglevel >= level) {
 1353             fprintf(stderr, "%s%s", header, footer);
 1354             fflush(stderr);
 1355         }
 1356 
 1357 #ifdef GF_LINUX_HOST_OS
 1358         /* We want only serious logs in 'syslog', not our debug
 1359          * and trace logs */
 1360         if (ctx->log.gf_log_syslog && level &&
 1361             (level <= ctx->log.sys_log_level)) {
 1362             syslog((level - 1), "%s%s", header, footer);
 1363         }
 1364 #endif
 1365     }
 1366 
 1367     /* TODO: Plugin in memory log buffer retention here. For logs not
 1368      * flushed during cores, it would be useful to retain some of the last
 1369      * few messages in memory */
 1370     pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1371     ret = 0;
 1372 
 1373 err:
 1374     GF_FREE(header);
 1375     GF_FREE(footer);
 1376 
 1377     return ret;
 1378 }
 1379 
 1380 static int
 1381 gf_syslog_log_repetitions(const char *domain, const char *file,
 1382                           const char *function, int32_t line,
 1383                           gf_loglevel_t level, int errnum, uint64_t msgid,
 1384                           char **appmsgstr, char *callstr, int refcount,
 1385                           struct timeval oldest, struct timeval latest,
 1386                           int graph_id)
 1387 {
 1388     int priority;
 1389     char timestr_latest[GF_LOG_TIMESTR_SIZE] = {
 1390         0,
 1391     };
 1392     char timestr_oldest[GF_LOG_TIMESTR_SIZE] = {
 1393         0,
 1394     };
 1395 
 1396     SET_LOG_PRIO(level, priority);
 1397 
 1398     gf_time_fmt(timestr_latest, sizeof timestr_latest, latest.tv_sec,
 1399                 gf_timefmt_FT);
 1400     gf_time_fmt(timestr_oldest, sizeof timestr_oldest, oldest.tv_sec,
 1401                 gf_timefmt_FT);
 1402 
 1403     if (errnum) {
 1404         syslog(
 1405             priority,
 1406             "The message \"[MSGID: %" PRIu64
 1407             "] [%s:%d:%s] "
 1408             "%d-%s: %s [%s] \" repeated %d times between %s.%" GF_PRI_SUSECONDS
 1409             " and %s.%" GF_PRI_SUSECONDS,
 1410             msgid, file, line, function, graph_id, domain, *appmsgstr,
 1411             strerror(errnum), refcount, timestr_oldest, oldest.tv_usec,
 1412             timestr_latest, latest.tv_usec);
 1413     } else {
 1414         syslog(priority,
 1415                "The message \"[MSGID: %" PRIu64
 1416                "] [%s:%d:%s] "
 1417                "%d-%s: %s \" repeated %d times between %s.%" GF_PRI_SUSECONDS
 1418                " and %s.%" GF_PRI_SUSECONDS,
 1419                msgid, file, line, function, graph_id, domain, *appmsgstr,
 1420                refcount, timestr_oldest, oldest.tv_usec, timestr_latest,
 1421                latest.tv_usec);
 1422     }
 1423     return 0;
 1424 }
 1425 
 1426 static int
 1427 gf_glusterlog_log_repetitions(glusterfs_ctx_t *ctx, const char *domain,
 1428                               const char *file, const char *function,
 1429                               int32_t line, gf_loglevel_t level, int errnum,
 1430                               uint64_t msgid, char **appmsgstr, char *callstr,
 1431                               int refcount, struct timeval oldest,
 1432                               struct timeval latest, int graph_id)
 1433 {
 1434     int ret = 0;
 1435     char timestr_latest[GF_LOG_TIMESTR_SIZE] = {
 1436         0,
 1437     };
 1438     char timestr_oldest[GF_LOG_TIMESTR_SIZE] = {
 1439         0,
 1440     };
 1441     char errstr[256] = {
 1442         0,
 1443     };
 1444     char *header = NULL;
 1445     char *footer = NULL;
 1446 
 1447     if (!ctx)
 1448         goto err;
 1449 
 1450     gf_log_rotate(ctx);
 1451 
 1452     ret = gf_asprintf(&header,
 1453                       "The message \"%c [MSGID: %" PRIu64
 1454                       "]"
 1455                       " [%s:%d:%s] %d-%s: %s",
 1456                       gf_level_strings[level], msgid, file, line, function,
 1457                       graph_id, domain, *appmsgstr);
 1458     if (-1 == ret) {
 1459         goto err;
 1460     }
 1461 
 1462     gf_time_fmt(timestr_latest, sizeof timestr_latest, latest.tv_sec,
 1463                 gf_timefmt_FT);
 1464 
 1465     gf_time_fmt(timestr_oldest, sizeof timestr_oldest, oldest.tv_sec,
 1466                 gf_timefmt_FT);
 1467 
 1468     if (errnum)
 1469         snprintf(errstr, sizeof(errstr) - 1, " [%s]", strerror(errnum));
 1470 
 1471     ret = gf_asprintf(&footer,
 1472                       "%s\" repeated %d times between"
 1473                       " [%s.%" GF_PRI_SUSECONDS "] and [%s.%" GF_PRI_SUSECONDS
 1474                       "]",
 1475                       errstr, refcount, timestr_oldest, oldest.tv_usec,
 1476                       timestr_latest, latest.tv_usec);
 1477     if (-1 == ret) {
 1478         ret = -1;
 1479         goto err;
 1480     }
 1481 
 1482     pthread_mutex_lock(&ctx->log.logfile_mutex);
 1483     {
 1484         if (ctx->log.logfile) {
 1485             fprintf(ctx->log.logfile, "%s%s\n", header, footer);
 1486             fflush(ctx->log.logfile);
 1487         } else if (ctx->log.loglevel >= level) {
 1488             fprintf(stderr, "%s%s\n", header, footer);
 1489             fflush(stderr);
 1490         }
 1491 
 1492 #ifdef GF_LINUX_HOST_OS
 1493         /* We want only serious logs in 'syslog', not our debug
 1494          * and trace logs */
 1495         if (ctx->log.gf_log_syslog && level &&
 1496             (level <= ctx->log.sys_log_level))
 1497             syslog((level - 1), "%s%s\n", header, footer);
 1498 #endif
 1499     }
 1500 
 1501     /* TODO: Plugin in memory log buffer retention here. For logs not
 1502      * flushed during cores, it would be useful to retain some of the last
 1503      * few messages in memory */
 1504     pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1505     ret = 0;
 1506 
 1507 err:
 1508     GF_FREE(header);
 1509     GF_FREE(footer);
 1510 
 1511     return ret;
 1512 }
 1513 
 1514 static int
 1515 gf_log_print_with_repetitions(glusterfs_ctx_t *ctx, const char *domain,
 1516                               const char *file, const char *function,
 1517                               int32_t line, gf_loglevel_t level, int errnum,
 1518                               uint64_t msgid, char **appmsgstr, char *callstr,
 1519                               int refcount, struct timeval oldest,
 1520                               struct timeval latest, int graph_id)
 1521 {
 1522     int ret = -1;
 1523     gf_log_logger_t logger = ctx->log.logger;
 1524 
 1525     switch (logger) {
 1526         case gf_logger_syslog:
 1527             if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) {
 1528                 ret = gf_syslog_log_repetitions(
 1529                     domain, file, function, line, level, errnum, msgid,
 1530                     appmsgstr, callstr, refcount, oldest, latest, graph_id);
 1531                 break;
 1532             }
 1533             /* NOTE: If syslog control file is absent, which is another
 1534              * way to control logging to syslog, then we will fall through
 1535              * to the gluster log. The ideal way to do things would be to
 1536              * not have the extra control file check */
 1537 
 1538         case gf_logger_glusterlog:
 1539             ret = gf_glusterlog_log_repetitions(
 1540                 ctx, domain, file, function, line, level, errnum, msgid,
 1541                 appmsgstr, callstr, refcount, oldest, latest, graph_id);
 1542             break;
 1543     }
 1544 
 1545     return ret;
 1546 }
 1547 
 1548 static int
 1549 gf_log_print_plain_fmt(glusterfs_ctx_t *ctx, const char *domain,
 1550                        const char *file, const char *function, int32_t line,
 1551                        gf_loglevel_t level, int errnum, uint64_t msgid,
 1552                        char **appmsgstr, char *callstr, struct timeval tv,
 1553                        int graph_id, gf_log_format_t fmt)
 1554 {
 1555     int ret = -1;
 1556     gf_log_logger_t logger = 0;
 1557 
 1558     logger = ctx->log.logger;
 1559 
 1560     /* log to the configured logging service */
 1561     switch (logger) {
 1562         case gf_logger_syslog:
 1563             if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) {
 1564                 ret = gf_log_syslog(ctx, domain, file, function, line, level,
 1565                                     errnum, msgid, appmsgstr, callstr, graph_id,
 1566                                     fmt);
 1567                 break;
 1568             }
 1569             /* NOTE: If syslog control file is absent, which is another
 1570              * way to control logging to syslog, then we will fall through
 1571              * to the gluster log. The ideal way to do things would be to
 1572              * not have the extra control file check */
 1573         case gf_logger_glusterlog:
 1574             ret = gf_log_glusterlog(ctx, domain, file, function, line, level,
 1575                                     errnum, msgid, appmsgstr, callstr, tv,
 1576                                     graph_id, fmt);
 1577             break;
 1578     }
 1579 
 1580     return ret;
 1581 }
 1582 
 1583 void
 1584 gf_log_flush_message(log_buf_t *buf, glusterfs_ctx_t *ctx)
 1585 {
 1586     if (buf->refcount == 1) {
 1587         (void)gf_log_print_plain_fmt(ctx, buf->domain, buf->file, buf->function,
 1588                                      buf->line, buf->level, buf->errnum,
 1589                                      buf->msg_id, &buf->msg, NULL, buf->latest,
 1590                                      buf->graph_id, gf_logformat_withmsgid);
 1591     }
 1592 
 1593     if (buf->refcount > 1) {
 1594         gf_log_print_with_repetitions(
 1595             ctx, buf->domain, buf->file, buf->function, buf->line, buf->level,
 1596             buf->errnum, buf->msg_id, &buf->msg, NULL, buf->refcount,
 1597             buf->oldest, buf->latest, buf->graph_id);
 1598     }
 1599     return;
 1600 }
 1601 
 1602 static void
 1603 gf_log_flush_list(struct list_head *copy, glusterfs_ctx_t *ctx)
 1604 {
 1605     log_buf_t *iter = NULL;
 1606     log_buf_t *tmp = NULL;
 1607 
 1608     list_for_each_entry_safe(iter, tmp, copy, msg_list)
 1609     {
 1610         gf_log_flush_message(iter, ctx);
 1611         list_del_init(&iter->msg_list);
 1612         log_buf_destroy(iter);
 1613     }
 1614 }
 1615 
 1616 void
 1617 gf_log_flush_msgs(glusterfs_ctx_t *ctx)
 1618 {
 1619     struct list_head copy;
 1620 
 1621     INIT_LIST_HEAD(&copy);
 1622 
 1623     pthread_mutex_lock(&ctx->log.log_buf_lock);
 1624     {
 1625         list_splice_init(&ctx->log.lru_queue, &copy);
 1626         ctx->log.lru_cur_size = 0;
 1627     }
 1628     pthread_mutex_unlock(&ctx->log.log_buf_lock);
 1629 
 1630     gf_log_flush_list(&copy, ctx);
 1631 
 1632     return;
 1633 }
 1634 
 1635 static void
 1636 gf_log_flush_extra_msgs(glusterfs_ctx_t *ctx, uint32_t new)
 1637 {
 1638     int count = 0;
 1639     int i = 0;
 1640     log_buf_t *iter = NULL;
 1641     log_buf_t *tmp = NULL;
 1642     struct list_head copy;
 1643 
 1644     INIT_LIST_HEAD(&copy);
 1645 
 1646     /* If the number of outstanding log messages does not cause list
 1647      * overflow even after reducing the size of the list, then do nothing.
 1648      * Otherwise (that is if there are more items in the list than there
 1649      * need to be after reducing its size), move the least recently used
 1650      * 'diff' elements to be flushed into a separate list...
 1651      */
 1652 
 1653     pthread_mutex_lock(&ctx->log.log_buf_lock);
 1654     {
 1655         if (ctx->log.lru_cur_size <= new)
 1656             goto unlock;
 1657         count = ctx->log.lru_cur_size - new;
 1658         list_for_each_entry_safe(iter, tmp, &ctx->log.lru_queue, msg_list)
 1659         {
 1660             if (i == count)
 1661                 break;
 1662 
 1663             list_del_init(&iter->msg_list);
 1664             list_add_tail(&iter->msg_list, &copy);
 1665             i++;
 1666         }
 1667         ctx->log.lru_cur_size = ctx->log.lru_cur_size - count;
 1668     }
 1669     // ... quickly unlock ...
 1670 unlock:
 1671     pthread_mutex_unlock(&ctx->log.log_buf_lock);
 1672     if (list_empty(&copy))
 1673         return;
 1674 
 1675     TEST_LOG(
 1676         "Log buffer size reduced. About to flush %d extra log "
 1677         "messages",
 1678         count);
 1679     // ... and then flush them outside the lock.
 1680     gf_log_flush_list(&copy, ctx);
 1681     TEST_LOG("Just flushed %d extra log messages", count);
 1682 
 1683     return;
 1684 }
 1685 
 1686 static int
 1687 __gf_log_inject_timer_event(glusterfs_ctx_t *ctx)
 1688 {
 1689     int ret = -1;
 1690     struct timespec timeout = {
 1691         0,
 1692     };
 1693 
 1694     if (!ctx)
 1695         goto out;
 1696 
 1697     if (ctx->log.log_flush_timer) {
 1698         gf_timer_call_cancel(ctx, ctx->log.log_flush_timer);
 1699         ctx->log.log_flush_timer = NULL;
 1700     }
 1701 
 1702     timeout.tv_sec = ctx->log.timeout;
 1703     timeout.tv_nsec = 0;
 1704 
 1705     TEST_LOG("Starting timer now. Timeout = %u, current buf size = %d",
 1706              ctx->log.timeout, ctx->log.lru_size);
 1707     ctx->log.log_flush_timer = gf_timer_call_after(
 1708         ctx, timeout, gf_log_flush_timeout_cbk, (void *)ctx);
 1709     if (!ctx->log.log_flush_timer)
 1710         goto out;
 1711 
 1712     ret = 0;
 1713 
 1714 out:
 1715     return ret;
 1716 }
 1717 
 1718 int
 1719 gf_log_inject_timer_event(glusterfs_ctx_t *ctx)
 1720 {
 1721     int ret = -1;
 1722 
 1723     if (!ctx)
 1724         return -1;
 1725 
 1726     pthread_mutex_lock(&ctx->log.log_buf_lock);
 1727     {
 1728         ret = __gf_log_inject_timer_event(ctx);
 1729     }
 1730     pthread_mutex_unlock(&ctx->log.log_buf_lock);
 1731 
 1732     return ret;
 1733 }
 1734 
 1735 void
 1736 gf_log_flush_timeout_cbk(void *data)
 1737 {
 1738     glusterfs_ctx_t *ctx = NULL;
 1739 
 1740     ctx = (glusterfs_ctx_t *)data;
 1741 
 1742     TEST_LOG(
 1743         "Log timer timed out. About to flush outstanding messages if "
 1744         "present");
 1745     gf_log_flush_msgs(ctx);
 1746 
 1747     (void)gf_log_inject_timer_event(ctx);
 1748 
 1749     return;
 1750 }
 1751 
 1752 static int
 1753 _gf_msg_internal(const char *domain, const char *file, const char *function,
 1754                  int32_t line, gf_loglevel_t level, int errnum, uint64_t msgid,
 1755                  char **appmsgstr, char *callstr, int graph_id)
 1756 {
 1757     int ret = -1;
 1758     uint32_t size = 0;
 1759     const char *basename = NULL;
 1760     xlator_t *this = NULL;
 1761     glusterfs_ctx_t *ctx = NULL;
 1762     log_buf_t *iter = NULL;
 1763     log_buf_t *buf_tmp = NULL;
 1764     log_buf_t *buf_new = NULL;
 1765     log_buf_t *first = NULL;
 1766     struct timeval tv = {
 1767         0,
 1768     };
 1769     gf_boolean_t found = _gf_false;
 1770     gf_boolean_t flush_lru = _gf_false;
 1771     gf_boolean_t flush_logged_msg = _gf_false;
 1772 
 1773     this = THIS;
 1774     ctx = this->ctx;
 1775 
 1776     if (!ctx)
 1777         goto out;
 1778 
 1779     GET_FILE_NAME_TO_LOG(file, basename);
 1780 
 1781     ret = gettimeofday(&tv, NULL);
 1782     if (ret)
 1783         goto out;
 1784 
 1785     /* If this function is called via _gf_msg_callingfn () (indicated by a
 1786      * non-NULL callstr), or if the logformat is traditional, flush the
 1787      * message directly to disk.
 1788      */
 1789 
 1790     if ((callstr) || (ctx->log.logformat == gf_logformat_traditional)) {
 1791         ret = gf_log_print_plain_fmt(ctx, domain, basename, function, line,
 1792                                      level, errnum, msgid, appmsgstr, callstr,
 1793                                      tv, graph_id, gf_logformat_traditional);
 1794         goto out;
 1795     }
 1796 
 1797     pthread_mutex_lock(&ctx->log.log_buf_lock);
 1798     {
 1799         /* Check if the msg being logged is already part of the list */
 1800         list_for_each_entry_safe_reverse(iter, buf_tmp, &ctx->log.lru_queue,
 1801                                          msg_list)
 1802         {
 1803             if (first == NULL)
 1804                 // Remember the first (lru) element in first ptr
 1805                 first = iter;
 1806 
 1807             /* Try to fail the search early on by doing the less
 1808              * expensive integer comparisons and continue to string
 1809              * parameter comparisons only after all int parameters
 1810              * are found to be matching.
 1811              */
 1812             if (line != iter->line)
 1813                 continue;
 1814 
 1815             if (errnum != iter->errnum)
 1816                 continue;
 1817 
 1818             if (msgid != iter->msg_id)
 1819                 continue;
 1820 
 1821             if (level != iter->level)
 1822                 continue;
 1823 
 1824             if (graph_id != iter->graph_id)
 1825                 continue;
 1826 
 1827             if (strcmp(domain, iter->domain))
 1828                 continue;
 1829 
 1830             if (strcmp(basename, iter->file))
 1831                 continue;
 1832 
 1833             if (strcmp(function, iter->function))
 1834                 continue;
 1835 
 1836             if (strcmp(*appmsgstr, iter->msg))
 1837                 continue;
 1838 
 1839             // Ah! Found a match!
 1840             list_move_tail(&iter->msg_list, &ctx->log.lru_queue);
 1841             iter->refcount++;
 1842             found = _gf_true;
 1843             // Update the 'latest' timestamp.
 1844             memcpy((void *)&(iter->latest), (void *)&tv,
 1845                    sizeof(struct timeval));
 1846             break;
 1847         }
 1848         if (found) {
 1849             ret = 0;
 1850             goto unlock;
 1851         }
 1852         // else ...
 1853 
 1854         size = ctx->log.lru_size;
 1855         /* If the upper limit on the log buf size is 0, flush the msg to
 1856          * disk directly after unlock. There's no need to buffer the
 1857          * msg here.
 1858          */
 1859         if (size == 0) {
 1860             flush_logged_msg = _gf_true;
 1861             goto unlock;
 1862         } else if (((ctx->log.lru_cur_size + 1) > size) && (first)) {
 1863             /* If the list is full, flush the lru msg to disk and also
 1864              * release it after unlock, and ...
 1865              * */
 1866             if (first->refcount >= 1)
 1867                 TEST_LOG(
 1868                     "Buffer overflow of a buffer whose size limit "
 1869                     "is %d. About to flush least recently used log"
 1870                     " message to disk",
 1871                     size);
 1872             list_del_init(&first->msg_list);
 1873             ctx->log.lru_cur_size--;
 1874             flush_lru = _gf_true;
 1875         }
 1876         /* create a new list element, initialise and enqueue it.
 1877          * Additionally, this being the first occurrence of the msg,
 1878          * log it directly to disk after unlock. */
 1879         buf_new = mem_get0(THIS->ctx->logbuf_pool);
 1880         if (!buf_new) {
 1881             ret = -1;
 1882             goto unlock;
 1883         }
 1884         ret = log_buf_init(buf_new, domain, basename, function, line, level,
 1885                            errnum, msgid, appmsgstr, graph_id);
 1886         if (ret) {
 1887             log_buf_destroy(buf_new);
 1888             goto unlock;
 1889         }
 1890 
 1891         memcpy((void *)&(buf_new->latest), (void *)&tv, sizeof(struct timeval));
 1892         memcpy((void *)&(buf_new->oldest), (void *)&tv, sizeof(struct timeval));
 1893 
 1894         list_add_tail(&buf_new->msg_list, &ctx->log.lru_queue);
 1895         ctx->log.lru_cur_size++;
 1896         flush_logged_msg = _gf_true;
 1897         ret = 0;
 1898     }
 1899 unlock:
 1900     pthread_mutex_unlock(&ctx->log.log_buf_lock);
 1901 
 1902     /* Value of @ret is a don't-care below since irrespective of success or
 1903      * failure post setting of @flush_lru, @first must be flushed and freed.
 1904      */
 1905     if (flush_lru) {
 1906         gf_log_flush_message(first, ctx);
 1907         log_buf_destroy(first);
 1908     }
 1909     /* Similarly, irrespective of whether all operations since setting of
 1910      * @flush_logged_msg were successful or not, flush the message being
 1911      * logged to disk in the plain format.
 1912      */
 1913     if (flush_logged_msg) {
 1914         ret = gf_log_print_plain_fmt(ctx, domain, basename, function, line,
 1915                                      level, errnum, msgid, appmsgstr, callstr,
 1916                                      tv, graph_id, gf_logformat_withmsgid);
 1917     }
 1918 
 1919 out:
 1920     return ret;
 1921 }
 1922 
 1923 int
 1924 _gf_msg(const char *domain, const char *file, const char *function,
 1925         int32_t line, gf_loglevel_t level, int errnum, int trace,
 1926         uint64_t msgid, const char *fmt, ...)
 1927 {
 1928     int ret = 0;
 1929     char *msgstr = NULL;
 1930     va_list ap;
 1931     xlator_t *this = THIS;
 1932     glusterfs_ctx_t *ctx = NULL;
 1933     char *callstr = NULL;
 1934     int log_inited = 0;
 1935 
 1936     if (this == NULL)
 1937         return -1;
 1938 
 1939     ctx = this->ctx;
 1940     if (ctx == NULL) {
 1941         /* messages before context initialization are ignored */
 1942         return -1;
 1943     }
 1944 
 1945     /* check if we should be logging */
 1946     if (skip_logging(this, level))
 1947         goto out;
 1948 
 1949     /* in args check */
 1950     if (!domain || !file || !function || !fmt) {
 1951         fprintf(stderr, "logging: %s:%s():%d: invalid argument\n", __FILE__,
 1952                 __PRETTY_FUNCTION__, __LINE__);
 1953         return -1;
 1954     }
 1955 
 1956     /* form the message */
 1957     va_start(ap, fmt);
 1958     ret = vasprintf(&msgstr, fmt, ap);
 1959     va_end(ap);
 1960 
 1961     /* log */
 1962     if (ret != -1) {
 1963         if (trace) {
 1964             callstr = GF_MALLOC(GF_LOG_BACKTRACE_SIZE, gf_common_mt_char);
 1965             if (callstr == NULL)
 1966                 return -1;
 1967 
 1968             ret = _gf_msg_backtrace(GF_LOG_BACKTRACE_DEPTH, callstr,
 1969                                     GF_LOG_BACKTRACE_SIZE);
 1970             if (ret < 0) {
 1971                 GF_FREE(callstr);
 1972                 callstr = NULL;
 1973             }
 1974         }
 1975 
 1976         pthread_mutex_lock(&ctx->log.logfile_mutex);
 1977         {
 1978             if (ctx->log.logfile) {
 1979                 log_inited = 1;
 1980             }
 1981         }
 1982         pthread_mutex_unlock(&ctx->log.logfile_mutex);
 1983 
 1984         if (!log_inited && ctx->log.gf_log_syslog) {
 1985             ret = gf_log_syslog(
 1986                 ctx, domain, file, function, line, level, errnum, msgid,
 1987                 &msgstr, (callstr ? callstr : NULL),
 1988                 (this->graph) ? this->graph->id : 0, gf_logformat_traditional);
 1989         } else {
 1990             ret = _gf_msg_internal(domain, file, function, line, level, errnum,
 1991                                    msgid, &msgstr, (callstr ? callstr : NULL),
 1992                                    (this->graph) ? this->graph->id : 0);
 1993         }
 1994     } else {
 1995         /* man (3) vasprintf states on error strp contents
 1996          * are undefined, be safe */
 1997         msgstr = NULL;
 1998     }
 1999     if (callstr)
 2000         GF_FREE(callstr);
 2001     FREE(msgstr);
 2002 
 2003 out:
 2004     return ret;
 2005 }
 2006 
 2007 /* TODO: Deprecate (delete) _gf_log, _gf_log_callingfn,
 2008  * once messages are changed to use _gf_msgXXX APIs for logging */
 2009 int
 2010 _gf_log(const char *domain, const char *file, const char *function, int line,
 2011         gf_loglevel_t level, const char *fmt, ...)
 2012 {
 2013     const char *basename = NULL;
 2014     FILE *new_logfile = NULL;
 2015     va_list ap;
 2016     char timestr[GF_LOG_TIMESTR_SIZE] = {
 2017         0,
 2018     };
 2019     struct timeval tv = {
 2020         0,
 2021     };
 2022     char *logline = NULL;
 2023     char *msg = NULL;
 2024     int ret = 0;
 2025     int fd = -1;
 2026     xlator_t *this = THIS;
 2027     glusterfs_ctx_t *ctx = this->ctx;
 2028 
 2029     if (!ctx)
 2030         goto out;
 2031 
 2032     if (skip_logging(this, level))
 2033         goto out;
 2034 
 2035     if (!domain || !file || !function || !fmt) {
 2036         fprintf(stderr, "logging: %s:%s():%d: invalid argument\n", __FILE__,
 2037                 __PRETTY_FUNCTION__, __LINE__);
 2038         return -1;
 2039     }
 2040 
 2041     basename = strrchr(file, '/');
 2042     if (basename)
 2043         basename++;
 2044     else
 2045         basename = file;
 2046 
 2047     va_start(ap, fmt);
 2048     ret = vasprintf(&msg, fmt, ap);
 2049     va_end(ap);
 2050     if (-1 == ret) {
 2051         goto err;
 2052     }
 2053 
 2054     if (ctx->log.log_control_file_found) {
 2055         int priority;
 2056         /* treat GF_LOG_TRACE and GF_LOG_NONE as LOG_DEBUG and
 2057            other level as is */
 2058         if (GF_LOG_TRACE == level || GF_LOG_NONE == level) {
 2059             priority = LOG_DEBUG;
 2060         } else {
 2061             priority = level - 1;
 2062         }
 2063 
 2064         gf_syslog(priority, "[%s:%d:%s] %d-%s: %s", basename, line, function,
 2065                   ((this->graph) ? this->graph->id : 0), domain, msg);
 2066         goto err;
 2067     }
 2068 
 2069     if (ctx->log.logrotate) {
 2070         ctx->log.logrotate = 0;
 2071 
 2072         fd = sys_open(ctx->log.filename, O_CREAT | O_RDONLY, S_IRUSR | S_IWUSR);
 2073         if (fd < 0) {
 2074             gf_smsg("logrotate", GF_LOG_ERROR, errno,
 2075                     LG_MSG_OPEN_LOGFILE_FAILED, NULL);
 2076             return -1;
 2077         }
 2078         sys_close(fd);
 2079 
 2080         new_logfile = fopen(ctx->log.filename, "a");
 2081         if (!new_logfile) {
 2082             gf_smsg("logrotate", GF_LOG_CRITICAL, errno,
 2083                     LG_MSG_OPEN_LOGFILE_FAILED, "filename=%s",
 2084                     ctx->log.filename, NULL);
 2085             goto log;
 2086         }
 2087 
 2088         pthread_mutex_lock(&ctx->log.logfile_mutex);
 2089         {
 2090             if (ctx->log.logfile)
 2091                 fclose(ctx->log.logfile);
 2092 
 2093             ctx->log.gf_log_logfile = ctx->log.logfile = new_logfile;
 2094         }
 2095         pthread_mutex_unlock(&ctx->log.logfile_mutex);
 2096     }
 2097 
 2098 log:
 2099     ret = gettimeofday(&tv, NULL);
 2100     if (-1 == ret)
 2101         goto out;
 2102 
 2103     gf_time_fmt(timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
 2104 
 2105     ret = gf_asprintf(
 2106         &logline, "[%s.%" GF_PRI_SUSECONDS "] %c [%s:%d:%s] %d-%s: %s\n",
 2107         timestr, tv.tv_usec, gf_level_strings[level], basename, line, function,
 2108         ((this->graph) ? this->graph->id : 0), domain, msg);
 2109     if (-1 == ret) {
 2110         goto err;
 2111     }
 2112 
 2113     pthread_mutex_lock(&ctx->log.logfile_mutex);
 2114     {
 2115         if (ctx->log.logfile) {
 2116             fputs(logline, ctx->log.logfile);
 2117             fflush(ctx->log.logfile);
 2118         } else if (ctx->log.loglevel >= level) {
 2119             fputs(logline, stderr);
 2120             fflush(stderr);
 2121         }
 2122 
 2123 #ifdef GF_LINUX_HOST_OS
 2124         /* We want only serious log in 'syslog', not our debug
 2125            and trace logs */
 2126         if (ctx->log.gf_log_syslog && level &&
 2127             (level <= ctx->log.sys_log_level))
 2128             syslog((level - 1), "%s", logline);
 2129 #endif
 2130     }
 2131 
 2132     pthread_mutex_unlock(&ctx->log.logfile_mutex);
 2133 
 2134 err:
 2135     GF_FREE(logline);
 2136 
 2137     FREE(msg);
 2138 
 2139 out:
 2140     return (0);
 2141 }
 2142 
 2143 int
 2144 _gf_log_eh(const char *function, const char *fmt, ...)
 2145 {
 2146     int ret = -1;
 2147     va_list ap;
 2148     char *logline = NULL;
 2149     char *msg = NULL;
 2150     xlator_t *this = NULL;
 2151 
 2152     this = THIS;
 2153 
 2154     va_start(ap, fmt);
 2155     ret = vasprintf(&msg, fmt, ap);
 2156     va_end(ap);
 2157     if (-1 == ret) {
 2158         goto out;
 2159     }
 2160 
 2161     ret = gf_asprintf(&logline, "[%d] %s: %s",
 2162                       ((this->graph) ? this->graph->id : 0), function, msg);
 2163     if (-1 == ret) {
 2164         goto out;
 2165     }
 2166 
 2167     ret = eh_save_history(this->history, logline);
 2168 
 2169 out:
 2170     GF_FREE(logline);
 2171 
 2172     FREE(msg);
 2173 
 2174     return ret;
 2175 }
 2176 
 2177 int
 2178 gf_cmd_log_init(const char *filename)
 2179 {
 2180     int fd = -1;
 2181     xlator_t *this = NULL;
 2182     glusterfs_ctx_t *ctx = NULL;
 2183 
 2184     this = THIS;
 2185     ctx = this->ctx;
 2186 
 2187     if (!ctx)
 2188         return -1;
 2189 
 2190     if (!filename) {
 2191         gf_smsg(this->name, GF_LOG_CRITICAL, 0, LG_MSG_FILENAME_NOT_SPECIFIED,
 2192                 "gf_cmd_log_init", NULL);
 2193         return -1;
 2194     }
 2195 
 2196     ctx->log.cmd_log_filename = gf_strdup(filename);
 2197     if (!ctx->log.cmd_log_filename) {
 2198         return -1;
 2199     }
 2200     /* close and reopen cmdlogfile for log rotate*/
 2201     if (ctx->log.cmdlogfile) {
 2202         fclose(ctx->log.cmdlogfile);
 2203         ctx->log.cmdlogfile = NULL;
 2204     }
 2205 
 2206     fd = sys_open(ctx->log.cmd_log_filename, O_CREAT | O_WRONLY | O_APPEND,
 2207                   S_IRUSR | S_IWUSR);
 2208     if (fd < 0) {
 2209         gf_smsg(this->name, GF_LOG_CRITICAL, errno, LG_MSG_OPEN_LOGFILE_FAILED,
 2210                 "cmd_log_file", NULL);
 2211         return -1;
 2212     }
 2213 
 2214     ctx->log.cmdlogfile = fdopen(fd, "a");
 2215     if (!ctx->log.cmdlogfile) {
 2216         gf_smsg(this->name, GF_LOG_CRITICAL, errno, LG_MSG_OPEN_LOGFILE_FAILED,
 2217                 "gf_cmd_log_init: %s", ctx->log.cmd_log_filename, NULL);
 2218         sys_close(fd);
 2219         return -1;
 2220     }
 2221     return 0;
 2222 }
 2223 
 2224 int
 2225 gf_cmd_log(const char *domain, const char *fmt, ...)
 2226 {
 2227     va_list ap;
 2228     char timestr[64];
 2229     struct timeval tv = {
 2230         0,
 2231     };
 2232     char *logline = NULL;
 2233     char *msg = NULL;
 2234     int ret = 0;
 2235     int fd = -1;
 2236     glusterfs_ctx_t *ctx = NULL;
 2237 
 2238     ctx = THIS->ctx;
 2239 
 2240     if (!ctx)
 2241         return -1;
 2242 
 2243     if (!ctx->log.cmdlogfile)
 2244         return -1;
 2245 
 2246     if (!domain || !fmt) {
 2247         gf_msg_trace("glusterd", 0, "logging: invalid argument\n");
 2248         return -1;
 2249     }
 2250 
 2251     ret = gettimeofday(&tv, NULL);
 2252     if (ret == -1)
 2253         goto out;
 2254     va_start(ap, fmt);
 2255     ret = vasprintf(&msg, fmt, ap);
 2256     va_end(ap);
 2257     if (ret == -1) {
 2258         goto out;
 2259     }
 2260 
 2261     gf_time_fmt(timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
 2262 
 2263     ret = gf_asprintf(&logline, "[%s.%" GF_PRI_SUSECONDS "] %s : %s\n", timestr,
 2264                       tv.tv_usec, domain, msg);
 2265     if (ret == -1) {
 2266         goto out;
 2267     }
 2268 
 2269     /* close and reopen cmdlogfile fd for in case of log rotate*/
 2270     if (ctx->log.cmd_history_logrotate) {
 2271         ctx->log.cmd_history_logrotate = 0;
 2272 
 2273         if (ctx->log.cmdlogfile) {
 2274             fclose(ctx->log.cmdlogfile);
 2275             ctx->log.cmdlogfile = NULL;
 2276         }
 2277 
 2278         fd = sys_open(ctx->log.cmd_log_filename, O_CREAT | O_WRONLY | O_APPEND,
 2279                       S_IRUSR | S_IWUSR);
 2280         if (fd < 0) {
 2281             gf_smsg(THIS->name, GF_LOG_CRITICAL, errno,
 2282                     LG_MSG_OPEN_LOGFILE_FAILED, "name=%s",
 2283                     ctx->log.cmd_log_filename, NULL);
 2284             ret = -1;
 2285             goto out;
 2286         }
 2287 
 2288         ctx->log.cmdlogfile = fdopen(fd, "a");
 2289         if (!ctx->log.cmdlogfile) {
 2290             gf_smsg(THIS->name, GF_LOG_CRITICAL, errno,
 2291                     LG_MSG_OPEN_LOGFILE_FAILED, "name=%s",
 2292                     ctx->log.cmd_log_filename, NULL);
 2293             ret = -1;
 2294             sys_close(fd);
 2295             goto out;
 2296         }
 2297     }
 2298 
 2299     fputs(logline, ctx->log.cmdlogfile);
 2300     fflush(ctx->log.cmdlogfile);
 2301 
 2302 out:
 2303     GF_FREE(logline);
 2304 
 2305     FREE(msg);
 2306 
 2307     return ret;
 2308 }
 2309 
 2310 static int
 2311 _do_slog_format(int errnum, const char *event, va_list inp, char **msg)
 2312 {
 2313     va_list valist_tmp;
 2314     int i = 0;
 2315     int j = 0;
 2316     int k = 0;
 2317     int ret = 0;
 2318     char *fmt = NULL;
 2319     char *buffer = NULL;
 2320     int num_format_chars = 0;
 2321     char format_char = '%';
 2322     char *tmp1 = NULL;
 2323     char *tmp2 = NULL;
 2324     char temp_sep[3] = "";
 2325 
 2326     tmp2 = gf_strdup("");
 2327     if (!tmp2) {
 2328         ret = -1;
 2329         goto out;
 2330     }
 2331 
 2332     /* Hardcoded value for max key value pairs, exits early */
 2333     /* from loop if found NULL */
 2334     for (i = 0; i < GF_MAX_SLOG_PAIR_COUNT; i++) {
 2335         fmt = va_arg(inp, char *);
 2336         if (fmt == NULL) {
 2337             break;
 2338         }
 2339 
 2340         /* Get number of times % is used in input for formatting, */
 2341         /* this count will be used to skip those many args from the */
 2342         /* main list and will be used to format inner format */
 2343         num_format_chars = 0;
 2344         for (k = 0; fmt[k] != '\0'; k++) {
 2345             /* If %% is used then that is escaped */
 2346             if (fmt[k] == format_char && fmt[k + 1] == format_char) {
 2347                 k++;
 2348             } else if (fmt[k] == format_char) {
 2349                 num_format_chars++;
 2350             }
 2351         }
 2352 
 2353         tmp1 = gf_strdup(tmp2);
 2354         if (!tmp1) {
 2355             ret = -1;
 2356             goto out;
 2357         }
 2358 
 2359         GF_FREE(tmp2);
 2360         tmp2 = NULL;
 2361 
 2362         if (num_format_chars > 0) {
 2363             /* Make separate valist and format the string */
 2364             va_copy(valist_tmp, inp);
 2365             ret = gf_vasprintf(&buffer, fmt, valist_tmp);
 2366             if (ret < 0) {
 2367                 va_end(valist_tmp);
 2368                 goto out;
 2369             }
 2370             va_end(valist_tmp);
 2371 
 2372             for (j = 0; j < num_format_chars; j++) {
 2373                 /* Skip the va_arg value since these values
 2374                    are already used for internal formatting */
 2375                 (void)va_arg(inp, void *);
 2376             }
 2377 
 2378             ret = gf_asprintf(&tmp2, "%s%s{%s}", tmp1, temp_sep, buffer);
 2379             if (ret < 0)
 2380                 goto out;
 2381 
 2382             GF_FREE(buffer);
 2383             buffer = NULL;
 2384         } else {
 2385             ret = gf_asprintf(&tmp2, "%s%s{%s}", tmp1, temp_sep, fmt);
 2386             if (ret < 0)
 2387                 goto out;
 2388         }
 2389 
 2390         /* Set seperator for next iteration */
 2391         temp_sep[0] = ',';
 2392         temp_sep[1] = ' ';
 2393         temp_sep[2] = 0;
 2394 
 2395         GF_FREE(tmp1);
 2396         tmp1 = NULL;
 2397     }
 2398 
 2399     tmp1 = gf_strdup(tmp2);
 2400     if (!tmp1) {
 2401         ret = -1;
 2402         goto out;
 2403     }
 2404     GF_FREE(tmp2);
 2405     tmp2 = NULL;
 2406 
 2407     if (errnum) {
 2408         ret = gf_asprintf(&tmp2, "%s [%s%s{errno=%d}, {error=%s}]", event, tmp1,
 2409                           temp_sep, errnum, strerror(errnum));
 2410     } else {
 2411         ret = gf_asprintf(&tmp2, "%s [%s]", event, tmp1);
 2412     }
 2413 
 2414     if (ret == -1)
 2415         goto out;
 2416 
 2417     *msg = gf_strdup(tmp2);
 2418     if (!*msg)
 2419         ret = -1;
 2420 
 2421 out:
 2422     if (buffer)
 2423         GF_FREE(buffer);
 2424 
 2425     if (tmp1)
 2426         GF_FREE(tmp1);
 2427 
 2428     if (tmp2)
 2429         GF_FREE(tmp2);
 2430 
 2431     return ret;
 2432 }
 2433 
 2434 int
 2435 _gf_smsg(const char *domain, const char *file, const char *function,
 2436          int32_t line, gf_loglevel_t level, int errnum, int trace,
 2437          uint64_t msgid, const char *event, ...)
 2438 {
 2439     va_list valist;
 2440     char *msg = NULL;
 2441     int ret = 0;
 2442     xlator_t *this = THIS;
 2443 
 2444     if (skip_logging(this, level))
 2445         return ret;
 2446 
 2447     va_start(valist, event);
 2448     ret = _do_slog_format(errnum, event, valist, &msg);
 2449     if (ret == -1)
 2450         goto out;
 2451 
 2452     /* Pass errnum as zero since it is already formated as required */
 2453     ret = _gf_msg(domain, file, function, line, level, 0, trace, msgid, "%s",
 2454                   msg);
 2455 
 2456 out:
 2457     va_end(valist);
 2458     if (msg)
 2459         GF_FREE(msg);
 2460     return ret;
 2461 }