diff --git a/headers/os/kernel/debugger.h b/headers/os/kernel/debugger.h index a9b1fc7ffc..ca180dd87a 100644 --- a/headers/os/kernel/debugger.h +++ b/headers/os/kernel/debugger.h @@ -171,8 +171,8 @@ typedef enum { B_DEBUGGER_MESSAGE_IMAGE_CREATED, // an image has been created B_DEBUGGER_MESSAGE_IMAGE_DELETED, // an image has been deleted - B_DEBUGGER_MESSAGE_PROFILER_STOPPED, // a profiled thread is going to - // exit + B_DEBUGGER_MESSAGE_PROFILER_UPDATE, // flush the profiling buffer for a + // thread B_DEBUGGER_MESSAGE_HANDED_OVER, // the debugged team has been // handed over to another debugger @@ -363,13 +363,18 @@ typedef struct { port_id reply_port; // port to send the reply to thread_id thread; // thread to profile bigtime_t interval; // sample interval - int32 function_count; // number of functions we count hits for - struct debug_profile_function functions[1]; - // functions that shall be tracked + area_id sample_area; // area into which the sample will be + // written + int32 stack_depth; // number of return address per hit } debug_nub_start_profiler; typedef struct { status_t error; + int32 profile_event; // number of the last event influencing + // profiling (e.g. image + // created/deleted) + bigtime_t interval; // actual sample interval (might + // differ from the requested one) } debug_nub_start_profiler_reply; // B_DEBUG_STOP_PROFILER @@ -379,7 +384,7 @@ typedef struct { thread_id thread; // thread to profile } debug_nub_stop_profiler; -// reply is debug_profiler_stopped +// reply is debug_profiler_update // union of all messages structures sent to the debug nub thread typedef union { @@ -532,17 +537,21 @@ typedef struct { image_info info; // info for the image } debug_image_deleted; -// B_DEBUGGER_MESSAGE_PROFILER_STOPPED +// B_DEBUGGER_MESSAGE_PROFILER_UPDATE typedef struct { debug_origin origin; - int32 function_count; - bigtime_t interval; // actual sample interval (might - // differ from the requested one) - int64 total_ticks; // total number of sample ticks - int64 missed_ticks; // ticks that didn't hit a function - int64 function_ticks[1]; // number of hits for each function -} debug_profiler_stopped; + int32 profile_event; // number of the last event + // influencing profiling (e.g. + // image created/deleted); all + // samples were recorded after this + // event and before the next one + int32 stack_depth; // number of return addresses per + // tick + int32 sample_count; // number of samples in the buffer + bool stopped; // if true, the thread is no longer + // being profiled +} debug_profiler_update; // B_DEBUGGER_MESSAGE_HANDED_OVER @@ -570,7 +579,7 @@ typedef union { debug_thread_deleted thread_deleted; debug_image_created image_created; debug_image_deleted image_deleted; - debug_profiler_stopped profiler_stopped; // dynamic size! + debug_profiler_update profiler_update; debug_handed_over handed_over; debug_origin origin; // for convenience (no real message) diff --git a/headers/private/kernel/user_debugger.h b/headers/private/kernel/user_debugger.h index f6e9ebe336..7fb75cdceb 100644 --- a/headers/private/kernel/user_debugger.h +++ b/headers/private/kernel/user_debugger.h @@ -72,25 +72,29 @@ struct thread_debug_info { // the signals the debugger wishes not to be notified of, when they // occur the next time + // profiling related part; if samples != NULL, the thread is profiled struct { - bigtime_t interval; + bigtime_t interval; // sampling interval + area_id sample_area; + // cloned sample buffer area + addr_t* samples; + // sample buffer + int32 max_samples; + // maximum number of samples the buffer can hold + int32 sample_count; + // number of samples the buffer currently holds + int32 stack_depth; + // number of return addresses to record per timer interval union { - bigtime_t interval_left; + bigtime_t interval_left; // when unscheduled: the time left of the current sampling // interval - bigtime_t timer_end; + bigtime_t timer_end; // when running: the absolute time the timer is supposed to go // off }; - int32 function_count; - // number of tracked functions - struct function_profile_info* functions; - // array of tracked functions - debug_profiler_stopped* result; - // the result message to be sent to the debugger when profiling end; - // contains the current hit counts for all functions - timer* installed_timer; + timer* installed_timer; // when running and being profiled: the CPU's profiling timer } profile; diff --git a/src/bin/debug/Jamfile b/src/bin/debug/Jamfile index 77b39c071c..4f9ed6aa16 100644 --- a/src/bin/debug/Jamfile +++ b/src/bin/debug/Jamfile @@ -1,6 +1,7 @@ SubDir HAIKU_TOP src bin debug ; UsePrivateHeaders debug ; +UsePrivateHeaders kernel ; UsePrivateHeaders libroot ; UsePrivateHeaders shared ; UsePrivateSystemHeaders ; diff --git a/src/bin/debug/profile.cpp b/src/bin/debug/profile.cpp index 6c47cca66e..27f5d63b54 100644 --- a/src/bin/debug/profile.cpp +++ b/src/bin/debug/profile.cpp @@ -19,6 +19,8 @@ #include #include +#include + #include "debug_utils.h" @@ -26,10 +28,21 @@ extern const char* __progname; static const char* kCommandName = __progname; +class Image; +class Team; + + +enum { + SAMPLE_AREA_SIZE = 128 * 1024, + SAMPLE_STACK_DEPTH = 5 +}; + + class Symbol { public: - Symbol(addr_t base, size_t size, const char* name) + Symbol(Image* image, addr_t base, size_t size, const char* name) : + image(image), base(base), size(size), name(name) @@ -38,32 +51,392 @@ public: const char* Name() const { return name.String(); } + Image* image; addr_t base; size_t size; BString name; }; -struct hit_symbol { +struct SymbolComparator { + inline bool operator()(const Symbol* a, const Symbol* b) const + { + return a->base < b->base; + } +}; + + +struct HitSymbol { int64 hits; Symbol* symbol; - inline bool operator<(const hit_symbol& other) const + inline bool operator<(const HitSymbol& other) const { return hits > other.hits; } }; -struct Team; +class Image { +public: + Image(const image_info& info) + : + fInfo(info), + fSymbols(NULL), + fSymbolCount(0) + { + } + + ~Image() + { + if (fSymbols != NULL) { + for (int32 i = 0; i < fSymbolCount; i++) + delete fSymbols[i]; + delete[] fSymbols; + } + } + + const image_info& Info() const + { + return fInfo; + } + + status_t LoadSymbols(debug_symbol_lookup_context* lookupContext) + { + printf("Loading symbols of image \"%s\" (%ld)...\n", fInfo.name, + fInfo.id); + + // create symbol iterator + debug_symbol_iterator* iterator; + status_t error = debug_create_image_symbol_iterator(lookupContext, + fInfo.id, &iterator); + if (error != B_OK) { + printf("Failed to init symbol iterator: %s\n", strerror(error)); + return error; + } + + // iterate through the symbols + BObjectList symbols(512, true); + char symbolName[1024]; + int32 symbolType; + void* symbolLocation; + size_t symbolSize; + while (debug_next_image_symbol(iterator, symbolName, sizeof(symbolName), + &symbolType, &symbolLocation, &symbolSize) == B_OK) { +// printf(" %s %p (%6lu) %s\n", +// symbolType == B_SYMBOL_TYPE_TEXT ? "text" : "data", +// symbolLocation, symbolSize, symbolName); + if (symbolSize > 0 && symbolType == B_SYMBOL_TYPE_TEXT) { + Symbol* symbol = new(std::nothrow) Symbol(this, + (addr_t)symbolLocation, symbolSize, symbolName); + if (symbol == NULL || !symbols.AddItem(symbol)) { + delete symbol; + fprintf(stderr, "%s: Out of memory\n", kCommandName); + debug_delete_image_symbol_iterator(iterator); + return B_NO_MEMORY; + } + } + } + + debug_delete_image_symbol_iterator(iterator); + + // sort the symbols + fSymbolCount = symbols.CountItems(); + fSymbols = new(std::nothrow) Symbol*[fSymbolCount]; + if (fSymbols == NULL) + return B_NO_MEMORY; + + for (int32 i = fSymbolCount - 1; i >= 0 ; i--) + fSymbols[i] = symbols.RemoveItemAt(i); + + std::sort(fSymbols, fSymbols + fSymbolCount, SymbolComparator()); + + return B_OK; + } + + Symbol** Symbols() const + { + return fSymbols; + } + + int32 SymbolCount() const + { + return fSymbolCount; + } + + bool ContainsAddress(addr_t address) const + { + return address >= (addr_t)fInfo.text + && address < (addr_t)fInfo.data + fInfo.data_size; + } + + int32 FindSymbol(addr_t address) const + { + // binary search the function + int32 lower = 0; + int32 upper = fSymbolCount; + + while (lower < upper) { + int32 mid = (lower + upper) / 2; + if (address >= fSymbols[mid]->base + fSymbols[mid]->size) + lower = mid + 1; + else + upper = mid; + } + + if (lower == fSymbolCount) + return -1; + + const Symbol* symbol = fSymbols[lower]; + if (address >= symbol->base && address < symbol->base + symbol->size) + return lower; + return -1; + } + +private: + image_info fInfo; + Symbol** fSymbols; + int32 fSymbolCount; +}; -struct Thread { - thread_info info; - Team* team; +class ThreadImage : public DoublyLinkedListLinkImpl { +public: + ThreadImage(Image* image) + : + fImage(image), + fSymbolHits(NULL), + fTotalHits(0), + fMissedTicks(0) + { + } - thread_id ID() const { return info.thread; } - const char* Name() const { return info.name; } + status_t Init() + { + int32 symbolCount = fImage->SymbolCount(); + fSymbolHits = new(std::nothrow) int64[symbolCount]; + if (fSymbolHits == NULL) + return B_NO_MEMORY; + + memset(fSymbolHits, 0, 8 * symbolCount); + + return B_OK; + } + + bool ContainsAddress(addr_t address) const + { + return fImage->ContainsAddress(address); + } + + void AddHit(addr_t address) + { + int32 symbolIndex = fImage->FindSymbol(address); + if (symbolIndex >= 0) + fSymbolHits[symbolIndex]++; + else + fMissedTicks++; + + fTotalHits++; + } + + Image* GetImage() const + { + return fImage; + } + + const int64* SymbolHits() const + { + return fSymbolHits; + } + + int64 TotalHits() const + { + return fTotalHits; + } + + int64 MissedHits() const + { + return fMissedTicks; + } + +private: + Image* fImage; + int64* fSymbolHits; + int64 fTotalHits; + int64 fMissedTicks; +}; + + +class Thread { +public: + Thread(const thread_info& info, Team* team) + : + fInfo(info), + fTeam(team), + fSampleArea(-1), + fSamples(NULL), + fImages(), + fOldImages(), + fTotalHits(0), + fMissedTicks(0), + fInterval(1) + { + } + + ~Thread() + { + while (ThreadImage* image = fImages.RemoveHead()) + delete image; + while (ThreadImage* image = fOldImages.RemoveHead()) + delete image; + + if (fSampleArea >= 0) + delete_area(fSampleArea); + } + + thread_id ID() const { return fInfo.thread; } + const char* Name() const { return fInfo.name; } + addr_t* Samples() const { return fSamples; } + Team* GetTeam() const { return fTeam; } + + void SetSampleArea(area_id area, addr_t* samples) + { + fSampleArea = area; + fSamples = samples; + } + + void SetInterval(bigtime_t interval) + { + fInterval = interval; + } + + status_t AddImage(Image* image) + { + ThreadImage* threadImage = new(std::nothrow) ThreadImage(image); + if (threadImage == NULL) + return B_NO_MEMORY; + + status_t error = threadImage->Init(); + if (error != B_OK) { + delete threadImage; + return error; + } + + fImages.Add(threadImage); + + return B_OK; + } + + ThreadImage* FindImage(addr_t address) const + { + ImageList::ConstIterator it = fImages.GetIterator(); + while (ThreadImage* image = it.Next()) { + if (image->ContainsAddress(address)) + return image; + } + return NULL; + } + + void AddSamples(int32 count, int32 stackDepth) + { + count = count / stackDepth * stackDepth; + + for (int32 i = 0; i < count; i += stackDepth) { + ThreadImage* image = NULL; + for (int32 k = 0; k < stackDepth; k++) { + addr_t address = fSamples[i + k]; + image = FindImage(address); + if (image != NULL) { + image->AddHit(address); + break; + } + } + + if (image == NULL) + fMissedTicks++; + } + + fTotalHits += count / stackDepth; + } + + void PrintResults() const + { + printf("total hits: %lld, missed: %lld\n", fTotalHits, fMissedTicks); + + int32 symbolCount = 0; + + ImageList::ConstIterator it = fImages.GetIterator(); + while (ThreadImage* image = it.Next()) { + const image_info& imageInfo = image->GetImage()->Info(); + printf(" image: %s (%ld): %lld hits, %lld misses\n", + imageInfo.name, imageInfo.id, image->TotalHits(), + image->MissedHits()); + symbolCount += image->GetImage()->SymbolCount(); + } + + // find and sort the hit symbols + HitSymbol hitSymbols[symbolCount]; + int32 hitSymbolCount = 0; + + it = fImages.GetIterator(); + while (ThreadImage* image = it.Next()) { + Symbol** symbols = image->GetImage()->Symbols(); + const int64* symbolHits = image->SymbolHits(); + int32 imageSymbolCount = image->GetImage()->SymbolCount(); + for (int32 i = 0; i < imageSymbolCount; i++) { + if (symbolHits[i] > 0) { + HitSymbol& hitSymbol = hitSymbols[hitSymbolCount++]; + hitSymbol.hits = symbolHits[i]; + hitSymbol.symbol = symbols[i]; + } + } + } + + if (hitSymbolCount > 1) + std::sort(hitSymbols, hitSymbols + hitSymbolCount); + + int64 totalTicks = fTotalHits; + printf("\nprofiling results for thread \"%s\" (%ld):\n", Name(), ID()); + printf(" tick interval: %lld us\n", fInterval); + printf(" total ticks: %lld (%lld us)\n", totalTicks, + totalTicks * fInterval); + if (totalTicks == 0) + totalTicks = 1; + printf(" missed ticks: %lld (%lld us, %6.2f%%)\n", + fMissedTicks, fMissedTicks * fInterval, + 100.0 * fMissedTicks / totalTicks); + + + if (hitSymbolCount > 0) { + printf("\n"); + printf(" hits in us in %% function\n"); + printf(" -------------------------------------------------" + "-----------------------------\n"); + for (int32 i = 0; i < hitSymbolCount; i++) { + const HitSymbol& hitSymbol = hitSymbols[i]; + const Symbol* symbol = hitSymbol.symbol; + printf(" %10lld %10lld %6.2f %s\n", hitSymbol.hits, + hitSymbol.hits * fInterval, + 100.0 * hitSymbol.hits / totalTicks, + symbol->Name()); + } + } else + printf(" no functions were hit\n"); + } + +private: + typedef DoublyLinkedList ImageList; + +private: + thread_info fInfo; + ::Team* fTeam; + area_id fSampleArea; + addr_t* fSamples; + ImageList fImages; + ImageList fOldImages; + int64 fTotalHits; + int64 fMissedTicks; + bigtime_t fInterval; }; @@ -72,9 +445,7 @@ public: Team() : fNubPort(-1), - fSymbols(1000, true), - fStartProfilerSize(0), - fStartProfiler(NULL) + fImages(20, false) { fInfo.team = -1; fDebugContext.nub_port = -1; @@ -82,13 +453,15 @@ public: ~Team() { - free(fStartProfiler); - if (fDebugContext.nub_port >= 0) destroy_debug_context(&fDebugContext); if (fNubPort >= 0) remove_team_debugger(fInfo.team); + +// TODO: Just decrement ref-count! + for (int32 i = 0; Image* image = fImages.ItemAt(i); i++) + delete image; } status_t Init(team_id teamID, port_id debuggerPort) @@ -129,35 +502,6 @@ public: if (error != B_OK) return error; - // prepare the start profiler message - int32 symbolCount = fSymbols.CountItems(); - if (symbolCount == 0) { - fprintf(stderr, "%s: Got no symbols at all...\n", kCommandName); - return B_ERROR; - } - - printf("Found %ld functions.\n", symbolCount); - - fStartProfilerSize = sizeof(debug_nub_start_profiler) - + (symbolCount - 1) * sizeof(debug_profile_function); -printf("start profiler message size: %lu\n", fStartProfilerSize); - fStartProfiler = (debug_nub_start_profiler*)malloc(fStartProfilerSize); - if (fStartProfiler == NULL) { - fprintf(stderr, "%s: Out of memory\n", kCommandName); - exit(1); - } - - fStartProfiler->reply_port = fDebugContext.reply_port; - fStartProfiler->interval = 1000; - fStartProfiler->function_count = symbolCount; - - for (int32 i = 0; i < symbolCount; i++) { - Symbol* symbol = fSymbols.ItemAt(i); - debug_profile_function& function = fStartProfiler->functions[i]; - function.base = symbol->base; - function.size = symbol->size; - } - // set team debugging flags int32 teamDebugFlags = B_TEAM_DEBUG_THREADS | B_TEAM_DEBUG_TEAM_CREATION; @@ -168,6 +512,29 @@ printf("start profiler message size: %lu\n", fStartProfilerSize); status_t InitThread(Thread* thread) { + // create the sample area + char areaName[B_OS_NAME_LENGTH]; + snprintf(areaName, sizeof(areaName), "profiling samples %ld", + thread->ID()); + void* samples; + area_id sampleArea = create_area(areaName, &samples, B_ANY_ADDRESS, + SAMPLE_AREA_SIZE, B_NO_LOCK, B_READ_AREA | B_WRITE_AREA); + if (sampleArea < 0) { + fprintf(stderr, "%s: Failed to create sample area for thread %ld: " + "%s\n", kCommandName, thread->ID(), strerror(sampleArea)); + return sampleArea; + } + + thread->SetSampleArea(sampleArea, (addr_t*)samples); + + // add the current images to the thread + int32 imageCount = fImages.CountItems(); + for (int32 i = 0; i < imageCount; i++) { + status_t error = thread->AddImage(fImages.ItemAt(i)); + if (error != B_OK) + return error; + } + // set thread debugging flags and start profiling int32 threadDebugFlags = 0; // if (!traceTeam) { @@ -178,10 +545,16 @@ printf("start profiler message size: %lu\n", fStartProfilerSize); set_thread_debugging_flags(fNubPort, thread->ID(), threadDebugFlags); // start profiling - fStartProfiler->thread = thread->ID(); + debug_nub_start_profiler message; + message.reply_port = fDebugContext.reply_port; + message.thread = thread->ID(); + message.interval = 1000; + message.sample_area = sampleArea; + message.stack_depth = SAMPLE_STACK_DEPTH; + debug_nub_start_profiler_reply reply; status_t error = send_debug_message(&fDebugContext, - B_DEBUG_START_PROFILER, fStartProfiler, fStartProfilerSize, &reply, + B_DEBUG_START_PROFILER, &message, sizeof(message), &reply, sizeof(reply)); if (error != B_OK || (error = reply.error) != B_OK) { fprintf(stderr, "%s: Failed to start profiler for thread %ld: %s\n", @@ -189,11 +562,12 @@ printf("start profiler message size: %lu\n", fStartProfilerSize); return error; } + thread->SetInterval(reply.interval); +//reply.profile_event + // resume the target thread to be sure, it's running resume_thread(thread->ID()); - thread->team = this; - return B_OK; } @@ -202,16 +576,6 @@ printf("start profiler message size: %lu\n", fStartProfilerSize); return fInfo.team; } - BObjectList& Symbols() - { - return fSymbols; - } - - int32 SymbolCount() const - { - return fSymbols.CountItems(); - } - private: status_t _LoadSymbols(debug_symbol_lookup_context* lookupContext) { @@ -222,38 +586,22 @@ private: printf("Loading symbols of image \"%s\" (%ld)...\n", imageInfo.name, imageInfo.id); - // create symbol iterator - debug_symbol_iterator* iterator; - status_t error = debug_create_image_symbol_iterator(lookupContext, - imageInfo.id, &iterator); + Image* image = new(std::nothrow) Image(imageInfo); + if (image == NULL) + return B_NO_MEMORY; + + status_t error = image->LoadSymbols(lookupContext); if (error != B_OK) { - printf("Failed to init symbol iterator: %s\n", strerror(error)); + delete image; + if (error == B_NO_MEMORY) + return error; continue; } - // iterate through the images - char symbolName[1024]; - int32 symbolType; - void* symbolLocation; - size_t symbolSize; - while (debug_next_image_symbol(iterator, symbolName, sizeof(symbolName), - &symbolType, &symbolLocation, &symbolSize) == B_OK) { - // printf(" %s %p (%6lu) %s\n", - // symbolType == B_SYMBOL_TYPE_TEXT ? "text" : "data", - // symbolLocation, symbolSize, symbolName); - if (symbolSize > 0 && symbolType == B_SYMBOL_TYPE_TEXT) { - Symbol* symbol = new(std::nothrow) Symbol( - (addr_t)symbolLocation, symbolSize, symbolName); - if (symbol == NULL || !fSymbols.AddItem(symbol)) { - delete symbol; - fprintf(stderr, "%s: Out of memory\n", kCommandName); - debug_delete_image_symbol_iterator(iterator); - return B_NO_MEMORY; - } - } + if (!fImages.AddItem(image)) { + delete image; + return B_NO_MEMORY; } - - debug_delete_image_symbol_iterator(iterator); } return B_OK; @@ -263,9 +611,7 @@ private: team_info fInfo; port_id fNubPort; debug_context fDebugContext; - BObjectList fSymbols; - size_t fStartProfilerSize; - debug_nub_start_profiler* fStartProfiler; + BObjectList fImages; }; @@ -275,9 +621,7 @@ public: : fTeams(20, true), fThreads(20, true), - fDebuggerPort(debuggerPort), - fDebuggerMessage(NULL), - fMaxDebuggerMessageSize(0) + fDebuggerPort(debuggerPort) { } @@ -291,9 +635,6 @@ public: return B_NO_MEMORY; status_t error = team->Init(teamID, fDebuggerPort); - if (error == B_OK) - error = _ReallocateDebuggerMessage(team->SymbolCount()); - if (error != B_OK) { delete team; return error; @@ -321,12 +662,10 @@ public: if (team == NULL) return B_BAD_TEAM_ID; - Thread* thread = new(std::nothrow) Thread; + Thread* thread = new(std::nothrow) Thread(threadInfo, team); if (thread == NULL) return B_NO_MEMORY; - thread->info = threadInfo; - error = team->InitThread(thread); if (error != B_OK) { delete thread; @@ -361,50 +700,16 @@ public: Thread* FindThread(thread_id threadID) const { for (int32 i = 0; Thread* thread = fThreads.ItemAt(i); i++) { - if (thread->info.thread == threadID) + if (thread->ID() == threadID) return thread; } return NULL; } - debug_debugger_message_data* DebuggerMessage() const - { - return fDebuggerMessage; - } - - size_t MaxDebuggerMessageSize() const - { - return fMaxDebuggerMessageSize; - } - -private: - status_t _ReallocateDebuggerMessage(int32 symbolCount) - { - // allocate memory for the reply - size_t maxMessageSize = max_c(sizeof(debug_debugger_message_data), - sizeof(debug_profiler_stopped) + 8 * symbolCount); - if (maxMessageSize <= fMaxDebuggerMessageSize) - return B_OK; - - debug_debugger_message_data* message = (debug_debugger_message_data*) - realloc(fDebuggerMessage, maxMessageSize); - if (message == NULL) { - fprintf(stderr, "%s: Out of memory\n", kCommandName); - return B_NO_MEMORY; - } - - fDebuggerMessage = message; - fMaxDebuggerMessageSize = maxMessageSize; - - return B_OK; - } - private: BObjectList fTeams; BObjectList fThreads; port_id fDebuggerPort; - debug_debugger_message_data* fDebuggerMessage; - size_t fMaxDebuggerMessageSize; }; @@ -533,12 +838,11 @@ main(int argc, const char* const* argv) // debug loop while (true) { - size_t maxMessageSize = threadManager.MaxDebuggerMessageSize(); - debug_debugger_message_data* message = threadManager.DebuggerMessage(); + debug_debugger_message_data message; bool quitLoop = false; int32 code; - ssize_t messageSize = read_port(debuggerPort, &code, message, - maxMessageSize); + ssize_t messageSize = read_port(debuggerPort, &code, &message, + sizeof(message)); if (messageSize < 0) { if (messageSize == B_INTERRUPTED) @@ -550,82 +854,40 @@ main(int argc, const char* const* argv) } switch (code) { - case B_DEBUGGER_MESSAGE_PROFILER_STOPPED: + case B_DEBUGGER_MESSAGE_PROFILER_UPDATE: { +debug_printf("B_DEBUGGER_MESSAGE_PROFILER_UPDATE: thread %ld, %ld samples\n", +message.profiler_update.origin.thread, message.profiler_update.sample_count); Thread* thread = threadManager.FindThread( - message->profiler_stopped.origin.thread); + message.profiler_update.origin.thread); if (thread == NULL) break; - BObjectList& symbols = thread->team->Symbols(); - int32 symbolCount = symbols.CountItems(); + thread->AddSamples(message.profiler_update.sample_count, + message.profiler_update.stack_depth); - int64 totalTicks = message->profiler_stopped.total_ticks; - int64 missedTicks = message->profiler_stopped.missed_ticks; - bigtime_t interval = message->profiler_stopped.interval; - - printf("\nprofiling results for thread \"%s\" (%ld):\n", - thread->Name(), thread->ID()); - printf(" tick interval: %lld us\n", interval); - printf(" total ticks: %lld (%lld us)\n", totalTicks, - totalTicks * interval); - if (totalTicks == 0) - totalTicks = 1; - printf(" missed ticks: %lld (%lld us, %6.2f%%)\n", - missedTicks, missedTicks * interval, - 100.0 * missedTicks / totalTicks); - - // find and sort the hit symbols - hit_symbol hitSymbols[symbolCount]; - int32 hitSymbolCount = 0; - - for (int32 i = 0; i < symbolCount; i++) { - int64 hits = message->profiler_stopped.function_ticks[i]; - if (hits > 0) { - hit_symbol& hitSymbol = hitSymbols[hitSymbolCount++]; - hitSymbol.hits = hits; - hitSymbol.symbol = symbols.ItemAt(i); - } + if (message.profiler_update.stopped) { + thread->PrintResults(); + threadManager.RemoveThread(thread->ID()); } - - if (hitSymbolCount > 1) - std::sort(hitSymbols, hitSymbols + hitSymbolCount); - - if (hitSymbolCount > 0) { - printf("\n"); - printf(" hits in us in %% function\n"); - printf(" -------------------------------------------------" - "-----------------------------\n"); - for (int32 i = 0; i < hitSymbolCount; i++) { - const hit_symbol& hitSymbol = hitSymbols[i]; - const Symbol* symbol = hitSymbol.symbol; - printf(" %10lld %10lld %6.2f %s\n", hitSymbol.hits, - hitSymbol.hits * interval, - 100.0 * hitSymbol.hits / totalTicks, - symbol->Name()); - } - } else - printf(" no functions were hit\n"); - - threadManager.RemoveThread(thread->ID()); break; } case B_DEBUGGER_MESSAGE_TEAM_CREATED: - if (threadManager.AddTeam(message->team_created.new_team) + if (threadManager.AddTeam(message.team_created.new_team) == B_OK) { - threadManager.AddThread(message->team_created.new_team); + threadManager.AddThread(message.team_created.new_team); } break; case B_DEBUGGER_MESSAGE_TEAM_DELETED: // a debugged team is gone -- quit, if it is our team - quitLoop = message->origin.team == teamID; + quitLoop = message.origin.team == teamID; break; case B_DEBUGGER_MESSAGE_THREAD_CREATED: - threadManager.AddThread(message->thread_created.new_thread); + threadManager.AddThread(message.thread_created.new_thread); break; case B_DEBUGGER_MESSAGE_THREAD_DELETED: - threadManager.RemoveThread(message->origin.thread); + threadManager.RemoveThread(message.origin.thread); break; case B_DEBUGGER_MESSAGE_POST_SYSCALL: @@ -647,8 +909,8 @@ main(int argc, const char* const* argv) // tell the thread to continue (only when there is a thread and the // message was synchronous) - if (message->origin.thread >= 0 && message->origin.nub_port >= 0) - continue_thread(message->origin.nub_port, message->origin.thread); + if (message.origin.thread >= 0 && message.origin.nub_port >= 0) + continue_thread(message.origin.nub_port, message.origin.thread); } return 0; diff --git a/src/system/kernel/debug/user_debugger.cpp b/src/system/kernel/debug/user_debugger.cpp index 76c533a2ea..977b9d7cb6 100644 --- a/src/system/kernel/debug/user_debugger.cpp +++ b/src/system/kernel/debug/user_debugger.cpp @@ -39,11 +39,6 @@ #endif -struct function_profile_info : debug_profile_function { - int32 index; -}; - - static port_id sDefaultDebuggerPort = -1; // accessed atomically @@ -57,15 +52,6 @@ static status_t ensure_debugger_installed(team_id teamID, port_id *port = NULL); static void get_team_debug_info(team_debug_info &teamDebugInfo); -struct ProfileFunctionComparator { - inline bool operator()(const function_profile_info& a, - const function_profile_info& b) const - { - return a.base < b.base; - } -}; - - static status_t kill_interruptable_write_port(port_id port, int32 code, const void *buffer, size_t bufferSize) @@ -296,8 +282,8 @@ init_thread_debug_info(struct thread_debug_info *info) info->debug_port = -1; info->ignore_signals = 0; info->ignore_signals_once = 0; - info->profile.functions = NULL; - info->profile.result = NULL; + info->profile.sample_area = -1; + info->profile.samples = NULL; info->profile.installed_timer = NULL; } } @@ -321,8 +307,8 @@ clear_thread_debug_info(struct thread_debug_info *info, bool dying) info->debug_port = -1; info->ignore_signals = 0; info->ignore_signals_once = 0; - info->profile.functions = NULL; - info->profile.result = NULL; + info->profile.sample_area = -1; + info->profile.samples = NULL; } } @@ -331,8 +317,14 @@ void destroy_thread_debug_info(struct thread_debug_info *info) { if (info) { - free(info->profile.functions); - free(info->profile.result); + area_id sampleArea = info->profile.sample_area; + if (sampleArea >= 0) { + area_info areaInfo; + if (get_area_info(sampleArea, &areaInfo) == B_OK) { + unlock_memory(areaInfo.address, areaInfo.size, B_READ_DEVICE); + delete_area(sampleArea); + } + } arch_destroy_thread_debug_info(&info->arch_info); @@ -1002,14 +994,14 @@ user_debug_thread_exiting(struct thread* thread) SpinLocker threadLocker(gThreadSpinlock); thread_debug_info& threadDebugInfo = thread->debug_info; - if (threadDebugInfo.profile.functions == NULL) + if (threadDebugInfo.profile.samples == NULL) return; - int32 functionCount = threadDebugInfo.profile.function_count; - function_profile_info* profileFunctions = threadDebugInfo.profile.functions; - debug_profiler_stopped* profileResult = threadDebugInfo.profile.result; - threadDebugInfo.profile.functions = NULL; - threadDebugInfo.profile.result = NULL; + area_id sampleArea = threadDebugInfo.profile.sample_area; + int32 sampleCount = threadDebugInfo.profile.sample_count; + int32 stackDepth = threadDebugInfo.profile.stack_depth; + threadDebugInfo.profile.sample_area = -1; + threadDebugInfo.profile.samples = NULL; atomic_or(&threadDebugInfo.flags, B_THREAD_DEBUG_DYING); @@ -1017,13 +1009,23 @@ user_debug_thread_exiting(struct thread* thread) interruptsLocker.Unlock(); // notify the debugger - size_t messageSize = sizeof(debug_profiler_stopped) - + 8 * (functionCount - 1); - debugger_write(debuggerPort, B_DEBUGGER_MESSAGE_PROFILER_STOPPED, - profileResult, messageSize, false); + debug_profiler_update message; + message.origin.thread = thread->id; + message.origin.team = thread->team->id; + message.origin.nub_port = -1; // asynchronous message + message.sample_count = sampleCount; + message.stack_depth = stackDepth; + message.stopped = true; + debugger_write(debuggerPort, B_DEBUGGER_MESSAGE_PROFILER_UPDATE, + &message, sizeof(message), false); - free(profileFunctions); - free(profileResult); + if (sampleArea >= 0) { + area_info areaInfo; + if (get_area_info(sampleArea, &areaInfo) == B_OK) { + unlock_memory(areaInfo.address, areaInfo.size, B_READ_DEVICE); + delete_area(sampleArea); + } + } } @@ -1145,60 +1147,49 @@ schedule_profiling_timer(struct thread* thread, bigtime_t interval) } -static function_profile_info* -find_profiled_function(const thread_debug_info& debugInfo, addr_t address) -{ - // binary search the function - function_profile_info* functions = debugInfo.profile.functions; - int32 lower = 0; - int32 upper = debugInfo.profile.function_count; - - while (lower < upper) { - int32 mid = (lower + upper) / 2; - if (address >= functions[mid].base + functions[mid].size) - lower = mid + 1; - else - upper = mid; - } - - if (lower == debugInfo.profile.function_count) - return NULL; - - function_profile_info* function = &functions[lower]; - if (address >= function->base && address < function->base + function->size) - return function; - return NULL; -} - - static int32 profiling_event(timer* /*unused*/) { struct thread* thread = thread_get_current_thread(); thread_debug_info& debugInfo = thread->debug_info; - if (debugInfo.profile.functions != NULL) { - // Find the hit function and increment the tick counter. We - addr_t returnAddresses[B_DEBUG_STACK_TRACE_DEPTH]; - int32 count = arch_debug_get_stack_trace(returnAddresses, - B_DEBUG_STACK_TRACE_DEPTH, 1, 0, false); + if (debugInfo.profile.samples != NULL) { + int32 stackDepth = debugInfo.profile.stack_depth; + addr_t* returnAddresses = debugInfo.profile.samples + + debugInfo.profile.sample_count; + int32 count = arch_debug_get_stack_trace(returnAddresses, stackDepth, 1, + 0, false); - function_profile_info* function = NULL; - for (int32 i = 0; i < count; i++) { - function = find_profiled_function(debugInfo, returnAddresses[i]); - if (function != NULL) - break; + for (int32 i = count; i < stackDepth; i++) + returnAddresses[i] = 0; + + debugInfo.profile.sample_count += stackDepth; + int32 sampleCount = debugInfo.profile.sample_count; + if (debugInfo.profile.max_samples - sampleCount < stackDepth) { + // The sample buffer is full; notify the debugger. + debugInfo.profile.sample_count = 0; + + RELEASE_THREAD_LOCK(); + enable_interrupts(); + + // prepare the message + debug_profiler_update message; + message.sample_count = sampleCount; + message.stack_depth = stackDepth; + message.stopped = true; + + thread_hit_debug_event(B_DEBUGGER_MESSAGE_PROFILER_UPDATE, &message, + sizeof(message), false); + + disable_interrupts(); + GRAB_THREAD_LOCK(); } + } - if (function != NULL) - debugInfo.profile.result->function_ticks[function->index]++; - else - debugInfo.profile.result->missed_ticks++; - debugInfo.profile.result->total_ticks++; - - // reschedule timer + // reschedule timer + if (debugInfo.profile.samples != NULL) schedule_profiling_timer(thread, debugInfo.profile.interval); - } else + else debugInfo.profile.installed_timer = NULL; return B_HANDLED_INTERRUPT; @@ -1225,7 +1216,7 @@ user_debug_thread_unscheduled(struct thread* thread) void user_debug_thread_scheduled(struct thread* thread) { - if (thread->debug_info.profile.functions != NULL) { + if (thread->debug_info.profile.samples != NULL) { // install profiling timer schedule_profiling_timer(thread, thread->debug_info.profile.interval_left); @@ -1537,7 +1528,7 @@ debug_nub_thread(void *) int32 command; debug_nub_message_data message; ssize_t messageSize = read_port_etc(port, &command, &message, - sizeof(message), B_PEEK_PORT_MESSAGE | B_KILL_CAN_INTERRUPT, 0); + sizeof(message), B_KILL_CAN_INTERRUPT, 0); if (messageSize < 0) { // The port is no longer valid or we were interrupted by a kill @@ -1561,12 +1552,10 @@ debug_nub_thread(void *) debug_nub_get_signal_masks_reply get_signal_masks; debug_nub_get_signal_handler_reply get_signal_handler; debug_nub_start_profiler_reply start_profiler; - debug_profiler_stopped stop_profiler; + debug_profiler_update profiler_update; } reply; - void* replyToSend = &reply; int32 replySize = 0; port_id replyPort = -1; - bool removeCommandMessage = true; // process the command switch (command) { @@ -2112,128 +2101,85 @@ debug_nub_thread(void *) // get the parameters thread_id threadID = message.start_profiler.thread; replyPort = message.start_profiler.reply_port; - int32 functionCount = message.start_profiler.function_count; + area_id sampleArea = message.start_profiler.sample_area; + int32 stackDepth = message.start_profiler.stack_depth; + bigtime_t interval = max_c(message.start_profiler.interval, + B_DEBUG_MIN_PROFILE_INTERVAL); status_t result = B_OK; TRACE(("nub thread %ld: B_DEBUG_START_PROFILER: " - "thread: %ld, %ld functions\n", nubThread->id, threadID, - functionCount)); + "thread: %ld, sample area: %ld\n", nubThread->id, threadID, + sampleArea)); - if (functionCount < 1 - || functionCount > B_DEBUG_MAX_PROFILE_FUNCTIONS) { - result = B_BAD_VALUE; - } + if (stackDepth < 1) + stackDepth = 1; + else if (stackDepth > B_DEBUG_STACK_TRACE_DEPTH) + stackDepth = B_DEBUG_STACK_TRACE_DEPTH; - // allocate memory for the complete message - debug_nub_start_profiler* profileMessage = NULL; - size_t size = 0; + // clone the sample area + area_info areaInfo; + if (result == B_OK) + result = get_area_info(sampleArea, &areaInfo); + + area_id clonedSampleArea = -1; + void* samples = NULL; if (result == B_OK) { - size = (addr_t)&message.start_profiler.functions[ - functionCount] - - (addr_t)&message.start_profiler; - profileMessage = (debug_nub_start_profiler*)malloc(size); - if (profileMessage == NULL) - result = B_NO_MEMORY; - } - MemoryDeleter profileMessageDeleter(profileMessage); - - // read the complete message from the port - if (result == B_OK) { - int32 dummy; - ssize_t bytesRead = read_port_etc(port, &dummy, - profileMessage, size, B_RELATIVE_TIMEOUT, 0); - if (bytesRead < 0) { - result = bytesRead; - } else { - removeCommandMessage = false; - - if ((size_t)bytesRead != size) - result = B_BAD_VALUE; - } - } - - // allocate memory for the function infos - function_profile_info* profileFunctions = NULL; - if (result == B_OK) { - profileFunctions = (function_profile_info*)malloc( - sizeof(function_profile_info) * functionCount); - if (profileFunctions == NULL) - result = B_NO_MEMORY; - } - MemoryDeleter profileFunctionsDeleter(profileFunctions); - - // allocate memory for the reply - debug_profiler_stopped* profileResult = NULL; - size_t profileResultSize = 0; - if (result == B_OK) { - profileResultSize = sizeof(debug_profiler_stopped) - + 8 * (functionCount - 1); - profileResult - = (debug_profiler_stopped*)malloc(profileResultSize); - if (profileResult == NULL) - result = B_NO_MEMORY; - } - MemoryDeleter profileResultDeleter(profileResult); - - // transfer the function array from the message - if (result == B_OK) { - for (int32 i = 0; i < functionCount; i++) { - profileFunctions[i].base - = profileMessage->functions[i].base; - profileFunctions[i].size - = profileMessage->functions[i].size; - profileFunctions[i].index = i; - } - } - - // sort the functions and prepare the reply - if (result == B_OK) { - std::sort(profileFunctions, - profileFunctions + functionCount, - ProfileFunctionComparator()); - - memset(profileResult, 0, profileResultSize); - profileResult->origin.thread = threadID; - profileResult->origin.team = nubThread->team->id; - profileResult->origin.nub_port = -1; - profileResult->interval = max_c(profileMessage->interval, - B_DEBUG_MIN_PROFILE_INTERVAL); - profileResult->function_count = functionCount; + clonedSampleArea = clone_area("profiling samples", &samples, + B_ANY_KERNEL_ADDRESS, B_READ_AREA | B_WRITE_AREA, + sampleArea); + if (clonedSampleArea >= 0) { + // we need the memory locked + result = lock_memory(samples, areaInfo.size, + B_READ_DEVICE); + if (result != B_OK) { + delete_area(clonedSampleArea); + clonedSampleArea = -1; + } + } else + result = clonedSampleArea; } // get the thread and set the profile info - cpu_status state = disable_interrupts(); - GRAB_THREAD_LOCK(); - - struct thread *thread - = thread_get_thread_struct_locked(threadID); - if (thread && thread->team == nubThread->team) { - thread_debug_info &threadDebugInfo = thread->debug_info; - if (threadDebugInfo.profile.functions == NULL) { - threadDebugInfo.profile.interval - = profileResult->interval; - threadDebugInfo.profile.interval_left - = threadDebugInfo.profile.interval; - threadDebugInfo.profile.function_count = functionCount; - threadDebugInfo.profile.functions = profileFunctions; - threadDebugInfo.profile.result = profileResult; - threadDebugInfo.profile.installed_timer = NULL; - } else - result = B_BAD_VALUE; - } else - result = B_BAD_THREAD_ID; - - RELEASE_THREAD_LOCK(); - restore_interrupts(state); - - // if all went well, keep the allocated structures if (result == B_OK) { - profileFunctionsDeleter.Detach(); - profileResultDeleter.Detach(); + cpu_status state = disable_interrupts(); + GRAB_THREAD_LOCK(); + + struct thread *thread + = thread_get_thread_struct_locked(threadID); + if (thread && thread->team == nubThread->team) { + thread_debug_info &threadDebugInfo = thread->debug_info; + if (threadDebugInfo.profile.samples == NULL) { + threadDebugInfo.profile.interval = interval; + threadDebugInfo.profile.sample_area + = clonedSampleArea; + threadDebugInfo.profile.samples = (addr_t*)samples; + threadDebugInfo.profile.max_samples + = areaInfo.size / sizeof(addr_t); + threadDebugInfo.profile.sample_count = 0; + threadDebugInfo.profile.stack_depth = stackDepth; + threadDebugInfo.profile.interval_left = interval; + threadDebugInfo.profile.installed_timer = NULL; + } else + result = B_BAD_VALUE; + } else + result = B_BAD_THREAD_ID; + + RELEASE_THREAD_LOCK(); + restore_interrupts(state); + } + + // on error unlock and delete the sample area + if (result != B_OK) { + if (clonedSampleArea >= 0) { + unlock_memory(samples, areaInfo.size, B_READ_DEVICE); + delete_area(clonedSampleArea); + } } // send a reply to the debugger +// TODO: profile_event reply.start_profiler.error = result; + reply.start_profiler.interval = interval; sendReply = true; replySize = sizeof(reply.start_profiler); @@ -2250,9 +2196,10 @@ debug_nub_thread(void *) TRACE(("nub thread %ld: B_DEBUG_STOP_PROFILER: " "thread: %ld\n", nubThread->id, threadID)); - function_profile_info* profileFunctions = NULL; - debug_profiler_stopped* profileResult = NULL; - int32 functionCount = 0; + area_id sampleArea = -1; + addr_t* samples = NULL; + int32 sampleCount = 0; + int32 stackDepth = 0; // get the thread and detach the profile info cpu_status state = disable_interrupts(); @@ -2262,12 +2209,13 @@ debug_nub_thread(void *) = thread_get_thread_struct_locked(threadID); if (thread && thread->team == nubThread->team) { thread_debug_info &threadDebugInfo = thread->debug_info; - if (threadDebugInfo.profile.functions != NULL) { - functionCount = threadDebugInfo.profile.function_count; - profileFunctions = threadDebugInfo.profile.functions; - profileResult = threadDebugInfo.profile.result; - threadDebugInfo.profile.functions = NULL; - threadDebugInfo.profile.result = NULL; + if (threadDebugInfo.profile.samples != NULL) { + sampleArea = threadDebugInfo.profile.sample_area; + samples = threadDebugInfo.profile.samples; + sampleCount = threadDebugInfo.profile.sample_count; + stackDepth = threadDebugInfo.profile.stack_depth; + threadDebugInfo.profile.sample_area = -1; + threadDebugInfo.profile.samples = NULL; } else result = B_BAD_VALUE; } else @@ -2278,37 +2226,31 @@ debug_nub_thread(void *) // prepare the reply if (result == B_OK) { - replyToSend = profileResult; - replySize = sizeof(debug_profiler_stopped) - + 8 * (functionCount - 1); - } else { - reply.stop_profiler.origin.thread = result; - reply.stop_profiler.total_ticks = 0; - reply.stop_profiler.missed_ticks = 0; - replySize = sizeof(reply.stop_profiler); - } + reply.profiler_update.origin.thread = threadID; +// TODO: profile_event + reply.profiler_update.stack_depth = stackDepth; + reply.profiler_update.sample_count = sampleCount; + reply.profiler_update.stopped = true; + } else + reply.profiler_update.origin.thread = result; + + replySize = sizeof(debug_profiler_update); sendReply = true; - free(profileFunctions); - // profileResult is the reply to be sent and will be deleted - // after sending. + if (sampleArea >= 0) { + area_info areaInfo; + if (get_area_info(sampleArea, &areaInfo) == B_OK) { + unlock_memory(samples, areaInfo.size, B_READ_DEVICE); + delete_area(sampleArea); + } + } } } - // We only peeked the command message -- unless the command handler did - // that already, we need to remove the message from the port. - if (removeCommandMessage) { - int32 dummy; - read_port_etc(port, &dummy, NULL, 0, B_RELATIVE_TIMEOUT, 0); - } - // send the reply, if necessary if (sendReply) { status_t error = kill_interruptable_write_port(replyPort, command, - replyToSend, replySize); - - if (replyToSend != &reply) - free(replyToSend); + &reply, replySize); if (error != B_OK) { // The debugger port is either not longer existing or we got