aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorNeels Hofmeyr <neels@hofmeyr.de>2018-05-31 15:30:15 +0200
committerNeels Hofmeyr <neels@hofmeyr.de>2018-08-28 21:42:54 +0200
commitd52fc24a967fede1d33894cd6d4ed9155c2d5960 (patch)
tree3fd1383efbff9f66b9c9ad86f8a17c2e4bcfa0bd
parent43c266f6c6419e97d8097cb656d1aee4e3eeebea (diff)
log: fsm: log timeout on state change
To not break the osmo-msc test expectations, this needs to be merged at the same time as osmo-msc I621fa6ce2485149750e2062abca63d66c417998b. Change-Id: I089b81021a1a4ada1205261470da032b82d57872
-rw-r--r--src/fsm.c15
-rw-r--r--tests/fsm/fsm_test.err12
2 files changed, 19 insertions, 8 deletions
diff --git a/src/fsm.c b/src/fsm.c
index b5af2e7..ac53bca 100644
--- a/src/fsm.c
+++ b/src/fsm.c
@@ -436,6 +436,7 @@ static int state_chg(struct osmo_fsm_inst *fi, uint32_t new_state,
struct osmo_fsm *fsm = fi->fsm;
uint32_t old_state = fi->state;
const struct osmo_fsm_state *st = &fsm->states[fi->state];
+ struct timeval remaining;
/* validate if new_state is a valid state */
if (!(st->out_state_mask & (1 << new_state))) {
@@ -453,8 +454,18 @@ static int state_chg(struct osmo_fsm_inst *fi, uint32_t new_state,
if (st->onleave)
st->onleave(fi, new_state);
- LOGPFSMSRC(fi, file, line, "state_chg to %s\n",
- osmo_fsm_state_name(fsm, new_state));
+ if (keep_timer && fi->timer.active && (osmo_timer_remaining(&fi->timer, NULL, &remaining) == 0))
+ LOGPFSMSRC(fi, file, line, "State change to %s (keeping T%d, %ld.%03lds remaining)\n",
+ osmo_fsm_state_name(fsm, new_state),
+ fi->T, remaining.tv_sec, remaining.tv_usec / 1000);
+ else if (timeout_secs && !keep_timer)
+ LOGPFSMSRC(fi, file, line, "State change to %s (T%d, %lus)\n",
+ osmo_fsm_state_name(fsm, new_state),
+ T, timeout_secs);
+ else
+ LOGPFSMSRC(fi, file, line, "State change to %s (no timeout)\n",
+ osmo_fsm_state_name(fsm, new_state));
+
fi->state = new_state;
st = &fsm->states[new_state];
diff --git a/tests/fsm/fsm_test.err b/tests/fsm/fsm_test.err
index 85606e2..6283d86 100644
--- a/tests/fsm/fsm_test.err
+++ b/tests/fsm/fsm_test.err
@@ -3,9 +3,9 @@ Checking FSM allocation
Test_FSM(my_id){NULL}: Received Event EV_B
Test_FSM(my_id){NULL}: Event EV_B not permitted
Test_FSM(my_id){NULL}: Received Event EV_A
-Test_FSM(my_id){NULL}: state_chg to ONE
+Test_FSM(my_id){NULL}: State change to ONE (no timeout)
Test_FSM(my_id){ONE}: Received Event EV_B
-Test_FSM(my_id){ONE}: state_chg to TWO
+Test_FSM(my_id){ONE}: State change to TWO (T2342, 1s)
Test_FSM(my_id){TWO}: Timeout of T2342
Timer
Test_FSM(my_id){TWO}: Deallocated
@@ -83,16 +83,16 @@ Test_FSM(arbitrary_id){NULL}: Terminating (cause = OSMO_FSM_TERM_REQUEST)

--- test_state_chg_keep_timer()
Test_FSM{NULL}: Allocated
-Test_FSM{NULL}: state_chg to ONE
-Test_FSM{ONE}: state_chg to TWO
+Test_FSM{NULL}: State change to ONE (no timeout)
+Test_FSM{ONE}: State change to TWO (no timeout)
Test_FSM{TWO}: Terminating (cause = OSMO_FSM_TERM_REQUEST)
Test_FSM{TWO}: Freeing instance
Test_FSM{TWO}: Deallocated
Total time passed: 0.000000 s
Test_FSM{NULL}: Allocated
-Test_FSM{NULL}: state_chg to ONE
+Test_FSM{NULL}: State change to ONE (T10, 10s)
Total time passed: 2.000342 s
-Test_FSM{ONE}: state_chg to TWO
+Test_FSM{ONE}: State change to TWO (keeping T10, 7.999s remaining)
Total time passed: 2.000342 s
Total time passed: 9.999999 s
Total time passed: 10.000000 s