commit d0858c2ae9cdd065d09c3a58e60409b7af50111e
author Neels Hofmeyr <nhofmeyr@sysmocom.de> Thu Sep 22 04:50:13 2016 +0200
committer Neels Hofmeyr <nhofmeyr@sysmocom.de> Thu Sep 22 07:18:39 2016 +0200
tree b81c505382af2281f0de298a8a5a168997eca10e
parent 255dac16a4a69e29be62bcc692dabf9cd1a586b5

timer_test: print more details to stdout to check

The test is now fully deterministic, so include all detail in stdout, to check
for.

Change-Id: Iecf6387f1d25253fcf1260777673853030c1d326

tests/timer/timer_test.c

diff --git a/tests/timer/timer_test.c b/tests/timer/timer_test.c
index 12caecf..ec85c04 100644
--- a/tests/timer/timer_test.c
+++ b/tests/timer/timer_test.c
@@ -73,6 +73,7 @@
 	unsigned int *step = data;
 	unsigned int add_in_this_step;
 	int i;
+	printf("main_timer_fired()\n");
 
 	if (*step == timer_nsteps) {
 		printf("Main timer has finished, please, "
@@ -98,6 +99,8 @@
 		v->stop.tv_usec = v->start.tv_usec;
 		osmo_timer_schedule(&v->timer, seconds, 0);
 		llist_add(&v->head, &timer_test_list);
+		printf("scheduled timer at %d.%06d\n",
+		       (int)v->stop.tv_sec, (int)v->stop.tv_usec);
 	}
 	printf("added %d timers in step %u (expired=%u)\n",
 		add_in_this_step, *step, expired_timers);
@@ -111,7 +114,7 @@
 	struct test_timer *v = data, *this, *tmp;
 	struct timeval current, res;
 	struct timeval precision = { 0, TIME_BETWEEN_TIMER_CHECKS + 1};
-	int i;
+	int i, deleted;
 
 	osmo_gettimeofday(&current, NULL);
 
@@ -132,6 +135,10 @@
 		       (int)res.tv_sec, (int)res.tv_usec);
 		too_soon++;
 	}
+	else
+		printf("timer fired on time: %d.%06d (+ %d.%06d)\n",
+		       (int)v->stop.tv_sec, (int)v->stop.tv_usec,
+		       (int)res.tv_sec, (int)res.tv_usec);
 
 	llist_del(&v->head);
 	talloc_free(data);
@@ -144,15 +151,19 @@
 
 	/* "random" deletion of timers. */
 	i = 0;
+	deleted = 0;
 	llist_for_each_entry_safe(this, tmp, &timer_test_list, head) {
 		i ++;
 		if (!(i & 0x3)) {
 			osmo_timer_del(&this->timer);
 			llist_del(&this->head);
 			talloc_free(this);
-			expired_timers++;
+			deleted++;
 		}
 	}
+	expired_timers += deleted;
+	printf("early deleted %d timers, %d still active\n", deleted,
+	       total_timers - expired_timers);
 }
 
 int main(int argc, char *argv[])
@@ -180,12 +191,16 @@
 	steps = ((MAIN_TIMER_NSTEPS * TIME_BETWEEN_STEPS + 20) * 1e6)
 		/ TIME_BETWEEN_TIMER_CHECKS;
 
-	printf("Running timer test for %u steps\n", timer_nsteps);
+	printf("Running timer test for %d iterations,"
+	       " %d steps of %d msecs each\n",
+	       timer_nsteps, steps, TIME_BETWEEN_TIMER_CHECKS / 1000);
 
 	osmo_timer_schedule(&main_timer, 1, 0);
 
 #ifdef HAVE_SYS_SELECT_H
 	while (steps--) {
+		printf("%d.%06d\n", (int)osmo_gettimeofday_override_time.tv_sec,
+		       (int)osmo_gettimeofday_override_time.tv_usec);
 		osmo_timers_prepare();
 		osmo_timers_update();
 		osmo_gettimeofday_override_add(0, TIME_BETWEEN_TIMER_CHECKS);