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