fsm: add unit tests verifying state timeout s/ms accuracy
This change adds test_state_chg_Ts() and test_state_chg_Tms() checking
state timeout s/ms accuracy when using osmo_fsm_inst_state_chg() and
osmo_fsm_inst_state_chg_ms() calls, respectively.
test_state_chg_Tms() demonstrates that osmo_fsm_inst_state_chg_ms()
is not working as expected: the timeout fires earlier than expected.
Change-Id: I5a35730a8448292b075aefafed897353678250f9
Related: OS#5622
diff --git a/tests/fsm/fsm_test.c b/tests/fsm/fsm_test.c
index 2cfdacd..ec31dd2 100644
--- a/tests/fsm/fsm_test.c
+++ b/tests/fsm/fsm_test.c
@@ -386,6 +386,76 @@
fprintf(stderr, "--- %s() done\n", __func__);
}
+/* Test setting a state timeout with second granularity */
+static void test_state_chg_Ts(void)
+{
+ struct osmo_fsm_inst *fi;
+
+ fprintf(stderr, "\n--- %s()\n", __func__);
+
+ fsm.timer_cb = &timer_cb;
+ timeout_fired = -1;
+ fake_time_start();
+
+ fi = osmo_fsm_inst_alloc(&fsm, g_ctx, NULL, LOGL_DEBUG, NULL);
+ OSMO_ASSERT(fi);
+
+ osmo_fsm_inst_state_chg(fi, ST_ONE, 8, 4242);
+ OSMO_ASSERT(timeout_fired == -1);
+
+ fake_time_passes(3, 0); /* +3s */
+ OSMO_ASSERT(timeout_fired == -1);
+
+ fake_time_passes(2, 500000); /* +2.5s */
+ OSMO_ASSERT(timeout_fired == -1);
+
+ fake_time_passes(2, 500000); /* +2.5s */
+ OSMO_ASSERT(timeout_fired == 4242);
+
+ osmo_fsm_inst_term(fi, OSMO_FSM_TERM_REQUEST, NULL);
+
+ fprintf(stderr, "--- %s() done\n", __func__);
+}
+
+/* Test setting a state timeout with millisecond granularity */
+static void test_state_chg_Tms(void)
+{
+ struct osmo_fsm_inst *fi;
+
+ fprintf(stderr, "\n--- %s()\n", __func__);
+
+ fsm.timer_cb = &timer_cb;
+ timeout_fired = -1;
+ fake_time_start();
+
+ fi = osmo_fsm_inst_alloc(&fsm, g_ctx, NULL, LOGL_DEBUG, NULL);
+ OSMO_ASSERT(fi);
+
+ osmo_fsm_inst_state_chg_ms(fi, ST_ONE, 1337, 4242); /* 1s 337ms */
+ OSMO_ASSERT(timeout_fired == -1);
+
+ fake_time_passes(0, 500000); /* +500ms, 500ms total */
+ OSMO_ASSERT(timeout_fired == -1);
+
+ fake_time_passes(0, 250000); /* +250ms, 750ms total */
+ OSMO_ASSERT(timeout_fired == -1);
+
+ fake_time_passes(0, 350000); /* +350ms, 1s 100ms total */
+ /* OSMO_ASSERT(timeout_fired == -1); */
+
+ /* FIXME: the timeout expires here, earlier than expected */
+
+ fake_time_passes(0, 200000); /* +200ms, 1s 300ms total */
+ /* OSMO_ASSERT(timeout_fired == -1); */
+
+ fake_time_passes(0, 37000); /* +37ms, 1s 337ms total */
+ /* OSMO_ASSERT(timeout_fired == 4242); */
+
+ osmo_fsm_inst_term(fi, OSMO_FSM_TERM_REQUEST, NULL);
+
+ fprintf(stderr, "--- %s() done\n", __func__);
+}
+
static const struct log_info_cat default_categories[] = {
[DMAIN] = {
.name = "DMAIN",
@@ -434,6 +504,8 @@
test_id_api();
test_state_chg_keep_timer();
test_state_chg_T();
+ test_state_chg_Ts();
+ test_state_chg_Tms();
osmo_fsm_unregister(&fsm);
exit(0);
diff --git a/tests/fsm/fsm_test.err b/tests/fsm/fsm_test.err
index 4cc5ca4..f140d2e 100644
--- a/tests/fsm/fsm_test.err
+++ b/tests/fsm/fsm_test.err
@@ -116,3 +116,31 @@
Test_FSM{TWO}: Freeing instance
Test_FSM{TWO}: Deallocated
--- test_state_chg_T() done
+
+--- test_state_chg_Ts()
+Total time passed: 0.000000 s
+Test_FSM{NULL}: Allocated
+Test_FSM{NULL}: State change to ONE (T4242, 8s)
+Total time passed: 3.000000 s
+Total time passed: 5.500000 s
+Total time passed: 8.000000 s
+Test_FSM{ONE}: Timeout of T4242
+Test_FSM{ONE}: Terminating (cause = OSMO_FSM_TERM_REQUEST)
+Test_FSM{ONE}: Freeing instance
+Test_FSM{ONE}: Deallocated
+--- test_state_chg_Ts() done
+
+--- test_state_chg_Tms()
+Total time passed: 0.000000 s
+Test_FSM{NULL}: Allocated
+Test_FSM{NULL}: State change to ONE (T4242, 1337ms)
+Total time passed: 0.500000 s
+Total time passed: 0.750000 s
+Total time passed: 1.100000 s
+Test_FSM{ONE}: Timeout of T4242
+Total time passed: 1.300000 s
+Total time passed: 1.337000 s
+Test_FSM{ONE}: Terminating (cause = OSMO_FSM_TERM_REQUEST)
+Test_FSM{ONE}: Freeing instance
+Test_FSM{ONE}: Deallocated
+--- test_state_chg_Tms() done