Commit 829c9548 authored by sletz's avatar sletz
Browse files

More robust profiling tools when clients come and go.

git-svn-id: http://subversion.jackaudio.org/jack/jack2/trunk/jackmp@3390 0c269be4-1314-0410-8aa9-9f06e86f4224
parent 03f53667
...@@ -23,6 +23,10 @@ Michael Voigt ...@@ -23,6 +23,10 @@ Michael Voigt
Jackdmp changes log Jackdmp changes log
--------------------------- ---------------------------
2009-03-03 Stephane Letz <letz@grame.fr>
* More robust profiling tools when clients come and go.
2009-03-01 Stephane Letz <letz@grame.fr> 2009-03-01 Stephane Letz <letz@grame.fr>
* Raise default port number to 1024. * Raise default port number to 1024.
......
...@@ -26,7 +26,7 @@ Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA. ...@@ -26,7 +26,7 @@ Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
namespace Jack namespace Jack
{ {
JackEngineProfiling::JackEngineProfiling():fAudioCycle(0) JackEngineProfiling::JackEngineProfiling():fAudioCycle(0),fMeasuredClient(0)
{ {
jack_info("Engine profiling activated, beware %ld MBytes are needed to record profiling points...", sizeof(fProfileTable) / (1024 * 1024)); jack_info("Engine profiling activated, beware %ld MBytes are needed to record profiling points...", sizeof(fProfileTable) / (1024 * 1024));
...@@ -36,66 +36,60 @@ JackEngineProfiling::JackEngineProfiling():fAudioCycle(0) ...@@ -36,66 +36,60 @@ JackEngineProfiling::JackEngineProfiling():fAudioCycle(0)
JackEngineProfiling::~JackEngineProfiling() JackEngineProfiling::~JackEngineProfiling()
{ {
// Window monitoring
int max_client = 0;
char buffer[1024];
char* nameTable[CLIENT_NUM];
FILE* file = fopen("JackEngineProfiling.log", "w"); FILE* file = fopen("JackEngineProfiling.log", "w");
char buffer[1024];
jack_info("Write server and clients timing data..."); jack_info("Write server and clients timing data...");
if (file == NULL) { if (file == NULL) {
jack_error("JackEngineProfiling::Save cannot open JackEngineProfiling.log file"); jack_error("JackEngineProfiling::Save cannot open JackEngineProfiling.log file");
} else { } else {
for (int i = 2; i < TIME_POINTS; i++) { // For each measured point
bool header = true; for (int i = 3; i < TIME_POINTS; i++) {
bool printed = false;
int count = 0; // Driver timing values
for (int j = REAL_REFNUM; j < CLIENT_NUM; j++) { //long d1 = long(fProfileTable[i].fCurCycleBegin - fProfileTable[i - 1].fCurCycleBegin);
if (fProfileTable[i].fClientTable[j].fRefNum > 0) { long d1 = long(fProfileTable[i - 1].fCurCycleBegin - fProfileTable[i - 2].fCurCycleBegin);
long d1 = long(fProfileTable[i - 1].fCurCycleBegin - fProfileTable[i - 2].fCurCycleBegin); long d2 = long(fProfileTable[i].fPrevCycleEnd - fProfileTable[i - 1].fCurCycleBegin);
long d2 = long(fProfileTable[i].fPrevCycleEnd - fProfileTable[i - 1].fCurCycleBegin);
if (d1 > 0 && fProfileTable[i].fClientTable[j].fStatus != NotTriggered) { // Valid cycle if (d1 <= 0 || fProfileTable[i].fAudioCycle <= 0)
count++; continue; // Skip non valid cycles
nameTable[count] = fNameTable[fProfileTable[i].fClientTable[j].fRefNum];
// Print driver delta and end cycle
// driver delta and end cycle fprintf(file, "%ld \t %ld \t", d1, d2);
if (header) {
fprintf(file, "%ld \t %ld \t", d1, d2); // For each measured client
header = false; for (unsigned int j = 0; j < fMeasuredClient; j++) {
}
long d5 = long(fProfileTable[i].fClientTable[j].fSignaledAt - fProfileTable[i - 1].fCurCycleBegin); int ref = fIntervalTable[j].fRefNum;
long d6 = long(fProfileTable[i].fClientTable[j].fAwakeAt - fProfileTable[i - 1].fCurCycleBegin);
long d7 = long(fProfileTable[i].fClientTable[j].fFinishedAt - fProfileTable[i - 1].fCurCycleBegin); // Is valid client cycle
if (fProfileTable[i].fClientTable[ref].fStatus != NotTriggered) {
// ref, signal, start, end, scheduling, duration, status
fprintf(file, "%d \t %ld \t %ld \t %ld \t %ld \t %ld \t %d \t", long d5 = long(fProfileTable[i].fClientTable[ref].fSignaledAt - fProfileTable[i - 1].fCurCycleBegin);
fProfileTable[i].fClientTable[j].fRefNum, long d6 = long(fProfileTable[i].fClientTable[ref].fAwakeAt - fProfileTable[i - 1].fCurCycleBegin);
((d5 > 0) ? d5 : 0), long d7 = long(fProfileTable[i].fClientTable[ref].fFinishedAt - fProfileTable[i - 1].fCurCycleBegin);
((d6 > 0) ? d6 : 0),
((d7 > 0) ? d7 : 0), // Print ref, signal, start, end, scheduling, duration, status
((d6 > 0 && d5 > 0) ? (d6 - d5) : 0), fprintf(file, "%d \t %ld \t %ld \t %ld \t %ld \t %ld \t %d \t",
((d7 > 0 && d6 > 0) ? (d7 - d6) : 0), ref,
fProfileTable[i].fClientTable[j].fStatus); ((d5 > 0) ? d5 : 0),
printed = true; ((d6 > 0) ? d6 : 0),
} ((d7 > 0) ? d7 : 0),
} ((d6 > 0 && d5 > 0) ? (d6 - d5) : 0),
max_client = (count > max_client) ? count : max_client; ((d7 > 0 && d6 > 0) ? (d7 - d6) : 0),
} fProfileTable[i].fClientTable[ref].fStatus);
if (printed) { } else { // Print tabs
fprintf(file, "\n"); fprintf(file, "\t \t \t \t \t \t \t");
} else if (fProfileTable[i].fAudioCycle > 0) { // Driver timing only
long d1 = long(fProfileTable[i].fCurCycleBegin - fProfileTable[i - 1].fCurCycleBegin);
long d2 = long(fProfileTable[i].fPrevCycleEnd - fProfileTable[i - 1].fCurCycleBegin);
if (d1 > 0) { // Valid cycle
fprintf(file, "%ld \t %ld \n", d1, d2);
} }
} }
// Terminate line
fprintf(file, "\n");
} }
fclose(file);
} }
// Driver period // Driver period
file = fopen("Timing1.plot", "w"); file = fopen("Timing1.plot", "w");
...@@ -145,9 +139,9 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -145,9 +139,9 @@ JackEngineProfiling::~JackEngineProfiling()
fclose(file); fclose(file);
} }
// Clients end date // Clients end date
if (max_client > 0) { if (fMeasuredClient > 0) {
file = fopen("Timing3.plot", "w"); file = fopen("Timing3.plot", "w");
if (file == NULL) { if (file == NULL) {
jack_error("JackEngineProfiling::Save cannot open Timing3.log file"); jack_error("JackEngineProfiling::Save cannot open Timing3.log file");
...@@ -158,21 +152,20 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -158,21 +152,20 @@ JackEngineProfiling::~JackEngineProfiling()
fprintf(file, "set title \"Clients end date\"\n"); fprintf(file, "set title \"Clients end date\"\n");
fprintf(file, "set xlabel \"audio cycles\"\n"); fprintf(file, "set xlabel \"audio cycles\"\n");
fprintf(file, "set ylabel \"usec\"\n"); fprintf(file, "set ylabel \"usec\"\n");
fprintf(file, "plot "); fprintf(file, "plot ");
for (int i = 0; i < max_client; i++) { for (unsigned int i = 0; i < fMeasuredClient; i++) {
if (i == 0) { if (i == 0) {
if ((i + 1) == max_client) { if (i + 1 == fMeasuredClient) { // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines", sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines",
((i + 1) * 7) - 1 , nameTable[(i + 1)]); ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
} else { } else {
sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines,",
((i + 1) * 7) - 1 , nameTable[(i + 1)]); ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
} }
} else if ((i + 1) == max_client) { // Last client } else if (i + 1 == fMeasuredClient) { // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) - 1 , nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
} else { } else {
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) - 1, nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) - 1, fIntervalTable[i].fName);
} }
fprintf(file, buffer); fprintf(file, buffer);
} }
...@@ -187,28 +180,29 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -187,28 +180,29 @@ JackEngineProfiling::~JackEngineProfiling()
fprintf(file, "set xlabel \"audio cycles\"\n"); fprintf(file, "set xlabel \"audio cycles\"\n");
fprintf(file, "set ylabel \"usec\"\n"); fprintf(file, "set ylabel \"usec\"\n");
fprintf(file, "plot "); fprintf(file, "plot ");
for (int i = 0; i < max_client; i++) { for (unsigned int i = 0; i < fMeasuredClient; i++) {
if (i == 0) { if (i == 0) {
if ((i + 1) == max_client) { if ((i + 1) == fMeasuredClient) { // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines", sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines",
((i + 1) * 7) - 1 , nameTable[(i + 1)]); ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
} else { } else {
sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", sprintf(buffer, "\"JackEngineProfiling.log\" using 1 title \"Audio period\" with lines,\"JackEngineProfiling.log\" using %d title \"%s\" with lines,",
((i + 1) * 7) - 1 , nameTable[(i + 1)]); ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
} }
} else if ((i + 1) == max_client) { // Last client } else if ((i + 1) == fMeasuredClient) { // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) - 1 , nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) - 1 , fIntervalTable[i].fName);
} else { } else {
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) - 1, nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) - 1, fIntervalTable[i].fName);
} }
fprintf(file, buffer); fprintf(file, buffer);
} }
fclose(file); fclose(file);
} }
} }
// Clients scheduling // Clients scheduling
if (max_client > 0) { if (fMeasuredClient > 0) {
file = fopen("Timing4.plot", "w"); file = fopen("Timing4.plot", "w");
if (file == NULL) { if (file == NULL) {
...@@ -221,11 +215,11 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -221,11 +215,11 @@ JackEngineProfiling::~JackEngineProfiling()
fprintf(file, "set xlabel \"audio cycles\"\n"); fprintf(file, "set xlabel \"audio cycles\"\n");
fprintf(file, "set ylabel \"usec\"\n"); fprintf(file, "set ylabel \"usec\"\n");
fprintf(file, "plot "); fprintf(file, "plot ");
for (int i = 0; i < max_client; i++) { for (unsigned int i = 0; i < fMeasuredClient; i++) {
if ((i + 1) == max_client) // Last client if ((i + 1) == fMeasuredClient) // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7), nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7), fIntervalTable[i].fName);
else else
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7), nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7), fIntervalTable[i].fName);
fprintf(file, buffer); fprintf(file, buffer);
} }
...@@ -239,11 +233,11 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -239,11 +233,11 @@ JackEngineProfiling::~JackEngineProfiling()
fprintf(file, "set xlabel \"audio cycles\"\n"); fprintf(file, "set xlabel \"audio cycles\"\n");
fprintf(file, "set ylabel \"usec\"\n"); fprintf(file, "set ylabel \"usec\"\n");
fprintf(file, "plot "); fprintf(file, "plot ");
for (int i = 0; i < max_client; i++) { for (unsigned int i = 0; i < fMeasuredClient; i++) {
if ((i + 1) == max_client) // Last client if ((i + 1) == fMeasuredClient) // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7), nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7), fIntervalTable[i].fName);
else else
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7), nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7), fIntervalTable[i].fName);
fprintf(file, buffer); fprintf(file, buffer);
} }
fclose(file); fclose(file);
...@@ -251,7 +245,7 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -251,7 +245,7 @@ JackEngineProfiling::~JackEngineProfiling()
} }
// Clients duration // Clients duration
if (max_client > 0) { if (fMeasuredClient > 0) {
file = fopen("Timing5.plot", "w"); file = fopen("Timing5.plot", "w");
if (file == NULL) { if (file == NULL) {
...@@ -264,11 +258,11 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -264,11 +258,11 @@ JackEngineProfiling::~JackEngineProfiling()
fprintf(file, "set xlabel \"audio cycles\"\n"); fprintf(file, "set xlabel \"audio cycles\"\n");
fprintf(file, "set ylabel \"usec\"\n"); fprintf(file, "set ylabel \"usec\"\n");
fprintf(file, "plot "); fprintf(file, "plot ");
for (int i = 0; i < max_client; i++) { for (unsigned int i = 0; i < fMeasuredClient; i++) {
if ((i + 1) == max_client) // Last client if ((i + 1) == fMeasuredClient) // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) + 1, nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
else else
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) + 1, nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
fprintf(file, buffer); fprintf(file, buffer);
} }
...@@ -282,11 +276,11 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -282,11 +276,11 @@ JackEngineProfiling::~JackEngineProfiling()
fprintf(file, "set xlabel \"audio cycles\"\n"); fprintf(file, "set xlabel \"audio cycles\"\n");
fprintf(file, "set ylabel \"usec\"\n"); fprintf(file, "set ylabel \"usec\"\n");
fprintf(file, "plot "); fprintf(file, "plot ");
for (int i = 0; i < max_client; i++) { for (unsigned int i = 0; i < fMeasuredClient; i++) {
if ((i + 1) == max_client) // Last client if ((i + 1) == fMeasuredClient) // Last client
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) + 1, nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
else else
sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) + 1, nameTable[(i + 1)]); sprintf(buffer, "\"JackEngineProfiling.log\" using %d title \"%s\" with lines,", ((i + 1) * 7) + 1, fIntervalTable[i].fName);
fprintf(file, buffer); fprintf(file, buffer);
} }
fclose(file); fclose(file);
...@@ -294,6 +288,17 @@ JackEngineProfiling::~JackEngineProfiling() ...@@ -294,6 +288,17 @@ JackEngineProfiling::~JackEngineProfiling()
} }
} }
bool JackEngineProfiling::CheckClient(const char* name, int cur_point)
{
for (int i = 0; i < MEASURED_CLIENTS; i++) {
if (strcmp(fIntervalTable[i].fName, name) == 0) {
fIntervalTable[i].fEndInterval = cur_point;
return true;
}
}
return false;
}
void JackEngineProfiling::Profile(JackClientInterface** table, void JackEngineProfiling::Profile(JackClientInterface** table,
JackGraphManager* manager, JackGraphManager* manager,
jack_time_t period_usecs, jack_time_t period_usecs,
...@@ -311,8 +316,16 @@ void JackEngineProfiling::Profile(JackClientInterface** table, ...@@ -311,8 +316,16 @@ void JackEngineProfiling::Profile(JackClientInterface** table,
for (int i = REAL_REFNUM; i < CLIENT_NUM; i++) { for (int i = REAL_REFNUM; i < CLIENT_NUM; i++) {
JackClientInterface* client = table[i]; JackClientInterface* client = table[i];
JackClientTiming* timing = manager->GetClientTiming(i); JackClientTiming* timing = manager->GetClientTiming(i);
if (client && client->GetClientControl()->fActive) { if (client && client->GetClientControl()->fActive && client->GetClientControl()->fCallback[kRealTimeCallback]) {
strcpy(fNameTable[i], client->GetClientControl()->fName);
if (!CheckClient(client->GetClientControl()->fName, fAudioCycle)) {
// Keep new measured client
fIntervalTable[fMeasuredClient].fRefNum = i;
strcpy(fIntervalTable[fMeasuredClient].fName, client->GetClientControl()->fName);
fIntervalTable[fMeasuredClient].fBeginInterval = fAudioCycle;
fIntervalTable[fMeasuredClient].fEndInterval = fAudioCycle;
fMeasuredClient++;
}
fProfileTable[fAudioCycle].fClientTable[i].fRefNum = i; fProfileTable[fAudioCycle].fClientTable[i].fRefNum = i;
fProfileTable[fAudioCycle].fClientTable[i].fSignaledAt = timing->fSignaledAt; fProfileTable[fAudioCycle].fClientTable[i].fSignaledAt = timing->fSignaledAt;
fProfileTable[fAudioCycle].fClientTable[i].fAwakeAt = timing->fAwakeAt; fProfileTable[fAudioCycle].fClientTable[i].fAwakeAt = timing->fAwakeAt;
......
...@@ -31,6 +31,7 @@ namespace Jack ...@@ -31,6 +31,7 @@ namespace Jack
#define TIME_POINTS 250000 #define TIME_POINTS 250000
#define FAILURE_TIME_POINTS 10000 #define FAILURE_TIME_POINTS 10000
#define FAILURE_WINDOW 10 #define FAILURE_WINDOW 10
#define MEASURED_CLIENTS 32
/*! /*!
\brief Timing stucture for a client. \brief Timing stucture for a client.
...@@ -43,6 +44,32 @@ struct JackTimingMeasureClient ...@@ -43,6 +44,32 @@ struct JackTimingMeasureClient
jack_time_t fAwakeAt; jack_time_t fAwakeAt;
jack_time_t fFinishedAt; jack_time_t fFinishedAt;
jack_client_state_t fStatus; jack_client_state_t fStatus;
JackTimingMeasureClient()
:fRefNum(-1),
fSignaledAt(0),
fAwakeAt(0),
fFinishedAt(0),
fStatus((jack_client_state_t)0)
{}
};
/*!
\brief Timing interval in the global table for a given client
*/
struct JackTimingClientInterval
{
int fRefNum;
char fName[JACK_CLIENT_NAME_SIZE + 1];
int fBeginInterval;
int fEndInterval;
JackTimingClientInterval()
:fRefNum(-1),
fBeginInterval(-1),
fEndInterval(-1)
{}
}; };
/*! /*!
...@@ -56,6 +83,13 @@ struct JackTimingMeasure ...@@ -56,6 +83,13 @@ struct JackTimingMeasure
jack_time_t fCurCycleBegin; jack_time_t fCurCycleBegin;
jack_time_t fPrevCycleEnd; jack_time_t fPrevCycleEnd;
JackTimingMeasureClient fClientTable[CLIENT_NUM]; JackTimingMeasureClient fClientTable[CLIENT_NUM];
JackTimingMeasure()
:fAudioCycle(0),
fPeriodUsecs(0),
fCurCycleBegin(0),
fPrevCycleEnd(0)
{}
}; };
/*! /*!
...@@ -71,9 +105,13 @@ class SERVER_EXPORT JackEngineProfiling ...@@ -71,9 +105,13 @@ class SERVER_EXPORT JackEngineProfiling
private: private:
JackTimingMeasure fProfileTable[TIME_POINTS]; JackTimingMeasure fProfileTable[TIME_POINTS];
char fNameTable[CLIENT_NUM][JACK_CLIENT_NAME_SIZE + 1]; JackTimingClientInterval fIntervalTable[MEASURED_CLIENTS];
unsigned int fAudioCycle; unsigned int fAudioCycle;
unsigned int fMeasuredClient;
bool CheckClient(const char* name, int cur_point);
public: public:
JackEngineProfiling(); JackEngineProfiling();
......
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment