tdef_test: tweak output to prepare for a fix

- Always print the state after a state transition.
  This shows that actually state transitions are missing for states that have
  no timer defined. This is a bug in tdef_test.c, to be fixed subsequently.

- Instead of total time passed since start, print the individual fake time
  intervals. Omit initial useless zero fake time advance.

- Add two more state transitions, back out from and into a state that has no
  timeout set.

Change-Id: Icb31af96d37741e256ff07868f3d4f5c48cdda74

3 files changed, 24 insertions, 21 deletions

diff --git a/tests/tdef/tdef_test.c b/tests/tdef/tdef_test.c
index f5b6413c..fe2accfa 100644
--- a/tests/tdef/tdef_test.c
+++ b/tests/tdef/tdef_test.c
@@ -287,7 +287,7 @@ const struct timeval fake_time_start_time = { 123, 456 };
 	osmo_gettimeofday_override_add(secs, usecs); \
 	osmo_clock_override_add(CLOCK_MONOTONIC, secs, usecs * 1000); \
 	timersub(&osmo_gettimeofday_override_time, &fake_time_start_time, &diff); \
-	printf("Total time passed: %ld.%06ld s\n", diff.tv_sec, diff.tv_usec); \
+	printf("Time passes: %ld.%06ld s\n", (long)secs, (long)usecs); \
 	osmo_timers_prepare(); \
 	osmo_timers_update(); \
 } while (0)
@@ -303,7 +303,6 @@ void fake_time_start()
 	clock_override->tv_sec = fake_time_start_time.tv_sec;
 	clock_override->tv_nsec = fake_time_start_time.tv_usec * 1000;
 	osmo_clock_override_enable(CLOCK_MONOTONIC, true);
-	fake_time_passes(0, 0);
 }
 
 static void print_fsm_state(struct osmo_fsm_inst *fi)
