Profiler rewrite; simplified, streamlined and less overhead.

This commit is contained in:
Nathan Woods 2012-12-09 23:11:14 +00:00
parent 6bec0abb67
commit c8b9a2095e
6 changed files with 134 additions and 133 deletions

View File

@ -692,17 +692,17 @@ _atomic_decrement32(INT32 volatile *ptr)
#define get_profile_ticks _get_profile_ticks
#ifndef __x86_64__
INLINE INT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
INLINE UINT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
{
UINT64 result;
__asm__ __volatile__ (
"rdtsc"
: "=A" (result)
);
return (INT64) (result & U64(0x7fffffffffffffff));
return result;
}
#else
INLINE INT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
INLINE UINT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
{
_x86_union r;
__asm__ __volatile__ (
@ -710,7 +710,7 @@ INLINE INT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
: "=a" (r.u32.l), "=d" (r.u32.h)
);
return (INT64) (r.u64 & U64(0x7fffffffffffffff));
return (UINT64) r.u64;
}
#endif

View File

@ -75,6 +75,14 @@ profiler_state g_profiler;
//**************************************************************************
// CONSTANTS
//**************************************************************************
#define TEXT_UPDATE_TIME 0.5
//**************************************************************************
// DUMMY PROFILER STATE
//**************************************************************************
@ -98,84 +106,69 @@ dummy_profiler_state::dummy_profiler_state()
//-------------------------------------------------
real_profiler_state::real_profiler_state()
: m_enabled(false),
m_dataready(false),
m_filoindex(0),
m_dataindex(0)
{
memset(m_filo, 0, sizeof(m_filo));
memset(m_data, 0, sizeof(m_data));
reset(false);
}
//-------------------------------------------------
// real_start - mark the beginning of a
// profiler entry
// reset - initializes state
//-------------------------------------------------
void real_profiler_state::real_start(profile_type type)
void real_profiler_state::reset(bool enabled)
{
osd_ticks_t curticks = get_profile_ticks();
m_text_time = attotime::never;
// track context switches
history_data &data = m_data[m_dataindex];
if (type >= PROFILER_DEVICE_FIRST && type <= PROFILER_DEVICE_MAX)
data.context_switches++;
// we're starting a new bucket, begin now
int index = m_filoindex++;
filo_entry &entry = m_filo[index];
// fail if we overflow
if (index > ARRAY_LENGTH(m_filo))
throw emu_fatalerror("Profiler FILO overflow (type = %d)\n", type);
// if we're nested, stop the previous entry
if (index > 0)
if (enabled)
{
filo_entry &preventry = m_filo[index - 1];
data.duration[preventry.type] += curticks - preventry.start;
// we're enabled now
m_filoptr = m_filo;
// set up dummy entry
m_filoptr->start = 0;
m_filoptr->type = PROFILER_TOTAL;
}
// fill in this entry
entry.type = type;
entry.start = curticks;
}
//-------------------------------------------------
// real_stop - mark the end of a profiler entry
//-------------------------------------------------
void real_profiler_state::real_stop()
{
osd_ticks_t curticks = get_profile_ticks();
// we're ending an existing bucket, update the time
if (m_filoindex > 0)
else
{
int index = --m_filoindex;
filo_entry &entry = m_filo[index];
// account for the time taken
history_data &data = m_data[m_dataindex];
data.duration[entry.type] += curticks - entry.start;
// if we have a previous entry, restart his time now
if (index != 0)
{
filo_entry &preventry = m_filo[index - 1];
preventry.start = curticks;
}
// magic value to indicate disabled
m_filoptr = NULL;
}
}
//-------------------------------------------------
// text - return the current text in an astring
//-------------------------------------------------
const char *real_profiler_state::text(running_machine &machine, astring &string)
const char *real_profiler_state::text(running_machine &machine)
{
start(PROFILER_PROFILER);
// get the current time
attotime current_time = machine.scheduler().time();
// we only want to update the text periodically
if ((m_text_time == attotime::never) || ((current_time - m_text_time).as_double() >= TEXT_UPDATE_TIME))
{
update_text(machine);
m_text_time = current_time;
}
stop();
return m_text;
}
//-------------------------------------------------
// update_text - update the current astring
//-------------------------------------------------
void real_profiler_state::update_text(running_machine &machine)
{
static const profile_string names[] =
{
@ -208,28 +201,23 @@ const char *real_profiler_state::text(running_machine &machine, astring &string)
{ PROFILER_IDLE, "Idle" }
};
g_profiler.start(PROFILER_PROFILER);
// compute the total time for all bits, not including profiler or idle
UINT64 computed = 0;
profile_type curtype;
for (curtype = PROFILER_DEVICE_FIRST; curtype < PROFILER_PROFILER; curtype++)
for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
computed += m_data[curmem].duration[curtype];
computed += m_data[curtype];
// save that result in normalize, and continue adding the rest
UINT64 normalize = computed;
for ( ; curtype < PROFILER_TOTAL; curtype++)
for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
computed += m_data[curmem].duration[curtype];
computed += m_data[curtype];
// this becomes the total; if we end up with 0 for anything, we were just started, so return empty
UINT64 total = computed;
string.reset();
m_text.reset();
if (total == 0 || normalize == 0)
{
g_profiler.stop();
return string;
return;
}
// loop over all types and generate the string
@ -237,53 +225,34 @@ const char *real_profiler_state::text(running_machine &machine, astring &string)
for (curtype = PROFILER_DEVICE_FIRST; curtype < PROFILER_TOTAL; curtype++)
{
// determine the accumulated time for this type
computed = 0;
for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
computed += m_data[curmem].duration[curtype];
computed = m_data[curtype];
// if we have non-zero data and we're ready to display, do it
if (m_dataready && computed != 0)
if (computed != 0)
{
// start with the un-normalized percentage
string.catprintf("%02d%% ", (int)((computed * 100 + total/2) / total));
m_text.catprintf("%02d%% ", (int)((computed * 100 + total/2) / total));
// followed by the normalized percentage for everything but profiler and idle
if (curtype < PROFILER_PROFILER)
string.catprintf("%02d%% ", (int)((computed * 100 + normalize/2) / normalize));
m_text.catprintf("%02d%% ", (int)((computed * 100 + normalize/2) / normalize));
// and then the text
if (curtype >= PROFILER_DEVICE_FIRST && curtype <= PROFILER_DEVICE_MAX)
string.catprintf("'%s'", iter.byindex(curtype - PROFILER_DEVICE_FIRST)->tag());
m_text.catprintf("'%s'", iter.byindex(curtype - PROFILER_DEVICE_FIRST)->tag());
else
for (int nameindex = 0; nameindex < ARRAY_LENGTH(names); nameindex++)
if (names[nameindex].type == curtype)
{
string.cat(names[nameindex].string);
m_text.cat(names[nameindex].string);
break;
}
// followed by a carriage return
string.cat("\n");
m_text.cat("\n");
}
}
// followed by context switches
if (m_dataready)
{
int switches = 0;
for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
switches += m_data[curmem].context_switches;
string.catprintf("%d CPU switches\n", switches / (int) ARRAY_LENGTH(m_data));
}
// advance to the next dataset and reset it to 0
m_dataindex = (m_dataindex + 1) % ARRAY_LENGTH(m_data);
memset(&m_data[m_dataindex], 0, sizeof(m_data[m_dataindex]));
// we are ready once we have wrapped around
if (m_dataindex == 0)
m_dataready = true;
g_profiler.stop();
return string;
// reset data set to 0
memset(m_data, 0, sizeof(m_data));
}

