Skip to content
Snippets Groups Projects
Commit 2280bf95 authored by George Nachman's avatar George Nachman
Browse files

Log timing stats to debug logs always.

parent b0622c2f
No related branches found
No related tags found
No related merge requests found
Loading
Loading
@@ -46,7 +46,8 @@ NSTimeInterval iTermPreciseTimerStatsGetStddev(iTermPreciseTimerStats *stats);
 
void iTermPreciseTimerPeriodicLog(iTermPreciseTimerStats stats[],
size_t count,
NSTimeInterval interval);
NSTimeInterval interval,
BOOL logToConsole);
#else
static inline void iTermPreciseTimerStart(iTermPreciseTimer *timer) { }
static inline NSTimeInterval iTermPreciseTimerAccumulate(iTermPreciseTimer *timer) { return 0; }
Loading
Loading
@@ -68,5 +69,6 @@ static inline NSTimeInterval iTermPreciseTimerStatsGetStddev(iTermPreciseTimerSt
 
static inline void iTermPreciseTimerPeriodicLog(iTermPreciseTimerStats stats[],
size_t count,
NSTimeInterval interval) { }
NSTimeInterval interval,
BOOL logToConsole) { }
#endif
Loading
Loading
@@ -8,6 +8,7 @@
 
#import "iTermPreciseTimer.h"
 
#import "DebugLogging.h"
#include <assert.h>
#include <CoreServices/CoreServices.h>
#include <mach/mach.h>
Loading
Loading
@@ -116,29 +117,34 @@ NSTimeInterval iTermPreciseTimerStatsGetStddev(iTermPreciseTimerStats *stats) {
 
void iTermPreciseTimerPeriodicLog(iTermPreciseTimerStats stats[],
size_t count,
NSTimeInterval interval) {
NSTimeInterval interval,
BOOL logToConsole) {
static iTermPreciseTimer gLastLog;
if (!gLastLog.start) {
iTermPreciseTimerStart(&gLastLog);
}
 
if (iTermPreciseTimerMeasure(&gLastLog) >= interval) {
NSLog(@"-- Precise Timers --");
NSMutableString *log = [[@"-- Precise Timers --\n" mutableCopy] autorelease];
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);
[log appendFormat:@"%20s: µ=%0.3fms σ=%.03fms (95%% CI ≅ %0.3fms–%0.3fms) 𝚺=%.2fms N=%@ avg. events=%01.f\n",
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);
}
if (logToConsole) {
ELog(@"%@", log);
} else {
DLog(@"%@", log);
}
NSLog(@"");
iTermPreciseTimerStart(&gLastLog);
}
}
Loading
Loading
Loading
Loading
@@ -158,23 +158,21 @@ typedef struct iTermTextColorContext {
- (instancetype)init {
self = [super init];
if (self) {
if ([iTermAdvancedSettingsModel logDrawingPerformance]) {
NSLog(@"** Drawing performance timing enabled **");
iTermPreciseTimerStatsInit(&_stats[TIMER_TOTAL_DRAW_RECT], "Total drawRect");
iTermPreciseTimerStatsInit(&_stats[TIMER_CONSTRUCT_BACKGROUND_RUNS], "Construct BG runs");
iTermPreciseTimerStatsInit(&_stats[TIMER_DRAW_BACKGROUND], "Draw BG");
iTermPreciseTimerStatsInit(&_stats[TIMER_STAT_CONSTRUCTION], "Construction");
iTermPreciseTimerStatsInit(&_stats[TIMER_STAT_BUILD_MUTABLE_ATTRIBUTED_STRING], "Build attr strings");
iTermPreciseTimerStatsInit(&_stats[TIMER_STAT_DRAW], "Drawing");
iTermPreciseTimerStatsInit(&_stats[TIMER_ATTRS_FOR_CHAR], "Compute Attrs");
iTermPreciseTimerStatsInit(&_stats[TIMER_SHOULD_SEGMENT], "Segment");
iTermPreciseTimerStatsInit(&_stats[TIMER_UPDATE_BUILDER], "Update Builder");
iTermPreciseTimerStatsInit(&_stats[TIMER_COMBINE_ATTRIBUTES], "Combine Attrs");
iTermPreciseTimerStatsInit(&_stats[TIMER_ADVANCES], "Advances");
iTermPreciseTimerStatsInit(&_stats[TIMER_BETWEEN_CALLS_TO_DRAW_RECT], "Between calls");
}
iTermPreciseTimerStatsInit(&_stats[TIMER_TOTAL_DRAW_RECT], "Total drawRect");
iTermPreciseTimerStatsInit(&_stats[TIMER_CONSTRUCT_BACKGROUND_RUNS], "Construct BG runs");
iTermPreciseTimerStatsInit(&_stats[TIMER_DRAW_BACKGROUND], "Draw BG");
iTermPreciseTimerStatsInit(&_stats[TIMER_STAT_CONSTRUCTION], "Construction");
iTermPreciseTimerStatsInit(&_stats[TIMER_STAT_BUILD_MUTABLE_ATTRIBUTED_STRING], "Build attr strings");
iTermPreciseTimerStatsInit(&_stats[TIMER_STAT_DRAW], "Drawing");
iTermPreciseTimerStatsInit(&_stats[TIMER_ATTRS_FOR_CHAR], "Compute Attrs");
iTermPreciseTimerStatsInit(&_stats[TIMER_SHOULD_SEGMENT], "Segment");
iTermPreciseTimerStatsInit(&_stats[TIMER_UPDATE_BUILDER], "Update Builder");
iTermPreciseTimerStatsInit(&_stats[TIMER_COMBINE_ATTRIBUTES], "Combine Attrs");
iTermPreciseTimerStatsInit(&_stats[TIMER_ADVANCES], "Advances");
iTermPreciseTimerStatsInit(&_stats[TIMER_BETWEEN_CALLS_TO_DRAW_RECT], "Between calls");
_missingImages = [[NSMutableSet alloc] init];
_lineRefCache = [[NSMutableDictionary alloc] init];
_replacementLineRefCache = [[NSMutableDictionary alloc] init];
Loading
Loading
@@ -263,10 +261,7 @@ typedef struct iTermTextColorContext {
 
[self stopTiming];
 
if ([iTermAdvancedSettingsModel logDrawingPerformance]) {
iTermPreciseTimerPeriodicLog(_stats, sizeof(_stats) / sizeof(*_stats), 5);
}
iTermPreciseTimerPeriodicLog(_stats, sizeof(_stats) / sizeof(*_stats), 5, [iTermAdvancedSettingsModel logDrawingPerformance]);
 
if (_debug) {
NSColor *c = [NSColor colorWithCalibratedRed:(rand() % 255) / 255.0
Loading
Loading
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment