RE: gwlib log issue

Hi

Have anybody had a look at this yet?

Regards
Werner


-----Original Message-----
From: Werner Coetzee [mailto:[email protected]]
Sent: 17 November 2008 11:27
To: [email protected]
Subject: gwlib log issue

Hi List

I've come across an issue in the shutdown phase of gwlist_shutdown().
It happens in the log_close_all() function as part of the log_shutdown().

If you have the same log file opened twice (or more), e.g. 2 smsc binds sharing the same log file, fclose() will fail on the second attempt, and abort.
The reason is that the log file is added twice to the logfiles array, with the same file descriptor.

Below is the output from a test program, opening test1.log, test2.log and then test1.log again.
When shutting down, it fails on the second close of test1.log (I've added some extra printf in log_close_all to print the log file being close):

2008-11-17 11:03:45 [27637] [0] INFO: Added logfile `test1.log' with level `0'.
2008-11-17 11:03:45 [27637] [0] INFO: Added logfile `test2.log' with level `0'.
2008-11-17 11:03:45 [27637] [0] INFO: Added logfile `test1.log' with level `0'.
2008-11-17 11:03:45 [27637] [0] DEBUG: calling gwlib_shutdown
2008-11-17 11:03:45 [27637] [0] DEBUG: Closing all log files
Closing log file test1.log
Closing log file test2.log
Closing log file test1.log
*** glibc detected *** double free or corruption (!prev): 0x09ed4108 ***
Aborted


I have attached a patch to fix this issue.
Instead of adding the already opened log to the logfiles array again, it will update the log level and exclusivity of the already opened log file, and return its log index.

This produces a successful test with output found below:

2008-11-17 11:05:22 [27862] [0] INFO: Added logfile `test1.log' with level `0'.
2008-11-17 11:05:22 [27862] [0] INFO: Added logfile `test2.log' with level `0'.
2008-11-17 11:05:22 [27862] [0] INFO: Re-using logfile `test1.log' with level `0'.
2008-11-17 11:05:22 [27862] [0] DEBUG: calling gwlib_shutdown
2008-11-17 11:05:22 [27862] [0] DEBUG: Closing all log files
Closing log file test2.log
Closing log file test1.log


Please review the patch and comment.

Thanks
Werner

Index: log.c
===================================================================
RCS file: /home/cvs/gateway/gwlib/log.c,v
retrieving revision 1.54
diff -u -r1.54 log.c
--- log.c	9 Jan 2008 20:06:55 -0000	1.54
+++ log.c	17 Nov 2008 06:46:00 -0000
@@ -323,9 +323,11 @@
      * If there is an open file, then assign the file descriptor
      * that is already existing for this log file.
      */
-    for (i = 0; i < num_logfiles && f == NULL; ++i) {
-        if (strcmp(logfiles[i].filename, filename) == 0)
+    for (i = 0; i < num_logfiles; ++i) {
+        if (strcmp(logfiles[i].filename, filename) == 0) {
             f = logfiles[i].file;
+            break;
+        }
     }
 
     /* if not previously opened, then open it now */
@@ -338,15 +340,23 @@
         }
     }
     
-    logfiles[num_logfiles].file = f;
-    logfiles[num_logfiles].minimum_output_level = level;
-    logfiles[num_logfiles].exclusive = excl;
-    strcpy(logfiles[num_logfiles].filename, filename);
-    ++num_logfiles;
-    i = num_logfiles - 1;
-    gw_rwlock_unlock(&rwlock);
+    logfiles[i].file = f;
+    logfiles[i].minimum_output_level = level;
+    logfiles[i].exclusive = excl;
+
+    if (i == num_logfiles) {
+        /* filename was not found in the logfiles array, so add it */
+        strcpy(logfiles[i].filename, filename);
+        ++num_logfiles;
+        gw_rwlock_unlock(&rwlock);
+
+        info(0, "Added logfile `%s' with level `%d'.", filename, level);
+    } else {
+        /* filename was found in the logfiles array, so reuse the existing slot */
+        gw_rwlock_unlock(&rwlock);
 
-    info(0, "Added logfile `%s' with level `%d'.", filename, level);
+        info(0, "Re-using logfile `%s' with level `%d'.", filename, level);
+    }
 
     return i;
 }