Added a frame timing statistics window to the Qt tools. Allows user to enable frame timing statistical calculations and view the output on a window in realtime. Is used to verify emulator is getting the proper clock interrupts from the OS and thus check that emulation timing is deterministic.

src/CMakeLists.txt

@@ -435,6 +435,7 @@ set(SRC_DRIVERS_SDL
   ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/GamePadConf.cpp  
   ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/HotKeyConf.cpp  
   ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/TimingConf.cpp  
+  ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/FrameTimingStats.cpp  
   ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/PaletteConf.cpp  
   ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/GuiConf.cpp  
   ${CMAKE_CURRENT_SOURCE_DIR}/drivers/Qt/MoviePlay.cpp  

src/drivers/Qt/ConsoleWindow.cpp

@@ -37,6 +37,7 @@
 #include "Qt/MoviePlay.h"
 #include "Qt/MovieOptions.h"
 #include "Qt/TimingConf.h"
+#include "Qt/FrameTimingStats.h"
 #include "Qt/LuaControl.h"
 #include "Qt/CheatsConf.h"
 #include "Qt/GameGenie.h"
@@ -654,6 +655,14 @@ void consoleWin_t::createMainMenu(void)
 
     toolsMenu->addAction(ramWatchAct);
 
+	// Tools -> Frame Timing
+	act = new QAction(tr("Frame Timing ..."), this);
+	//act->setShortcut( QKeySequence(tr("Shift+F7")));
+	act->setStatusTip(tr("Open Frame Timing Window"));
+	connect(act, SIGNAL(triggered()), this, SLOT(openTimingStatWin(void)) );
+
+	toolsMenu->addAction(act);
+
 	 //-----------------------------------------------------------------------
 	 // Debug
     debugMenu = menuBar()->addMenu(tr("Debug"));
@@ -1303,6 +1312,17 @@ void consoleWin_t::openTimingConfWin(void)
    tmConfWin->show();
 }
 
