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 }