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 namespace Jack
  29 {
  30
  31 JackEngineProfiling::JackEngineProfiling():fAudioCycle(0),fMeasuredClient(0)
  32 {
  33     jack_info("Engine profiling activated, beware %ld MBytes are needed to record profiling points...", sizeof(fProfileTable) / (1024 * 1024));
  34
  35     // Force memory page in
  36     memset(fProfileTable, 0, sizeof(fProfileTable));
  37 }
  38
  39 JackEngineProfiling::~JackEngineProfiling()
  40 {
  41     FILE* file = fopen("JackEngineProfiling.log", "w");
  42     char buffer[1024];
  43
  44     jack_info("Write server and clients timing data...");
  45
  46     if (file == NULL) {
  47         jack_error("JackEngineProfiling::Save cannot open JackEngineProfiling.log file");
  48     } else {
  49
  50         // For each measured point
  51         for (int i = 2; i < TIME_POINTS; i++) {
  52
  53             // Driver timing values
  54             long d1 = long(fProfileTable[i].fCurCycleBegin - fProfileTable[i - 1].fCurCycleBegin);
  55             long d2 = long(fProfileTable[i].fPrevCycleEnd - fProfileTable[i - 1].fCurCycleBegin);
  56
  57             if (d1 <= 0 || fProfileTable[i].fAudioCycle <= 0)
  58                 continue; // Skip non valid cycles
  59
  60             // Print driver delta and end cycle
  61             fprintf(file, "%ld \t %ld \t", d1, d2);
  62
  63             // For each measured client
  64             for (unsigned int j = 0; j < fMeasuredClient; j++) {
  65
  66                 int ref = fIntervalTable[j].fRefNum;
  67
  68                 // Is valid client cycle
  69                  if (fProfileTable[i].fClientTable[ref].fStatus != NotTriggered) {
  70
  71                     long d5 = long(fProfileTable[i].fClientTable[ref].fSignaledAt - fProfileTable[i - 1].fCurCycleBegin);
  72                     long d6 = long(fProfileTable[i].fClientTable[ref].fAwakeAt - fProfileTable[i - 1].fCurCycleBegin);
  73                     long d7 = long(fProfileTable[i].fClientTable[ref].fFinishedAt - fProfileTable[i - 1].fCurCycleBegin);
  74
  75                     // Print ref, signal, start, end, scheduling, duration, status
  76                     fprintf(file, "%d \t %ld \t %ld \t %ld \t %ld \t %ld \t %d \t",
  77                             ref,
  78                             ((d5 > 0) ? d5 : 0),
  79                             ((d6 > 0) ? d6 : 0),
  80                             ((d7 > 0) ? d7 : 0),
  81                             ((d6 > 0 && d5 > 0) ? (d6 - d5) : 0),
  82                             ((d7 > 0 && d6 > 0) ? (d7 - d6) : 0),
  83                             fProfileTable[i].fClientTable[ref].fStatus);
  84                 } else { // Print tabs
  85                      fprintf(file, "\t  \t  \t  \t  \t  \t \t");
  86                 }
  87             }
  88
  89             // Terminate line
  90             fprintf(file, "\n");
  91         }
  92     }
  93
  94     // Driver period
  95     file = fopen("Timing1.plot", "w");
  96
  97     if (file == NULL) {
  98         jack_error("JackEngineProfiling::Save cannot open Timing1.log file");
  99     } else {
 100
 101         fprintf(file, "set grid\n");
 102         fprintf(file, "set title \"Audio driver timing\"\n");
 103         fprintf(file, "set xlabel \"audio cycles\"\n");
 104         fprintf(file, "set ylabel \"usec\"\n");
 105         fprintf(file, "plot \"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines \n");
 106
 107         fprintf(file, "set output 'Timing1.pdf\n");
 108         fprintf(file, "set terminal pdf\n");
 109
 110         fprintf(file, "set grid\n");
 111         fprintf(file, "set title \"Audio driver timing\"\n");
 112         fprintf(file, "set xlabel \"audio cycles\"\n");
 113         fprintf(file, "set ylabel \"usec\"\n");
 114         fprintf(file, "plot \"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines \n");
 115
 116         fclose(file);
 117     }
 118
 119     // Driver end date
 120     file = fopen("Timing2.plot", "w");
 121
 122     if (file == NULL) {
 123         jack_error("JackEngineProfiling::Save cannot open Timing2.log file");
 124     } else {
 125
 126         fprintf(file, "set grid\n");
 127         fprintf(file, "set title \"Driver end date\"\n");
 128         fprintf(file, "set xlabel \"audio cycles\"\n");
 129         fprintf(file, "set ylabel \"usec\"\n");
 130         fprintf(file, "plot  \"JackEngineProfiling.log\" using 2 title \"Driver end date\" with lines \n");
 131
 132         fprintf(file, "set output 'Timing2.pdf\n");
 133         fprintf(file, "set terminal pdf\n");
 134
 135         fprintf(file, "set grid\n");
 136         fprintf(file, "set title \"Driver end date\"\n");
 137         fprintf(file, "set xlabel \"audio cycles\"\n");
 138         fprintf(file, "set ylabel \"usec\"\n");
 139         fprintf(file, "plot  \"JackEngineProfiling.log\" using 2 title \"Driver end date\" with lines \n");
 140
 141         fclose(file);
 142     }
 143
 144     // Clients end date
 145     if (fMeasuredClient > 0) {
 146         file = fopen("Timing3.plot", "w");
 147         if (file == NULL) {
 148             jack_error("JackEngineProfiling::Save cannot open Timing3.log file");
 149         } else {
 150
 151             fprintf(file, "set multiplot\n");
 152             fprintf(file, "set grid\n");
 153             fprintf(file, "set title \"Clients end date\"\n");
 154             fprintf(file, "set xlabel \"audio cycles\"\n");
 155             fprintf(file, "set ylabel \"usec\"\n");
 156             fprintf(file, "plot ");
 157             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 158                 if (i == 0) {
 159                     if (i + 1 == fMeasuredClient) { // Last client
 160                         sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines",
 161                         ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
 162                     } else {
 163                         sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines,",
 164                         ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
 165                     }
 166                 } else if (i + 1 == fMeasuredClient) { // Last client
 167                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
 168                 } else {
 169                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) - 1, fIntervalTable[i].fName);
 170                 }
 171                 fprintf(file, buffer);
 172             }
 173
 174             fprintf(file, "\n unset multiplot\n");
 175             fprintf(file, "set output 'Timing3.pdf\n");
 176             fprintf(file, "set terminal pdf\n");
 177
 178             fprintf(file, "set multiplot\n");
 179             fprintf(file, "set grid\n");
 180             fprintf(file, "set title \"Clients end date\"\n");
 181             fprintf(file, "set xlabel \"audio cycles\"\n");
 182             fprintf(file, "set ylabel \"usec\"\n");
 183             fprintf(file, "plot ");
 184             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 185                 if (i == 0) {
 186                     if ((i + 1) == fMeasuredClient) { // Last client
 187                         sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines",
 188                         ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
 189                     } else {
 190                         sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines,",
 191                         ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
 192                     }
 193                 } else if ((i + 1) == fMeasuredClient) { // Last client
 194                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
 195                 } else {
 196                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) - 1, fIntervalTable[i].fName);
 197                 }
 198                 fprintf(file, buffer);
 199             }
 200
 201             fclose(file);
 202         }
 203     }
 204
 205     // Clients scheduling
 206     if (fMeasuredClient > 0) {
 207         file = fopen("Timing4.plot", "w");
 208
 209         if (file == NULL) {
 210             jack_error("JackEngineProfiling::Save cannot open Timing4.log file");
 211         } else {
 212
 213             fprintf(file, "set multiplot\n");
 214             fprintf(file, "set grid\n");
 215             fprintf(file, "set title \"Clients scheduling latency\"\n");
 216             fprintf(file, "set xlabel \"audio cycles\"\n");
 217             fprintf(file, "set ylabel \"usec\"\n");
 218             fprintf(file, "plot ");
 219             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 220                 if ((i + 1) == fMeasuredClient) // Last client
 221                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7), fIntervalTable[i].fName);
 222                 else
 223                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7), fIntervalTable[i].fName);
 224                 fprintf(file, buffer);
 225             }
 226
 227             fprintf(file, "\n unset multiplot\n");
 228             fprintf(file, "set output 'Timing4.pdf\n");
 229             fprintf(file, "set terminal pdf\n");
 230
 231             fprintf(file, "set multiplot\n");
 232             fprintf(file, "set grid\n");
 233             fprintf(file, "set title \"Clients scheduling latency\"\n");
 234             fprintf(file, "set xlabel \"audio cycles\"\n");
 235             fprintf(file, "set ylabel \"usec\"\n");
 236             fprintf(file, "plot ");
 237             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 238                 if ((i + 1) == fMeasuredClient) // Last client
 239                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7), fIntervalTable[i].fName);
 240                 else
 241                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7), fIntervalTable[i].fName);
 242                 fprintf(file, buffer);
 243             }
 244             fclose(file);
 245         }
 246     }
 247
 248      // Clients duration
 249     if (fMeasuredClient > 0) {
 250         file = fopen("Timing5.plot", "w");
 251
 252         if (file == NULL) {
 253             jack_error("JackEngineProfiling::Save cannot open Timing5.log file");
 254         } else {
 255
 256             fprintf(file, "set multiplot\n");
 257             fprintf(file, "set grid\n");
 258             fprintf(file, "set title \"Clients duration\"\n");
 259             fprintf(file, "set xlabel \"audio cycles\"\n");
 260             fprintf(file, "set ylabel \"usec\"\n");
 261             fprintf(file, "plot ");
 262             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 263                 if ((i + 1) == fMeasuredClient) // Last client
 264                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
 265                 else
 266                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
 267                 fprintf(file, buffer);
 268             }
 269
 270             fprintf(file, "\n unset multiplot\n");
 271             fprintf(file, "set output 'Timing5.pdf\n");
 272             fprintf(file, "set terminal pdf\n");
 273
 274             fprintf(file, "set multiplot\n");
 275             fprintf(file, "set grid\n");
 276             fprintf(file, "set title \"Clients duration\"\n");
 277             fprintf(file, "set xlabel \"audio cycles\"\n");
 278             fprintf(file, "set ylabel \"usec\"\n");
 279             fprintf(file, "plot ");
 280             for (unsigned int i = 0; i < fMeasuredClient; i++) {
 281                 if ((i + 1) == fMeasuredClient) // Last client
 282                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
 283                 else
 284                     sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
 285                 fprintf(file, buffer);
 286             }
 287             fclose(file);
 288         }
 289     }
 290 }
 291
 292 bool JackEngineProfiling::CheckClient(const char* name, int cur_point)
 293 {
 294     for (int i = 0; i < MEASURED_CLIENTS; i++) {
 295        if (strcmp(fIntervalTable[i].fName, name) == 0) {
 296             fIntervalTable[i].fEndInterval = cur_point;
 297             return true;
 298         }
 299     }
 300     return false;
 301 }
 302
 303 void JackEngineProfiling::Profile(JackClientInterface** table,
 304                                    JackGraphManager* manager,
 305                                    jack_time_t period_usecs,
 306                                    jack_time_t cur_cycle_begin,
 307                                    jack_time_t prev_cycle_end)
 308 {
 309     fAudioCycle = (fAudioCycle + 1) % TIME_POINTS;
 310
 311     // Keeps cycle data
 312     fProfileTable[fAudioCycle].fPeriodUsecs = period_usecs;
 313     fProfileTable[fAudioCycle].fCurCycleBegin = cur_cycle_begin;
 314     fProfileTable[fAudioCycle].fPrevCycleEnd = prev_cycle_end;
 315     fProfileTable[fAudioCycle].fAudioCycle = fAudioCycle;
 316
 317     for (int i = GetEngineControl()->fDriverNum; i < CLIENT_NUM; i++) {
 318         JackClientInterface* client = table[i];
 319         JackClientTiming* timing = manager->GetClientTiming(i);
 320         if (client && client->GetClientControl()->fActive && client->GetClientControl()->fCallback[kRealTimeCallback]) {
 321
 322             if (!CheckClient(client->GetClientControl()->fName, fAudioCycle)) {
 323                 // Keep new measured client
 324                 fIntervalTable[fMeasuredClient].fRefNum = i;
 325                 strcpy(fIntervalTable[fMeasuredClient].fName, client->GetClientControl()->fName);
 326                 fIntervalTable[fMeasuredClient].fBeginInterval = fAudioCycle;
 327                 fIntervalTable[fMeasuredClient].fEndInterval = fAudioCycle;
 328                 fMeasuredClient++;
 329             }
 330             fProfileTable[fAudioCycle].fClientTable[i].fRefNum = i;
 331             fProfileTable[fAudioCycle].fClientTable[i].fSignaledAt = timing->fSignaledAt;
 332             fProfileTable[fAudioCycle].fClientTable[i].fAwakeAt = timing->fAwakeAt;
 333             fProfileTable[fAudioCycle].fClientTable[i].fFinishedAt = timing->fFinishedAt;
 334             fProfileTable[fAudioCycle].fClientTable[i].fStatus = timing->fStatus;
 335         }
 336     }
 337 }
 338
 339 JackTimingMeasure* JackEngineProfiling::GetCurMeasure()
 340 {
 341     return &fProfileTable[fAudioCycle];
 342 }
 343
 344 } // end of namespace