+void consoleWin_t::openTimingStatWin(void)
+{
+	FrameTimingDialog_t *tmStatWin;
+
+	//printf("Open Timing Statistics Window\n");
+	
+   tmStatWin = new FrameTimingDialog_t(this);
+	
+   tmStatWin->show();
+}
+
 void consoleWin_t::openMovieOptWin(void)
 {
 	MovieOptionsDialog_t *win;

src/drivers/Qt/ConsoleWindow.h

@@ -183,6 +183,7 @@ class  consoleWin_t : public QMainWindow
       void openPaletteConfWin(void);
       void openGuiConfWin(void);
       void openTimingConfWin(void);
+      void openTimingStatWin(void);
       void openMovieOptWin(void);
 		void openCodeDataLogger(void);
 		void openTraceLogger(void);

src/drivers/Qt/FrameTimingStats.cpp

@@ -0,0 +1,265 @@
+// FrameTimingStats.cpp
+//
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <string>
+
+#include <SDL.h>
+#include <QHeaderView>
+#include <QCloseEvent>
+
+#include "Qt/main.h"
+#include "Qt/dface.h"
+#include "Qt/input.h"
+#include "Qt/config.h"
+#include "Qt/keyscan.h"
+#include "Qt/throttle.h"
+#include "Qt/fceuWrapper.h"
+#include "Qt/FrameTimingStats.h"
+
+//----------------------------------------------------------------------------
+FrameTimingDialog_t::FrameTimingDialog_t(QWidget *parent)
+	: QDialog( parent )
+{
+	QVBoxLayout *mainLayout, *vbox;
+	QHBoxLayout *hbox;
+	QGroupBox   *frame;
+	QTreeWidgetItem *item;
+	QPushButton *resetBtn;
+	struct frameTimingStat_t stats;
+
+	getFrameTimingStats( &stats );
+
+	setWindowTitle("Frame Timing Statistics");
+
+	resize( 512, 512 );
+
+	mainLayout = new QVBoxLayout();
+	vbox       = new QVBoxLayout();
+	frame      = new QGroupBox( tr("Timing Statistics") );
+	frame->setLayout( vbox );
+
+	tree = new QTreeWidget();
+	vbox->addWidget( tree );
+
+	tree->setColumnCount(4);
+
+	item = new QTreeWidgetItem();
+	item->setText( 0, tr( "Parameter" ) );
+	item->setText( 1, tr( "Target"  ) );
+	item->setText( 2, tr( "Current" ) );
+	item->setText( 3, tr( "Minimum" ) );
+	item->setText( 4, tr( "Maximum" ) );
+	item->setTextAlignment( 0, Qt::AlignLeft);
+	item->setTextAlignment( 1, Qt::AlignCenter);
+	item->setTextAlignment( 2, Qt::AlignCenter);
+	item->setTextAlignment( 3, Qt::AlignCenter);
+	item->setTextAlignment( 4, Qt::AlignCenter);
+
+	tree->setHeaderItem( item );
+	tree->header()->setSectionResizeMode( QHeaderView::Stretch );
+	tree->header()->setSectionResizeMode( 0, QHeaderView::ResizeToContents );
+
+	frameTimeAbs     = new QTreeWidgetItem();
+	frameTimeDel     = new QTreeWidgetItem();
+	frameTimeWork    = new QTreeWidgetItem();
+	frameTimeIdle    = new QTreeWidgetItem();
+	frameTimeWorkPct = new QTreeWidgetItem();
+	frameTimeIdlePct = new QTreeWidgetItem();
+	frameLateCount   = new QTreeWidgetItem();
+
+	tree->addTopLevelItem( frameTimeAbs );
+	tree->addTopLevelItem( frameTimeDel );
+	tree->addTopLevelItem( frameTimeWork );
+	tree->addTopLevelItem( frameTimeIdle );
+	tree->addTopLevelItem( frameTimeWorkPct );
+	tree->addTopLevelItem( frameTimeIdlePct );
+	tree->addTopLevelItem( frameLateCount );
+
+	frameTimeAbs->setFlags( Qt::ItemIsEnabled | Qt::ItemNeverHasChildren );
+	frameTimeDel->setFlags( Qt::ItemIsEnabled | Qt::ItemNeverHasChildren );
+
+	frameTimeAbs->setText( 0, tr("Frame Period ms") );
+	frameTimeDel->setText( 0, tr("Frame Delta ms") );
+	frameTimeWork->setText( 0, tr("Frame Work ms") );
+	frameTimeIdle->setText( 0, tr("Frame Idle ms") );
+	frameTimeWorkPct->setText( 0, tr("Frame Work %") );
+	frameTimeIdlePct->setText( 0, tr("Frame Idle %") );
+	frameLateCount->setText( 0, tr("Frame Late Count") );
+
+	frameTimeAbs->setTextAlignment( 0, Qt::AlignLeft);
+	frameTimeDel->setTextAlignment( 0, Qt::AlignLeft);
+	frameTimeWork->setTextAlignment( 0, Qt::AlignLeft);
+	frameTimeIdle->setTextAlignment( 0, Qt::AlignLeft);
+	frameTimeWorkPct->setTextAlignment( 0, Qt::AlignLeft);
+	frameTimeIdlePct->setTextAlignment( 0, Qt::AlignLeft);
+	frameLateCount->setTextAlignment( 0, Qt::AlignLeft);
+
+	for (int i=0; i<4; i++)
+	{
+		frameTimeAbs->setTextAlignment( i+1, Qt::AlignCenter);
+		frameTimeDel->setTextAlignment( i+1, Qt::AlignCenter);
+		frameTimeWork->setTextAlignment( i+1, Qt::AlignCenter);
+		frameTimeIdle->setTextAlignment( i+1, Qt::AlignCenter);
+		frameTimeWorkPct->setTextAlignment( i+1, Qt::AlignCenter);
+		frameTimeIdlePct->setTextAlignment( i+1, Qt::AlignCenter);
+		frameLateCount->setTextAlignment( i+1, Qt::AlignCenter);
+	}
+
+	hbox         = new QHBoxLayout();
+	timingEnable = new QCheckBox( tr("Enable Timing Statistics Calculations") );
+	resetBtn     = new QPushButton( tr("Reset") );
+
+	timingEnable->setChecked( stats.enabled );
+
+	hbox->addWidget( timingEnable );
+	hbox->addWidget( resetBtn     );
+
+	connect( timingEnable, SIGNAL(stateChanged(int)), this, SLOT(timingEnableChanged(int)) );
+	connect( resetBtn    , SIGNAL(clicked(void))    , this, SLOT(resetTimingClicked(void)) );
+
+	mainLayout->addLayout( hbox  );
+	mainLayout->addWidget( frame );
+
+	setLayout( mainLayout );
+
+	updateTimingStats();
+
+	updateTimer  = new QTimer( this );
+
+	connect( updateTimer, &QTimer::timeout, this, &FrameTimingDialog_t::updatePeriodic );
+
+	updateTimer->start( 200 ); // 5hz
+
+}
+//----------------------------------------------------------------------------
+FrameTimingDialog_t::~FrameTimingDialog_t(void)
+{
+	printf("Destroy Frame Timing Window\n");
+	updateTimer->stop();
+}
+//----------------------------------------------------------------------------
+void FrameTimingDialog_t::closeEvent(QCloseEvent *event)
+{
+	printf("Frame Timing Close Window Event\n");
+	done(0);
+	deleteLater();
+	event->accept();
+}
+//----------------------------------------------------------------------------
+void FrameTimingDialog_t::closeWindow(void)
+{
+	//printf("Close Window\n");
+	done(0);
+	deleteLater();
+}
+//----------------------------------------------------------------------------
+void FrameTimingDialog_t::updateTimingStats(void)
+{
+	char stmp[128];
+	struct frameTimingStat_t stats;
+
+	getFrameTimingStats( &stats );
+
+	// Absolute
+	sprintf( stmp, "%.3f", stats.frameTimeAbs.tgt * 1e3 );
+	frameTimeAbs->setText( 1, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeAbs.cur * 1e3 );
+	frameTimeAbs->setText( 2, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeAbs.min * 1e3 );
+	frameTimeAbs->setText( 3, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeAbs.max * 1e3 );
+	frameTimeAbs->setText( 4, tr(stmp) );
+
+	// Delta
+	sprintf( stmp, "%.3f", stats.frameTimeDel.tgt * 1e3 );
+	frameTimeDel->setText( 1, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeDel.cur * 1e3 );
+	frameTimeDel->setText( 2, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeDel.min * 1e3 );
+	frameTimeDel->setText( 3, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeDel.max * 1e3 );
+	frameTimeDel->setText( 4, tr(stmp) );
+
+	// Work
+	sprintf( stmp, "lt %.3f", stats.frameTimeWork.tgt * 1e3 );
+	frameTimeWork->setText( 1, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeWork.cur * 1e3 );
+	frameTimeWork->setText( 2, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeWork.min * 1e3 );
+	frameTimeWork->setText( 3, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeWork.max * 1e3 );
+	frameTimeWork->setText( 4, tr(stmp) );
+
+	// Idle
+	sprintf( stmp, "gt %.3f", stats.frameTimeIdle.tgt * 1e3 );
+	frameTimeIdle->setText( 1, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeIdle.cur * 1e3 );
+	frameTimeIdle->setText( 2, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeIdle.min * 1e3 );
+	frameTimeIdle->setText( 3, tr(stmp) );
+
+	sprintf( stmp, "%.3f", stats.frameTimeIdle.max * 1e3 );
+	frameTimeIdle->setText( 4, tr(stmp) );
+
+	// Work %
+	sprintf( stmp, "lt %.1f", 100.0 * stats.frameTimeWork.tgt / stats.frameTimeAbs.tgt );
+	frameTimeWorkPct->setText( 1, tr(stmp) );
+
+	sprintf( stmp, "%.1f", 100.0 * stats.frameTimeWork.cur / stats.frameTimeAbs.tgt );
+	frameTimeWorkPct->setText( 2, tr(stmp) );
+
+	sprintf( stmp, "%.1f", 100.0 * stats.frameTimeWork.min / stats.frameTimeAbs.tgt );
+	frameTimeWorkPct->setText( 3, tr(stmp) );
+
+	sprintf( stmp, "%.1f", 100.0 * stats.frameTimeWork.max / stats.frameTimeAbs.tgt );
+	frameTimeWorkPct->setText( 4, tr(stmp) );
+
+	// Idle %
+	sprintf( stmp, "gt %.1f", 100.0 * stats.frameTimeIdle.tgt / stats.frameTimeAbs.tgt );
+	frameTimeIdlePct->setText( 1, tr(stmp) );
+
+	sprintf( stmp, "%.1f", 100.0 * stats.frameTimeIdle.cur / stats.frameTimeAbs.tgt );
+	frameTimeIdlePct->setText( 2, tr(stmp) );
+
+	sprintf( stmp, "%.1f", 100.0 * stats.frameTimeIdle.min / stats.frameTimeAbs.tgt );
+	frameTimeIdlePct->setText( 3, tr(stmp) );
+
+	sprintf( stmp, "%.1f", 100.0 * stats.frameTimeIdle.max / stats.frameTimeAbs.tgt );
+	frameTimeIdlePct->setText( 4, tr(stmp) );
+
+	// Late Count
+	sprintf( stmp, "%u", stats.lateCount );
+	frameLateCount->setText( 1, tr("0") );
+	frameLateCount->setText( 2, tr(stmp) );
+
+	tree->viewport()->update();
+}
+//----------------------------------------------------------------------------
+void FrameTimingDialog_t::updatePeriodic(void)
+{
+	updateTimingStats();
+}
+//----------------------------------------------------------------------------
+void FrameTimingDialog_t::timingEnableChanged(int state)
+{
+	setFrameTimingEnable( state != Qt::Unchecked );
+}
+//----------------------------------------------------------------------------
+void FrameTimingDialog_t::resetTimingClicked(void)
+{
+	resetFrameTiming();
+}
+//----------------------------------------------------------------------------

src/drivers/Qt/FrameTimingStats.h

@@ -0,0 +1,55 @@
+// FrameTimingStats.h
+//
+
+#pragma once
+
+#include <QWidget>
+#include <QDialog>
+#include <QVBoxLayout>
+#include <QHBoxLayout>
+#include <QComboBox>
+#include <QCheckBox>
+#include <QPushButton>
+#include <QLabel>
+#include <QTimer>
+#include <QFrame>
+#include <QGroupBox>
+#include <QTreeWidget>
+#include <QTreeWidgetItem>
+
+#include "Qt/main.h"
+
+class FrameTimingDialog_t : public QDialog
+{
+   Q_OBJECT
+
+	public:
+		FrameTimingDialog_t(QWidget *parent = 0);
+		~FrameTimingDialog_t(void);
+
+	protected:
+		void closeEvent(QCloseEvent *event);
+
+		QTimer          *updateTimer;
+		QCheckBox       *timingEnable;
+		QTreeWidgetItem *frameTimeAbs;
+		QTreeWidgetItem *frameTimeDel;
+		QTreeWidgetItem *frameTimeWork;
+		QTreeWidgetItem *frameTimeWorkPct;
+		QTreeWidgetItem *frameTimeIdle;
+		QTreeWidgetItem *frameTimeIdlePct;
+		QTreeWidgetItem *frameLateCount;
+
+		QTreeWidget  *tree;
+
+	private:
+		void updateTimingStats(void);
+
+	public slots:
+		void closeWindow(void);
+	private slots:
+		void updatePeriodic(void);
+		void resetTimingClicked(void);
+		void timingEnableChanged(int state);
+
+};

src/drivers/Qt/InputConf.cpp

@@ -238,7 +238,7 @@ InputConfDialog_t::~InputConfDialog_t(void)
 //----------------------------------------------------------------------------
 void InputConfDialog_t::closeEvent(QCloseEvent *event)
 {
-   printf("Hot Key Close Window Event\n");
+   printf("Input Config Close Window Event\n");
    done(0);
 	deleteLater();
    event->accept();

src/drivers/Qt/sdl-throttle.cpp

@@ -19,8 +19,12 @@ static const double Normal  = 1.0;      // 1x speed    (around 60 fps on NTSC)
 static uint32 frameLateCounter = 0;
 static double Lasttime=0, Nexttime=0, Latetime=0;
 static double desired_frametime = (1.0 / 60.099823);
-static double frameDeltaMin = 99999.0;
+static double frameDeltaCur = 0.0;
+static double frameDeltaMin = 1.0;
 static double frameDeltaMax = 0.0;
+static double frameIdleCur = 0.0;
+static double frameIdleMin = 1.0;
+static double frameIdleMax = 0.0;
 static bool   keepFrameTimeStats = false;
 static int InFrame = 0;
 double g_fpsScale = Normal; // used by sdl.cpp
@@ -87,7 +91,7 @@ static void setTimer( double hz )
 
 	Lasttime = getHighPrecTimeStamp();
 	Nexttime = Lasttime + desired_frametime;
-	Latetime = Nexttime + desired_frametime;
+	Latetime = Nexttime + (desired_frametime*0.50);
 }
 #endif
 
@@ -110,6 +114,61 @@ int setTimingMode( int mode )
 	return 0;
 }
 
