vppinfra/vppinfra/test_timing_wheel.c

   1 /*
   2  * Copyright (c) 2015 Cisco and/or its affiliates.
   3  * Licensed under the Apache License, Version 2.0 (the "License");
   4  * you may not use this file except in compliance with the License.
   5  * You may obtain a copy of the License at:
   6  *
   7  *     http://www.apache.org/licenses/LICENSE-2.0
   8  *
   9  * Unless required by applicable law or agreed to in writing, software
  10  * distributed under the License is distributed on an "AS IS" BASIS,
  11  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12  * See the License for the specific language governing permissions and
  13  * limitations under the License.
  14  */
  15 #include <vppinfra/bitmap.h>
  16 #include <vppinfra/error.h>
  17 #include <vppinfra/format.h>
  18 #include <vppinfra/pool.h>
  19 #include <vppinfra/random.h>
  20 #include <vppinfra/time.h>
  21 #include <vppinfra/timing_wheel.h>
  22 #include <vppinfra/zvec.h>
  23
  24 #include <vppinfra/math.h>
  25
  26 #if __GNUC__ < 4
  27 #define SQRT(a) a
  28 #else
  29 #define SQRT(a) sqrt(a)
  30 #endif
  31
  32 typedef struct {
  33   uword n_iter;
  34
  35   u32 n_events;
  36   u32 seed;
  37   u32 verbose;
  38
  39   /* Time is "synthetic" e.g. not taken from CPU timer. */
  40   u32 synthetic_time;
  41
  42   clib_time_t time;
  43   timing_wheel_t timing_wheel;
  44
  45   u64 * events;
  46
  47   f64 max_time;
  48   f64 wait_time;
  49
  50   f64 total_iterate_time;
  51   f64 time_iterate_start;
  52
  53   f64 time_per_status_update;
  54   f64 time_next_status_update;
  55 } test_timing_wheel_main_t;
  56
  57 static void set_event (test_timing_wheel_main_t * tm, uword i)
  58 {
  59   timing_wheel_t * w = &tm->timing_wheel;
  60   u64 cpu_time;
  61
  62   cpu_time = w->current_time_index << w->log2_clocks_per_bin;
  63   if (tm->synthetic_time)
  64     cpu_time += random_u32 (&tm->seed) % tm->n_iter;
  65   else
  66     cpu_time += random_f64 (&tm->seed) * tm->max_time * tm->time.clocks_per_second;
  67
  68   timing_wheel_insert (w, cpu_time, i);
  69   timing_wheel_validate (w);
  70   tm->events[i] = cpu_time;
  71 }
  72
  73 clib_error_t *
  74 test_timing_wheel_main (unformat_input_t * input)
  75 {
  76   clib_error_t * error = 0;
  77   test_timing_wheel_main_t _tm, * tm = &_tm;
  78   timing_wheel_t * w = &tm->timing_wheel;
  79   uword iter, i;
  80
  81   memset (tm, 0, sizeof (tm[0]));
  82   tm->n_iter = 10;
  83   tm->time_per_status_update = 0;
  84   tm->n_events = 100;
  85   tm->seed = 1;
  86   tm->synthetic_time = 1;
  87   tm->max_time = 1;
  88   tm->wait_time = 1e-3;
  89
  90   w->validate = 0;
  91   w->n_wheel_elt_time_bits = 32;
  92
  93   while (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
  94     {
  95       if (unformat (input, "iter %wd", &tm->n_iter))
  96         ;
  97       else if (unformat (input, "events %d", &tm->n_events))
  98         ;
  99       else if (unformat (input, "elt-time-bits %d", &w->n_wheel_elt_time_bits))
 100         ;
 101       else if (unformat (input, "seed %d", &tm->seed))
 102         ;
 103       else if (unformat (input, "verbose"))
 104         tm->verbose = 1;
 105       else if (unformat (input, "validate"))
 106         w->validate = 1;
 107
 108       else if (unformat (input, "real-time"))
 109         tm->synthetic_time = 0;
 110       else if (unformat (input, "synthetic-time"))
 111         tm->synthetic_time = 1;
 112       else if (unformat (input, "max-time %f", &tm->max_time))
 113         ;
 114       else if (unformat (input, "wait-time %f", &tm->wait_time))
 115         ;
 116       else if (unformat (input, "iter-time %f", &tm->total_iterate_time))
 117         ;
 118       else if (unformat (input, "print %f", &tm->time_per_status_update))
 119         ;
 120
 121       else
 122         {
 123           error = clib_error_create ("unknown input `%U'\n",
 124                                      format_unformat_error, input);
 125           goto done;
 126         }
 127     }
 128
 129   if (! tm->seed)
 130     tm->seed = random_default_seed ();
 131
 132   clib_time_init (&tm->time);
 133
 134   if (tm->synthetic_time)
 135     {
 136       w->min_sched_time = tm->time.seconds_per_clock;
 137       w->max_sched_time = w->min_sched_time * 256;
 138       timing_wheel_init (w, 0, tm->time.clocks_per_second);
 139     }
 140   else
 141     {
 142       timing_wheel_init (w, clib_cpu_time_now (), tm->time.clocks_per_second);
 143     }
 144
 145   clib_warning ("iter %wd, events %d, seed %u, %U",
 146                 tm->n_iter, tm->n_events, tm->seed,
 147                 format_timing_wheel, &tm->timing_wheel, /* verbose */ 0);
 148
 149   /* Make some events. */
 150   vec_resize (tm->events, tm->n_events);
 151   for (i = 0; i < vec_len (tm->events); i++)
 152     set_event (tm, i);
 153
 154   {
 155     u32 * expired = 0;
 156     f64 ave_error = 0;
 157     f64 rms_error = 0;
 158     f64 max_error = 0, min_error = 1e30;
 159     u32 * error_hist = 0;
 160     uword n_expired = 0;
 161     uword * expired_bitmap[2] = {0};
 162     uword n_events_in_wheel = vec_len (tm->events);
 163
 164     vec_resize (expired, 32);
 165     vec_resize (error_hist, 1024);
 166
 167     tm->time_iterate_start = clib_time_now (&tm->time);
 168     tm->time_next_status_update = tm->time_iterate_start + tm->time_per_status_update;
 169
 170     if (tm->total_iterate_time != 0)
 171       tm->n_iter = ~0;
 172
 173     for (iter = 0; iter < tm->n_iter || n_events_in_wheel > 0; iter++)
 174       {
 175         u64 cpu_time, min_next_time[2];
 176
 177         if (tm->synthetic_time)
 178           cpu_time = iter << w->log2_clocks_per_bin;
 179         else
 180           cpu_time = clib_cpu_time_now ();
 181
 182         _vec_len (expired) = 0;
 183         expired = timing_wheel_advance (w, cpu_time, expired, &min_next_time[0]);
 184         timing_wheel_validate (w);
 185
 186         /* Update bitmap of expired events. */
 187         if (w->validate)
 188           {
 189             for (i = 0; i < vec_len (tm->events); i++)
 190               {
 191                 uword is_expired;
 192
 193                 is_expired = (cpu_time >> w->log2_clocks_per_bin) >= (tm->events[i] >> w->log2_clocks_per_bin);
 194                 expired_bitmap[0] = clib_bitmap_set (expired_bitmap[0], i, is_expired);
 195
 196                 /* Validate min next time. */
 197                 if (is_expired)
 198                   ASSERT (min_next_time[0] > tm->events[i]);
 199                 else
 200                   ASSERT (min_next_time[0] <= tm->events[i]);
 201               }
 202           }
 203
 204         n_expired += vec_len (expired);
 205         for (i = 0; i < vec_len (expired); i++)
 206           {
 207             word j, idt;
 208             i64 dt_cpu;
 209             f64 fdt_cpu;
 210
 211             j = expired[i];
 212             expired_bitmap[1] = clib_bitmap_ori (expired_bitmap[1], j);
 213
 214             dt_cpu = cpu_time - tm->events[j];
 215
 216             /* Event must be scheduled in correct bin. */
 217             if (tm->synthetic_time)
 218               ASSERT (dt_cpu >= 0 && dt_cpu <= (1 << w->log2_clocks_per_bin));
 219
 220             fdt_cpu = dt_cpu * tm->time.seconds_per_clock;
 221
 222             ave_error += fdt_cpu;
 223             rms_error += fdt_cpu * fdt_cpu;
 224
 225             if (fdt_cpu > max_error)
 226               max_error = fdt_cpu;
 227             if (fdt_cpu < min_error)
 228               min_error = fdt_cpu;
 229
 230             idt = (cpu_time >> w->log2_clocks_per_bin) - (tm->events[j] >> w->log2_clocks_per_bin);
 231             idt = zvec_signed_to_unsigned (idt);
 232             vec_validate (error_hist, idt);
 233             error_hist[idt] += 1;
 234           }
 235
 236         if (w->validate)
 237           for (i = 0; i < vec_len (tm->events); i++)
 238             {
 239               int is_expired = clib_bitmap_get (expired_bitmap[0], i);
 240               int is_expired_w = clib_bitmap_get (expired_bitmap[1], i);
 241               ASSERT (is_expired == is_expired_w);
 242             }
 243
 244         min_next_time[1] = ~0;
 245         for (i = 0; i < vec_len (tm->events); i++)
 246           {
 247             if (! clib_bitmap_get (expired_bitmap[1], i))
 248               min_next_time[1] = clib_min (min_next_time[1], tm->events[i]);
 249           }
 250         if (min_next_time[0] != min_next_time[1])
 251           clib_error ("min next time wrong 0x%Lx != 0x%Lx", min_next_time[0], min_next_time[1]);
 252
 253         if (tm->time_per_status_update != 0
 254             && clib_time_now (&tm->time) >= tm->time_next_status_update)
 255           {
 256             f64 ave = 0, rms = 0;
 257
 258             tm->time_next_status_update += tm->time_per_status_update;
 259             if (n_expired > 0)
 260               {
 261                 ave = ave_error / n_expired;
 262                 rms = SQRT (rms_error / n_expired - ave * ave);
 263               }
 264
 265             clib_warning ("%12wd iter done %10wd expired; ave. error %.4e +- %.4e, range %.4e %.4e",
 266                           iter, n_expired, ave, rms, min_error, max_error);
 267           }
 268
 269         if (tm->total_iterate_time != 0
 270             && (clib_time_now (&tm->time) - tm->time_iterate_start
 271                 >= tm->total_iterate_time))
 272           tm->n_iter = iter;
 273
 274         /* Add new events to wheel to replace expired ones. */
 275         n_events_in_wheel -= vec_len (expired);
 276         if (iter < tm->n_iter)
 277           {
 278             for (i = 0; i < vec_len (expired); i++)
 279               {
 280                 uword j = expired[i];
 281                 set_event (tm, j);
 282                 expired_bitmap[1] = clib_bitmap_andnoti (expired_bitmap[1], j);
 283               }
 284             n_events_in_wheel += vec_len (expired);
 285           }
 286       }
 287
 288     ave_error /= n_expired;
 289     rms_error = SQRT (rms_error / n_expired - ave_error * ave_error);
 290
 291     clib_warning ("%wd iter done %wd expired; ave. error %.4e +- %.4e, range %.4e %.4e",
 292                   1 + iter, n_expired,
 293                   ave_error, rms_error,
 294                   min_error, max_error);
 295
 296     {
 297       struct tmp {
 298         f64 dt;
 299         f64 fraction;
 300         u64 count;
 301       } * fs, * f;
 302       f64 total_fraction;
 303
 304       fs = 0;
 305       for (i = 0; i < vec_len (error_hist); i++)
 306         {
 307           if (error_hist[i] == 0)
 308             continue;
 309           vec_add2 (fs, f, 1);
 310           f->dt = (((i64) zvec_unsigned_to_signed (i) << w->log2_clocks_per_bin)
 311                    * tm->time.seconds_per_clock);
 312           f->fraction = (f64) error_hist[i] / (f64) n_expired;
 313           f->count = error_hist[i];
 314         }
 315
 316       vec_sort (fs, f1, f2, f1->dt < f2->dt ? -1 : (f1->dt > f2->dt ? +1 : 0));
 317
 318       total_fraction = 0;
 319       vec_foreach (f, fs)
 320         {
 321           total_fraction += f->fraction;
 322           if (f == fs)
 323             fformat (stdout, "%=12s %=16s %=16s %s\n", "Error max", "Fraction", "Total", "Count");
 324           fformat (stdout, "%12.4e %16.4f%% %16.4f%% %Ld\n",
 325                    f->dt, f->fraction * 100, total_fraction * 100, f->count);
 326         }
 327     }
 328
 329     clib_warning ("%U", format_timing_wheel, w, /* verbose */ 1);
 330   }
 331
 332  done:
 333   return error;
 334 }
 335
 336 #ifdef CLIB_UNIX
 337 int main (int argc, char * argv[])
 338 {
 339   unformat_input_t i;
 340   clib_error_t * error;
 341
 342   unformat_init_command_line (&i, argv);
 343   error = test_timing_wheel_main (&i);
 344   unformat_free (&i);
 345   if (error)
 346     {
 347       clib_error_report (error);
 348       return 1;
 349     }
 350   else
 351     return 0;
 352 }
 353 #endif /* CLIB_UNIX */