Merge pull request #3807 from ZappoMan/flightTimeDebugging

Flight time debugging
This commit is contained in:
AndrewMeadows 2014-11-17 10:59:46 -08:00
commit e2218de71b
7 changed files with 64 additions and 10 deletions

View file

@ -1017,6 +1017,9 @@ void OctreeServer::readConfiguration() {
readOptionBool(QString("debugReceiving"), settingsSectionObject, _debugReceiving);
qDebug("debugReceiving=%s", debug::valueOf(_debugReceiving));
readOptionBool(QString("debugTimestampNow"), settingsSectionObject, _debugTimestampNow);
qDebug() << "debugTimestampNow=" << _debugTimestampNow;
bool noPersist;
readOptionBool(QString("NoPersist"), settingsSectionObject, noPersist);
_wantPersist = !noPersist;
@ -1133,7 +1136,7 @@ void OctreeServer::run() {
// now set up PersistThread
_persistThread = new OctreePersistThread(_tree, _persistFilename, _persistInterval,
_wantBackup, _backupInterval, _backupExtensionFormat);
_wantBackup, _backupInterval, _backupExtensionFormat, _debugTimestampNow);
if (_persistThread) {
_persistThread->initialize(true);
}

View file

@ -162,6 +162,7 @@ protected:
bool _wantPersist;
bool _debugSending;
bool _debugReceiving;
bool _debugTimestampNow;
bool _verboseDebug;
JurisdictionMap* _jurisdiction;
JurisdictionSender* _jurisdictionSender;

View file

@ -359,6 +359,13 @@
"default": false,
"advanced": true
},
{
"name": "debugTimestampNow",
"type": "checkbox",
"help": "extra debugging for usecTimestampNow() function",
"default": false,
"advanced": true
},
{
"name": "clockSkew",
"label": "Clock Skew",

View file

@ -22,8 +22,8 @@ const int OctreePersistThread::DEFAULT_BACKUP_INTERVAL = 1000 * 60 * 30; // ever
const QString OctreePersistThread::DEFAULT_BACKUP_EXTENSION_FORMAT(".backup.%Y-%m-%d.%H:%M:%S.%z");
OctreePersistThread::OctreePersistThread(Octree* tree, const QString& filename, int persistInterval,
bool wantBackup, int backupInterval, const QString& backupExtensionFormat) :
OctreePersistThread::OctreePersistThread(Octree* tree, const QString& filename, int persistInterval, bool wantBackup,
int backupInterval, const QString& backupExtensionFormat, bool debugTimestampNow) :
_tree(tree),
_filename(filename),
_backupExtensionFormat(backupExtensionFormat),
@ -33,7 +33,9 @@ OctreePersistThread::OctreePersistThread(Octree* tree, const QString& filename,
_loadTimeUSecs(0),
_lastCheck(0),
_lastBackup(0),
_wantBackup(wantBackup)
_wantBackup(wantBackup),
_debugTimestampNow(debugTimestampNow),
_lastTimeDebug(0)
{
}
@ -101,6 +103,18 @@ bool OctreePersistThread::process() {
persist();
}
}
// if we were asked to debugTimestampNow do that now...
if (_debugTimestampNow) {
quint64 now = usecTimestampNow();
quint64 sinceLastDebug = now - _lastTimeDebug;
quint64 DEBUG_TIMESTAMP_INTERVAL = 600000000; // every 10 minutes
if (sinceLastDebug > DEBUG_TIMESTAMP_INTERVAL) {
_lastTimeDebug = usecTimestampNow(true); // ask for debug output
}
}
return isStillRunning(); // keep running till they terminate us
}

View file

@ -28,7 +28,8 @@ public:
OctreePersistThread(Octree* tree, const QString& filename, int persistInterval = DEFAULT_PERSIST_INTERVAL,
bool wantBackup = false, int backupInterval = DEFAULT_BACKUP_INTERVAL,
const QString& backupExtensionFormat = DEFAULT_BACKUP_EXTENSION_FORMAT);
const QString& backupExtensionFormat = DEFAULT_BACKUP_EXTENSION_FORMAT,
bool debugTimestampNow = false);
bool isInitialLoadComplete() const { return _initialLoadComplete; }
quint64 getLoadElapsedTime() const { return _loadTimeUSecs; }
@ -57,6 +58,9 @@ private:
quint64 _lastBackup;
bool _wantBackup;
time_t _lastPersistTime;
bool _debugTimestampNow;
quint64 _lastTimeDebug;
};
#endif // hifi_OctreePersistThread_h

View file

@ -37,7 +37,7 @@ void usecTimestampNowForceClockSkew(int clockSkew) {
::usecTimestampNowAdjust = clockSkew;
}
quint64 usecTimestampNow() {
quint64 usecTimestampNow(bool wantDebug) {
static bool usecTimestampNowIsInitialized = false;
static qint64 TIME_REFERENCE = 0; // in usec
static QElapsedTimer timestampTimer;
@ -57,7 +57,6 @@ quint64 usecTimestampNow() {
quint64 msecsElapsed = timestampTimer.restart();
quint64 usecsElapsed = nsecsElapsed / 1000; // nsec to usec
TIME_REFERENCE += usecsElapsed;
const bool wantDebug = false;
if (wantDebug) {
qDebug() << "usecTimestampNow() - resetting QElapsedTimer. ";
qDebug() << " RESET_AFTER_ELAPSED_NSECS:" << RESET_AFTER_ELAPSED_NSECS;
@ -68,8 +67,34 @@ quint64 usecTimestampNow() {
}
}
// usec nsec to usec usec
return TIME_REFERENCE + timestampTimer.nsecsElapsed() / 1000 + ::usecTimestampNowAdjust;
quint64 nsecsElapsed = timestampTimer.nsecsElapsed();
quint64 usecsElapsed = nsecsElapsed / 1000; // nsec to usec
quint64 now = TIME_REFERENCE + usecsElapsed + ::usecTimestampNowAdjust;
if (wantDebug) {
QDateTime currentLocalTime = QDateTime::currentDateTime();
quint64 msecsNow = now / 1000; // usecs to msecs
QDateTime nowAsString;
nowAsString.setMSecsSinceEpoch(msecsNow);
quint64 msecsTimeReference = TIME_REFERENCE / 1000; // usecs to msecs
QDateTime timeReferenceAsString;
timeReferenceAsString.setMSecsSinceEpoch(msecsTimeReference);
qDebug() << "usecTimestampNow() - details... ";
qDebug() << " TIME_REFERENCE:" << TIME_REFERENCE;
qDebug() << " timeReferenceAsString:" << timeReferenceAsString.toString("yyyy-MM-dd hh:mm:ss.zzz");
qDebug() << " usecTimestampNowAdjust:" << usecTimestampNowAdjust;
qDebug() << " nsecsElapsed:" << nsecsElapsed;
qDebug() << " usecsElapsed:" << usecsElapsed;
qDebug() << " now:" << now;
qDebug() << " msecsNow:" << msecsNow;
qDebug() << " nowAsString:" << nowAsString.toString("yyyy-MM-dd hh:mm:ss.zzz");
qDebug() << " currentLocalTime:" << currentLocalTime.toString("yyyy-MM-dd hh:mm:ss.zzz");
}
return now;
}
float randFloat() {

View file

@ -67,7 +67,7 @@ static const quint64 USECS_PER_SECOND = USECS_PER_MSEC * MSECS_PER_SECOND;
const int BITS_IN_BYTE = 8;
quint64 usecTimestampNow();
quint64 usecTimestampNow(bool wantDebug = false);
void usecTimestampNowForceClockSkew(int clockSkew);
float randFloat();