mirror of
https://github.com/privacore/open-source-search-engine.git
synced 2025-01-22 02:18:42 -05:00
536 lines
13 KiB
C++
536 lines
13 KiB
C++
#include "Profiler.h"
|
|
#include <execinfo.h>
|
|
#include "HttpRequest.h"
|
|
#include "HttpServer.h"
|
|
#include "Pages.h"
|
|
#include "Conf.h"
|
|
#include "Hostdb.h"
|
|
#include "Loop.h"
|
|
#include "Mem.h"
|
|
#include "Errno.h"
|
|
#include <fcntl.h>
|
|
#include <unistd.h>
|
|
#include <sys/time.h>
|
|
|
|
|
|
Profiler g_profiler;
|
|
|
|
Profiler::Profiler() :
|
|
m_realTimeProfilerRunning(false),
|
|
rtNumEntries(0),
|
|
hitEntries(NULL),
|
|
m_addressMap(NULL),
|
|
m_addressMapSize(0),
|
|
m_rootFrame(0),
|
|
m_lastDeltaAddress(0),
|
|
m_lastDeltaAddressTime(0),
|
|
m_frameTraces(NULL),
|
|
m_numUsedFrameTraces(0)
|
|
{
|
|
|
|
// Coverity
|
|
m_totalFrames = 0;
|
|
}
|
|
|
|
Profiler::~Profiler() {//reset();
|
|
reset();
|
|
}
|
|
|
|
bool Profiler::reset(){
|
|
m_fn.reset();
|
|
|
|
if(hitEntries)
|
|
mfree(hitEntries, sizeof(HitEntry) * rtNumEntries,
|
|
"hitEntries");
|
|
hitEntries = NULL;
|
|
if(m_addressMap)
|
|
mfree(m_addressMap, sizeof(uint32_t) * m_addressMapSize,
|
|
"m_addressMap");
|
|
m_addressMap = NULL;
|
|
|
|
m_ipBuf.purge();
|
|
|
|
return true;
|
|
}
|
|
|
|
bool Profiler::init() {
|
|
if ( m_ipBuf.getCapacity() <= 0 &&
|
|
! m_ipBuf.reserve ( 5000000 , "profbuf" ) )
|
|
return false;
|
|
|
|
return true;
|
|
}
|
|
|
|
char* Profiler::getFnName( void * address,int32_t *nameLen){
|
|
FnInfo *fnInfo;
|
|
int32_t slot=m_fn.getSlot(&address);
|
|
if(slot!=-1)
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(slot);
|
|
else
|
|
return NULL;
|
|
if (nameLen)
|
|
*nameLen=strlen(fnInfo->m_fnName);
|
|
return fnInfo->m_fnName;
|
|
}
|
|
|
|
bool sendPageProfiler ( TcpSocket *s , HttpRequest *r ) {
|
|
SafeBuf sb;
|
|
sb.reserve2x(32768);
|
|
|
|
//read in all of the possible cgi parms off the bat:
|
|
const char *coll = r->getString ("c");
|
|
if ( ! coll || ! coll[0] ) {
|
|
coll = g_conf.getDefaultColl( );
|
|
}
|
|
|
|
int startRt=(int)r->getLong("rtstart",0);
|
|
int stopRt=(int)r->getLong("rtstop",0);
|
|
|
|
g_pages.printAdminTop ( &sb , s , r );
|
|
|
|
// no permmission?
|
|
bool isMasterAdmin = g_conf.isMasterAdmin ( s , r );
|
|
bool isCollAdmin = g_conf.isCollAdmin ( s , r );
|
|
if ( ! isMasterAdmin && ! isCollAdmin ) {
|
|
startRt = 0;
|
|
stopRt = 0;
|
|
}
|
|
|
|
if (!g_conf.m_profilingEnabled) {
|
|
sb.safePrintf("<font color=#ff0000><b><center>"
|
|
"Sorry, this feature is temporarily disabled. "
|
|
"Enable it in MasterControls.</center></b></font>");
|
|
} else {
|
|
if (g_profiler.m_realTimeProfilerRunning) {
|
|
if (stopRt) {
|
|
g_profiler.stopRealTimeProfiler(false);
|
|
g_profiler.m_ipBuf.purge();
|
|
}
|
|
} else if (startRt) {
|
|
g_profiler.startRealTimeProfiler();
|
|
}
|
|
|
|
g_profiler.printRealTimeInfo(&sb, coll);
|
|
}
|
|
|
|
return g_httpServer.sendDynamicPage ( s, (char*)sb.getBufStart(), sb.length(), -1, false);
|
|
}
|
|
|
|
FrameTrace *
|
|
FrameTrace::set(const intptr_t addr) {
|
|
address = addr;
|
|
return this;
|
|
}
|
|
|
|
FrameTrace *
|
|
FrameTrace::add(const intptr_t addr) {
|
|
//log("add %x", addr);
|
|
// We should be finding children most of the time not adding them.
|
|
int32_t left = 0;
|
|
int32_t right = m_numChildren - 1;
|
|
while(left <= right) {
|
|
const int32_t middle = (left + right) >> 1;
|
|
FrameTrace *frame = m_children[middle];
|
|
if(frame->address == addr) {
|
|
//log("found %x %x", addr, frame);
|
|
return frame;
|
|
}
|
|
if(frame->address < addr) {
|
|
left = middle + 1;
|
|
}
|
|
else {
|
|
right = middle - 1;
|
|
}
|
|
}
|
|
if(m_numChildren == MAX_CHILDREN) {
|
|
log("profiler: Relatime profiler frame trace node full!");
|
|
// This node is full.
|
|
return NULL;
|
|
}
|
|
// Did not find it, add it
|
|
FrameTrace *frame = g_profiler.getNewFrameTrace(addr);
|
|
if(!frame) {
|
|
// Our static buffer must be used up.
|
|
return NULL;
|
|
}
|
|
memmove( m_children + left + 1,
|
|
m_children + left,
|
|
sizeof(FrameTrace *) * (m_numChildren - left));
|
|
m_children[left] = frame;
|
|
++m_numChildren;
|
|
return frame;
|
|
}
|
|
|
|
void
|
|
FrameTrace::dump( SafeBuf *out,
|
|
const uint32_t level,
|
|
uint32_t printStart) const {
|
|
if(level) {
|
|
char *name = g_profiler.getFnName((void*)address);
|
|
out->pad(' ', level);
|
|
uint32_t l;
|
|
if(name && (l = strlen(name))) {
|
|
out->safePrintf("%s ", name);
|
|
} else {
|
|
l = sizeof("Unknown ") - 2;
|
|
out->safePrintf("Unknown ");
|
|
}
|
|
if(hits) {
|
|
out->pushChar(' ');
|
|
out->pad('.', printStart - level - l - 3);
|
|
out->pushChar('|');
|
|
out->safePrintf(" %-10i", hits);
|
|
out->pushChar('|');
|
|
} else {
|
|
out->pad(' ', printStart - level - l - 2);
|
|
out->safePrintf("| |");
|
|
}
|
|
out->safePrintf(" %p |", (void*)address);
|
|
out->safePrintf("\n");
|
|
} else {
|
|
out->safePrintf("|Stack Trace");
|
|
printStart = getPrintLen(0) + 3;
|
|
out->pad(' ', printStart - sizeof("|Stack Trace"));
|
|
out->safePrintf("| Hits | Address |\n");
|
|
out->pad('-', printStart + sizeof("| Hits | Address |") - 2);
|
|
out->safePrintf("\n");
|
|
}
|
|
for(uint32_t i = 0; i < m_numChildren; ++i)
|
|
m_children[i]->dump(out, level + 2, printStart);
|
|
}
|
|
|
|
uint32_t
|
|
FrameTrace::getPrintLen(const uint32_t level) const {
|
|
uint32_t ret = level;
|
|
if(level) {
|
|
char *name = g_profiler.getFnName((void*)address);
|
|
uint32_t l;
|
|
if(!(name && (l = strlen(name)))) {
|
|
l = sizeof("Unknown");
|
|
}
|
|
ret += l;
|
|
}
|
|
for(uint32_t i = 0; i < m_numChildren; ++i) {
|
|
const uint32_t l = m_children[i]->getPrintLen(level + 2);
|
|
if(l > ret) ret = l;
|
|
}
|
|
return ret;
|
|
}
|
|
|
|
void
|
|
Profiler::getStackFrame() {
|
|
|
|
// turn off automatically after 60000 samples
|
|
if ( m_totalFrames++ >= 60000 ) {
|
|
stopRealTimeProfiler(false);
|
|
return;
|
|
}
|
|
|
|
// the lines calling functions
|
|
if ( g_profiler.m_ipBuf.getAvail() <= 8*32 )
|
|
return;
|
|
|
|
// support 64-bit
|
|
void *trace[32];
|
|
int32_t numFrames = backtrace((void **)trace, 32);
|
|
if(numFrames < 3) return;
|
|
|
|
// . now just store the Instruction Ptrs into a count hashtable
|
|
// . skip ahead 2 to avoid the sigalrm function handler
|
|
for ( int32_t i = 2 ; i < numFrames ; i++ ) {
|
|
// even if we are 32-bit, make this 64-bit for ease
|
|
uint64_t addr = (uint64_t)(intptr_t)trace[i];
|
|
|
|
// the call stack path for profiling the worst paths
|
|
g_profiler.m_ipBuf.pushLongLong(addr);
|
|
}
|
|
|
|
// indicate end of call stack path
|
|
g_profiler.m_ipBuf.pushLongLong(0LL);//addr);
|
|
|
|
return;
|
|
}
|
|
|
|
void
|
|
Profiler::startRealTimeProfiler() {
|
|
log(LOG_INIT, "admin: starting real time profiler");
|
|
init();
|
|
m_realTimeProfilerRunning = true;
|
|
m_totalFrames = 0;
|
|
|
|
//set up SIGPROF to be sent every 5 milliseconds
|
|
struct itimerval value;
|
|
value.it_interval.tv_sec = 0;
|
|
value.it_interval.tv_usec = 1000;
|
|
value.it_value.tv_sec = 0;
|
|
value.it_value.tv_usec = 5000;
|
|
if( setitimer( ITIMER_PROF, &value, NULL ) != 0) {
|
|
log(LOG_INIT, "admin: Profiler::startRealTimeProfiler(): setitimer() failed, errno=%d",errno);
|
|
}
|
|
}
|
|
|
|
void
|
|
Profiler::stopRealTimeProfiler(bool keepData) {
|
|
log(LOG_INIT, "admin: stopping real time profiler");
|
|
m_realTimeProfilerRunning = false;
|
|
|
|
//disable SIGPROF
|
|
struct itimerval value;
|
|
value.it_interval.tv_sec = 0;
|
|
value.it_interval.tv_usec = 0;
|
|
value.it_value.tv_sec = 0;
|
|
value.it_value.tv_usec = 0;
|
|
setitimer( ITIMER_PROF, &value, NULL );
|
|
}
|
|
|
|
class PathBucket {
|
|
public:
|
|
char *m_pathStackPtr;
|
|
int32_t m_calledTimes;
|
|
};
|
|
|
|
|
|
static int cmpPathBucket (const void *A, const void *B) {
|
|
const PathBucket *a = *(const PathBucket **)A;
|
|
const PathBucket *b = *(const PathBucket **)B;
|
|
if ( a->m_calledTimes < b->m_calledTimes ) return 1;
|
|
else if ( a->m_calledTimes > b->m_calledTimes ) return -1;
|
|
return 0;
|
|
}
|
|
|
|
bool
|
|
Profiler::printRealTimeInfo(SafeBuf *sb, const char *coll) {
|
|
if(!m_realTimeProfilerRunning) {
|
|
sb->safePrintf("<table %s>",TABLE_STYLE);
|
|
sb->safePrintf("<tr class=hdrow><td colspan=7>"
|
|
"<center><b>Real Time Profiler "
|
|
"<a href=\"/admin/profiler?c=%s"
|
|
"&rtstart=1\">"
|
|
"(Start)</a></b></center>"
|
|
"</td></tr>\n",coll);
|
|
sb->safePrintf("</table><br><br>\n");
|
|
return true;
|
|
}
|
|
stopRealTimeProfiler(true);
|
|
|
|
|
|
sb->safePrintf("<table %s>",TABLE_STYLE);
|
|
sb->safePrintf("<tr class=hdrow>"
|
|
"<td colspan=7>"
|
|
"<b>Top 100 Profiled Line Numbers "
|
|
//"<a href=\"/admin/profiler?c=%s"
|
|
// "&rtall=%i\">%s</a>"
|
|
//,coll,
|
|
// rtall, showMessage);
|
|
);
|
|
sb->safePrintf(
|
|
// "<a href=\"/admin/profiler?c=%s&rtstop=1\">"
|
|
// "(Stop)</a> [Click refresh to get latest profile "
|
|
// "stats][Don't forget to click STOP when done so you "
|
|
// "don't leave the profiler running which can slow "
|
|
//"things down.]"
|
|
"</b>"
|
|
"</td></tr>\n"
|
|
//,coll
|
|
);
|
|
|
|
// system call to get the function names and line numbers
|
|
// just dump the buffer
|
|
char *ip = (char *)m_ipBuf.getBufStart();
|
|
char *ipEnd = (char *)m_ipBuf.getBufPtr();
|
|
SafeBuf ff;
|
|
ff.safePrintf("%strash/profile.txt",g_hostdb.m_dir);
|
|
char *filename = ff.getBufStart();
|
|
unlink ( filename );
|
|
int fd = open ( filename , O_RDWR | O_CREAT , getFileCreationFlags() );
|
|
if ( fd < 0 ) {
|
|
sb->safePrintf("FAILED TO OPEN %s for writing: %s"
|
|
,ff.getBufStart(),mstrerror(errno));
|
|
return false;
|
|
}
|
|
for ( ; ip < ipEnd ; ip += sizeof(uint64_t) ) {
|
|
// 0 marks end of call stack
|
|
if ( *(long long *)ip == 0 ) continue;
|
|
char tmp[64];
|
|
int tlen = sprintf(tmp, "0x%llx\n", *(long long *)ip);
|
|
int nw = write ( fd , tmp , tlen );
|
|
if ( nw != tlen )
|
|
log("profiler: write failed");
|
|
}
|
|
::close(fd);
|
|
SafeBuf cmd;
|
|
SafeBuf newf;
|
|
newf.safePrintf("%strash/output.txt",g_hostdb.m_dir);
|
|
// print the addr again somehow so we know
|
|
cmd.safePrintf("addr2line -a -s -p -C -f -e ./gb < %s | "
|
|
"sort | uniq -c | sort -rn > %s"
|
|
,filename,newf.getBufStart());
|
|
gbsystem ( cmd.getBufStart() );
|
|
|
|
SafeBuf out;
|
|
out.load ( newf.getBufStart());
|
|
|
|
// restrict to top 100 lines
|
|
char *x = out.getBufStart();
|
|
|
|
if ( ! x ) {
|
|
sb->safePrintf("FAILED TO READ trash/output.txt: %s"
|
|
,mstrerror(g_errno));
|
|
return false;
|
|
}
|
|
|
|
int lineCount = 0;
|
|
for ( ; *x ; x++ ) {
|
|
if ( *x != '\n' ) continue;
|
|
if ( ++lineCount >= 100 ) break;
|
|
}
|
|
char c = *x;
|
|
*x = '\0';
|
|
|
|
sb->safePrintf("<tr><td colspan=10>"
|
|
"<pre>"
|
|
"%s"
|
|
"</pre>"
|
|
"</td>"
|
|
"</tr>"
|
|
"</table>"
|
|
, out.getBufStart()
|
|
);
|
|
|
|
*x = c;
|
|
|
|
// now each function is in outbuf with the addr, so make a map
|
|
// and use that map to display the top paths below. we hash the addrs
|
|
// in each callstack together and the count those hashes to get
|
|
// the top winners. and then convert the top winners to the
|
|
// function names.
|
|
char *p = out.getBufStart();
|
|
HashTableX map;
|
|
map.set ( 8,8,1024,NULL,0,false,"pmtb");
|
|
for ( ; *p ; ) {
|
|
// get addr
|
|
uint64_t addr64;
|
|
sscanf ( p , "%*i %" PRIx64" ", &addr64 );
|
|
// skip if 0
|
|
if ( addr64 ) {
|
|
// record it
|
|
int64_t off = p - out.getBufStart();
|
|
map.addKey ( &addr64 , &off );
|
|
}
|
|
// skip to next line
|
|
for ( ; *p && *p !='\n' ; p++ );
|
|
if ( *p ) p++;
|
|
}
|
|
|
|
// now scan m_ipBuf (Instruction Ptr Buf) and make the callstack hashes
|
|
ip = (char *)m_ipBuf.getBufStart();
|
|
ipEnd = (char *)m_ipBuf.getBufPtr();
|
|
char *firstOne = NULL;
|
|
uint64_t hhh = 0LL;
|
|
HashTableX pathTable;
|
|
pathTable.set ( 8,sizeof(PathBucket),1024,NULL,0,false,"pbproftb");
|
|
for ( ; ip < ipEnd ; ip += sizeof(uint64_t) ) {
|
|
if ( ! firstOne ) firstOne = ip;
|
|
uint64_t addr64 = *(uint64_t *)ip;
|
|
// end of a stack
|
|
if ( addr64 != 0LL ) {
|
|
hhh ^= addr64;
|
|
continue;
|
|
}
|
|
// remove the last one though, because that is the line #
|
|
// of the innermost function and we don't want to include it
|
|
//hhh ^= lastAddr64;
|
|
// it's the end, so add it into table
|
|
PathBucket *pb = (PathBucket *)pathTable.getValue ( &hhh );
|
|
if ( pb ) {
|
|
pb->m_calledTimes++;
|
|
firstOne = NULL;
|
|
hhh = 0LL;
|
|
continue;
|
|
}
|
|
// make a new one
|
|
PathBucket npb;
|
|
npb.m_pathStackPtr = firstOne;
|
|
npb.m_calledTimes = 1;
|
|
pathTable.addKey ( &hhh , &npb );
|
|
// start over for next path
|
|
firstOne = NULL;
|
|
hhh = 0LL;
|
|
}
|
|
|
|
// now make a buffer of pointers to the pathbuckets in the table
|
|
SafeBuf sortBuf;
|
|
for ( int32_t i = 0 ; i < pathTable.getNumSlots() ; i++ ) {
|
|
// skip empty slots
|
|
if ( ! pathTable.m_flags[i] ) continue;
|
|
// get the bucket
|
|
PathBucket *pb = (PathBucket *)pathTable.getValueFromSlot(i);
|
|
// store the ptr
|
|
sortBuf.safeMemcpy ( &pb , sizeof(PathBucket *) );
|
|
}
|
|
// now sort it up
|
|
int32_t count = sortBuf.length() / sizeof(PathBucket *);
|
|
qsort(sortBuf.getBufStart(),count,sizeof(PathBucket *),cmpPathBucket);
|
|
|
|
|
|
// show profiled paths
|
|
sb->safePrintf("<br><br><table %s>",TABLE_STYLE);
|
|
sb->safePrintf("<tr class=hdrow>"
|
|
"<td colspan=7>"
|
|
"<b>Top 50 Profiled Paths</b>"
|
|
"</td></tr>"
|
|
"<tr><td colspan=10><pre>");
|
|
|
|
// now print the top 50 out
|
|
char *sp = sortBuf.getBufStart();
|
|
char *spend = sp + sortBuf.length();
|
|
int toPrint = 50;
|
|
for ( ; sp < spend && toPrint > 0 ; sp += sizeof(PathBucket *) ) {
|
|
toPrint--;
|
|
PathBucket *pb = *(PathBucket **)sp;
|
|
// get the callstack into m_ipBuf
|
|
uint64_t *cs = (uint64_t *)pb->m_pathStackPtr;
|
|
// scan those
|
|
for ( ; *cs ; cs++ ) {
|
|
// lookup this addr
|
|
long *outOffPtr = (long *)map.getValue ( cs );
|
|
if ( ! outOffPtr ) {
|
|
sb->safePrintf(" [0x%" PRIx64"]\n",*cs);
|
|
continue;
|
|
}
|
|
// print that line out until \n
|
|
char *a = out.getBufStart() + *outOffPtr;
|
|
for ( ; *a && *a != '\n' ; a++ )
|
|
sb->pushChar(*a);
|
|
sb->pushChar('\n');
|
|
}
|
|
// the count
|
|
sb->safePrintf("<b>%i</b>",(int)pb->m_calledTimes);
|
|
sb->safePrintf("\n-----------------------------\n");
|
|
}
|
|
|
|
|
|
sb->safePrintf("</pre></td></tr></table>");
|
|
|
|
// just leave it off if we printed something. but if we just
|
|
// turn the profiler on then m_ipBuf will be empty so start it
|
|
if ( m_ipBuf.length() == 0 )
|
|
g_profiler.startRealTimeProfiler();
|
|
|
|
return true;
|
|
}
|
|
|
|
void
|
|
Profiler::cleanup() {
|
|
m_rootFrame = 0;
|
|
}
|
|
|
|
FrameTrace *
|
|
Profiler::getNewFrameTrace(const intptr_t addr) {
|
|
if(m_numUsedFrameTraces >= MAX_FRAME_TRACES) {
|
|
log("profiler: Real time profiler ran out of static memory");
|
|
return NULL;
|
|
}
|
|
return m_frameTraces[m_numUsedFrameTraces++].set(addr);
|
|
}
|