+void setFrameTimingEnable( bool enable )
+{
+	keepFrameTimeStats = enable;
+}
+
+int  getFrameTimingStats( struct frameTimingStat_t *stats )
+{
+	stats->enabled   = keepFrameTimeStats;
+	stats->lateCount = frameLateCounter;
+
+	stats->frameTimeAbs.tgt = desired_frametime;
+	stats->frameTimeAbs.cur = frameDeltaCur;
+	stats->frameTimeAbs.min = frameDeltaMin;
+	stats->frameTimeAbs.max = frameDeltaMax;
+
+	stats->frameTimeDel.tgt = 0.0;
+	stats->frameTimeDel.cur = frameDeltaCur - desired_frametime;
+	stats->frameTimeDel.min = frameDeltaMin - desired_frametime;
+	stats->frameTimeDel.max = frameDeltaMax - desired_frametime;
+
+	stats->frameTimeIdle.tgt = desired_frametime * 0.50;
+	stats->frameTimeIdle.cur = frameIdleCur;
+	stats->frameTimeIdle.min = frameIdleMin;
+	stats->frameTimeIdle.max = frameIdleMax;
+
+	stats->frameTimeWork.tgt = desired_frametime - stats->frameTimeIdle.tgt;
+	stats->frameTimeWork.cur = desired_frametime - frameIdleCur;
+	stats->frameTimeWork.min = desired_frametime - frameIdleMax;
+	stats->frameTimeWork.max = desired_frametime - frameIdleMin;
+
+	if ( stats->frameTimeWork.cur < 0 )
+	{
+		stats->frameTimeWork.cur = 0;
+	}
+	if ( stats->frameTimeWork.min < 0 )
+	{
+		stats->frameTimeWork.min = 0;
+	}
+	if ( stats->frameTimeWork.max < 0 )
+	{
+		stats->frameTimeWork.max = 0;
+	}
+
+	return 0;
+}
+
+void resetFrameTiming(void)
+{
+	frameLateCounter = 0;
+	frameDeltaMax = 0.0;
+	frameDeltaMin = 1.0;
+	frameIdleMax = 0.0;
+	frameIdleMin = 1.0;
+}
+
 /* LOGMUL = exp(log(2) / 3)
  *
  * This gives us a value such that if we do x*=LOGMUL three times,
@@ -177,23 +236,24 @@ SpeedThrottle(void)
 		return 0; /* Done waiting */
 	}
 	double time_left;
