Skip to content

Commit

Permalink
Add timing code from 3.1
Browse files Browse the repository at this point in the history
  • Loading branch information
George Nachman committed Nov 11, 2016
1 parent 596bb60 commit b04601f
Show file tree
Hide file tree
Showing 4 changed files with 270 additions and 25 deletions.
8 changes: 8 additions & 0 deletions iTerm2.xcodeproj/project.pbxproj
Original file line number Diff line number Diff line change
Expand Up @@ -1212,6 +1212,8 @@
5346902C1C94FF1900B7E4E9 /* overflowImage@2x.png in Resources */ = {isa = PBXBuildFile; fileRef = 5346902B1C94FF1900B7E4E9 /* overflowImage@2x.png */; };
5370F2EA1C7895F800874C0F /* QLPreviewPanel+iTerm.m in Sources */ = {isa = PBXBuildFile; fileRef = 5370F2E71C78958900874C0F /* QLPreviewPanel+iTerm.m */; };
5370F2EB1C7895FD00874C0F /* QLPreviewPanel+iTerm.h in Headers */ = {isa = PBXBuildFile; fileRef = 5370F2E61C78958900874C0F /* QLPreviewPanel+iTerm.h */; };
539325F21DD66EFA00CABCEF /* iTermPreciseTimer.h in Headers */ = {isa = PBXBuildFile; fileRef = 539325EE1DD66EF100CABCEF /* iTermPreciseTimer.h */; };
539325F31DD66EFA00CABCEF /* iTermPreciseTimer.m in Sources */ = {isa = PBXBuildFile; fileRef = 539325EF1DD66EF100CABCEF /* iTermPreciseTimer.m */; };
5ECE005F1454E59B004861E9 /* PseudoTerminalRestorer.h in Headers */ = {isa = PBXBuildFile; fileRef = 5ECE005D1454E59B004861E9 /* PseudoTerminalRestorer.h */; };
5ECE4AE814513F05002A9CC2 /* Growl.framework in CopyFiles */ = {isa = PBXBuildFile; fileRef = 5ECE4AC41451343E002A9CC2 /* Growl.framework */; settings = {ATTRIBUTES = (CodeSignOnCopy, ); }; };
5ECE4AEA14514058002A9CC2 /* Growl Registration Ticket.growlRegDict in Resources */ = {isa = PBXBuildFile; fileRef = 5ECE4AE914514058002A9CC2 /* Growl Registration Ticket.growlRegDict */; };
Expand Down Expand Up @@ -2780,6 +2782,8 @@
5346902B1C94FF1900B7E4E9 /* overflowImage@2x.png */ = {isa = PBXFileReference; lastKnownFileType = image.png; path = "overflowImage@2x.png"; sourceTree = "<group>"; };
5370F2E61C78958900874C0F /* QLPreviewPanel+iTerm.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = "QLPreviewPanel+iTerm.h"; sourceTree = "<group>"; };
5370F2E71C78958900874C0F /* QLPreviewPanel+iTerm.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = "QLPreviewPanel+iTerm.m"; sourceTree = "<group>"; };
539325EE1DD66EF100CABCEF /* iTermPreciseTimer.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = iTermPreciseTimer.h; sourceTree = "<group>"; };
539325EF1DD66EF100CABCEF /* iTermPreciseTimer.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = iTermPreciseTimer.m; sourceTree = "<group>"; };
5BC84AA2F3A178CCEF36EB64 /* Pods-iTerm2XCTests.nightly.xcconfig */ = {isa = PBXFileReference; includeInIndex = 1; lastKnownFileType = text.xcconfig; name = "Pods-iTerm2XCTests.nightly.xcconfig"; path = "Pods/Target Support Files/Pods-iTerm2XCTests/Pods-iTerm2XCTests.nightly.xcconfig"; sourceTree = "<group>"; };
5ECE005D1454E59B004861E9 /* PseudoTerminalRestorer.h */ = {isa = PBXFileReference; fileEncoding = 4; indentWidth = 4; lastKnownFileType = sourcecode.c.h; path = PseudoTerminalRestorer.h; sourceTree = "<group>"; tabWidth = 4; };
5ECE005E1454E59B004861E9 /* PseudoTerminalRestorer.m */ = {isa = PBXFileReference; fileEncoding = 4; indentWidth = 4; lastKnownFileType = sourcecode.c.objc; path = PseudoTerminalRestorer.m; sourceTree = "<group>"; tabWidth = 4; };
Expand Down Expand Up @@ -5071,6 +5075,8 @@
A68A30C9186D101C007F550F /* Helpers */ = {
isa = PBXGroup;
children = (
539325EE1DD66EF100CABCEF /* iTermPreciseTimer.h */,
539325EF1DD66EF100CABCEF /* iTermPreciseTimer.m */,
A6CFDAD6185D53C2005DC94B /* AsyncHostLookupController.m */,
1DA26ABF15007507004B5792 /* BackgroundThread.m */,
A67F57D31B11882900B4F135 /* CapturedOutput.m */,
Expand Down Expand Up @@ -6136,6 +6142,7 @@
A62C3A891BCAE03300B5629D /* iTermDirectoryTreeNode.h in Headers */,
1D027C111CD1867000B0FBFF /* iTermColorPresets.h in Headers */,
A66BFADC1CD072DB00DA2346 /* iTermThroughputEstimator.h in Headers */,
539325F21DD66EFA00CABCEF /* iTermPreciseTimer.h in Headers */,
A62C3A8D1BCAE08300B5629D /* iTermDirectoryTree.h in Headers */,
A66DB8361C8E4CBB00233E88 /* iTermOpenQuicklyCommands.h in Headers */,
A6FC49861C3A31840061B3BA /* iTermSystemVersion.h in Headers */,
Expand Down Expand Up @@ -7523,6 +7530,7 @@
A6C7639B1B45C52B00E3C992 /* TmuxHistoryParser.m in Sources */,
A6C763761B45C52B00E3C992 /* PointerPreferencesViewController.m in Sources */,
A6C762BD1B45C52B00E3C992 /* NSPasteboard+iTerm.m in Sources */,
539325F31DD66EFA00CABCEF /* iTermPreciseTimer.m in Sources */,
A6C762EC1B45C52B00E3C992 /* EquivalenceClassSet.m in Sources */,
A6C762E21B45C52B00E3C992 /* ScreenChar.m in Sources */,
A6C763EA1B45C71900E3C992 /* UKNibOwner.m in Sources */,
Expand Down
71 changes: 71 additions & 0 deletions sources/iTermPreciseTimer.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,71 @@
//
// iTermPreciseTimer.h
// iTerm2
//
// Created by George Nachman on 7/13/16.
//
//

#import <Foundation/Foundation.h>

typedef struct {
uint64_t start;
NSTimeInterval total;
NSInteger eventCount;
} iTermPreciseTimer;

typedef struct {
char name[20];
iTermPreciseTimer timer;
NSInteger n;
NSInteger totalEventCount;
double mean;
double m2;
} iTermPreciseTimerStats;

#define ENABLE_PRECISE_TIMERS 0

#if ENABLE_PRECISE_TIMERS
void iTermPreciseTimerStart(iTermPreciseTimer *timer);
NSTimeInterval iTermPreciseTimerAccumulate(iTermPreciseTimer *timer, NSTimeInterval value);
NSTimeInterval iTermPreciseTimerMeasureAndAccumulate(iTermPreciseTimer *timer);
void iTermPreciseTimerReset(iTermPreciseTimer *timer);
NSTimeInterval iTermPreciseTimerMeasure(iTermPreciseTimer *timer);

void iTermPreciseTimerStatsInit(iTermPreciseTimerStats *stats, char *name);
void iTermPreciseTimerStatsStartTimer(iTermPreciseTimerStats *stats);
void iTermPreciseTimerStatsMeasureAndRecordTimer(iTermPreciseTimerStats *stats);
void iTermPreciseTimerStatsRecordTimer(iTermPreciseTimerStats *stats);

void iTermPreciseTimerStatsMeasureAndAccumulate(iTermPreciseTimerStats *stats);
void iTermPreciseTimerStatsAccumulate(iTermPreciseTimerStats *stats, NSTimeInterval value);
void iTermPreciseTimerStatsRecord(iTermPreciseTimerStats *stats, NSTimeInterval value, int eventCount);
NSInteger iTermPreciseTimerStatsGetCount(iTermPreciseTimerStats *stats);
NSTimeInterval iTermPreciseTimerStatsGetMean(iTermPreciseTimerStats *stats);
NSTimeInterval iTermPreciseTimerStatsGetStddev(iTermPreciseTimerStats *stats);

void iTermPreciseTimerPeriodicLog(iTermPreciseTimerStats stats[],
size_t count,
NSTimeInterval interval);
#else
static inline void iTermPreciseTimerStart(iTermPreciseTimer *timer) { }
static inline NSTimeInterval iTermPreciseTimerAccumulate(iTermPreciseTimer *timer) { return 0; }
static inline NSTimeInterval iTermPreciseTimerMeasureAndAccumulate(iTermPreciseTimer *timer) { return 0; }
static inline void iTermPreciseTimerReset(iTermPreciseTimer *timer) { }
static inline NSTimeInterval iTermPreciseTimerMeasure(iTermPreciseTimer *timer) { return 0; }

static inline void iTermPreciseTimerStatsInit(iTermPreciseTimerStats *stats, char *name) { }
static inline void iTermPreciseTimerStatsStartTimer(iTermPreciseTimerStats *stats) { }
static inline void iTermPreciseTimerStatsMeasureAndRecordTimer(iTermPreciseTimerStats *stats) { }
static inline void iTermPreciseTimerStatsRecordTimer(iTermPreciseTimerStats *stats) { }

static inline void iTermPreciseTimerStatsAccumulate(iTermPreciseTimerStats *stats) { }
static inline void iTermPreciseTimerStatsRecord(iTermPreciseTimerStats *stats, NSTimeInterval value, int eventCount) { }
static inline NSInteger iTermPreciseTimerStatsGetCount(iTermPreciseTimerStats *stats) { return 0; }
static inline NSTimeInterval iTermPreciseTimerStatsGetMean(iTermPreciseTimerStats *stats) { return 0; }
static inline NSTimeInterval iTermPreciseTimerStatsGetStddev(iTermPreciseTimerStats *stats) { return 0; }

static inline void iTermPreciseTimerPeriodicLog(iTermPreciseTimerStats stats[],
size_t count,
NSTimeInterval interval) { }
#endif
145 changes: 145 additions & 0 deletions sources/iTermPreciseTimer.m
Original file line number Diff line number Diff line change
@@ -0,0 +1,145 @@
//
// iTermPreciseTimer.m
// iTerm2
//
// Created by George Nachman on 7/13/16.
//
//

#import "iTermPreciseTimer.h"

#include <assert.h>
#include <CoreServices/CoreServices.h>
#include <mach/mach.h>
#include <mach/mach_time.h>
#include <unistd.h>

#if ENABLE_PRECISE_TIMERS
void iTermPreciseTimerStart(iTermPreciseTimer *timer) {
timer->start = mach_absolute_time();
}

NSTimeInterval iTermPreciseTimerMeasureAndAccumulate(iTermPreciseTimer *timer) {
timer->total += iTermPreciseTimerMeasure(timer);
timer->eventCount += 1;
return timer->total;
}

NSTimeInterval iTermPreciseTimerAccumulate(iTermPreciseTimer *timer, NSTimeInterval value) {
return timer->total;
}

void iTermPreciseTimerReset(iTermPreciseTimer *timer) {
timer->total = 0;
timer->eventCount = 0;
}

NSTimeInterval iTermPreciseTimerMeasure(iTermPreciseTimer *timer) {
uint64_t end;
NSTimeInterval elapsed;

end = mach_absolute_time();
elapsed = end - timer->start;

static mach_timebase_info_data_t sTimebaseInfo;
if (sTimebaseInfo.denom == 0) {
mach_timebase_info(&sTimebaseInfo);
}

double nanoseconds = elapsed * sTimebaseInfo.numer / sTimebaseInfo.denom;
return nanoseconds / 1000000000.0;
}

void iTermPreciseTimerStatsInit(iTermPreciseTimerStats *stats, char *name) {
stats->n = 0;
stats->totalEventCount = 0;
stats->mean = 0;
stats->m2 = 0;
iTermPreciseTimerReset(&stats->timer);
if (name) {
strlcpy(stats->name, name, sizeof(stats->name));
}
}

NSInteger iTermPreciseTimerStatsGetCount(iTermPreciseTimerStats *stats) {
return stats->n;
}

void iTermPreciseTimerStatsStartTimer(iTermPreciseTimerStats *stats) {
iTermPreciseTimerStart(&stats->timer);
}

void iTermPreciseTimerStatsMeasureAndRecordTimer(iTermPreciseTimerStats *stats) {
if (stats->timer.start) {
NSTimeInterval total = iTermPreciseTimerMeasureAndAccumulate(&stats->timer);
int eventCount = stats->timer.eventCount;
iTermPreciseTimerStatsRecord(stats, total, eventCount);
iTermPreciseTimerReset(&stats->timer);
}
}

void iTermPreciseTimerStatsRecordTimer(iTermPreciseTimerStats *stats) {
iTermPreciseTimerStatsRecord(stats, stats->timer.total, stats->timer.eventCount);
iTermPreciseTimerReset(&stats->timer);
}

void iTermPreciseTimerStatsMeasureAndAccumulate(iTermPreciseTimerStats *stats) {
iTermPreciseTimerMeasureAndAccumulate(&stats->timer);
}

void iTermPreciseTimerStatsAccumulate(iTermPreciseTimerStats *stats, NSTimeInterval value) {
iTermPreciseTimerAccumulate(&stats->timer, value);
}

void iTermPreciseTimerStatsRecord(iTermPreciseTimerStats *stats, NSTimeInterval value, int eventCount) {
stats->totalEventCount += eventCount;

// Welford's online variance algorithm, adopted from:
// https://en.wikipedia.org/wiki/Algorithms_for_calculating_variance#Higher-order_statistics
stats->n += 1;
double delta = value - stats->mean;
stats->mean += delta / stats->n;
stats->m2 += delta * (value - stats->mean);
}

NSTimeInterval iTermPreciseTimerStatsGetMean(iTermPreciseTimerStats *stats) {
return stats->mean;
}

NSTimeInterval iTermPreciseTimerStatsGetStddev(iTermPreciseTimerStats *stats) {
if (stats->n < 2) {
return NAN;
} else {
return sqrt(stats->m2 / (stats->n - 1));
}
}

void iTermPreciseTimerPeriodicLog(iTermPreciseTimerStats stats[],
size_t count,
NSTimeInterval interval) {
static iTermPreciseTimer gLastLog;
if (!gLastLog.start) {
iTermPreciseTimerStart(&gLastLog);
}

if (iTermPreciseTimerMeasure(&gLastLog) >= interval) {
NSLog(@"-- Precise Timers --");
for (size_t i = 0; i < count; i++) {
NSTimeInterval mean = iTermPreciseTimerStatsGetMean(&stats[i]) * 1000.0;
NSTimeInterval stddev = iTermPreciseTimerStatsGetStddev(&stats[i]) * 1000.0;
NSLog(@"%20s: µ=%0.3fms σ=%.03fms (95%% CI ≅ %0.3fms–%0.3fms) 𝚺=%.2fms N=%@ avg. events=%01.f",
stats[i].name,
mean,
stddev,
MAX(0, mean - stddev),
mean + stddev,
stats[i].n * mean,
@(stats[i].n),
(double)stats[i].totalEventCount / (double)stats[i].n);
iTermPreciseTimerStatsInit(&stats[i], NULL);
}
NSLog(@"");
iTermPreciseTimerStart(&gLastLog);
}
}
#endif
Loading

0 comments on commit b04601f

Please sign in to comment.