[asterisk-commits] mjordan: branch 1.8 r375893 - in /branches/1.8: bridges/ channels/ include/as...

SVN commits to the Asterisk project asterisk-commits at lists.digium.com
Mon Nov 5 16:50:28 CST 2012


Author: mjordan
Date: Mon Nov  5 16:50:21 2012
New Revision: 375893

URL: http://svnview.digium.com/svn/asterisk?view=rev&rev=375893
Log:
Refactor ast_timer_ack to return an error and handle the error in timer users

Currently, if an acknowledgement of a timer fails Asterisk will not realize
that a serious error occurred and will continue attempting to use the timer's
file descriptor.  This can lead to situations where errors stream to the
CLI/log file.  This consumes significant resources, masks the actual problem
that occurred (whatever caused the timer to fail in the first place), and
can leave channels in odd states.

This patch propagates the errors in the timing resource modules up through
the timer core, and makes users of these timers handle acknowledgement
failures.  It also adds some defensive coding around the use of timers
to prevent using bad file descriptors in off nominal code paths.

Note that the patch created by the issue reporter was modified slightly for
this commit and backported to 1.8, as it was originally written for
Asterisk 10.

(issue ASTERISK-20032)
Reported by: Jeremiah Gowdy
patches:
  jgowdy-timerfd-6-22-2012.diff uploaded by Jeremiah Gowdy (license 6358)



Modified:
    branches/1.8/bridges/bridge_softmix.c
    branches/1.8/channels/chan_iax2.c
    branches/1.8/include/asterisk/timing.h
    branches/1.8/main/channel.c
    branches/1.8/main/timing.c
    branches/1.8/res/res_fax_spandsp.c
    branches/1.8/res/res_musiconhold.c
    branches/1.8/res/res_timing_dahdi.c
    branches/1.8/res/res_timing_kqueue.c
    branches/1.8/res/res_timing_pthread.c
    branches/1.8/res/res_timing_timerfd.c

Modified: branches/1.8/bridges/bridge_softmix.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/bridges/bridge_softmix.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/bridges/bridge_softmix.c (original)
+++ branches/1.8/bridges/bridge_softmix.c Mon Nov  5 16:50:21 2012
@@ -107,7 +107,7 @@
 		return -1;
 	}
 	ast_timer_close((struct ast_timer *) bridge->bridge_pvt);
-
+	bridge->bridge_pvt = NULL;
 	return 0;
 }
 
@@ -274,7 +274,11 @@
 		/* Wait for the timing source to tell us to wake up and get things done */
 		ast_waitfor_n_fd(&timingfd, 1, &timeout, NULL);
 
-		ast_timer_ack(timer, 1);
+		if (ast_timer_ack(timer, 1) < 0) {
+			ast_log(LOG_ERROR, "Failed to acknowledge timer in softmix bridge\n");
+			ao2_lock(bridge);
+			break;
+		}
 
 		ao2_lock(bridge);
 	}

Modified: branches/1.8/channels/chan_iax2.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/channels/chan_iax2.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/channels/chan_iax2.c (original)
+++ branches/1.8/channels/chan_iax2.c Mon Nov  5 16:50:21 2012
@@ -9168,8 +9168,11 @@
 	if (iaxtrunkdebug)
 		ast_verbose("Beginning trunk processing. Trunk queue ceiling is %d bytes per host\n", trunkmaxsize);
 
-	if (timer) { 
-		ast_timer_ack(timer, 1);
+	if (timer) {
+		if (ast_timer_ack(timer, 1) < 0) {
+			ast_log(LOG_ERROR, "Timer failed acknowledge\n");
+			return 0;
+		}
 	}
 
 	/* For each peer that supports trunking... */
@@ -12194,7 +12197,9 @@
 		/* Wake up once a second just in case SIGURG was sent while
 		 * we weren't in poll(), to make sure we don't hang when trying
 		 * to unload. */
-		ast_io_wait(io, 1000);
+		if (ast_io_wait(io, 1000) <= 0) {
+			break;
+		}
 	}
 
 	return NULL;
@@ -14405,6 +14410,7 @@
 	ao2_ref(callno_pool_trunk, -1);
 	if (timer) {
 		ast_timer_close(timer);
+		timer = NULL;
 	}
 	transmit_processor = ast_taskprocessor_unreference(transmit_processor);
 	sched = ast_sched_thread_destroy(sched);
