1 /* 2 * Copyright 2008-2011, Ingo Weinhold, ingo_weinhold@gmx.de. 3 * Copyright 2008-2009, Axel Dörfler, axeld@pinc-software.de. 4 * Copyright 2012, Rene Gollent, rene@gollent.com. 5 * Distributed under the terms of the MIT License. 6 */ 7 8 9 #include <tracing.h> 10 11 #include <stdlib.h> 12 13 #include <algorithm> 14 15 #include <arch/debug.h> 16 #include <debug.h> 17 #include <debug_heap.h> 18 #include <elf.h> 19 #include <int.h> 20 #include <kernel.h> 21 #include <team.h> 22 #include <thread.h> 23 #include <util/AutoLock.h> 24 #include <vm/vm.h> 25 26 27 #if ENABLE_TRACING 28 29 //#define TRACE_TRACING 30 #ifdef TRACE_TRACING 31 # define TRACE(x) dprintf_no_syslog x 32 #else 33 # define TRACE(x) ; 34 #endif 35 36 37 enum { 38 WRAP_ENTRY = 0x01, 39 ENTRY_INITIALIZED = 0x02, 40 BUFFER_ENTRY = 0x04, 41 FILTER_MATCH = 0x08, 42 INVALID_ENTRY = 0x10, 43 CHECK_ENTRY = 0x20, 44 }; 45 46 47 static const size_t kTraceOutputBufferSize = 10240; 48 static const size_t kBufferSize = MAX_TRACE_SIZE / sizeof(trace_entry); 49 50 static const uint32 kMaxRecoveringErrorCount = 100; 51 static const addr_t kMetaDataBaseAddress = 32 * 1024 * 1024; 52 static const addr_t kMetaDataBaseEndAddress = 128 * 1024 * 1024; 53 static const addr_t kMetaDataAddressIncrement = 8 * 1024 * 1024; 54 static const uint32 kMetaDataMagic1 = 'Vali'; 55 static const uint32 kMetaDataMagic2 = 'dTra'; 56 static const uint32 kMetaDataMagic3 = 'cing'; 57 58 // the maximum we can address with the trace_entry::[previous_]size fields 59 static const size_t kMaxTracingEntryByteSize 60 = ((1 << 13) - 1) * sizeof(trace_entry); 61 62 63 struct TraceOutputPrint { 64 TraceOutputPrint(TraceOutput& output) 65 : 66 fOutput(output) 67 { 68 } 69 70 void operator()(const char* format,...) const 71 { 72 va_list args; 73 va_start(args, format); 74 fOutput.PrintArgs(format, args); 75 va_end(args); 76 } 77 78 private: 79 TraceOutput& fOutput; 80 }; 81 82 83 class TracingMetaData { 84 public: 85 static status_t Create(TracingMetaData*& _metaData); 86 87 inline bool Lock(); 88 inline void Unlock(); 89 90 inline trace_entry* FirstEntry() const; 91 inline trace_entry* AfterLastEntry() const; 92 93 inline uint32 Entries() const; 94 inline uint32 EntriesEver() const; 95 96 inline void IncrementEntriesEver(); 97 98 inline char* TraceOutputBuffer() const; 99 100 trace_entry* NextEntry(trace_entry* entry); 101 trace_entry* PreviousEntry(trace_entry* entry); 102 103 trace_entry* AllocateEntry(size_t size, uint16 flags); 104 105 bool IsInBuffer(void* address, size_t size); 106 107 private: 108 bool _FreeFirstEntry(); 109 bool _MakeSpace(size_t needed); 110 111 static status_t _CreateMetaDataArea(bool findPrevious, 112 area_id& _area, 113 TracingMetaData*& _metaData); 114 bool _InitPreviousTracingData(); 115 116 private: 117 uint32 fMagic1; 118 trace_entry* fBuffer; 119 trace_entry* fFirstEntry; 120 trace_entry* fAfterLastEntry; 121 uint32 fEntries; 122 uint32 fMagic2; 123 uint32 fEntriesEver; 124 spinlock fLock; 125 char* fTraceOutputBuffer; 126 phys_addr_t fPhysicalAddress; 127 uint32 fMagic3; 128 }; 129 130 static TracingMetaData sFallbackTracingMetaData; 131 static TracingMetaData* sTracingMetaData = &sFallbackTracingMetaData; 132 static bool sTracingDataRecovered = false; 133 134 135 // #pragma mark - 136 137 138 template<typename Print> 139 static void 140 print_stack_trace(struct tracing_stack_trace* stackTrace, 141 const Print& print) 142 { 143 if (stackTrace == NULL || stackTrace->depth <= 0) 144 return; 145 146 static const size_t kBufferSize = 256; 147 char* buffer = (char*)debug_malloc(kBufferSize); 148 149 for (int32 i = 0; i < stackTrace->depth; i++) { 150 addr_t address = stackTrace->return_addresses[i]; 151 152 const char* symbol; 153 const char* demangledName = NULL; 154 const char* imageName; 155 bool exactMatch; 156 addr_t baseAddress; 157 158 if (elf_debug_lookup_symbol_address(address, &baseAddress, &symbol, 159 &imageName, &exactMatch) == B_OK) { 160 161 if (buffer != NULL) { 162 bool isObjectMethod; 163 demangledName = debug_demangle_symbol(symbol, buffer, 164 kBufferSize, &isObjectMethod); 165 } 166 167 print(" %p %s + 0x%lx (%s)%s\n", (void*)address, 168 demangledName != NULL ? demangledName : symbol, 169 address - baseAddress, imageName, 170 exactMatch ? "" : " (nearest)"); 171 } else 172 print(" %p\n", (void*)address); 173 } 174 175 if (buffer != NULL) 176 debug_free(buffer); 177 } 178 179 180 // #pragma mark - TracingMetaData 181 182 183 bool 184 TracingMetaData::Lock() 185 { 186 acquire_spinlock(&fLock); 187 return true; 188 } 189 190 191 void 192 TracingMetaData::Unlock() 193 { 194 release_spinlock(&fLock); 195 } 196 197 198 trace_entry* 199 TracingMetaData::FirstEntry() const 200 { 201 return fFirstEntry; 202 } 203 204 205 trace_entry* 206 TracingMetaData::AfterLastEntry() const 207 { 208 return fAfterLastEntry; 209 } 210 211 212 uint32 213 TracingMetaData::Entries() const 214 { 215 return fEntries; 216 } 217 218 219 uint32 220 TracingMetaData::EntriesEver() const 221 { 222 return fEntriesEver; 223 } 224 225 226 void 227 TracingMetaData::IncrementEntriesEver() 228 { 229 fEntriesEver++; 230 // NOTE: Race condition on SMP machines! We should use atomic_add(), 231 // though that costs some performance and the information is for 232 // informational purpose anyway. 233 } 234 235 236 char* 237 TracingMetaData::TraceOutputBuffer() const 238 { 239 return fTraceOutputBuffer; 240 } 241 242 243 trace_entry* 244 TracingMetaData::NextEntry(trace_entry* entry) 245 { 246 entry += entry->size; 247 if ((entry->flags & WRAP_ENTRY) != 0) 248 entry = fBuffer; 249 250 if (entry == fAfterLastEntry) 251 return NULL; 252 253 return entry; 254 } 255 256 257 trace_entry* 258 TracingMetaData::PreviousEntry(trace_entry* entry) 259 { 260 if (entry == fFirstEntry) 261 return NULL; 262 263 if (entry == fBuffer) { 264 // beginning of buffer -- previous entry is a wrap entry 265 entry = fBuffer + kBufferSize - entry->previous_size; 266 } 267 268 return entry - entry->previous_size; 269 } 270 271 272 trace_entry* 273 TracingMetaData::AllocateEntry(size_t size, uint16 flags) 274 { 275 if (fAfterLastEntry == NULL || size == 0 276 || size >= kMaxTracingEntryByteSize) { 277 return NULL; 278 } 279 280 InterruptsSpinLocker _(fLock); 281 282 size = (size + 3) >> 2; 283 // 4 byte aligned, don't store the lower 2 bits 284 285 TRACE(("AllocateEntry(%lu), start %p, end %p, buffer %p\n", size * 4, 286 fFirstEntry, fAfterLastEntry, fBuffer)); 287 288 if (!_MakeSpace(size)) 289 return NULL; 290 291 trace_entry* entry = fAfterLastEntry; 292 entry->size = size; 293 entry->flags = flags; 294 fAfterLastEntry += size; 295 fAfterLastEntry->previous_size = size; 296 297 if (!(flags & BUFFER_ENTRY)) 298 fEntries++; 299 300 TRACE((" entry: %p, end %p, start %p, entries %ld\n", entry, 301 fAfterLastEntry, fFirstEntry, fEntries)); 302 303 return entry; 304 } 305 306 307 bool 308 TracingMetaData::IsInBuffer(void* address, size_t size) 309 { 310 if (fEntries == 0) 311 return false; 312 313 addr_t start = (addr_t)address; 314 addr_t end = start + size; 315 316 if (start < (addr_t)fBuffer || end > (addr_t)(fBuffer + kBufferSize)) 317 return false; 318 319 if (fFirstEntry > fAfterLastEntry) 320 return start >= (addr_t)fFirstEntry || end <= (addr_t)fAfterLastEntry; 321 322 return start >= (addr_t)fFirstEntry && end <= (addr_t)fAfterLastEntry; 323 } 324 325 326 bool 327 TracingMetaData::_FreeFirstEntry() 328 { 329 TRACE((" skip start %p, %lu*4 bytes\n", fFirstEntry, fFirstEntry->size)); 330 331 trace_entry* newFirst = NextEntry(fFirstEntry); 332 333 if (fFirstEntry->flags & BUFFER_ENTRY) { 334 // a buffer entry -- just skip it 335 } else if (fFirstEntry->flags & ENTRY_INITIALIZED) { 336 // Fully initialized TraceEntry: We could destroy it, but don't do so 337 // for sake of robustness. The destructors of tracing entry classes 338 // should be empty anyway. 339 fEntries--; 340 } else { 341 // Not fully initialized TraceEntry. We can't free it, since 342 // then it's constructor might still write into the memory and 343 // overwrite data of the entry we're going to allocate. 344 // We can't do anything until this entry can be discarded. 345 return false; 346 } 347 348 if (newFirst == NULL) { 349 // everything is freed -- practically this can't happen, if 350 // the buffer is large enough to hold three max-sized entries 351 fFirstEntry = fAfterLastEntry = fBuffer; 352 TRACE(("_FreeFirstEntry(): all entries freed!\n")); 353 } else 354 fFirstEntry = newFirst; 355 356 return true; 357 } 358 359 360 /*! Makes sure we have needed * 4 bytes of memory at fAfterLastEntry. 361 Returns \c false, if unable to free that much. 362 */ 363 bool 364 TracingMetaData::_MakeSpace(size_t needed) 365 { 366 // we need space for fAfterLastEntry, too (in case we need to wrap around 367 // later) 368 needed++; 369 370 // If there's not enough space (free or occupied) after fAfterLastEntry, 371 // we free all entries in that region and wrap around. 372 if (fAfterLastEntry + needed > fBuffer + kBufferSize) { 373 TRACE(("_MakeSpace(%lu), wrapping around: after last: %p\n", needed, 374 fAfterLastEntry)); 375 376 // Free all entries after fAfterLastEntry and one more at the beginning 377 // of the buffer. 378 while (fFirstEntry > fAfterLastEntry) { 379 if (!_FreeFirstEntry()) 380 return false; 381 } 382 if (fAfterLastEntry != fBuffer && !_FreeFirstEntry()) 383 return false; 384 385 // just in case _FreeFirstEntry() freed the very last existing entry 386 if (fAfterLastEntry == fBuffer) 387 return true; 388 389 // mark as wrap entry and actually wrap around 390 trace_entry* wrapEntry = fAfterLastEntry; 391 wrapEntry->size = 0; 392 wrapEntry->flags = WRAP_ENTRY; 393 fAfterLastEntry = fBuffer; 394 fAfterLastEntry->previous_size = fBuffer + kBufferSize - wrapEntry; 395 } 396 397 if (fFirstEntry <= fAfterLastEntry) { 398 // buffer is empty or the space after fAfterLastEntry is unoccupied 399 return true; 400 } 401 402 // free the first entries, until there's enough space 403 size_t space = fFirstEntry - fAfterLastEntry; 404 405 if (space < needed) { 406 TRACE(("_MakeSpace(%lu), left %ld\n", needed, space)); 407 } 408 409 while (space < needed) { 410 space += fFirstEntry->size; 411 412 if (!_FreeFirstEntry()) 413 return false; 414 } 415 416 TRACE((" out: start %p, entries %ld\n", fFirstEntry, fEntries)); 417 418 return true; 419 } 420 421 422 /*static*/ status_t 423 TracingMetaData::Create(TracingMetaData*& _metaData) 424 { 425 // search meta data in memory (from previous session) 426 area_id area; 427 TracingMetaData* metaData; 428 status_t error = _CreateMetaDataArea(true, area, metaData); 429 if (error == B_OK) { 430 if (metaData->_InitPreviousTracingData()) { 431 _metaData = metaData; 432 return B_OK; 433 } 434 435 dprintf("Found previous tracing meta data, but failed to init.\n"); 436 437 // invalidate the meta data 438 metaData->fMagic1 = 0; 439 metaData->fMagic2 = 0; 440 metaData->fMagic3 = 0; 441 delete_area(area); 442 } else 443 dprintf("No previous tracing meta data found.\n"); 444 445 // no previous tracing data found -- create new one 446 error = _CreateMetaDataArea(false, area, metaData); 447 if (error != B_OK) 448 return error; 449 450 virtual_address_restrictions virtualRestrictions = {}; 451 virtualRestrictions.address_specification = B_ANY_KERNEL_ADDRESS; 452 physical_address_restrictions physicalRestrictions = {}; 453 area = create_area_etc(B_SYSTEM_TEAM, "tracing log", 454 kTraceOutputBufferSize + MAX_TRACE_SIZE, B_CONTIGUOUS, 455 B_KERNEL_READ_AREA | B_KERNEL_WRITE_AREA, CREATE_AREA_DONT_WAIT, 0, 456 &virtualRestrictions, &physicalRestrictions, 457 (void**)&metaData->fTraceOutputBuffer); 458 if (area < 0) 459 return area; 460 461 // get the physical address 462 physical_entry physicalEntry; 463 if (get_memory_map(metaData->fTraceOutputBuffer, B_PAGE_SIZE, 464 &physicalEntry, 1) == B_OK) { 465 metaData->fPhysicalAddress = physicalEntry.address; 466 } else { 467 dprintf("TracingMetaData::Create(): failed to get physical address " 468 "of tracing buffer\n"); 469 metaData->fPhysicalAddress = 0; 470 } 471 472 metaData->fBuffer = (trace_entry*)(metaData->fTraceOutputBuffer 473 + kTraceOutputBufferSize); 474 metaData->fFirstEntry = metaData->fBuffer; 475 metaData->fAfterLastEntry = metaData->fBuffer; 476 477 metaData->fEntries = 0; 478 metaData->fEntriesEver = 0; 479 B_INITIALIZE_SPINLOCK(&metaData->fLock); 480 481 metaData->fMagic1 = kMetaDataMagic1; 482 metaData->fMagic2 = kMetaDataMagic2; 483 metaData->fMagic3 = kMetaDataMagic3; 484 485 _metaData = metaData; 486 return B_OK; 487 } 488 489 490 /*static*/ status_t 491 TracingMetaData::_CreateMetaDataArea(bool findPrevious, area_id& _area, 492 TracingMetaData*& _metaData) 493 { 494 // search meta data in memory (from previous session) 495 TracingMetaData* metaData; 496 phys_addr_t metaDataAddress = kMetaDataBaseAddress; 497 for (; metaDataAddress <= kMetaDataBaseEndAddress; 498 metaDataAddress += kMetaDataAddressIncrement) { 499 virtual_address_restrictions virtualRestrictions = {}; 500 virtualRestrictions.address_specification = B_ANY_KERNEL_ADDRESS; 501 physical_address_restrictions physicalRestrictions = {}; 502 physicalRestrictions.low_address = metaDataAddress; 503 physicalRestrictions.high_address = metaDataAddress + B_PAGE_SIZE; 504 area_id area = create_area_etc(B_SYSTEM_TEAM, "tracing metadata", 505 B_PAGE_SIZE, B_FULL_LOCK, B_KERNEL_READ_AREA | B_KERNEL_WRITE_AREA, 506 CREATE_AREA_DONT_CLEAR, 0, &virtualRestrictions, 507 &physicalRestrictions, (void**)&metaData); 508 if (area < 0) 509 continue; 510 511 if (!findPrevious) { 512 _area = area; 513 _metaData = metaData; 514 return B_OK; 515 } 516 517 if (metaData->fMagic1 == kMetaDataMagic1 518 && metaData->fMagic2 == kMetaDataMagic2 519 && metaData->fMagic3 == kMetaDataMagic3) { 520 _area = area; 521 _metaData = metaData; 522 return B_OK; 523 } 524 525 delete_area(area); 526 } 527 528 if (findPrevious) 529 return B_ENTRY_NOT_FOUND; 530 531 // We could allocate any of the standard locations. Instead of failing 532 // entirely, we use the static meta data. The tracing buffer won't be 533 // reattachable in the next session, but at least we can use it in this 534 // session. 535 _metaData = &sFallbackTracingMetaData; 536 return B_OK; 537 } 538 539 540 bool 541 TracingMetaData::_InitPreviousTracingData() 542 { 543 // TODO: ATM re-attaching the previous tracing buffer doesn't work very 544 // well. The entries should be checked more thoroughly for validity -- e.g. 545 // the pointers to the entries' vtable pointers could be invalid, which can 546 // make the "traced" command quite unusable. The validity of the entries 547 // could be checked in a safe environment (i.e. with a fault handler) with 548 // typeid() and call of a virtual function. 549 return false; 550 551 addr_t bufferStart 552 = (addr_t)fTraceOutputBuffer + kTraceOutputBufferSize; 553 addr_t bufferEnd = bufferStart + MAX_TRACE_SIZE; 554 555 if (bufferStart > bufferEnd || (addr_t)fBuffer != bufferStart 556 || (addr_t)fFirstEntry % sizeof(trace_entry) != 0 557 || (addr_t)fFirstEntry < bufferStart 558 || (addr_t)fFirstEntry + sizeof(trace_entry) >= bufferEnd 559 || (addr_t)fAfterLastEntry % sizeof(trace_entry) != 0 560 || (addr_t)fAfterLastEntry < bufferStart 561 || (addr_t)fAfterLastEntry > bufferEnd 562 || fPhysicalAddress == 0) { 563 dprintf("Failed to init tracing meta data: Sanity checks " 564 "failed.\n"); 565 return false; 566 } 567 568 // re-map the previous tracing buffer 569 virtual_address_restrictions virtualRestrictions = {}; 570 virtualRestrictions.address = fTraceOutputBuffer; 571 virtualRestrictions.address_specification = B_EXACT_ADDRESS; 572 physical_address_restrictions physicalRestrictions = {}; 573 physicalRestrictions.low_address = fPhysicalAddress; 574 physicalRestrictions.high_address = fPhysicalAddress 575 + ROUNDUP(kTraceOutputBufferSize + MAX_TRACE_SIZE, B_PAGE_SIZE); 576 area_id area = create_area_etc(B_SYSTEM_TEAM, "tracing log", 577 kTraceOutputBufferSize + MAX_TRACE_SIZE, B_CONTIGUOUS, 578 B_KERNEL_READ_AREA | B_KERNEL_WRITE_AREA, CREATE_AREA_DONT_CLEAR, 0, 579 &virtualRestrictions, &physicalRestrictions, NULL); 580 if (area < 0) { 581 dprintf("Failed to init tracing meta data: Mapping tracing log " 582 "buffer failed: %s\n", strerror(area)); 583 return false; 584 } 585 586 dprintf("ktrace: Remapped tracing buffer at %p, size: %" B_PRIuSIZE "\n", 587 fTraceOutputBuffer, kTraceOutputBufferSize + MAX_TRACE_SIZE); 588 589 // verify/repair the tracing entry list 590 uint32 errorCount = 0; 591 uint32 entryCount = 0; 592 uint32 nonBufferEntryCount = 0; 593 uint32 previousEntrySize = 0; 594 trace_entry* entry = fFirstEntry; 595 while (errorCount <= kMaxRecoveringErrorCount) { 596 // check previous entry size 597 if (entry->previous_size != previousEntrySize) { 598 if (entry != fFirstEntry) { 599 dprintf("ktrace recovering: entry %p: fixing previous_size " 600 "size: %" B_PRIu32 " (should be %" B_PRIu32 ")\n", entry, 601 entry->previous_size, previousEntrySize); 602 errorCount++; 603 } 604 entry->previous_size = previousEntrySize; 605 } 606 607 if (entry == fAfterLastEntry) 608 break; 609 610 // check size field 611 if ((entry->flags & WRAP_ENTRY) == 0 && entry->size == 0) { 612 dprintf("ktrace recovering: entry %p: non-wrap entry size is 0\n", 613 entry); 614 errorCount++; 615 fAfterLastEntry = entry; 616 break; 617 } 618 619 if (entry->size > uint32(fBuffer + kBufferSize - entry)) { 620 dprintf("ktrace recovering: entry %p: size too big: %" B_PRIu32 "\n", 621 entry, entry->size); 622 errorCount++; 623 fAfterLastEntry = entry; 624 break; 625 } 626 627 if (entry < fAfterLastEntry && entry + entry->size > fAfterLastEntry) { 628 dprintf("ktrace recovering: entry %p: entry crosses " 629 "fAfterLastEntry (%p)\n", entry, fAfterLastEntry); 630 errorCount++; 631 fAfterLastEntry = entry; 632 break; 633 } 634 635 // check for wrap entry 636 if ((entry->flags & WRAP_ENTRY) != 0) { 637 if ((uint32)(fBuffer + kBufferSize - entry) 638 > kMaxTracingEntryByteSize / sizeof(trace_entry)) { 639 dprintf("ktrace recovering: entry %p: wrap entry at invalid " 640 "buffer location\n", entry); 641 errorCount++; 642 } 643 644 if (entry->size != 0) { 645 dprintf("ktrace recovering: entry %p: invalid wrap entry " 646 "size: %" B_PRIu32 "\n", entry, entry->size); 647 errorCount++; 648 entry->size = 0; 649 } 650 651 previousEntrySize = fBuffer + kBufferSize - entry; 652 entry = fBuffer; 653 continue; 654 } 655 656 if ((entry->flags & BUFFER_ENTRY) == 0) { 657 entry->flags |= CHECK_ENTRY; 658 nonBufferEntryCount++; 659 } 660 661 entryCount++; 662 previousEntrySize = entry->size; 663 664 entry += entry->size; 665 } 666 667 if (errorCount > kMaxRecoveringErrorCount) { 668 dprintf("ktrace recovering: Too many errors.\n"); 669 fAfterLastEntry = entry; 670 fAfterLastEntry->previous_size = previousEntrySize; 671 } 672 673 dprintf("ktrace recovering: Recovered %" B_PRIu32 " entries + %" B_PRIu32 674 " buffer entries from previous session. Expected %" B_PRIu32 675 " entries.\n", nonBufferEntryCount, entryCount - nonBufferEntryCount, 676 fEntries); 677 fEntries = nonBufferEntryCount; 678 679 B_INITIALIZE_SPINLOCK(&fLock); 680 681 // TODO: Actually check the entries! Do that when first accessing the 682 // tracing buffer from the kernel debugger (when sTracingDataRecovered is 683 // true). 684 sTracingDataRecovered = true; 685 return true; 686 } 687 688 689 #endif // ENABLE_TRACING 690 691 692 // #pragma mark - 693 694 695 TraceOutput::TraceOutput(char* buffer, size_t bufferSize, uint32 flags) 696 : fBuffer(buffer), 697 fCapacity(bufferSize), 698 fFlags(flags) 699 { 700 Clear(); 701 } 702 703 704 void 705 TraceOutput::Clear() 706 { 707 if (fCapacity > 0) 708 fBuffer[0] = '\0'; 709 fSize = 0; 710 } 711 712 713 void 714 TraceOutput::PrintArgs(const char* format, va_list args) 715 { 716 #if ENABLE_TRACING 717 if (IsFull()) 718 return; 719 720 size_t length = vsnprintf(fBuffer + fSize, fCapacity - fSize, format, args); 721 fSize += std::min(length, fCapacity - fSize - 1); 722 #endif 723 } 724 725 726 void 727 TraceOutput::PrintStackTrace(tracing_stack_trace* stackTrace) 728 { 729 #if ENABLE_TRACING 730 print_stack_trace(stackTrace, TraceOutputPrint(*this)); 731 #endif 732 } 733 734 735 void 736 TraceOutput::SetLastEntryTime(bigtime_t time) 737 { 738 fLastEntryTime = time; 739 } 740 741 742 bigtime_t 743 TraceOutput::LastEntryTime() const 744 { 745 return fLastEntryTime; 746 } 747 748 749 // #pragma mark - 750 751 752 TraceEntry::TraceEntry() 753 { 754 } 755 756 757 TraceEntry::~TraceEntry() 758 { 759 } 760 761 762 void 763 TraceEntry::Dump(TraceOutput& out) 764 { 765 #if ENABLE_TRACING 766 // to be overridden by subclasses 767 out.Print("ENTRY %p", this); 768 #endif 769 } 770 771 772 void 773 TraceEntry::DumpStackTrace(TraceOutput& out) 774 { 775 } 776 777 778 void 779 TraceEntry::Initialized() 780 { 781 #if ENABLE_TRACING 782 ToTraceEntry()->flags |= ENTRY_INITIALIZED; 783 sTracingMetaData->IncrementEntriesEver(); 784 #endif 785 } 786 787 788 void* 789 TraceEntry::operator new(size_t size, const std::nothrow_t&) throw() 790 { 791 #if ENABLE_TRACING 792 trace_entry* entry = sTracingMetaData->AllocateEntry( 793 size + sizeof(trace_entry), 0); 794 return entry != NULL ? entry + 1 : NULL; 795 #endif 796 return NULL; 797 } 798 799 800 // #pragma mark - 801 802 803 AbstractTraceEntry::~AbstractTraceEntry() 804 { 805 } 806 807 808 void 809 AbstractTraceEntry::Dump(TraceOutput& out) 810 { 811 bigtime_t time = (out.Flags() & TRACE_OUTPUT_DIFF_TIME) 812 ? fTime - out.LastEntryTime() 813 : fTime; 814 815 if (out.Flags() & TRACE_OUTPUT_TEAM_ID) { 816 out.Print("[%6" B_PRId32 ":%6" B_PRId32 "] %10" B_PRId64 ": ", fThread, 817 fTeam, time); 818 } else 819 out.Print("[%6" B_PRId32 "] %10" B_PRId64 ": ", fThread, time); 820 821 AddDump(out); 822 823 out.SetLastEntryTime(fTime); 824 } 825 826 827 void 828 AbstractTraceEntry::AddDump(TraceOutput& out) 829 { 830 } 831 832 833 void 834 AbstractTraceEntry::_Init() 835 { 836 Thread* thread = thread_get_current_thread(); 837 if (thread != NULL) { 838 fThread = thread->id; 839 if (thread->team) 840 fTeam = thread->team->id; 841 } 842 fTime = system_time(); 843 } 844 845 846 // #pragma mark - AbstractTraceEntryWithStackTrace 847 848 849 850 AbstractTraceEntryWithStackTrace::AbstractTraceEntryWithStackTrace( 851 size_t stackTraceDepth, size_t skipFrames, bool kernelOnly) 852 { 853 fStackTrace = capture_tracing_stack_trace(stackTraceDepth, skipFrames + 1, 854 kernelOnly); 855 } 856 857 858 void 859 AbstractTraceEntryWithStackTrace::DumpStackTrace(TraceOutput& out) 860 { 861 out.PrintStackTrace(fStackTrace); 862 } 863 864 865 // #pragma mark - 866 867 868 #if ENABLE_TRACING 869 870 class KernelTraceEntry : public AbstractTraceEntry { 871 public: 872 KernelTraceEntry(const char* message) 873 { 874 fMessage = alloc_tracing_buffer_strcpy(message, 256, false); 875 876 #if KTRACE_PRINTF_STACK_TRACE 877 fStackTrace = capture_tracing_stack_trace( 878 KTRACE_PRINTF_STACK_TRACE, 1, false); 879 #endif 880 Initialized(); 881 } 882 883 virtual void AddDump(TraceOutput& out) 884 { 885 out.Print("kern: %s", fMessage); 886 } 887 888 #if KTRACE_PRINTF_STACK_TRACE 889 virtual void DumpStackTrace(TraceOutput& out) 890 { 891 out.PrintStackTrace(fStackTrace); 892 } 893 #endif 894 895 private: 896 char* fMessage; 897 #if KTRACE_PRINTF_STACK_TRACE 898 tracing_stack_trace* fStackTrace; 899 #endif 900 }; 901 902 903 class UserTraceEntry : public AbstractTraceEntry { 904 public: 905 UserTraceEntry(const char* message) 906 { 907 fMessage = alloc_tracing_buffer_strcpy(message, 256, true); 908 909 #if KTRACE_PRINTF_STACK_TRACE 910 fStackTrace = capture_tracing_stack_trace( 911 KTRACE_PRINTF_STACK_TRACE, 1, false); 912 #endif 913 Initialized(); 914 } 915 916 virtual void AddDump(TraceOutput& out) 917 { 918 out.Print("user: %s", fMessage); 919 } 920 921 #if KTRACE_PRINTF_STACK_TRACE 922 virtual void DumpStackTrace(TraceOutput& out) 923 { 924 out.PrintStackTrace(fStackTrace); 925 } 926 #endif 927 928 private: 929 char* fMessage; 930 #if KTRACE_PRINTF_STACK_TRACE 931 tracing_stack_trace* fStackTrace; 932 #endif 933 }; 934 935 936 class TracingLogStartEntry : public AbstractTraceEntry { 937 public: 938 TracingLogStartEntry() 939 { 940 Initialized(); 941 } 942 943 virtual void AddDump(TraceOutput& out) 944 { 945 out.Print("ktrace start"); 946 } 947 }; 948 949 #endif // ENABLE_TRACING 950 951 952 // #pragma mark - trace filters 953 954 955 TraceFilter::~TraceFilter() 956 { 957 } 958 959 960 bool 961 TraceFilter::Filter(const TraceEntry* entry, LazyTraceOutput& out) 962 { 963 return false; 964 } 965 966 967 968 class ThreadTraceFilter : public TraceFilter { 969 public: 970 virtual bool Filter(const TraceEntry* _entry, LazyTraceOutput& out) 971 { 972 const AbstractTraceEntry* entry 973 = dynamic_cast<const AbstractTraceEntry*>(_entry); 974 return (entry != NULL && entry->ThreadID() == fThread); 975 } 976 }; 977 978 979 class TeamTraceFilter : public TraceFilter { 980 public: 981 virtual bool Filter(const TraceEntry* _entry, LazyTraceOutput& out) 982 { 983 const AbstractTraceEntry* entry 984 = dynamic_cast<const AbstractTraceEntry*>(_entry); 985 return (entry != NULL && entry->TeamID() == fTeam); 986 } 987 }; 988 989 990 class PatternTraceFilter : public TraceFilter { 991 public: 992 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 993 { 994 return strstr(out.DumpEntry(entry), fString) != NULL; 995 } 996 }; 997 998 999 class DecimalPatternTraceFilter : public TraceFilter { 1000 public: 1001 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 1002 { 1003 // TODO: this is *very* slow 1004 char buffer[64]; 1005 snprintf(buffer, sizeof(buffer), "%" B_PRId64, fValue); 1006 return strstr(out.DumpEntry(entry), buffer) != NULL; 1007 } 1008 }; 1009 1010 class HexPatternTraceFilter : public TraceFilter { 1011 public: 1012 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 1013 { 1014 // TODO: this is *very* slow 1015 char buffer[64]; 1016 snprintf(buffer, sizeof(buffer), "%" B_PRIx64, fValue); 1017 return strstr(out.DumpEntry(entry), buffer) != NULL; 1018 } 1019 }; 1020 1021 class StringPatternTraceFilter : public TraceFilter { 1022 public: 1023 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 1024 { 1025 if (IS_KERNEL_ADDRESS(fValue)) 1026 return strstr(out.DumpEntry(entry), (const char*)fValue) != NULL; 1027 1028 // TODO: this is *very* slow 1029 char buffer[64]; 1030 user_strlcpy(buffer, (const char*)fValue, sizeof(buffer)); 1031 return strstr(out.DumpEntry(entry), buffer) != NULL; 1032 } 1033 }; 1034 1035 class NotTraceFilter : public TraceFilter { 1036 public: 1037 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 1038 { 1039 return !fSubFilters.first->Filter(entry, out); 1040 } 1041 }; 1042 1043 1044 class AndTraceFilter : public TraceFilter { 1045 public: 1046 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 1047 { 1048 return fSubFilters.first->Filter(entry, out) 1049 && fSubFilters.second->Filter(entry, out); 1050 } 1051 }; 1052 1053 1054 class OrTraceFilter : public TraceFilter { 1055 public: 1056 virtual bool Filter(const TraceEntry* entry, LazyTraceOutput& out) 1057 { 1058 return fSubFilters.first->Filter(entry, out) 1059 || fSubFilters.second->Filter(entry, out); 1060 } 1061 }; 1062 1063 1064 class TraceFilterParser { 1065 public: 1066 static TraceFilterParser* Default() 1067 { 1068 return &sParser; 1069 } 1070 1071 bool Parse(int argc, const char* const* argv) 1072 { 1073 fTokens = argv; 1074 fTokenCount = argc; 1075 fTokenIndex = 0; 1076 fFilterCount = 0; 1077 1078 TraceFilter* filter = _ParseExpression(); 1079 return fTokenIndex == fTokenCount && filter != NULL; 1080 } 1081 1082 TraceFilter* Filter() 1083 { 1084 return &fFilters[0]; 1085 } 1086 1087 private: 1088 TraceFilter* _ParseExpression() 1089 { 1090 const char* token = _NextToken(); 1091 if (!token) { 1092 // unexpected end of expression 1093 return NULL; 1094 } 1095 1096 if (fFilterCount == MAX_FILTERS) { 1097 // too many filters 1098 return NULL; 1099 } 1100 1101 if (token[0] == '#') { 1102 TraceFilter* filter = new(&fFilters[fFilterCount++]) 1103 PatternTraceFilter; 1104 filter->fString = token + 1; 1105 return filter; 1106 } else if (token[0] == 'd' && token[1] == '#') { 1107 TraceFilter* filter = new(&fFilters[fFilterCount++]) 1108 DecimalPatternTraceFilter; 1109 filter->fValue = parse_expression(token + 2); 1110 return filter; 1111 } else if (token[0] == 'x' && token[1] == '#') { 1112 TraceFilter* filter = new(&fFilters[fFilterCount++]) 1113 HexPatternTraceFilter; 1114 filter->fValue = parse_expression(token + 2); 1115 return filter; 1116 } else if (token[0] == 's' && token[1] == '#') { 1117 TraceFilter* filter = new(&fFilters[fFilterCount++]) 1118 StringPatternTraceFilter; 1119 filter->fValue = parse_expression(token + 2); 1120 return filter; 1121 } else if (strcmp(token, "not") == 0) { 1122 TraceFilter* filter = new(&fFilters[fFilterCount++]) NotTraceFilter; 1123 if ((filter->fSubFilters.first = _ParseExpression()) != NULL) 1124 return filter; 1125 return NULL; 1126 } else if (strcmp(token, "and") == 0) { 1127 TraceFilter* filter = new(&fFilters[fFilterCount++]) AndTraceFilter; 1128 if ((filter->fSubFilters.first = _ParseExpression()) != NULL 1129 && (filter->fSubFilters.second = _ParseExpression()) != NULL) { 1130 return filter; 1131 } 1132 return NULL; 1133 } else if (strcmp(token, "or") == 0) { 1134 TraceFilter* filter = new(&fFilters[fFilterCount++]) OrTraceFilter; 1135 if ((filter->fSubFilters.first = _ParseExpression()) != NULL 1136 && (filter->fSubFilters.second = _ParseExpression()) != NULL) { 1137 return filter; 1138 } 1139 return NULL; 1140 } else if (strcmp(token, "thread") == 0) { 1141 const char* arg = _NextToken(); 1142 if (arg == NULL) { 1143 // unexpected end of expression 1144 return NULL; 1145 } 1146 1147 TraceFilter* filter = new(&fFilters[fFilterCount++]) 1148 ThreadTraceFilter; 1149 filter->fThread = strtol(arg, NULL, 0); 1150 return filter; 1151 } else if (strcmp(token, "team") == 0) { 1152 const char* arg = _NextToken(); 1153 if (arg == NULL) { 1154 // unexpected end of expression 1155 return NULL; 1156 } 1157 1158 TraceFilter* filter = new(&fFilters[fFilterCount++]) 1159 TeamTraceFilter; 1160 filter->fTeam = strtol(arg, NULL, 0); 1161 return filter; 1162 } else { 1163 // invalid token 1164 return NULL; 1165 } 1166 } 1167 1168 const char* _CurrentToken() const 1169 { 1170 if (fTokenIndex >= 1 && fTokenIndex <= fTokenCount) 1171 return fTokens[fTokenIndex - 1]; 1172 return NULL; 1173 } 1174 1175 const char* _NextToken() 1176 { 1177 if (fTokenIndex >= fTokenCount) 1178 return NULL; 1179 return fTokens[fTokenIndex++]; 1180 } 1181 1182 private: 1183 enum { MAX_FILTERS = 32 }; 1184 1185 const char* const* fTokens; 1186 int fTokenCount; 1187 int fTokenIndex; 1188 TraceFilter fFilters[MAX_FILTERS]; 1189 int fFilterCount; 1190 1191 static TraceFilterParser sParser; 1192 }; 1193 1194 1195 TraceFilterParser TraceFilterParser::sParser; 1196 1197 1198 // #pragma mark - 1199 1200 1201 #if ENABLE_TRACING 1202 1203 1204 TraceEntry* 1205 TraceEntryIterator::Next() 1206 { 1207 if (fIndex == 0) { 1208 fEntry = _NextNonBufferEntry(sTracingMetaData->FirstEntry()); 1209 fIndex = 1; 1210 } else if (fEntry != NULL) { 1211 fEntry = _NextNonBufferEntry(sTracingMetaData->NextEntry(fEntry)); 1212 fIndex++; 1213 } 1214 1215 return Current(); 1216 } 1217 1218 1219 TraceEntry* 1220 TraceEntryIterator::Previous() 1221 { 1222 if (fIndex == (int32)sTracingMetaData->Entries() + 1) 1223 fEntry = sTracingMetaData->AfterLastEntry(); 1224 1225 if (fEntry != NULL) { 1226 fEntry = _PreviousNonBufferEntry( 1227 sTracingMetaData->PreviousEntry(fEntry)); 1228 fIndex--; 1229 } 1230 1231 return Current(); 1232 } 1233 1234 1235 TraceEntry* 1236 TraceEntryIterator::MoveTo(int32 index) 1237 { 1238 if (index == fIndex) 1239 return Current(); 1240 1241 if (index <= 0 || index > (int32)sTracingMetaData->Entries()) { 1242 fIndex = (index <= 0 ? 0 : sTracingMetaData->Entries() + 1); 1243 fEntry = NULL; 1244 return NULL; 1245 } 1246 1247 // get the shortest iteration path 1248 int32 distance = index - fIndex; 1249 int32 direction = distance < 0 ? -1 : 1; 1250 distance *= direction; 1251 1252 if (index < distance) { 1253 distance = index; 1254 direction = 1; 1255 fEntry = NULL; 1256 fIndex = 0; 1257 } 1258 if ((int32)sTracingMetaData->Entries() + 1 - fIndex < distance) { 1259 distance = sTracingMetaData->Entries() + 1 - fIndex; 1260 direction = -1; 1261 fEntry = NULL; 1262 fIndex = sTracingMetaData->Entries() + 1; 1263 } 1264 1265 // iterate to the index 1266 if (direction < 0) { 1267 while (fIndex != index) 1268 Previous(); 1269 } else { 1270 while (fIndex != index) 1271 Next(); 1272 } 1273 1274 return Current(); 1275 } 1276 1277 1278 trace_entry* 1279 TraceEntryIterator::_NextNonBufferEntry(trace_entry* entry) 1280 { 1281 while (entry != NULL && (entry->flags & BUFFER_ENTRY) != 0) 1282 entry = sTracingMetaData->NextEntry(entry); 1283 1284 return entry; 1285 } 1286 1287 1288 trace_entry* 1289 TraceEntryIterator::_PreviousNonBufferEntry(trace_entry* entry) 1290 { 1291 while (entry != NULL && (entry->flags & BUFFER_ENTRY) != 0) 1292 entry = sTracingMetaData->PreviousEntry(entry); 1293 1294 return entry; 1295 } 1296 1297 1298 int 1299 dump_tracing_internal(int argc, char** argv, WrapperTraceFilter* wrapperFilter) 1300 { 1301 int argi = 1; 1302 1303 // variables in which we store our state to be continuable 1304 static int32 _previousCount = 0; 1305 static bool _previousHasFilter = false; 1306 static bool _previousPrintStackTrace = false; 1307 static int32 _previousMaxToCheck = 0; 1308 static int32 _previousFirstChecked = 1; 1309 static int32 _previousLastChecked = -1; 1310 static int32 _previousDirection = 1; 1311 static uint32 _previousEntriesEver = 0; 1312 static uint32 _previousEntries = 0; 1313 static uint32 _previousOutputFlags = 0; 1314 static TraceEntryIterator iterator; 1315 1316 uint32 entriesEver = sTracingMetaData->EntriesEver(); 1317 1318 // Note: start and index are Pascal-like indices (i.e. in [1, Entries()]). 1319 int32 start = 0; // special index: print the last count entries 1320 int32 count = 0; 1321 int32 maxToCheck = 0; 1322 int32 cont = 0; 1323 1324 bool hasFilter = false; 1325 bool printStackTrace = false; 1326 1327 uint32 outputFlags = 0; 1328 while (argi < argc) { 1329 if (strcmp(argv[argi], "--difftime") == 0) { 1330 outputFlags |= TRACE_OUTPUT_DIFF_TIME; 1331 argi++; 1332 } else if (strcmp(argv[argi], "--printteam") == 0) { 1333 outputFlags |= TRACE_OUTPUT_TEAM_ID; 1334 argi++; 1335 } else if (strcmp(argv[argi], "--stacktrace") == 0) { 1336 printStackTrace = true; 1337 argi++; 1338 } else 1339 break; 1340 } 1341 1342 if (argi < argc) { 1343 if (strcmp(argv[argi], "forward") == 0) { 1344 cont = 1; 1345 argi++; 1346 } else if (strcmp(argv[argi], "backward") == 0) { 1347 cont = -1; 1348 argi++; 1349 } 1350 } else 1351 cont = _previousDirection; 1352 1353 if (cont != 0) { 1354 if (argi < argc) { 1355 print_debugger_command_usage(argv[0]); 1356 return 0; 1357 } 1358 if (entriesEver == 0 || entriesEver != _previousEntriesEver 1359 || sTracingMetaData->Entries() != _previousEntries) { 1360 kprintf("Can't continue iteration. \"%s\" has not been invoked " 1361 "before, or there were new entries written since the last " 1362 "invocation.\n", argv[0]); 1363 return 0; 1364 } 1365 } 1366 1367 // get start, count, maxToCheck 1368 int32* params[3] = { &start, &count, &maxToCheck }; 1369 for (int i = 0; i < 3 && !hasFilter && argi < argc; i++) { 1370 if (strcmp(argv[argi], "filter") == 0) { 1371 hasFilter = true; 1372 argi++; 1373 } else if (argv[argi][0] == '#') { 1374 hasFilter = true; 1375 } else { 1376 *params[i] = parse_expression(argv[argi]); 1377 argi++; 1378 } 1379 } 1380 1381 // filter specification 1382 if (argi < argc) { 1383 hasFilter = true; 1384 if (strcmp(argv[argi], "filter") == 0) 1385 argi++; 1386 1387 if (!TraceFilterParser::Default()->Parse(argc - argi, argv + argi)) { 1388 print_debugger_command_usage(argv[0]); 1389 return 0; 1390 } 1391 } 1392 1393 int32 direction; 1394 int32 firstToCheck; 1395 int32 lastToCheck; 1396 1397 if (cont != 0) { 1398 // get values from the previous iteration 1399 direction = cont; 1400 count = _previousCount; 1401 maxToCheck = _previousMaxToCheck; 1402 hasFilter = _previousHasFilter; 1403 outputFlags = _previousOutputFlags; 1404 printStackTrace = _previousPrintStackTrace; 1405 1406 if (direction < 0) 1407 start = _previousFirstChecked - 1; 1408 else 1409 start = _previousLastChecked + 1; 1410 } else { 1411 // defaults for count and maxToCheck 1412 if (count == 0) 1413 count = 30; 1414 if (maxToCheck == 0 || !hasFilter) 1415 maxToCheck = count; 1416 else if (maxToCheck < 0) 1417 maxToCheck = sTracingMetaData->Entries(); 1418 1419 // determine iteration direction 1420 direction = (start <= 0 || count < 0 ? -1 : 1); 1421 1422 // validate count and maxToCheck 1423 if (count < 0) 1424 count = -count; 1425 if (maxToCheck < 0) 1426 maxToCheck = -maxToCheck; 1427 if (maxToCheck > (int32)sTracingMetaData->Entries()) 1428 maxToCheck = sTracingMetaData->Entries(); 1429 if (count > maxToCheck) 1430 count = maxToCheck; 1431 1432 // validate start 1433 if (start <= 0 || start > (int32)sTracingMetaData->Entries()) 1434 start = max_c(1, sTracingMetaData->Entries()); 1435 } 1436 1437 if (direction < 0) { 1438 firstToCheck = max_c(1, start - maxToCheck + 1); 1439 lastToCheck = start; 1440 } else { 1441 firstToCheck = start; 1442 lastToCheck = min_c((int32)sTracingMetaData->Entries(), 1443 start + maxToCheck - 1); 1444 } 1445 1446 // reset the iterator, if something changed in the meantime 1447 if (entriesEver == 0 || entriesEver != _previousEntriesEver 1448 || sTracingMetaData->Entries() != _previousEntries) { 1449 iterator.Reset(); 1450 } 1451 1452 LazyTraceOutput out(sTracingMetaData->TraceOutputBuffer(), 1453 kTraceOutputBufferSize, outputFlags); 1454 1455 bool markedMatching = false; 1456 int32 firstToDump = firstToCheck; 1457 int32 lastToDump = lastToCheck; 1458 1459 TraceFilter* filter = NULL; 1460 if (hasFilter) 1461 filter = TraceFilterParser::Default()->Filter(); 1462 1463 if (wrapperFilter != NULL) { 1464 wrapperFilter->Init(filter, direction, cont != 0); 1465 filter = wrapperFilter; 1466 } 1467 1468 if (direction < 0 && filter && lastToCheck - firstToCheck >= count) { 1469 // iteration direction is backwards 1470 markedMatching = true; 1471 1472 // From the last entry to check iterate backwards to check filter 1473 // matches. 1474 int32 matching = 0; 1475 1476 // move to the entry after the last entry to check 1477 iterator.MoveTo(lastToCheck + 1); 1478 1479 // iterate backwards 1480 firstToDump = -1; 1481 lastToDump = -1; 1482 while (iterator.Index() > firstToCheck) { 1483 TraceEntry* entry = iterator.Previous(); 1484 if ((entry->Flags() & ENTRY_INITIALIZED) != 0) { 1485 out.Clear(); 1486 if (filter->Filter(entry, out)) { 1487 entry->ToTraceEntry()->flags |= FILTER_MATCH; 1488 if (lastToDump == -1) 1489 lastToDump = iterator.Index(); 1490 firstToDump = iterator.Index(); 1491 1492 matching++; 1493 if (matching >= count) 1494 break; 1495 } else 1496 entry->ToTraceEntry()->flags &= ~FILTER_MATCH; 1497 } 1498 } 1499 1500 firstToCheck = iterator.Index(); 1501 1502 // iterate to the previous entry, so that the next loop starts at the 1503 // right one 1504 iterator.Previous(); 1505 } 1506 1507 out.SetLastEntryTime(0); 1508 1509 // set the iterator to the entry before the first one to dump 1510 iterator.MoveTo(firstToDump - 1); 1511 1512 // dump the entries matching the filter in the range 1513 // [firstToDump, lastToDump] 1514 int32 dumped = 0; 1515 1516 while (TraceEntry* entry = iterator.Next()) { 1517 int32 index = iterator.Index(); 1518 if (index < firstToDump) 1519 continue; 1520 if (index > lastToDump || dumped >= count) { 1521 if (direction > 0) 1522 lastToCheck = index - 1; 1523 break; 1524 } 1525 1526 if ((entry->Flags() & ENTRY_INITIALIZED) != 0) { 1527 out.Clear(); 1528 if (filter && (markedMatching 1529 ? (entry->Flags() & FILTER_MATCH) == 0 1530 : !filter->Filter(entry, out))) { 1531 continue; 1532 } 1533 1534 // don't print trailing new line 1535 const char* dump = out.DumpEntry(entry); 1536 int len = strlen(dump); 1537 if (len > 0 && dump[len - 1] == '\n') 1538 len--; 1539 1540 kprintf("%5" B_PRId32 ". %.*s\n", index, len, dump); 1541 1542 if (printStackTrace) { 1543 out.Clear(); 1544 entry->DumpStackTrace(out); 1545 if (out.Size() > 0) 1546 kputs(out.Buffer()); 1547 } 1548 } else if (!filter) 1549 kprintf("%5" B_PRId32 ". ** uninitialized entry **\n", index); 1550 1551 dumped++; 1552 } 1553 1554 kprintf("printed %" B_PRId32 " entries within range %" B_PRId32 " to %" 1555 B_PRId32 " (%" B_PRId32 " of %" B_PRId32 " total, %" B_PRId32 " ever)\n", 1556 dumped, firstToCheck, lastToCheck, lastToCheck - firstToCheck + 1, 1557 sTracingMetaData->Entries(), entriesEver); 1558 1559 // store iteration state 1560 _previousCount = count; 1561 _previousMaxToCheck = maxToCheck; 1562 _previousHasFilter = hasFilter; 1563 _previousPrintStackTrace = printStackTrace; 1564 _previousFirstChecked = firstToCheck; 1565 _previousLastChecked = lastToCheck; 1566 _previousDirection = direction; 1567 _previousEntriesEver = entriesEver; 1568 _previousEntries = sTracingMetaData->Entries(); 1569 _previousOutputFlags = outputFlags; 1570 1571 return cont != 0 ? B_KDEBUG_CONT : 0; 1572 } 1573 1574 1575 static int 1576 dump_tracing_command(int argc, char** argv) 1577 { 1578 return dump_tracing_internal(argc, argv, NULL); 1579 } 1580 1581 1582 #endif // ENABLE_TRACING 1583 1584 1585 extern "C" uint8* 1586 alloc_tracing_buffer(size_t size) 1587 { 1588 #if ENABLE_TRACING 1589 trace_entry* entry = sTracingMetaData->AllocateEntry( 1590 size + sizeof(trace_entry), BUFFER_ENTRY); 1591 if (entry == NULL) 1592 return NULL; 1593 1594 return (uint8*)(entry + 1); 1595 #else 1596 return NULL; 1597 #endif 1598 } 1599 1600 1601 uint8* 1602 alloc_tracing_buffer_memcpy(const void* source, size_t size, bool user) 1603 { 1604 if (user && !IS_USER_ADDRESS(source)) 1605 return NULL; 1606 1607 uint8* buffer = alloc_tracing_buffer(size); 1608 if (buffer == NULL) 1609 return NULL; 1610 1611 if (user) { 1612 if (user_memcpy(buffer, source, size) != B_OK) 1613 return NULL; 1614 } else 1615 memcpy(buffer, source, size); 1616 1617 return buffer; 1618 } 1619 1620 1621 char* 1622 alloc_tracing_buffer_strcpy(const char* source, size_t maxSize, bool user) 1623 { 1624 if (source == NULL || maxSize == 0) 1625 return NULL; 1626 1627 if (user && !IS_USER_ADDRESS(source)) 1628 return NULL; 1629 1630 // limit maxSize to the actual source string len 1631 if (user) { 1632 ssize_t size = user_strlcpy(NULL, source, 0); 1633 // there's no user_strnlen() 1634 if (size < 0) 1635 return 0; 1636 maxSize = min_c(maxSize, (size_t)size + 1); 1637 } else 1638 maxSize = strnlen(source, maxSize - 1) + 1; 1639 1640 char* buffer = (char*)alloc_tracing_buffer(maxSize); 1641 if (buffer == NULL) 1642 return NULL; 1643 1644 if (user) { 1645 if (user_strlcpy(buffer, source, maxSize) < B_OK) 1646 return NULL; 1647 } else 1648 strlcpy(buffer, source, maxSize); 1649 1650 return buffer; 1651 } 1652 1653 1654 tracing_stack_trace* 1655 capture_tracing_stack_trace(int32 maxCount, int32 skipFrames, bool kernelOnly) 1656 { 1657 #if ENABLE_TRACING 1658 // page_fault_exception() doesn't allow us to gracefully handle a bad 1659 // address in the stack trace, if interrupts are disabled, so we always 1660 // restrict the stack traces to the kernel only in this case. A bad address 1661 // in the kernel stack trace would still cause a panic(), but this is 1662 // probably even desired. 1663 if (!are_interrupts_enabled()) 1664 kernelOnly = true; 1665 1666 tracing_stack_trace* stackTrace 1667 = (tracing_stack_trace*)alloc_tracing_buffer( 1668 sizeof(tracing_stack_trace) + maxCount * sizeof(addr_t)); 1669 1670 if (stackTrace != NULL) { 1671 stackTrace->depth = arch_debug_get_stack_trace( 1672 stackTrace->return_addresses, maxCount, 0, skipFrames + 1, 1673 STACK_TRACE_KERNEL | (kernelOnly ? 0 : STACK_TRACE_USER)); 1674 } 1675 1676 return stackTrace; 1677 #else 1678 return NULL; 1679 #endif 1680 } 1681 1682 1683 addr_t 1684 tracing_find_caller_in_stack_trace(struct tracing_stack_trace* stackTrace, 1685 const addr_t excludeRanges[], uint32 excludeRangeCount) 1686 { 1687 for (int32 i = 0; i < stackTrace->depth; i++) { 1688 addr_t returnAddress = stackTrace->return_addresses[i]; 1689 1690 bool inRange = false; 1691 for (uint32 j = 0; j < excludeRangeCount; j++) { 1692 if (returnAddress >= excludeRanges[j * 2 + 0] 1693 && returnAddress < excludeRanges[j * 2 + 1]) { 1694 inRange = true; 1695 break; 1696 } 1697 } 1698 1699 if (!inRange) 1700 return returnAddress; 1701 } 1702 1703 return 0; 1704 } 1705 1706 1707 void 1708 tracing_print_stack_trace(struct tracing_stack_trace* stackTrace) 1709 { 1710 #if ENABLE_TRACING 1711 print_stack_trace(stackTrace, kprintf); 1712 #endif 1713 } 1714 1715 1716 int 1717 dump_tracing(int argc, char** argv, WrapperTraceFilter* wrapperFilter) 1718 { 1719 #if ENABLE_TRACING 1720 return dump_tracing_internal(argc, argv, wrapperFilter); 1721 #else 1722 return 0; 1723 #endif 1724 } 1725 1726 1727 bool 1728 tracing_is_entry_valid(AbstractTraceEntry* candidate, bigtime_t entryTime) 1729 { 1730 #if ENABLE_TRACING 1731 if (!sTracingMetaData->IsInBuffer(candidate, sizeof(*candidate))) 1732 return false; 1733 1734 if (entryTime < 0) 1735 return true; 1736 1737 TraceEntryIterator iterator; 1738 while (TraceEntry* entry = iterator.Next()) { 1739 AbstractTraceEntry* abstract = dynamic_cast<AbstractTraceEntry*>(entry); 1740 if (abstract == NULL) 1741 continue; 1742 1743 if (abstract != candidate && abstract->Time() > entryTime) 1744 return false; 1745 1746 return candidate->Time() == entryTime; 1747 } 1748 #endif 1749 1750 return false; 1751 } 1752 1753 1754 void 1755 lock_tracing_buffer() 1756 { 1757 #if ENABLE_TRACING 1758 sTracingMetaData->Lock(); 1759 #endif 1760 } 1761 1762 1763 void 1764 unlock_tracing_buffer() 1765 { 1766 #if ENABLE_TRACING 1767 sTracingMetaData->Unlock(); 1768 #endif 1769 } 1770 1771 1772 extern "C" status_t 1773 tracing_init(void) 1774 { 1775 #if ENABLE_TRACING 1776 status_t result = TracingMetaData::Create(sTracingMetaData); 1777 if (result != B_OK) { 1778 memset(&sFallbackTracingMetaData, 0, sizeof(sFallbackTracingMetaData)); 1779 sTracingMetaData = &sFallbackTracingMetaData; 1780 return result; 1781 } 1782 1783 new(nothrow) TracingLogStartEntry(); 1784 1785 add_debugger_command_etc("traced", &dump_tracing_command, 1786 "Dump recorded trace entries", 1787 "[ --printteam ] [ --difftime ] [ --stacktrace ] " 1788 "(\"forward\" | \"backward\") " 1789 "| ([ <start> [ <count> [ <range> ] ] ] " 1790 "[ #<pattern> | (\"filter\" <filter>) ])\n" 1791 "Prints recorded trace entries. If \"backward\" or \"forward\" is\n" 1792 "specified, the command continues where the previous invocation left\n" 1793 "off, i.e. printing the previous respectively next entries (as many\n" 1794 "as printed before). In this case the command is continuable, that is\n" 1795 "afterwards entering an empty line in the debugger will reinvoke it.\n" 1796 "If no arguments are given, the command continues in the direction\n" 1797 "of the last invocation.\n" 1798 "--printteam - enables printing the entries' team IDs.\n" 1799 "--difftime - print difference times for all but the first entry.\n" 1800 "--stacktrace - print stack traces for entries that captured one.\n" 1801 " <start> - The base index of the entries to print. Depending on\n" 1802 " whether the iteration direction is forward or\n" 1803 " backward this will be the first or last entry printed\n" 1804 " (potentially, if a filter is specified). The index of\n" 1805 " the first entry in the trace buffer is 1. If 0 is\n" 1806 " specified, the last <count> recorded entries are\n" 1807 " printed (iteration direction is backward). Defaults \n" 1808 " to 0.\n" 1809 " <count> - The number of entries to be printed. Defaults to 30.\n" 1810 " If negative, the -<count> entries before and\n" 1811 " including <start> will be printed.\n" 1812 " <range> - Only relevant if a filter is specified. Specifies the\n" 1813 " number of entries to be filtered -- depending on the\n" 1814 " iteration direction the entries before or after\n" 1815 " <start>. If more than <count> entries match the\n" 1816 " filter, only the first (forward) or last (backward)\n" 1817 " <count> matching entries will be printed. If 0 is\n" 1818 " specified <range> will be set to <count>. If -1,\n" 1819 " <range> will be set to the number of recorded\n" 1820 " entries.\n" 1821 " <pattern> - If specified only entries containing this string are\n" 1822 " printed.\n" 1823 " <filter> - If specified only entries matching this filter\n" 1824 " expression are printed. The expression can consist of\n" 1825 " prefix operators \"not\", \"and\", \"or\", and\n" 1826 " filters \"'thread' <thread>\" (matching entries\n" 1827 " with the given thread ID), \"'team' <team>\"\n" 1828 "(matching entries with the given team ID), and\n" 1829 " \"#<pattern>\" (matching entries containing the given\n" 1830 " string).\n", 0); 1831 #endif // ENABLE_TRACING 1832 return B_OK; 1833 } 1834 1835 1836 void 1837 ktrace_printf(const char *format, ...) 1838 { 1839 #if ENABLE_TRACING 1840 va_list list; 1841 va_start(list, format); 1842 1843 char buffer[256]; 1844 vsnprintf(buffer, sizeof(buffer), format, list); 1845 1846 va_end(list); 1847 1848 new(nothrow) KernelTraceEntry(buffer); 1849 #endif // ENABLE_TRACING 1850 } 1851 1852 1853 void 1854 _user_ktrace_output(const char *message) 1855 { 1856 #if ENABLE_TRACING 1857 new(nothrow) UserTraceEntry(message); 1858 #endif // ENABLE_TRACING 1859 } 1860 1861