From: Mike Brady Date: Sun, 5 Aug 2018 16:23:07 +0000 (+0100) Subject: Begin to use a unified and more accurate scheme for translating between local time... X-Git-Tag: 3.3RC0~273 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=3870195cf987ebf9f96244107f0bdecdf4f1ea55;p=thirdparty%2Fshairport-sync.git Begin to use a unified and more accurate scheme for translating between local time and rtp timestamp, taking clock drift and actualt source rate into account if available. Not dealing with highes output rates yet. --- diff --git a/player.c b/player.c index 3dd1ac4b..51a59ef4 100644 --- a/player.c +++ b/player.c @@ -494,8 +494,7 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp debug(3, "Dropping flushed packet in player_put_packet, seqno %u, timestamp %lld, flushing to " "timestamp: %lld.", - seqno, ltimestamp, conn->flush_rtp_timestamp); - + seqno, ltimestamp, conn->flush_rtp_timestamp); } else { if ((conn->flush_rtp_timestamp != 0x0) && (ltimestamp > conn->flush_rtp_timestamp)) // if we have gone past the flush boundary time @@ -527,11 +526,11 @@ void player_put_packet(seq_t seqno, uint32_t actual_timestamp, int64_t timestamp if (conn->ab_write == seqno) { // expected packet uint64_t reception_time = get_absolute_time_in_fp(); - if ((conn->packet_count_since_flush>=145) && (conn->packet_count_since_flush<=155)) { + if ((conn->packet_count_since_flush>=500) && (conn->packet_count_since_flush<=510)) { conn->frames_inward_measurement_start_time = reception_time; conn->frames_inward_frames_received_at_measurement_start_time = timestamp; conn->input_frame_rate_status = 1; // valid now - debug(1,"frames_inward_measurement_start_time set"); + // debug(1,"frames_inward_measurement_start_time set"); } conn->frames_inward_measurement_time = reception_time; @@ -911,7 +910,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { // debug(1,"First frame seen, time %u, with %d // frames...",curframe->timestamp,seq_diff(ab_read, ab_write)); - if (reference_timestamp) { // if we have a reference time + if (have_timestamp_timing_information(conn)) { // if we have a reference time // debug(1,"First frame seen with timestamp..."); conn->first_packet_timestamp = curframe->timestamp; // we will keep buffering until we are @@ -951,6 +950,9 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { // -4410 frames. // debug(1, "Output sample ratio is %d", conn->output_sample_ratio); + + + // what we are asking for here is "what is the local time at which time the calculated frame should be played" int64_t delta = (conn->first_packet_timestamp - reference_timestamp) + conn->latency * conn->output_sample_ratio + @@ -964,9 +966,23 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { int64_t abs_delta = -delta; int64_t delta_fp_sec = (abs_delta << 32) / config.output_rate; // int64_t which is positive - conn->first_packet_time_to_play = reference_timestamp_time - delta_fp_sec; + conn->first_packet_time_to_play = reference_timestamp_time - delta_fp_sec; } + uint64_t should_be_time; + frame_to_local_time(conn->first_packet_timestamp +conn->latency * conn->output_sample_ratio + (int64_t)(config.audio_backend_latency_offset * config.output_rate),&should_be_time,conn); + + if(should_be_time>=conn->first_packet_time_to_play) { + if ((((should_be_time-conn->first_packet_time_to_play)*1000000)>>32)>10) + debug(1,"New time for first packet timestamp %" PRId64 " is later than calculated time by %" PRId64 " microseconds.",curframe->timestamp,((should_be_time-conn->first_packet_time_to_play)*1000000)>>32); + } else { + if ((((conn->first_packet_time_to_play-should_be_time)*1000000)>>32)>10) + debug(1,"New time for first packet timestamp %" PRId64 " is earlier than calculated time by %" PRId64 " microseconds.",curframe->timestamp,((conn->first_packet_time_to_play-should_be_time)*1000000)>>32); + } + + // cut over to new calculation scheme + conn->first_packet_time_to_play = should_be_time; + if (local_time_now >= conn->first_packet_time_to_play) { debug( 1, @@ -993,6 +1009,19 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { (abs_delta << 32) / config.output_rate; // int64_t which is positive conn->first_packet_time_to_play = reference_timestamp_time - delta_fp_sec; } + + uint64_t should_be_time; + frame_to_local_time(conn->first_packet_timestamp +conn->latency * conn->output_sample_ratio + (int64_t)(config.audio_backend_latency_offset * config.output_rate),&should_be_time,conn); + + if(should_be_time>=conn->first_packet_time_to_play) { + if ((((should_be_time-conn->first_packet_time_to_play)*1000000)>>32)>50) + debug(1,"New time for recalculated first packet timestamp %" PRId64 " is later than calculated time by %" PRId64 " microseconds.",curframe->timestamp,((should_be_time-conn->first_packet_time_to_play)*1000000)>>32); + } else { + if ((((conn->first_packet_time_to_play-should_be_time)*1000000)>>32)>50) + debug(1,"New time for recalculated first packet timestamp %" PRId64 " is earlier than calculated time by %" PRId64 " microseconds.",curframe->timestamp,((conn->first_packet_time_to_play-should_be_time)*1000000)>>32); + } + + // now, the size of the initial silence must be affected by the lead-in time. // it must be somewhat less than the lead-in time so that dynamic adjustments can be @@ -1140,12 +1169,14 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { } } if (conn->ab_buffering == 0) { + /* // note the time of the playing of the first frame uint64_t reference_timestamp_time; // don't need this... get_reference_timestamp_stuff(&conn->play_segment_reference_frame, &reference_timestamp_time, &conn->play_segment_reference_frame_remote_time, conn); conn->play_segment_reference_frame *= conn->output_sample_ratio; + */ #ifdef CONFIG_METADATA debug(2, "prsm"); send_ssnc_metadata('prsm', NULL, 0, @@ -1172,12 +1203,14 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { if ((conn->ab_synced) && (curframe) && (curframe->ready) && (curframe->timestamp)) { do_wait = 1; // if the current frame exists and is ready, then wait unless it's time to let it go... + + // here, get the time to play the current frame. int64_t reference_timestamp; uint64_t reference_timestamp_time, remote_reference_timestamp_time; get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, &remote_reference_timestamp_time, conn); // all types okay reference_timestamp *= conn->output_sample_ratio; - if (reference_timestamp) { // if we have a reference time + if (have_timestamp_timing_information(conn)) { // if we have a reference time int64_t packet_timestamp = curframe->timestamp; // types okay int64_t delta = packet_timestamp - reference_timestamp; int64_t offset = @@ -1186,6 +1219,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { config.audio_backend_buffer_desired_length * config.output_rate; // all arguments are int32_t, so expression promotion okay int64_t net_offset = delta + offset; // okay + uint64_t time_to_play = reference_timestamp_time; // type okay if (net_offset >= 0) { uint64_t net_offset_fp_sec = @@ -1199,7 +1233,20 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { time_to_play -= net_offset_fp_sec; // debug(2,"Net Offset: %lld, adjusted: -%lld.",net_offset,net_offset_fp_sec); } - + + uint64_t new_time_to_play = 0; + frame_to_local_time(packet_timestamp+offset, &new_time_to_play, conn); + + if(new_time_to_play>=time_to_play) { + if ((((new_time_to_play-time_to_play)*1000000)>>32)>100) + debug(1,"New time for frame %" PRId64 " is later than calculated time by %" PRId64 " microseconds.",curframe->timestamp,((new_time_to_play-time_to_play)*1000000)>>32); + } else { + if ((((time_to_play-new_time_to_play)*1000000)>>32)>100) + debug(1,"New time for frame %" PRId64 " is earlier than calculated time by %" PRId64 " microseconds.",curframe->timestamp,((time_to_play-new_time_to_play)*1000000)>>32); + } + // cut over to the new calculation system + time_to_play = new_time_to_play; + if (local_time_now >= time_to_play) { do_wait = 0; } @@ -1583,7 +1630,7 @@ void *player_thread_func(void *arg) { debug(3, "Output frame bytes is %d.", conn->output_bytes_per_frame); conn->session_corrections = 0; - conn->play_segment_reference_frame = 0; // zero signals that we are not in a play segment + // conn->play_segment_reference_frame = 0; // zero signals that we are not in a play segment // check that there are enough buffers to accommodate the desired latency and the latency offset @@ -1739,7 +1786,8 @@ void *player_thread_func(void *arg) { "min buffer occupancy, " "max buffer occupancy, " "input frames per second, " - "output frames per second."); + "output frames per second, " + "drift client vs local clock in ppm"); } else { inform("sync error in milliseconds, " "total packets, " @@ -1937,10 +1985,10 @@ void *player_thread_func(void *arg) { // uint64_t // local_time_now=((uint64_t)tn.tv_sec<<32)+((uint64_t)tn.tv_nsec<<32)/1000000000; - int64_t td = 0; - int64_t td_in_frames = 0; + int64_t td = 0; // td is the time difference between the reference timestamp time and the present time. Only used to calculate td_in_frames + int64_t td_in_frames = 0; // td_in_frames is the number of frames between between the reference timestamp time and the present time + if (local_time_now >= reference_timestamp_time) { - // debug(1,"td is %lld.",td); td = local_time_now - reference_timestamp_time; // this is the positive value. // Conversion is positive uint64_t to // int64_t, thus okay @@ -2014,9 +2062,20 @@ void *player_thread_func(void *arg) { if (resp >= 0) { + int64_t should_be_frame; + local_time_to_frame(local_time_now,&should_be_frame,conn); + + if (abs(td_in_frames + rt-should_be_frame)>10) + debug(1,"Difference between old and new frame number is %" PRId64 " frames.",td_in_frames + rt - should_be_frame); // this is the actual delay, including the latency we actually want, which will // fluctuate a good bit about a potentially rising or falling trend. - int64_t delay = td_in_frames + rt - (nt - current_delay); // all int64_t + +// int64_t delay = td_in_frames + rt - (nt - current_delay); // all int64_t + // cut over to the new calculation method + int64_t delay = should_be_frame - (nt - current_delay); // all int64_t + + // td_in_frames + rt is the frame number that should be output at local_time_now. + // This is the timing error for the next audio frame in the DAC. @@ -2344,7 +2403,7 @@ void *player_thread_func(void *arg) { if ((config.output->delay)) { if (config.no_sync == 0) { - inform("%*.1f," /* Sync error in milliseconds */ + inform("%*.2f," /* Sync error in milliseconds */ "%*.1f," /* net correction in ppm */ "%*.1f," /* corrections in ppm */ "%*d," /* total packets */ @@ -2356,7 +2415,8 @@ void *player_thread_func(void *arg) { "%*d," /* min buffer occupancy */ "%*d," /* max buffer occupancy */ "%*.2f," /* input frame rate */ - "%*.2f", /* output frame rate */ + "%*.2f," /* output frame rate */ + "%*.2f", /* client clock to local clock drift in ppm */ 10, 1000 * moving_average_sync_error / config.output_rate, 10, moving_average_correction * 1000000 / (352 * conn->output_sample_ratio), @@ -2365,9 +2425,9 @@ void *player_thread_func(void *arg) { 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->input_frame_rate, 11, conn->frame_rate); + maximum_buffer_occupancy, 11, conn->input_frame_rate, 11, conn->frame_rate , 10, (1.0-conn->local_to_remote_time_gradient)*1000000); } else { - inform("%*.1f," /* Sync error in milliseconds */ + inform("%*.2f," /* Sync error in milliseconds */ "%*d," /* total packets */ "%*llu," /* missing packets */ "%*llu," /* late packets */ @@ -2384,7 +2444,7 @@ void *player_thread_func(void *arg) { minimum_buffer_occupancy, 5, maximum_buffer_occupancy, 11, conn->input_frame_rate); } } else { - inform("%*.1f," /* Sync error in milliseconds */ + inform("%*.2f," /* Sync error in milliseconds */ "%*d," /* total packets */ "%*llu," /* missing packets */ "%*llu," /* late packets */ @@ -2661,9 +2721,10 @@ void do_flush(int64_t timestamp, rtsp_conn_info *conn) { conn->flush_requested = 1; // if (timestamp!=0) conn->flush_rtp_timestamp = timestamp; // flush all packets up to (and including?) this - conn->play_segment_reference_frame = 0; + // conn->play_segment_reference_frame = 0; conn->play_number_after_flush = 0; conn->packet_count_since_flush = 0; + debug_mutex_unlock(&conn->flush_mutex, 3); #ifdef CONFIG_METADATA diff --git a/player.h b/player.h index 134cba26..5402a18f 100644 --- a/player.h +++ b/player.h @@ -24,13 +24,15 @@ #include "alac.h" #include "audio.h" -#define time_ping_history 8 +#define time_ping_history 32 typedef struct time_ping_record { uint64_t local_to_remote_difference; uint64_t dispersion; uint64_t local_time; uint64_t remote_time; + int sequence_number; + int chosen; } time_ping_record; typedef uint16_t seq_t; @@ -182,14 +184,21 @@ typedef struct { uint16_t local_timing_port; int64_t latency_delayed_timestamp; // this is for debugging only... + + // this is what connects an rtp timestamp to the remote time + int64_t reference_timestamp; - uint64_t reference_timestamp_time; - uint64_t remote_reference_timestamp_time; + uint64_t remote_reference_timestamp_time; + + // the ratio of the following should give us the operating rate, nominally 44,100 + int64_t reference_to_previous_frame_difference; + uint64_t reference_to_previous_time_difference; + // debug variables int request_sent; - uint8_t time_ping_count; + int time_ping_count; struct time_ping_record time_pings[time_ping_history]; uint64_t departure_time; // dangerous -- this assumes that there will never be two timing @@ -197,12 +206,14 @@ typedef struct { pthread_mutex_t reference_time_mutex; + double local_to_remote_time_gradient; // if no drift, this would be exactly 1.0; likely it's slightly above or below. uint64_t local_to_remote_time_difference; // used to switch between local and remote clocks + uint64_t local_to_remote_time_difference_measurement_time; // when the above was calculated int last_stuff_request; - int64_t play_segment_reference_frame; - uint64_t play_segment_reference_frame_remote_time; + // int64_t play_segment_reference_frame; + // uint64_t play_segment_reference_frame_remote_time; int32_t buffer_occupancy; // allow it to be negative because seq_diff may be negative int64_t session_corrections; diff --git a/rtp.c b/rtp.c index c86d3fa0..ef053e9b 100644 --- a/rtp.c +++ b/rtp.c @@ -45,8 +45,8 @@ #include #include -uint64_t local_to_remote_time_jitters; -uint64_t local_to_remote_time_jitters_count; +uint64_t local_to_remote_time_jitter; +uint64_t local_to_remote_time_jitter_count; void rtp_initialise(rtsp_conn_info *conn) { conn->rtp_time_of_last_resend_request_error_fp = 0; @@ -65,6 +65,27 @@ void rtp_terminate(rtsp_conn_info *conn) { debug(1, "Error destroying reference_time_mutex variable."); } +uint64_t local_to_remote_time_difference_now(rtsp_conn_info *conn) { + // this is an attempt to compensate for clock drift since the last time ping that was used + // so, if we have a non-zero clock drift, we will calculate the drift there would + // be from the time of the last time ping + uint64_t local_time_now_fp = get_absolute_time_in_fp(); + uint64_t time_since_last_local_to_remote_time_difference_measurement = local_time_now_fp - conn->local_to_remote_time_difference_measurement_time; + + uint64_t remote_time_since_last_local_to_remote_time_difference_measurement = (uint64_t)(conn->local_to_remote_time_gradient*time_since_last_local_to_remote_time_difference_measurement); + + double drift; + if (remote_time_since_last_local_to_remote_time_difference_measurement >= time_since_last_local_to_remote_time_difference_measurement) + drift = (1.0*(remote_time_since_last_local_to_remote_time_difference_measurement - time_since_last_local_to_remote_time_difference_measurement))/(uint64_t)0x100000000; + else + drift = -((1.0*(time_since_last_local_to_remote_time_difference_measurement - remote_time_since_last_local_to_remote_time_difference_measurement))/(uint64_t)0x100000000); + + double interval_ms = 1.0*(((time_since_last_local_to_remote_time_difference_measurement)*1000)>>32); +// debug(1,"Measurement drift is %.2f microseconds (0x%" PRIx64 " in 64-bit fp) over %.2f milliseconds with drift of %.2f ppm.",drift*1000000,(uint64_t)(drift*(uint64_t)0x100000000),interval_ms,(1.0-conn->local_to_remote_time_gradient)*1000000); +// return conn->local_to_remote_time_difference + (uint64_t)(drift*(uint64_t 0x100000000)); + return conn->local_to_remote_time_difference + (uint64_t)(drift*(uint64_t)0x100000000); +} + void rtp_audio_receiver_cleanup_handler(void *arg) { debug(3, "Audio Receiver Cleanup."); rtsp_conn_info *conn = (rtsp_conn_info *)arg; @@ -246,7 +267,7 @@ void *rtp_control_receiver(void *arg) { // 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 packe is 7 + // pair of bytes in the packet is 7 // then an extra time lag is expected to be added, presumably by // the AirPort Express. @@ -337,28 +358,30 @@ void *rtp_control_receiver(void *arg) { debug_mutex_lock(&conn->reference_time_mutex, 1000, 1); // this is for debugging - // uint64_t old_remote_reference_time = conn->remote_reference_timestamp_time; - // int64_t old_reference_timestamp = conn->reference_timestamp; - // int64_t old_latency_delayed_timestamp = conn->latency_delayed_timestamp; + uint64_t old_remote_reference_time = conn->remote_reference_timestamp_time; + int64_t old_reference_timestamp = conn->reference_timestamp; + int64_t old_latency_delayed_timestamp = conn->latency_delayed_timestamp; + conn->remote_reference_timestamp_time = remote_time_of_sync; - conn->reference_timestamp_time = - remote_time_of_sync - conn->local_to_remote_time_difference; + //conn->reference_timestamp_time = + // remote_time_of_sync - local_to_remote_time_difference_now(conn); conn->reference_timestamp = sync_rtp_timestamp; conn->latency_delayed_timestamp = rtp_timestamp_less_latency; debug_mutex_unlock(&conn->reference_time_mutex, 3); + + conn->reference_to_previous_time_difference = remote_time_of_sync - old_remote_reference_time; + if (old_reference_timestamp==0) + conn->reference_to_previous_frame_difference = 0; + else + conn->reference_to_previous_frame_difference = sync_rtp_timestamp - old_reference_timestamp; - // this is for debugging + int64_t delayed_frame_difference = rtp_timestamp_less_latency - old_latency_delayed_timestamp; + /* - uint64_t time_difference = remote_time_of_sync - old_remote_reference_time; - int64_t reference_frame_difference = sync_rtp_timestamp - old_reference_timestamp; - int64_t delayed_frame_difference = rtp_timestamp_less_latency - - old_latency_delayed_timestamp; - if (old_remote_reference_time) - debug(1,"Time difference: %" PRIu64 " reference and delayed frame differences: %" - PRId64 " - and %" PRId64 ", giving rates of %f and %f respectively.", - (time_difference*1000000)>>32,reference_frame_difference,delayed_frame_difference,(1.0*(reference_frame_difference*10000000))/((time_difference*10000000)>>32),(1.0*(delayed_frame_difference*10000000))/((time_difference*10000000)>>32)); + debug(1,"Time difference: %" PRIu64 " reference and delayed frame differences: %" PRId64 " and %" PRId64 ", giving rates _at source!!_ of %f and %f respectively.", + (conn->reference_to_previous_time_difference*1000000)>>32,conn->reference_to_previous_frame_difference,delayed_frame_difference, + (1.0*(conn->reference_to_previous_frame_difference*10000000))/((conn->reference_to_previous_time_difference*10000000)>>32),(1.0*(delayed_frame_difference*10000000))/((conn->reference_to_previous_time_difference*10000000)>>32)); else debug(1,"First sync received"); */ @@ -493,14 +516,21 @@ void *rtp_timing_receiver(void *arg) { pthread_create(&conn->timer_requester, NULL, &rtp_timing_sender, arg); // struct timespec att; uint64_t distant_receive_time, distant_transmit_time, arrival_time, return_time; - local_to_remote_time_jitters = 0; - local_to_remote_time_jitters_count = 0; + local_to_remote_time_jitter = 0; + local_to_remote_time_jitter_count = 0; // uint64_t first_remote_time = 0; - uint64_t first_local_time = 0; + // uint64_t first_local_time = 0; uint64_t first_local_to_remote_time_difference = 0; // uint64_t first_local_to_remote_time_difference_time; // uint64_t l2rtd = 0; + int sequence_number = 0; + + // for getting mean and sd of return times + int32_t stat_n = 0; + double stat_mean = 0.0; + double stat_M2 = 0.0; + while (1) { nread = recv(conn->timing_socket, packet, sizeof(packet), 0); @@ -548,151 +578,175 @@ void *rtp_timing_receiver(void *arg) { distant_transmit_time = (uint64_t)nctohl(&packet[24]) << 32; distant_transmit_time += nctohl(&packet[28]); - // processing_time = distant_transmit_time - distant_receive_time; - - // debug(1,"Return trip time: %lluuS, remote processing time: - // %lluuS.",(return_time*1000000)>>32,(processing_time*1000000)>>32); - + uint64_t remote_processing_time = distant_transmit_time - distant_receive_time; + + //debug(1,"Return trip time: %" PRIu64 " uS, remote processing time: %" PRIu64 " uS.",(return_time*1000000)>>32,(remote_processing_time*1000000)>>32); + uint64_t local_time_by_remote_clock = distant_transmit_time + return_time / 2; + + // remove the remote processing time from the record of the return time, as long at the processing time looks sensible. + + if ((remote_processing_time > 0) && (remote_processing_time < return_time)) + return_time -= remote_processing_time; + else + debug(1,"Non-sensical remote processing time -- ignored."); - unsigned int cc; + int cc; for (cc = time_ping_history - 1; cc > 0; cc--) { conn->time_pings[cc] = conn->time_pings[cc - 1]; + //if ((conn->time_ping_count) && (conn->time_ping_count < 10)) +// conn->time_pings[cc].dispersion = +// conn->time_pings[cc].dispersion * pow(2.14, 1.0/conn->time_ping_count); conn->time_pings[cc].dispersion = - (conn->time_pings[cc].dispersion * 110) / - 100; // make the dispersions 'age' by this rational factor + (conn->time_pings[cc].dispersion * 110) / 100; // make the dispersions 'age' by this rational factor } - // these are for diagnostics only -- not used + // these are used for doing a least squares calculation to get the drift conn->time_pings[0].local_time = arrival_time; - conn->time_pings[0].remote_time = distant_transmit_time; + conn->time_pings[0].remote_time = distant_transmit_time; + conn->time_pings[0].sequence_number = sequence_number++; + conn->time_pings[0].chosen = 0; + + conn->time_pings[0].local_to_remote_difference = local_time_by_remote_clock - arrival_time; conn->time_pings[0].dispersion = return_time; if (conn->time_ping_count < time_ping_history) conn->time_ping_count++; - - uint64_t local_time_chosen = arrival_time; - + + // here, calculate the mean and standard deviation of the return times + + // mean and variance calculations from "online_variance" algorithm at + // https://en.wikipedia.org/wiki/Algorithms_for_calculating_variance#Online_algorithm + + double rtfus = 1.0*((return_time * 1000000) >> 32); + stat_n += 1; + double stat_delta = rtfus - stat_mean; + stat_mean += stat_delta / stat_n; + stat_M2 += stat_delta * (rtfus - stat_mean); + //debug(1, "Timing packet return time stats: current, mean and standard deviation over %d packets: %.1f, %.1f, %.1f (microseconds).", + // stat_n,rtfus,stat_mean, sqrtf(stat_M2 / (stat_n - 1))); + + // here, pick the record with the least dispersion, and record that it's been chosen + + // uint64_t local_time_chosen = arrival_time; // uint64_t remote_time_chosen = distant_transmit_time; // now pick the timestamp with the lowest dispersion uint64_t l2rtd = conn->time_pings[0].local_to_remote_difference; + uint64_t lt = conn->time_pings[0].local_time; uint64_t tld = conn->time_pings[0].dispersion; - // chosen = 0; + int chosen = 0; for (cc = 1; cc < conn->time_ping_count; cc++) if (conn->time_pings[cc].dispersion < tld) { + chosen = cc; l2rtd = conn->time_pings[cc].local_to_remote_difference; - // chosen = cc; + lt = conn->time_pings[cc].local_time; tld = conn->time_pings[cc].dispersion; - local_time_chosen = conn->time_pings[cc].local_time; + // local_time_chosen = conn->time_pings[cc].local_time; // remote_time_chosen = conn->time_pings[cc].remote_time; } - // int64_t ji; + // debug(1,"Record %d has the lowest dispersion with %0.2f us dispersion.",chosen,1.0*((tld * 1000000) >> 32)); + conn->time_pings[chosen].chosen = 1; // record the fact that it has been used for timing + // calculate the jitter -- the absolute time between the current local_to_remote_time_difference and the new one and add it to the total jitter count + int64_t ji; + int64_t ltd =0; // local time difference for the jitter + if (conn->time_ping_count > 1) { if (l2rtd > conn->local_to_remote_time_difference) { - local_to_remote_time_jitters = - local_to_remote_time_jitters + l2rtd - conn->local_to_remote_time_difference; - // ji = l2rtd - conn->local_to_remote_time_difference; + local_to_remote_time_jitter = + local_to_remote_time_jitter + l2rtd - conn->local_to_remote_time_difference; + ji = l2rtd - conn->local_to_remote_time_difference; // this is the difference between the present local-to-remote-time-difference and the new one, i.e. the jitter step } else { - local_to_remote_time_jitters = - local_to_remote_time_jitters + conn->local_to_remote_time_difference - l2rtd; - // ji = -(conn->local_to_remote_time_difference - l2rtd); + local_to_remote_time_jitter = + local_to_remote_time_jitter + conn->local_to_remote_time_difference - l2rtd; + ji = -(conn->local_to_remote_time_difference - l2rtd); } - local_to_remote_time_jitters_count += 1; + local_to_remote_time_jitter_count += 1; } - // uncomment below to print jitter between client's clock and oour clock - // int64_t rtus = (tld*1000000)>>32; ji = (ji*1000000)>>32; debug(1,"Choosing time - // difference - // with dispersion of %lld us with delta of %lld us",rtus,ji); - conn->local_to_remote_time_difference = l2rtd; + if (conn->local_to_remote_time_difference_measurement_time < lt) + ltd = lt-conn->local_to_remote_time_difference_measurement_time; + else + ltd = -(conn->local_to_remote_time_difference_measurement_time-lt); + + /* + if (ltd) { + debug(1,"Jitter: %" PRId64 " microseconds in %" PRId64 " microseconds.", (ji * (int64_t)1000000)>>32, (ltd * (int64_t)1000000)>>32); + debug(1,"Source clock to local clock drift: %.2f ppm.",((1.0*ji)/ltd)*1000000.0); + } + // uncomment below to print jitter between client's clock and our clock + */ + + /* + if (ji) { + int64_t rtus = (tld*1000000)>>32; + debug(1,"Choosing time difference[%d] with dispersion of %" PRId64 " us with an adjustment of %" PRId64 " us",chosen, rtus, (ji*1000000)>>32); + } + */ + conn->local_to_remote_time_difference = l2rtd; // make this the new local-to-remote-time-difference + conn->local_to_remote_time_difference_measurement_time = lt; // done at this time. + if (first_local_to_remote_time_difference == 0) { first_local_to_remote_time_difference = conn->local_to_remote_time_difference; // first_local_to_remote_time_difference_time = get_absolute_time_in_fp(); } - // int64_t clock_drift; - // int64_t clock_drift_in_usec; - // double clock_drift_ppm = 0.0; - if (first_local_time == 0) { - first_local_time = local_time_chosen; - // first_remote_time = remote_time_chosen; - // clock_drift = 0; + // here, let's try to use the timing pings that were selected because of their short return times to + // estimate a figure for drift between the local clock (x) and the remote clock (y) + + // if we plug in a local interval, we will get back what that is in remote time + + // calculate the line of best fit for relating the local time and the remote time + // we will calculate the slope, which is the drift + // see https://www.varsitytutors.com/hotmath/hotmath_help/topics/line-of-best-fit + + double m,drift; + + drift = 0.0; + + uint64_t y_bar = 0; // remote timestamp average + uint64_t x_bar = 0; // local timestamp average + int sample_count = 0; + + + for (cc = 0; cc < conn->time_ping_count; cc++) + if ((conn->time_pings[cc].chosen) && (conn->time_pings[cc].sequence_number>9)) { // wait for a minute or so.... + y_bar += (conn->time_pings[cc].remote_time>>12); //precision is down to 1/4th of a microsecond + x_bar += (conn->time_pings[cc].local_time>>12); + sample_count++; + } + + y_bar = y_bar/sample_count; + x_bar = x_bar/sample_count; + + int64_t xid, yid; + int64_t mtl, mbl; + mtl=0;mbl=0; + for (cc = 0; cc < conn->time_ping_count; cc++) + if ((conn->time_pings[cc].chosen) && (conn->time_pings[cc].sequence_number>9)) { + + uint64_t slt = conn->time_pings[cc].local_time>>12; + if (slt > x_bar) + xid = slt - x_bar; + else + xid = -(x_bar - slt); + + uint64_t srt = conn->time_pings[cc].remote_time>>12; + if (srt > y_bar) + yid = srt - y_bar; + else + yid = -(y_bar - srt); + + mtl = mtl + xid*yid; + mbl = mbl + xid*xid; + } + if (sample_count > 2) { + conn->local_to_remote_time_gradient = (1.0*mtl)/mbl; + // debug(1,"Drift is %12.2f ppm, based on %d samples.",(1.0-conn->local_to_remote_time_gradient)*1000000,sample_count); } else { - // uint64_t local_time_change = local_time_chosen - first_local_time; - // uint64_t remote_time_change = remote_time_chosen - first_remote_time; - - /* - if (remote_time_change >= local_time_change) - clock_drift = remote_time_change - local_time_change; - else - clock_drift = -(local_time_change - remote_time_change); - */ - /* - if (clock_drift >= 0) - clock_drift_in_usec = (clock_drift * 1000000) >> 32; - else - clock_drift_in_usec = -(((-clock_drift) * 1000000) >> 32); - */ - - // clock_drift_ppm = (1.0 * clock_drift_in_usec) / (local_time_change >> 32); + conn->local_to_remote_time_gradient = 1.0; } - - int64_t source_drift_usec; - if (conn->play_segment_reference_frame != 0) { - int64_t reference_timestamp; - uint64_t reference_timestamp_time, remote_reference_timestamp_time; - get_reference_timestamp_stuff(&reference_timestamp, &reference_timestamp_time, - &remote_reference_timestamp_time, conn); - uint64_t frame_difference = 0; - if (reference_timestamp >= conn->play_segment_reference_frame) - frame_difference = - (uint64_t)reference_timestamp - (uint64_t)conn->play_segment_reference_frame; - else // rollover - frame_difference = (uint64_t)reference_timestamp + 0x100000000 - - (uint64_t)conn->play_segment_reference_frame; - uint64_t frame_time_difference_calculated = - (((uint64_t)frame_difference << 32) / 44100); - uint64_t frame_time_difference_actual = - remote_reference_timestamp_time - - conn->play_segment_reference_frame_remote_time; // this is all done by reference - // to - // the - // sources' system clock - // debug(1,"%llu frames since play started, %llu usec calculated, %llu usec - // actual",frame_difference, (frame_time_difference_calculated*1000000)>>32, - // (frame_time_difference_actual*1000000)>>32); - if (frame_time_difference_calculated >= - frame_time_difference_actual) // i.e. if the time it should have taken to send the - // packets is greater than the actual time difference - // measured on the source clock - // then the source DAC's clock is running fast relative to the source system clock - source_drift_usec = frame_time_difference_calculated - frame_time_difference_actual; - else - // otherwise the source DAC's clock is running slow relative to the source system - // clock - source_drift_usec = - -(frame_time_difference_actual - frame_time_difference_calculated); - } else - source_drift_usec = 0; - source_drift_usec = (source_drift_usec * 1000000) >> 32; // turn it to microseconds - - // long current_delay = 0; - // if (config.output->delay) { - // config.output->delay(¤t_delay); - //} - // Useful for troubleshooting: - // debug(1, "clock_drift_ppm %f\tchosen %5d\tsource_drift_usec - // %10.1lld\treturn_time_in_usec - // %10.1llu", - // clock_drift_ppm, - // chosen, - //(session_corrections*1000000)/44100, - // current_delay, - // source_drift_usec, - // buffer_occupancy, - //(return_time*1000000)>>32); } else { debug(2, "Time ping turnaround time: %lld us -- it looks like a timing ping was lost.", (return_time * 1000000) >> 32); @@ -902,19 +956,101 @@ void get_reference_timestamp_stuff(int64_t *timestamp, uint64_t *timestamp_time, // types okay debug_mutex_lock(&conn->reference_time_mutex, 1000, 1); *timestamp = conn->reference_timestamp; - *timestamp_time = conn->reference_timestamp_time; + *remote_timestamp_time = conn->remote_reference_timestamp_time; + *timestamp_time = conn->remote_reference_timestamp_time - local_to_remote_time_difference_now(conn); // if ((*timestamp == 0) && (*timestamp_time == 0)) { // debug(1,"Reference timestamp is invalid."); //} - *remote_timestamp_time = conn->remote_reference_timestamp_time; debug_mutex_unlock(&conn->reference_time_mutex, 3); } void clear_reference_timestamp(rtsp_conn_info *conn) { debug_mutex_lock(&conn->reference_time_mutex, 1000, 1); conn->reference_timestamp = 0; - conn->reference_timestamp_time = 0; + conn->remote_reference_timestamp_time = 0; + debug_mutex_unlock(&conn->reference_time_mutex, 3); +} + +int have_timestamp_timing_information(rtsp_conn_info *conn) { + if (conn->reference_timestamp==0) + return 0; + else + return 1; +} + +int sanitised_source_rate_information(int64_t *frames, uint64_t *time, rtsp_conn_info *conn) { + int result = 0; + *frames = conn->input_rate; + *time = (uint64_t)(0x100000000); // one second in fp form + int64_t local_frames = conn->reference_to_previous_frame_difference; + uint64_t local_time = conn->reference_to_previous_time_difference; + if ((local_frames == 0) || (local_time == 0)) { + result = 1; + } else { + double calculated_frame_rate = ((1.0*local_frames)/local_time)*(uint64_t)0x100000000; + if (((calculated_frame_rate/conn->input_rate) > 1.001) || ((calculated_frame_rate/conn->input_rate) < 0.999)) { + result = 1; + } else { + *frames = local_frames; + *time = local_time; + result = 0; + } + } + return result; +} + +int frame_to_local_time(int64_t timestamp, uint64_t *time, rtsp_conn_info *conn) { + debug_mutex_lock(&conn->reference_time_mutex, 1000, 1); + int result = 0; + uint64_t time_difference; + int64_t frame_difference; + result = sanitised_source_rate_information(&frame_difference,&time_difference,conn); + + int64_t timestamp_interval = timestamp - conn->reference_timestamp; // we could be dealing with multiples of 44100 (nominally) + // debug(1, "Timestamp interval: %" PRId64 " frames with reference timestamp %" PRId64 ".",timestamp_interval,conn->reference_timestamp); + uint64_t timestamp_interval_time; + uint64_t remote_time_of_timestamp; + if (timestamp_interval>=0) { + timestamp_interval_time = (timestamp_interval * time_difference)/frame_difference; // this is the nominal time, based on the fps specified between current and previous sync frame. + remote_time_of_timestamp = conn->remote_reference_timestamp_time + timestamp_interval_time; // based on the reference timestamp time plus the time interval calculated based on the specified fps. + } else { + timestamp_interval_time = ((-timestamp_interval) * time_difference)/frame_difference; // this is the nominal time, based on the fps specified between current and previous sync frame. + remote_time_of_timestamp = conn->remote_reference_timestamp_time - timestamp_interval_time; // based on the reference timestamp time plus the time interval calculated based on the specified fps. + } + *time = remote_time_of_timestamp - local_to_remote_time_difference_now(conn); + debug_mutex_unlock(&conn->reference_time_mutex, 3); + return result; +} + +int local_time_to_frame(uint64_t time, int64_t *frame, rtsp_conn_info *conn) { + debug_mutex_lock(&conn->reference_time_mutex, 1000, 1); + int result = 0; + + uint64_t time_difference; + int64_t frame_difference; + result = sanitised_source_rate_information(&frame_difference,&time_difference,conn); + + // first, get from [local] time to remote time. + uint64_t remote_time = time + local_to_remote_time_difference_now(conn); + // next, get the remote time interval from the remote_time to the reference time + uint64_t time_interval; + + if (remote_time >= conn->remote_reference_timestamp_time) + time_interval = remote_time - conn->remote_reference_timestamp_time; + else + time_interval = conn->remote_reference_timestamp_time - remote_time; + + // now, convert the remote time interval into frames + int64_t frame_interval = (time_interval * frame_difference)/time_difference; + if (remote_time >= conn->remote_reference_timestamp_time) { + // debug(1,"Frame interval is %" PRId64 " frames.",frame_interval); + *frame = conn->reference_timestamp+frame_interval; + } else { + // debug(1,"Frame interval is %" PRId64 " frames.",-frame_interval); + *frame = conn->reference_timestamp-frame_interval; + } debug_mutex_unlock(&conn->reference_time_mutex, 3); + return result; } void rtp_request_resend(seq_t first, uint32_t count, rtsp_conn_info *conn) { diff --git a/rtp.h b/rtp.h index 743cff52..13bf2b3f 100644 --- a/rtp.h +++ b/rtp.h @@ -21,4 +21,13 @@ void get_reference_timestamp_stuff(int64_t *timestamp, uint64_t *timestamp_time, uint64_t *remote_timestamp_time, rtsp_conn_info *conn); void clear_reference_timestamp(rtsp_conn_info *conn); +int have_timestamp_timing_information(rtsp_conn_info *conn); + +int get_frame_play_time(int64_t timestamp, int sample_ratio, uint64_t *time_to_play); + +int frame_to_local_time(int64_t timestamp, uint64_t *time, rtsp_conn_info *conn); +int local_time_to_frame(uint64_t time, int64_t *frame, rtsp_conn_info *conn); + +int sanitised_source_rate_information(int64_t *frames, uint64_t *time, rtsp_conn_info *conn); + #endif // _RTP_H