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>

4 files changed, 89 insertions, 58 deletions

diff --git a/libglusterfs/src/common-utils.c b/libglusterfs/src/common-utils.c
index 3e6543be75c..dbcee77be80 100644
--- a/libglusterfs/src/common-utils.c
+++ b/libglusterfs/src/common-utils.c
@@ -342,10 +342,8 @@ void
 gf_print_trace (int32_t signum)
 {
         extern FILE *gf_log_logfile;
-        struct tm   *tm = NULL;
         char         msg[1024] = {0,};
-        char         timestr[256] = {0,};
-        time_t       utime = 0;
+        char         timestr[64] = {0,};
         int          ret = 0;
         int          fd = 0;
 
@@ -394,9 +392,7 @@ gf_print_trace (int32_t signum)
         {
                 /* Dump the timestamp of the crash too, so the previous logs
                    can be related */
-                utime = time (NULL);
-                tm    = localtime (&utime);
-                strftime (timestr, 256, "%Y-%m-%d %H:%M:%S\n", tm);
+                gf_time_fmt (timestr, sizeof timestr, time (NULL), gf_timefmt_FT);
                 ret = write (fd, "time of crash: ", 15);
                 if (ret < 0)
                         goto out;
@@ -2038,3 +2034,26 @@ gf_strip_whitespace (char *str, int len)
         GF_FREE (new_str);
         return new_len;
 }
+
+static const char *__gf_timefmts[] = {
+        "%F %T",
+        "%Y/%m/%d-%T",
+        "%b %d %T",
+        "%F %H%M%S"
+};
+
+static const char *__gf_zerotimes[] = {
+        "0000-00-00 00:00:00",
+        "0000/00/00-00:00:00",
+        "xxx 00 00:00:00",
+        "0000-00-00 000000"
+};
+
+void
+_gf_timestuff (gf_timefmts *fmt, const char ***fmts, const char ***zeros)
+{
+        *fmt = gf_timefmt_last;
+        *fmts = __gf_timefmts;
+        *zeros = __gf_zerotimes;
+}
+
diff --git a/libglusterfs/src/common-utils.h b/libglusterfs/src/common-utils.h
index d5880291250..3df6dd91ccb 100644
--- a/libglusterfs/src/common-utils.h
+++ b/libglusterfs/src/common-utils.h
@@ -392,6 +392,34 @@ memdup (const void *ptr, size_t size)
 	return newptr;
 }
 
+typedef enum {
+        gf_timefmt_default = 0,
+        gf_timefmt_FT = 0,  /* YYYY-MM-DD hh:mm:ss */
+        gf_timefmt_Ymd_T,   /* YYYY/MM-DD-hh:mm:ss */
+        gf_timefmt_bdT,     /* ddd DD hh:mm:ss */
+        gf_timefmt_F_HMS,   /* YYYY-MM-DD hhmmss */
+        gf_timefmt_last
+} gf_timefmts;
+
+static inline void
+gf_time_fmt (char *dst, size_t sz_dst, time_t utime, unsigned int fmt)
+{
+        extern void _gf_timestuff (gf_timefmts *, const char ***, const char ***);
+        static gf_timefmts timefmt_last = (gf_timefmts) -1;
+        static const char **fmts;
+        static const char **zeros;
+        struct tm tm;
+
+        if (timefmt_last == -1)
+                _gf_timestuff (&timefmt_last, &fmts, &zeros);
+        if (timefmt_last < fmt) fmt = gf_timefmt_default;
+        if (gmtime_r (&utime, &tm) != NULL) {
+                strftime (dst, sz_dst, fmts[fmt], &tm);
+        } else {
+                strncpy (dst, zeros[fmt], sz_dst);
+        }
+}
+
 /*
  * rounds up nr to power of two. If nr is already a power of two, just returns
  * nr
diff --git a/libglusterfs/src/graph.c b/libglusterfs/src/graph.c
index 65cbb2e8323..a42ae7cd7fa 100644
--- a/libglusterfs/src/graph.c
+++ b/libglusterfs/src/graph.c
@@ -28,20 +28,17 @@ _gf_dump_details (int argc, char **argv)
 {
         extern FILE *gf_log_logfile;
         int          i = 0;
-        char         timestr[256];
+        char         timestr[64];
         time_t       utime = 0;
-        struct tm   *tm = NULL;
         pid_t        mypid = 0;
         struct utsname uname_buf = {{0, }, };
         int            uname_ret = -1;
 
-        utime = time (NULL);
-        tm    = localtime (&utime);
         mypid = getpid ();
         uname_ret   = uname (&uname_buf);
 
-        /* Which git? What time? */
-        strftime (timestr, 256, "%Y-%m-%d %H:%M:%S", tm);
+        utime = time (NULL);
+        gf_time_fmt (timestr, sizeof timestr, utime, gf_timefmt_FT);
         fprintf (gf_log_logfile,
                  "========================================"
                  "========================================\n");
@@ -340,8 +337,7 @@ fill_uuid (char *uuid, int size)
 {
         char           hostname[256] = {0,};
         struct timeval tv = {0,};
-        struct tm      now = {0, };
-        char           now_str[32];
+        char           now_str[64];
 
         if (gettimeofday (&tv, NULL) == -1) {
                 gf_log ("graph", GF_LOG_ERROR,
@@ -355,8 +351,7 @@ fill_uuid (char *uuid, int size)
                         strerror (errno));
         }
 
-        localtime_r (&tv.tv_sec, &now);
-        strftime (now_str, 32, "%Y/%m/%d-%H:%M:%S", &now);
+        gf_time_fmt (now_str, sizeof now_str, tv.tv_sec, gf_timefmt_Ymd_T);
         snprintf (uuid, size, "%s-%d-%s:%"GF_PRI_SUSECONDS,
                   hostname, getpid(), now_str, tv.tv_usec);
 
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);