src/vppinfra/elog.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 /*
  16   Copyright (c) 2005,2009 Eliot Dresselhaus
  17
  18   Permission is hereby granted, free of charge, to any person obtaining
  19   a copy of this software and associated documentation files (the
  20   "Software"), to deal in the Software without restriction, including
  21   without limitation the rights to use, copy, modify, merge, publish,
  22   distribute, sublicense, and/or sell copies of the Software, and to
  23   permit persons to whom the Software is furnished to do so, subject to
  24   the following conditions:
  25
  26   The above copyright notice and this permission notice shall be
  27   included in all copies or substantial portions of the Software.
  28
  29   THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
  30   EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
  31   MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
  32   NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
  33   LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
  34   OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
  35   WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
  36 */
  37
  38 #include <vppinfra/elog.h>
  39 #include <vppinfra/cache.h>
  40 #include <vppinfra/error.h>
  41 #include <vppinfra/format.h>
  42 #include <vppinfra/hash.h>
  43 #include <vppinfra/math.h>
  44
  45 static inline void
  46 elog_lock (elog_main_t * em)
  47 {
  48   if (PREDICT_FALSE (em->lock != 0))
  49     while (__sync_lock_test_and_set (em->lock, 1))
  50       ;
  51 }
  52
  53 static inline void
  54 elog_unlock (elog_main_t * em)
  55 {
  56   if (PREDICT_FALSE (em->lock != 0))
  57     {
  58       CLIB_MEMORY_BARRIER ();
  59       *em->lock = 0;
  60     }
  61 }
  62
  63 /* Non-inline version. */
  64 void *
  65 elog_event_data (elog_main_t * em,
  66                  elog_event_type_t * type, elog_track_t * track, u64 cpu_time)
  67 {
  68   return elog_event_data_inline (em, type, track, cpu_time);
  69 }
  70
  71 static void
  72 new_event_type (elog_main_t * em, uword i)
  73 {
  74   elog_event_type_t *t = vec_elt_at_index (em->event_types, i);
  75
  76   if (!em->event_type_by_format)
  77     em->event_type_by_format =
  78       hash_create_vec ( /* size */ 0, sizeof (u8), sizeof (uword));
  79
  80   t->type_index_plus_one = i + 1;
  81   hash_set_mem (em->event_type_by_format, t->format, i);
  82 }
  83
  84 static uword
  85 find_or_create_type (elog_main_t * em, elog_event_type_t * t)
  86 {
  87   uword *p = hash_get_mem (em->event_type_by_format, t->format);
  88   uword i;
  89
  90   if (p)
  91     i = p[0];
  92   else
  93     {
  94       i = vec_len (em->event_types);
  95       vec_add1 (em->event_types, t[0]);
  96       new_event_type (em, i);
  97     }
  98
  99   return i;
 100 }
 101
 102 /* External function to register types. */
 103 word
 104 elog_event_type_register (elog_main_t * em, elog_event_type_t * t)
 105 {
 106   elog_event_type_t *static_type = t;
 107   word l;
 108
 109   elog_lock (em);
 110
 111   /* Multiple simultaneous registration attempts, */
 112   if (t->type_index_plus_one > 0)
 113     {
 114       elog_unlock (em);
 115       return t->type_index_plus_one - 1;
 116     }
 117
 118   l = vec_len (em->event_types);
 119
 120   t->type_index_plus_one = 1 + l;
 121
 122   ASSERT (t->format);
 123
 124   /* If format args are not specified try to be smart about providing defaults
 125      so most of the time user does not have to specify them. */
 126   if (!t->format_args)
 127     {
 128       uword i, l;
 129       char *this_arg;
 130
 131       l = strlen (t->format);
 132       for (i = 0; i < l; i++)
 133         {
 134           if (t->format[i] != '%')
 135             continue;
 136           if (i + 1 >= l)
 137             continue;
 138           if (t->format[i + 1] == '%')  /* %% */
 139             continue;
 140
 141           switch (t->format[i + 1])
 142             {
 143             default:
 144             case 'd':
 145             case 'x':
 146             case 'u':
 147               this_arg = "i4";  /* size of u32 */
 148               break;
 149             case 'f':
 150               this_arg = "f8";  /* defaults to f64 */
 151               break;
 152             case 's':
 153               this_arg = "s0";  /* defaults to null terminated string. */
 154               break;
 155             }
 156
 157           t->format_args =
 158             (char *) format ((u8 *) t->format_args, "%s", this_arg);
 159         }
 160
 161       /* Null terminate. */
 162       vec_add1 (t->format_args, 0);
 163     }
 164
 165   vec_add1 (em->event_types, t[0]);
 166
 167   t = em->event_types + l;
 168
 169   /* Make copies of strings for hashing etc. */
 170   if (t->function)
 171     t->format = (char *) format (0, "%s %s%c", t->function, t->format, 0);
 172   else
 173     t->format = (char *) format (0, "%s%c", t->format, 0);
 174
 175   t->format_args = (char *) format (0, "%s%c", t->format_args, 0);
 176
 177   /* Construct string table. */
 178   {
 179     uword i;
 180     t->n_enum_strings = static_type->n_enum_strings;
 181     for (i = 0; i < t->n_enum_strings; i++)
 182       {
 183         if (!static_type->enum_strings[i])
 184           static_type->enum_strings[i] = "MISSING";
 185         vec_add1 (t->enum_strings_vector,
 186                   (char *) format (0, "%s%c", static_type->enum_strings[i],
 187                                    0));
 188       }
 189   }
 190
 191   new_event_type (em, l);
 192   elog_unlock (em);
 193
 194   return l;
 195 }
 196
 197 word
 198 elog_track_register (elog_main_t * em, elog_track_t * t)
 199 {
 200   word l;
 201
 202   elog_lock (em);
 203
 204   l = vec_len (em->tracks);
 205
 206   t->track_index_plus_one = 1 + l;
 207
 208   ASSERT (t->name);
 209
 210   vec_add1 (em->tracks, t[0]);
 211
 212   t = em->tracks + l;
 213
 214   t->name = (char *) format (0, "%s%c", t->name, 0);
 215
 216   elog_unlock (em);
 217
 218   return l;
 219 }
 220
 221 static uword
 222 parse_2digit_decimal (char *p, uword * number)
 223 {
 224   uword i = 0;
 225   u8 digits[2];
 226
 227   digits[0] = digits[1] = 0;
 228   while (p[i] >= '0' && p[i] <= '9')
 229     {
 230       if (i >= 2)
 231         break;
 232       digits[i] = p[i] - '0';
 233       i++;
 234     }
 235
 236   if (i >= 1 && i <= 2)
 237     {
 238       if (i == 1)
 239         *number = digits[0];
 240       else
 241         *number = 10 * digits[0] + digits[1];
 242       return i;
 243     }
 244   else
 245     return 0;
 246 }
 247
 248 static u8 *
 249 fixed_format (u8 * s, char *fmt, char *result, uword * result_len)
 250 {
 251   char *f = fmt;
 252   char *percent;
 253   uword l = 0;
 254
 255   while (1)
 256     {
 257       if (f[0] == 0)
 258         break;
 259       if (f[0] == '%' && f[1] != '%')
 260         break;
 261       f++;
 262     }
 263   if (f > fmt)
 264     vec_add (s, fmt, f - fmt);
 265
 266   if (f[0] != '%')
 267     goto done;
 268
 269   /* Skip percent. */
 270   percent = f++;
 271
 272   /* Skip possible +-= justification. */
 273   f += f[0] == '+' || f[0] == '-' || f[0] == '=';
 274
 275   /* Skip possible X.Y width. */
 276   while ((f[0] >= '0' && f[0] <= '9') || f[0] == '.')
 277     f++;
 278
 279   /* Skip wlL as in e.g. %Ld. */
 280   f += f[0] == 'w' || f[0] == 'l' || f[0] == 'L';
 281
 282   /* Finally skip format letter. */
 283   f += f[0] != 0;
 284
 285   ASSERT (*result_len > f - percent);
 286   l = clib_min (f - percent, *result_len - 1);
 287   clib_memcpy (result, percent, l);
 288   result[l] = 0;
 289
 290 done:
 291   *result_len = f - fmt;
 292   return s;
 293 }
 294
 295 u8 *
 296 format_elog_event (u8 * s, va_list * va)
 297 {
 298   elog_main_t *em = va_arg (*va, elog_main_t *);
 299   elog_event_t *e = va_arg (*va, elog_event_t *);
 300   elog_event_type_t *t;
 301   char *a, *f;
 302   void *d = (u8 *) e->data;
 303   char arg_format[64];
 304
 305   t = vec_elt_at_index (em->event_types, e->type);
 306
 307   f = t->format;
 308   a = t->format_args;
 309   while (1)
 310     {
 311       uword n_bytes = 0, n_digits, f_bytes = 0;
 312
 313       f_bytes = sizeof (arg_format);
 314       s = fixed_format (s, f, arg_format, &f_bytes);
 315       f += f_bytes;
 316
 317       if (a == 0 || a[0] == 0)
 318         {
 319           /* Format must also be at end. */
 320           ASSERT (f[0] == 0);
 321           break;
 322         }
 323
 324       /* Don't go past end of event data. */
 325       ASSERT (d < (void *) (e->data + sizeof (e->data)));
 326
 327       n_digits = parse_2digit_decimal (a + 1, &n_bytes);
 328       switch (a[0])
 329         {
 330         case 'i':
 331         case 't':
 332         case 'T':
 333           {
 334             u32 i = 0;
 335             u64 l = 0;
 336
 337             if (n_bytes == 1)
 338               i = ((u8 *) d)[0];
 339             else if (n_bytes == 2)
 340               i = clib_mem_unaligned (d, u16);
 341             else if (n_bytes == 4)
 342               i = clib_mem_unaligned (d, u32);
 343             else if (n_bytes == 8)
 344               l = clib_mem_unaligned (d, u64);
 345             else
 346               ASSERT (0);
 347             if (a[0] == 't')
 348               {
 349                 char *e =
 350                   vec_elt (t->enum_strings_vector, n_bytes == 8 ? l : i);
 351                 s = format (s, arg_format, e);
 352               }
 353             else if (a[0] == 'T')
 354               {
 355                 char *e =
 356                   vec_elt_at_index (em->string_table, n_bytes == 8 ? l : i);
 357                 s = format (s, arg_format, e);
 358               }
 359             else if (n_bytes == 8)
 360               s = format (s, arg_format, l);
 361             else
 362               s = format (s, arg_format, i);
 363           }
 364           break;
 365
 366         case 'f':
 367           {
 368             f64 x = 0;
 369             if (n_bytes == 4)
 370               x = clib_mem_unaligned (d, f32);
 371             else if (n_bytes == 8)
 372               x = clib_mem_unaligned (d, f64);
 373             else
 374               ASSERT (0);
 375             s = format (s, arg_format, x);
 376           }
 377           break;
 378
 379         case 's':
 380           s = format (s, arg_format, d);
 381           if (n_bytes == 0)
 382             n_bytes = strlen (d) + 1;
 383           break;
 384
 385         default:
 386           ASSERT (0);
 387           break;
 388         }
 389
 390       ASSERT (n_digits > 0 && n_digits <= 2);
 391       a += 1 + n_digits;
 392       d += n_bytes;
 393     }
 394
 395   return s;
 396 }
 397
 398 u8 *
 399 format_elog_track (u8 * s, va_list * va)
 400 {
 401   elog_main_t *em = va_arg (*va, elog_main_t *);
 402   elog_event_t *e = va_arg (*va, elog_event_t *);
 403   elog_track_t *t = vec_elt_at_index (em->tracks, e->track);
 404   return format (s, "%s", t->name);
 405 }
 406
 407 void
 408 elog_time_now (elog_time_stamp_t * et)
 409 {
 410   u64 cpu_time_now, os_time_now_nsec;
 411   struct timespec ts;
 412
 413 #ifdef CLIB_UNIX
 414   {
 415 #include <sys/syscall.h>
 416 #ifdef __APPLE__
 417     clock_gettime (CLOCK_REALTIME, &ts);
 418 #else
 419     syscall (SYS_clock_gettime, CLOCK_REALTIME, &ts);
 420 #endif
 421     cpu_time_now = clib_cpu_time_now ();
 422     /* Subtract 3/30/2017's worth of seconds to retain precision */
 423     os_time_now_nsec = 1e9 * (ts.tv_sec - 1490885108) + ts.tv_nsec;
 424   }
 425 #else
 426   cpu_time_now = clib_cpu_time_now ();
 427   os_time_now_nsec = 0;
 428 #endif
 429
 430   et->cpu = cpu_time_now;
 431   et->os_nsec = os_time_now_nsec;
 432 }
 433
 434 always_inline i64
 435 elog_time_stamp_diff_os_nsec (elog_time_stamp_t * t1, elog_time_stamp_t * t2)
 436 {
 437   return (i64) t1->os_nsec - (i64) t2->os_nsec;
 438 }
 439
 440 always_inline i64
 441 elog_time_stamp_diff_cpu (elog_time_stamp_t * t1, elog_time_stamp_t * t2)
 442 {
 443   return (i64) t1->cpu - (i64) t2->cpu;
 444 }
 445
 446 always_inline f64
 447 elog_nsec_per_clock (elog_main_t * em)
 448 {
 449   return ((f64) elog_time_stamp_diff_os_nsec (&em->serialize_time,
 450                                               &em->init_time)
 451           / (f64) elog_time_stamp_diff_cpu (&em->serialize_time,
 452                                             &em->init_time));
 453 }
 454
 455 void
 456 elog_alloc (elog_main_t * em, u32 n_events)
 457 {
 458   if (em->event_ring)
 459     vec_free (em->event_ring);
 460
 461   /* Ring size must be a power of 2. */
 462   em->event_ring_size = n_events = max_pow2 (n_events);
 463
 464   /* Leave an empty ievent at end so we can always speculatively write
 465      and event there (possibly a long form event). */
 466   vec_resize_aligned (em->event_ring, n_events, CLIB_CACHE_LINE_BYTES);
 467 }
 468
 469 void
 470 elog_init (elog_main_t * em, u32 n_events)
 471 {
 472   memset (em, 0, sizeof (em[0]));
 473
 474   em->lock = 0;
 475
 476   if (n_events > 0)
 477     elog_alloc (em, n_events);
 478
 479   clib_time_init (&em->cpu_timer);
 480
 481   em->n_total_events_disable_limit = ~0;
 482
 483   /* Make track 0. */
 484   em->default_track.name = "default";
 485   elog_track_register (em, &em->default_track);
 486
 487   elog_time_now (&em->init_time);
 488 }
 489
 490 /* Returns number of events in ring and start index. */
 491 static uword
 492 elog_event_range (elog_main_t * em, uword * lo)
 493 {
 494   uword l = em->event_ring_size;
 495   u64 i = em->n_total_events;
 496
 497   /* Ring never wrapped? */
 498   if (i <= (u64) l)
 499     {
 500       if (lo)
 501         *lo = 0;
 502       return i;
 503     }
 504   else
 505     {
 506       if (lo)
 507         *lo = i & (l - 1);
 508       return l;
 509     }
 510 }
 511
 512 elog_event_t *
 513 elog_peek_events (elog_main_t * em)
 514 {
 515   elog_event_t *e, *f, *es = 0;
 516   uword i, j, n;
 517
 518   n = elog_event_range (em, &j);
 519   for (i = 0; i < n; i++)
 520     {
 521       vec_add2 (es, e, 1);
 522       f = vec_elt_at_index (em->event_ring, j);
 523       e[0] = f[0];
 524
 525       /* Convert absolute time from cycles to seconds from start. */
 526       e->time =
 527         (e->time_cycles -
 528          em->init_time.cpu) * em->cpu_timer.seconds_per_clock;
 529
 530       j = (j + 1) & (em->event_ring_size - 1);
 531     }
 532
 533   return es;
 534 }
 535
 536 /* Add a formatted string to the string table. */
 537 u32
 538 elog_string (elog_main_t * em, char *fmt, ...)
 539 {
 540   u32 offset;
 541   va_list va;
 542
 543   va_start (va, fmt);
 544   offset = vec_len (em->string_table);
 545   em->string_table = (char *) va_format ((u8 *) em->string_table, fmt, &va);
 546   va_end (va);
 547
 548   /* Null terminate string if it is not already. */
 549   if (vec_end (em->string_table)[-1] != 0)
 550     vec_add1 (em->string_table, 0);
 551
 552   return offset;
 553 }
 554
 555 elog_event_t *
 556 elog_get_events (elog_main_t * em)
 557 {
 558   if (!em->events)
 559     em->events = elog_peek_events (em);
 560   return em->events;
 561 }
 562
 563 static void
 564 maybe_fix_string_table_offset (elog_event_t * e,
 565                                elog_event_type_t * t, u32 offset)
 566 {
 567   void *d = (u8 *) e->data;
 568   char *a;
 569
 570   if (offset == 0)
 571     return;
 572
 573   a = t->format_args;
 574
 575   while (1)
 576     {
 577       uword n_bytes = 0, n_digits;
 578
 579       if (a[0] == 0)
 580         break;
 581
 582       /* Don't go past end of event data. */
 583       ASSERT (d < (void *) (e->data + sizeof (e->data)));
 584
 585       n_digits = parse_2digit_decimal (a + 1, &n_bytes);
 586       switch (a[0])
 587         {
 588         case 'T':
 589           ASSERT (n_bytes == 4);
 590           clib_mem_unaligned (d, u32) += offset;
 591           break;
 592
 593         case 'i':
 594         case 't':
 595         case 'f':
 596         case 's':
 597           break;
 598
 599         default:
 600           ASSERT (0);
 601           break;
 602         }
 603
 604       ASSERT (n_digits > 0 && n_digits <= 2);
 605       a += 1 + n_digits;
 606       d += n_bytes;
 607     }
 608 }
 609
 610 static int
 611 elog_cmp (void *a1, void *a2)
 612 {
 613   elog_event_t *e1 = a1;
 614   elog_event_t *e2 = a2;
 615
 616   if (e1->time < e2->time)
 617     return -1;
 618
 619   if (e1->time > e2->time)
 620     return 1;
 621
 622   return 0;
 623 }
 624
 625 /*
 626  * merge two event logs. Complicated and cranky.
 627  */
 628 void
 629 elog_merge (elog_main_t * dst, u8 * dst_tag, elog_main_t * src, u8 * src_tag,
 630             f64 align_tweak)
 631 {
 632   elog_event_t *e;
 633   uword l;
 634   u32 string_table_offset_for_src_events;
 635   u32 track_offset_for_src_tracks;
 636   elog_track_t newt;
 637   int i;
 638
 639   memset (&newt, 0, sizeof (newt));
 640
 641   /* Acquire src and dst events */
 642   elog_get_events (src);
 643   elog_get_events (dst);
 644
 645   string_table_offset_for_src_events = vec_len (dst->string_table);
 646   vec_append (dst->string_table, src->string_table);
 647
 648   l = vec_len (dst->events);
 649   vec_append (dst->events, src->events);
 650
 651   /* Prepend the supplied tag (if any) to all dst track names */
 652   if (dst_tag)
 653     {
 654       for (i = 0; i < vec_len (dst->tracks); i++)
 655         {
 656           elog_track_t *t = vec_elt_at_index (dst->tracks, i);
 657           char *new_name;
 658
 659           new_name = (char *) format (0, "%s:%s%c", dst_tag, t->name, 0);
 660           vec_free (t->name);
 661           t->name = new_name;
 662         }
 663     }
 664
 665   /*
 666    * Remember where we started allocating new tracks while merging
 667    */
 668   track_offset_for_src_tracks = vec_len (dst->tracks);
 669
 670   /* Copy / tag source tracks */
 671   for (i = 0; i < vec_len (src->tracks); i++)
 672     {
 673       elog_track_t *t = vec_elt_at_index (src->tracks, i);
 674       if (src_tag)
 675         newt.name = (char *) format (0, "%s:%s%c", src_tag, t->name, 0);
 676       else
 677         newt.name = (char *) format (0, "%s%c", t->name, 0);
 678       (void) elog_track_register (dst, &newt);
 679       vec_free (newt.name);
 680     }
 681
 682   /* Across all (copied) src events... */
 683   for (e = dst->events + l; e < vec_end (dst->events); e++)
 684     {
 685       elog_event_type_t *t = vec_elt_at_index (src->event_types, e->type);
 686
 687       /* Remap type from src -> dst. */
 688       e->type = find_or_create_type (dst, t);
 689
 690       /* Remap string table offsets for 'T' format args */
 691       maybe_fix_string_table_offset (e, t,
 692                                      string_table_offset_for_src_events);
 693
 694       /* Remap track */
 695       e->track += track_offset_for_src_tracks;
 696     }
 697
 698   /* Adjust event times for relative starting times of event streams. */
 699   {
 700     f64 dt_event, dt_os_nsec, dt_clock_nsec;
 701
 702     /* Set clock parameters if dst was not generated by unserialize. */
 703     if (dst->serialize_time.cpu == 0)
 704       {
 705         dst->init_time = src->init_time;
 706         dst->serialize_time = src->serialize_time;
 707         dst->nsec_per_cpu_clock = src->nsec_per_cpu_clock;
 708       }
 709
 710     dt_os_nsec =
 711       elog_time_stamp_diff_os_nsec (&src->init_time, &dst->init_time);
 712
 713     dt_event = dt_os_nsec;
 714     dt_clock_nsec =
 715       (elog_time_stamp_diff_cpu (&src->init_time, &dst->init_time) * .5 *
 716        (dst->nsec_per_cpu_clock + src->nsec_per_cpu_clock));
 717
 718     /*
 719      * Heuristic to see if src/dst came from same time source.
 720      * If frequencies are "the same" and os clock and cpu clock agree
 721      * to within 100e-9 secs about time difference between src/dst
 722      * init_time, then we use cpu clock.  Otherwise we use OS clock.
 723      *
 724      * When merging event logs from different systems, time paradoxes
 725      * at the O(1ms) level are to be expected. Hence, the "align_tweak"
 726      * parameter. If two events logged on different processors are known
 727      * to occur in a specific order - and with a reasonably-estimated
 728      * interval - supply a non-zero "align_tweak" parameter
 729      */
 730     if (fabs (src->nsec_per_cpu_clock - dst->nsec_per_cpu_clock) < 1e-2
 731         && fabs (dt_os_nsec - dt_clock_nsec) < 100)
 732       dt_event = dt_clock_nsec;
 733
 734     /* Convert to seconds. */
 735     dt_event *= 1e-9;
 736
 737     /*
 738      * Move the earlier set of events later, to avoid creating
 739      * events which precede the Big Bang (aka have negative timestamps).
 740      *
 741      * Not to any scale, we have something like the following picture:
 742      *
 743      * DST capture start point
 744      *       ^
 745      *       +--- dt_event --+
 746      *                       v
 747      *                 SRC capture start point
 748      *
 749      * In this case dt_event is positive, src started after dst,
 750      * to put src events onto a common timebase we have to move them
 751      * forward in time. Naturally, the opposite case is
 752      * possible, too: dt_event will be negative, and so we have to
 753      * move dst events forward in time by the |dt_event|.
 754      * In both cases, we add align_tweak.
 755      */
 756     if (dt_event > 0)
 757       {
 758         /* Src started after dst. */
 759         for (e = dst->events + l; e < vec_end (dst->events); e++)
 760           e->time += dt_event + align_tweak;
 761       }
 762     else
 763       {
 764         /* Dst started after src. */
 765         dt_event = -dt_event;
 766         for (e = dst->events + 0; e < dst->events + l; e++)
 767           e->time += dt_event + align_tweak;
 768       }
 769   }
 770
 771   /* Sort events by increasing time. */
 772   vec_sort_with_function (dst->events, elog_cmp);
 773
 774   dst->n_total_events = vec_len (dst->events);
 775
 776   /* Recreate the event ring or the results won't serialize */
 777   {
 778     int i;
 779
 780     ASSERT (dst->cpu_timer.seconds_per_clock);
 781
 782     elog_alloc (dst, vec_len (dst->events));
 783     for (i = 0; i < vec_len (dst->events); i++)
 784       {
 785         elog_event_t *es, *ed;
 786
 787         es = dst->events + i;
 788         ed = dst->event_ring + i;
 789
 790         ed[0] = es[0];
 791       }
 792   }
 793 }
 794
 795 static void
 796 serialize_elog_event (serialize_main_t * m, va_list * va)
 797 {
 798   elog_main_t *em = va_arg (*va, elog_main_t *);
 799   elog_event_t *e = va_arg (*va, elog_event_t *);
 800   elog_event_type_t *t = vec_elt_at_index (em->event_types, e->type);
 801   u8 *d = e->data;
 802   u8 *p = (u8 *) t->format_args;
 803
 804   serialize_integer (m, e->type, sizeof (e->type));
 805   serialize_integer (m, e->track, sizeof (e->track));
 806   serialize (m, serialize_f64, e->time);
 807
 808   while (*p)
 809     {
 810       uword n_digits, n_bytes = 0;
 811
 812       n_digits = parse_2digit_decimal ((char *) p + 1, &n_bytes);
 813
 814       switch (p[0])
 815         {
 816         case 'i':
 817         case 't':
 818         case 'T':
 819           if (n_bytes == 1)
 820             serialize_integer (m, d[0], sizeof (u8));
 821           else if (n_bytes == 2)
 822             serialize_integer (m, clib_mem_unaligned (d, u16), sizeof (u16));
 823           else if (n_bytes == 4)
 824             serialize_integer (m, clib_mem_unaligned (d, u32), sizeof (u32));
 825           else if (n_bytes == 8)
 826             serialize (m, serialize_64, clib_mem_unaligned (d, u64));
 827           else
 828             ASSERT (0);
 829           break;
 830
 831         case 's':
 832           serialize_cstring (m, (char *) d);
 833           if (n_bytes == 0)
 834             n_bytes = strlen ((char *) d) + 1;
 835           break;
 836
 837         case 'f':
 838           if (n_bytes == 4)
 839             serialize (m, serialize_f32, clib_mem_unaligned (d, f32));
 840           else if (n_bytes == 8)
 841             serialize (m, serialize_f64, clib_mem_unaligned (d, f64));
 842           else
 843             ASSERT (0);
 844           break;
 845
 846         default:
 847           ASSERT (0);
 848           break;
 849         }
 850
 851       p += 1 + n_digits;
 852       d += n_bytes;
 853     }
 854 }
 855
 856 static void
 857 unserialize_elog_event (serialize_main_t * m, va_list * va)
 858 {
 859   elog_main_t *em = va_arg (*va, elog_main_t *);
 860   elog_event_t *e = va_arg (*va, elog_event_t *);
 861   elog_event_type_t *t;
 862   u8 *p, *d;
 863
 864   {
 865     u16 tmp[2];
 866
 867     unserialize_integer (m, &tmp[0], sizeof (e->type));
 868     unserialize_integer (m, &tmp[1], sizeof (e->track));
 869
 870     e->type = tmp[0];
 871     e->track = tmp[1];
 872
 873     /* Make sure it fits. */
 874     ASSERT (e->type == tmp[0]);
 875     ASSERT (e->track == tmp[1]);
 876   }
 877
 878   t = vec_elt_at_index (em->event_types, e->type);
 879
 880   unserialize (m, unserialize_f64, &e->time);
 881
 882   d = e->data;
 883   p = (u8 *) t->format_args;
 884
 885   while (p && *p)
 886     {
 887       uword n_digits, n_bytes = 0;
 888       u32 tmp;
 889
 890       n_digits = parse_2digit_decimal ((char *) p + 1, &n_bytes);
 891
 892       switch (p[0])
 893         {
 894         case 'i':
 895         case 't':
 896         case 'T':
 897           if (n_bytes == 1)
 898             {
 899               unserialize_integer (m, &tmp, sizeof (u8));
 900               d[0] = tmp;
 901             }
 902           else if (n_bytes == 2)
 903             {
 904               unserialize_integer (m, &tmp, sizeof (u16));
 905               clib_mem_unaligned (d, u16) = tmp;
 906             }
 907           else if (n_bytes == 4)
 908             {
 909               unserialize_integer (m, &tmp, sizeof (u32));
 910               clib_mem_unaligned (d, u32) = tmp;
 911             }
 912           else if (n_bytes == 8)
 913             {
 914               u64 x;
 915               unserialize (m, unserialize_64, &x);
 916               clib_mem_unaligned (d, u64) = x;
 917             }
 918           else
 919             ASSERT (0);
 920           break;
 921
 922         case 's':
 923           {
 924             char *t;
 925             unserialize_cstring (m, &t);
 926             if (n_bytes == 0)
 927               n_bytes = strlen (t) + 1;
 928             clib_memcpy (d, t, clib_min (n_bytes, vec_len (t)));
 929             vec_free (t);
 930             break;
 931           }
 932
 933         case 'f':
 934           if (n_bytes == 4)
 935             {
 936               f32 x;
 937               unserialize (m, unserialize_f32, &x);
 938               clib_mem_unaligned (d, f32) = x;
 939             }
 940           else if (n_bytes == 8)
 941             {
 942               f64 x;
 943               unserialize (m, unserialize_f64, &x);
 944               clib_mem_unaligned (d, f64) = x;
 945             }
 946           else
 947             ASSERT (0);
 948           break;
 949
 950         default:
 951           ASSERT (0);
 952           break;
 953         }
 954
 955       p += 1 + n_digits;
 956       d += n_bytes;
 957     }
 958 }
 959
 960 static void
 961 serialize_elog_event_type (serialize_main_t * m, va_list * va)
 962 {
 963   elog_event_type_t *t = va_arg (*va, elog_event_type_t *);
 964   int n = va_arg (*va, int);
 965   int i, j;
 966   for (i = 0; i < n; i++)
 967     {
 968       serialize_cstring (m, t[i].format);
 969       serialize_cstring (m, t[i].format_args);
 970       serialize_integer (m, t[i].type_index_plus_one,
 971                          sizeof (t->type_index_plus_one));
 972       serialize_integer (m, t[i].n_enum_strings,
 973                          sizeof (t[i].n_enum_strings));
 974       for (j = 0; j < t[i].n_enum_strings; j++)
 975         serialize_cstring (m, t[i].enum_strings_vector[j]);
 976     }
 977 }
 978
 979 static void
 980 unserialize_elog_event_type (serialize_main_t * m, va_list * va)
 981 {
 982   elog_event_type_t *t = va_arg (*va, elog_event_type_t *);
 983   int n = va_arg (*va, int);
 984   int i, j;
 985   for (i = 0; i < n; i++)
 986     {
 987       unserialize_cstring (m, &t[i].format);
 988       unserialize_cstring (m, &t[i].format_args);
 989       unserialize_integer (m, &t[i].type_index_plus_one,
 990                            sizeof (t->type_index_plus_one));
 991       unserialize_integer (m, &t[i].n_enum_strings,
 992                            sizeof (t[i].n_enum_strings));
 993       vec_resize (t[i].enum_strings_vector, t[i].n_enum_strings);
 994       for (j = 0; j < t[i].n_enum_strings; j++)
 995         unserialize_cstring (m, &t[i].enum_strings_vector[j]);
 996     }
 997 }
 998
 999 static void
