From c8b9a2095e2d486f3727a448a921fb9663bda8b1 Mon Sep 17 00:00:00 2001 From: Nathan Woods Date: Sun, 9 Dec 2012 23:11:14 +0000 Subject: [PATCH] Profiler rewrite; simplified, streamlined and less overhead. --- src/emu/eigccx86.h | 8 +- src/emu/profiler.c | 155 +++++++++++++++----------------------- src/emu/profiler.h | 91 +++++++++++++++------- src/emu/ui.c | 5 +- src/osd/osdcore.h | 4 +- src/osd/windows/eivcx86.h | 4 +- 6 files changed, 134 insertions(+), 133 deletions(-) diff --git a/src/emu/eigccx86.h b/src/emu/eigccx86.h index fc0af12fbfa..d7ad34d89e3 100644 --- a/src/emu/eigccx86.h +++ b/src/emu/eigccx86.h @@ -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 diff --git a/src/emu/profiler.c b/src/emu/profiler.c index 71b8735c052..f1b18d7560b 100644 --- a/src/emu/profiler.c +++ b/src/emu/profiler.c @@ -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)); } diff --git a/src/emu/profiler.h b/src/emu/profiler.h index 29301b8662a..0340e4f1faf 100644 --- a/src/emu/profiler.h +++ b/src/emu/profiler.h @@ -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) { } diff --git a/src/emu/ui.c b/src/emu/ui.c index 8a5c60c7e3b..22e99e50e5e 100644 --- a/src/emu/ui.c +++ b/src/emu/ui.c @@ -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 */ diff --git a/src/osd/osdcore.h b/src/osd/osdcore.h index 6c9d3dec4e9..314b17b43b3 100644 --- a/src/osd/osdcore.h +++ b/src/osd/osdcore.h @@ -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; /*----------------------------------------------------------------------------- diff --git a/src/osd/windows/eivcx86.h b/src/osd/windows/eivcx86.h index 759f4221ddb..b9cd1e30dcb 100644 --- a/src/osd/windows/eivcx86.h +++ b/src/osd/windows/eivcx86.h @@ -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