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.

Review: https://reviewboard.asterisk.org/r/2178/

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

Merged revisions 375893 from http://svn.asterisk.org/svn/asterisk/branches/1.8
........

Merged revisions 375894 from http://svn.asterisk.org/svn/asterisk/branches/10
........

Merged revisions 375895 from http://svn.asterisk.org/svn/asterisk/branches/11


git-svn-id: https://origsvn.digium.com/svn/asterisk/trunk@375896 65c4cc65-6c06-0410-ace0-fbb531ad65f3

bridges/bridge_softmix.c

@@ -300,6 +300,7 @@ static void softmix_bridge_data_destroy(void *obj)
 
 	if (softmix_data->timer) {
 		ast_timer_close(softmix_data->timer);
+		softmix_data->timer = NULL;
 	}
 }
 
@@ -885,7 +886,11 @@ static int softmix_bridge_thread(struct ast_bridge *bridge)
 		softmix_translate_helper_cleanup(&trans_helper);
 		/* 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);
+			goto softmix_cleanup;
+		}
 		ao2_lock(bridge);
 
 		/* make sure to detect mixing interval changes if they occur. */

channels/chan_iax2.c

@@ -9254,7 +9254,10 @@ static int timing_read(int *id, int fd, short events, void *cbdata)
 		ast_verbose("Beginning trunk processing. Trunk queue ceiling is %d bytes per host\n", trunkmaxsize);
 
 	if (timer) {
-		ast_timer_ack(timer, 1);
+		if (ast_timer_ack(timer, 1) < 0) {
+			ast_log(LOG_ERROR, "Timer failed acknowledge\n");
+			return 0;
+		}
 	}
 
 	/* For each peer that supports trunking... */
@@ -12372,7 +12375,9 @@ static void *network_thread(void *ignore)
 		/* 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;
@@ -14591,6 +14596,7 @@ static int __unload_module(void)
 	ao2_ref(callno_pool_trunk, -1);
 	if (timer) {
 		ast_timer_close(timer);
+		timer = NULL;
 	}
 	transmit_processor = ast_taskprocessor_unreference(transmit_processor);
 	ast_sched_context_destroy(sched);
@@ -14976,6 +14982,7 @@ static int load_module(void)
 	if (set_config(config, 0, 0) == -1) {
 		if (timer) {
 			ast_timer_close(timer);
+			timer = NULL;
 		}
 		return AST_MODULE_LOAD_DECLINE;
 	}

funcs/func_jitterbuffer.c

@@ -219,7 +219,10 @@ static struct ast_frame *hook_event_cb(struct ast_channel *chan, struct ast_fram
 	}
 
 	if (ast_channel_fdno(chan) == AST_JITTERBUFFER_FD && framedata->timer) {
-		ast_timer_ack(framedata->timer, 1);
+		if (ast_timer_ack(framedata->timer, 1) < 0) {
+			ast_log(LOG_ERROR, "Failed to acknowledge timer in jitter buffer\n");
+			return frame;
+		}
 	}
 
 	if (!frame) {

include/asterisk/timing.h

@@ -74,7 +74,7 @@ struct ast_timing_interface {
 	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 @@ int ast_timer_set_rate(const struct ast_timer *handle, unsigned int rate);
  * \note This function should only be called if timer_get_event()
  *       returned AST_TIMING_EVENT_EXPIRED.
  *
- * \return nothing
+ * \retval -1 failure, with errno set
- * \since 1.6.1
+ * \retval 0 success
+ * \since 10.5.2
  */
-void ast_timer_ack(const struct ast_timer *handle, unsigned int quantity);
+int ast_timer_ack(const struct ast_timer *handle, unsigned int quantity);
 
 /*!
  * \brief Enable continuous mode

main/channel.c

@@ -2431,6 +2431,7 @@ static void ast_channel_destructor(void *obj)
 	ast_channel_internal_alertpipe_close(chan);
 	if (ast_channel_timer(chan)) {
 		ast_timer_close(ast_channel_timer(chan));
+		ast_channel_timer_set(chan, NULL);
 	}
 #ifdef HAVE_EPOLL
 	for (i = 0; i < AST_MAX_FDS; i++) {
@@ -3940,7 +3941,10 @@ static struct ast_frame *__ast_read(struct ast_channel *chan, int dropaudio)
 
 		switch (res) {
 		case AST_TIMING_EVENT_EXPIRED:
-			ast_timer_ack(ast_channel_timer(chan), 1);
+			if (ast_timer_ack(ast_channel_timer(chan), 1) < 0) {
+				ast_log(LOG_ERROR, "Failed to acknoweldge timer in ast_read\n");
+				goto done;
+			}
 
 			if (ast_channel_timingfunc(chan)) {
 				/* save a copy of func/data before unlocking the channel */

main/timing.c

@@ -150,6 +150,7 @@ struct ast_timer *ast_timer_open(void)
 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 @@ int ast_timer_set_rate(const struct ast_timer *handle, unsigned int rate)
 	return res;
 }
 