View File

@ -55,6 +55,8 @@
#ifndef __PROFILER_H__
#define __PROFILER_H__
#include "attotime.h"
//**************************************************************************
@ -111,37 +113,76 @@ DECLARE_ENUM_OPERATORS(profile_type);
class real_profiler_state
{
friend class profile_scope;
public:
// construction/destruction
real_profiler_state();
// getters
bool enabled() const { return m_enabled; }
const char *text(running_machine &machine, astring &string);
bool enabled() const { return m_filoptr != NULL; }
const char *text(running_machine &machine);
// enable/disable
void enable(bool state = true)
{
if (state != m_enabled)
if (state != enabled())
{
m_enabled = state;
if (m_enabled)
{
m_dataready = false;
m_filoindex = m_dataindex = 0;
}
reset(state);
}
}
// start/stop
void start(profile_type type) { if (m_enabled) real_start(type); }
void stop() { if (m_enabled) real_stop(); }
void start(profile_type type) { if (enabled()) real_start(type); }
void stop() { if (enabled()) real_stop(); }
private:
void real_start(profile_type type);
void real_stop();
void reset(bool enabled);
void update_text(running_machine &machine);
//-------------------------------------------------
// real_start - mark the beginning of a
// profiler entry
//-------------------------------------------------
ATTR_FORCE_INLINE void real_start(profile_type type)
{
// fail if we overflow
if (m_filoptr >= &m_filo[ARRAY_LENGTH(m_filo) - 1])
throw emu_fatalerror("Profiler FILO overflow (type = %d)\n", type);
// get current tick count
osd_ticks_t curticks = get_profile_ticks();
// update previous entry
m_data[m_filoptr->type] += curticks - m_filoptr->start;
// move to next entry
m_filoptr++;
// fill in this entry
m_filoptr->type = type;
m_filoptr->start = curticks;
}
//-------------------------------------------------
// real_stop - mark the end of a profiler entry
//-------------------------------------------------
ATTR_FORCE_INLINE void real_stop()
{
// degenerate scenario
if (UNEXPECTED(m_filoptr <= m_filo))
return;
// get current tick count
osd_ticks_t curticks = get_profile_ticks();
// account for the time taken
m_data[m_filoptr->type] += curticks - m_filoptr->start;
// move back an entry
m_filoptr--;
// reset previous entry start time
m_filoptr->start = curticks;
}
// an entry in the FILO
struct filo_entry
@ -150,20 +191,12 @@ private:
osd_ticks_t start; // start time
};
// item in the array of recent states
struct history_data
{
UINT32 context_switches; // number of context switches seen
osd_ticks_t duration[PROFILER_TOTAL]; // duration spent in each entry
};
// internal state
bool m_enabled; // are we enabled?
bool m_dataready; // are we to display the data yet?
UINT8 m_filoindex; // current FILO index
UINT8 m_dataindex; // current data index
filo_entry m_filo[16]; // array of FILO entries
history_data m_data[16]; // array of data
filo_entry * m_filoptr; // current FILO index
astring m_text; // profiler text
attotime m_text_time; // profiler text last update
filo_entry m_filo[32]; // array of FILO entries
osd_ticks_t m_data[PROFILER_TOTAL + 1]; // array of data
};
@ -177,7 +210,7 @@ public:
// getters
bool enabled() const { return false; }
const char *text(running_machine &machine, astring &string) { return string.cpy(""); }
const char *text(running_machine &machine) { return ""; }
// enable/disable
void enable(bool state = true) { }

