1 /* 2 * Copyright 2008, Ingo Weinhold, ingo_weinhold@gmx.de. 3 * Copyright 2008, Axel Dörfler, axeld@pinc-software.de. 4 * Distributed under the terms of the MIT License. 5 */ 6 7 8 #include <tracing.h> 9 10 #include <stdarg.h> 11 #include <stdlib.h> 12 13 #include <arch/debug.h> 14 #include <debug.h> 15 #include <elf.h> 16 #include <int.h> 17 #include <kernel.h> 18 #include <team.h> 19 #include <thread.h> 20 #include <util/AutoLock.h> 21 22 23 struct tracing_stack_trace { 24 int32 depth; 25 addr_t return_addresses[0]; 26 }; 27 28 29 #if ENABLE_TRACING 30 31 //#define TRACE_TRACING 32 #ifdef TRACE_TRACING 33 # define TRACE(x) dprintf_no_syslog x 34 #else 35 # define TRACE(x) ; 36 #endif 37 38 39 enum { 40 WRAP_ENTRY = 0x01, 41 ENTRY_INITIALIZED = 0x02, 42 BUFFER_ENTRY = 0x04, 43 FILTER_MATCH = 0x08 44 }; 45 46 47 static const size_t kTraceOutputBufferSize = 10240; 48 static const size_t kBufferSize = MAX_TRACE_SIZE / 4; 49 50 static trace_entry* sBuffer; 51 static trace_entry* sFirstEntry; 52 static trace_entry* sAfterLastEntry; 53 static uint32 sEntries; 54 static uint32 sWritten; 55 static spinlock sLock; 56 static char* sTraceOutputBuffer; 57 58 59 static trace_entry* 60 next_entry(trace_entry* entry) 61 { 62 entry += entry->size; 63 if ((entry->flags & WRAP_ENTRY) != 0) 64 entry = sBuffer; 65 66 if (entry == sAfterLastEntry) 67 return NULL; 68 69 return entry; 70 } 71 72 73 static trace_entry* 74 previous_entry(trace_entry* entry) 75 { 76 if (entry == sFirstEntry) 77 return NULL; 78 79 if (entry == sBuffer) { 80 // beginning of buffer -- previous entry is a wrap entry 81 entry = sBuffer + kBufferSize - entry->previous_size; 82 } 83 84 return entry - entry->previous_size; 85 } 86 87 88 static bool 89 free_first_entry() 90 { 91 TRACE((" skip start %p, %lu*4 bytes\n", sFirstEntry, sFirstEntry->size)); 92 93 trace_entry* newFirst = next_entry(sFirstEntry); 94 95 if (sFirstEntry->flags & BUFFER_ENTRY) { 96 // a buffer entry -- just skip it 97 } else if (sFirstEntry->flags & ENTRY_INITIALIZED) { 98 // fully initialized TraceEntry -- destroy it 99 ((TraceEntry*)sFirstEntry)->~TraceEntry(); 100 sEntries--; 101 } else { 102 // Not fully initialized TraceEntry. We can't free it, since 103 // then it's constructor might still write into the memory and 104 // overwrite data of the entry we're going to allocate. 105 // We can't do anything until this entry can be discarded. 106 return false; 107 } 108 109 if (newFirst == NULL) { 110 // everything is freed -- that practically this can't happen, if 111 // the buffer is large enough to hold three max-sized entries 112 sFirstEntry = sAfterLastEntry = sBuffer; 113 TRACE(("free_first_entry(): all entries freed!\n")); 114 } else 115 sFirstEntry = newFirst; 116 117 return true; 118 } 119 120 121 /*! Makes sure we have needed * 4 bytes of memory at sAfterLastEntry. 122 Returns \c false, if unable to free that much. 123 */ 124 static bool 125 make_space(size_t needed) 126 { 127 // we need space for sAfterLastEntry, too (in case we need to wrap around 128 // later) 129 needed++; 130 131 // If there's not enough space (free or occupied) after sAfterLastEntry, 132 // we free all entries in that region and wrap around. 133 if (sAfterLastEntry + needed > sBuffer + kBufferSize) { 134 TRACE(("make_space(%lu), wrapping around: after last: %p\n", needed, 135 sAfterLastEntry)); 136 137 // Free all entries after sAfterLastEntry and one more at the beginning 138 // of the buffer. 139 while (sFirstEntry > sAfterLastEntry) { 140 if (!free_first_entry()) 141 return false; 142 } 143 if (sAfterLastEntry != sBuffer && !free_first_entry()) 144 return false; 145 146 // just in case free_first_entry() freed the very last existing entry 147 if (sAfterLastEntry == sBuffer) 148 return true; 149 150 // mark as wrap entry and actually wrap around 151 trace_entry* wrapEntry = sAfterLastEntry; 152 wrapEntry->size = 0; 153 wrapEntry->flags = WRAP_ENTRY; 154 sAfterLastEntry = sBuffer; 155 sAfterLastEntry->previous_size = sBuffer + kBufferSize - wrapEntry; 156 } 157 158 if (sFirstEntry <= sAfterLastEntry) { 159 // buffer is empty or the space after sAfterLastEntry is unoccupied 160 return true; 161 } 162 163 // free the first entries, until there's enough space 164 size_t space = sFirstEntry - sAfterLastEntry; 165 166 if (space < needed) { 167 TRACE(("make_space(%lu), left %ld\n", needed, space)); 168 } 169 170 while (space < needed) { 171 space += sFirstEntry->size; 172 173 if (!free_first_entry()) 174 return false; 175 } 176 177 TRACE((" out: start %p, entries %ld\n", sFirstEntry, sEntries)); 178 179 return true; 180 } 181 182 183 static trace_entry* 184 allocate_entry(size_t size, uint16 flags) 185 { 186 if (sAfterLastEntry == NULL || size == 0 || size >= 65532) 187 return NULL; 188 189 InterruptsSpinLocker _(sLock); 190 191 size = (size + 3) >> 2; 192 // 4 byte aligned, don't store the lower 2 bits 193 194 TRACE(("allocate_entry(%lu), start %p, end %p, buffer %p\n", size * 4, 195 sFirstEntry, sAfterLastEntry, sBuffer)); 196 197 if (!make_space(size)) 198 return NULL; 199 200 trace_entry* entry = sAfterLastEntry; 201 entry->size = size; 202 entry->flags = flags; 203 sAfterLastEntry += size; 204 sAfterLastEntry->previous_size = size; 205 206 if (!(flags & BUFFER_ENTRY)) 207 sEntries++; 208 209 TRACE((" entry: %p, end %p, start %p, entries %ld\n", entry, 210 sAfterLastEntry, sFirstEntry, sEntries)); 211 212 return entry; 213 } 214 215 216 #endif // ENABLE_TRACING 217 218 219 // #pragma mark - 220 221 222 TraceOutput::TraceOutput(char* buffer, size_t bufferSize, uint32 flags) 223 : fBuffer(buffer), 224 fCapacity(bufferSize), 225 fFlags(flags) 226 { 227 Clear(); 228 } 229 230 231 void 232 TraceOutput::Clear() 233 { 234 if (fCapacity > 0) 235 fBuffer[0] = '\0'; 236 fSize = 0; 237 } 238 239 240 void 241 TraceOutput::Print(const char* format,...) 242 { 243 #if ENABLE_TRACING 244 if (IsFull()) 245 return; 246 247 va_list args; 248 va_start(args, format); 249 fSize += vsnprintf(fBuffer + fSize, fCapacity - fSize, format, args); 250 va_end(args); 251 #endif 252 } 253 254 255 void 256 TraceOutput::PrintStackTrace(tracing_stack_trace* stackTrace) 257 { 258 #if ENABLE_TRACING 259 if (stackTrace == NULL || stackTrace->depth <= 0) 260 return; 261 262 for (int32 i = 0; i < stackTrace->depth; i++) { 263 addr_t address = stackTrace->return_addresses[i]; 264 265 const char* symbol; 266 const char* imageName; 267 bool exactMatch; 268 addr_t baseAddress; 269 270 if (elf_debug_lookup_symbol_address(address, &baseAddress, &symbol, 271 &imageName, &exactMatch) == B_OK) { 272 Print(" %p %s + 0x%lx (%s)%s\n", (void*)address, symbol, 273 address - baseAddress, imageName, 274 exactMatch ? "" : " (nearest)"); 275 } else 276 Print(" %p\n", (void*)address); 277 } 278 #endif 279 } 280 281 282 void 283 TraceOutput::SetLastEntryTime(bigtime_t time) 284 { 285 fLastEntryTime = time; 286 } 287 288 289 bigtime_t 290 TraceOutput::LastEntryTime() const 291 { 292 return fLastEntryTime; 293 } 294 295 296 // #pragma mark - 297 298 299 TraceEntry::TraceEntry() 300 { 301 } 302 303 304 TraceEntry::~TraceEntry() 305 { 306 } 307 308 309 void 310 TraceEntry::Dump(TraceOutput& out) 311 { 312 #if ENABLE_TRACING 313 // to be overridden by subclasses 314 out.Print("ENTRY %p", this); 315 #endif 316 } 317 318 319 void 320 TraceEntry::DumpStackTrace(TraceOutput& out) 321 { 322 } 323 324 325 void 326 TraceEntry::Initialized() 327 { 328 #if ENABLE_TRACING 329 flags |= ENTRY_INITIALIZED; 330 sWritten++; 331 #endif 332 } 333 334 335 void* 336 TraceEntry::operator new(size_t size, const std::nothrow_t&) throw() 337 { 338 #if ENABLE_TRACING 339 return allocate_entry(size, 0); 340 #endif 341 return NULL; 342 } 343 344 345 // #pragma mark - 346 347 348 AbstractTraceEntry::AbstractTraceEntry() 349 { 350 struct thread* thread = thread_get_current_thread(); 351 if (thread != NULL) { 352 fThread = thread->id; 353 if (thread->team) 354 fTeam = thread->team->id; 355 } 356 fTime = system_time(); 357 } 358 359 AbstractTraceEntry::~AbstractTraceEntry() 360 { 361 } 362 363 364 void 365 AbstractTraceEntry::Dump(TraceOutput& out) 366 { 367 bigtime_t time = (out.Flags() & TRACE_OUTPUT_DIFF_TIME) 368 ? fTime - out.LastEntryTime() 369 : fTime; 370 371 if (out.Flags() & TRACE_OUTPUT_TEAM_ID) 372 out.Print("[%6ld:%6ld] %10Ld: ", fThread, fTeam, time); 373 else 374 out.Print("[%6ld] %10Ld: ", fThread, time); 375 376 AddDump(out); 377 378 out.SetLastEntryTime(fTime); 379 } 380 381 382 void 383 AbstractTraceEntry::AddDump(TraceOutput& out) 384 { 385 } 386 387 388 // #pragma mark - 389 390 391 #if ENABLE_TRACING 392 393 class KernelTraceEntry : public AbstractTraceEntry { 394 public: 395 KernelTraceEntry(const char* message) 396 { 397 fMessage = alloc_tracing_buffer_strcpy(message, 256, false); 398 399 Initialized(); 400 } 401 402 virtual void AddDump(TraceOutput& out) 403 { 404 out.Print("kern: %s", fMessage); 405 } 406 407 private: 408 char* fMessage; 409 }; 410 411 412 class UserTraceEntry : public AbstractTraceEntry { 413 public: 414 UserTraceEntry(const char* message) 415 { 416 fMessage = alloc_tracing_buffer_strcpy(message, 256, true); 417 418 Initialized(); 419 } 420 421 virtual void AddDump(TraceOutput& out) 422 { 423 out.Print("user: %s", fMessage); 424 } 425 426 private: 427 char* fMessage; 428 }; 429 430 #endif // ENABLE_TRACING 431 432 433 // #pragma mark - trace filters 434 435 436 TraceFilter::~TraceFilter() 437 { 438 } 439 440 441 bool 442 TraceFilter::Filter(const TraceEntry* entry, LazyTraceOutput& out) 443 { 444 return false; 445 } 446 447 448 449 class ThreadTraceFilter : public TraceFilter { 450 public: 451 virtual bool Filter(const TraceEntry* _entry, LazyTraceOutput& out) 452 { 453 const AbstractTraceEntry* entry 454 = dynamic_cast<const AbstractTraceEntry*>(_entry); 455 return (entry != NULL && entry->Thread() == fThread); 456 } 457 }; 458 459 460 class TeamTraceFilter : public TraceFilter { 461 public: 462 virtual bool Filter(const TraceEntry* _entry, LazyTraceOutput& out) 463 { 464 const AbstractTraceEntry* entry 465 = dynamic_cast<const AbstractTraceEntry*>(_entry); 466 return (entry != NULL && entry->Team() == fTeam); 467 } 468 }; 469 470 471 class PatternTraceFilter : public TraceFilter { 472 public: 473 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 474 { 475 return strstr(out.DumpEntry(entry), fString) != NULL; 476 } 477 }; 478 479 480 class DecimalPatternTraceFilter : public TraceFilter { 481 public: 482 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 483 { 484 // TODO: this is *very* slow 485 char buffer[64]; 486 snprintf(buffer, sizeof(buffer), "%Ld", fValue); 487 return strstr(out.DumpEntry(entry), buffer) != NULL; 488 } 489 }; 490 491 class HexPatternTraceFilter : public TraceFilter { 492 public: 493 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 494 { 495 // TODO: this is *very* slow 496 char buffer[64]; 497 snprintf(buffer, sizeof(buffer), "%Lx", fValue); 498 return strstr(out.DumpEntry(entry), buffer) != NULL; 499 } 500 }; 501 502 class StringPatternTraceFilter : public TraceFilter { 503 public: 504 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 505 { 506 if (IS_KERNEL_ADDRESS(fValue)) 507 return strstr(out.DumpEntry(entry), (const char*)fValue) != NULL; 508 509 // TODO: this is *very* slow 510 char buffer[64]; 511 user_strlcpy(buffer, (const char*)fValue, sizeof(buffer)); 512 return strstr(out.DumpEntry(entry), buffer) != NULL; 513 } 514 }; 515 516 class NotTraceFilter : public TraceFilter { 517 public: 518 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 519 { 520 return !fSubFilters.first->Filter(entry, out); 521 } 522 }; 523 524 525 class AndTraceFilter : public TraceFilter { 526 public: 527 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 528 { 529 return fSubFilters.first->Filter(entry, out) 530 && fSubFilters.second->Filter(entry, out); 531 } 532 }; 533 534 535 class OrTraceFilter : public TraceFilter { 536 public: 537 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 538 { 539 return fSubFilters.first->Filter(entry, out) 540 || fSubFilters.second->Filter(entry, out); 541 } 542 }; 543 544 545 class TraceFilterParser { 546 public: 547 static TraceFilterParser* Default() 548 { 549 return &sParser; 550 } 551 552 bool Parse(int argc, const char* const* argv) 553 { 554 fTokens = argv; 555 fTokenCount = argc; 556 fTokenIndex = 0; 557 fFilterCount = 0; 558 559 TraceFilter* filter = _ParseExpression(); 560 return fTokenIndex == fTokenCount && filter != NULL; 561 } 562 563 TraceFilter* Filter() 564 { 565 return &fFilters[0]; 566 } 567 568 private: 569 TraceFilter* _ParseExpression() 570 { 571 const char* token = _NextToken(); 572 if (!token) { 573 // unexpected end of expression 574 return NULL; 575 } 576 577 if (fFilterCount == MAX_FILTERS) { 578 // too many filters 579 return NULL; 580 } 581 582 if (token[0] == '#') { 583 TraceFilter* filter = new(&fFilters[fFilterCount++]) 584 PatternTraceFilter; 585 filter->fString = token + 1; 586 return filter; 587 } else if (token[0] == 'd' && token[1] == '#') { 588 TraceFilter* filter = new(&fFilters[fFilterCount++]) 589 DecimalPatternTraceFilter; 590 filter->fValue = parse_expression(token + 2); 591 return filter; 592 } else if (token[0] == 'x' && token[1] == '#') { 593 TraceFilter* filter = new(&fFilters[fFilterCount++]) 594 HexPatternTraceFilter; 595 filter->fValue = parse_expression(token + 2); 596 return filter; 597 } else if (token[0] == 's' && token[1] == '#') { 598 TraceFilter* filter = new(&fFilters[fFilterCount++]) 599 StringPatternTraceFilter; 600 filter->fValue = parse_expression(token + 2); 601 return filter; 602 } else if (strcmp(token, "not") == 0) { 603 TraceFilter* filter = new(&fFilters[fFilterCount++]) NotTraceFilter; 604 if ((filter->fSubFilters.first = _ParseExpression()) != NULL) 605 return filter; 606 return NULL; 607 } else if (strcmp(token, "and") == 0) { 608 TraceFilter* filter = new(&fFilters[fFilterCount++]) AndTraceFilter; 609 if ((filter->fSubFilters.first = _ParseExpression()) != NULL 610 && (filter->fSubFilters.second = _ParseExpression()) != NULL) { 611 return filter; 612 } 613 return NULL; 614 } else if (strcmp(token, "or") == 0) { 615 TraceFilter* filter = new(&fFilters[fFilterCount++]) OrTraceFilter; 616 if ((filter->fSubFilters.first = _ParseExpression()) != NULL 617 && (filter->fSubFilters.second = _ParseExpression()) != NULL) { 618 return filter; 619 } 620 return NULL; 621 } else if (strcmp(token, "thread") == 0) { 622 const char* arg = _NextToken(); 623 if (arg == NULL) { 624 // unexpected end of expression 625 return NULL; 626 } 627 628 TraceFilter* filter = new(&fFilters[fFilterCount++]) 629 ThreadTraceFilter; 630 filter->fThread = strtol(arg, NULL, 0); 631 return filter; 632 } else if (strcmp(token, "team") == 0) { 633 const char* arg = _NextToken(); 634 if (arg == NULL) { 635 // unexpected end of expression 636 return NULL; 637 } 638 639 TraceFilter* filter = new(&fFilters[fFilterCount++]) 640 TeamTraceFilter; 641 filter->fTeam = strtol(arg, NULL, 0); 642 return filter; 643 } else { 644 // invalid token 645 return NULL; 646 } 647 } 648 649 const char* _CurrentToken() const 650 { 651 if (fTokenIndex >= 1 && fTokenIndex <= fTokenCount) 652 return fTokens[fTokenIndex - 1]; 653 return NULL; 654 } 655 656 const char* _NextToken() 657 { 658 if (fTokenIndex >= fTokenCount) 659 return NULL; 660 return fTokens[fTokenIndex++]; 661 } 662 663 private: 664 enum { MAX_FILTERS = 32 }; 665 666 const char* const* fTokens; 667 int fTokenCount; 668 int fTokenIndex; 669 TraceFilter fFilters[MAX_FILTERS]; 670 int fFilterCount; 671 672 static TraceFilterParser sParser; 673 }; 674 675 676 TraceFilterParser TraceFilterParser::sParser; 677 678 679 // #pragma mark - 680 681 682 #if ENABLE_TRACING 683 684 685 class TraceEntryIterator { 686 public: 687 TraceEntryIterator() 688 : 689 fEntry(NULL), 690 fIndex(0) 691 { 692 } 693 694 void Reset() 695 { 696 fEntry = NULL; 697 fIndex = 0; 698 } 699 700 int32 Index() const 701 { 702 return fIndex; 703 } 704 705 TraceEntry* Current() const 706 { 707 return (TraceEntry*)fEntry; 708 } 709 710 TraceEntry* Next() 711 { 712 if (fIndex == 0) { 713 fEntry = _NextNonBufferEntry(sFirstEntry); 714 fIndex = 1; 715 } else if (fEntry != NULL) { 716 fEntry = _NextNonBufferEntry(next_entry(fEntry)); 717 fIndex++; 718 } 719 720 return Current(); 721 } 722 723 TraceEntry* Previous() 724 { 725 if (fIndex == (int32)sEntries + 1) 726 fEntry = sAfterLastEntry; 727 728 if (fEntry != NULL) { 729 fEntry = _PreviousNonBufferEntry(previous_entry(fEntry)); 730 fIndex--; 731 } 732 733 return Current(); 734 } 735 736 TraceEntry* MoveTo(int32 index) 737 { 738 if (index == fIndex) 739 return Current(); 740 741 if (index <= 0 || index > (int32)sEntries) { 742 fIndex = (index <= 0 ? 0 : sEntries + 1); 743 fEntry = NULL; 744 return NULL; 745 } 746 747 // get the shortest iteration path 748 int32 distance = index - fIndex; 749 int32 direction = distance < 0 ? -1 : 1; 750 distance *= direction; 751 752 if (index < distance) { 753 distance = index; 754 direction = 1; 755 fEntry = NULL; 756 fIndex = 0; 757 } 758 if ((int32)sEntries + 1 - fIndex < distance) { 759 distance = sEntries + 1 - fIndex; 760 direction = -1; 761 fEntry = NULL; 762 fIndex = sEntries + 1; 763 } 764 765 // iterate to the index 766 if (direction < 0) { 767 while (fIndex != index) 768 Previous(); 769 } else { 770 while (fIndex != index) 771 Next(); 772 } 773 774 return Current(); 775 } 776 777 private: 778 trace_entry* _NextNonBufferEntry(trace_entry* entry) 779 { 780 while (entry != NULL && (entry->flags & BUFFER_ENTRY) != 0) 781 entry = next_entry(entry); 782 783 return entry; 784 } 785 786 trace_entry* _PreviousNonBufferEntry(trace_entry* entry) 787 { 788 while (entry != NULL && (entry->flags & BUFFER_ENTRY) != 0) 789 entry = previous_entry(entry); 790 791 return entry; 792 } 793 794 private: 795 trace_entry* fEntry; 796 int32 fIndex; 797 }; 798 799 800 int 801 dump_tracing_internal(int argc, char** argv, WrapperTraceFilter* wrapperFilter) 802 { 803 int argi = 1; 804 805 // variables in which we store our state to be continuable 806 static int32 _previousCount = 0; 807 static bool _previousHasFilter = false; 808 static bool _previousPrintStackTrace = false; 809 static int32 _previousMaxToCheck = 0; 810 static int32 _previousFirstChecked = 1; 811 static int32 _previousLastChecked = -1; 812 static int32 _previousDirection = 1; 813 static uint32 _previousWritten = 0; 814 static uint32 _previousEntries = 0; 815 static uint32 _previousOutputFlags = 0; 816 static TraceEntryIterator iterator; 817 818 819 // Note: start and index are Pascal-like indices (i.e. in [1, sEntries]). 820 int32 start = 0; // special index: print the last count entries 821 int32 count = 0; 822 int32 maxToCheck = 0; 823 int32 cont = 0; 824 825 bool hasFilter = false; 826 bool printStackTrace = false; 827 828 uint32 outputFlags = 0; 829 while (argi < argc) { 830 if (strcmp(argv[argi], "--difftime") == 0) { 831 outputFlags |= TRACE_OUTPUT_DIFF_TIME; 832 argi++; 833 } else if (strcmp(argv[argi], "--printteam") == 0) { 834 outputFlags |= TRACE_OUTPUT_TEAM_ID; 835 argi++; 836 } else if (strcmp(argv[argi], "--stacktrace") == 0) { 837 printStackTrace = true; 838 argi++; 839 } else 840 break; 841 } 842 843 if (argi < argc) { 844 if (strcmp(argv[argi], "forward") == 0) { 845 cont = 1; 846 argi++; 847 } else if (strcmp(argv[argi], "backward") == 0) { 848 cont = -1; 849 argi++; 850 } 851 } else 852 cont = _previousDirection; 853 854 if (cont != 0) { 855 if (argi < argc) { 856 print_debugger_command_usage(argv[0]); 857 return 0; 858 } 859 if (sWritten == 0 || sWritten != _previousWritten 860 || sEntries != _previousEntries) { 861 kprintf("Can't continue iteration. \"%s\" has not been invoked " 862 "before, or there were new entries written since the last " 863 "invocation.\n", argv[0]); 864 return 0; 865 } 866 } 867 868 // get start, count, maxToCheck 869 int32* params[3] = { &start, &count, &maxToCheck }; 870 for (int i = 0; i < 3 && !hasFilter && argi < argc; i++) { 871 if (strcmp(argv[argi], "filter") == 0) { 872 hasFilter = true; 873 argi++; 874 } else if (argv[argi][0] == '#') { 875 hasFilter = true; 876 } else { 877 *params[i] = parse_expression(argv[argi]); 878 argi++; 879 } 880 } 881 882 // filter specification 883 if (argi < argc) { 884 hasFilter = true; 885 if (strcmp(argv[argi], "filter") == 0) 886 argi++; 887 888 if (!TraceFilterParser::Default()->Parse(argc - argi, argv + argi)) { 889 print_debugger_command_usage(argv[0]); 890 return 0; 891 } 892 } 893 894 int32 direction; 895 int32 firstToCheck; 896 int32 lastToCheck; 897 898 if (cont != 0) { 899 // get values from the previous iteration 900 direction = cont; 901 count = _previousCount; 902 maxToCheck = _previousMaxToCheck; 903 hasFilter = _previousHasFilter; 904 outputFlags = _previousOutputFlags; 905 printStackTrace = _previousPrintStackTrace; 906 907 if (direction < 0) 908 start = _previousFirstChecked - 1; 909 else 910 start = _previousLastChecked + 1; 911 } else { 912 // defaults for count and maxToCheck 913 if (count == 0) 914 count = 30; 915 if (maxToCheck == 0 || !hasFilter) 916 maxToCheck = count; 917 else if (maxToCheck < 0) 918 maxToCheck = sEntries; 919 920 // determine iteration direction 921 direction = (start <= 0 || count < 0 ? -1 : 1); 922 923 // validate count and maxToCheck 924 if (count < 0) 925 count = -count; 926 if (maxToCheck < 0) 927 maxToCheck = -maxToCheck; 928 if (maxToCheck > (int32)sEntries) 929 maxToCheck = sEntries; 930 if (count > maxToCheck) 931 count = maxToCheck; 932 933 // validate start 934 if (start <= 0 || start > (int32)sEntries) 935 start = max_c(1, sEntries); 936 } 937 938 if (direction < 0) { 939 firstToCheck = max_c(1, start - maxToCheck + 1); 940 lastToCheck = start; 941 } else { 942 firstToCheck = start; 943 lastToCheck = min_c((int32)sEntries, start + maxToCheck - 1); 944 } 945 946 // reset the iterator, if something changed in the meantime 947 if (sWritten == 0 || sWritten != _previousWritten 948 || sEntries != _previousEntries) { 949 iterator.Reset(); 950 } 951 952 LazyTraceOutput out(sTraceOutputBuffer, kTraceOutputBufferSize, 953 outputFlags); 954 955 bool markedMatching = false; 956 int32 firstToDump = firstToCheck; 957 int32 lastToDump = lastToCheck; 958 959 TraceFilter* filter = NULL; 960 if (hasFilter) 961 filter = TraceFilterParser::Default()->Filter(); 962 963 if (wrapperFilter != NULL) { 964 wrapperFilter->Init(filter, direction, cont != 0); 965 filter = wrapperFilter; 966 } 967 968 if (direction < 0 && filter && lastToCheck - firstToCheck >= count) { 969 // iteration direction is backwards 970 markedMatching = true; 971 972 // From the last entry to check iterate backwards to check filter 973 // matches. 974 int32 matching = 0; 975 976 // move to the entry after the last entry to check 977 iterator.MoveTo(lastToCheck + 1); 978 979 // iterate backwards 980 firstToDump = -1; 981 lastToDump = -1; 982 while (iterator.Index() > firstToCheck) { 983 TraceEntry* entry = iterator.Previous(); 984 if ((entry->flags & ENTRY_INITIALIZED) != 0) { 985 out.Clear(); 986 if (filter->Filter(entry, out)) { 987 entry->flags |= FILTER_MATCH; 988 if (lastToDump == -1) 989 lastToDump = iterator.Index(); 990 firstToDump = iterator.Index(); 991 992 matching++; 993 if (matching >= count) 994 break; 995 } else 996 entry->flags &= ~FILTER_MATCH; 997 } 998 } 999 1000 firstToCheck = iterator.Index(); 1001 1002 // iterate to the previous entry, so that the next loop starts at the 1003 // right one 1004 iterator.Previous(); 1005 } 1006 1007 out.SetLastEntryTime(0); 1008 1009 // set the iterator to the entry before the first one to dump 1010 iterator.MoveTo(firstToDump - 1); 1011 1012 // dump the entries matching the filter in the range 1013 // [firstToDump, lastToDump] 1014 int32 dumped = 0; 1015 1016 while (TraceEntry* entry = iterator.Next()) { 1017 int32 index = iterator.Index(); 1018 if (index < firstToDump) 1019 continue; 1020 if (index > lastToDump || dumped >= count) { 1021 if (direction > 0) 1022 lastToCheck = index - 1; 1023 break; 1024 } 1025 1026 if ((entry->flags & ENTRY_INITIALIZED) != 0) { 1027 out.Clear(); 1028 if (filter && (markedMatching 1029 ? (entry->flags & FILTER_MATCH) == 0 1030 : !filter->Filter(entry, out))) { 1031 continue; 1032 } 1033 1034 // don't print trailing new line 1035 const char* dump = out.DumpEntry(entry); 1036 int len = strlen(dump); 1037 if (len > 0 && dump[len - 1] == '\n') 1038 len--; 1039 1040 kprintf("%5ld. %.*s\n", index, len, dump); 1041 1042 if (printStackTrace) { 1043 out.Clear(); 1044 entry->DumpStackTrace(out); 1045 if (out.Size() > 0) 1046 kputs(out.Buffer()); 1047 } 1048 } else if (!filter) 1049 kprintf("%5ld. ** uninitialized entry **\n", index); 1050 1051 dumped++; 1052 } 1053 1054 kprintf("printed %ld entries within range %ld to %ld (%ld of %ld total, " 1055 "%ld ever)\n", dumped, firstToCheck, lastToCheck, 1056 lastToCheck - firstToCheck + 1, sEntries, sWritten); 1057 1058 // store iteration state 1059 _previousCount = count; 1060 _previousMaxToCheck = maxToCheck; 1061 _previousHasFilter = hasFilter; 1062 _previousPrintStackTrace = printStackTrace; 1063 _previousFirstChecked = firstToCheck; 1064 _previousLastChecked = lastToCheck; 1065 _previousDirection = direction; 1066 _previousWritten = sWritten; 1067 _previousEntries = sEntries; 1068 _previousOutputFlags = outputFlags; 1069 1070 return cont != 0 ? B_KDEBUG_CONT : 0; 1071 } 1072 1073 1074 static int 1075 dump_tracing_command(int argc, char** argv) 1076 { 1077 return dump_tracing_internal(argc, argv, NULL); 1078 } 1079 1080 1081 #endif // ENABLE_TRACING 1082 1083 1084 extern "C" uint8* 1085 alloc_tracing_buffer(size_t size) 1086 { 1087 #if ENABLE_TRACING 1088 trace_entry* entry = allocate_entry(size + sizeof(trace_entry), 1089 BUFFER_ENTRY); 1090 if (entry == NULL) 1091 return NULL; 1092 1093 return (uint8*)(entry + 1); 1094 #else 1095 return NULL; 1096 #endif 1097 } 1098 1099 1100 uint8* 1101 alloc_tracing_buffer_memcpy(const void* source, size_t size, bool user) 1102 { 1103 if (user && !IS_USER_ADDRESS(source)) 1104 return NULL; 1105 1106 uint8* buffer = alloc_tracing_buffer(size); 1107 if (buffer == NULL) 1108 return NULL; 1109 1110 if (user) { 1111 if (user_memcpy(buffer, source, size) != B_OK) 1112 return NULL; 1113 } else 1114 memcpy(buffer, source, size); 1115 1116 return buffer; 1117 } 1118 1119 1120 char* 1121 alloc_tracing_buffer_strcpy(const char* source, size_t maxSize, bool user) 1122 { 1123 if (source == NULL || maxSize == 0) 1124 return NULL; 1125 1126 if (user && !IS_USER_ADDRESS(source)) 1127 return NULL; 1128 1129 // limit maxSize to the actual source string len 1130 if (user) { 1131 ssize_t size = user_strlcpy(NULL, source, 0); 1132 // there's no user_strnlen() 1133 if (size < 0) 1134 return 0; 1135 maxSize = min_c(maxSize, (size_t)size + 1); 1136 } else 1137 maxSize = strnlen(source, maxSize - 1) + 1; 1138 1139 char* buffer = (char*)alloc_tracing_buffer(maxSize); 1140 if (buffer == NULL) 1141 return NULL; 1142 1143 if (user) { 1144 if (user_strlcpy(buffer, source, maxSize) < B_OK) 1145 return NULL; 1146 } else 1147 strlcpy(buffer, source, maxSize); 1148 1149 return buffer; 1150 } 1151 1152 1153 tracing_stack_trace* 1154 capture_tracing_stack_trace(int32 maxCount, int32 skipFrames, bool userOnly) 1155 { 1156 #if ENABLE_TRACING 1157 // TODO: page_fault_exception() doesn't allow us to gracefully handle 1158 // a bad address in the stack trace, if interrupts are disabled. 1159 if (!are_interrupts_enabled()) 1160 return NULL; 1161 1162 tracing_stack_trace* stackTrace 1163 = (tracing_stack_trace*)alloc_tracing_buffer( 1164 sizeof(tracing_stack_trace) + maxCount * sizeof(addr_t)); 1165 1166 if (stackTrace != NULL) { 1167 stackTrace->depth = arch_debug_get_stack_trace( 1168 stackTrace->return_addresses, maxCount, skipFrames + 1, userOnly); 1169 } 1170 1171 return stackTrace; 1172 #else 1173 return NULL; 1174 #endif 1175 } 1176 1177 1178 int 1179 dump_tracing(int argc, char** argv, WrapperTraceFilter* wrapperFilter) 1180 { 1181 #if ENABLE_TRACING 1182 return dump_tracing_internal(argc, argv, wrapperFilter); 1183 #else 1184 return 0; 1185 #endif 1186 } 1187 1188 1189 extern "C" status_t 1190 tracing_init(void) 1191 { 1192 #if ENABLE_TRACING 1193 area_id area = create_area("tracing log", (void**)&sTraceOutputBuffer, 1194 B_ANY_KERNEL_ADDRESS, MAX_TRACE_SIZE + kTraceOutputBufferSize, 1195 B_FULL_LOCK, B_KERNEL_READ_AREA | B_KERNEL_WRITE_AREA); 1196 if (area < B_OK) 1197 return area; 1198 1199 sBuffer = (trace_entry*)(sTraceOutputBuffer + kTraceOutputBufferSize); 1200 sFirstEntry = sBuffer; 1201 sAfterLastEntry = sBuffer; 1202 1203 add_debugger_command_etc("traced", &dump_tracing_command, 1204 "Dump recorded trace entries", 1205 "[ \"--printteam\" ] [ \"--difftime\" ] (\"forward\" | \"backward\") " 1206 "| ([ <start> [ <count> [ <range> ] ] ] " 1207 "[ #<pattern> | (\"filter\" <filter>) ])\n" 1208 "Prints recorded trace entries. If \"backward\" or \"forward\" is\n" 1209 "specified, the command continues where the previous invocation left\n" 1210 "off, i.e. printing the previous respectively next entries (as many\n" 1211 "as printed before). In this case the command is continuable, that is\n" 1212 "afterwards entering an empty line in the debugger will reinvoke it.\n" 1213 "If no arguments are given, the command continues in the direction\n" 1214 "of the last invocation.\n" 1215 "\"--printteam\" enables printing the entries' team IDs.\n" 1216 "\"--difftime\" print difference times for all but the first entry.\n" 1217 "\"--stacktrace\" print stack traces for entries that captured one.\n" 1218 " <start> - The base index of the entries to print. Depending on\n" 1219 " whether the iteration direction is forward or\n" 1220 " backward this will be the first or last entry printed\n" 1221 " (potentially, if a filter is specified). The index of\n" 1222 " the first entry in the trace buffer is 1. If 0 is\n" 1223 " specified, the last <count> recorded entries are\n" 1224 " printed (iteration direction is backward). Defaults \n" 1225 " to 0.\n" 1226 " <count> - The number of entries to be printed. Defaults to 30.\n" 1227 " If negative, the -<count> entries before and\n" 1228 " including <start> will be printed.\n" 1229 " <range> - Only relevant if a filter is specified. Specifies the\n" 1230 " number of entries to be filtered -- depending on the\n" 1231 " iteration direction the entries before or after\n" 1232 " <start>. If more than <count> entries match the\n" 1233 " filter, only the first (forward) or last (backward)\n" 1234 " <count> matching entries will be printed. If 0 is\n" 1235 " specified <range> will be set to <count>. If -1,\n" 1236 " <range> will be set to the number of recorded\n" 1237 " entries.\n" 1238 " <pattern> - If specified only entries containing this string are\n" 1239 " printed.\n" 1240 " <filter> - If specified only entries matching this filter\n" 1241 " expression are printed. The expression can consist of\n" 1242 " prefix operators \"not\", \"and\", \"or\", and\n" 1243 " filters \"'thread' <thread>\" (matching entries\n" 1244 " with the given thread ID), \"'team' <team>\"\n" 1245 "(matching entries with the given team ID), and\n" 1246 " \"#<pattern>\" (matching entries containing the given\n" 1247 " string).\n", 0); 1248 #endif // ENABLE_TRACING 1249 return B_OK; 1250 } 1251 1252 1253 void 1254 ktrace_printf(const char *format, ...) 1255 { 1256 #if ENABLE_TRACING 1257 va_list list; 1258 va_start(list, format); 1259 1260 char buffer[256]; 1261 vsnprintf(buffer, sizeof(buffer), format, list); 1262 1263 va_end(list); 1264 1265 new(nothrow) KernelTraceEntry(buffer); 1266 #endif // ENABLE_TRACING 1267 } 1268 1269 1270 void 1271 _user_ktrace_output(const char *message) 1272 { 1273 #if ENABLE_TRACING 1274 new(nothrow) UserTraceEntry(message); 1275 #endif // ENABLE_TRACING 1276 } 1277 1278