1 /*
2 Copyright (C) 2008 Grame & RTL
3 
4 This program is free software; you can redistribute it and/or modify
5 it under the terms of the GNU Lesser General Public License as published by
6 the Free Software Foundation; either version 2.1 of the License, or
7 (at your option) any later version.
8 
9 This program is distributed in the hope that it will be useful,
10 but WITHOUT ANY WARRANTY; without even the implied warranty of
11 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12 GNU Lesser General Public License for more details.
13 
14 You should have received a copy of the GNU Lesser General Public License
15 along with this program; if not, write to the Free Software
16 Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
17 
18 */
19 
20 #include "JackEngineProfiling.h"
21 #include "JackGraphManager.h"
22 #include "JackClientControl.h"
23 #include "JackEngineControl.h"
24 #include "JackClientInterface.h"
25 #include "JackGlobals.h"
26 #include "JackTime.h"
27 
28 #include <iostream>
29 #include <fstream>
30 
31 namespace Jack
32 {
33 
JackEngineProfiling()34 JackEngineProfiling::JackEngineProfiling():fAudioCycle(0),fMeasuredClient(0)
35 {
36     jack_info("Engine profiling activated, beware %ld MBytes are needed to record profiling points...", sizeof(fProfileTable) / (1024 * 1024));
37 
38     // Force memory page in
39     memset(fProfileTable, 0, sizeof(fProfileTable));
40 }
41 
~JackEngineProfiling()42 JackEngineProfiling::~JackEngineProfiling()
43 {
44     std::ofstream fStream("JackEngineProfiling.log", std::ios_base::ate);
45     jack_info("Write server and clients timing data...");
46 
47     if (!fStream.is_open()) {
48         jack_error("JackEngineProfiling::Save cannot open JackEngineProfiling.log file");
49     } else {
50 
51         // For each measured point
52         for (int i = 2; i < TIME_POINTS; i++) {
53 
54             // Driver timing values
55             long d1 = long(fProfileTable[i].fCurCycleBegin - fProfileTable[i - 1].fCurCycleBegin);
56             long d2 = long(fProfileTable[i].fPrevCycleEnd - fProfileTable[i - 1].fCurCycleBegin);
57 
58             if (d1 <= 0 || fProfileTable[i].fAudioCycle <= 0)
59                 continue; // Skip non valid cycles
60 
61             // Print driver delta and end cycle
62             fStream << d1 << "\t" << d2 << "\t";
63 
64             // For each measured client
65             for (unsigned int j = 0; j < fMeasuredClient; j++) {
66 
67                 int ref = fIntervalTable[j].fRefNum;
68 
69                 // Is valid client cycle
70                 if (fProfileTable[i].fClientTable[ref].fStatus != NotTriggered) {
71 
72                     long d5 = long(fProfileTable[i].fClientTable[ref].fSignaledAt - fProfileTable[i - 1].fCurCycleBegin);
73                     long d6 = long(fProfileTable[i].fClientTable[ref].fAwakeAt - fProfileTable[i - 1].fCurCycleBegin);
74                     long d7 = long(fProfileTable[i].fClientTable[ref].fFinishedAt - fProfileTable[i - 1].fCurCycleBegin);
75 
76                      fStream << ref << "\t" ;
77                      fStream << ((d5 > 0) ? d5 : 0) << "\t";
78                      fStream << ((d6 > 0) ? d6 : 0) << "\t" ;
79                      fStream << ((d7 > 0) ? d7 : 0) << "\t";
80                      fStream << ((d6 > 0 && d5 > 0) ? (d6 - d5) : 0) << "\t" ;
81                      fStream << ((d7 > 0 && d6 > 0) ? (d7 - d6) : 0) << "\t" ;
82                      fStream << fProfileTable[i].fClientTable[ref].fStatus << "\t" ;;
83 
84                 } else { // Print tabs
85                      fStream <<  "\t  \t  \t  \t  \t  \t \t";
86                 }
87             }
88 
89             // Terminate line
90             fStream << std::endl;
91         }
92     }
93 
94     // Driver period
95      std::ofstream fStream1("Timing1.plot", std::ios_base::ate);
96 
97     if (!fStream1.is_open()) {
98         jack_error("JackEngineProfiling::Save cannot open Timing1.plot file");
99     } else {
100 
101         fStream1 << "set grid\n";
102         fStream1 <<  "set title \"Audio driver timing\"\n";
103         fStream1 <<  "set xlabel \"audio cycles\"\n";
104         fStream1 <<  "set ylabel \"usec\"\n";
105         fStream1 <<  "plot \"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines \n";
106 
107         fStream1 <<  "set output 'Timing1.svg\n";
108         fStream1 <<  "set terminal svg\n";
109 
110         fStream1 <<  "set grid\n";
111         fStream1 <<  "set title \"Audio driver timing\"\n";
112         fStream1 <<  "set xlabel \"audio cycles\"\n";
113         fStream1 <<  "set ylabel \"usec\"\n";
114         fStream1 <<  "plot \"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines \n";
115         fStream1 <<  "unset output\n";
116     }
117 
118     // Driver end date
119     std::ofstream fStream2("Timing2.plot", std::ios_base::ate);
120 
121     if (!fStream2.is_open()) {
122         jack_error("JackEngineProfiling::Save cannot open Timing2.plot file");
123     } else {
124 
125         fStream2 << "set grid\n";
126         fStream2 <<  "set title \"Driver end date\"\n";
127         fStream2 <<  "set xlabel \"audio cycles\"\n";
128         fStream2 <<  "set ylabel \"usec\"\n";
129         fStream2 <<  "plot  \"JackEngineProfiling.log\" using 2 title \"Driver end date\" with lines \n";
130 
131         fStream2 <<  "set output 'Timing2.svg\n";
132         fStream2 <<  "set terminal svg\n";
133 
134         fStream2 <<  "set grid\n";
135         fStream2 <<  "set title \"Driver end date\"\n";
136         fStream2 <<  "set xlabel \"audio cycles\"\n";
137         fStream2 <<  "set ylabel \"usec\"\n";
138         fStream2 <<  "plot  \"JackEngineProfiling.log\" using 2 title \"Driver end date\" with lines \n";
139         fStream2 <<  "unset output\n";
140     }
141 
142     // Clients end date
143     if (fMeasuredClient > 0) {
144         std::ofstream fStream3("Timing3.plot", std::ios_base::ate);
145 
146         if (!fStream3.is_open()) {
147             jack_error("JackEngineProfiling::Save cannot open Timing3.plot file");
148         } else {
149 
150             fStream3 << "set multiplot\n";
151             fStream3 << "set grid\n";
152             fStream3 << "set title \"Clients end date\"\n";
153             fStream3 << "set xlabel \"audio cycles\"\n";
154             fStream3 << "set ylabel \"usec\"\n";
155             fStream3 << "plot ";
156             for (unsigned int i = 0; i < fMeasuredClient; i++) {
157                 if (i == 0) {
158                     if (i + 1 == fMeasuredClient) { // Last client
159                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
160                         fStream3 <<  ((i + 1) * 7) - 1;
161                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines";
162                      } else {
163                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
164                         fStream3 <<  ((i + 1) * 7) - 1;
165                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines,";
166                     }
167                 } else if (i + 1 == fMeasuredClient) { // Last client
168                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
169                 } else {
170                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
171                 }
172             }
173 
174             fStream3 << "\n unset multiplot\n";
175             fStream3 << "set output 'Timing3.svg\n";
176             fStream3 << "set terminal svg\n";
177 
178             fStream3 << "set multiplot\n";
179             fStream3 << "set grid\n";
180             fStream3 << "set title \"Clients end date\"\n";
181             fStream3 << "set xlabel \"audio cycles\"\n";
182             fStream3 << "set ylabel \"usec\"\n";
183             fStream3 << "plot ";
184             for (unsigned int i = 0; i < fMeasuredClient; i++) {
185                 if (i == 0) {
186                     if ((i + 1) == fMeasuredClient) { // Last client
187                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
188                         fStream3 <<  ((i + 1) * 7) - 1;
189                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines";
190                     } else {
191                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
192                         fStream3 <<  ((i + 1) * 7) - 1;
193                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines,";
194                     }
195                 } else if ((i + 1) == fMeasuredClient) { // Last client
196                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
197                 } else {
198                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
199                 }
200             }
201             fStream3 << "\nunset multiplot\n";
202             fStream3 << "unset output\n";
203         }
204     }
205 
206     // Clients scheduling
207     if (fMeasuredClient > 0) {
208         std::ofstream fStream4("Timing4.plot", std::ios_base::ate);
209 
210         if (!fStream4.is_open()) {
211             jack_error("JackEngineProfiling::Save cannot open Timing4.plot file");
212         } else {
213 
214             fStream4 << "set multiplot\n";
215             fStream4 << "set grid\n";
216             fStream4 << "set title \"Clients scheduling latency\"\n";
217             fStream4 << "set xlabel \"audio cycles\"\n";
218             fStream4 << "set ylabel \"usec\"\n";
219             fStream4 << "plot ";
220             for (unsigned int i = 0; i < fMeasuredClient; i++) {
221                 if ((i + 1) == fMeasuredClient) { // Last client
222                     fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines";
223                  } else {
224                      fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
225                 }
226             }
227 
228             fStream4 << "\n unset multiplot\n";
229             fStream4 << "set output 'Timing4.svg\n";
230             fStream4 << "set terminal svg\n";
231 
232             fStream4 << "set multiplot\n";
233             fStream4 << "set grid\n";
234             fStream4 << "set title \"Clients scheduling latency\"\n";
235             fStream4 << "set xlabel \"audio cycles\"\n";
236             fStream4 << "set ylabel \"usec\"\n";
237             fStream4 << "plot ";
238             for (unsigned int i = 0; i < fMeasuredClient; i++) {
239                 if ((i + 1) == fMeasuredClient) { // Last client
240                     fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines";
241                 } else {
242                      fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
243                 }
244             }
245             fStream4 << "\nunset multiplot\n";
246             fStream4 << "unset output\n";
247         }
248     }
249 
250      // Clients duration
251     if (fMeasuredClient > 0) {
252         std::ofstream fStream5("Timing5.plot", std::ios_base::ate);
253 
254         if (!fStream5.is_open()) {
255             jack_error("JackEngineProfiling::Save cannot open Timing5.plot file");
256         } else {
257 
258             fStream5 << "set multiplot\n";
259             fStream5 << "set grid\n";
260             fStream5 << "set title \"Clients duration\"\n";
261             fStream5 << "set xlabel \"audio cycles\"\n";
262             fStream5 << "set ylabel \"usec\"\n";
263             fStream5 << "plot ";
264             for (unsigned int i = 0; i < fMeasuredClient; i++) {
265                 if ((i + 1) == fMeasuredClient) { // Last client
266                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
267                 } else {
268                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
269                 }
270             }
271 
272             fStream5 << "\n unset multiplot\n";
273             fStream5 << "set output 'Timing5.svg\n";
274             fStream5 << "set terminal svg\n";
275 
276             fStream5 << "set multiplot\n";
277             fStream5 << "set grid\n";
278             fStream5 << "set title \"Clients duration\"\n";
279             fStream5 << "set xlabel \"audio cycles\"\n";
280             fStream5 << "set ylabel \"usec\"\n";
281             fStream5 << "plot ";
282             for (unsigned int i = 0; i < fMeasuredClient; i++) {
283                 if ((i + 1) == fMeasuredClient) {// Last client
284                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
285                 } else {
286                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
287                 }
288             }
289             fStream5 << "\nunset multiplot\n";
290             fStream5 << "unset output\n";
291         }
292     }
293 
294     std::ofstream fStream6("Timings.html", std::ios_base::ate);
295     if (!fStream6.is_open()) {
296         jack_error("JackEngineProfiling::Save cannot open Timings.html file");
297     } else {
298         fStream6 << "<?xml version='1.0' encoding='utf-8'?>\n";
299         fStream6 << "<!DOCTYPE html PUBLIC \"-//W3C//DTD XHTML 1.0 Transitional//EN\"\n";
300         fStream6 << "\"http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd\">\n";
301         fStream6 << "<html xmlns='http://www.w3.org/1999/xhtml' lang='en'>\n";
302         fStream6 << "  <head>\n";
303         fStream6 << "    <title>JACK engine profiling</title>\n";
304         fStream6 << "    <!-- assuming that images are 600px wide -->\n";
305         fStream6 << "    <style media='all' type='text/css'>\n";
306         fStream6 << "    .center { margin-left:auto ; margin-right: auto; width: 650px; height: 550px }\n";
307         fStream6 << "    </style>\n";
308         fStream6 << "  </head>\n";
309         fStream6 << "  <body>\n";
310         fStream6 << "    <h2 style='text-align:center'>JACK engine profiling</h2>\n";
311         fStream6 << "    <div class='center'><object class='center' type='image/svg+xml' data='Timing1.svg'>Timing1</object></div>";
312         fStream6 << "    <div class='center'><object class='center' type='image/svg+xml' data='Timing2.svg'>Timing2</object></div>";
313         fStream6 << "    <div class='center'><object class='center' type='image/svg+xml' data='Timing3.svg'>Timing3</object></div>";
314         fStream6 << "    <div class='center'><object class='center' type='image/svg+xml' data='Timing4.svg'>Timing4</object></div>";
315         fStream6 << "    <div class='center'><object class='center' type='image/svg+xml' data='Timing5.svg'>Timing5</object></div>";
316         fStream6 << "  </body>\n";
317         fStream6 << "</html>\n";
318     }
319 
320     std::ofstream fStream7("generate_timings", std::ios_base::ate);
321     if (!fStream7.is_open()) {
322         jack_error("JackEngineProfiling::Save cannot open generate_timings file");
323     } else {
324         fStream7 << "gnuplot -persist Timing1.plot \n";
325         fStream7 << "gnuplot -persist Timing2.plot\n";
326         fStream7 << "gnuplot -persist Timing3.plot\n";
327         fStream7 << "gnuplot -persist Timing4.plot\n";
328         fStream7 << "gnuplot -persist Timing5.plot\n";
329     }
330 }
331 
CheckClient(const char * name,int cur_point)332 bool JackEngineProfiling::CheckClient(const char* name, int cur_point)
333 {
334     for (int i = 0; i < MEASURED_CLIENTS; i++) {
335        if (strcmp(fIntervalTable[i].fName, name) == 0) {
336             fIntervalTable[i].fEndInterval = cur_point;
337             return true;
338         }
339     }
340     return false;
341 }
342 
Profile(JackClientInterface ** table,JackGraphManager * manager,jack_time_t period_usecs,jack_time_t cur_cycle_begin,jack_time_t prev_cycle_end)343 void JackEngineProfiling::Profile(JackClientInterface** table,
344                                    JackGraphManager* manager,
345                                    jack_time_t period_usecs,
346                                    jack_time_t cur_cycle_begin,
347                                    jack_time_t prev_cycle_end)
348 {
349     fAudioCycle = (fAudioCycle + 1) % TIME_POINTS;
350 
351     // Keeps cycle data
352     fProfileTable[fAudioCycle].fPeriodUsecs = period_usecs;
353     fProfileTable[fAudioCycle].fCurCycleBegin = cur_cycle_begin;
354     fProfileTable[fAudioCycle].fPrevCycleEnd = prev_cycle_end;
355     fProfileTable[fAudioCycle].fAudioCycle = fAudioCycle;
356 
357     for (int i = GetEngineControl()->fDriverNum; i < CLIENT_NUM; i++) {
358         JackClientInterface* client = table[i];
359         JackClientTiming* timing = manager->GetClientTiming(i);
360         if (client && client->GetClientControl()->fActive && client->GetClientControl()->fCallback[kRealTimeCallback]) {
361 
362             if (!CheckClient(client->GetClientControl()->fName, fAudioCycle)) {
363                 // Keep new measured client
364                 fIntervalTable[fMeasuredClient].fRefNum = i;
365                 strcpy(fIntervalTable[fMeasuredClient].fName, client->GetClientControl()->fName);
366                 fIntervalTable[fMeasuredClient].fBeginInterval = fAudioCycle;
367                 fIntervalTable[fMeasuredClient].fEndInterval = fAudioCycle;
368                 fMeasuredClient++;
369             }
370             fProfileTable[fAudioCycle].fClientTable[i].fRefNum = i;
371             fProfileTable[fAudioCycle].fClientTable[i].fSignaledAt = timing->fSignaledAt;
372             fProfileTable[fAudioCycle].fClientTable[i].fAwakeAt = timing->fAwakeAt;
373             fProfileTable[fAudioCycle].fClientTable[i].fFinishedAt = timing->fFinishedAt;
374             fProfileTable[fAudioCycle].fClientTable[i].fStatus = timing->fStatus;
375         }
376     }
377 }
378 
GetCurMeasure()379 JackTimingMeasure* JackEngineProfiling::GetCurMeasure()
380 {
381     return &fProfileTable[fAudioCycle];
382 }
383 
384 } // end of namespace
385