localtime and ctime are not MT-SAFE

There are a number of nit-level issues throughout the source with
the use of localtime and ctime. While they apparently aren't causing
too many problems, apart from the one in bz 828058, they ought to be
fixed. Among the "real" problems that are fixed in this patch:
1) general localtime and ctime not MT-SAFE. There's a non-zero chance
   that another thread calling localtime (or ctime) will over-write
   the static data about to be used in another thread
2) localtime(& <64-bit-type>) or ctime(& <64-bit-type>) generally
   not a problem on 64-bit or little-endian 32-bit. But even though
   we probably have zero users on big-ending 32-bit platforms, it's
   still incorrect.
3) multiple nested calls passed as params. Last one wins, i.e. over-
   writes result of prior calls.
4) Inconsistent error handling. Most of these calls are for logging,
   tracing, or dumping. I submit that if an error somehow occurs in
   the call to localtime or ctime, the log/trace/dump still should
   still occur.
5) Appliances should all have their clocks set to UTC, and all log
   entries, traces, and dumps should use GMT.
6) fix strtok(), change to strtok_r()

Other things this patch fixes/changes (that aren't bugs per se):
1) Change "%Y-%m-%d %H:%M:%S" and similar to their equivalent shorthand,
   e.g. "%F %T"
2) change sizeof(timestr) to sizeof timestr. sizeof is an operator,
   not a function. You don't use i +(32), why use sizeof(<var>).
   (And yes, you do use parens with sizeof(<type>).)
3) change 'char timestr[256]' to 'char timestr[32]' where appropriate.
   Per-thread stack is limited. Time strings are never longer than ~20
   characters, so why waste 220+ bytes on the stack?

Things this patch doesn't fix:
1) hodgepodge of %Y-%m-%d %H:%M:%S versus %Y/%m/%d-%H%M%S and other
   variations. It's not clear to me whether this ever matters, not to
   mention 3rd party log filtering tools may already rely on a
   particular format. Still it would be nice to have a single manifest
   constant and have every call to localtime/strftime consistently use
   the same format.

BUG: 832173

Change-Id: Iee9719db4576eacc6c75694d9107954d0912cba8
Signed-off-by: Kaleb S. KEITHLEY <kkeithle@redhat.com>
Reviewed-on: http://review.gluster.org/3613
Reviewed-by: Anand Avati <avati@redhat.com>
Tested-by: Anand Avati <avati@redhat.com>

1 files changed, 31 insertions, 42 deletions

diff --git a/libglusterfs/src/logging.c b/libglusterfs/src/logging.c
index c47237f829e..0cfeed586d3 100644
--- a/libglusterfs/src/logging.c
+++ b/libglusterfs/src/logging.c
@@ -206,13 +206,12 @@ _gf_log_nomem (const char *domain, const char *file,
                size_t size)
 {
         const char     *basename        = NULL;
-        struct tm      *tm              = NULL;
         xlator_t       *this            = NULL;
         struct timeval  tv              = {0,};
         int             ret             = 0;
-        char            msg[8092];
-        char            timestr[256];
-        char            callstr[4096];
+        char            msg[8092]       = {0,};
+        char            timestr[256]    = {0,};
+        char            callstr[4096]   = {0,};
 
         this = THIS;
 
@@ -272,12 +271,11 @@ _gf_log_nomem (const char *domain, const char *file,
         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_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
+                snprintf (timestr + strlen (timestr),
+                          sizeof timestr - strlen (timestr),
                           ".%"GF_PRI_SUSECONDS, tv.tv_usec);
 
                 basename = strrchr (file, '/');
@@ -321,7 +319,6 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function,
                    int line, gf_loglevel_t level, const char *fmt, ...)
 {
         const char     *basename        = NULL;
-        struct tm      *tm              = NULL;
         xlator_t       *this            = NULL;
         char           *str1            = NULL;
         char           *str2            = NULL;
@@ -391,14 +388,13 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function,
         if (-1 == ret)
                 goto out;
 
-        tm    = localtime (&tv.tv_sec);
-
         pthread_mutex_lock (&logfile_mutex);
         {
                 va_start (ap, fmt);
 
-                strftime (timestr, 256, "%Y-%m-%d %H:%M:%S", tm);
-                snprintf (timestr + strlen (timestr), 256 - strlen (timestr),
+                gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
+                snprintf (timestr + strlen (timestr),
+                          sizeof timestr - strlen (timestr),
                           ".%"GF_PRI_SUSECONDS, tv.tv_usec);
 
                 basename = strrchr (file, '/');
@@ -464,20 +460,18 @@ int
 _gf_log (const char *domain, const char *file, const char *function, int line,
          gf_loglevel_t level, const char *fmt, ...)
 {
-        const char  *basename = NULL;
-        FILE        *new_logfile = NULL;
-        va_list      ap;
-        struct tm   *tm = NULL;
-        char         timestr[256];
+        const char    *basename = NULL;
+        FILE          *new_logfile = NULL;
+        va_list        ap;
+        char           timestr[256] = {0,};
         struct timeval tv = {0,};
-
-        char        *str1 = NULL;
-        char        *str2 = NULL;
-        char        *msg  = NULL;
-        size_t       len  = 0;
-        int          ret  = 0;
-        int          fd   = -1;
-        xlator_t    *this = NULL;
+        char          *str1 = NULL;
+        char          *str2 = NULL;
+        char          *msg  = NULL;
+        size_t         len  = 0;
+        int            ret  = 0;
+        int            fd   = -1;
+        xlator_t      *this = NULL;
 
         this = THIS;
 
@@ -538,14 +532,13 @@ log:
         if (-1 == ret)
                 goto out;
 
-        tm    = localtime (&tv.tv_sec);
-
         pthread_mutex_lock (&logfile_mutex);
         {
                 va_start (ap, fmt);
 
-                strftime (timestr, 256, "%Y-%m-%d %H:%M:%S", tm);
-                snprintf (timestr + strlen (timestr), 256 - strlen (timestr),
+                gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
+                snprintf (timestr + strlen (timestr),
+                          sizeof timestr - strlen (timestr),
                           ".%"GF_PRI_SUSECONDS, tv.tv_usec);
 
                 basename = strrchr (file, '/');
@@ -664,15 +657,14 @@ gf_cmd_log_init (const char *filename)
 int
 gf_cmd_log (const char *domain, const char *fmt, ...)
 {
-        va_list      ap;
-        struct tm   *tm = NULL;
-        char         timestr[256];
+        va_list        ap;
+        char           timestr[64];
         struct timeval tv = {0,};
-        char        *str1 = NULL;
-        char        *str2 = NULL;
-        char        *msg  = NULL;
-        size_t       len  = 0;
-        int          ret  = 0;
+        char          *str1 = NULL;
+        char          *str2 = NULL;
+        char          *msg  = NULL;
+        size_t         len  = 0;
+        int            ret  = 0;
 
         if (!cmdlogfile)
                 return -1;
@@ -687,11 +679,8 @@ gf_cmd_log (const char *domain, const char *fmt, ...)
         ret = gettimeofday (&tv, NULL);
         if (ret == -1)
                 goto out;
-
-        tm = localtime (&tv.tv_sec);
-
         va_start (ap, fmt);
-        strftime (timestr, 256, "%Y-%m-%d %H:%M:%S", tm);
+        gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT);
         snprintf (timestr + strlen (timestr), 256 - strlen (timestr),
                   ".%"GF_PRI_SUSECONDS, tv.tv_usec);