kernel/fiasco/src/kern/tb_entry_output.cpp

   1 IMPLEMENTATION:
   2
   3 #include <cstdarg>
   4 #include <cstdio>
   5 #include <cstdlib>
   6 #include <cstring>
   7
   8 #include "config.h"
   9 #include "jdb_symbol.h"
  10 #include "jdb_tbuf_output.h"
  11 #include "jdb_util.h"
  12 #include "static_init.h"
  13 #include "tb_entry.h"
  14 #include "thread.h"
  15
  16 static __attribute__((format(printf, 3, 4)))
  17 void
  18 my_snprintf(char *&buf, int &maxlen, const char *format, ...)
  19 {
  20   int len;
  21   va_list list;
  22
  23   if (maxlen<=0)
  24     return;
  25
  26   va_start(list, format);
  27   len = vsnprintf(buf, maxlen, format, list);
  28   va_end(list);
  29
  30   if (len<0 || len>=maxlen)
  31     len = maxlen-1;
  32
  33   buf    += len;
  34   maxlen -= len;
  35 }
  36
  37
  38 // timeout => x.x{
  39 static
  40 void
  41 format_timeout(Mword us, char *&buf, int &maxlen)
  42 {
  43   if (us >= 1000000000)         // =>100s
  44     my_snprintf(buf, maxlen, ">99s");
  45   else if (us >= 10000000)      // >=10s
  46     my_snprintf(buf, maxlen, "%lds", us/1000000);
  47   else if (us >= 1000000)       // >=1s
  48     my_snprintf(buf, maxlen, "%ld.%lds", us/1000000, (us%1000000)/100000);
  49   else if (us >= 10000)         // 10ms
  50     my_snprintf(buf, maxlen, "%ldm", us/1000);
  51   else if (us >= 1000)          // 1ms
  52     my_snprintf(buf, maxlen, "%ld.%ldm", us/1000, (us%1000)/100);
  53   else
  54     my_snprintf(buf, maxlen, "%ld%c", us, Config::char_micro);
  55 }
  56
  57 template< typename T >
  58 static
  59 char const *
  60 get_ipc_type(T e)
  61 {
  62   switch (e->ipc_type())
  63     {
  64     case L4_obj_ref::Ipc_call:           return "call";
  65     case L4_obj_ref::Ipc_call_ipc:       return "call ipc";
  66     case L4_obj_ref::Ipc_send:           return "send";
  67     case L4_obj_ref::Ipc_recv:           return "recv";
  68     case L4_obj_ref::Ipc_send_and_wait:  return "snd wait";
  69     case L4_obj_ref::Ipc_reply_and_wait: return "repl";
  70     case L4_obj_ref::Ipc_wait:           return "wait";
  71     default:                             return "unk ipc";
  72     }
  73 }
  74
  75 static char const * const __tag_interpreter_strings_l4re[] = {
  76     "ds", // 0
  77     "name",
  78     "parent",
  79     "goos",
  80     "ma",
  81     "rm", // 5
  82     "ev",
  83   };
  84 static char const * const __tag_interpreter_strings_fiasco[] = {
  85     "Kirq",      // -1
  86     "Kpf",
  87     "Kpreempt",
  88     "Ksysexc",
  89     "Kexc",      // -5
  90     "Ksigma",
  91     0,
  92     "Kiopf",
  93     "Kcapfault",
  94     0,           // -10
  95     "Ktask",
  96     "Kthread",
  97     "Klog",
  98     "Ksched",
  99     "Kfactory",  // -15
 100     "Kvm",
 101     0,
 102     0,
 103     0,
 104     "Ksem",      // -20
 105     "Kmeta",
 106   };
 107
 108 static
 109 char const *
 110 tag_to_string(L4_msg_tag const &tag)
 111 {
 112   if (0x4000 <= tag.proto() && tag.proto() <= 0x4006)
 113     return __tag_interpreter_strings_l4re[tag.proto() - 0x4000];
 114   if (-21L <= tag.proto() && tag.proto() <= -1)
 115     return __tag_interpreter_strings_fiasco[-tag.proto() - 1];
 116   return 0;
 117 }
 118
 119 static
 120 void
 121 tag_interpreter_snprintf(char *&buf, int &maxlen, L4_msg_tag const &tag)
 122 {
 123   int len;
 124   char const *s;
 125
 126   if (maxlen<=0)
 127     return;
 128
 129   s = tag_to_string(tag);
 130   if (s)
 131     len = snprintf(buf, maxlen, "%s%04lx", s, tag.raw() & 0xffff);
 132   else
 133     len = snprintf(buf, maxlen, L4_PTR_FMT, tag.raw());
 134
 135   if (len<0 || len>=maxlen)
 136     len = maxlen-1;
 137
 138   buf    += len;
 139   maxlen -= len;
 140 }
 141
 142 // ipc / irq / shortcut success
 143 static
 144 unsigned
 145 formatter_ipc(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 146               char *buf, int maxlen)
 147 {
 148   Tb_entry_ipc *e = static_cast<Tb_entry_ipc*>(tb);
 149   unsigned char type = e->ipc_type();
 150   if (!type)
 151     type = L4_obj_ref::Ipc_call_ipc;
 152
 153   // ipc operation / shortcut succeeded/failed
 154   const char *m = get_ipc_type(e);
 155
 156   my_snprintf(buf, maxlen, "%s: ", (e->type()==Tbuf_ipc) ? "ipc" : "sc ");
 157   my_snprintf(buf, maxlen, "%s%-*s %s->",
 158       /*e->dst().next_period() ? "[NP] " :*/ "", tidlen, tidstr, m);
 159
 160   // print destination id
 161   if (e->dst().special())
 162     my_snprintf(buf, maxlen, "[C:INV] DID=%lx", e->dbg_id());
 163   else
 164     my_snprintf(buf, maxlen, "[C:%lx] DID=%lx", e->dst().raw(), e->dbg_id());
 165
 166   my_snprintf(buf, maxlen, " L=%lx", e->label());
 167
 168   // print mwords if have send part
 169   if (type & L4_obj_ref::Ipc_send)
 170     {
 171       my_snprintf(buf, maxlen, " [");
 172
 173       tag_interpreter_snprintf(buf, maxlen, e->tag());
 174
 175       my_snprintf(buf, maxlen, "] (" L4_PTR_FMT "," L4_PTR_FMT ")",
 176                                e->dword(0), e->dword(1));
 177     }
 178
 179   my_snprintf(buf, maxlen, " TO=");
 180   L4_timeout_pair to = e->timeout();
 181   if (type & L4_obj_ref::Ipc_send)
 182     {
 183       if (to.snd.is_absolute())
 184         {
 185           // absolute send timeout
 186           Unsigned64 end = 0; // FIXME: to.snd.microsecs_abs (e->kclock());
 187           format_timeout((Mword)(end > e->kclock() ? end-e->kclock() : 0),
 188                          buf, maxlen);
 189         }
 190       else
 191         {
 192           // relative send timeout
 193           if (to.snd.is_never())
 194             my_snprintf(buf, maxlen, "INF");
 195           else if (to.snd.is_zero())
 196             my_snprintf(buf, maxlen, "0");
 197           else
 198             format_timeout((Mword)to.snd.microsecs_rel(0), buf, maxlen);
 199         }
 200     }
 201   if (type & L4_obj_ref::Ipc_send
 202       && type & L4_obj_ref::Ipc_recv)
 203     my_snprintf(buf, maxlen, "/");
 204   if (type & L4_obj_ref::Ipc_recv)
 205     {
 206       if (to.rcv.is_absolute())
 207         {
 208           // absolute receive timeout
 209           Unsigned64 end = 0; // FIXME: to.rcv.microsecs_abs (e->kclock());
 210           format_timeout((Mword)(end > e->kclock() ? end-e->kclock() : 0),
 211                          buf, maxlen);
 212         }
 213       else
 214         {
 215           // relative receive timeout
 216           if (to.rcv.is_never())
 217             my_snprintf(buf, maxlen, "INF");
 218           else if (to.rcv.is_zero())
 219             my_snprintf(buf, maxlen, "0");
 220           else
 221             format_timeout((Mword)to.rcv.microsecs_rel(0), buf, maxlen);
 222         }
 223     }
 224
 225   return maxlen;
 226 }
 227
 228 // result of ipc
 229 static
 230 unsigned
 231 formatter_ipc_res(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 232                   char *buf, int maxlen)
 233 {
 234   Tb_entry_ipc_res *e = static_cast<Tb_entry_ipc_res*>(tb);
 235   L4_error error;
 236   if (e->tag().has_error())
 237     error = e->result();
 238   else
 239     error = L4_error::None;
 240   const char *m = "answ"; //get_ipc_type(e);
 241
 242   my_snprintf(buf, maxlen, "     %s%-*s %s [%08lx] L=%lx err=%lx (%s) (%lx,%lx) ",
 243                             e->is_np() ? "[np] " : "",
 244                             tidlen, tidstr, m, e->tag().raw(), e->from(),
 245                             error.raw(), error.str_error(), e->dword(0),
 246                             e->dword(1));
 247
 248   return maxlen;
 249 }
 250
 251 IMPLEMENTATION:
 252
 253 #include "kobject_dbg.h"
 254
 255 // pagefault
 256 static
 257 unsigned
 258 formatter_pf(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 259              char *buf, int maxlen)
 260 {
 261   Tb_entry_pf *e = static_cast<Tb_entry_pf*>(tb);
 262   char ip_buf[32];
 263
 264   snprintf(ip_buf, sizeof(ip_buf), L4_PTR_FMT, e->ip());
 265   my_snprintf(buf, maxlen, "pf:  %-*s pfa=" L4_PTR_FMT " ip=%s (%c%c) spc=%p",
 266       tidlen, tidstr, e->pfa(), e->ip() ? ip_buf : "unknown",
 267       !PF::is_read_error(e->error()) ? (e->error() & 4 ? 'w' : 'W')
 268                                      : (e->error() & 4 ? 'r' : 'R'),
 269       !PF::is_translation_error(e->error()) ? 'p' : '-',
 270       e->space());
 271
 272   return maxlen;
 273 }
 274
 275 // pagefault result
 276 static
 277 unsigned
 278 formatter_pf_res(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 279                  char *buf, int maxlen)
 280 {
 281   Tb_entry_pf_res *e = static_cast<Tb_entry_pf_res*>(tb);
 282
 283   // e->ret contains only an error code
 284   // e->err contains only up to 3 dwords
 285   my_snprintf(buf, maxlen, "     %-*s pfa=" L4_PTR_FMT " dope=%02lx (%s%s) "
 286                 "err=%04lx (%s%s)",
 287               tidlen, tidstr, e->pfa(),
 288               e->ret().raw(), e->ret().error() ? "L4_IPC_" : "",
 289               e->ret().str_error(),
 290               e->err().raw(), e->err().error() ? "L4_IPC_" : "",
 291               e->err().str_error());
 292
 293   return maxlen;
 294 }
 295
 296 // kernel event (enter_kdebug("*..."))
 297 static
 298 unsigned
 299 formatter_ke(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 300              char *buf, int maxlen)
 301 {
 302   Tb_entry_ke *e = static_cast<Tb_entry_ke*>(tb);
 303   char ip_buf[32];
 304
 305   snprintf(ip_buf, sizeof(ip_buf), " @ " L4_PTR_FMT, e->ip());
 306   my_snprintf(buf, maxlen, "ke:  %-*s \"%s\"%s",
 307       tidlen, tidstr, e->msg(), e->ip() ? ip_buf : "");
 308
 309   return maxlen;
 310 }
 311
 312 // kernel event (enter_kdebug_verb("*+...", val1, val2, val3))
 313 static
 314 unsigned
 315 formatter_ke_reg(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 316                  char *buf, int maxlen)
 317 {
 318   Tb_entry_ke_reg *e = static_cast<Tb_entry_ke_reg*>(tb);
 319
 320   char ip_buf[32];
 321   snprintf(ip_buf, sizeof(ip_buf), " @ " L4_PTR_FMT, e->ip());
 322   my_snprintf(buf, maxlen, "ke:  %-*s \"%s\" "
 323       L4_PTR_FMT " " L4_PTR_FMT " " L4_PTR_FMT "%s",
 324       tidlen, tidstr, e->msg(), e->val1(), e->val2(), e->val3(),
 325       e->ip() ? ip_buf : "");
 326
 327   return maxlen;
 328 }
 329
 330
 331 // breakpoint
 332 static
 333 unsigned
 334 formatter_bp(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 335              char *buf, int maxlen)
 336 {
 337   Tb_entry_bp *e = static_cast<Tb_entry_bp*>(tb);
 338
 339   my_snprintf(buf, maxlen, "b%c:  %-*s @ " L4_PTR_FMT " ",
 340       "iwpa"[e->mode() & 3], tidlen, tidstr, e->ip());
 341   switch (e->mode() & 3)
 342     {
 343     case 1:
 344     case 3:
 345       switch (e->len())
 346         {
 347         case 1:
 348           my_snprintf(buf, maxlen, "[" L4_PTR_FMT "]=%02lx",
 349                       e->addr(), e->value());
 350           break;
 351         case 2:
 352           my_snprintf(buf, maxlen, "[" L4_PTR_FMT "]=%04lx",
 353                       e->addr(), e->value());
 354           break;
 355         case 4:
 356           my_snprintf(buf, maxlen, "[" L4_PTR_FMT "]=" L4_PTR_FMT,
 357                       e->addr(), e->value());
 358           break;
 359         }
 360       break;
 361     case 2:
 362       my_snprintf(buf, maxlen, "[" L4_PTR_FMT "]", e->addr());
 363       break;
 364     }
 365
 366   return maxlen;
 367 }
 368
 369 // context switch
 370 static
 371 unsigned
 372 formatter_ctx_switch(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 373                      char *buf, int maxlen)
 374 {
 375   char symstr[24], spcstr[16] = "";
 376   Tb_entry_ctx_sw *e = static_cast<Tb_entry_ctx_sw*>(tb);
 377
 378   Context   *sctx    = 0;
 379   Mword sctxid = ~0UL;
 380   Mword dst;
 381   Mword dst_orig;
 382
 383   sctx = e->from_sched()->context();
 384   sctxid = static_cast<Thread*>(sctx)->dbg_id();
 385
 386   dst = static_cast<Thread const *>(e->dst())->dbg_id();
 387   dst_orig = static_cast<Thread const *>(e->dst_orig())->dbg_id();
 388
 389   Address addr       = e->kernel_ip();
 390
 391   if (!Jdb_symbol::match_addr_to_symbol_fuzzy(&addr, 0 /*kernel*/,
 392                                               symstr, sizeof(symstr)))
 393     snprintf(symstr, sizeof(symstr), L4_PTR_FMT, e->kernel_ip());
 394
 395   my_snprintf(buf, maxlen, "     %-*s%s '%02lx",
 396       tidlen, tidstr, spcstr, e->from_prio());
 397   if (sctx != e->ctx())
 398     my_snprintf(buf, maxlen, "(%lx)", sctxid);
 399
 400   my_snprintf(buf, maxlen, " ==> %lx ", dst);
 401
 402   if (dst != dst_orig || e->lock_cnt())
 403     my_snprintf(buf, maxlen, "(");
 404
 405   if (dst != dst_orig)
 406     my_snprintf(buf, maxlen, "want %lx",
 407         dst_orig);
 408
 409   if (dst != dst_orig && e->lock_cnt())
 410     my_snprintf(buf, maxlen, " ");
 411
 412   if (e->lock_cnt())
 413     my_snprintf(buf, maxlen, "lck %ld", e->lock_cnt());
 414
 415   if (dst != dst_orig || e->lock_cnt())
 416     my_snprintf(buf, maxlen, ") ");
 417
 418   my_snprintf(buf, maxlen, " krnl %s", symstr);
 419
 420   return maxlen;
 421 }
 422
 423
 424 // trap
 425 static
 426 unsigned
 427 formatter_trap(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 428                char *buf, int maxlen)
 429 {
 430   Tb_entry_trap *e = static_cast<Tb_entry_trap*>(tb);
 431
 432   if (!e->cs())
 433     my_snprintf(buf, maxlen, "#%02x: %-*s err=%08x @ " L4_PTR_FMT,
 434                 e->trapno(), tidlen, tidstr, e->error(), e->ip());
 435   else
 436     my_snprintf(buf, maxlen,
 437                 e->trapno() == 14
 438                   ? "#%02x: %-*s err=%04x @ " L4_PTR_FMT
 439                     " cs=%04x sp=" L4_PTR_FMT " cr2=" L4_PTR_FMT
 440                   : "#%02x: %-*s err=%04x @ " L4_PTR_FMT
 441                     " cs=%04x sp=" L4_PTR_FMT " eax=" L4_PTR_FMT,
 442                 e->trapno(),
 443                 tidlen, tidstr, e->error(), e->ip(), e->cs(), e->sp(),
 444                 e->trapno() == 14 ? e->cr2() : e->eax());
 445
 446   return maxlen;
 447 }
 448
 449 // sched
 450 static
 451 unsigned
 452 formatter_sched(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 453                 char *buf, int maxlen)
 454 {
 455   Tb_entry_sched *e = static_cast<Tb_entry_sched*>(tb);
 456   Thread const *_t = static_cast<Thread const *>(e->owner());
 457   Mword t = ~0UL;
 458   if (Jdb_util::is_mapped(_t))
 459     t = _t->dbg_id();
 460
 461
 462   my_snprintf(buf, maxlen,
 463             "%-*s (ts %s) owner:%lx id:%2x, prio:%2x, left:%6ld/%-6lu",
 464                tidlen, tidstr,
 465                e->mode() == 0 ? "save" :
 466                e->mode() == 1 ? "load" :
 467                e->mode() == 2 ? "invl" : "????",
 468                t,
 469                e->id(), e->prio(), e->left(), e->quantum());
 470
 471   return maxlen;
 472 }
 473
 474 // preemption
 475 static
 476 unsigned
 477 formatter_preemption(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 478                      char *buf, int maxlen)
 479 {
 480   Tb_entry_preemption *e = static_cast<Tb_entry_preemption*>(tb);
 481   Mword t = e->preempter();
 482
 483   my_snprintf(buf, maxlen,
 484              "pre: %-*s sent to %lx",
 485              tidlen, tidstr, t);
 486
 487   return maxlen;
 488 }
 489
 490 // kernel event log binary data
 491 static
 492 unsigned
 493 formatter_ke_bin(Tb_entry *tb, const char *tidstr, unsigned tidlen,
 494                  char *buf, int maxlen)
 495 {
 496   Tb_entry_ke_bin *e = static_cast<Tb_entry_ke_bin*>(tb);
 497   char ip_buf[32];
 498
 499   snprintf(ip_buf, sizeof(ip_buf), " @ " L4_PTR_FMT, e->ip());
 500   my_snprintf(buf, maxlen, "ke:  %-*s BINDATA %s",
 501               tidlen, tidstr, e->ip() ? ip_buf : "");
 502
 503   return maxlen;
 504 }
 505
 506 STATIC_INITIALIZER(init_formatters);
 507
 508 // register all available format functions
 509 static FIASCO_INIT
 510 void
 511 init_formatters()
 512 {
 513   Jdb_tbuf_output::register_ff(Tbuf_pf, formatter_pf);
 514   Jdb_tbuf_output::register_ff(Tbuf_pf_res, formatter_pf_res);
 515   Jdb_tbuf_output::register_ff(Tbuf_ipc, formatter_ipc);
 516   Jdb_tbuf_output::register_ff(Tbuf_ipc_res, formatter_ipc_res);
 517   Jdb_tbuf_output::register_ff(Tbuf_ke, formatter_ke);
 518   Jdb_tbuf_output::register_ff(Tbuf_ke_reg, formatter_ke_reg);
 519   Jdb_tbuf_output::register_ff(Tbuf_shortcut_succeeded, formatter_ipc);
 520   Jdb_tbuf_output::register_ff(Tbuf_context_switch, formatter_ctx_switch);
 521   Jdb_tbuf_output::register_ff(Tbuf_breakpoint, formatter_bp);
 522   Jdb_tbuf_output::register_ff(Tbuf_trap, formatter_trap);
 523   Jdb_tbuf_output::register_ff(Tbuf_sched, formatter_sched);
 524   Jdb_tbuf_output::register_ff(Tbuf_preemption, formatter_preemption);
 525   Jdb_tbuf_output::register_ff(Tbuf_ke_bin, formatter_ke_bin);
 526 }