mirror of
https://github.com/gigablast/open-source-search-engine.git
synced 2024-10-05 12:47:37 +03:00
1771 lines
53 KiB
C++
1771 lines
53 KiB
C++
#ifdef CYGWIN
|
|
|
|
#include "Profiler.h"
|
|
Profiler::Profiler(){return;}
|
|
Profiler::~Profiler(){return;}
|
|
bool Profiler::reset(){return true;}
|
|
bool Profiler::init(){return true;}
|
|
char *Profiler::getFnName(unsigned long address,long *nameLen){return NULL;}
|
|
void Profiler::stopRealTimeProfiler(const bool keepData){return;}
|
|
void Profiler::cleanup(){return;}
|
|
bool Profiler:: readSymbolTable(){return true;}
|
|
bool sendPageProfiler ( class TcpSocket *s,class HttpRequest *r){return true;}
|
|
Profiler g_profiler;
|
|
|
|
#else
|
|
|
|
#include <execinfo.h>
|
|
#include <assert.h>
|
|
#include "gb-include.h"
|
|
#include "Profiler.h"
|
|
#include "Stats.h"
|
|
#include "sort.h"
|
|
#include "Users.h"
|
|
Profiler g_profiler;
|
|
|
|
|
|
static int decend_cmpUll ( const void *h1 , const void *h2 );
|
|
static int decend_cmpF ( const void *h1 , const void *h2 );
|
|
unsigned long *indexTable;
|
|
unsigned long *keyTable;
|
|
unsigned long long *valueTableUll;
|
|
float *valueTableF;
|
|
//HashTableT<uint32_t, uint64_t> realTimeProfilerData;
|
|
#include "HashTableX.h"
|
|
HashTableX realTimeProfilerData;
|
|
uint32_t lastQuickPollAddress = 0;
|
|
uint64_t lastQuickPollTime = 0;
|
|
|
|
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)
|
|
{
|
|
}
|
|
|
|
Profiler::~Profiler() {//reset();
|
|
reset();
|
|
}
|
|
|
|
bool Profiler::reset(){
|
|
m_fn.reset();
|
|
m_lastQPUsed = 0;
|
|
for (long i=0;i<11;i++)
|
|
m_fnTmp[i].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_activeFns.reset();
|
|
m_quickpolls.reset();
|
|
return true;
|
|
}
|
|
|
|
bool Profiler::init() {
|
|
m_lastQPUsed = 0;
|
|
realTimeProfilerData.set(4,8,0,NULL,0,false,0,"rtprof");
|
|
m_quickpolls.set(4,4,0,NULL,0,false,0,"qckpllcnt");
|
|
for (long i=0;i<11;i++)
|
|
//m_fnTmp[i].set(256);
|
|
if ( ! m_fnTmp[i].set(4,sizeof(FnInfo),256,NULL,0,false,0,
|
|
"fntmp"))
|
|
return false;
|
|
if ( ! m_activeFns.set(4,4,256,NULL,0,false,0,"activefns") )
|
|
return false;
|
|
return m_fn.set(4,sizeof(FnInfo),65536,NULL,0,false,0,"fntbl");
|
|
}
|
|
|
|
|
|
// This reads the symbol table of gb executable (thought to be the file gb in
|
|
// the working directory) into a hashtable.
|
|
// The gb executable file is in the ELF format, and the code here resembles
|
|
// readelf function in binutils from gnu.org. gb is 32-bits.
|
|
bool Profiler:: readSymbolTable(){
|
|
long long start=gettimeofdayInMillisecondsLocal();
|
|
struct stat statbuf;
|
|
//unsigned int i;
|
|
char fileName[512];
|
|
|
|
sprintf(fileName,"%sgb",g_hostdb.m_dir);
|
|
//Checking to see if the file is present
|
|
if (stat (fileName, & statbuf) < 0)
|
|
{
|
|
log(LOG_INIT,"admin: Cannot stat input file %s."
|
|
"You must be in the same directory", fileName);
|
|
return false;
|
|
}
|
|
|
|
m_file = fopen (fileName, "rb");
|
|
if (m_file == NULL)
|
|
{
|
|
log (LOG_INIT,"admin: Input file %s not found.", fileName);
|
|
return false;
|
|
}
|
|
|
|
if (! getFileHeader (m_file))
|
|
{
|
|
log(LOG_INIT,"admin: %s, Failed to read file header", fileName);
|
|
fclose (m_file);
|
|
return false;
|
|
}
|
|
|
|
processSectionHeaders (m_file);
|
|
|
|
/* process_program_headers (m_file);
|
|
|
|
process_dynamic_segment (m_file);
|
|
|
|
process_relocs (m_file);*/
|
|
|
|
processSymbolTable (m_file);
|
|
|
|
long long end=gettimeofdayInMillisecondsLocal();
|
|
log(LOG_INIT,"admin: Took %lli milliseconds to build symbol table",
|
|
end-start);
|
|
mfree(m_sectionHeaders,m_elfHeader.e_shnum * sizeof (Elf_Internal_Shdr),
|
|
"ProfilerD");
|
|
mfree(m_stringTable,m_stringTableSize,"ProfilerB");
|
|
fclose (m_file);
|
|
return true;
|
|
}
|
|
|
|
|
|
bool Profiler:: getFileHeader (FILE * file){
|
|
/* Read in the identity array. */
|
|
if (fread (m_elfHeader.e_ident, EI_NIDENT, 1, file) != 1)
|
|
return 0;
|
|
|
|
/* Determine how to read the rest of the header. */
|
|
//Found that gb is little_endian
|
|
//Found that bfd_vma type is unsigned long
|
|
//gb is supposed to be 32-bit
|
|
/* Read in the rest of the header. */
|
|
Elf32_External_Ehdr ehdr32;
|
|
|
|
if (fread (ehdr32.e_type, sizeof (ehdr32) - EI_NIDENT, 1, file) != 1)
|
|
return 0;
|
|
|
|
m_elfHeader.e_type = getByte (ehdr32.e_type,sizeof(ehdr32.e_type));
|
|
m_elfHeader.e_machine = getByte (ehdr32.e_machine,sizeof(ehdr32.e_machine));
|
|
m_elfHeader.e_version = getByte (ehdr32.e_version,sizeof(ehdr32.e_version));
|
|
m_elfHeader.e_entry = getByte (ehdr32.e_entry,sizeof(ehdr32.e_entry));
|
|
m_elfHeader.e_phoff = getByte (ehdr32.e_phoff,sizeof(ehdr32.e_phoff));
|
|
m_elfHeader.e_shoff = getByte (ehdr32.e_shoff,sizeof(ehdr32.e_shoff));
|
|
m_elfHeader.e_flags = getByte (ehdr32.e_flags,sizeof(ehdr32.e_flags));
|
|
m_elfHeader.e_ehsize = getByte (ehdr32.e_ehsize,sizeof(ehdr32.e_ehsize));
|
|
m_elfHeader.e_phentsize = getByte (ehdr32.e_phentsize,sizeof(ehdr32.e_phentsize));
|
|
m_elfHeader.e_phnum = getByte (ehdr32.e_phnum,sizeof(ehdr32.e_phnum));
|
|
m_elfHeader.e_shentsize = getByte (ehdr32.e_shentsize,sizeof(ehdr32.e_shentsize));
|
|
m_elfHeader.e_shnum = getByte (ehdr32.e_shnum,sizeof(ehdr32.e_shnum));
|
|
m_elfHeader.e_shstrndx = getByte (ehdr32.e_shstrndx,sizeof(ehdr32.e_shstrndx));
|
|
return 1;
|
|
}
|
|
|
|
unsigned long Profiler::getByte (unsigned char * field,int size){
|
|
switch (size)
|
|
{
|
|
case 1:
|
|
return * field;
|
|
|
|
case 2:
|
|
return ((unsigned int) (field [0]))
|
|
| (((unsigned int) (field [1])) << 8);
|
|
|
|
case 8:
|
|
/* We want to extract data from an 8 byte wide field and
|
|
place it into a 4 byte wide field. Since this is a little
|
|
endian source we can juts use the 4 byte extraction code. */
|
|
/* Fall through. */
|
|
case 4:
|
|
return ((unsigned long) (field [0]))
|
|
| (((unsigned long) (field [1])) << 8)
|
|
| (((unsigned long) (field [2])) << 16)
|
|
| (((unsigned long) (field [3])) << 24);
|
|
default:
|
|
log(LOG_INIT,"admin: Unhandled data length: %d", size);
|
|
char *xx=NULL; xx=0;
|
|
return 0;
|
|
}
|
|
return 0;
|
|
}
|
|
|
|
|
|
static int s_addressMapCmp(const void *A, const void *B) {
|
|
if(*(uint32_t*)A < *(uint32_t*)B) return -1;
|
|
else if(*(uint32_t*)A > *(uint32_t*)B) return 1;
|
|
return 0;
|
|
}
|
|
|
|
bool Profiler::processSymbolTable (FILE * file){
|
|
Elf_Internal_Shdr * section;
|
|
unsigned int i;
|
|
Elf_Internal_Shdr * string_sec = NULL;
|
|
|
|
if(m_addressMap)
|
|
mfree(m_addressMap, sizeof(uint32_t) * m_addressMapSize, "m_addressMap");
|
|
|
|
m_addressMapSize = 0;
|
|
|
|
for(i = 0, section = m_sectionHeaders; i < m_elfHeader.e_shnum; ++i, ++section) {
|
|
if ( section->sh_type != SHT_SYMTAB
|
|
&& section->sh_type != SHT_DYNSYM)
|
|
continue;
|
|
unsigned int si;
|
|
Elf_Internal_Sym * symtab;
|
|
Elf_Internal_Sym * psym;
|
|
symtab = get32bitElfSymbols(file, section->sh_offset,
|
|
section->sh_size / section->sh_entsize);
|
|
if(!symtab) continue;
|
|
for (si = 0, psym = symtab;
|
|
si < section->sh_size / section->sh_entsize;
|
|
si ++, psym ++)
|
|
if (((long)psym->st_size)>0)
|
|
++m_addressMapSize;
|
|
mfree (symtab,
|
|
(section->sh_size/section->sh_entsize)*sizeof(Elf32_External_Sym),
|
|
"ProfilerF");
|
|
}
|
|
|
|
m_addressMap = (uint32_t *)mmalloc(sizeof(uint32_t) * m_addressMapSize, "m_addressMap");
|
|
m_lastAddressMapIndex = 0;
|
|
|
|
for (i = 0, section = m_sectionHeaders;
|
|
i < m_elfHeader.e_shnum;
|
|
i++, section++){
|
|
unsigned int si;
|
|
char * strtab;
|
|
Elf_Internal_Sym * symtab;
|
|
Elf_Internal_Sym * psym;
|
|
|
|
if ( section->sh_type != SHT_SYMTAB
|
|
&& section->sh_type != SHT_DYNSYM)
|
|
continue;
|
|
|
|
log(LOG_INIT,"admin: Symbol table '%s' contains %lu entries",
|
|
m_stringTable+section->sh_name,
|
|
(unsigned long) (section->sh_size / section->sh_entsize));
|
|
//log(LOG_WARN,"Profiler: Num\t Value\t Size\t Name");
|
|
symtab = get32bitElfSymbols(file, section->sh_offset,
|
|
section->sh_size / section->sh_entsize);
|
|
if (symtab == NULL)
|
|
continue;
|
|
|
|
if (section->sh_link == m_elfHeader.e_shstrndx)
|
|
strtab = m_stringTable;
|
|
else{
|
|
string_sec = m_sectionHeaders + section->sh_link;
|
|
|
|
if (fseek (m_file,string_sec->sh_offset, SEEK_SET)){
|
|
log(LOG_INIT,"admin: Unable to seek to start "
|
|
"of %s at %lx", "string table",
|
|
string_sec->sh_offset);
|
|
return 0;
|
|
}
|
|
strtab = (char *) mmalloc (string_sec->sh_size,
|
|
"ProfilerG");
|
|
if (strtab == NULL){
|
|
log(LOG_INIT,"admin: Out of memory allocating "
|
|
"%ld bytes for %s", string_sec->sh_size,
|
|
"string table");
|
|
}
|
|
if (fread ( strtab, string_sec->sh_size, 1,
|
|
m_file) != 1 ){
|
|
log(LOG_INIT,"admin: Unable to read in %ld "
|
|
"bytes of %s", string_sec->sh_size,
|
|
"string table");
|
|
mfree (strtab,string_sec->sh_size,"ProfilerG");
|
|
strtab = NULL;
|
|
return 0;
|
|
}
|
|
}
|
|
for (si = 0, psym = symtab;
|
|
si < section->sh_size / section->sh_entsize;
|
|
si ++, psym ++){
|
|
if (((long)psym->st_size)>0){
|
|
// FnInfo *fnInfo;
|
|
long key = psym->st_value;
|
|
long slot=m_fn.getSlot(&key);
|
|
if (slot!=-1){
|
|
//fnInfo=m_fn.getValuePointerFromSlot(slot);
|
|
//This is happeninig because the
|
|
// symbol table stores the same
|
|
// variable through two section headers
|
|
//There is a WEAK type and a GLOBAL
|
|
// type. Doesn't seem to create a
|
|
// problem for the profiler
|
|
// log(LOG_WARN,"Profiler: Two "
|
|
// "functions pointing to "
|
|
// "same address space %li",
|
|
// (long)psym->st_value);
|
|
}
|
|
else{
|
|
FnInfo fnInfoTmp;
|
|
strncpy(fnInfoTmp.m_fnName,
|
|
strtab+psym->st_name,255);
|
|
|
|
char* end = strnstr(fnInfoTmp.m_fnName,
|
|
255, "__");
|
|
if(end)
|
|
*end = '\0';
|
|
else
|
|
fnInfoTmp.m_fnName[gbstrlen(strtab+psym->st_name)]='\0';
|
|
fnInfoTmp.m_timesCalled=0;
|
|
fnInfoTmp.m_totalTimeTaken=0;
|
|
fnInfoTmp.m_maxTimeTaken=0;
|
|
fnInfoTmp.m_numCalledFromThread=0;
|
|
fnInfoTmp.m_inFunction = 0;
|
|
fnInfoTmp.m_maxBlockedTime = 0;
|
|
fnInfoTmp.m_lastQpoll = "";
|
|
fnInfoTmp.m_prevQpoll = "";
|
|
unsigned long address=(long)psym->st_value;
|
|
//log(LOG_WARN,"Profiler: Adding fninfo name=%s, key=%li",
|
|
// fnInfo->m_fnName,address);
|
|
long key = (long)address;
|
|
m_fn.addKey(&key,&fnInfoTmp);
|
|
m_addressMap[m_lastAddressMapIndex++] = address;
|
|
}
|
|
}
|
|
/*log(LOG_WARN,"%6d\t %8.8lx\t %5ld\t %s",
|
|
si,(unsigned long)psym->st_value,
|
|
(long)psym->st_size,strtab + psym->st_name);*/
|
|
}
|
|
mfree (symtab,
|
|
(section->sh_size/section->sh_entsize)*sizeof(Elf32_External_Sym),
|
|
"ProfilerF");
|
|
if (strtab != m_stringTable)
|
|
mfree (strtab,string_sec->sh_size,"ProfilerG");
|
|
}
|
|
gbqsort(m_addressMap, m_lastAddressMapIndex, sizeof(uint32_t), s_addressMapCmp);
|
|
return 1;
|
|
}
|
|
|
|
Elf_Internal_Sym *Profiler::get32bitElfSymbols(FILE * file,
|
|
unsigned long offset,
|
|
unsigned long number){
|
|
Elf32_External_Sym* esyms;
|
|
Elf_Internal_Sym *isyms;
|
|
Elf_Internal_Sym *psym;
|
|
unsigned int j;
|
|
|
|
// GET_DATA_ALLOC (offset, number * sizeof (Elf32_External_Sym),
|
|
// esyms, Elf32_External_Sym *, "symbols");
|
|
|
|
if (fseek(file, offset, SEEK_SET)){
|
|
log(LOG_INIT,"admin: Unable to seek to start of %s at %lx", "symbols", offset);
|
|
return 0;
|
|
}
|
|
esyms = (Elf32_External_Sym *)
|
|
mmalloc (number * sizeof (Elf32_External_Sym),"ProfilerE");
|
|
if (esyms==NULL){
|
|
log(LOG_INIT,"admin: Out of memory allocating %ld bytes for %s",
|
|
number *sizeof (Elf32_External_Sym),"Symbols");
|
|
return 0;
|
|
}
|
|
|
|
if (fread (esyms,number * sizeof (Elf32_External_Sym), 1, file) != 1){
|
|
log(LOG_INIT,"admin: Unable to read in %ld bytes of %s",
|
|
number * sizeof (Elf32_External_Sym), "symbols");
|
|
mfree (esyms,number * sizeof (Elf32_External_Sym),"ProfilerE");
|
|
esyms = NULL;
|
|
return 0;
|
|
}
|
|
long need = number * sizeof (Elf_Internal_Sym);
|
|
isyms = (Elf_Internal_Sym *) mmalloc (need,"ProfilerF");
|
|
|
|
if (isyms == NULL){
|
|
log(LOG_INIT,"admin: Out of memory");
|
|
mfree (esyms,number * sizeof (Elf32_External_Sym),"ProfilerF");
|
|
return NULL;
|
|
}
|
|
|
|
for (j = 0, psym = isyms;
|
|
j < number;
|
|
j ++, psym ++){
|
|
psym->st_name = getByte (esyms[j].st_name,sizeof(esyms[j].st_name));
|
|
|
|
psym->st_value = getByte (esyms[j].st_value,sizeof(esyms[j].st_value));
|
|
psym->st_size = getByte (esyms[j].st_size,sizeof(esyms[j].st_size));
|
|
psym->st_shndx = getByte (esyms[j].st_shndx,sizeof(esyms[j].st_shndx));
|
|
psym->st_info = getByte (esyms[j].st_info,sizeof(esyms[j].st_info));
|
|
psym->st_other = getByte (esyms[j].st_other,sizeof(esyms[j].st_other));
|
|
}
|
|
|
|
mfree (esyms,number * sizeof (Elf32_External_Sym),"ProfilerE");
|
|
return isyms;
|
|
}
|
|
|
|
|
|
|
|
|
|
bool Profiler::processSectionHeaders (FILE * file){
|
|
Elf_Internal_Shdr * section;
|
|
|
|
m_sectionHeaders = NULL;
|
|
|
|
if (m_elfHeader.e_shnum == 0)
|
|
{
|
|
return 1;
|
|
}
|
|
if (! get32bitSectionHeaders (file))
|
|
return 0;
|
|
|
|
/* Read in the string table, so that we have names to display. */
|
|
section = m_sectionHeaders + m_elfHeader.e_shstrndx;
|
|
|
|
if (section->sh_size != 0)
|
|
{
|
|
if (fseek (m_file,section->sh_offset,SEEK_SET)){
|
|
log(LOG_INIT,"admin: Unable to seek to start of %s "
|
|
"at %lx\n","string table",section->sh_offset);
|
|
return 0;
|
|
}
|
|
m_stringTableSize=section->sh_size;
|
|
m_stringTable = (char *) mmalloc (m_stringTableSize,
|
|
"ProfilerB");
|
|
if (m_stringTable == NULL){
|
|
log(LOG_INIT,"admin: Out of memory allocating %ld "
|
|
"bytes for %s\n", section->sh_size,"string table");
|
|
return 0;
|
|
}
|
|
if (fread (m_stringTable, section->sh_size, 1, m_file) != 1){
|
|
log(LOG_INIT,"admin: Unable to read in %ld bytes of "
|
|
"%s\n",section->sh_size,"section table");
|
|
mfree (m_stringTable,m_stringTableSize,"ProfilerB");
|
|
m_stringTable = NULL;
|
|
return 0;
|
|
}
|
|
}
|
|
return 1;
|
|
}
|
|
|
|
|
|
bool Profiler::get32bitSectionHeaders (FILE * file){
|
|
Elf32_External_Shdr * shdrs;
|
|
Elf_Internal_Shdr * internal;
|
|
unsigned int i;
|
|
|
|
if (fseek (m_file, m_elfHeader.e_shoff, SEEK_SET)){
|
|
log(LOG_INIT,"admin: Unable to seek to start of %s at %lx\n",
|
|
"section headers", m_elfHeader.e_shoff);
|
|
return 0;
|
|
}
|
|
|
|
shdrs = (Elf32_External_Shdr *) mmalloc
|
|
(m_elfHeader.e_shentsize * m_elfHeader.e_shnum,"ProfilerC");
|
|
if (shdrs == NULL){
|
|
log(LOG_INIT,"admin: Out of memory allocating %d bytes for "
|
|
"%s\n", m_elfHeader.e_shentsize * m_elfHeader.e_shnum,
|
|
"section headers");
|
|
return 0;
|
|
}
|
|
|
|
if (fread (shdrs,m_elfHeader.e_shentsize * m_elfHeader.e_shnum,
|
|
1,m_file) != 1){
|
|
log(LOG_INIT,"admin: Unable to read in %d bytes of %s\n",
|
|
m_elfHeader.e_shentsize * m_elfHeader.e_shnum,
|
|
"section headers");
|
|
mfree (shdrs,m_elfHeader.e_shentsize * m_elfHeader.e_shnum,
|
|
"ProfilerC");
|
|
shdrs = NULL;
|
|
return 0;
|
|
}
|
|
|
|
m_sectionHeaders = (Elf_Internal_Shdr *) mmalloc
|
|
(m_elfHeader.e_shnum * sizeof (Elf_Internal_Shdr),"ProfilerD");
|
|
|
|
if (m_sectionHeaders == NULL){
|
|
log(LOG_INIT,"admin: Out of memory\n");
|
|
return 0;
|
|
}
|
|
|
|
for (i = 0, internal = m_sectionHeaders;
|
|
i < m_elfHeader.e_shnum;
|
|
i ++, internal ++){
|
|
internal->sh_name = getByte (shdrs[i].sh_name,sizeof(shdrs[i].sh_name));
|
|
internal->sh_type = getByte (shdrs[i].sh_type,sizeof(shdrs[i].sh_type));
|
|
internal->sh_flags= getByte (shdrs[i].sh_flags,sizeof(shdrs[i].sh_flags));
|
|
internal->sh_addr = getByte (shdrs[i].sh_addr,sizeof(shdrs[i].sh_addr));
|
|
internal->sh_offset= getByte (shdrs[i].sh_offset,sizeof(shdrs[i].sh_offset));
|
|
internal->sh_size = getByte (shdrs[i].sh_size,sizeof(shdrs[i].sh_size));
|
|
internal->sh_link = getByte (shdrs[i].sh_link,sizeof(shdrs[i].sh_link));
|
|
internal->sh_info = getByte (shdrs[i].sh_info,sizeof(shdrs[i].sh_info));
|
|
internal->sh_addralign= getByte (shdrs[i].sh_addralign,sizeof(shdrs[i].sh_addralign));
|
|
internal->sh_entsize = getByte (shdrs[i].sh_entsize,sizeof(shdrs[i].sh_entsize));
|
|
}
|
|
mfree (shdrs,m_elfHeader.e_shentsize * m_elfHeader.e_shnum,
|
|
"ProfilerC");
|
|
return 1;
|
|
}
|
|
|
|
|
|
bool Profiler::startTimer(long address, const char* caller) {
|
|
// disable - we do interrupt based profiling now
|
|
return true;
|
|
if(g_inSigHandler) return 1;
|
|
long slot = m_fn.getSlot(&address);
|
|
FnInfo *fnInfo;
|
|
if (slot == -1) return false;
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(slot);
|
|
|
|
if(fnInfo->m_inFunction++ > 0) return true;
|
|
|
|
fnInfo->m_startTimeLocal = gettimeofdayInMillisecondsLocal();
|
|
fnInfo->m_lastPauseTime = fnInfo->m_startTimeLocal;
|
|
fnInfo->m_startTime = gettimeofdayInMilliseconds();
|
|
m_activeFns.addKey(&address, &fnInfo);
|
|
return true;
|
|
}
|
|
|
|
inline uint64_t gettimeofdayInMicroseconds(void) {
|
|
struct timeval tv;
|
|
gettimeofday(&tv, NULL);
|
|
return(((uint64_t)tv.tv_sec * 1000000LL) + (uint64_t)tv.tv_usec);
|
|
}
|
|
bool Profiler::pause(const char* caller, long lineno, long took) {
|
|
lastQuickPollTime = gettimeofdayInMicroseconds();
|
|
unsigned long long nowLocal = lastQuickPollTime / 1000;
|
|
void *trace[3];
|
|
backtrace(trace, 3);
|
|
const void *stackPtr = trace[2];
|
|
lastQuickPollAddress = (uint32_t)stackPtr;
|
|
for(long i = 0; i < m_activeFns.getNumSlots(); i++) {
|
|
//if(m_activeFns.getKey(i) == 0) continue;
|
|
if ( m_activeFns.isEmpty(i) ) continue;
|
|
FnInfo* fnInfo = *(FnInfo **)m_activeFns.getValueFromSlot(i);
|
|
unsigned long long blockedTime = nowLocal -
|
|
fnInfo->m_lastPauseTime ;
|
|
if (blockedTime > fnInfo->m_maxBlockedTime) {
|
|
fnInfo->m_maxBlockedTime = blockedTime;
|
|
fnInfo->m_lastQpoll = caller;
|
|
fnInfo->m_prevQpoll = m_lastQpoll;
|
|
}
|
|
fnInfo->m_lastPauseTime = nowLocal;
|
|
}
|
|
|
|
if(!caller || took < 0) return true;
|
|
|
|
|
|
//break here in gdb and go up on the stack if you want to find a place
|
|
//to add a quickpoll!!!!1!!
|
|
// if(took > 50)
|
|
// log(LOG_WARN, "admin qp %s--%li took %li",
|
|
// caller, lineno, took);
|
|
long qpkey = (long)caller + lineno;
|
|
long slot = m_quickpolls.getSlot(&qpkey);
|
|
if(slot < 0) {
|
|
if(m_lastQPUsed >= 512) {
|
|
log(LOG_WARN, "admin: profiler refusing to add to "
|
|
"full quickpoll table.");
|
|
return true;
|
|
}
|
|
|
|
QuickPollInfo* q = &m_quickPollInfos[m_lastQPUsed++];
|
|
memset(q, 0, sizeof(QuickPollInfo));
|
|
q->m_caller = caller;
|
|
q->m_lineno = lineno;
|
|
q->m_last = m_lastQpoll;
|
|
q->m_lastlineno = m_lastQpollLine;
|
|
q->m_timeAcc = took;
|
|
q->m_maxTime = took;
|
|
q->m_times = 1;
|
|
m_quickpolls.addKey(&qpkey, &q);
|
|
}
|
|
else {
|
|
QuickPollInfo* q = *(QuickPollInfo **)m_quickpolls.getValueFromSlot(slot);
|
|
if(q->m_maxTime < took) {
|
|
q->m_caller = caller;
|
|
q->m_lineno = lineno;
|
|
q->m_last = m_lastQpoll;
|
|
q->m_lastlineno = m_lastQpollLine;
|
|
q->m_maxTime = took;
|
|
}
|
|
q->m_timeAcc += took;
|
|
q->m_times++;
|
|
}
|
|
|
|
m_lastQpoll = caller;
|
|
m_lastQpollLine = lineno;
|
|
|
|
return true;
|
|
}
|
|
|
|
bool Profiler::unpause() {
|
|
unsigned long long nowLocal = gettimeofdayInMillisecondsLocal();
|
|
for(long i = 0; i < m_activeFns.getNumSlots(); i++) {
|
|
//if(m_activeFns.getKey(i) == 0) continue;
|
|
if ( m_activeFns.isEmpty(i) ) continue;
|
|
FnInfo* fnInfo = *(FnInfo **)m_activeFns.getValueFromSlot(i);
|
|
fnInfo->m_lastPauseTime = nowLocal;
|
|
}
|
|
return true;
|
|
}
|
|
|
|
bool Profiler::endTimer(long address,
|
|
const char *caller,
|
|
bool isThread ) {
|
|
// disable - we do interrupt based profiling now
|
|
if(g_inSigHandler) return 1;
|
|
FnInfo *fnInfo;
|
|
long slot = m_activeFns.getSlot(&address);
|
|
if (slot < 0 ) {
|
|
//log(LOG_WARN,"Profiler: got a non added function at
|
|
// address %li",address);
|
|
// This happens because at closing the profiler is still on
|
|
// after destructor has been called. Not displaying address
|
|
// because is is of no use
|
|
// { char *xx = NULL; *xx = 0; }
|
|
// return false;
|
|
return true;
|
|
}
|
|
fnInfo=*(FnInfo **)m_activeFns.getValueFromSlot(slot);
|
|
if(--fnInfo->m_inFunction > 0) return true;
|
|
|
|
unsigned long long nowLocal = gettimeofdayInMillisecondsLocal();
|
|
//unsigned long long now = gettimeofdayInMilliseconds();
|
|
unsigned long long timeTaken = nowLocal - fnInfo->m_startTimeLocal;
|
|
|
|
unsigned long long blockedTime = nowLocal - fnInfo->m_lastPauseTime ;
|
|
if (blockedTime > fnInfo->m_maxBlockedTime) {
|
|
fnInfo->m_maxBlockedTime = blockedTime;
|
|
fnInfo->m_prevQpoll = fnInfo->m_lastQpoll;
|
|
fnInfo->m_lastQpoll = caller;
|
|
}
|
|
|
|
fnInfo->m_totalTimeTaken += timeTaken;
|
|
fnInfo->m_timesCalled++;
|
|
if (timeTaken > (fnInfo->m_maxTimeTaken))
|
|
fnInfo->m_maxTimeTaken = timeTaken;
|
|
if (isThread)
|
|
fnInfo->m_numCalledFromThread++;
|
|
|
|
m_activeFns.removeKey(&address);
|
|
char* name = getFnName(address);
|
|
|
|
|
|
if (timeTaken > (unsigned long)g_conf.m_minProfThreshold) {
|
|
if(g_conf.m_sequentialProfiling)
|
|
log(LOG_TIMING, "admin: %lli ms in %s from %s",
|
|
timeTaken,
|
|
name,
|
|
caller?caller:"");
|
|
|
|
/*
|
|
if(g_conf.m_dynamicPerfGraph) {
|
|
g_stats.addStat_r ( 0 ,
|
|
fnInfo->m_startTime,
|
|
now,
|
|
"profiler_stat",
|
|
0 , //color will be the hash of
|
|
//the callback
|
|
STAT_GENERIC,
|
|
name);
|
|
}
|
|
*/
|
|
}
|
|
|
|
for (long i=0;i<11;i++){
|
|
//if we find a hashtable is less than 1 second old
|
|
unsigned long long diffTime=nowLocal-m_fnTime[i];
|
|
if((diffTime<1000)&&(m_fnTime[i]!=0)){
|
|
//Add this function. Don't add the function name,
|
|
//shall get that from m_fn
|
|
//log(LOG_WARN,"Profiler: adding funtion to existing "
|
|
//"hashtable i=%li,now=%lli,"
|
|
// "m_fnTime=%lli, diffTime=%lli",i,now,
|
|
// m_fnTime[i],diffTime);
|
|
slot=m_fnTmp[i].getSlot(&address);
|
|
if (slot!=-1){
|
|
fnInfo=(FnInfo *)m_fnTmp[i].
|
|
getValueFromSlot(slot);
|
|
fnInfo->m_totalTimeTaken+=timeTaken;
|
|
fnInfo->m_timesCalled++;
|
|
if (timeTaken>(fnInfo->m_maxTimeTaken))
|
|
fnInfo->m_maxTimeTaken=timeTaken;
|
|
if(isThread)
|
|
fnInfo->m_numCalledFromThread++;
|
|
}
|
|
else {
|
|
FnInfo fnInfoTmp;
|
|
fnInfoTmp.m_timesCalled=1;
|
|
fnInfoTmp.m_totalTimeTaken=timeTaken;
|
|
fnInfoTmp.m_maxTimeTaken=timeTaken;
|
|
if (isThread)
|
|
fnInfoTmp.m_numCalledFromThread=1;
|
|
else
|
|
fnInfoTmp.m_numCalledFromThread=0;
|
|
m_fnTmp[i].addKey(&address,&fnInfoTmp);
|
|
}
|
|
return true;
|
|
}
|
|
}
|
|
//if not, then find a hashtable that is more than 10 seconds old
|
|
//and replace it with the new hashtable
|
|
for (long i=0;i<11;i++){
|
|
unsigned long long diffTime=nowLocal-m_fnTime[i];
|
|
if((diffTime>=10000) || (m_fnTime[i]==0)){
|
|
/*log(LOG_WARN,"Profiler: m_fntime=%lli,i=%li,now=%lli,diffTime=%lli",
|
|
m_fnTime[i],i,now,diffTime);*/
|
|
//First clear the hashtable
|
|
m_fnTmp[i].clear();
|
|
//Add this function
|
|
FnInfo fnInfoTmp;
|
|
fnInfoTmp.m_timesCalled=1;
|
|
fnInfoTmp.m_totalTimeTaken=timeTaken;
|
|
|
|
fnInfoTmp.m_maxTimeTaken=timeTaken;
|
|
if (isThread)
|
|
fnInfoTmp.m_numCalledFromThread=1;
|
|
else
|
|
fnInfoTmp.m_numCalledFromThread=0;
|
|
m_fnTmp[i].addKey(&address,&fnInfoTmp);
|
|
|
|
//Change time of hashtable
|
|
m_fnTime[i]=nowLocal;
|
|
return true;
|
|
}
|
|
}
|
|
return true;
|
|
}
|
|
|
|
bool Profiler::printInfo(SafeBuf *sb,char *username, //long user,
|
|
char *pwd, char *coll,
|
|
int sorts,int sort10, int qpreset,
|
|
int profilerreset) {
|
|
// sort by max blocked time by default
|
|
if ( sorts == 0 ) sorts = 8;
|
|
|
|
long slot;
|
|
unsigned long key(0);
|
|
long numSlots = m_fn.getNumSlots();
|
|
long numSlotsUsed = m_fn.getNumSlotsUsed();
|
|
FnInfo *fnInfo;
|
|
|
|
if ( profilerreset ) {
|
|
for ( long i = 0; i < m_fn.getNumSlots(); i++ ){
|
|
//key=m_fn.getKey(i);
|
|
//if (key!=0){
|
|
if ( ! m_fn.isEmpty(i) ) {
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(i);
|
|
// set everything to 0
|
|
fnInfo->m_timesCalled = 0;
|
|
fnInfo->m_totalTimeTaken = 0;
|
|
fnInfo->m_maxTimeTaken = 0;
|
|
fnInfo->m_numCalledFromThread = 0;
|
|
fnInfo->m_maxBlockedTime = 0;
|
|
}
|
|
}
|
|
}
|
|
|
|
|
|
sb->safePrintf( "<center>\n<table %s>\n"
|
|
"<tr class=hdrow><td colspan=9>"
|
|
"<center><b>Profiler "//- Since Startup</b></center>"
|
|
"<a href=\"/admin/profiler?c=%s"//"
|
|
"&profilerreset=1\">"
|
|
"(reset)</a></b></center>"
|
|
"</td></tr>\n",
|
|
TABLE_STYLE,
|
|
coll);
|
|
|
|
sb->safePrintf("<tr bgcolor=#%s>"
|
|
"<td><b>Address</b></td><td><b>Function</b></td>"
|
|
, LIGHT_BLUE);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sorts=3&c=%s>"
|
|
"Times Called</a></b></td></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sorts=4&c=%s>"
|
|
"Total Time(msec)</a></b></td></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sorts=5&c=%s>"
|
|
"Avg Time(msec)</b></a></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sorts=6&c=%s>"
|
|
"Max Time(msec)</a></b></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sorts=7&c=%s>"
|
|
"Times from Thread</a></b></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sorts=8&c=%s>"
|
|
"Max Blocked Time</a></b></td>",coll);
|
|
// sb->safePrintf("<td><b><a href=/admin/profiler?sorts=8&c=%s>"
|
|
// "Between Quick Polls</a></b></td></tr>",coll);
|
|
|
|
indexTable=(unsigned long*)
|
|
mcalloc(numSlotsUsed*sizeof(unsigned long),"ProfilerW");
|
|
keyTable=(unsigned long*) mcalloc
|
|
(numSlotsUsed*sizeof(unsigned long),"ProfilerX");
|
|
if(sorts==5 ||sort10==5)
|
|
valueTableF=(float*)
|
|
mcalloc(numSlotsUsed*sizeof(float),"ProfilerY");
|
|
else
|
|
valueTableUll=(unsigned long long*)
|
|
mcalloc(numSlotsUsed*sizeof(unsigned long long),
|
|
"ProfilerY");
|
|
long numFnsCalled=0;
|
|
for (long i=0;i<numSlots;i++){
|
|
//key=m_fn.getKey(i);
|
|
//if (key!=0){
|
|
if ( !m_fn.isEmpty(i) ) {
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(i);
|
|
// To save calculating time, just store functions
|
|
// that have been called
|
|
if(fnInfo->m_timesCalled!=0){
|
|
keyTable[numFnsCalled]=key;
|
|
indexTable[numFnsCalled]=numFnsCalled;
|
|
switch(sorts){
|
|
case 3:valueTableUll[numFnsCalled] = fnInfo->
|
|
m_timesCalled;
|
|
break;
|
|
case 4:valueTableUll[numFnsCalled] = fnInfo->
|
|
m_totalTimeTaken;
|
|
break;
|
|
case 5:// sorting float values till the 4th
|
|
// dec place
|
|
valueTableF[numFnsCalled] = ((float)fnInfo->m_totalTimeTaken)/((float)fnInfo->m_timesCalled);
|
|
break;
|
|
case 6:valueTableUll[numFnsCalled] = fnInfo->
|
|
m_maxTimeTaken;
|
|
break;
|
|
case 7:valueTableUll[numFnsCalled] = fnInfo->
|
|
m_numCalledFromThread;
|
|
break;
|
|
case 8:valueTableUll[numFnsCalled] = fnInfo->
|
|
m_maxBlockedTime;
|
|
break;
|
|
//For now for any other value of slot
|
|
// so that we don't error
|
|
default:valueTableUll[numFnsCalled] = fnInfo->
|
|
m_numCalledFromThread;
|
|
}
|
|
numFnsCalled++;
|
|
}
|
|
}
|
|
}
|
|
if (sorts==5)
|
|
gbqsort(indexTable,numFnsCalled,sizeof(unsigned long),
|
|
decend_cmpF);
|
|
else
|
|
gbqsort(indexTable,numFnsCalled,sizeof(unsigned long),
|
|
decend_cmpUll);
|
|
|
|
//Now print the sorted values
|
|
for (long i=0;i<numFnsCalled;i++){
|
|
slot=m_fn.getSlot(&keyTable[indexTable[i]]);
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(slot);
|
|
//Don't print functions that have not been called
|
|
sb->safePrintf("<tr><td>%lx</td><td>%s</td><td>%li</td><td>%li</td>"
|
|
"<td>%.4f</td><td>%li</td><td>%li</td><td>%li</td>"
|
|
"</tr>",
|
|
keyTable[indexTable[i]],
|
|
fnInfo->m_fnName,
|
|
fnInfo->m_timesCalled,
|
|
fnInfo->m_totalTimeTaken,
|
|
((float)fnInfo->m_totalTimeTaken)/((float)fnInfo->m_timesCalled),
|
|
fnInfo->m_maxTimeTaken,
|
|
fnInfo->m_numCalledFromThread,
|
|
fnInfo->m_maxBlockedTime);
|
|
}
|
|
|
|
sb->safePrintf("</table><br><br>");
|
|
|
|
|
|
|
|
//Now to print the table of functions called in the last 10 seconds
|
|
sb->safePrintf( "<center>\n<table %s>\n"
|
|
"<tr class=hdrow><td colspan=8>"
|
|
"<center><b>Profiler - Last 10 seconds</b></center>"
|
|
"</td></tr>\n",TABLE_STYLE);
|
|
sb->safePrintf("<tr bgcolor=#%s>"
|
|
"<td><b>Address</b></td><td><b>Function</b></td>",
|
|
LIGHT_BLUE);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sort10=3&c=%s&"
|
|
">"
|
|
"Times Called</a></b></td></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sort10=4&c=%s&"
|
|
">"
|
|
"Total Time(msec)</a></b></td></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sort10=5&c=%s&"
|
|
">"
|
|
"Avg Time(msec)</b></a></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sort10=6&c=%s&"
|
|
">"
|
|
"Max Time(msec)</a></b></td>",coll);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?sort10=7&c=%s&"
|
|
">"
|
|
"Times From Thread</a></b></td></tr>",coll);
|
|
unsigned long long now=gettimeofdayInMillisecondsLocal();
|
|
long numFnsCalled10=0;;
|
|
for(long i=0;i<numFnsCalled;i++){
|
|
unsigned long long timesCalled=0;
|
|
unsigned long long totalTimeTaken=0;
|
|
unsigned long long maxTimeTaken=0;
|
|
unsigned long long numCalledFromThread=0;
|
|
//If hashtable is less than 10 secs old, use it
|
|
for(long j=0;j<11;j++){
|
|
if ((now-m_fnTime[i]) < 10000){
|
|
//From the keyTable, we know the keys of the
|
|
// functions that have been called
|
|
slot=m_fnTmp[j].getSlot(&keyTable[i]);
|
|
if (slot>=0){
|
|
fnInfo=(FnInfo *)m_fnTmp[j].
|
|
getValueFromSlot(slot);
|
|
totalTimeTaken += fnInfo->
|
|
m_totalTimeTaken;
|
|
timesCalled += fnInfo->m_timesCalled;
|
|
if( ( fnInfo->m_maxTimeTaken) >
|
|
maxTimeTaken )
|
|
maxTimeTaken = fnInfo->
|
|
m_maxTimeTaken;
|
|
numCalledFromThread += fnInfo->
|
|
m_numCalledFromThread;
|
|
}
|
|
}
|
|
}
|
|
//After getting all the info, put it in table for sorting
|
|
//Only print those functions that have been called
|
|
if (timesCalled==0) continue;
|
|
//Simply overwriting all the stuff
|
|
keyTable[numFnsCalled10]=keyTable[i];
|
|
indexTable[numFnsCalled10]=numFnsCalled10;
|
|
switch(sort10){
|
|
case 0:break;
|
|
case 3:valueTableUll[numFnsCalled10]=timesCalled;
|
|
break;
|
|
case 4:valueTableUll[numFnsCalled10]=totalTimeTaken;;
|
|
break;
|
|
case 5:valueTableF[numFnsCalled10]=((float)totalTimeTaken)/((float)timesCalled);
|
|
break;
|
|
case 6:valueTableUll[numFnsCalled10]=maxTimeTaken;
|
|
break;
|
|
//For now for any other value of slot so that we don't error
|
|
default:valueTableUll[numFnsCalled10]=numCalledFromThread;
|
|
}
|
|
numFnsCalled10++;
|
|
}
|
|
|
|
if (sort10==5)
|
|
gbqsort(indexTable,numFnsCalled10,sizeof(unsigned long),
|
|
decend_cmpF);
|
|
else
|
|
gbqsort(indexTable,numFnsCalled10,sizeof(unsigned long),
|
|
decend_cmpUll);
|
|
|
|
for(long i=0;i<numFnsCalled10;i++){
|
|
unsigned long long timesCalled=0;
|
|
unsigned long long totalTimeTaken=0;
|
|
unsigned long long maxTimeTaken=0;
|
|
unsigned long long numCalledFromThread=0;
|
|
//If hashtable is less than 10 secs old, continue
|
|
for(long j=0;j<11;j++){
|
|
if ((now-m_fnTime[i])<10000){
|
|
// From the keyTable, we know the keys of the
|
|
// functions that have been called
|
|
slot=m_fnTmp[j].
|
|
getSlot(&keyTable[indexTable[i]]);
|
|
if (slot>=0){
|
|
fnInfo=(FnInfo *)m_fnTmp[j].
|
|
getValueFromSlot(slot);
|
|
totalTimeTaken += fnInfo->
|
|
m_totalTimeTaken;
|
|
timesCalled += fnInfo->m_timesCalled;
|
|
if( ( fnInfo->m_maxTimeTaken)>
|
|
maxTimeTaken )
|
|
maxTimeTaken = fnInfo->
|
|
m_maxTimeTaken;
|
|
numCalledFromThread += fnInfo->
|
|
m_numCalledFromThread;
|
|
}
|
|
}
|
|
}
|
|
//Only print those functions that have been called
|
|
if (timesCalled==0) continue;
|
|
slot=m_fn.getSlot(&keyTable[indexTable[i]]);
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(slot);
|
|
//Don't print functions that have not been called
|
|
sb->safePrintf("<tr><td>%lx</td><td>%s</td><td>%lli</td>"
|
|
"<td>%lli</td>"
|
|
"<td>%.4f</td><td>%lli</td><td>%lli</td></tr>",
|
|
keyTable[indexTable[i]],
|
|
fnInfo->m_fnName,
|
|
timesCalled,
|
|
totalTimeTaken,
|
|
((float)totalTimeTaken)/((float)timesCalled),
|
|
maxTimeTaken,
|
|
numCalledFromThread);
|
|
}
|
|
sb->safePrintf("</table><br><br>");
|
|
|
|
|
|
|
|
mfree(indexTable,numSlotsUsed*sizeof(unsigned long),"ProfilerX");
|
|
mfree(keyTable,numSlotsUsed*sizeof(unsigned long),"ProfilerX");
|
|
if (sorts==5 || sort10==5)
|
|
mfree(valueTableF,
|
|
numSlotsUsed*sizeof(float),
|
|
"ProfilerY");
|
|
else
|
|
mfree(valueTableUll,
|
|
numSlotsUsed*sizeof(unsigned long long),
|
|
"ProfilerY");
|
|
|
|
|
|
|
|
if(qpreset) {
|
|
m_quickpolls.clear();
|
|
m_lastQPUsed = 0;
|
|
}
|
|
|
|
numSlots = m_quickpolls.getNumSlots();
|
|
numSlotsUsed = m_quickpolls.getNumSlotsUsed();
|
|
sb->safePrintf("<center>\n<table %s>\n"
|
|
"<tr class=hdrow><td colspan=5>"
|
|
"<center><b>Triggered Quickpolls "
|
|
"<a href=\"/admin/profiler?c=%s"
|
|
"&qpreset=1\">"
|
|
"(reset)</a></b></center>"
|
|
"</td></tr>\n",
|
|
TABLE_STYLE,
|
|
coll);
|
|
|
|
sb->safePrintf("<tr bgcolor=#%s>"
|
|
"<td><b>Between Functions</b></td>"
|
|
"<td><b>max blocked(msec)</b></td>"
|
|
"<td><b>avg time(msec)</b></td>"
|
|
"<td><b>times triggered</b></td>"
|
|
"<td><b>total(msec)</b></td>"
|
|
"</tr>"
|
|
, LIGHT_BLUE );
|
|
|
|
if(numSlotsUsed == 0) {
|
|
sb->safePrintf("</table>");
|
|
return true;
|
|
}
|
|
|
|
valueTableUll = (unsigned long long*)
|
|
mcalloc(numSlotsUsed * sizeof(unsigned long long),"ProfilerZ");
|
|
if(!valueTableUll) {
|
|
sb->safePrintf("</table>");
|
|
return true;
|
|
}
|
|
|
|
indexTable = (unsigned long*)mcalloc(numSlotsUsed *
|
|
sizeof(unsigned long),
|
|
"ProfilerZ");
|
|
if(!indexTable) {
|
|
mfree(indexTable,
|
|
numSlotsUsed*sizeof(unsigned long),
|
|
"ProfilerZ");
|
|
sb->safePrintf("</table>");
|
|
return true;
|
|
}
|
|
|
|
keyTable = (unsigned long*)mcalloc(numSlotsUsed *
|
|
sizeof(unsigned long),
|
|
"ProfilerZ");
|
|
if(!keyTable) {
|
|
mfree(indexTable,
|
|
numSlotsUsed*sizeof(unsigned long),
|
|
"ProfilerZ");
|
|
mfree(valueTableUll,
|
|
numSlotsUsed*sizeof(unsigned long long),
|
|
"ProfilerZ");
|
|
sb->safePrintf("</table>");
|
|
return true;
|
|
}
|
|
|
|
long j = 0;
|
|
for (long i = 0; i < numSlots; i++) {
|
|
//if((key = m_quickpolls.getKey(i)) == 0) continue;
|
|
if ( m_quickpolls.isEmpty(i) ) continue;
|
|
QuickPollInfo* q = *(QuickPollInfo **)m_quickpolls.getValueFromSlot(i);
|
|
long took = q->m_maxTime;
|
|
valueTableUll[j] = took;
|
|
indexTable[j] = j;
|
|
keyTable[j] = i;
|
|
j++;
|
|
}
|
|
gbqsort(indexTable, j, sizeof(unsigned long), decend_cmpUll);
|
|
|
|
for (long i = 0; i < numSlotsUsed; i++){
|
|
long slot = keyTable[indexTable[i]];
|
|
//key = m_quickpolls.getKey(slot);
|
|
QuickPollInfo* q = *(QuickPollInfo **)m_quickpolls.getValueFromSlot(slot);
|
|
sb->safePrintf("<tr><td>%s:%li<br>%s:%li</td>"
|
|
"<td>%li</td>"
|
|
"<td>%f</td>"
|
|
"<td>%li</td>"
|
|
"<td>%li</td>"
|
|
"</tr>",
|
|
q->m_caller, q->m_lineno, q->m_last,
|
|
q->m_lastlineno,q->m_maxTime,
|
|
(float)q->m_timeAcc / q->m_times,
|
|
q->m_times,
|
|
q->m_timeAcc);
|
|
}
|
|
sb->safePrintf("</table>");
|
|
|
|
mfree(valueTableUll,numSlotsUsed*sizeof(unsigned long long),"ProfilerZ");
|
|
mfree(indexTable, numSlotsUsed*sizeof(unsigned long),"ProfilerZ");
|
|
mfree(keyTable, numSlotsUsed*sizeof(unsigned long),"ProfilerZ");
|
|
return true;
|
|
}
|
|
|
|
//backwards so we get highest scores first.
|
|
static int decend_cmpUll ( const void *h1 , const void *h2 ) {
|
|
unsigned long tmp1, tmp2;
|
|
tmp1 = *(unsigned long *)h1;
|
|
tmp2 = *(unsigned long *)h2;
|
|
if (valueTableUll[tmp1]>valueTableUll[tmp2]) {
|
|
return -1;
|
|
}
|
|
else if(valueTableUll[tmp1]<valueTableUll[tmp2]){
|
|
return 1;
|
|
}
|
|
else return 0;
|
|
}
|
|
|
|
//backwards so we get highest scores first.
|
|
static int decend_cmpF ( const void *h1 , const void *h2 ) {
|
|
unsigned long tmp1, tmp2;
|
|
tmp1 = *(unsigned long *)h1;
|
|
tmp2 = *(unsigned long *)h2;
|
|
if (valueTableF[tmp1]>valueTableF[tmp2]) {
|
|
return -1;
|
|
}
|
|
else if(valueTableF[tmp1]<valueTableF[tmp2]){
|
|
return 1;
|
|
}
|
|
else return 0;
|
|
}
|
|
|
|
|
|
char* Profiler::getFnName(unsigned long address,long *nameLen){
|
|
FnInfo *fnInfo;
|
|
long slot=m_fn.getSlot(&address);
|
|
if(slot!=-1)
|
|
fnInfo=(FnInfo *)m_fn.getValueFromSlot(slot);
|
|
else
|
|
return NULL;
|
|
if (nameLen)
|
|
*nameLen=gbstrlen(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:
|
|
//long user = g_pages.getUserType( s , r );
|
|
char *username = g_users.getUsername(r);
|
|
//char *pwd = r->getString ("pwd");
|
|
|
|
char *coll = r->getString ("c");
|
|
long collLen;
|
|
if ( ! coll || ! coll[0] ) {
|
|
//coll = g_conf.m_defaultColl;
|
|
coll = g_conf.getDefaultColl( r->getHost(), r->getHostLen() );
|
|
}
|
|
collLen = gbstrlen(coll);
|
|
int sorts=(int) r->getLong("sorts",0);
|
|
int sort10=(int)r->getLong("sort10",0);
|
|
int qpreset=(int)r->getLong("qpreset",0);
|
|
int profilerreset=(int)r->getLong("profilerreset",0);
|
|
int realTimeSortMode=(int)r->getLong("rtsort",2);
|
|
int realTimeShowAll=(int)r->getLong("rtall",0);
|
|
int startRt=(int)r->getLong("rtstart",0);
|
|
int stopRt=(int)r->getLong("rtstop",0);
|
|
|
|
g_pages.printAdminTop ( &sb , s , r );
|
|
|
|
|
|
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();
|
|
} else if(startRt) g_profiler.startRealTimeProfiler();
|
|
|
|
g_profiler.printRealTimeInfo(&sb,
|
|
username,
|
|
NULL,
|
|
coll,
|
|
realTimeSortMode,
|
|
realTimeShowAll);
|
|
g_profiler.printInfo(&sb,username,NULL,coll,sorts,sort10, qpreset,
|
|
profilerreset);
|
|
}
|
|
return g_httpServer.sendDynamicPage ( s , (char*) sb.getBufStart() ,
|
|
sb.length() ,-1 , false);
|
|
}
|
|
|
|
FrameTrace *
|
|
FrameTrace::set(const uint32_t addr) {
|
|
address = addr;
|
|
return this;
|
|
}
|
|
|
|
FrameTrace *
|
|
FrameTrace::add(const uint32_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(address);
|
|
out->pad(' ', level);
|
|
uint32_t l;
|
|
if(name && (l = gbstrlen(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("| |");
|
|
}
|
|
if(missQuickPoll) {
|
|
out->safePrintf(" %-10i |", missQuickPoll);
|
|
} else {
|
|
out->safePrintf(" |");
|
|
}
|
|
out->safePrintf(" %#.8x |", address);
|
|
out->safePrintf("\n");
|
|
} else {
|
|
out->safePrintf("|Stack Trace");
|
|
printStart = getPrintLen(0) + 3;
|
|
out->pad(' ', printStart - sizeof("|Stack Trace"));
|
|
out->safePrintf("| Hits |Missed QUICKPOLL| Address |\n");
|
|
out->pad('-', printStart + sizeof("| Hits |Missed QUICKPOLL| 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(address);
|
|
uint32_t l;
|
|
if(!(name && (l = gbstrlen(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;
|
|
}
|
|
|
|
FrameTrace *
|
|
Profiler::getFrameTrace(void **trace, const uint32_t numFrames) {
|
|
FrameTrace *frame = g_profiler.m_rootFrame;
|
|
for(uint32_t i = numFrames - 3; i > 1; --i) {
|
|
uint32_t base =
|
|
g_profiler.getFuncBaseAddr((uint32_t)trace[i]);
|
|
frame = frame->add(base);
|
|
if(!frame) return NULL;
|
|
}
|
|
return frame;
|
|
}
|
|
|
|
FrameTrace *
|
|
Profiler::updateRealTimeData( void **trace,
|
|
const uint32_t numFrames,
|
|
uint32_t **ptr) {
|
|
// Find or create and set of stack frames which match this one.
|
|
FrameTrace *frame = getFrameTrace(trace, numFrames);
|
|
if(frame) ++frame->hits;
|
|
uint32_t stackPtr = (uint32_t)trace[2];
|
|
//*ptr = (uint32_t *)realTimeProfilerData.getValuePointer(stackPtr);
|
|
*ptr = (uint32_t *)realTimeProfilerData.getValue(&stackPtr);
|
|
uint64_t newHit = 1;
|
|
//if(!*ptr) realTimeProfilerData.addKey(stackPtr, newHit);
|
|
if(!*ptr) realTimeProfilerData.addKey(&stackPtr, &newHit);
|
|
else ++*ptr[0];
|
|
return frame;
|
|
}
|
|
|
|
|
|
// void
|
|
// Profiler::addMissedQuickPoll( ) {
|
|
// void *trace[32];
|
|
// uint32_t numFrames = backtrace(trace, 32);
|
|
// if(numFrames < 3) return;
|
|
// const void *stackPtr = trace[2];
|
|
// uint32_t baseAddress = g_profiler.getFuncBaseAddr((uint32_t)stackPtr);
|
|
// uint32_t *ptr;
|
|
// FrameTrace *frame = updateRealTimeData(trace, numFrames, &ptr);
|
|
// if(frame) ++frame->missQuickPoll;
|
|
// if(!ptr) ptr = (uint32_t *)realTimeProfilerData.getValuePointer(
|
|
// uint32_t(stackPtr));
|
|
// if(ptr) ++ptr[1];
|
|
// }
|
|
|
|
|
|
void
|
|
Profiler::checkMissedQuickPoll( FrameTrace *frame,
|
|
const uint32_t stackPtr,
|
|
uint32_t *ptr)
|
|
{
|
|
if(g_niceness == 0 || // !g_loop.m_canQuickPoll ||
|
|
!g_loop.m_needsToQuickPoll ||
|
|
g_loop.m_inQuickPoll) return;
|
|
// Get the time difference from when the function we last saw was
|
|
// different. The odds are very good that this time represents the time
|
|
// which has been spent in this function.
|
|
// const uint64_t time = gettimeofdayInMilliseconds();
|
|
// const uint64_t delta = time - g_profiler.m_lastDeltaAddressTime;
|
|
// const uint32_t maxDelta = QUICKPOLL_INTERVAL;
|
|
//log("delta %i", delta);
|
|
// if(delta <= maxDelta) return;
|
|
// if(time - g_loop.m_lastPollTime <= maxDelta) return;
|
|
// If it got here then there is a good change a quick poll call needs to
|
|
// be added.
|
|
if(frame) ++frame->missQuickPoll;
|
|
//if(!ptr) ptr =(uint32_t *)realTimeProfilerData.getValuePointer(
|
|
// uint32_t(stackPtr));
|
|
if(!ptr) ptr = (uint32_t *)realTimeProfilerData.getValue((uint32_t *)
|
|
&stackPtr);
|
|
if(ptr) ++ptr[1];
|
|
}
|
|
|
|
void
|
|
Profiler::getStackFrame(int sig) {
|
|
void *trace[32];
|
|
uint32_t numFrames = backtrace(trace, 32);
|
|
if(numFrames < 3) return;
|
|
const void *stackPtr = trace[2];
|
|
uint32_t baseAddress = g_profiler.getFuncBaseAddr((uint32_t)stackPtr);
|
|
uint32_t *ptr;
|
|
FrameTrace *frame = updateRealTimeData(trace, numFrames, &ptr);
|
|
if(baseAddress != g_profiler.m_lastDeltaAddress) {
|
|
// This function is different from the last function we saw
|
|
g_profiler.m_lastDeltaAddressTime =gettimeofdayInMilliseconds();
|
|
g_profiler.m_lastDeltaAddress = baseAddress;
|
|
}
|
|
checkMissedQuickPoll( frame,
|
|
(uint32_t)stackPtr,
|
|
ptr);
|
|
}
|
|
|
|
void
|
|
Profiler::startRealTimeProfiler() {
|
|
log(LOG_INIT, "admin: starting real time profiler");
|
|
if(!m_frameTraces) {
|
|
m_frameTraces = (FrameTrace *)mmalloc(
|
|
sizeof(FrameTrace) * MAX_FRAME_TRACES, "FrameTraces");
|
|
memset(m_frameTraces, 0, sizeof(FrameTrace) * MAX_FRAME_TRACES);
|
|
m_numUsedFrameTraces = 0;
|
|
m_rootFrame = &m_frameTraces[m_numUsedFrameTraces++];
|
|
}
|
|
struct itimerval value, ovalue;
|
|
int which = ITIMER_REAL;
|
|
//signal(SIGVTALRM, Profiler::getStackFrame);
|
|
signal(SIGALRM, Profiler::getStackFrame);
|
|
value.it_interval.tv_sec = 0;
|
|
value.it_interval.tv_usec = 5000;
|
|
value.it_value.tv_sec = 0;
|
|
value.it_value.tv_usec = 5000;
|
|
setitimer( which, &value, &ovalue );
|
|
m_realTimeProfilerRunning = true;
|
|
}
|
|
|
|
void
|
|
Profiler::stopRealTimeProfiler(const bool keepData) {
|
|
log(LOG_INIT, "admin: stopping real time profiler");
|
|
struct itimerval value;
|
|
int which = ITIMER_REAL;
|
|
getitimer( which, &value );
|
|
value.it_value.tv_sec = 0;
|
|
value.it_value.tv_usec = 0;
|
|
setitimer( which, &value, NULL );
|
|
m_realTimeProfilerRunning = false;
|
|
if(!keepData && m_frameTraces) {
|
|
mfree( m_frameTraces,
|
|
sizeof(FrameTrace) * MAX_FRAME_TRACES,
|
|
"FrameTraces");
|
|
m_rootFrame = NULL;
|
|
m_frameTraces = NULL;
|
|
}
|
|
}
|
|
|
|
uint32_t
|
|
Profiler::getFuncBaseAddr(const uint32_t address) {
|
|
int32_t low = -1;
|
|
int32_t high = (int32_t)m_lastAddressMapIndex;
|
|
int32_t probe;
|
|
// @@@ MLT Interpolation might be faster.
|
|
while((high - low) > 1) {
|
|
probe = (low + high) >> 1;
|
|
if(m_addressMap[probe] <= address)
|
|
low = probe;
|
|
else
|
|
high = probe;
|
|
}
|
|
return m_addressMap[low];
|
|
}
|
|
|
|
uint32_t
|
|
Profiler::getFuncBaseAddr(const char *funcName) {
|
|
for(int32_t i = 0; i < m_fn.getNumSlots(); ++i) {
|
|
if ( m_fn.isEmpty(i) ) continue;
|
|
uint32_t key = *(uint32_t *)m_fn.getKey(i);
|
|
FnInfo *info = (FnInfo *)m_fn.getValueFromSlot(i);
|
|
if(!info || strcmp(info->m_fnName, funcName)) continue;
|
|
return key;
|
|
}
|
|
return 0;
|
|
}
|
|
|
|
int
|
|
Profiler::rtDataLocationCmp(const void *A, const void *B) {
|
|
const HitEntry * a = (const HitEntry *)A;
|
|
const HitEntry * b = (const HitEntry *)B;
|
|
if(a->fileHash > b->fileHash) return 1;
|
|
else if(a->fileHash < b->fileHash) return -1;
|
|
if(a->line > b->line) return 1;
|
|
else if(a->line < b->line) return -1;
|
|
return 0;
|
|
}
|
|
|
|
int
|
|
Profiler::rtHitCmp(const void *A, const void *B) {
|
|
const HitEntry * a = (const HitEntry *)A;
|
|
const HitEntry * b = (const HitEntry *)B;
|
|
if(a->numHits > b->numHits) return -1;
|
|
else if(a->numHits < b->numHits) return 1;
|
|
return 0;
|
|
}
|
|
|
|
int
|
|
Profiler::rtFuncHitCmp(const void *A, const void *B) {
|
|
const HitEntry *a = (const HitEntry *)A;
|
|
const HitEntry *b = (const HitEntry *)B;
|
|
if(a->numHitsPerFunc > b->numHitsPerFunc) return -1;
|
|
else if(a->numHitsPerFunc < b->numHitsPerFunc) return 1;
|
|
return Profiler::rtHitCmp(A, B);
|
|
}
|
|
|
|
int
|
|
Profiler::rtAddressCmp(const void *A, const void *B) {
|
|
const HitEntry * a = (const HitEntry *)A;
|
|
const HitEntry * b = (const HitEntry *)B;
|
|
if(a->address > b->address) return -1;
|
|
else if(a->address < b->address) return 1;
|
|
return 0;
|
|
}
|
|
|
|
int
|
|
Profiler::rtMissedQuickPolls(const void *A, const void *B) {
|
|
const HitEntry * a = (const HitEntry *)A;
|
|
const HitEntry * b = (const HitEntry *)B;
|
|
if(a->missedQuickPolls > b->missedQuickPolls) return -1;
|
|
else if(a->missedQuickPolls < b->missedQuickPolls) return 1;
|
|
return 0;
|
|
}
|
|
|
|
int
|
|
Profiler::rtMissedQuickPollPerFunc(const void *A, const void *B) {
|
|
const HitEntry * a = (const HitEntry *)A;
|
|
const HitEntry * b = (const HitEntry *)B;
|
|
if(a->missedQuickPollsPerFunc > b->missedQuickPollsPerFunc) return -1;
|
|
else if(a->missedQuickPollsPerFunc < b->missedQuickPollsPerFunc)
|
|
return 1;
|
|
return Profiler::rtMissedQuickPolls(A, B);
|
|
}
|
|
|
|
void
|
|
Profiler::sortRealTimeData(const uint8_t type, const uint32_t num) {
|
|
// MLT: if too slow then sort using pointers.
|
|
switch(type) {
|
|
case 0:
|
|
gbqsort(hitEntries, num, sizeof(HitEntry),
|
|
&Profiler::rtMissedQuickPollPerFunc);
|
|
break;
|
|
case 1:
|
|
gbqsort(hitEntries, num, sizeof(HitEntry),
|
|
&Profiler::rtAddressCmp);
|
|
break;
|
|
case 2:
|
|
gbqsort(hitEntries, num, sizeof(HitEntry),
|
|
&Profiler::rtFuncHitCmp);
|
|
break;
|
|
}
|
|
}
|
|
|
|
bool
|
|
Profiler::printRealTimeInfo(SafeBuf *sb,
|
|
//long user,
|
|
char *username,
|
|
char *pwd,
|
|
char *coll,
|
|
int realTimeSortMode,
|
|
int realTimeShowAll) {
|
|
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);
|
|
if(hitEntries)
|
|
mfree(hitEntries, sizeof(HitEntry)*rtNumEntries, "hitEntries");
|
|
//rtNumEntries = 0;
|
|
//for(int32_t i = 0; i < realTimeProfilerData.getNumSlots(); ++i) {
|
|
// uint32_t key = realTimeProfilerData.getKey(i);
|
|
// if(realTimeProfilerData.getValuePointer(key))
|
|
// ++rtNumEntries;
|
|
//}
|
|
rtNumEntries = realTimeProfilerData.getNumUsedSlots();
|
|
if(!rtNumEntries) {
|
|
sb->safePrintf("<table %s>",TABLE_STYLE);
|
|
sb->safePrintf("<tr class=hdrow><td colspan=7>"
|
|
"<center><b>Real Time Profiler started, refresh page "
|
|
"after some time."
|
|
"<a href=\"/admin/profiler?c=%s"
|
|
"&rtstop=1\">"
|
|
"(Stop)</a></b></center>"
|
|
"</td></tr>\n",coll);
|
|
sb->safePrintf("</table><br><br>\n");
|
|
startRealTimeProfiler();
|
|
return true;
|
|
}
|
|
hitEntries = (HitEntry *)mmalloc(sizeof(HitEntry) * rtNumEntries,
|
|
"hiEntries");
|
|
memset(hitEntries, 0, sizeof(HitEntry) * rtNumEntries);
|
|
uint32_t index = 0;
|
|
for(int32_t i = 0; i < realTimeProfilerData.getNumSlots(); ++i) {
|
|
//if(!realTimeProfilerData.getValuePointer(key))
|
|
// continue;
|
|
if ( realTimeProfilerData.isEmpty(i) ) continue;
|
|
uint32_t key = *(uint32_t *)realTimeProfilerData.getKey(i);
|
|
HitEntry &entry = hitEntries[index++];
|
|
//const uint32_t *ptr =
|
|
// (uint32_t *)realTimeProfilerData.getValuePointer(key);
|
|
uint32_t *ptr = (uint32_t *)realTimeProfilerData.
|
|
getValueFromSlot(i);
|
|
entry.numHits = ptr[0];
|
|
entry.numHitsPerFunc = 0;
|
|
entry.baseAddress = getFuncBaseAddr(key);
|
|
entry.funcName = getFnName(entry.baseAddress);
|
|
entry.line = 0;
|
|
entry.file = NULL;
|
|
entry.address = key;
|
|
entry.missedQuickPolls = ptr[1];
|
|
}
|
|
sortRealTimeData(1, index);
|
|
uint32_t lastBaseAddress = hitEntries[0].baseAddress;
|
|
uint32_t lastChangeIndex = 0;
|
|
uint32_t hitCount = 0;
|
|
uint32_t missedQuickPolls = 0;
|
|
for(uint32_t i = 0; i < index; ++i) {
|
|
const HitEntry &entry = hitEntries[i];
|
|
if(entry.baseAddress == lastBaseAddress) {
|
|
hitCount += entry.numHits;
|
|
missedQuickPolls += entry.missedQuickPolls;
|
|
continue;
|
|
}
|
|
for(uint32_t j = lastChangeIndex; j < i; ++j) {
|
|
hitEntries[j].numHitsPerFunc = hitCount;
|
|
hitEntries[j].missedQuickPollsPerFunc=missedQuickPolls;
|
|
}
|
|
lastChangeIndex = i;
|
|
hitCount = entry.numHits;
|
|
missedQuickPolls = entry.missedQuickPolls;
|
|
lastBaseAddress = entry.baseAddress;
|
|
}
|
|
if(hitCount) {
|
|
for(uint32_t i = lastChangeIndex; i < index; ++i) {
|
|
hitEntries[i].numHitsPerFunc = hitCount;
|
|
hitEntries[i].missedQuickPollsPerFunc=missedQuickPolls;
|
|
}
|
|
}
|
|
sb->safePrintf("<table %s>",TABLE_STYLE);
|
|
char *showMessage;
|
|
int rtall;
|
|
if(realTimeShowAll) {
|
|
showMessage = "(show only 10)";
|
|
rtall = 0;
|
|
} else {
|
|
showMessage = "(show all)";
|
|
rtall = 1;
|
|
}
|
|
sb->safePrintf("<tr class=hdrow><td colspan=7>"
|
|
"<center><b>Real Time Profiler "
|
|
"<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></b></center></td></tr>\n",
|
|
coll);
|
|
rtall = !rtall;
|
|
sb->safePrintf("<tr><td><b>"
|
|
"Function</b></td>");
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?rtsort=2&c=%s&"
|
|
"&rtall=%i>"
|
|
"Hits per Func</b></a></td>",coll,rtall);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?rtsort=0&c=%s&"
|
|
"&rtall=%i>"
|
|
"Missed QUICKPOLL calls<br>per Func</b></a></td>",
|
|
coll,rtall);
|
|
sb->safePrintf("<td><b><a href=/admin/profiler?rtsort=1&c=%s&"
|
|
"&rtall=%i>"
|
|
"Base Address</b></a></td>",coll,rtall);
|
|
sb->safePrintf("<td><b>Hits per Line</b></td><td>"
|
|
"<b>Line Address</b></td>"
|
|
"<td><b>Missed QUICKPOLL calls<br>"
|
|
"per Line</b></td></tr>");
|
|
sortRealTimeData(realTimeSortMode, index);
|
|
const HitEntry &entry = hitEntries[0];
|
|
lastBaseAddress = entry.baseAddress;
|
|
uint32_t maxEntries;
|
|
if(realTimeShowAll) maxEntries = UINT_MAX;
|
|
else maxEntries = 25;
|
|
for(uint32_t i = 0; i < index; ++i) {
|
|
top:
|
|
const HitEntry &entry = hitEntries[i];
|
|
if(entry.baseAddress == lastBaseAddress) continue;
|
|
if(!(maxEntries--)) break;
|
|
char * funcName;
|
|
if(!entry.funcName || !gbstrlen(entry.funcName))
|
|
funcName = "Unknown";
|
|
else funcName = entry.funcName;
|
|
sb->safePrintf("<tr><td valign=\"top\">%s</td>"
|
|
"<td valign=\"top\">%i</td>"
|
|
"<td valign=\"top\">%i</td>"
|
|
"<td valign=\"top\">%#.8x</td>",
|
|
funcName,
|
|
entry.numHitsPerFunc,
|
|
entry.missedQuickPollsPerFunc,
|
|
entry.baseAddress);
|
|
lastBaseAddress = entry.baseAddress;
|
|
sb->safePrintf("<td><table>");
|
|
sb->safePrintf("<tr><td>%i</td></tr>", entry.numHits);
|
|
if(!realTimeShowAll) {
|
|
sb->safePrintf("</table><td><table>");
|
|
sb->safePrintf("<tr><td>%#.8x</td></tr>",entry.address);
|
|
sb->safePrintf("<tr><td>...</td></tr>");
|
|
sb->safePrintf("</table><td><table>");
|
|
sb->safePrintf("<tr><td>%i</td></tr>",
|
|
entry.missedQuickPolls);
|
|
sb->safePrintf("<tr><td>...</td></tr>");
|
|
sb->safePrintf("</table></td></td></tr>");
|
|
continue;
|
|
}
|
|
for(uint32_t j = i + 1; j < index; ++j) {
|
|
const HitEntry &entry = hitEntries[j];
|
|
if(entry.baseAddress != lastBaseAddress) break;
|
|
sb->safePrintf("<tr><td>%i</td></tr>",
|
|
entry.numHits);
|
|
}
|
|
sb->safePrintf("</table><td><table>");
|
|
sb->safePrintf("<tr><td>%#.8x</td></tr>", entry.address);
|
|
for(uint32_t j = i + 1; j < index; ++j) {
|
|
const HitEntry &entry = hitEntries[j];
|
|
if(entry.baseAddress != lastBaseAddress) break;
|
|
sb->safePrintf("<tr><td>%#.8x</td></tr>",
|
|
entry.address);
|
|
}
|
|
sb->safePrintf("</table><td><table>");
|
|
sb->safePrintf("<tr><td>%i</td></tr>",
|
|
entry.missedQuickPolls);
|
|
for(++i; i < index; ++i) {
|
|
const HitEntry &entry = hitEntries[i];
|
|
if(entry.baseAddress != lastBaseAddress) {
|
|
sb->safePrintf("</table></td>"
|
|
"</td></tr>");
|
|
goto top;
|
|
}
|
|
sb->safePrintf("<tr><td>%i</td></tr>",
|
|
entry.missedQuickPolls);
|
|
}
|
|
}
|
|
sb->safePrintf("</table></td></td></tr></table><br><br>\n");
|
|
sb->safePrintf("<pre>");
|
|
m_rootFrame->dump(sb);
|
|
sb->safePrintf("</pre>");
|
|
g_profiler.startRealTimeProfiler();
|
|
return true;
|
|
}
|
|
|
|
void
|
|
Profiler::cleanup() {
|
|
m_rootFrame = 0;
|
|
}
|
|
|
|
FrameTrace *
|
|
Profiler::getNewFrameTrace(const uint32_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);
|
|
}
|
|
|
|
#endif
|