-void ast_timer_ack(const struct ast_timer *handle, unsigned int quantity)
+int ast_timer_ack(const struct ast_timer *handle, unsigned int quantity)
 {
-	handle->holder->iface->timer_ack(handle->fd, 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 @@ static char *timing_test(struct ast_cli_entry *e, int cmd, struct ast_cli_args *
 
 		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 @@ static char *timing_test(struct ast_cli_entry *e, int cmd, struct ast_cli_args *
 	}
 
 	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);

res/res_fax_spandsp.c

@@ -181,7 +181,7 @@ static void session_destroy(struct spandsp_pvt *p)
 	p->isdone = 1;
 
 	ast_timer_close(p->timer);
-
+	p->timer = NULL;
 	fax_release(&p->fax_state);
 	t38_terminal_release(&p->t38_state);
 
@@ -611,7 +611,10 @@ static struct ast_frame *spandsp_fax_read(struct ast_fax_session *s)
 	struct ast_frame *f = &fax_frame;
 	ast_format_set(&fax_frame.subclass.format, AST_FORMAT_SLINEAR, 0);
 
-	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) {

res/res_musiconhold.c

@@ -699,7 +699,10 @@ static void *monmp3thread(void *data)
 #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));

res/res_timing_dahdi.c

@@ -48,7 +48,7 @@ static void *timing_funcs_handle;
 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 @@ static int dahdi_timer_set_rate(int handle, unsigned int rate)
 	return 0;
 }
 
-static void dahdi_timer_ack(int handle, unsigned int quantity)
+static int dahdi_timer_ack(int handle, unsigned int quantity)
 {
-	ioctl(handle, DAHDI_TIMERACK, &quantity);
+	return ioctl(handle, DAHDI_TIMERACK, &quantity) ? -1 : 0;
 }
 
 static int dahdi_timer_enable_continuous(int handle)

res/res_timing_kqueue.c

@@ -51,7 +51,7 @@ static void *timing_funcs_handle;
 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);
@@ -197,20 +197,25 @@ static int kqueue_timer_set_rate(int handle, unsigned int rate)
 	return 0;
 }
 
-static void kqueue_timer_ack(int handle, unsigned int quantity)
+static int kqueue_timer_ack(int handle, unsigned int quantity)
 {
 	struct kqueue_timer *our_timer;
 
 	if (!(our_timer = lookup_timer(handle))) {
-		return;
+		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)

res/res_timing_pthread.c

@@ -47,7 +47,7 @@ static void *timing_funcs_handle;
 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 @@ struct pthread_timer {
 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 @@ static int pthread_timer_set_rate(int handle, unsigned int rate)
 	return 0;
 }
 
-static void pthread_timer_ack(int handle, unsigned int quantity)
+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 @@ static int pthread_timer_disable_continuous(int handle)
 	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 @@ static int check_timer(struct pthread_timer *timer)
 /*!
  * \internal
  * \pre timer is locked
+ * \retval 0 if nothing to read or read success
+ * \retval -1 on error
  */
-static void read_pipe(struct pthread_timer *timer, unsigned int quantity)
+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 @@ static void read_pipe(struct pthread_timer *timer, unsigned int quantity)
 	}
 
 	if (!quantity) {
-		return;
+		return 0;
 	}
 
 	do {
@@ -389,7 +399,7 @@ static void read_pipe(struct pthread_timer *timer, unsigned int quantity)
 		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 @@ static void read_pipe(struct pthread_timer *timer, unsigned int quantity)
 			}
 			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;
 }
 
 /*!

res/res_timing_timerfd.c

@@ -44,7 +44,7 @@ static void *timing_funcs_handle;
 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 @@ static void timer_destroy(void *obj)
 {
 	struct timerfd_timer *timer = obj;
 	close(timer->handle);
+	timer->handle = -1;
 }
 
 static int timerfd_timer_open(void)
@@ -121,6 +122,11 @@ static void timerfd_timer_close(int handle)
 		.handle = 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;
@@ -137,6 +143,11 @@ static int timerfd_timer_set_rate(int handle, unsigned int rate)
 	};
 	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);
 		return -1;
@@ -158,17 +169,23 @@ static int timerfd_timer_set_rate(int handle, unsigned int rate)
 	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;
+	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 @@ static void timerfd_timer_ack(int handle, unsigned int quantity)
 		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 @@ static void timerfd_timer_ack(int handle, unsigned int quantity)
 				continue;
 			} else {
 				ast_log(LOG_ERROR, "Read error: %s\n", strerror(errno));
+				res = -1;
 				break;
 			}
 		}
@@ -205,6 +224,7 @@ static void timerfd_timer_ack(int handle, unsigned int quantity)
 	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)
@@ -217,6 +237,11 @@ static int timerfd_timer_enable_continuous(int handle)
 		.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);
 		return -1;
@@ -246,13 +271,18 @@ static int timerfd_timer_disable_continuous(int handle)
 		.handle = handle,
 	};
 
+	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) {
+	if (!our_timer->is_continuous) {
 		/* No reason to do anything if we're not
 		 * in continuous mode
 		 */
@@ -276,6 +306,11 @@ static enum ast_timer_event timerfd_timer_get_event(int handle)
 		.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;