1000 serialize_elog_track (serialize_main_t * m, va_list * va)
1001 {
1002   elog_track_t *t = va_arg (*va, elog_track_t *);
1003   int n = va_arg (*va, int);
1004   int i;
1005   for (i = 0; i < n; i++)
1006     {
1007       serialize_cstring (m, t[i].name);
1008     }
1009 }
1010
1011 static void
1012 unserialize_elog_track (serialize_main_t * m, va_list * va)
1013 {
1014   elog_track_t *t = va_arg (*va, elog_track_t *);
1015   int n = va_arg (*va, int);
1016   int i;
1017   for (i = 0; i < n; i++)
1018     {
1019       unserialize_cstring (m, &t[i].name);
1020     }
1021 }
1022
1023 static void
1024 serialize_elog_time_stamp (serialize_main_t * m, va_list * va)
1025 {
1026   elog_time_stamp_t *st = va_arg (*va, elog_time_stamp_t *);
1027   serialize (m, serialize_64, st->os_nsec);
1028   serialize (m, serialize_64, st->cpu);
1029 }
1030
1031 static void
1032 unserialize_elog_time_stamp (serialize_main_t * m, va_list * va)
1033 {
1034   elog_time_stamp_t *st = va_arg (*va, elog_time_stamp_t *);
1035   unserialize (m, unserialize_64, &st->os_nsec);
1036   unserialize (m, unserialize_64, &st->cpu);
1037 }
1038
1039 static char *elog_serialize_magic = "elog v0";
1040
1041 void
1042 serialize_elog_main (serialize_main_t * m, va_list * va)
1043 {
1044   elog_main_t *em = va_arg (*va, elog_main_t *);
1045   int flush_ring = va_arg (*va, int);
1046   elog_event_t *e;
1047
1048   serialize_magic (m, elog_serialize_magic, strlen (elog_serialize_magic));
1049
1050   serialize_integer (m, em->event_ring_size, sizeof (u32));
1051
1052   elog_time_now (&em->serialize_time);
1053   serialize (m, serialize_elog_time_stamp, &em->serialize_time);
1054   serialize (m, serialize_elog_time_stamp, &em->init_time);
1055
1056   vec_serialize (m, em->event_types, serialize_elog_event_type);
1057   vec_serialize (m, em->tracks, serialize_elog_track);
1058   vec_serialize (m, em->string_table, serialize_vec_8);
1059
1060   /* Free old events (cached) in case they have changed. */
1061   if (flush_ring)
1062     {
1063       vec_free (em->events);
1064       elog_get_events (em);
1065     }
1066
1067   serialize_integer (m, vec_len (em->events), sizeof (u32));
1068
1069   /* SMP logs can easily have local time paradoxes... */
1070   vec_sort_with_function (em->events, elog_cmp);
1071
1072   vec_foreach (e, em->events) serialize (m, serialize_elog_event, em, e);
1073 }
1074
1075 void
1076 unserialize_elog_main (serialize_main_t * m, va_list * va)
1077 {
1078   elog_main_t *em = va_arg (*va, elog_main_t *);
1079   uword i;
1080   u32 rs;
1081
1082   unserialize_check_magic (m, elog_serialize_magic,
1083                            strlen (elog_serialize_magic));
1084
1085   unserialize_integer (m, &rs, sizeof (u32));
1086   em->event_ring_size = rs;
1087   elog_init (em, em->event_ring_size);
1088
1089   unserialize (m, unserialize_elog_time_stamp, &em->serialize_time);
1090   unserialize (m, unserialize_elog_time_stamp, &em->init_time);
1091   em->nsec_per_cpu_clock = elog_nsec_per_clock (em);
1092
1093   vec_unserialize (m, &em->event_types, unserialize_elog_event_type);
1094   for (i = 0; i < vec_len (em->event_types); i++)
1095     new_event_type (em, i);
1096
1097   vec_unserialize (m, &em->tracks, unserialize_elog_track);
1098   vec_unserialize (m, &em->string_table, unserialize_vec_8);
1099
1100   {
1101     u32 ne;
1102     elog_event_t *e;
1103
1104     unserialize_integer (m, &ne, sizeof (u32));
1105     vec_resize (em->events, ne);
1106     vec_foreach (e, em->events)
1107       unserialize (m, unserialize_elog_event, em, e);
1108   }
1109 }
1110
1111 /*
1112  * fd.io coding-style-patch-verification: ON
1113  *
1114  * Local Variables:
1115  * eval: (c-set-style "gnu")
1116  * End:
1117  */