profiler: add followerClock block

Add a new followerClock block in the profiler info. This is only set
when the follower could be a driver and it contains the clock info used
for following the driver, mostly the rate difference and delay.

Dump this info in pw-profiler -J

Make sure we always set the info in the clock, especially also when we
are following.
This commit is contained in:
Wim Taymans 2024-10-09 11:27:23 +02:00
parent d605a820d2
commit fa1ec61cf0
6 changed files with 95 additions and 8 deletions

View file

@ -26,6 +26,7 @@ static const struct spa_type_info spa_type_profiler[] = {
{ SPA_PROFILER_clock, SPA_TYPE_Struct, SPA_TYPE_INFO_PROFILER_BASE "clock", NULL, },
{ SPA_PROFILER_driverBlock, SPA_TYPE_Struct, SPA_TYPE_INFO_PROFILER_BASE "driverBlock", NULL, },
{ SPA_PROFILER_followerBlock, SPA_TYPE_Struct, SPA_TYPE_INFO_PROFILER_BASE "followerBlock", NULL, },
{ SPA_PROFILER_followerClock, SPA_TYPE_Struct, SPA_TYPE_INFO_PROFILER_BASE "followerClock", NULL, },
{ 0, 0, NULL, NULL },
};

View file

@ -40,7 +40,9 @@ enum spa_profiler {
* Long : clock delay,
* Double : clock rate_diff,
* Long : clock next_nsec,
* Int : transport_state)) */
* Int : transport_state,
* Int : clock cycle,
* Long : xrun duration)) */
SPA_PROFILER_driverBlock, /**< generic driver info block
* (Struct(
* Int : driver_id,
@ -65,7 +67,18 @@ enum spa_profiler {
* Int : status,
* Fraction : latency,
* Int : xrun_count)) */
SPA_PROFILER_followerClock, /**< follower clock information
* (Struct(
* Int : clock id,
* String: clock name,
* Long : clock nsec,
* Fraction : clock rate,
* Long : clock position,
* Long : clock duration,
* Long : clock delay,
* Double : clock rate_diff,
* Long : clock next_nsec,
* Long : xrun duration)) */
SPA_PROFILER_START_CUSTOM = 0x1000000,
};

View file

