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     syscall (SYS_clock_gettime, CLOCK_REALTIME, &ts);
 417     cpu_time_now = clib_cpu_time_now ();
 418     /* Subtract 3/30/2017's worth of seconds to retain precision */
 419     os_time_now_nsec = 1e9 * (ts.tv_sec - 1490885108) + ts.tv_nsec;
 420   }
 421 #else
 422   cpu_time_now = clib_cpu_time_now ();
 423   os_time_now_nsec = 0;
 424 #endif
 425
 426   et->cpu = cpu_time_now;
 427   et->os_nsec = os_time_now_nsec;
 428 }
 429
 430 always_inline i64
 431 elog_time_stamp_diff_os_nsec (elog_time_stamp_t * t1, elog_time_stamp_t * t2)
 432 {
 433   return (i64) t1->os_nsec - (i64) t2->os_nsec;
 434 }
 435
 436 always_inline i64
 437 elog_time_stamp_diff_cpu (elog_time_stamp_t * t1, elog_time_stamp_t * t2)
 438 {
 439   return (i64) t1->cpu - (i64) t2->cpu;
 440 }
 441
 442 always_inline f64
 443 elog_nsec_per_clock (elog_main_t * em)
 444 {
 445   return ((f64) elog_time_stamp_diff_os_nsec (&em->serialize_time,
 446                                               &em->init_time)
 447           / (f64) elog_time_stamp_diff_cpu (&em->serialize_time,
 448                                             &em->init_time));
 449 }
 450
 451 void
 452 elog_alloc (elog_main_t * em, u32 n_events)
 453 {
 454   if (em->event_ring)
 455     vec_free (em->event_ring);
 456
 457   /* Ring size must be a power of 2. */
 458   em->event_ring_size = n_events = max_pow2 (n_events);
 459
 460   /* Leave an empty ievent at end so we can always speculatively write
 461      and event there (possibly a long form event). */
 462   vec_resize_aligned (em->event_ring, n_events, CLIB_CACHE_LINE_BYTES);
 463 }
 464
 465 void
 466 elog_init (elog_main_t * em, u32 n_events)
 467 {
 468   memset (em, 0, sizeof (em[0]));
 469
 470   em->lock = 0;
 471
 472   if (n_events > 0)
 473     elog_alloc (em, n_events);
 474
 475   clib_time_init (&em->cpu_timer);
 476
 477   em->n_total_events_disable_limit = ~0;
 478
 479   /* Make track 0. */
 480   em->default_track.name = "default";
 481   elog_track_register (em, &em->default_track);
 482
 483   elog_time_now (&em->init_time);
 484 }
 485
 486 /* Returns number of events in ring and start index. */
 487 static uword
 488 elog_event_range (elog_main_t * em, uword * lo)
 489 {
 490   uword l = em->event_ring_size;
 491   u64 i = em->n_total_events;
 492
 493   /* Ring never wrapped? */
 494   if (i <= (u64) l)
 495     {
 496       if (lo)
 497         *lo = 0;
 498       return i;
 499     }
 500   else
 501     {
 502       if (lo)
 503         *lo = i & (l - 1);
 504       return l;
 505     }
 506 }
 507
 508 elog_event_t *
 509 elog_peek_events (elog_main_t * em)
 510 {
 511   elog_event_t *e, *f, *es = 0;
 512   uword i, j, n;
 513
 514   n = elog_event_range (em, &j);
 515   for (i = 0; i < n; i++)
 516     {
 517       vec_add2 (es, e, 1);
 518       f = vec_elt_at_index (em->event_ring, j);
 519       e[0] = f[0];
 520
 521       /* Convert absolute time from cycles to seconds from start. */
 522       e->time =
 523         (e->time_cycles -
 524          em->init_time.cpu) * em->cpu_timer.seconds_per_clock;
 525
 526       j = (j + 1) & (em->event_ring_size - 1);
 527     }
 528
 529   return es;
 530 }
 531
 532 /* Add a formatted string to the string table. */
 533 u32
 534 elog_string (elog_main_t * em, char *fmt, ...)
 535 {
 536   u32 offset;
 537   va_list va;
 538
 539   va_start (va, fmt);
 540   offset = vec_len (em->string_table);
 541   em->string_table = (char *) va_format ((u8 *) em->string_table, fmt, &va);
 542   va_end (va);
 543
 544   /* Null terminate string if it is not already. */
 545   if (vec_end (em->string_table)[-1] != 0)
 546     vec_add1 (em->string_table, 0);
 547
 548   return offset;
 549 }
 550
 551 elog_event_t *
 552 elog_get_events (elog_main_t * em)
 553 {
 554   if (!em->events)
 555     em->events = elog_peek_events (em);
 556   return em->events;
 557 }
 558
 559 static void
 560 maybe_fix_string_table_offset (elog_event_t * e,
 561                                elog_event_type_t * t, u32 offset)
 562 {
 563   void *d = (u8 *) e->data;
 564   char *a;
 565
 566   if (offset == 0)
 567     return;
 568
 569   a = t->format_args;
 570
 571   while (1)
 572     {
 573       uword n_bytes = 0, n_digits;
 574
 575       if (a[0] == 0)
 576         break;
 577
 578       /* Don't go past end of event data. */
 579       ASSERT (d < (void *) (e->data + sizeof (e->data)));
 580
 581       n_digits = parse_2digit_decimal (a + 1, &n_bytes);
 582       switch (a[0])
 583         {
 584         case 'T':
 585           ASSERT (n_bytes == 4);
 586           clib_mem_unaligned (d, u32) += offset;
 587           break;
 588
 589         case 'i':
 590         case 't':
 591         case 'f':
 592         case 's':
 593           break;
 594
 595         default:
 596           ASSERT (0);
 597           break;
 598         }
 599
 600       ASSERT (n_digits > 0 && n_digits <= 2);
 601       a += 1 + n_digits;
 602       d += n_bytes;
 603     }
 604 }
 605
 606 static int
 607 elog_cmp (void *a1, void *a2)
 608 {
 609   elog_event_t *e1 = a1;
 610   elog_event_t *e2 = a2;
 611
 612   if (e1->time < e2->time)
 613     return -1;
 614
 615   if (e1->time > e2->time)
 616     return 1;
 617
 618   return 0;
 619 }
 620
 621 /*
 622  * merge two event logs. Complicated and cranky.
 623  */
 624 void
 625 elog_merge (elog_main_t * dst, u8 * dst_tag, elog_main_t * src, u8 * src_tag,
 626             f64 align_tweak)
 627 {
 628   elog_event_t *e;
 629   uword l;
 630   u32 string_table_offset_for_src_events;
 631   u32 track_offset_for_src_tracks;
 632   elog_track_t newt;
 633   int i;
 634
 635   memset (&newt, 0, sizeof (newt));
 636
 637   /* Acquire src and dst events */
 638   elog_get_events (src);
 639   elog_get_events (dst);
 640
 641   string_table_offset_for_src_events = vec_len (dst->string_table);
 642   vec_append (dst->string_table, src->string_table);
 643
 644   l = vec_len (dst->events);
 645   vec_append (dst->events, src->events);
 646
 647   /* Prepend the supplied tag (if any) to all dst track names */
 648   if (dst_tag)
 649     {
 650       for (i = 0; i < vec_len (dst->tracks); i++)
 651         {
 652           elog_track_t *t = vec_elt_at_index (dst->tracks, i);
 653           char *new_name;
 654
 655           new_name = (char *) format (0, "%s:%s%c", dst_tag, t->name, 0);
 656           vec_free (t->name);
 657           t->name = new_name;
 658         }
 659     }
 660
 661   /*
 662    * Remember where we started allocating new tracks while merging
 663    */
 664   track_offset_for_src_tracks = vec_len (dst->tracks);
 665
 666   /* Copy / tag source tracks */
 667   for (i = 0; i < vec_len (src->tracks); i++)
 668     {
 669       elog_track_t *t = vec_elt_at_index (src->tracks, i);
 670       if (src_tag)
 671         newt.name = (char *) format (0, "%s:%s%c", src_tag, t->name, 0);
 672       else
 673         newt.name = (char *) format (0, "%s%c", t->name, 0);
 674       (void) elog_track_register (dst, &newt);
 675       vec_free (newt.name);
 676     }
 677
 678   /* Across all (copied) src events... */
 679   for (e = dst->events + l; e < vec_end (dst->events); e++)
 680     {
 681       elog_event_type_t *t = vec_elt_at_index (src->event_types, e->type);
 682
 683       /* Remap type from src -> dst. */
 684       e->type = find_or_create_type (dst, t);
 685
 686       /* Remap string table offsets for 'T' format args */
 687       maybe_fix_string_table_offset (e, t,
 688                                      string_table_offset_for_src_events);
 689
 690       /* Remap track */
 691       e->track += track_offset_for_src_tracks;
 692     }
 693
 694   /* Adjust event times for relative starting times of event streams. */
 695   {
 696     f64 dt_event, dt_os_nsec, dt_clock_nsec;
 697
 698     /* Set clock parameters if dst was not generated by unserialize. */
 699     if (dst->serialize_time.cpu == 0)
 700       {
 701         dst->init_time = src->init_time;
 702         dst->serialize_time = src->serialize_time;
 703         dst->nsec_per_cpu_clock = src->nsec_per_cpu_clock;
 704       }
 705
 706     dt_os_nsec =
 707       elog_time_stamp_diff_os_nsec (&src->init_time, &dst->init_time);
 708
 709     dt_event = dt_os_nsec;
 710     dt_clock_nsec =
 711       (elog_time_stamp_diff_cpu (&src->init_time, &dst->init_time) * .5 *
 712        (dst->nsec_per_cpu_clock + src->nsec_per_cpu_clock));
 713
 714     /*
 715      * Heuristic to see if src/dst came from same time source.
 716      * If frequencies are "the same" and os clock and cpu clock agree
 717      * to within 100e-9 secs about time difference between src/dst
 718      * init_time, then we use cpu clock.  Otherwise we use OS clock.
 719      *
 720      * When merging event logs from different systems, time paradoxes
 721      * at the O(1ms) level are to be expected. Hence, the "align_tweak"
 722      * parameter. If two events logged on different processors are known
 723      * to occur in a specific order - and with a reasonably-estimated
 724      * interval - supply a non-zero "align_tweak" parameter
 725      */
 726     if (fabs (src->nsec_per_cpu_clock - dst->nsec_per_cpu_clock) < 1e-2
 727         && fabs (dt_os_nsec - dt_clock_nsec) < 100)
 728       dt_event = dt_clock_nsec;
 729
 730     /* Convert to seconds. */
 731     dt_event *= 1e-9;
 732
 733     /*
 734      * Move the earlier set of events later, to avoid creating
 735      * events which preceed the Big Bang (aka have negative timestamps).
 736      *
 737      * Not to any scale, we have something like the following picture:
 738      *
 739      * DST capture start point
 740      *       ^
 741      *       +--- dt_event --+
 742      *                       v
 743      *                 SRC capture start point
 744      *
 745      * In this case dt_event is positive, src started after dst,
 746      * to put src events onto a common timebase we have to move them
 747      * forward in time. Naturally, the opposite case is
 748      * possible, too: dt_event will be negative, and so we have to
 749      * move dst events forward in time by the |dt_event|.
 750      * In both cases, we add align_tweak.
 751      */
 752     if (dt_event > 0)
 753       {
 754         /* Src started after dst. */
 755         for (e = dst->events + l; e < vec_end (dst->events); e++)
 756           e->time += dt_event + align_tweak;
 757       }
 758     else
 759       {
 760         /* Dst started after src. */
 761         dt_event = -dt_event;
 762         for (e = dst->events + 0; e < dst->events + l; e++)
 763           e->time += dt_event + align_tweak;
 764       }
 765   }
 766
 767   /* Sort events by increasing time. */
 768   vec_sort_with_function (dst->events, elog_cmp);
 769
 770   dst->n_total_events = vec_len (dst->events);
 771
 772   /* Recreate the event ring or the results won't serialize */
 773   {
 774     int i;
 775
 776     ASSERT (dst->cpu_timer.seconds_per_clock);
 777
 778     elog_alloc (dst, vec_len (dst->events));
 779     for (i = 0; i < vec_len (dst->events); i++)
 780       {
 781         elog_event_t *es, *ed;
 782
 783         es = dst->events + i;
 784         ed = dst->event_ring + i;
 785
 786         ed[0] = es[0];
 787       }
 788   }
 789 }
 790
 791 static void
 792 serialize_elog_event (serialize_main_t * m, va_list * va)
 793 {
 794   elog_main_t *em = va_arg (*va, elog_main_t *);
 795   elog_event_t *e = va_arg (*va, elog_event_t *);
 796   elog_event_type_t *t = vec_elt_at_index (em->event_types, e->type);
 797   u8 *d = e->data;
 798   u8 *p = (u8 *) t->format_args;
 799
 800   serialize_integer (m, e->type, sizeof (e->type));
 801   serialize_integer (m, e->track, sizeof (e->track));
 802   serialize (m, serialize_f64, e->time);
 803
 804   while (*p)
 805     {
 806       uword n_digits, n_bytes = 0;
 807
 808       n_digits = parse_2digit_decimal ((char *) p + 1, &n_bytes);
 809
 810       switch (p[0])
 811         {
 812         case 'i':
 813         case 't':
 814         case 'T':
 815           if (n_bytes == 1)
 816             serialize_integer (m, d[0], sizeof (u8));
 817           else if (n_bytes == 2)
 818             serialize_integer (m, clib_mem_unaligned (d, u16), sizeof (u16));
 819           else if (n_bytes == 4)
 820             serialize_integer (m, clib_mem_unaligned (d, u32), sizeof (u32));
 821           else if (n_bytes == 8)
 822             serialize (m, serialize_64, clib_mem_unaligned (d, u64));
 823           else
 824             ASSERT (0);
 825           break;
 826
 827         case 's':
 828           serialize_cstring (m, (char *) d);
 829           if (n_bytes == 0)
 830             n_bytes = strlen ((char *) d) + 1;
 831           break;
 832
 833         case 'f':
 834           if (n_bytes == 4)
 835             serialize (m, serialize_f32, clib_mem_unaligned (d, f32));
 836           else if (n_bytes == 8)
 837             serialize (m, serialize_f64, clib_mem_unaligned (d, f64));
 838           else
 839             ASSERT (0);
 840           break;
 841
 842         default:
 843           ASSERT (0);
 844           break;
 845         }
 846
 847       p += 1 + n_digits;
 848       d += n_bytes;
 849     }
 850 }
 851
 852 static void
 853 unserialize_elog_event (serialize_main_t * m, va_list * va)
 854 {
 855   elog_main_t *em = va_arg (*va, elog_main_t *);
 856   elog_event_t *e = va_arg (*va, elog_event_t *);
 857   elog_event_type_t *t;
 858   u8 *p, *d;
 859
 860   {
 861     u16 tmp[2];
 862
 863     unserialize_integer (m, &tmp[0], sizeof (e->type));
 864     unserialize_integer (m, &tmp[1], sizeof (e->track));
 865
 866     e->type = tmp[0];
 867     e->track = tmp[1];
 868
 869     /* Make sure it fits. */
 870     ASSERT (e->type == tmp[0]);
 871     ASSERT (e->track == tmp[1]);
 872   }
 873
 874   t = vec_elt_at_index (em->event_types, e->type);
 875
 876   unserialize (m, unserialize_f64, &e->time);
 877
 878   d = e->data;
 879   p = (u8 *) t->format_args;
 880
 881   while (p && *p)
 882     {
 883       uword n_digits, n_bytes = 0;
 884       u32 tmp;
 885
 886       n_digits = parse_2digit_decimal ((char *) p + 1, &n_bytes);
 887
 888       switch (p[0])
 889         {
 890         case 'i':
 891         case 't':
 892         case 'T':
 893           if (n_bytes == 1)
 894             {
 895               unserialize_integer (m, &tmp, sizeof (u8));
 896               d[0] = tmp;
 897             }
 898           else if (n_bytes == 2)
 899             {
 900               unserialize_integer (m, &tmp, sizeof (u16));
 901               clib_mem_unaligned (d, u16) = tmp;
 902             }
 903           else if (n_bytes == 4)
 904             {
 905               unserialize_integer (m, &tmp, sizeof (u32));
 906               clib_mem_unaligned (d, u32) = tmp;
 907             }
 908           else if (n_bytes == 8)
 909             {
 910               u64 x;
 911               unserialize (m, unserialize_64, &x);
 912               clib_mem_unaligned (d, u64) = x;
 913             }
 914           else
 915             ASSERT (0);
 916           break;
 917
 918         case 's':
 919           {
 920             char *t;
 921             unserialize_cstring (m, &t);
 922             if (n_bytes == 0)
 923               n_bytes = strlen (t) + 1;
 924             clib_memcpy (d, t, clib_min (n_bytes, vec_len (t)));
 925             vec_free (t);
 926             break;
 927           }
 928
 929         case 'f':
 930           if (n_bytes == 4)
 931             {
 932               f32 x;
 933               unserialize (m, unserialize_f32, &x);
 934               clib_mem_unaligned (d, f32) = x;
 935             }
 936           else if (n_bytes == 8)
 937             {
 938               f64 x;
 939               unserialize (m, unserialize_f64, &x);
 940               clib_mem_unaligned (d, f64) = x;
 941             }
 942           else
 943             ASSERT (0);
 944           break;
 945
 946         default:
 947           ASSERT (0);
 948           break;
 949         }
 950
 951       p += 1 + n_digits;
 952       d += n_bytes;
 953     }
 954 }
 955
 956 static void
 957 serialize_elog_event_type (serialize_main_t * m, va_list * va)
 958 {
 959   elog_event_type_t *t = va_arg (*va, elog_event_type_t *);
 960   int n = va_arg (*va, int);
 961   int i, j;
 962   for (i = 0; i < n; i++)
 963     {
 964       serialize_cstring (m, t[i].format);
 965       serialize_cstring (m, t[i].format_args);
 966       serialize_integer (m, t[i].type_index_plus_one,
 967                          sizeof (t->type_index_plus_one));
 968       serialize_integer (m, t[i].n_enum_strings,
 969                          sizeof (t[i].n_enum_strings));
 970       for (j = 0; j < t[i].n_enum_strings; j++)
 971         serialize_cstring (m, t[i].enum_strings_vector[j]);
 972     }
 973 }
 974
 975 static void
 976 unserialize_elog_event_type (serialize_main_t * m, va_list * va)
 977 {
 978   elog_event_type_t *t = va_arg (*va, elog_event_type_t *);
 979   int n = va_arg (*va, int);
 980   int i, j;
 981   for (i = 0; i < n; i++)
 982     {
 983       unserialize_cstring (m, &t[i].format);
 984       unserialize_cstring (m, &t[i].format_args);
 985       unserialize_integer (m, &t[i].type_index_plus_one,
 986                            sizeof (t->type_index_plus_one));
 987       unserialize_integer (m, &t[i].n_enum_strings,
 988                            sizeof (t[i].n_enum_strings));
 989       vec_resize (t[i].enum_strings_vector, t[i].n_enum_strings);
 990       for (j = 0; j < t[i].n_enum_strings; j++)
 991         unserialize_cstring (m, &t[i].enum_strings_vector[j]);
 992     }
 993 }
 994
 995 static void
 996 serialize_elog_track (serialize_main_t * m, va_list * va)
 997 {
 998   elog_track_t *t = va_arg (*va, elog_track_t *);
 999   int n = va_arg (*va, int);
1000   int i;
1001   for (i = 0; i < n; i++)
1002     {
1003       serialize_cstring (m, t[i].name);
1004     }
1005 }
1006
1007 static void
1008 unserialize_elog_track (serialize_main_t * m, va_list * va)
1009 {
1010   elog_track_t *t = va_arg (*va, elog_track_t *);
1011   int n = va_arg (*va, int);
1012   int i;
1013   for (i = 0; i < n; i++)
1014     {
1015       unserialize_cstring (m, &t[i].name);
1016     }
1017 }
1018
1019 static void
1020 serialize_elog_time_stamp (serialize_main_t * m, va_list * va)
1021 {
1022   elog_time_stamp_t *st = va_arg (*va, elog_time_stamp_t *);
1023   serialize (m, serialize_64, st->os_nsec);
1024   serialize (m, serialize_64, st->cpu);
1025 }
1026
1027 static void
1028 unserialize_elog_time_stamp (serialize_main_t * m, va_list * va)
1029 {
1030   elog_time_stamp_t *st = va_arg (*va, elog_time_stamp_t *);
1031   unserialize (m, unserialize_64, &st->os_nsec);
1032   unserialize (m, unserialize_64, &st->cpu);
1033 }
1034
1035 static char *elog_serialize_magic = "elog v0";
1036
1037 void
1038 serialize_elog_main (serialize_main_t * m, va_list * va)
1039 {
1040   elog_main_t *em = va_arg (*va, elog_main_t *);
1041   int flush_ring = va_arg (*va, int);
1042   elog_event_t *e;
1043
1044   serialize_magic (m, elog_serialize_magic, strlen (elog_serialize_magic));
1045
1046   serialize_integer (m, em->event_ring_size, sizeof (u32));
1047
1048   elog_time_now (&em->serialize_time);
1049   serialize (m, serialize_elog_time_stamp, &em->serialize_time);
1050   serialize (m, serialize_elog_time_stamp, &em->init_time);
1051
1052   vec_serialize (m, em->event_types, serialize_elog_event_type);
1053   vec_serialize (m, em->tracks, serialize_elog_track);
1054   vec_serialize (m, em->string_table, serialize_vec_8);
1055
1056   /* Free old events (cached) in case they have changed. */
1057   if (flush_ring)
1058     {
1059       vec_free (em->events);
1060       elog_get_events (em);
1061     }
1062
1063   serialize_integer (m, vec_len (em->events), sizeof (u32));
1064
1065   /* SMP logs can easily have local time paradoxes... */
1066   vec_sort_with_function (em->events, elog_cmp);
1067
1068   vec_foreach (e, em->events) serialize (m, serialize_elog_event, em, e);
1069 }
1070
1071 void
1072 unserialize_elog_main (serialize_main_t * m, va_list * va)
1073 {
1074   elog_main_t *em = va_arg (*va, elog_main_t *);
1075   uword i;
1076   u32 rs;
1077
1078   unserialize_check_magic (m, elog_serialize_magic,
1079                            strlen (elog_serialize_magic));
1080
1081   unserialize_integer (m, &rs, sizeof (u32));
1082   em->event_ring_size = rs;
1083   elog_init (em, em->event_ring_size);
1084
1085   unserialize (m, unserialize_elog_time_stamp, &em->serialize_time);
1086   unserialize (m, unserialize_elog_time_stamp, &em->init_time);
1087   em->nsec_per_cpu_clock = elog_nsec_per_clock (em);
1088
1089   vec_unserialize (m, &em->event_types, unserialize_elog_event_type);
1090   for (i = 0; i < vec_len (em->event_types); i++)
1091     new_event_type (em, i);
1092
1093   vec_unserialize (m, &em->tracks, unserialize_elog_track);
1094   vec_unserialize (m, &em->string_table, unserialize_vec_8);
1095
1096   {
1097     u32 ne;
1098     elog_event_t *e;
1099
1100     unserialize_integer (m, &ne, sizeof (u32));
1101     vec_resize (em->events, ne);
1102     vec_foreach (e, em->events)
1103       unserialize (m, unserialize_elog_event, em, e);
1104   }
1105 }
1106
1107 /*
1108  * fd.io coding-style-patch-verification: ON
1109  *
1110  * Local Variables:
1111  * eval: (c-set-style "gnu")
1112  * End:
1113  */