logging: change the 'logfile' value in a locked region

'logfile' is a global variable, and it can change if log-rotate
command is issued. currently 'fprintf(logfile)' happens in a
locked region where as the 'fclose(logfile)' can happen outside
the locked region causing racy behavior.

Change-Id: I40871e5c365303b7c602e2c302b085d64f6b945f
Signed-off-by: Amar Tumballi <amarts@redhat.com>
BUG: 826032
Reviewed-on: http://review.gluster.com/3493
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Anand Avati <avati@redhat.com>

1 files changed, 91 insertions, 88 deletions

diff --git a/libglusterfs/src/logging.c b/libglusterfs/src/logging.c
index c47237f829e..6e3757e14cf 100644
--- a/libglusterfs/src/logging.c
+++ b/libglusterfs/src/logging.c
@@ -274,27 +274,27 @@ _gf_log_nomem (const char *domain, const char *file,
 
         tm    = localtime (&tv.tv_sec);
 
+        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 out;
+        }
+
         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);
@@ -310,7 +310,6 @@ _gf_log_nomem (const char *domain, const char *file,
 #endif
         }
 
-unlock:
         pthread_mutex_unlock (&logfile_mutex);
 out:
         return ret;
@@ -393,41 +392,41 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function,
 
         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_PRI_SUSECONDS, tv.tv_usec);
-
-                basename = strrchr (file, '/');
-                if (basename)
-                        basename++;
-                else
-                        basename = file;
-
-                ret = gf_asprintf (&str1, "[%s] %s [%s:%d:%s] %s %d-%s: ",
-                                   timestr, level_strings[level],
-                                   basename, line, function, callstr,
-                                   ((this->graph) ? this->graph->id:0), domain);
-                if (-1 == ret) {
-                        goto unlock;
-                }
+        va_start (ap, fmt);
 
-                ret = vasprintf (&str2, fmt, ap);
-                if (-1 == ret) {
-                        goto unlock;
-                }
+        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 = gf_asprintf (&str1, "[%s] %s [%s:%d:%s] %s %d-%s: ",
+                           timestr, level_strings[level],
+                           basename, line, function, callstr,
+                           ((this->graph) ? this->graph->id:0), domain);
+        if (-1 == ret) {
+                goto out;
+        }
+
+        ret = vasprintf (&str2, fmt, ap);
+        if (-1 == ret) {
+                goto out;
+        }
 
-                va_end (ap);
+        va_end (ap);
 
-                len = strlen (str1);
-                msg = GF_MALLOC (len + strlen (str2) + 1, gf_common_mt_char);
+        len = strlen (str1);
+        msg = GF_MALLOC (len + strlen (str2) + 1, gf_common_mt_char);
 
-                strcpy (msg, str1);
-                strcpy (msg + len, str2);
+        strcpy (msg, str1);
+        strcpy (msg + len, str2);
 
+        pthread_mutex_lock (&logfile_mutex);
+        {
                 if (logfile) {
                         fprintf (logfile, "%s\n", msg);
                         fflush (logfile);
@@ -443,12 +442,11 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function,
 #endif
         }
 
-unlock:
         pthread_mutex_unlock (&logfile_mutex);
 
-        if (msg) {
+out:
+        if (msg)
                 GF_FREE (msg);
-        }
 
         if (str1)
                 GF_FREE (str1);
@@ -456,7 +454,6 @@ unlock:
         if (str2)
                 FREE (str2);
 
-out:
         return ret;
 }
 
@@ -527,10 +524,15 @@ _gf_log (const char *domain, const char *file, const char *function, int line,
                         goto log;
                 }
 
-                if (logfile)
-                        fclose (logfile);
+                pthread_mutex_lock (&logfile_mutex);
+                {
+                        if (logfile)
+                                fclose (logfile);
+
+                        gf_log_logfile = logfile = new_logfile;
+                }
+                pthread_mutex_unlock (&logfile_mutex);
 
-                gf_log_logfile = logfile = new_logfile;
         }
 
 log:
@@ -540,40 +542,41 @@ log:
 
         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_PRI_SUSECONDS, tv.tv_usec);
-
-                basename = strrchr (file, '/');
-                if (basename)
-                        basename++;
-                else
-                        basename = file;
-
-                ret = gf_asprintf (&str1, "[%s] %s [%s:%d:%s] %d-%s: ",
-                                   timestr, level_strings[level],
-                                   basename, line, function,
-                                   ((this->graph)?this->graph->id:0), domain);
-                if (-1 == ret) {
-                        goto unlock;
-                }
+        va_start (ap, fmt);
 
-                ret = vasprintf (&str2, fmt, ap);
-                if (-1 == ret) {
-                        goto unlock;
-                }
+        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 = gf_asprintf (&str1, "[%s] %s [%s:%d:%s] %d-%s: ",
+                           timestr, level_strings[level],
+                           basename, line, function,
+                           ((this->graph)?this->graph->id:0), domain);
+        if (-1 == ret) {
+                goto err;
+        }
+
+        ret = vasprintf (&str2, fmt, ap);
+        if (-1 == ret) {
+                goto err;
+        }
+
+        va_end (ap);
 
-                va_end (ap);
+        len = strlen (str1);
+        msg = GF_MALLOC (len + strlen (str2) + 1, gf_common_mt_char);
 
-                len = strlen (str1);
-                msg = GF_MALLOC (len + strlen (str2) + 1, gf_common_mt_char);
+        strcpy (msg, str1);
+        strcpy (msg + len, str2);
 
-                strcpy (msg, str1);
-                strcpy (msg + len, str2);
+        pthread_mutex_lock (&logfile_mutex);
+        {
 
                 if (logfile) {
                         fprintf (logfile, "%s\n", msg);
@@ -590,9 +593,9 @@ log:
 #endif
         }
 
-unlock:
         pthread_mutex_unlock (&logfile_mutex);
 
+err:
         if (msg) {
                 GF_FREE (msg);
         }