#include <limits.h>
#include <math.h>
#include <pthread.h>
+#include <stdarg.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
conn->connection_number);
}
+char line_of_stats[1024];
+int statistics_row; // statistics_line 0 means print the headings; anything else 1 means print the
+ // values. Set to 0 the first time out.
+int statistics_column; // used to index through the statistics_print_profile array to check if it
+ // should be printed
+int was_a_previous_column;
+int *statistics_print_profile;
+
+// these arrays specify which of the statistics specified by the statistics_item calls will actually
+// be printed -- 1 means print, 0 means skip
+int ap1_synced_statistics_print_profile[] = {1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1};
+int ap1_nosync_statistics_print_profile[] = {1, 0, 0, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 1, 1, 0};
+int ap1_nodelay_statistics_print_profile[] = {0, 0, 0, 1, 1, 1, 1, 1, 0, 1, 1, 1, 1, 0, 1, 1, 0};
+
+int ap2_realtime_synced_stream_statistics_print_profile[] = {1, 1, 1, 1, 1, 1, 1, 1, 1,
+ 1, 1, 0, 0, 1, 0, 0, 0};
+int ap2_realtime_nosync_stream_statistics_print_profile[] = {1, 0, 0, 1, 1, 1, 1, 1, 1,
+ 1, 1, 0, 0, 0, 0, 0, 0};
+int ap2_realtime_nodelay_stream_statistics_print_profile[] = {0, 0, 0, 1, 1, 1, 1, 1, 0,
+ 1, 1, 0, 0, 0, 0, 0, 0};
+
+int ap2_buffered_synced_stream_statistics_print_profile[] = {1, 1, 1, 1, 0, 0, 0, 0, 1,
+ 1, 1, 0, 0, 1, 0, 0, 0};
+int ap2_buffered_nosync_stream_statistics_print_profile[] = {1, 0, 0, 1, 0, 0, 0, 0, 1,
+ 1, 1, 0, 0, 0, 0, 0, 0};
+int ap2_buffered_nodelay_stream_statistics_print_profile[] = {0, 0, 0, 1, 0, 0, 0, 0, 0,
+ 1, 1, 0, 0, 0, 0, 0, 0};
+
+void statistics_item(const char *heading, const char *format, ...) {
+ if (statistics_print_profile[statistics_column] == 1) { // include this column?
+ if (was_a_previous_column != 0)
+ strcat(line_of_stats, ", ");
+ if (statistics_row == 0) {
+ strcat(line_of_stats, heading);
+ } else {
+ char b[1024];
+ b[0] = 0;
+ va_list args;
+ va_start(args, format);
+ vsnprintf(b, sizeof(b), format, args);
+ va_end(args);
+ strcat(line_of_stats, b);
+ }
+ was_a_previous_column = 1;
+ }
+ statistics_column++;
+}
+
void player_thread_cleanup_handler(void *arg) {
rtsp_conn_info *conn = (rtsp_conn_info *)arg;
if (pthread_mutex_trylock(&playing_conn_lock) == 0) {
conn->framesProcessedInThisEpoch = 0;
conn->framesGeneratedInThisEpoch = 0;
conn->correctionsRequestedInThisEpoch = 0;
-
+ statistics_row = 0; // statistics_line 0 means print the headings; anything else 1 means print the
+ // values. Set to 0 the first time out.
if (config.statistics_requested) {
- if ((config.output->delay)) {
- if (config.no_sync == 0) {
- inform("sync error in milliseconds, "
- "net correction in ppm, "
- "corrections in ppm, "
- "total packets, "
- "missing packets, "
- "late packets, "
- "too late packets, "
- "resend requests, "
- "min DAC queue size, "
- "min buffer occupancy, "
- "max buffer occupancy, "
- "source nominal frames per second, "
- "source actual frames per second, "
- "output frames per second, "
- "source clock drift in ppm, "
- "source clock drift sample count, "
- "rough calculated correction in ppm");
+ // decide on what statistics profile to use
+#ifdef CONFIG_AIRPLAY_2
+ if (conn->airplay_type == ap_2) {
+ if (conn->airplay_stream_type == realtime_stream) {
+ if (config.output->delay) {
+ if (config.no_sync == 0)
+ statistics_print_profile = ap2_realtime_synced_stream_statistics_print_profile;
+ else
+ statistics_print_profile = ap2_realtime_nosync_stream_statistics_print_profile;
+ } else {
+ statistics_print_profile = ap2_realtime_nodelay_stream_statistics_print_profile;
+ }
} else {
- inform("sync error in milliseconds, "
- "total packets, "
- "missing packets, "
- "late packets, "
- "too late packets, "
- "resend requests, "
- "min DAC queue size, "
- "min buffer occupancy, "
- "max buffer occupancy, "
- "source nominal frames per second, "
- "source actual frames per second, "
- "source clock drift in ppm, "
- "source clock drift sample count");
+ if (config.output->delay) {
+ if (config.no_sync == 0)
+ statistics_print_profile = ap2_buffered_synced_stream_statistics_print_profile;
+ else
+ statistics_print_profile = ap2_buffered_nosync_stream_statistics_print_profile;
+ } else {
+ statistics_print_profile = ap2_buffered_nodelay_stream_statistics_print_profile;
+ }
}
} else {
- inform("total packets, "
- "missing packets, "
- "late packets, "
- "too late packets, "
- "resend requests, "
- "min buffer occupancy, "
- "max buffer occupancy, "
- "source nominal frames per second, "
- "source actual frames per second, "
- "source clock drift in ppm, "
- "source clock drift sample count");
+#endif
+ if (config.output->delay) {
+ if (config.no_sync == 0)
+ statistics_print_profile = ap1_synced_statistics_print_profile;
+ else
+ statistics_print_profile = ap1_nosync_statistics_print_profile;
+ } else {
+ statistics_print_profile = ap1_nodelay_statistics_print_profile;
+ }
+// airplay 1 stuff here
+#ifdef CONFIG_AIRPLAY_2
}
+#endif
}
#ifdef CONFIG_AIRPLAY_2
(1.0 * tsum_of_insertions_and_deletions) / number_of_statistics;
// double moving_average_drift = (1.0 * tsum_of_drifts) / number_of_statistics;
// if ((play_number/print_interval)%20==0)
+ // figure out which statistics profile to use, depending on the kind of stream
+
if (config.statistics_requested) {
- if (at_least_one_frame_seen) {
- if ((config.output->delay)) {
- if (config.no_sync == 0) {
- inform(
- "%*.2f," /* Sync error in milliseconds */
- "%*.1f," /* net correction in ppm */
- "%*.1f," /* corrections in ppm */
- "%*d," /* total packets */
- "%*" PRIu64 "," /* missing packets */
- "%*" PRIu64 "," /* late packets */
- "%*" PRIu64 "," /* too late packets */
- "%*" PRIu64 "," /* resend requests */
- "%*" PRIu64 "," /* min DAC queue size */
- "%*" PRId32 "," /* min buffer occupancy */
- "%*" PRId32 "," /* max buffer occupancy */
- "%*.2f," /* source nominal frame rate */
- "%*.2f," /* source actual (average) frame rate */
- "%*.2f," /* output frame rate */
- "%*.2f," /* source clock drift */
- "%*d," /* source clock drift sample count */
- "%*.2f", /* rough calculated correction in ppm */
- 10, 1000 * moving_average_sync_error / config.output_rate, 10,
- moving_average_correction * 1000000 / (352 * conn->output_sample_ratio), 10,
- moving_average_insertions_plus_deletions * 1000000 /
- (352 * conn->output_sample_ratio),
- 12, play_number, 7, conn->missing_packets, 7, conn->late_packets, 7,
- conn->too_late_packets, 7, conn->resend_requests, 7, minimum_dac_queue_size,
- 5, minimum_buffer_occupancy, 5, maximum_buffer_occupancy, 11,
- conn->remote_frame_rate, 11, conn->input_frame_rate, 11, conn->frame_rate, 10,
- (conn->local_to_remote_time_gradient - 1.0) * 1000000, 6,
- conn->local_to_remote_time_gradient_sample_count, 10,
- (conn->frame_rate > 0.0)
- ? ((conn->frame_rate - conn->remote_frame_rate *
- conn->output_sample_ratio *
- conn->local_to_remote_time_gradient) *
- 1000000) /
- conn->frame_rate
- : 0.0);
- } else {
- inform("%*.2f," /* Sync error in milliseconds */
- "%*d," /* total packets */
- "%*" PRIu64 "," /* missing packets */
- "%*" PRIu64 "," /* late packets */
- "%*" PRIu64 "," /* too late packets */
- "%*" PRIu64 "," /* resend requests */
- "%*" PRIu64 "," /* min DAC queue size */
- "%*" PRId32 "," /* min buffer occupancy */
- "%*" PRId32 "," /* max buffer occupancy */
- "%*.2f," /* source nominal frame rate */
- "%*.2f," /* source actual (average) frame rate */
- "%*.2f," /* source clock drift */
- "%*d", /* source clock drift sample count */
- 10, 1000 * moving_average_sync_error / config.output_rate, 12, play_number,
- 7, conn->missing_packets, 7, conn->late_packets, 7, conn->too_late_packets,
- 7, conn->resend_requests, 7, minimum_dac_queue_size, 5,
- minimum_buffer_occupancy, 5, maximum_buffer_occupancy, 11,
- conn->remote_frame_rate, 11, conn->input_frame_rate, 10,
- (conn->local_to_remote_time_gradient - 1.0) * 1000000, 6,
- conn->local_to_remote_time_gradient_sample_count);
- }
- } else {
- inform("%*d," /* total packets */
- "%*" PRIu64 "," /* missing packets */
- "%*" PRIu64 "," /* late packets */
- "%*" PRIu64 "," /* too late packets */
- "%*" PRIu64 "," /* resend requests */
- "%*" PRId32 "," /* min buffer occupancy */
- "%*" PRId32 "," /* max buffer occupancy */
- "%*.2f," /* source nominal frame rate */
- "%*.2f," /* source actual (average) frame rate */
- "%*.2f," /* source clock drift */
- "%*d", /* source clock drift sample count */
- 12, play_number, 7, conn->missing_packets, 7, conn->late_packets, 7,
- conn->too_late_packets, 7, conn->resend_requests, 5,
- minimum_buffer_occupancy, 5, maximum_buffer_occupancy, 11,
- conn->remote_frame_rate, 11, conn->input_frame_rate, 10,
- (conn->local_to_remote_time_gradient - 1.0) * 1000000, 6,
- conn->local_to_remote_time_gradient_sample_count);
- }
+ if (at_least_one_frame_seen) {
+ do {
+ line_of_stats[0] = '\0';
+ statistics_column = 0;
+ was_a_previous_column = 0;
+ statistics_item("sync error ms", "%*.2f", 13,
+ 1000 * moving_average_sync_error / config.output_rate);
+ statistics_item("net sync ppm", "%*.1f", 12,
+ moving_average_correction * 1000000 /
+ (352 * conn->output_sample_ratio));
+ statistics_item("all sync ppm", "%*.1f", 12,
+ moving_average_insertions_plus_deletions * 1000000 /
+ (352 * conn->output_sample_ratio));
+ statistics_item(" packets", "%*d", 11, play_number);
+ statistics_item("missing", "%*" PRIu64 "", 7, conn->missing_packets);
+ statistics_item(" late", "%*" PRIu64 "", 6, conn->late_packets);
+ statistics_item("too late", "%*" PRIu64 "", 8, conn->too_late_packets);
+ statistics_item("resend reqs", "%*" PRIu64 "", 11, conn->resend_requests);
+ statistics_item("min DAC queue", "%*" PRIu64 "", 13, minimum_dac_queue_size);
+ statistics_item("min buffers", "%*" PRIu32 "", 11, minimum_buffer_occupancy);
+ statistics_item("max buffers", "%*" PRIu32 "", 11, maximum_buffer_occupancy);
+ statistics_item("source nominal frames per second", "%*.2f", 10,
+ conn->remote_frame_rate);
+ statistics_item("source actual frames per second", "%*.2f", 10,
+ conn->input_frame_rate);
+ statistics_item("output fps", "%*.2f", 10, conn->frame_rate);
+ statistics_item("source clock drift ppm", "%*.2f", 9,
+ (conn->local_to_remote_time_gradient - 1.0) * 1000000);
+ statistics_item("source clock drift samples", "%*d", 5,
+ conn->local_to_remote_time_gradient_sample_count);
+ statistics_item(
+ "rough calculated correction in ppm", "%*.2f", 9,
+ (conn->frame_rate > 0.0)
+ ? ((conn->frame_rate - conn->remote_frame_rate * conn->output_sample_ratio *
+ conn->local_to_remote_time_gradient) *
+ 1000000) /
+ conn->frame_rate
+ : 0.0);
+ statistics_row++;
+ inform(line_of_stats);
+ } while (statistics_row < 2);
} else {
inform("No frames received in the last sampling interval.");
}
obfp += 2;
};
*obfp = 0;
-
-
+
+
// get raw timestamp information
// I think that a good way to understand these timestamps is that
// (1) the rtlt below is the timestamp of the frame that should be playing at the
// Thus, (3) the latency can be calculated by subtracting the second from the
// first.
// There must be more to it -- there something missing.
-
+
// In addition, it seems that if the value of the short represented by the second
// pair of bytes in the packet is 7
// then an extra time lag is expected to be added, presumably by
// the AirPort Express.
-
+
// Best guess is that this delay is 11,025 frames.
-
+
uint32_t rtlt = nctohl(&packet[4]); // raw timestamp less latency
uint32_t rt = nctohl(&packet[16]); // raw timestamp
-
+
uint32_t fl = nctohs(&packet[2]); //
-
+
debug(1,"Sync Packet of %d bytes received: \"%s\", flags: %d, timestamps %u and %u,
giving a latency of %d frames.",plen,obf,fl,rt,rtlt,rt-rtlt);
//debug(1,"Monotonic timestamps are: %" PRId64 " and %" PRId64 "
// we know its local time, so we use the new clocks's offset to
// calculate what time that must be on the new clock
- // but if the master clock has become equal to the actual anchor clock
- // then we can reinstate it all
- // first, calculate the cumulative offset after swapping all the clocks...
+ // Now, the thing is that while the anchor clock and master clock for a
+ // buffered session starts off the same,
+ // the master clock can change without the anchor clock changing.
+ // SPS allows the new master clock time to settle down and then
+ // calculates the appropriate offset to it by
+ // calculating back from the local anchor information and the new clock's
+ // advertised offset. Of course, small errors will occur.
+ // More importantly, the new master clock(s) and the original one will
+ // drift at different rates. So, after all this, if the original master
+ // clock becomes the master again, then there could be quite a difference
+ // in the time information that was calculated through all the clock
+ // changes and the actual master clock's time information.
+ // What do we do? We can hardly ignore this new and reliable information
+ // so we'll take it. Maybe we should add code to slowly correct towards it
+ // but at present, we just take it.
+
+ // So, if the master clock has again become equal to the actual anchor clock
+ // then we can reinstate it all.
+ // first, let us calculate the cumulative offset after swapping all the clocks...
conn->anchor_time = conn->last_anchor_local_time + actual_offset;
- // we can check how much of a deviation there was going from clock to clock and bakc around to the master clock
+ // we can check how much of a deviation there was going from clock to clock and back
+ // around to the master clock
if (actual_clock_id == conn->actual_anchor_clock) {
- int64_t cumulative_deviation = conn->actual_anchor_time - conn->anchor_time;
- debug(1, "Master clock has become equal to the anchor clock. The actual clock is %f ms ahead/behind (+/-) the calculated clock.", 0.000001 * cumulative_deviation);
+ int64_t cumulative_deviation = conn->anchor_time - conn->actual_anchor_time;
+ debug(1,
+ "Master clock has become equal to the anchor clock. The estimated clock time "
+ "was %f ms ahead(+) or behind (-) the real clock time.",
+ 0.000001 * cumulative_deviation);
conn->anchor_clock = conn->actual_anchor_clock;
conn->anchor_time = conn->actual_anchor_time;
conn->anchor_rtptime = conn->actual_anchor_rtptime;
projects / thirdparty / shairport-sync.git / commitdiff
