common/JackEngineProfiling.cpp

   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
  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
  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
 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
 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
 379 JackTimingMeasure* JackEngineProfiling::GetCurMeasure()
 380 {
 381     return &fProfileTable[fAudioCycle];
 382 }
 383
 384 } // end of namespace