From ebe47d5dae42da18b289e7be44eb67a8157a56b1 Mon Sep 17 00:00:00 2001 From: Amar Tumballi Date: Wed, 16 Mar 2011 09:38:21 +0000 Subject: libglusterfs: gf_log_nomem() and other minor updates log will be done when the memory allocation fails, hence in code, no explicit logs required for memory allocation failures. also, if there are logs before actually doing a log_init(), they will be logged in 'stderr'. Signed-off-by: Amar Tumballi Signed-off-by: Vijay Bellur BUG: 2346 (Log message enhancements in GlusterFS - phase 1) URL: http://bugs.gluster.com/cgi-bin/bugzilla3/show_bug.cgi?id=2346 --- libglusterfs/src/globals.c | 2 + libglusterfs/src/logging.c | 173 +++++++++++++++++++++++++++++++++++++------- libglusterfs/src/logging.h | 39 ++++++---- libglusterfs/src/mem-pool.c | 23 +++--- libglusterfs/src/mem-pool.h | 64 ++++++++++++---- 5 files changed, 235 insertions(+), 66 deletions(-) diff --git a/libglusterfs/src/globals.c b/libglusterfs/src/globals.c index 3121a1f1415..9e9870e0bf0 100644 --- a/libglusterfs/src/globals.c +++ b/libglusterfs/src/globals.c @@ -349,6 +349,8 @@ glusterfs_globals_init () gf_op_list_init (); + gf_log_globals_init (); + ret = glusterfs_ctx_init (); if (ret) goto out; diff --git a/libglusterfs/src/logging.c b/libglusterfs/src/logging.c index ed024840aa4..4c6bc2ed73e 100644 --- a/libglusterfs/src/logging.c +++ b/libglusterfs/src/logging.c @@ -48,8 +48,8 @@ static pthread_mutex_t logfile_mutex; static char *filename = NULL; static uint8_t logrotate = 0; static FILE *logfile = NULL; -static gf_loglevel_t loglevel = GF_LOG_MAX; -static int gf_log_syslog = 0; +static gf_loglevel_t loglevel = GF_LOG_INFO; +static int gf_log_syslog = 1; char gf_log_xl_log_set; gf_loglevel_t gf_log_loglevel; /* extern'd */ @@ -115,6 +115,18 @@ gf_log_fini (void) } +void +gf_log_globals_init (void) +{ + pthread_mutex_init (&logfile_mutex, NULL); + +#ifdef GF_LINUX_HOST_OS + /* For the 'syslog' output. one can grep 'GlusterFS' in syslog + for serious logs */ + openlog ("GlusterFS", LOG_PID, LOG_DAEMON); +#endif +} + int gf_log_init (const char *file) { @@ -123,8 +135,6 @@ gf_log_init (const char *file) return -1; } - pthread_mutex_init (&logfile_mutex, NULL); - filename = gf_strdup (file); if (!filename) { fprintf (stderr, "gf_log_init: strdup error\n"); @@ -140,12 +150,6 @@ gf_log_init (const char *file) return -1; } -#ifdef GF_LINUX_HOST_OS - /* For the 'syslog' output. one can grep 'GlusterFS' in syslog - for serious logs */ - openlog ("GlusterFS", LOG_PID, LOG_DAEMON); -#endif - gf_log_logfile = logfile; return 0; @@ -170,8 +174,6 @@ struct _log_msg { }; - - void gf_log_lock (void) { @@ -192,6 +194,123 @@ gf_log_cleanup (void) pthread_mutex_destroy (&logfile_mutex); } +int +_gf_log_nomem (const char *domain, const char *file, + const char *function, int line, gf_loglevel_t level, + size_t size) +{ + const char *basename = NULL; + struct tm *tm = NULL; + xlator_t *this = NULL; + struct timeval tv = {0,}; + int ret = 0; + gf_loglevel_t xlator_loglevel = 0; + char msg[8092]; + char timestr[256]; + char callstr[4096]; + + this = THIS; + + xlator_loglevel = this->loglevel; + if (xlator_loglevel == 0) + xlator_loglevel = loglevel; + + if (level > xlator_loglevel) + goto out; + + static char *level_strings[] = {"", /* NONE */ + "M", /* EMERGENCY */ + "A", /* ALERT */ + "C", /* CRITICAL */ + "E", /* ERROR */ + "W", /* WARNING */ + "N", /* NOTICE */ + "I", /* INFO/NORMAL */ + "D", /* DEBUG */ + "T", /* TRACE */ + ""}; + + if (!domain || !file || !function) { + fprintf (stderr, + "logging: %s:%s():%d: invalid argument\n", + __FILE__, __PRETTY_FUNCTION__, __LINE__); + return -1; + } + +#if HAVE_BACKTRACE + /* Print 'calling function' */ + do { + void *array[5]; + char **callingfn = NULL; + size_t bt_size = 0; + + bt_size = backtrace (array, 5); + if (bt_size) + callingfn = backtrace_symbols (&array[2], bt_size-2); + if (!callingfn) + break; + + if (bt_size == 5) + snprintf (callstr, 4096, "(-->%s (-->%s (-->%s)))", + callingfn[2], callingfn[1], callingfn[0]); + if (bt_size == 4) + snprintf (callstr, 4096, "(-->%s (-->%s))", + callingfn[1], callingfn[0]); + if (bt_size == 3) + snprintf (callstr, 4096, "(-->%s)", callingfn[0]); + + free (callingfn); + } while (0); +#endif /* HAVE_BACKTRACE */ + + ret = gettimeofday (&tv, NULL); + if (-1 == ret) + goto out; + + tm = localtime (&tv.tv_sec); + + pthread_mutex_lock (&logfile_mutex); + { + strftime (timestr, 256, "%Y-%m-%d %H:%M:%S", tm); + snprintf (timestr + strlen (timestr), 256 - strlen (timestr), + ".%"GF_PRI_SUSECONDS, tv.tv_usec); + + basename = strrchr (file, '/'); + if (basename) + basename++; + else + basename = file; + + ret = sprintf (msg, "[%s] %s [%s:%d:%s] %s %s: no memory " + "available for size (%"GF_PRI_SIZET")", + timestr, level_strings[level], + basename, line, function, callstr, + domain, size); + if (-1 == ret) { + goto unlock; + } + + if (logfile) { + fprintf (logfile, "%s\n", msg); + fflush (logfile); + } else { + fprintf (stderr, "%s\n", msg); + } + +#ifdef GF_LINUX_HOST_OS + /* We want only serious log in 'syslog', not our debug + and trace logs */ + if (gf_log_syslog && level && (level <= GF_LOG_ERROR)) + syslog ((level-1), "%s\n", msg); +#endif + } + +unlock: + pthread_mutex_unlock (&logfile_mutex); +out: + return ret; + } + int _gf_log_callingfn (const char *domain, const char *file, const char *function, int line, gf_loglevel_t level, const char *fmt, ...) @@ -210,9 +329,6 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function, gf_loglevel_t xlator_loglevel = 0; va_list ap; - if (!logfile) - return -1; - this = THIS; xlator_loglevel = this->loglevel; @@ -308,13 +424,17 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function, strcpy (msg, str1); strcpy (msg + len, str2); - fprintf (logfile, "%s\n", msg); - fflush (logfile); + if (logfile) { + fprintf (logfile, "%s\n", msg); + fflush (logfile); + } else { + fprintf (stderr, "%s\n", msg); + } #ifdef GF_LINUX_HOST_OS /* We want only serious log in 'syslog', not our debug and trace logs */ - if (gf_log_syslog && level && (level <= GF_LOG_ERROR)) + if (gf_log_syslog && level && (level <= GF_LOG_CRITICAL)) syslog ((level-1), "%s\n", msg); #endif } @@ -355,9 +475,6 @@ _gf_log (const char *domain, const char *file, const char *function, int line, xlator_t *this = NULL; gf_loglevel_t xlator_loglevel = 0; - if (!logfile) - return -1; - this = THIS; xlator_loglevel = this->loglevel; @@ -398,7 +515,9 @@ _gf_log (const char *domain, const char *file, const char *function, int line, goto log; } - fclose (logfile); + if (logfile) + fclose (logfile); + gf_log_logfile = logfile = new_logfile; } @@ -444,13 +563,17 @@ log: strcpy (msg, str1); strcpy (msg + len, str2); - fprintf (logfile, "%s\n", msg); - fflush (logfile); + if (logfile) { + fprintf (logfile, "%s\n", msg); + fflush (logfile); + } else { + fprintf (stderr, "%s\n", msg); + } #ifdef GF_LINUX_HOST_OS /* We want only serious log in 'syslog', not our debug and trace logs */ - if (gf_log_syslog && level && (level <= GF_LOG_ERROR)) + if (gf_log_syslog && level && (level <= GF_LOG_CRITICAL)) syslog ((level-1), "%s\n", msg); #endif } diff --git a/libglusterfs/src/logging.h b/libglusterfs/src/logging.h index aa6e00edb70..0664b2efae0 100644 --- a/libglusterfs/src/logging.h +++ b/libglusterfs/src/logging.h @@ -69,8 +69,6 @@ typedef enum { GF_LOG_TRACE, /* full trace of operation */ } gf_loglevel_t; -#define GF_LOG_MAX GF_LOG_DEBUG - extern gf_loglevel_t gf_log_loglevel; extern char gf_log_xl_log_set; @@ -94,27 +92,38 @@ extern char gf_log_xl_log_set; levl, ##fmt); \ } while (0) + +/* No malloc or calloc should be called in this function */ +#define gf_log_nomem(dom, levl, size) do { \ + if ((levl > gf_log_loglevel) && !gf_log_xl_log_set) \ + break; \ + _gf_log_nomem (dom, __FILE__, __FUNCTION__, __LINE__, \ + levl, size); \ + } while (0) + + /* Log once in GF_UNIVERSAL_ANSWER times */ #define GF_LOG_OCCASIONALLY(var, args...) if (!(var++%GF_UNIVERSAL_ANSWER)) { \ gf_log (args); \ } -void -gf_log_logrotate (int signum); +void gf_log_logrotate (int signum); +void gf_log_globals_init (void); int gf_log_init (const char *filename); void gf_log_cleanup (void); -int -_gf_log (const char *domain, const char *file, const char *function, - int32_t line, gf_loglevel_t level, const char *fmt, ...); -int -_gf_log_callingfn (const char *domain, const char *file, const char *function, - int32_t line, gf_loglevel_t level, const char *fmt, ...); +int _gf_log (const char *domain, const char *file, const char *function, + int32_t line, gf_loglevel_t level, const char *fmt, ...); +int _gf_log_callingfn (const char *domain, const char *file, const char *function, + int32_t line, gf_loglevel_t level, const char *fmt, ...); + +int _gf_log_nomem (const char *domain, const char *file, + const char *function, int line, gf_loglevel_t level, + size_t size); -int -gf_log_from_client (const char *msg, char *identifier); +int gf_log_from_client (const char *msg, char *identifier); void gf_log_lock (void); void gf_log_unlock (void); @@ -135,9 +144,7 @@ void gf_log_set_xl_loglevel (void *xl, gf_loglevel_t level); #define GF_ERROR(xl, format, args...) \ gf_log ((xl)->name, GF_LOG_ERROR, format, ##args) -int -gf_cmd_log (const char *domain, const char *fmt, ...); +int gf_cmd_log (const char *domain, const char *fmt, ...); -int -gf_cmd_log_init (const char *filename); +int gf_cmd_log_init (const char *filename); #endif /* __LOGGING_H__ */ diff --git a/libglusterfs/src/mem-pool.c b/libglusterfs/src/mem-pool.c index 9acebad4153..0d555020bbe 100644 --- a/libglusterfs/src/mem-pool.c +++ b/libglusterfs/src/mem-pool.c @@ -141,9 +141,10 @@ __gf_calloc (size_t nmemb, size_t size, uint32_t type) ptr = calloc (1, tot_size); - if (!ptr) + if (!ptr) { + gf_log_nomem ("", GF_LOG_ALERT, tot_size); return NULL; - + } gf_mem_set_acct_info (xl, &ptr, req_size, type); return (void *)ptr; @@ -164,9 +165,10 @@ __gf_malloc (size_t size, uint32_t type) tot_size = size + GF_MEM_HEADER_SIZE + GF_MEM_TRAILER_SIZE; ptr = malloc (tot_size); - if (!ptr) + if (!ptr) { + gf_log_nomem ("", GF_LOG_ALERT, tot_size); return NULL; - + } gf_mem_set_acct_info (xl, &ptr, size, type); return (void *)ptr; @@ -181,7 +183,7 @@ __gf_realloc (void *ptr, size_t size) uint32_t type = 0; if (!gf_mem_acct_enable) - return realloc (ptr, size); + return REALLOC (ptr, size); tot_size = size + GF_MEM_HEADER_SIZE + GF_MEM_TRAILER_SIZE; @@ -196,8 +198,10 @@ __gf_realloc (void *ptr, size_t size) type = *(uint32_t *)orig_ptr; ptr = realloc (orig_ptr, tot_size); - if (!ptr) + if (!ptr) { + gf_log_nomem ("", GF_LOG_ALERT, tot_size); return NULL; + } gf_mem_set_acct_info (xl, (char **)&ptr, size, type); @@ -221,12 +225,7 @@ gf_vasprintf (char **string_ptr, const char *format, va_list arg) size++; str = GF_MALLOC (size, gf_common_mt_asprintf); if (str == NULL) { - /* - * Strictly speaking, GNU asprintf doesn't do this, - * but the caller isn't checking the return value. - */ - gf_log ("libglusterfs", GF_LOG_CRITICAL, - "failed to allocate memory"); + /* log is done in GF_MALLOC itself */ return -1; } rv = vsnprintf (str, size, format, arg_save); diff --git a/libglusterfs/src/mem-pool.h b/libglusterfs/src/mem-pool.h index 0cda62fb85b..85ceeb87e06 100644 --- a/libglusterfs/src/mem-pool.h +++ b/libglusterfs/src/mem-pool.h @@ -22,6 +22,7 @@ #include "list.h" #include "locking.h" +#include "logging.h" #include "mem-types.h" #include #include @@ -29,15 +30,6 @@ #include -#define MALLOC(size) malloc(size) -#define CALLOC(cnt,size) calloc(cnt,size) - -#define FREE(ptr) \ - if (ptr != NULL) { \ - free ((void *)ptr); \ - ptr = (void *)0xeeeeeeee; \ - } - struct mem_acct { uint32_t num_types; struct mem_acct_rec *rec; @@ -67,16 +59,62 @@ gf_vasprintf (char **string_ptr, const char *format, va_list arg); int gf_asprintf (char **string_ptr, const char *format, ...); +void +__gf_free (void *ptr); + + +static inline +void* __gf_default_malloc (size_t size) +{ + void *ptr = NULL; + + ptr = malloc (size); + if (!ptr) + gf_log_nomem ("", GF_LOG_ALERT, size); + + return ptr; +} + +static inline +void* __gf_default_calloc (int cnt, size_t size) +{ + void *ptr = NULL; + + ptr = calloc (cnt, size); + if (!ptr) + gf_log_nomem ("", GF_LOG_ALERT, (cnt * size)); + + return ptr; +} + +static inline +void* __gf_default_realloc (void *oldptr, size_t size) +{ + void *ptr = NULL; + + ptr = realloc (oldptr, size); + if (!ptr) + gf_log_nomem ("", GF_LOG_ALERT, size); + + return ptr; +} + +#define MALLOC(size) __gf_default_malloc(size) +#define CALLOC(cnt,size) __gf_default_calloc(cnt,size) +#define REALLOC(ptr,size) __gf_default_realloc(ptr,size) + +#define FREE(ptr) \ + if (ptr != NULL) { \ + free ((void *)ptr); \ + ptr = (void *)0xeeeeeeee; \ + } + #define GF_CALLOC(nmemb, size, type) __gf_calloc (nmemb, size, type) #define GF_MALLOC(size, type) __gf_malloc (size, type) #define GF_REALLOC(ptr, size) __gf_realloc (ptr, size) -void -__gf_free (void *ptr); - - #define GF_FREE(free_ptr) __gf_free (free_ptr); static inline -- cgit