@@ -325,18 +324,18 @@ static void print_fsm_state(struct osmo_fsm_inst *fi)
 		const struct osmo_tdef_state_timeout *st = osmo_tdef_get_state_timeout(NEXT_STATE, \
 										       test_tdef_state_timeouts); \
 		if (!st) { \
-			printf(" --> %s (no timer configured for this state)\n", \
+			printf(" --> %s (no timer configured for this state)\t", \
 			       osmo_fsm_state_name(&test_tdef_fsm, NEXT_STATE)); \
 		} else { \
 			struct osmo_tdef *t = osmo_tdef_get_entry(tdefs, st->T); \
 			int rc = osmo_tdef_fsm_inst_state_chg(fi, NEXT_STATE, test_tdef_state_timeouts, tdefs, 999); \
-			printf(" --> %s (configured as T%d%s %lu %s) rc=%d;\t", osmo_fsm_state_name(&test_tdef_fsm, \
-												    NEXT_STATE), \
+			printf(" --> %s (configured as T%d%s %lu %s) rc=%d;\t", \
+			       osmo_fsm_state_name(&test_tdef_fsm, NEXT_STATE), \
 			       st->T, st->keep_timer ? "(keep_timer)" : "", \
 			       t? t->val : 0, t? osmo_tdef_unit_name(t->unit) : "-", \
 			       rc); \
-			print_fsm_state(fi); \
 		} \
+		print_fsm_state(fi); \
 	} while(0)
 
 
@@ -378,6 +377,8 @@ static void test_tdef_state_timeout(bool test_range)
 	fake_time_passes(23, 45678);
 	print_fsm_state(fi);
 	test_tdef_fsm_state_chg(tdefs, S_L);
+	test_tdef_fsm_state_chg(tdefs, S_O);
+	test_tdef_fsm_state_chg(tdefs, S_L);
 
 	printf("- test T=0:\n");
 	test_tdef_fsm_state_chg(tdefs, S_O);
diff --git a/tests/tdef/tdef_test.ok b/tests/tdef/tdef_test.ok
index 6e6ba004..1acf0e60 100644
--- a/tests/tdef/tdef_test.ok
+++ b/tests/tdef/tdef_test.ok
@@ -110,7 +110,6 @@ T7=50s
 osmo_tdef_get(7, s)	= 50
 
 test_tdef_state_timeout()
-Total time passed: 0.000000 s
 state=A T=0, no timeout
  --> A (configured as T1 100 s) rc=0;	state=A T=1, 100.000000 s remaining
  --> B (configured as T2 100 ms) rc=0;	state=B T=2, 1.000000 s remaining
@@ -121,25 +120,27 @@ state=A T=0, no timeout
  --> I (configured as T9 5 m) rc=0;	state=I T=9, 300.000000 s remaining
  --> J (configured as T10 20 m) rc=0;	state=J T=10, 1200.000000 s remaining
 - test keep_timer:
-Total time passed: 123.045678 s
+Time passes: 123.045678 s
 state=J T=10, 1076.954322 s remaining
  --> K (configured as T0(keep_timer) 1 custom-unit) rc=0;	state=K T=10, 1076.954322 s remaining
  --> A (configured as T1 100 s) rc=0;	state=A T=1, 100.000000 s remaining
-Total time passed: 146.091356 s
+Time passes: 23.045678 s
 state=A T=1, 76.954322 s remaining
  --> K (configured as T0(keep_timer) 1 custom-unit) rc=0;	state=K T=1, 76.954322 s remaining
  --> A (configured as T1 100 s) rc=0;	state=A T=1, 100.000000 s remaining
-Total time passed: 169.137034 s
+Time passes: 23.045678 s
 state=A T=1, 76.954322 s remaining
  --> L (configured as T123(keep_timer) 1 s) rc=0;	state=L T=123, 76.954322 s remaining
+ --> O (no timer configured for this state)	state=L T=123, 76.954322 s remaining
+ --> L (configured as T123(keep_timer) 1 s) rc=0;	state=L T=123, 76.954322 s remaining
 - test T=0:
- --> O (no timer configured for this state)
+ --> O (no timer configured for this state)	state=L T=123, 76.954322 s remaining
 - test no timer:
- --> X (no timer configured for this state)
+ --> X (no timer configured for this state)	state=L T=123, 76.954322 s remaining
 - test undefined timer, using default_val arg of osmo_tdef_fsm_inst_state_chg(), here passed as 999:
  --> Y (configured as T666 0 -) rc=0;	state=Y T=666, 999.000000 s remaining
 - test disallowed transition:
- --> Z (no timer configured for this state)
+ --> Z (no timer configured for this state)	state=Y T=666, 999.000000 s remaining
  --> B (configured as T2 100 ms) rc=0;	state=B T=2, 1.000000 s remaining
  --> C (configured as T3 100 m) rc=0;	state=C T=3, 6000.000000 s remaining
  --> D (configured as T4 100 custom-unit) rc=0;	state=D T=4, 100.000000 s remaining
diff --git a/tests/tdef/tdef_test_range_64bit.ok b/tests/tdef/tdef_test_range_64bit.ok
index bd104b66..72ac466e 100644
--- a/tests/tdef/tdef_test_range_64bit.ok
+++ b/tests/tdef/tdef_test_range_64bit.ok
@@ -138,7 +138,6 @@ T7=50s
 osmo_tdef_get(7, s)	= 50
 
 test_tdef_state_timeout()
-Total time passed: 0.000000 s
 state=A T=0, no timeout
  --> A (configured as T1 100 s) rc=0;	state=A T=1, 100.000000 s remaining
  --> B (configured as T2 100 ms) rc=0;	state=B T=2, 1.000000 s remaining
@@ -149,23 +148,25 @@ state=A T=0, no timeout
  --> I (configured as T9 5 m) rc=0;	state=I T=9, 300.000000 s remaining
  --> J (configured as T10 20 m) rc=0;	state=J T=10, 1200.000000 s remaining
 - test keep_timer:
-Total time passed: 123.045678 s
+Time passes: 123.045678 s
 state=J T=10, 1076.954322 s remaining
  --> K (configured as T0(keep_timer) 1 custom-unit) rc=0;	state=K T=10, 1076.954322 s remaining
  --> A (configured as T1 100 s) rc=0;	state=A T=1, 100.000000 s remaining
-Total time passed: 146.091356 s
+Time passes: 23.045678 s
 state=A T=1, 76.954322 s remaining
  --> K (configured as T0(keep_timer) 1 custom-unit) rc=0;	state=K T=1, 76.954322 s remaining
  --> A (configured as T1 100 s) rc=0;	state=A T=1, 100.000000 s remaining
-Total time passed: 169.137034 s
+Time passes: 23.045678 s
 state=A T=1, 76.954322 s remaining
  --> L (configured as T123(keep_timer) 1 s) rc=0;	state=L T=123, 76.954322 s remaining
+ --> O (no timer configured for this state)	state=L T=123, 76.954322 s remaining
+ --> L (configured as T123(keep_timer) 1 s) rc=0;	state=L T=123, 76.954322 s remaining
 - test T=0:
- --> O (no timer configured for this state)
+ --> O (no timer configured for this state)	state=L T=123, 76.954322 s remaining
 - test no timer:
- --> X (no timer configured for this state)
+ --> X (no timer configured for this state)	state=L T=123, 76.954322 s remaining
 - test undefined timer, using default_val arg of osmo_tdef_fsm_inst_state_chg(), here passed as 999:
- --> Y (configured as T666 18446744073709551615 -) rc=0;	state=Y T=666, 999.000000 s remaining
+ --> Y (configured as T666 0 -) rc=0;	state=Y T=666, 999.000000 s remaining
 - test large T:
  --> M (configured as T2147483647 0 s) rc=0;	state=M T=2147483647, no timeout
 - test T<0:
@@ -369,7 +370,7 @@ state=A T=1, 76.954322 s remaining
  --> M (configured as T2147483647 18446744073709551615 s) rc=0;	state=M T=2147483647, 2147483647.000000 s remaining
  --> M (configured as T2147483647 0 s) rc=0;	state=M T=2147483647, no timeout
 - test disallowed transition:
- --> Z (no timer configured for this state)
+ --> Z (no timer configured for this state)	state=M T=2147483647, no timeout
  --> B (configured as T2 100 ms) rc=0;	state=B T=2, 1.000000 s remaining
  --> C (configured as T3 100 m) rc=0;	state=C T=3, 6000.000000 s remaining
  --> D (configured as T4 100 custom-unit) rc=0;	state=D T=4, 100.000000 s remaining