[icinga-checkins] icinga.org: icinga-core/test/ido: partly revert #2271, add soft_lock around debug log, use reentrant localtime_r #2500

git at icinga.org git at icinga.org
Wed Apr 4 13:48:32 CEST 2012


Module: icinga-core
Branch: test/ido
Commit: 07d2f27740a277b951acf83252d8f2464a1c2117
URL:    https://git.icinga.org/?p=icinga-core.git;a=commit;h=07d2f27740a277b951acf83252d8f2464a1c2117

Author: Michael Friedrich <michael.friedrich at univie.ac.at>
Date:   Wed Apr  4 13:21:20 2012 +0200

partly revert #2271, add soft_lock around debug log, use reentrant localtime_r #2500

the recent change in #2271 introduced a change of vfprintf
to vasprintf afterwards. while at first sight the usage of
the non-reentrant / non-threadsafe localtime() seemed to be
the root cause (fixed in this commit to use localtime_r())
the real cause is the change of writing to that file
descriptor.

the observed behaviour sets the parent process to FUTEX_WAIT_PRIVATE
waiting for the child to terminate which is not possible
still having a lock on the file descriptor.

adding a soft_lock on the debug log not to interfere with
locks inherited from parent to child is good & added, but
does not solve the root cause either.

the reason for that changed behaviour is the usage of vasprintf
and a local buffer rather than vfprintf on fmt directly.

passing a NULL ptr to log_debug_info should be checked upon
call to that function by the caller himself.

this is a partly revert of 2256b95874b5eead76b7aef2a68d9f7b90858a68
and solves #2500

refs #2271
refs #2500

---

 module/idoutils/src/logging.c |   57 ++++++++++++++++++++++++++++++++++------
 1 files changed, 48 insertions(+), 9 deletions(-)

diff --git a/module/idoutils/src/logging.c b/module/idoutils/src/logging.c
index 4d8e747..746ba9c 100644
--- a/module/idoutils/src/logging.c
+++ b/module/idoutils/src/logging.c
@@ -29,6 +29,37 @@ extern unsigned long ido2db_max_debug_file_size;
 
 extern int ido2db_debug_readable_timestamp;
 
+static pthread_mutex_t ido2db_debug_fp_lock;
+
+/*
+ * since we don't want child processes to hang indefinitely
+ * in case they inherit a locked lock, we use soft-locking
+ * here, which basically tries to acquire the lock for a
+ * short while and then gives up, returning -1 to signal
+ * the error
+ */
+static inline int soft_lock(pthread_mutex_t *lock) {
+        int i;
+
+        for (i = 0; i < 5; i++) {
+                if (!pthread_mutex_trylock(lock)) {
+                        /* success */
+                        return 0;
+                }
+
+                if (errno == EDEADLK) {
+                        /* we already have the lock */
+                        return 0;
+                }
+
+                /* sleep briefly */
+                usleep(30);
+        }
+
+        return -1; /* we failed to get the lock. Nothing to do */
+}
+
+
 /****************************************************************************/
 /* LOGGING ROUTINES                                                         */
 /****************************************************************************/
@@ -68,9 +99,8 @@ int ido2db_close_debug_log(void) {
 int ido2db_log_debug_info(int level, int verbosity, const char *fmt, ...) {
         va_list ap;
         char *temp_path = NULL;
-		char *buf=NULL;
         time_t t;
-        struct tm *tm;
+        struct tm *tm, tm_s;
         char temp_time[80];
         struct timeval current_time;
         unsigned long tid;
@@ -85,12 +115,24 @@ int ido2db_log_debug_info(int level, int verbosity, const char *fmt, ...) {
         if (ido2db_debug_file_fp == NULL)
                 return IDO_ERROR;
 
+        /*
+         * lock it so concurrent threads don't stomp on each other's
+         * writings. We maintain the lock until we've (optionally)
+         * renamed the file.
+         * If soft_lock() fails we return early.
+         */
+        if (soft_lock(&ido2db_debug_fp_lock) < 0)
+                return ERROR;
+
         /* write the timestamp */
         gettimeofday(&current_time, NULL);
 
         time(&t);
-        tm=localtime(&t);
+
+        tm=localtime_r(&t, &tm_s);
+
         strftime(temp_time, 80, "%c", tm);
+
         tid=pthread_self();
         pid=getpid();
 	if (ido2db_debug_readable_timestamp)
@@ -100,13 +142,8 @@ int ido2db_log_debug_info(int level, int verbosity, const char *fmt, ...) {
 
         /* write the data */
         va_start(ap, fmt);
-		/* use gnu asprintf to take care about null pointer data*/
-        vasprintf(&buf, fmt, ap);
+	vfprintf(ido2db_debug_file_fp, fmt, ap);
         va_end(ap);
-		if (buf) {
-        	fprintf(ido2db_debug_file_fp, "%s", buf);
-			my_free(buf);
-		}
 
         /* flush, so we don't have problems tailing or when fork()ing */
         fflush(ido2db_debug_file_fp);
@@ -137,6 +174,8 @@ int ido2db_log_debug_info(int level, int verbosity, const char *fmt, ...) {
                 ido2db_open_debug_log();
         }
 
+	pthread_mutex_unlock(&ido2db_debug_fp_lock);
+
         return IDO_OK;
 }
 





More information about the icinga-checkins mailing list