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