@ -2826,7 +2826,7 @@ static int update_time(struct state *state, uint64_t current_time, snd_pcm_sfram
state->next_time += (uint64_t)(state->threshold / corr * 1e9 / state->rate);
if (SPA_LIKELY(!follower && state->clock)) {
if (SPA_LIKELY(state->clock)) {
state->clock->nsec = current_time;
state->clock->rate = state->driver_rate;
state->clock->position += state->clock->duration;

View file

@ -784,7 +784,7 @@ static int update_time(struct seq_state *state, uint64_t nsec, bool follower)
}
state->next_time += (uint64_t)(state->threshold / corr * 1e9 / state->rate.denom);
if (!follower && state->clock) {
if (SPA_LIKELY(state->clock)) {
state->clock->nsec = nsec;
state->clock->rate = state->rate;
state->clock->position += state->clock->duration;

View file

@ -225,7 +225,9 @@ static void context_do_profile(void *data)
SPA_POD_Long(pos->clock.delay),
SPA_POD_Double(pos->clock.rate_diff),
SPA_POD_Long(pos->clock.next_nsec),
SPA_POD_Int(pos->state));
SPA_POD_Int(pos->state),
SPA_POD_Int(pos->clock.cycle),
SPA_POD_Long(pos->clock.xrun));
spa_pod_builder_prop(&b, SPA_PROFILER_driverBlock, 0);
spa_pod_builder_add_struct(&b,
@ -243,6 +245,8 @@ static void context_do_profile(void *data)
struct pw_impl_node *n = t->node;
struct pw_node_activation *na;
struct spa_fraction latency;
struct pw_node_activation *a = n->rt.target.activation;
struct spa_io_position *pos = &a->position;
if (t->id == id)
continue;
@ -271,6 +275,21 @@ static void context_do_profile(void *data)
SPA_POD_Int(na->status),
SPA_POD_Fraction(&latency),
SPA_POD_Int(na->xrun_count));
if (n->driver) {
spa_pod_builder_prop(&b, SPA_PROFILER_followerClock, 0);
spa_pod_builder_add_struct(&b,
SPA_POD_Int(pos->clock.id),
SPA_POD_String(pos->clock.name),
SPA_POD_Long(pos->clock.nsec),
SPA_POD_Fraction(&pos->clock.rate),
SPA_POD_Long(pos->clock.position),
SPA_POD_Long(pos->clock.duration),
SPA_POD_Long(pos->clock.delay),
SPA_POD_Double(pos->clock.rate_diff),
SPA_POD_Long(pos->clock.next_nsec),
SPA_POD_Long(pos->clock.xrun));
}
}
spa_pod_builder_pop(&b, &f[0]);

View file

@ -69,6 +69,7 @@ struct point {
int64_t count;
float cpu_load[3];
struct spa_io_clock clock;
int transport_state;
struct measurement driver;
struct measurement follower[MAX_FOLLOWERS];
};
@ -89,6 +90,18 @@ static const char *status_to_string(int status)
}
return "unknown";
}
static const char *transport_to_string(int state)
{
switch(state) {
case SPA_IO_POSITION_STATE_STOPPED:
return "stopped";
case SPA_IO_POSITION_STATE_STARTING:
return "starting";
case SPA_IO_POSITION_STATE_RUNNING:
return "running";
}
return "unknown";
}
static int process_info(struct data *d, const struct spa_pod *pod, struct point *point)
{
@ -125,18 +138,23 @@ static int process_clock(struct data *d, const struct spa_pod *pod, struct point
SPA_POD_Long(&point->clock.duration),
SPA_POD_Long(&point->clock.delay),
SPA_POD_Double(&point->clock.rate_diff),
SPA_POD_Long(&point->clock.next_nsec));
SPA_POD_Long(&point->clock.next_nsec),
SPA_POD_Int(&point->transport_state),
SPA_POD_OPT_Int(&point->clock.cycle),
SPA_POD_OPT_Long(&point->clock.xrun));
if (d->json_dump) {
fprintf(stdout, "{ \"type\": \"clock\", \"flags\": %u, \"id\": %u, "
"\"name\": \"%s\", \"nsec\": %"PRIu64", \"rate\": \"%u/%u\", "
"\"position\": %"PRIu64", \"duration\": %"PRIu64", "
"\"delay\": %"PRIu64", \"diff\": %s, \"next_nsec\": %"PRIu64" },\n",
"\"delay\": %"PRIu64", \"diff\": %s, \"next_nsec\": %"PRIu64", "
"\"transport\": \"%s\", \"cycle\": %u, \"xrun\": %"PRIu64" },\n",
point->clock.flags, point->clock.id, point->clock.name,
point->clock.nsec, point->clock.rate.num, point->clock.rate.denom,
point->clock.position, point->clock.duration,
point->clock.delay,
spa_json_format_float(val, sizeof(val), (float)point->clock.rate_diff),
point->clock.next_nsec);
point->clock.next_nsec, transport_to_string(point->transport_state),
point->clock.cycle, point->clock.xrun);
}
return res;
}
@ -253,6 +271,39 @@ static int process_follower_block(struct data *d, const struct spa_pod *pod, str
return 0;
}
static int process_follower_clock(struct data *d, const struct spa_pod *pod, struct point *point)
{
int res;
char val[128];
struct spa_io_clock clock;
res = spa_pod_parse_struct(pod,
SPA_POD_Int(&clock.id),
SPA_POD_Stringn(clock.name, sizeof(clock.name)),
SPA_POD_Long(&clock.nsec),
SPA_POD_Fraction(&clock.rate),
SPA_POD_Long(&clock.position),
SPA_POD_Long(&clock.duration),
SPA_POD_Long(&clock.delay),
SPA_POD_Double(&clock.rate_diff),
SPA_POD_Long(&clock.next_nsec),
SPA_POD_Long(&clock.xrun));
if (d->json_dump) {
fprintf(stdout, "{ \"type\": \"followerClock\", \"id\": %u, "
"\"name\": \"%s\", \"nsec\": %"PRIu64", \"rate\": \"%u/%u\", "
"\"position\": %"PRIu64", \"duration\": %"PRIu64", "
"\"delay\": %"PRIu64", \"diff\": %s, \"next_nsec\": %"PRIu64", "
"\"xrun\": %"PRIu64" },\n",
clock.id, clock.name,
clock.nsec, clock.rate.num, clock.rate.denom,
clock.position, clock.duration,
clock.delay,
spa_json_format_float(val, sizeof(val), (float)clock.rate_diff),
clock.next_nsec, clock.xrun);
}
return res;
}
static void dump_point(struct data *d, struct point *point)
{
int i;
@ -511,6 +562,9 @@ static void profiler_profile(void *data, const struct spa_pod *pod)
case SPA_PROFILER_followerBlock:
process_follower_block(d, &p->value, &point);
break;
case SPA_PROFILER_followerClock:
process_follower_clock(d, &p->value, &point);
break;
default:
break;
}