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.log 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.pdf\n";
 108         fStream1 <<  "set terminal pdf\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     }
 116
 117     // Driver end date
 118     std::ofstream fStream2("Timing2.plot", std::ios_base::ate);
 119
 120     if (!fStream2.is_open()) {
 121         jack_error("JackEngineProfiling::Save cannot open Timing2.log file");
 122     } else {
 123
 124         fStream2 << "set grid\n";
 125         fStream2 <<  "set title \"Driver end date\"\n";
 126         fStream2 <<  "set xlabel \"audio cycles\"\n";
 127         fStream2 <<  "set ylabel \"usec\"\n";
 128         fStream2 <<  "plot  \"JackEngineProfiling.log\" using 2 title \"Driver end date\" with lines \n";
 129
 130         fStream2 <<  "set output 'Timing2.pdf\n";
 131         fStream2 <<  "set terminal pdf\n";
 132
 133         fStream2 <<  "set grid\n";
 134         fStream2 <<  "set title \"Driver end date\"\n";
 135         fStream2 <<  "set xlabel \"audio cycles\"\n";
 136         fStream2 <<  "set ylabel \"usec\"\n";
 137         fStream2 <<  "plot  \"JackEngineProfiling.log\" using 2 title \"Driver end date\" with lines \n";
 138     }
 139
 140     // Clients end date
 141     if (fMeasuredClient > 0) {
 142         std::ofstream fStream3("Timing3.plot", std::ios_base::ate);
 143
 144         if (!fStream3.is_open()) {
 145             jack_error("JackEngineProfiling::Save cannot open Timing3.log file");
 146         } else {
 147
 148             fStream3 << "set multiplot\n";
 149             fStream3 << "set grid\n";
 150             fStream3 << "set title \"Clients end date\"\n";
 151             fStream3 << "set xlabel \"audio cycles\"\n";
 152             fStream3 << "set ylabel \"usec\"\n";
 153             fStream3 << "plot ";
 154             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 155                 if (i == 0) {
 156                     if (i + 1 == fMeasuredClient) { // Last client
 157                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
 158                         fStream3 <<  ((i + 1) * 7) - 1;
 159                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines";
 160                      } else {
 161                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
 162                         fStream3 <<  ((i + 1) * 7) - 1;
 163                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines,";
 164                     }
 165                 } else if (i + 1 == fMeasuredClient) { // Last client
 166                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
 167                 } else {
 168                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
 169                 }
 170             }
 171
 172             fStream3 << "\n unset multiplot\n";
 173             fStream3 << "set output 'Timing3.pdf\n";
 174             fStream3 << "set terminal pdf\n";
 175
 176             fStream3 << "set multiplot\n";
 177             fStream3 << "set grid\n";
 178             fStream3 << "set title \"Clients end date\"\n";
 179             fStream3 << "set xlabel \"audio cycles\"\n";
 180             fStream3 << "set ylabel \"usec\"\n";
 181             fStream3 << "plot ";
 182             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 183                 if (i == 0) {
 184                     if ((i + 1) == fMeasuredClient) { // Last client
 185                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
 186                         fStream3 <<  ((i + 1) * 7) - 1;
 187                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines";
 188                     } else {
 189                         fStream3 << "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using ";
 190                         fStream3 <<  ((i + 1) * 7) - 1;
 191                         fStream3 << " title \"" << fIntervalTable[i].fName << "\"with lines,";
 192                     }
 193                 } else if ((i + 1) == fMeasuredClient) { // Last client
 194                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
 195                 } else {
 196                     fStream3 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) - 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
 197                 }
 198             }
 199         }
 200     }
 201
 202     // Clients scheduling
 203     if (fMeasuredClient > 0) {
 204         std::ofstream fStream4("Timing4.plot", std::ios_base::ate);
 205
 206         if (!fStream4.is_open()) {
 207             jack_error("JackEngineProfiling::Save cannot open Timing4.log file");
 208         } else {
 209
 210             fStream4 << "set multiplot\n";
 211             fStream4 << "set grid\n";
 212             fStream4 << "set title \"Clients scheduling latency\"\n";
 213             fStream4 << "set xlabel \"audio cycles\"\n";
 214             fStream4 << "set ylabel \"usec\"\n";
 215             fStream4 << "plot ";
 216             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 217                 if ((i + 1) == fMeasuredClient) { // Last client
 218                     fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines";
 219                  } else {
 220                      fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
 221                 }
 222             }
 223
 224             fStream4 << "\n unset multiplot\n";
 225             fStream4 << "set output 'Timing4.pdf\n";
 226             fStream4 << "set terminal pdf\n";
 227
 228             fStream4 << "set multiplot\n";
 229             fStream4 << "set grid\n";
 230             fStream4 << "set title \"Clients scheduling latency\"\n";
 231             fStream4 << "set xlabel \"audio cycles\"\n";
 232             fStream4 << "set ylabel \"usec\"\n";
 233             fStream4 << "plot ";
 234             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 235                 if ((i + 1) == fMeasuredClient) { // Last client
 236                     fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines";
 237                 } else {
 238                      fStream4 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7)  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
 239                 }
 240             }
 241         }
 242     }
 243
 244      // Clients duration
 245     if (fMeasuredClient > 0) {
 246         std::ofstream fStream5("Timing5.plot", std::ios_base::ate);
 247
 248         if (!fStream5.is_open()) {
 249             jack_error("JackEngineProfiling::Save cannot open Timing5.log file");
 250         } else {
 251
 252             fStream5 << "set multiplot\n";
 253             fStream5 << "set grid\n";
 254             fStream5 << "set title \"Clients duration\"\n";
 255             fStream5 << "set xlabel \"audio cycles\"\n";
 256             fStream5 << "set ylabel \"usec\"\n";
 257             fStream5 << "plot ";
 258             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 259                 if ((i + 1) == fMeasuredClient) { // Last client
 260                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
 261                 } else {
 262                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
 263                 }
 264             }
 265
 266             fStream5 << "\n unset multiplot\n";
 267             fStream5 << "set output 'Timing5.pdf\n";
 268             fStream5 << "set terminal pdf\n";
 269
 270             fStream5 << "set multiplot\n";
 271             fStream5 << "set grid\n";
 272             fStream5 << "set title \"Clients duration\"\n";
 273             fStream5 << "set xlabel \"audio cycles\"\n";
 274             fStream5 << "set ylabel \"usec\"\n";
 275             fStream5 << "plot ";
 276             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 277                 if ((i + 1) == fMeasuredClient) {// Last client
 278                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines";
 279                 } else {
 280                     fStream5 << "\"JackEngineProfiling.log\" using " << ((i + 1) * 7) + 1  << " title \"" << fIntervalTable[i].fName << "\" with lines,";
 281                 }
 282             }
 283         }
 284     }
 285 }
 286
 287 bool JackEngineProfiling::CheckClient(const char* name, int cur_point)
 288 {
 289     for (int i = 0; i < MEASURED_CLIENTS; i++) {
 290        if (strcmp(fIntervalTable[i].fName, name) == 0) {
 291             fIntervalTable[i].fEndInterval = cur_point;
 292             return true;
 293         }
 294     }
 295     return false;
 296 }
 297
 298 void JackEngineProfiling::Profile(JackClientInterface** table,
 299                                    JackGraphManager* manager,
 300                                    jack_time_t period_usecs,
 301                                    jack_time_t cur_cycle_begin,
 302                                    jack_time_t prev_cycle_end)
 303 {
 304     fAudioCycle = (fAudioCycle + 1) % TIME_POINTS;
 305
 306     // Keeps cycle data
 307     fProfileTable[fAudioCycle].fPeriodUsecs = period_usecs;
 308     fProfileTable[fAudioCycle].fCurCycleBegin = cur_cycle_begin;
 309     fProfileTable[fAudioCycle].fPrevCycleEnd = prev_cycle_end;
 310     fProfileTable[fAudioCycle].fAudioCycle = fAudioCycle;
 311
 312     for (int i = GetEngineControl()->fDriverNum; i < CLIENT_NUM; i++) {
 313         JackClientInterface* client = table[i];
 314         JackClientTiming* timing = manager->GetClientTiming(i);
 315         if (client && client->GetClientControl()->fActive && client->GetClientControl()->fCallback[kRealTimeCallback]) {
 316
 317             if (!CheckClient(client->GetClientControl()->fName, fAudioCycle)) {
 318                 // Keep new measured client
 319                 fIntervalTable[fMeasuredClient].fRefNum = i;
 320                 strcpy(fIntervalTable[fMeasuredClient].fName, client->GetClientControl()->fName);
 321                 fIntervalTable[fMeasuredClient].fBeginInterval = fAudioCycle;
 322                 fIntervalTable[fMeasuredClient].fEndInterval = fAudioCycle;
 323                 fMeasuredClient++;
 324             }
 325             fProfileTable[fAudioCycle].fClientTable[i].fRefNum = i;
 326             fProfileTable[fAudioCycle].fClientTable[i].fSignaledAt = timing->fSignaledAt;
 327             fProfileTable[fAudioCycle].fClientTable[i].fAwakeAt = timing->fAwakeAt;
 328             fProfileTable[fAudioCycle].fClientTable[i].fFinishedAt = timing->fFinishedAt;
 329             fProfileTable[fAudioCycle].fClientTable[i].fStatus = timing->fStatus;
 330         }
 331     }
 332 }
 333
 334 JackTimingMeasure* JackEngineProfiling::GetCurMeasure()
 335 {
 336     return &fProfileTable[fAudioCycle];
 337 }
 338
 339 } // end of namespace