From 424f833bc9646c8d5a317485c96f4371fa3a7636 Mon Sep 17 00:00:00 2001 From: Ingo Weinhold Date: Sat, 20 Sep 2008 00:34:03 +0000 Subject: [PATCH] * Changed the profiling API: Instead of sending all functions that shall be tracked to the kernel, which then counts the hits, an area is passed to kernel in which the hits are recorded. When the area is full, the debugger is notified. For some reason that part doesn't work yet -- the whole system freezes when waiting for a reply. * Reorganized the profile tool code a bit. For one with respect to the changed API, but also to prepare tracking of image creation/deletion. git-svn-id: file:///srv/svn/repos/haiku/haiku/trunk@27640 a95241bf-73f2-0310-859d-f6bbb57e9c96 --- headers/os/kernel/debugger.h | 39 +- headers/private/kernel/user_debugger.h | 26 +- src/bin/debug/Jamfile | 1 + src/bin/debug/profile.cpp | 648 +++++++++++++++------- src/system/kernel/debug/user_debugger.cpp | 384 ++++++------- 5 files changed, 658 insertions(+), 440 deletions(-) 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