View File

@ -1377,9 +1377,8 @@ static UINT32 handler_ingame(running_machine &machine, render_container *contain
/* draw the profiler if visible */
if (show_profiler)
{
astring profilertext;
g_profiler.text(machine, profilertext);
ui_draw_text_full(container, profilertext, 0.0f, 0.0f, 1.0f, JUSTIFY_LEFT, WRAP_WORD, DRAW_OPAQUE, ARGB_WHITE, ARGB_BLACK, NULL, NULL);
const char *text = g_profiler.text(machine);
ui_draw_text_full(container, text, 0.0f, 0.0f, 1.0f, JUSTIFY_LEFT, WRAP_WORD, DRAW_OPAQUE, ARGB_WHITE, ARGB_BLACK, NULL, NULL);
}
/* if we're single-stepping, pause now */

View File

@ -355,8 +355,8 @@ int osd_is_absolute_path(const char *path);
TIMING INTERFACES
***************************************************************************/
/* a osd_ticks_t is a 64-bit integer that is used as a core type in timing interfaces */
typedef INT64 osd_ticks_t;
/* a osd_ticks_t is a 64-bit unsigned integer that is used as a core type in timing interfaces */
typedef UINT64 osd_ticks_t;
/*-----------------------------------------------------------------------------

View File

@ -519,8 +519,8 @@ INLINE osd_ticks_t _get_profile_ticks(void)
INLINE osd_ticks_t _get_profile_ticks(void)
{
INT64 result;
INT64 *presult = &result;
UINT64 result;
UINT64 *presult = &result;
__asm {
__asm _emit 0Fh __asm _emit 031h // rdtsc