Previous 199869 Revisions Next

r19440 Sunday 9th December, 2012 at 23:11:14 UTC by Nathan Woods
Profiler rewrite; simplified, streamlined and less overhead.
[src/emu]eigccx86.h profiler.c profiler.h ui.c
[src/osd]osdcore.h
[src/osd/windows]eivcx86.h

trunk/src/osd/osdcore.h
r19439r19440
355355    TIMING INTERFACES
356356***************************************************************************/
357357
358/* a osd_ticks_t is a 64-bit integer that is used as a core type in timing interfaces */
359typedef INT64 osd_ticks_t;
358/* a osd_ticks_t is a 64-bit unsigned integer that is used as a core type in timing interfaces */
359typedef UINT64 osd_ticks_t;
360360
361361
362362/*-----------------------------------------------------------------------------
trunk/src/osd/windows/eivcx86.h
r19439r19440
519519
520520INLINE osd_ticks_t _get_profile_ticks(void)
521521{
522   INT64 result;
523   INT64 *presult = &result;
522   UINT64 result;
523   UINT64 *presult = &result;
524524
525525   __asm {
526526      __asm _emit 0Fh __asm _emit 031h   // rdtsc
trunk/src/emu/ui.c
r19439r19440
13771377   /* draw the profiler if visible */
13781378   if (show_profiler)
13791379   {
1380      astring profilertext;
1381      g_profiler.text(machine, profilertext);
1382      ui_draw_text_full(container, profilertext, 0.0f, 0.0f, 1.0f, JUSTIFY_LEFT, WRAP_WORD, DRAW_OPAQUE, ARGB_WHITE, ARGB_BLACK, NULL, NULL);
1380      const char *text = g_profiler.text(machine);
1381      ui_draw_text_full(container, text, 0.0f, 0.0f, 1.0f, JUSTIFY_LEFT, WRAP_WORD, DRAW_OPAQUE, ARGB_WHITE, ARGB_BLACK, NULL, NULL);
13831382   }
13841383
13851384   /* if we're single-stepping, pause now */
trunk/src/emu/profiler.c
r19439r19440
7676
7777
7878//**************************************************************************
79//  CONSTANTS
80//**************************************************************************
81
82#define TEXT_UPDATE_TIME      0.5
83
84
85
86//**************************************************************************
7987//  DUMMY PROFILER STATE
8088//**************************************************************************
8189
r19439r19440
98106//-------------------------------------------------
99107
100108real_profiler_state::real_profiler_state()
101   : m_enabled(false),
102     m_dataready(false),
103     m_filoindex(0),
104     m_dataindex(0)
105109{
106110   memset(m_filo, 0, sizeof(m_filo));
107111   memset(m_data, 0, sizeof(m_data));
112   reset(false);
108113}
109114
110115
116
111117//-------------------------------------------------
112//  real_start - mark the beginning of a
113//  profiler entry
118//  reset - initializes state
114119//-------------------------------------------------
115120
116void real_profiler_state::real_start(profile_type type)
121void real_profiler_state::reset(bool enabled)
117122{
118   osd_ticks_t curticks = get_profile_ticks();
123   m_text_time = attotime::never;
119124
120   // track context switches
121   history_data &data = m_data[m_dataindex];
122   if (type >= PROFILER_DEVICE_FIRST && type <= PROFILER_DEVICE_MAX)
123      data.context_switches++;
125   if (enabled)
126   {
127      // we're enabled now
128      m_filoptr = m_filo;
124129
125   // we're starting a new bucket, begin now
126   int index = m_filoindex++;
127   filo_entry &entry = m_filo[index];
128
129   // fail if we overflow
130   if (index > ARRAY_LENGTH(m_filo))
131      throw emu_fatalerror("Profiler FILO overflow (type = %d)\n", type);
132
133   // if we're nested, stop the previous entry
134   if (index > 0)
130      // set up dummy entry
131      m_filoptr->start = 0;
132      m_filoptr->type = PROFILER_TOTAL;
133   }
134   else
135135   {
136      filo_entry &preventry = m_filo[index - 1];
137      data.duration[preventry.type] += curticks - preventry.start;
136      // magic value to indicate disabled
137      m_filoptr = NULL;
138138   }
139
140   // fill in this entry
141   entry.type = type;
142   entry.start = curticks;
143139}
144140
145141
142
146143//-------------------------------------------------
147//  real_stop - mark the end of a profiler entry
144//  text - return the current text in an astring
148145//-------------------------------------------------
149146
150void real_profiler_state::real_stop()
147const char *real_profiler_state::text(running_machine &machine)
151148{
152   osd_ticks_t curticks = get_profile_ticks();
149   start(PROFILER_PROFILER);
153150
154   // we're ending an existing bucket, update the time
155   if (m_filoindex > 0)
156   {
157      int index = --m_filoindex;
158      filo_entry &entry = m_filo[index];
151   // get the current time
152   attotime current_time = machine.scheduler().time();
159153
160      // account for the time taken
161      history_data &data = m_data[m_dataindex];
162      data.duration[entry.type] += curticks - entry.start;
163
164      // if we have a previous entry, restart his time now
165      if (index != 0)
166      {
167         filo_entry &preventry = m_filo[index - 1];
168         preventry.start = curticks;
169      }
154   // we only want to update the text periodically
155   if ((m_text_time == attotime::never) || ((current_time - m_text_time).as_double() >= TEXT_UPDATE_TIME))
156   {
157      update_text(machine);
158      m_text_time = current_time;
170159   }
160
161   stop();
162   return m_text;
171163}
172164
173165
166
174167//-------------------------------------------------
175//  text - return the current text in an astring
168//  update_text - update the current astring
176169//-------------------------------------------------
177170
178const char *real_profiler_state::text(running_machine &machine, astring &string)
171void real_profiler_state::update_text(running_machine &machine)
179172{
180173   static const profile_string names[] =
181174   {
r19439r19440
208201      { PROFILER_IDLE,             "Idle" }
209202   };
210203
211   g_profiler.start(PROFILER_PROFILER);
212
213204   // compute the total time for all bits, not including profiler or idle
214205   UINT64 computed = 0;
215206   profile_type curtype;
216207   for (curtype = PROFILER_DEVICE_FIRST; curtype < PROFILER_PROFILER; curtype++)
217      for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
218         computed += m_data[curmem].duration[curtype];
208      computed += m_data[curtype];
219209
220210   // save that result in normalize, and continue adding the rest
221211   UINT64 normalize = computed;
222212   for ( ; curtype < PROFILER_TOTAL; curtype++)
223      for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
224         computed += m_data[curmem].duration[curtype];
213      computed += m_data[curtype];
225214
226215   // this becomes the total; if we end up with 0 for anything, we were just started, so return empty
227216   UINT64 total = computed;
228   string.reset();
217   m_text.reset();
229218   if (total == 0 || normalize == 0)
230219   {
231      g_profiler.stop();
232      return string;
220      return;
233221   }
234222
235223   // loop over all types and generate the string
r19439r19440
237225   for (curtype = PROFILER_DEVICE_FIRST; curtype < PROFILER_TOTAL; curtype++)
238226   {
239227      // determine the accumulated time for this type
240      computed = 0;
241      for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
242         computed += m_data[curmem].duration[curtype];
228      computed = m_data[curtype];
243229
244230      // if we have non-zero data and we're ready to display, do it
245      if (m_dataready && computed != 0)
231      if (computed != 0)
246232      {
247233         // start with the un-normalized percentage
248         string.catprintf("%02d%% ", (int)((computed * 100 + total/2) / total));
234         m_text.catprintf("%02d%% ", (int)((computed * 100 + total/2) / total));
249235
250236         // followed by the normalized percentage for everything but profiler and idle
251237         if (curtype < PROFILER_PROFILER)
252            string.catprintf("%02d%% ", (int)((computed * 100 + normalize/2) / normalize));
238            m_text.catprintf("%02d%% ", (int)((computed * 100 + normalize/2) / normalize));
253239
254240         // and then the text
255241         if (curtype >= PROFILER_DEVICE_FIRST && curtype <= PROFILER_DEVICE_MAX)
256            string.catprintf("'%s'", iter.byindex(curtype - PROFILER_DEVICE_FIRST)->tag());
242            m_text.catprintf("'%s'", iter.byindex(curtype - PROFILER_DEVICE_FIRST)->tag());
257243         else
258244            for (int nameindex = 0; nameindex < ARRAY_LENGTH(names); nameindex++)
259245               if (names[nameindex].type == curtype)
260246               {
261                  string.cat(names[nameindex].string);
247                  m_text.cat(names[nameindex].string);
262248                  break;
263249               }
264250
265251         // followed by a carriage return
266         string.cat("\n");
252         m_text.cat("\n");
267253      }
268254   }
269255
270   // followed by context switches
271   if (m_dataready)
272   {
273      int switches = 0;
274      for (int curmem = 0; curmem < ARRAY_LENGTH(m_data); curmem++)
275         switches += m_data[curmem].context_switches;
276      string.catprintf("%d CPU switches\n", switches / (int) ARRAY_LENGTH(m_data));
277   }
278
279   // advance to the next dataset and reset it to 0
280   m_dataindex = (m_dataindex + 1) % ARRAY_LENGTH(m_data);
281   memset(&m_data[m_dataindex], 0, sizeof(m_data[m_dataindex]));
282
283   // we are ready once we have wrapped around
284   if (m_dataindex == 0)
285      m_dataready = true;
286
287   g_profiler.stop();
288   return string;
256   // reset data set to 0
257   memset(m_data, 0, sizeof(m_data));
289258}
trunk/src/emu/profiler.h
r19439r19440
5555#ifndef __PROFILER_H__
5656#define __PROFILER_H__
5757
58#include "attotime.h"
5859
5960
61
6062//**************************************************************************
6163//  CONSTANTS
6264//**************************************************************************
r19439r19440
111113
112114class real_profiler_state
113115{
114   friend class profile_scope;
115
116116public:
117117   // construction/destruction
118118   real_profiler_state();
119119
120120   // getters
121   bool enabled() const { return m_enabled; }
122   const char *text(running_machine &machine, astring &string);
121   bool enabled() const { return m_filoptr != NULL; }
122   const char *text(running_machine &machine);
123123
124124   // enable/disable
125125   void enable(bool state = true)
126126   {
127      if (state != m_enabled)
127      if (state != enabled())
128128      {
129         m_enabled = state;
130         if (m_enabled)
131         {
132            m_dataready = false;
133            m_filoindex = m_dataindex = 0;
134         }
129         reset(state);
135130      }
136131   }
137132
138133   // start/stop
139   void start(profile_type type) { if (m_enabled) real_start(type); }
140   void stop() { if (m_enabled) real_stop(); }
134   void start(profile_type type) { if (enabled()) real_start(type); }
135   void stop() { if (enabled()) real_stop(); }
141136
142137private:
143   void real_start(profile_type type);
144   void real_stop();
138   void reset(bool enabled);
139   void update_text(running_machine &machine);
145140
141   //-------------------------------------------------
142   //  real_start - mark the beginning of a
143   //  profiler entry
144   //-------------------------------------------------
145   ATTR_FORCE_INLINE void real_start(profile_type type)
146   {
147      // fail if we overflow
148      if (m_filoptr >= &m_filo[ARRAY_LENGTH(m_filo) - 1])
149         throw emu_fatalerror("Profiler FILO overflow (type = %d)\n", type);
150
151      // get current tick count
152      osd_ticks_t curticks = get_profile_ticks();
153
154      // update previous entry
155      m_data[m_filoptr->type] += curticks - m_filoptr->start;
156
157      // move to next entry
158      m_filoptr++;
159
160      // fill in this entry
161      m_filoptr->type = type;
162      m_filoptr->start = curticks;
163   }
164
165   //-------------------------------------------------
166   //  real_stop - mark the end of a profiler entry
167   //-------------------------------------------------
168   ATTR_FORCE_INLINE void real_stop()
169   {
170      // degenerate scenario
171      if (UNEXPECTED(m_filoptr <= m_filo))
172         return;
173
174      // get current tick count
175      osd_ticks_t curticks = get_profile_ticks();
176
177      // account for the time taken
178      m_data[m_filoptr->type] += curticks - m_filoptr->start;
179
180      // move back an entry
181      m_filoptr--;
182
183      // reset previous entry start time
184      m_filoptr->start = curticks;
185   }
186
146187   // an entry in the FILO
147188   struct filo_entry
148189   {
r19439r19440
150191      osd_ticks_t      start;                  // start time
151192   };
152193
153   // item in the array of recent states
154   struct history_data
155   {
156      UINT32         context_switches;         // number of context switches seen
157      osd_ticks_t      duration[PROFILER_TOTAL];   // duration spent in each entry
158   };
159
160194   // internal state
161   bool            m_enabled;               // are we enabled?
162   bool            m_dataready;            // are we to display the data yet?
163   UINT8            m_filoindex;            // current FILO index
164   UINT8            m_dataindex;            // current data index
165   filo_entry         m_filo[16];               // array of FILO entries
166   history_data      m_data[16];               // array of data
195   filo_entry *      m_filoptr;               // current FILO index
196   astring            m_text;                  // profiler text
197   attotime         m_text_time;            // profiler text last update
198   filo_entry         m_filo[32];               // array of FILO entries
199   osd_ticks_t         m_data[PROFILER_TOTAL + 1];   // array of data
167200};
168201
169202
r19439r19440
177210
178211   // getters
179212   bool enabled() const { return false; }
180   const char *text(running_machine &machine, astring &string) { return string.cpy(""); }
213   const char *text(running_machine &machine) { return ""; }
181214
182215   // enable/disable
183216   void enable(bool state = true) { }
trunk/src/emu/eigccx86.h
r19439r19440
692692#define get_profile_ticks _get_profile_ticks
693693
694694#ifndef __x86_64__
695INLINE INT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
695INLINE UINT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
696696{
697697    UINT64 result;
698698    __asm__ __volatile__ (
699699            "rdtsc"
700700            : "=A" (result)
701701    );
702    return (INT64) (result & U64(0x7fffffffffffffff));
702    return result;
703703}
704704#else
705INLINE INT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
705INLINE UINT64 ATTR_UNUSED ATTR_FORCE_INLINE _get_profile_ticks(void)
706706{
707707   _x86_union r;
708708    __asm__ __volatile__ (
r19439r19440
710710            : "=a" (r.u32.l), "=d" (r.u32.h)
711711    );
712712
713    return (INT64) (r.u64 & U64(0x7fffffffffffffff));
713    return (UINT64) r.u64;
714714}
715715#endif
716716

Previous 199869 Revisions Next

© 1997-2024 The MAME Team