-	double cur_time;
+	double cur_time, idleStart;
 	double frame_time = desired_frametime;
+	double halfFrame = 0.500 * frame_time;
 	double quarterFrame = 0.250 * frame_time;
     
-	cur_time  = getHighPrecTimeStamp();
+	idleStart = cur_time = getHighPrecTimeStamp();
 
 	if (Lasttime < 1.0)
 	{
 		Lasttime = cur_time;
-		Latetime = Lasttime + frame_time;
+		Latetime = Lasttime + 2.0*frame_time;
 	}
     
 	if (!InFrame)
 	{
 		InFrame = 1;
 		Nexttime = Lasttime + frame_time;
-		Latetime = Nexttime + frame_time;
+		Latetime = Nexttime + halfFrame;
 	}
     
 	if (cur_time >= Nexttime)
@@ -266,30 +326,40 @@ SpeedThrottle(void)
 	{
 		if ( keepFrameTimeStats )
 		{
-			double frameDelta;
 
-			frameDelta = (cur_time - Lasttime);
+			frameDeltaCur = (cur_time - Lasttime);
 
-			if ( frameDelta < frameDeltaMin )
+			if ( frameDeltaCur < frameDeltaMin )
 			{
-				frameDeltaMin = frameDelta;
+				frameDeltaMin = frameDeltaCur;
 			}
-			if ( frameDelta > frameDeltaMax )
+			if ( frameDeltaCur > frameDeltaMax )
 			{
-				frameDeltaMax = frameDelta;
+				frameDeltaMax = frameDeltaCur;
+			}
+
+			frameIdleCur = (cur_time - idleStart);
+
+			if ( frameIdleCur < frameIdleMin )
+			{
+				frameIdleMin = frameIdleCur;
+			}
+			if ( frameIdleCur > frameIdleMax )
+			{
+				frameIdleMax = frameIdleCur;
 			}
 			//printf("Frame Delta: %f us   min:%f   max:%f \n", frameDelta * 1e6, frameDeltaMin * 1e6, frameDeltaMax * 1e6 );
 			//printf("Frame Sleep Time: %f   Target Error: %f us\n", time_left * 1e6, (cur_time - Nexttime) * 1e6 );
 		}
 		Lasttime = Nexttime;
 		Nexttime = Lasttime + frame_time;
-		Latetime = Nexttime + frame_time;
+		Latetime = Nexttime + halfFrame;
 
 		if ( cur_time >= Nexttime )
 		{
 			Lasttime = cur_time;
 			Nexttime = Lasttime + frame_time;
-			Latetime = Nexttime + frame_time;
+			Latetime = Nexttime + halfFrame;
 		}
 		return 0; /* Done waiting */
 	}

src/drivers/Qt/throttle.h

@@ -3,3 +3,44 @@ int SpeedThrottle(void);
 void RefreshThrottleFPS(void);
 int getTimingMode(void);
 int setTimingMode(int mode);
+
+
+struct frameTimingStat_t
+{
+
+	struct {
+		double tgt;
+		double cur;
+		double min;
+		double max;
+	} frameTimeAbs;
+
+	struct {
+		double tgt;
+		double cur;
+		double min;
+		double max;
+	} frameTimeDel;
+
+	struct {
+		double tgt;
+		double cur;
+		double min;
+		double max;
+	} frameTimeWork;
+
+	struct {
+		double tgt;
+		double cur;
+		double min;
+		double max;
+	} frameTimeIdle;
+
+	unsigned int lateCount;
+
+	bool enabled;
+};
+
+void resetFrameTiming(void);
+void setFrameTimingEnable( bool enable );
+int  getFrameTimingStats( struct frameTimingStat_t *stats );