From: Mike Brady <4265913+mikebrady@users.noreply.github.com> Date: Wed, 5 May 2021 17:33:21 +0000 (+0100) Subject: Slightly better timing. Bumped version for ejurgensen's new pair_ap work. X-Git-Tag: 4.0-dev~28 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=fd4cc98abaeb1c322e87fb56f348307bcfb8ab9b;p=thirdparty%2Fshairport-sync.git Slightly better timing. Bumped version for ejurgensen's new pair_ap work. --- diff --git a/configure.ac b/configure.ac index fdeaa139..087ef5a6 100644 --- a/configure.ac +++ b/configure.ac @@ -2,7 +2,7 @@ # Process this file with autoconf to produce a configure script. AC_PREREQ([2.50]) -AC_INIT([shairport-sync], [4.0d1], [4265913+mikebrady@users.noreply.github.com]) +AC_INIT([shairport-sync], [4.0d2], [4265913+mikebrady@users.noreply.github.com]) AM_INIT_AUTOMAKE AC_CONFIG_SRCDIR([shairport.c]) AC_CONFIG_HEADERS([config.h]) diff --git a/player.c b/player.c index e8d79115..24640c5a 100644 --- a/player.c +++ b/player.c @@ -442,6 +442,8 @@ void player_put_packet(int original_format, seq_t seqno, uint32_t actual_timesta conn->ab_write = seqno; conn->ab_read = seqno; conn->ab_synced = 1; + conn->first_packet_timestamp = 0; + debug(1,"synced by first packet"); } else if (original_format == 0) { // if the packet is coming in original format, the sequence number is important // otherwise, ignore is by setting it equal to the expected sequence number in ab_write @@ -1279,7 +1281,7 @@ static abuf_t *buffer_get_frame(rtsp_conn_info *conn) { if (do_wait == 0) if ((conn->ab_synced != 0) && (conn->ab_read == conn->ab_write)) { // the buffer is empty! if (notified_buffer_empty == 0) { - debug(3, "Buffers exhausted."); + debug(1, "Buffers exhausted."); notified_buffer_empty = 1; // reset_input_flow_metrics(conn); // don't do a full flush parameters reset conn->initial_reference_time = 0; @@ -1559,11 +1561,11 @@ void player_thread_cleanup_handler(void *arg) { int elapsedMin = (rawSeconds / 60) % 60; int elapsedSec = rawSeconds % 60; if (conn->frame_rate_status) - inform("Playback Stopped. Total playing time %02d:%02d:%02d. Input: %0.2f, output: %0.2f " - "frames per second.", + inform("Connection %d: Playback Stopped. Total playing time %02d:%02d:%02d. Input: %0.2f, output: %0.2f " + "frames per second.", conn->connection_number, elapsedHours, elapsedMin, elapsedSec, conn->input_frame_rate, conn->frame_rate); else - inform("Playback Stopped. Total playing time %02d:%02d:%02d. Input: %0.2f frames per second.", + inform("Connection %d: Playback Stopped. Total playing time %02d:%02d:%02d. Input: %0.2f frames per second.", conn->connection_number, elapsedHours, elapsedMin, elapsedSec, conn->input_frame_rate); } @@ -2280,7 +2282,7 @@ void *player_thread_func(void *arg) { int64_t filler_length = (int64_t)(config.resyncthreshold * config.output_rate); // number of samples if ((sync_error > 0) && (sync_error > filler_length)) { - debug(2, "Large positive sync error: %" PRId64 ".", sync_error); + debug(1, "Large positive sync error of: %" PRId64 " frames (%f seconds).", sync_error, (sync_error * 1.0)/config.output_rate); int64_t local_frames_to_drop = sync_error / conn->output_sample_ratio; uint32_t frames_to_drop_sized = local_frames_to_drop; @@ -2292,10 +2294,10 @@ void *player_thread_func(void *arg) { debug_mutex_unlock(&conn->flush_mutex, 3); } else if ((sync_error < 0) && ((-sync_error) > filler_length)) { - debug(2, - "Large negative sync error: %" PRId64 " with should_be_frame_32 of %" PRIu32 + debug(1, + "Large negative sync error of: %" PRId64 " frames (%f seconds), with should_be_frame_32 of %" PRIu32 ", nt of %" PRId64 " and current_delay of %" PRId64 ".", - sync_error, should_be_frame_32, + sync_error, (sync_error * 1.0)/config.output_rate, should_be_frame_32, inframe->given_timestamp * conn->output_sample_ratio, current_delay); int64_t silence_length = -sync_error; if (silence_length > (filler_length * 5)) diff --git a/rtp.c b/rtp.c index 06c7324d..182d19ba 100644 --- a/rtp.c +++ b/rtp.c @@ -290,8 +290,8 @@ void *rtp_control_receiver(void *arg) { 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 @@ -302,19 +302,19 @@ void *rtp_control_receiver(void *arg) { // 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 " @@ -2065,8 +2065,9 @@ void *rtp_buffered_audio_processor(void *arg) { get_audio_buffer_size_and_occupancy(&player_buffer_size, &player_buffer_occupancy, conn); // debug(1,"player buffer size and occupancy: %u and %u", player_buffer_size, // player_buffer_occupancy); + double reqested_lead_time = 0.4; // if (player_buffer_occupancy > - ((0.25 + 0.1) * 44100.0 / 352)) { // must be greater than the lead time. + ((reqested_lead_time + 0.1) * 44100.0 / 352)) { // must be greater than the lead time. // if there is enough stuff in the player's buffer, sleep for a while and try again // debug(1,"sleep for 20 ms"); usleep(20000); // wait for a while @@ -2089,8 +2090,7 @@ void *rtp_buffered_audio_processor(void *arg) { 0) { int64_t lead_time = buffer_should_be_time - get_absolute_time_in_ns(); // debug(1,"lead time in buffered_audio is %f milliseconds.", lead_time * 0.000001); - // ask for 0.5 sec of leadtime - if ((lead_time >= (int64_t)(0.25 * 1000000000)) || (streaming_has_started == 1)) { + if ((lead_time >= (int64_t)(reqested_lead_time * 1000000000)) || (streaming_has_started == 1)) { if (streaming_has_started == 0) debug(1, "rtp lead time is %f ms.", 0.000001 * lead_time); streaming_has_started = 1; diff --git a/rtsp.c b/rtsp.c index ade66145..74a1249a 100644 --- a/rtsp.c +++ b/rtsp.c @@ -3163,6 +3163,7 @@ static void handle_announce(rtsp_conn_info *conn, rtsp_message *req, rtsp_messag #ifdef CONFIG_AIRPLAY_2 conn->airplay_type = ap_1; conn->timing_type = ts_ntp; + debug(1, "Connection %d. AirPlay 1 Audio Stream Detected.", conn->connection_number); #endif conn->stream.type = ast_unknown;