@@ -14764,6 +14770,7 @@
 	if (set_config(config, 0) == -1) {
 		if (timer) {
 			ast_timer_close(timer);
+			timer = NULL;
 		}
 		return AST_MODULE_LOAD_DECLINE;
 	}

Modified: branches/1.8/include/asterisk/timing.h
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/include/asterisk/timing.h?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/include/asterisk/timing.h (original)
+++ branches/1.8/include/asterisk/timing.h Mon Nov  5 16:50:21 2012
@@ -74,7 +74,7 @@
 	int (*timer_open)(void);
 	void (*timer_close)(int handle);
 	int (*timer_set_rate)(int handle, unsigned int rate);
-	void (*timer_ack)(int handle, unsigned int quantity);
+	int (*timer_ack)(int handle, unsigned int quantity);
 	int (*timer_enable_continuous)(int handle);
 	int (*timer_disable_continuous)(int handle);
 	enum ast_timer_event (*timer_get_event)(int handle);
@@ -163,10 +163,11 @@
  * \note This function should only be called if timer_get_event()
  *       returned AST_TIMING_EVENT_EXPIRED.
  *
- * \return nothing
- * \since 1.6.1
- */
-void ast_timer_ack(const struct ast_timer *handle, unsigned int quantity);
+ * \retval -1 failure, with errno set
+ * \retval 0 success
+ * \since 10.5.2
+ */
+int ast_timer_ack(const struct ast_timer *handle, unsigned int quantity);
 
 /*!
  * \brief Enable continuous mode

Modified: branches/1.8/main/channel.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/main/channel.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/main/channel.c (original)
+++ branches/1.8/main/channel.c Mon Nov  5 16:50:21 2012
@@ -2469,6 +2469,7 @@
 		close(fd);
 	if (chan->timer) {
 		ast_timer_close(chan->timer);
+		chan->timer = NULL;
 	}
 #ifdef HAVE_EPOLL
 	for (i = 0; i < AST_MAX_FDS; i++) {
@@ -3854,7 +3855,10 @@
 
 		switch (res) {
 		case AST_TIMING_EVENT_EXPIRED:
-			ast_timer_ack(chan->timer, 1);
+			if (ast_timer_ack(chan->timer, 1) < 0) {
+				ast_log(LOG_ERROR, "Failed to acknoweldge timer in ast_read\n");
+				goto done;
+			}
 
 			if (chan->timingfunc) {
 				/* save a copy of func/data before unlocking the channel */

Modified: branches/1.8/main/timing.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/main/timing.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/main/timing.c (original)
+++ branches/1.8/main/timing.c Mon Nov  5 16:50:21 2012
@@ -150,6 +150,7 @@
 void ast_timer_close(struct ast_timer *handle)
 {
 	handle->holder->iface->timer_close(handle->fd);
+	handle->fd = -1;
 	ast_module_unref(handle->holder->mod);
 	ast_free(handle);
 }
@@ -168,9 +169,13 @@
 	return res;
 }
 
