Hi,
I've been hunting a problem with tw_timer expiring much too late (> 1s
later than expected).
As long as I call tw_timer_expire_timers_vec at roughly the interval I
specified on init, everything works fine.
But when I start using tw_timer_first_expires_in_ticks and sleep for
that time, a small number of timers fires excessively late.
I've written small test that simulates the time flow and function
calls to demonstrate the problem. Am I doing something wrong, is this
expected behaviour or is there a bug somewhere?
#define TW_SECS_PER_CLOCK 10e-3 /* 10ms */
#define TW_CLOCKS_PER_SECOND (1 / TW_SECS_PER_CLOCK)
typedef struct {
u32 period;
u32 handle;
u32 round;
f64 init;
f64 base;
f64 expected;
} upf_tt_t;
static upf_tt_t * upf_tt = NULL;
static TWT (tw_timer_wheel) upf_tt_timer;
static f64 min_late = 1.0;
static f64 max_late = 0.0;
static void
upf_test_timer_start (f64 now, upf_tt_t * t)
{
u32 interval;
now = upf_tt_timer.last_run_time;
++t->round;
t->expected = t->base + t->period;
interval = t->period * TW_CLOCKS_PER_SECOND -
floor ((now - t->base) * TW_CLOCKS_PER_SECOND);
interval = clib_max (interval, 1); /* make sure interval is at least 1 */
t->handle = TW (tw_timer_start) (&upf_tt_timer, t - upf_tt, 0, interval);
}
static f64
upf_test_timer_fn (vlib_main_t * vm, f64 now, int new)
{
u32 ticks_until_expiration;
u32 *expired = NULL;
upf_tt_t * t;
/* run the timing wheel first, to that the internal base for new and
updated timers
* is set to now */
expired = TW (tw_timer_expire_timers_vec) (&upf_tt_timer, now, expired);
if (new)
{
pool_get (upf_tt, t);
memset (t, 0, sizeof (*t));
t->period = 1800;
t->init = now;
t->base = now;
upf_test_timer_start (now, t);
}
for (int i = 0; i < vec_len (expired); i++)
{
f64 late;
t = pool_elt_at_index (upf_tt, expired[i]);
late = now - t->expected;
min_late = fmin(min_late, late);
max_late = fmax(max_late, late);
if (now < t->expected)
{
vlib_cli_output (vm, "Timer %8u @ %3u too early by %.53f secs\n",
expired[i], t->round, t->expected - now);
}
//else if (late > 0.05)
else if (late > 1)
{
vlib_cli_output (vm, "Timer %8u @ %3u too late by %.53f secs\n",
expired[i], t->round, late);
}
t->base += t->period;
upf_test_timer_start (now, t);
}
vec_reset_length (expired);
ticks_until_expiration =
TW (tw_timer_first_expires_in_ticks) (&upf_tt_timer);
/* min 1 tick wait */
ticks_until_expiration = clib_max (ticks_until_expiration, 1);
/* sleep max 1s */
ticks_until_expiration =
clib_min (ticks_until_expiration, TW_CLOCKS_PER_SECOND);
return (f64) ticks_until_expiration * TW_SECS_PER_CLOCK;
}
static clib_error_t *
upf_test_timer_command_fn (vlib_main_t * vm,
unformat_input_t * main_input,
vlib_cli_command_t * cmd)
{
unformat_input_t _line_input, *line_input = &_line_input;
f64 timer_interval = TW_SECS_PER_CLOCK;
f64 now = unix_time_now ();
clib_error_t *error = NULL;
f64 scale = 1.0;
f64 base = 0.5;
f64 next;
u32 i;
if (unformat_user (main_input, unformat_line_input, line_input))
{
while (unformat_check_input (line_input) != UNFORMAT_END_OF_INPUT)
{
if (unformat (line_input, "base %f", &base))
;
else if (unformat (line_input, "scale %f", &scale))
;
else
{
error = unformat_parse_error (line_input);
unformat_free (line_input);
goto done;
}
}
unformat_free (line_input);
}
TW (tw_timer_wheel_init) (&upf_tt_timer, NULL,
TW_SECS_PER_CLOCK /* 10ms timer interval */ , ~0);
upf_tt_timer.last_run_time = now;
next = now;
/* run for 2h (7200 secs, every 10ms) */
for (i = 1; i < 17200 * 100; i++)
{
/*jitter 5ms .. 15ms */
now += timer_interval * (base + drand48() * scale);
if (next <= now || (i % 100) == 1)
{
next = now + upf_test_timer_fn (vm, now, 1);
}
}
vlib_cli_output (vm, "Latency min %.8f, max %.8f\n", min_late, max_late);
done:
return error;
}
Regards
Andreas
--
Andreas Schultz
--
Principal Engineer
t: +49 391 819099-224
------------------------------- enabling your networks
-----------------------------
Travelping GmbH
Roentgenstraße 13
39108 Magdeburg
Germany
t: +49 391 819099-0
f: +49 391 819099-299
e: i...@travelping.com
w: https://www.travelping.com/
Company registration: Amtsgericht Stendal Reg. No.: HRB 10578
Geschaeftsfuehrer: Holger Winkelmann VAT ID: DE236673780
-=-=-=-=-=-=-=-=-=-=-=-
Links: You receive all messages sent to this group.
View/Reply Online (#13352): https://lists.fd.io/g/vpp-dev/message/13352
Mute This Topic: https://lists.fd.io/mt/32192172/21656
Group Owner: vpp-dev+ow...@lists.fd.io
Unsubscribe: https://lists.fd.io/g/vpp-dev/unsub [arch...@mail-archive.com]
-=-=-=-=-=-=-=-=-=-=-=-
