1 /** 2 Trace Event Format profiling. 3 4 Copyright: Guillaume Piolat 2022. 5 License: $(LINK2 http://www.boost.org/LICENSE_1_0.txt, Boost License 1.0) 6 * Authors: Guillaume Piolat 7 */ 8 module dplug.gui.profiler; 9 10 11 // TODO: clock should be monotonic per-thread 12 13 import core.stdc.stdio; 14 15 import dplug.core.math; 16 import dplug.core.sync; 17 import dplug.core.thread; 18 import dplug.core.string; 19 import dplug.core.nogc; 20 import dplug.core.vec; 21 22 version(Windows) 23 { 24 import core.sys.windows.windows; 25 } 26 27 nothrow @nogc: 28 29 /// Allows to generate a Trace Event Format profile JSON. 30 interface IProfiler 31 { 32 nothrow @nogc: 33 /// All functions for this interface can be called from many threads at once. 34 /// However, from the same thread, there is an ordering. 35 /// - `begin/end` pairs must be balanced, per-thread 36 /// - `begin/end` pairs can be nested, per-thread 37 /// - `category` must come outside of a `begin`/`end` pair 38 39 /// Set current category for pending begin and instant events, for the current thread. 40 /// categoryZ must be a zero-terminated slice (zero not counted in length). 41 /// This is thread-safe and can be called from multiple threads. 42 /// Returns: itself. 43 IProfiler category(const(char)[] categoryZ); 44 45 /// Add an instant event to the trace. 46 /// This is thread-safe and can be called from multiple threads. 47 /// Returns: itself. 48 IProfiler instant(const(char)[] categoryZ); 49 50 /// This Begin/End Event will be added to the queue. 51 /// Events can be added from whatever thread. But within the same threads, the begin/end events 52 /// are nested and must be balanced. 53 /// nameZ must be be a zero-terminated slice (zero not counted in length). 54 /// Returns: itself. 55 IProfiler begin(const(char)[] nameZ); 56 ///ditto 57 IProfiler end(); 58 59 /// Return a borrowed array of bytes for saving. 60 /// Lifetime is tied to lifetime of the interface object. 61 /// After `toBytes` is called, no recording function above can be called. 62 const(ubyte)[] toBytes(); 63 } 64 65 /// Create an `IProfiler`. 66 IProfiler createProfiler() 67 { 68 version(Dplug_ProfileUI) 69 { 70 return mallocNew!TraceProfiler(); 71 } 72 else 73 { 74 return mallocNew!NullProfiler(); 75 } 76 } 77 78 /// Destroy an `IProfiler` created with `createTraceProfiler`. 79 void destroyProfiler(IProfiler profiler) 80 { 81 destroyFree(profiler); 82 } 83 84 85 class NullProfiler : IProfiler 86 { 87 override IProfiler category(const(char)[] categoryZ) 88 { 89 return this; 90 } 91 92 override IProfiler instant(const(char)[] categoryZ) 93 { 94 return this; 95 } 96 97 override IProfiler begin(const(char)[] nameZ) 98 { 99 return this; 100 } 101 102 override IProfiler end() 103 { 104 return this; 105 } 106 107 override const(ubyte)[] toBytes() 108 { 109 return []; 110 } 111 } 112 113 114 version(Dplug_ProfileUI): 115 116 117 /// Allows to generate a Trace Event Format profile JSON. 118 class TraceProfiler : IProfiler 119 { 120 public: 121 nothrow: 122 @nogc: 123 124 this() 125 { 126 _clock.initialize(); 127 _mutex = makeMutex; 128 } 129 130 override IProfiler category(const(char)[] categoryZ) 131 { 132 ensureThreadContext(); 133 threadInfo.lastCategoryZ = categoryZ; 134 return this; 135 } 136 137 override IProfiler instant(const(char)[] nameZ) 138 { 139 ensureThreadContext(); 140 long us = _clock.getTickUs(); 141 addEvent(nameZ, threadInfo.lastCategoryZ, "i", us); 142 return this; 143 } 144 145 override IProfiler begin(const(char)[] nameZ) 146 { 147 ensureThreadContext(); 148 long us = _clock.getTickUs(); 149 addEvent(nameZ, threadInfo.lastCategoryZ, "B", us); 150 return this; 151 } 152 153 override IProfiler end() 154 { 155 // no ensureThreadContext, since by API can't begin with .end 156 long us = _clock.getTickUs(); 157 addEventNoname("E", us); 158 return this; 159 } 160 161 override const(ubyte)[] toBytes() 162 { 163 finalize(); 164 return cast(const(ubyte)[])_concatenated.asSlice(); 165 } 166 167 private: 168 169 bool _finalized = false; 170 Clock _clock; 171 static ThreadContext threadInfo; // this is TLS 172 173 Vec!(String*) _allBuffers; // list of all thread-local buffers, this access is checked 174 175 String _concatenated; 176 177 UncheckedMutex _mutex; // in below mutex. 178 179 void finalize() 180 { 181 if (_finalized) 182 return; 183 184 _concatenated.makeEmpty(); 185 _concatenated ~= "["; 186 _mutex.lock(); 187 188 foreach(ref bufptr; _allBuffers[]) 189 _concatenated ~= *bufptr; 190 191 _mutex.unlock(); 192 193 _concatenated ~= "]"; 194 _finalized = true; 195 } 196 197 void addEvent(const(char)[] nameZ, 198 const(char)[] categoryZ, 199 const(char)[] typeZ, 200 long us) 201 { 202 if (!threadInfo.firstEventForThisThread) 203 { 204 threadInfo.buffer ~= ",\n"; 205 } 206 threadInfo.firstEventForThisThread = false; 207 208 char[256] buf; 209 size_t tid = getCurrentThreadId(); 210 snprintf(buf.ptr, 256, `{ "name": "%s", "cat": "%s", "ph": "%s", "pid": 0, "tid": %zu, "ts": %lld }`, 211 nameZ.ptr, categoryZ.ptr, typeZ.ptr, tid, us); 212 threadInfo.buffer.appendZeroTerminatedString(buf.ptr); 213 } 214 215 void addEventNoname(const(char)[] typeZ, long us) 216 { 217 if (!threadInfo.firstEventForThisThread) 218 { 219 threadInfo.buffer ~= ",\n"; 220 } 221 threadInfo.firstEventForThisThread = false; 222 char[256] buf; 223 size_t tid = getCurrentThreadId(); 224 snprintf(buf.ptr, 256, `{ "ph": "%s", "pid": 0, "tid": %zu, "ts": %lld }`, 225 typeZ.ptr, tid, us); 226 threadInfo.buffer.appendZeroTerminatedString(buf.ptr); 227 } 228 229 // All thread-local requirements for the profiling to be thread-local. 230 static struct ThreadContext 231 { 232 bool threadWasSeenAlready = false; 233 Vec!long timeStack; // stack of "begin" time values 234 String buffer; // thread-local buffer 235 const(char)[] lastCategoryZ; 236 bool firstEventForThisThread = true; 237 } 238 239 void ensureThreadContext() 240 { 241 // have we seen this thread yet? If not, initialize thread locals 242 if (!threadInfo.threadWasSeenAlready) 243 { 244 threadInfo.threadWasSeenAlready = true; 245 threadInfo.lastCategoryZ = "none"; 246 threadInfo.buffer.makeEmpty; 247 threadInfo.firstEventForThisThread = true; 248 249 // register buffer 250 _mutex.lock(); 251 _allBuffers.pushBack(&threadInfo.buffer); 252 _mutex.unlock(); 253 } 254 } 255 } 256 257 258 private: 259 260 struct Clock 261 { 262 nothrow @nogc: 263 264 void initialize() 265 { 266 version(Windows) 267 { 268 QueryPerformanceFrequency(&_qpcFrequency); 269 } 270 } 271 272 /// Get us timestamp. 273 /// Must be thread-safe. 274 // It doesn't handle wrap-around superbly. 275 long getTickUs() nothrow @nogc 276 { 277 version(Windows) 278 { 279 import core.sys.windows.windows; 280 LARGE_INTEGER lint; 281 QueryPerformanceCounter(&lint); 282 double seconds = lint.QuadPart / cast(double)(_qpcFrequency.QuadPart); 283 long us = cast(long)(seconds * 1_000_000); 284 return us; 285 } 286 else 287 { 288 import core.time; 289 return convClockFreq(MonoTime.currTime.ticks, MonoTime.ticksPerSecond, 1_000_000); 290 } 291 } 292 293 private: 294 version(Windows) 295 { 296 LARGE_INTEGER _qpcFrequency; 297 } 298 } 299 300 version(Dplug_profileUI) 301 { 302 pragma(msg, "You probably meant Dplug_ProfileUI, not Dplug_profileUI. Correct your dub.json"); 303 }