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 }