-void ast_timer_ack(const struct ast_timer *handle, unsigned int quantity)
-{
-	handle->holder->iface->timer_ack(handle->fd, quantity);
+int ast_timer_ack(const struct ast_timer *handle, unsigned int quantity)
+{
+	int res = -1;
+
+	res = handle->holder->iface->timer_ack(handle->fd, quantity);
+
+	return res;
 }
 
 int ast_timer_enable_continuous(const struct ast_timer *handle)
@@ -269,7 +274,11 @@
 
 		if (res == 1) {
 			count++;
-			ast_timer_ack(timer, 1);
+			if (ast_timer_ack(timer, 1) < 0) {
+				ast_cli(a->fd, "Timer failed to acknowledge.\n");
+				ast_timer_close(timer);
+				return CLI_FAILURE;
+			}
 		} else if (!res) {
 			ast_cli(a->fd, "poll() timed out!  This is bad.\n");
 		} else if (errno != EAGAIN && errno != EINTR) {
@@ -278,6 +287,7 @@
 	}
 
 	ast_timer_close(timer);
+	timer = NULL;
 
 	ast_cli(a->fd, "It has been %" PRIi64 " milliseconds, and we got %d timer ticks\n", 
 		ast_tvdiff_ms(end, start), count);

Modified: branches/1.8/res/res_fax_spandsp.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/res/res_fax_spandsp.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/res/res_fax_spandsp.c (original)
+++ branches/1.8/res/res_fax_spandsp.c Mon Nov  5 16:50:21 2012
@@ -146,7 +146,7 @@
 	p->isdone = 1;
 
 	ast_timer_close(p->timer);
-
+	p->timer = NULL;
 	fax_release(&p->fax_state);
 	t38_terminal_release(&p->t38_state);
 
@@ -525,7 +525,10 @@
 
 	struct ast_frame *f = &fax_frame;
 
-	ast_timer_ack(p->timer, 1);
+	if (ast_timer_ack(p->timer, 1) < 0) {
+		ast_log(LOG_ERROR, "Failed to acknowledge timer for FAX session '%d'\n", s->id);
+		return NULL;
+	}
 
 	/* XXX do we need to lock here? */
 	if (p->isdone) {

Modified: branches/1.8/res/res_musiconhold.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/res/res_musiconhold.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/res/res_musiconhold.c (original)
+++ branches/1.8/res/res_musiconhold.c Mon Nov  5 16:50:21 2012
@@ -653,7 +653,10 @@
 #endif
 			/* Pause some amount of time */
 			if (ast_poll(&pfd, 1, -1) > 0) {
-				ast_timer_ack(class->timer, 1);
+				if (ast_timer_ack(class->timer, 1) < 0) {
+					ast_log(LOG_ERROR, "Failed to acknowledge timer for mp3player\n");
+					return NULL;
+				}
 				res = 320;
 			} else {
 				ast_log(LOG_WARNING, "poll() failed: %s\n", strerror(errno));

Modified: branches/1.8/res/res_timing_dahdi.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/res/res_timing_dahdi.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/res/res_timing_dahdi.c (original)
+++ branches/1.8/res/res_timing_dahdi.c Mon Nov  5 16:50:21 2012
@@ -48,7 +48,7 @@
 static int dahdi_timer_open(void);
 static void dahdi_timer_close(int handle);
 static int dahdi_timer_set_rate(int handle, unsigned int rate);
-static void dahdi_timer_ack(int handle, unsigned int quantity);
+static int dahdi_timer_ack(int handle, unsigned int quantity);
 static int dahdi_timer_enable_continuous(int handle);
 static int dahdi_timer_disable_continuous(int handle);
 static enum ast_timer_event dahdi_timer_get_event(int handle);
@@ -94,9 +94,9 @@
 	return 0;
 }
 
-static void dahdi_timer_ack(int handle, unsigned int quantity)
-{
-	ioctl(handle, DAHDI_TIMERACK, &quantity);
+static int dahdi_timer_ack(int handle, unsigned int quantity)
+{
+	return ioctl(handle, DAHDI_TIMERACK, &quantity) ? -1 : 0;
 }
 
 static int dahdi_timer_enable_continuous(int handle)

Modified: branches/1.8/res/res_timing_kqueue.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/res/res_timing_kqueue.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/res/res_timing_kqueue.c (original)
+++ branches/1.8/res/res_timing_kqueue.c Mon Nov  5 16:50:21 2012
@@ -49,7 +49,7 @@
 static int kqueue_timer_open(void);
 static void kqueue_timer_close(int handle);
 static int kqueue_timer_set_rate(int handle, unsigned int rate);
-static void kqueue_timer_ack(int handle, unsigned int quantity);
+static int kqueue_timer_ack(int handle, unsigned int quantity);
 static int kqueue_timer_enable_continuous(int handle);
 static int kqueue_timer_disable_continuous(int handle);
 static enum ast_timer_event kqueue_timer_get_event(int handle);
@@ -195,20 +195,25 @@
 	return 0;
 }
 
-static void kqueue_timer_ack(int handle, unsigned int quantity)
-{
-	struct kqueue_timer *our_timer;
-
-	if (!(our_timer = lookup_timer(handle))) {
-		return;
+static int kqueue_timer_ack(int handle, unsigned int quantity)
+{
+	struct kqueue_timer *our_timer;
+
+	if (!(our_timer = lookup_timer(handle))) {
+		return -1;
 	}
 
 	if (our_timer->unacked < quantity) {
 		ast_debug(1, "Acking more events than have expired?!!\n");
 		our_timer->unacked = 0;
+		ao2_ref(our_timer, -1);
+		return -1;
 	} else {
 		our_timer->unacked -= quantity;
 	}
+
+	ao2_ref(our_timer, -1);
+	return 0;
 }
 
 static int kqueue_timer_enable_continuous(int handle)

Modified: branches/1.8/res/res_timing_pthread.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/res/res_timing_pthread.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/res/res_timing_pthread.c (original)
+++ branches/1.8/res/res_timing_pthread.c Mon Nov  5 16:50:21 2012
@@ -47,7 +47,7 @@
 static int pthread_timer_open(void);
 static void pthread_timer_close(int handle);
 static int pthread_timer_set_rate(int handle, unsigned int rate);
-static void pthread_timer_ack(int handle, unsigned int quantity);
+static int pthread_timer_ack(int handle, unsigned int quantity);
 static int pthread_timer_enable_continuous(int handle);
 static int pthread_timer_disable_continuous(int handle);
 static enum ast_timer_event pthread_timer_get_event(int handle);
@@ -97,7 +97,7 @@
 static void pthread_timer_destructor(void *obj);
 static struct pthread_timer *find_timer(int handle, int unlinkobj);
 static void write_byte(struct pthread_timer *timer);
-static void read_pipe(struct pthread_timer *timer, unsigned int num);
+static int read_pipe(struct pthread_timer *timer, unsigned int num);
 
 /*!
  * \brief Data for the timing thread
@@ -190,21 +190,24 @@
 	return 0;
 }
 
-static void pthread_timer_ack(int handle, unsigned int quantity)
-{
-	struct pthread_timer *timer;
+static int pthread_timer_ack(int handle, unsigned int quantity)
+{
+	struct pthread_timer *timer;
+	int res;
 
 	ast_assert(quantity > 0);
 
 	if (!(timer = find_timer(handle, 0))) {
-		return;
+		return -1;
 	}
 
 	ao2_lock(timer);
-	read_pipe(timer, quantity);
+	res = read_pipe(timer, quantity);
 	ao2_unlock(timer);
 
 	ao2_ref(timer, -1);
+
+	return res;
 }
 
 static int pthread_timer_enable_continuous(int handle)
@@ -240,7 +243,12 @@
 	ao2_lock(timer);
 	if (timer->continuous) {
 		timer->continuous = 0;
-		read_pipe(timer, 1);
+		if (read_pipe(timer, 1) != 0) {
+			/* Let the errno from read_pipe propagate up */
+			ao2_unlock(timer);
+			ao2_ref(timer, -1);
+			return -1;
+		}
 	}
 	ao2_unlock(timer);
 
@@ -358,8 +366,10 @@
 /*!
  * \internal
  * \pre timer is locked
- */
-static void read_pipe(struct pthread_timer *timer, unsigned int quantity)
+ * \retval 0 if nothing to read or read success
+ * \retval -1 on error
+ */
+static int read_pipe(struct pthread_timer *timer, unsigned int quantity)
 {
 	int rd_fd = timer->pipe[PIPE_READ];
 	int pending_ticks = timer->pending_ticks;
@@ -375,7 +385,7 @@
 	}
 
 	if (!quantity) {
-		return;
+		return 0;
 	}
 
 	do {
@@ -389,7 +399,7 @@
 		if (ast_poll(&pfd, 1, 0) != 1) {
 			ast_debug(1, "Reading not available on timing pipe, "
 					"quantity: %u\n", quantity);
-			break;
+			return -1;
 		}
 
 		res = read(rd_fd, buf,
@@ -401,12 +411,14 @@
 			}
 			ast_log(LOG_ERROR, "read failed on timing pipe: %s\n",
 					strerror(errno));
-			break;
+			return -1;
 		}
 
 		quantity -= res;
 		timer->pending_ticks -= res;
 	} while (quantity);
+
+	return 0;
 }
 
 /*!

Modified: branches/1.8/res/res_timing_timerfd.c
URL: http://svnview.digium.com/svn/asterisk/branches/1.8/res/res_timing_timerfd.c?view=diff&rev=375893&r1=375892&r2=375893
==============================================================================
--- branches/1.8/res/res_timing_timerfd.c (original)
+++ branches/1.8/res/res_timing_timerfd.c Mon Nov  5 16:50:21 2012
@@ -44,7 +44,7 @@
 static int timerfd_timer_open(void);
 static void timerfd_timer_close(int handle);
 static int timerfd_timer_set_rate(int handle, unsigned int rate);
-static void timerfd_timer_ack(int handle, unsigned int quantity);
+static int timerfd_timer_ack(int handle, unsigned int quantity);
 static int timerfd_timer_enable_continuous(int handle);
 static int timerfd_timer_disable_continuous(int handle);
 static enum ast_timer_event timerfd_timer_get_event(int handle);
@@ -91,6 +91,7 @@
 {
 	struct timerfd_timer *timer = obj;
 	close(timer->handle);
+	timer->handle = -1;
 }
 
 static int timerfd_timer_open(void)
@@ -121,11 +122,16 @@
 		.handle = handle,
 	};
 
-	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
-		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
+	if (handle == -1) {
+		ast_log(LOG_ERROR, "Attempting to close timerfd handle -1");
 		return;
 	}
 
+	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
+		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
+		return;
+	}
+
 	ao2_unlink(timerfd_timers, our_timer);
 	ao2_ref(our_timer, -1);
 }
@@ -136,6 +142,11 @@
 		.handle = handle,
 	};
 	int res = 0;
+
+	if (handle == -1) {
+		ast_log(LOG_ERROR, "Attempting to set rate on timerfd handle -1");
+		return -1;
+	}
 
 	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
 		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
@@ -158,17 +169,23 @@
 	return res;
 }
 
-static void timerfd_timer_ack(int handle, unsigned int quantity)
+static int timerfd_timer_ack(int handle, unsigned int quantity)
 {
 	uint64_t expirations;
 	int read_result = 0;
-	struct timerfd_timer *our_timer, find_helper = {
-		.handle = handle,
-	};
+	int res = 0;
+	struct timerfd_timer *our_timer, find_helper = {
+		.handle = handle,
+	};
+
+	if (handle == -1) {
+		ast_log(LOG_ERROR, "Attempting to ack timerfd handle -1");
+		return -1;
+	}
 
 	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
 		ast_log(LOG_ERROR, "Couldn't find a timer with handle %d\n", handle);
-		return;
+		return -1;
 	}
 
 	ao2_lock(our_timer);
@@ -177,8 +194,9 @@
 		struct itimerspec timer_status;
 
 		if (timerfd_gettime(handle, &timer_status)) {
-			ast_log(LOG_ERROR, "Call to timerfd_gettime() error: %s\n", strerror(errno));
+			ast_log(LOG_ERROR, "Call to timerfd_gettime() using handle %d error: %s\n", handle, strerror(errno));
 			expirations = 0;
+			res = -1;
 			break;
 		}
 
@@ -194,6 +212,7 @@
 				continue;
 			} else {
 				ast_log(LOG_ERROR, "Read error: %s\n", strerror(errno));
+				res = -1;
 				break;
 			}
 		}
@@ -205,6 +224,7 @@
 	if (expirations != quantity) {
 		ast_debug(2, "Expected to acknowledge %u ticks but got %llu instead\n", quantity, (unsigned long long) expirations);
 	}
+	return res;
 }
 
 static int timerfd_timer_enable_continuous(int handle)
@@ -216,6 +236,11 @@
 	struct timerfd_timer *our_timer, find_helper = {
 		.handle = handle,
 	};
+
+	if (handle == -1) {
+		ast_log(LOG_ERROR, "Attempting to enable timerfd handle -1");
+		return -1;
+	}
 
 	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
 		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
@@ -246,13 +271,18 @@
 		.handle = handle,
 	};
 
-	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
-		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
-		return -1;
-	}
-	ao2_lock(our_timer);
-
-	if(!our_timer->is_continuous) {
+	if (handle == -1) {
+		ast_log(LOG_ERROR, "Attempting to disable timerfd handle -1");
+		return -1;
+	}
+
+	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
+		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
+		return -1;
+	}
+	ao2_lock(our_timer);
+
+	if (!our_timer->is_continuous) {
 		/* No reason to do anything if we're not
 		 * in continuous mode
 		 */
@@ -276,6 +306,11 @@
 		.handle = handle,
 	};
 
+	if (handle == -1) {
+		ast_log(LOG_ERROR, "Attempting to get event from timerfd handle -1");
+		return -1;
+	}
+
 	if (!(our_timer = ao2_find(timerfd_timers, &find_helper, OBJ_POINTER))) {
 		ast_log(LOG_ERROR, "Couldn't find timer with handle %d\n", handle);
 		return -1;




More information about the asterisk-commits mailing list