Airplay 2 consistently going out of sync

grappelli commented 2 years ago

Hi there!

I built the dev version of shairport-sync at the end of last year on a pi3b running raspbian lite and that was working really perfectly but unfortunately I managed to ruin that by getting greedy and running other stuff on the pi3b that ended up breaking.

Since deciding to rebuild the pi with only shairport-sync and nothing else at the end of last week, I've been having considerable issues with the audio being out of sync.

The audio source is a homepod OG with Apple music. Pausing and resuming a song seems to correct the issue but almost each new song change (by requesting a new song, or just letting it play through) will cause an even greater difference in the synced audio.

EDIT: If I let it play through to the next song after a while(something like a few songs, which I have manually put back into sync by pausing and resuming) .. it seems to stay in sync. Skipping to the next track resets the issue however.

Apart from rebuilding the latest version available from scratch (raspbian lite, nqptp and shairport-sync) nothing has changed.

Happy to provide any logs or try change some configs - I noticed there are some options but I don't know where to start so any advice would be most appreciated.

mikebrady commented 2 years ago

Thanks. There is some information in REPORTING ISSUES.md. Initially, I’d suggest that statistics should be set to “yes” and the log_verbosity should be set to 1. It would be very useful to know what output device you are using.

grappelli commented 2 years ago

Thanks for the response!

$ shairport-sync -V

4.1-dev-210-g0e7312de-AirPlay2-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc

My Pi has been running almost 24 hours:

$ sudo systemctl status shairport-sync

● shairport-sync.service - Shairport Sync - AirPlay Audio Receiver
     Loaded: loaded (/lib/systemd/system/shairport-sync.service; enabled; vendor preset: enabled)
     Active: active (running) since Wed 2022-03-09 17:27:01 GMT; 22h ago
   Main PID: 790 (shairport-sync)
      Tasks: 5 (limit: 1597)
        CPU: 24min 18.830s
     CGroup: /system.slice/shairport-sync.service
             └─790 /usr/local/bin/shairport-sync

Mar 09 17:27:01 raspberrypi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

The output I use is simply via the headphone socket.

I then added the verbosity and statistics configuration options, as well as specified a logfile location and rebooted to test.

The logfile did not appear as expected so I stopped the service and ran shairport from the command line to test instead.

$ sudo shairport-sync

Then I played some music on homepod and added the shairport-sync airplay output. The playback started in sync. Then I skipped to the next song and playback fell out of sync as expected. I then paused and resumed the music, putting it all back in sync. I then let the music play out to the next song naturally to see whether it would stay in sync. When the track changed, it stayed in sync. I then finally tried seeking (skipping back 20 seconds in the same track) and the music fell out of sync once more. I then closed out of shairport-sync with 'ctrl-c' to look at the relevant part of the log:

0.003533646 "shairport.c:1906" Started in Airplay 2 mode with features 0x405c4a00,0x1c340 on device "b8:27:eb:53:17:ae"!
         0.000406198 "shairport.c:1949" software version: "4.1-dev-210-g0e7312de-AirPlay2-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
         0.000059948 "shairport.c:1955" log verbosity is 1.
         0.000114322 "audio_alsa.c:1018" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000115053 "audio_alsa.c:1307" alsa: disable_standby_mode is "never".
         0.000051875 "audio_alsa.c:1311" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000053854 "audio_alsa.c:1313" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000064583 "audio_alsa.c:1353" alsa: output device name is "default".
         0.000489896 "shairport.c:1984" libsodium initialised.
         0.000691614 "shairport.c:2034" disable resend requests is off.
         0.000061459 "shairport.c:2035" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000058385 "shairport.c:2039" statistics_requester status is 1.
         0.000052709 "shairport.c:2044" rtsp listening port is 7000.
         0.000051927 "shairport.c:2045" udp base port is 6001.
         0.000051093 "shairport.c:2046" udp port range is 10.
         0.000051459 "shairport.c:2047" player name is "HiFi".
         0.000051093 "shairport.c:2048" backend is "alsa".
         0.000051094 "shairport.c:2049" run_this_before_play_begins action is "(null)".
         0.000051771 "shairport.c:2050" run_this_after_play_ends action is "(null)".
         0.000051510 "shairport.c:2051" wait-cmd status is 0.
         0.000051094 "shairport.c:2052" run_this_before_play_begins may return output is 0.
         0.000051198 "shairport.c:2053" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000051198 "shairport.c:2055" run_this_before_entering_active_state action is  "(null)".
         0.000051146 "shairport.c:2057" run_this_after_exiting_active_state action is  "(null)".
         0.000051406 "shairport.c:2059" active_state_timeout is  10.000000 seconds.
         0.000057656 "shairport.c:2060" mdns backend "(null)".
         0.000051198 "shairport.c:2062" interpolation setting is "auto".
         0.000051719 "shairport.c:2066" interpolation soxr_delay_threshold is 30.
         0.000050781 "shairport.c:2067" resync time is 0.050000 seconds.
         0.000054063 "shairport.c:2068" allow a session to be interrupted: 0.
         0.000051094 "shairport.c:2069" busy timeout time is 0.
         0.000051458 "shairport.c:2070" drift tolerance is 0.001995 seconds.
         0.000053437 "shairport.c:2071" password is "(null)".
         0.000050521 "shairport.c:2072" ignore_volume_control is 0.
         0.000051146 "shairport.c:2076" volume_max_db is not set
         0.000049896 "shairport.c:2077" volume range in dB (zero means use the range specified by the mixer): 45.
         0.000051771 "shairport.c:2079" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000051823 "shairport.c:2083" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000052291 "shairport.c:2085" disable_synchronization is 0.
         0.000050625 "shairport.c:2086" use_mmap_if_available is 1.
         0.000111354 "shairport.c:2087" output_format automatic selection is enabled.
         0.000052292 "shairport.c:2091" output_rate automatic selection is enabled.
         0.000050729 "shairport.c:2095" audio backend desired buffer length is 0.200000 seconds.
         0.000126979 "shairport.c:2097" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000056146 "shairport.c:2099" audio backend latency offset is 0.000000 seconds.
         0.000053802 "shairport.c:2101" audio backend silence lead-in time is "auto".
         0.000050157 "shairport.c:2105" zeroconf regtype is "_raop._tcp".
         0.000050468 "shairport.c:2106" decoders_supported field is 1.
         0.000050000 "shairport.c:2107" use_apple_decoder is 0.
         0.000050469 "shairport.c:2108" alsa_use_hardware_mute is 0.
         0.000050469 "shairport.c:2112" no special mdns service interface was requested.
         0.000072292 "shairport.c:2115" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000054947 "shairport.c:2145" loudness is 0.
         0.000051250 "shairport.c:2146" loudness reference level is -20.000000
         0.005944323 "shairport.c:2228" NQPTP is online.
         1.496733802 "shairport.c:221" "soxr" interpolation has been chosen.
        74.495755909 "rtsp.c:2645" Connection 1: AP2 PTP connection from fe80::14c4:8645:8ece:f10e:49267 to self at fe80::eb97:e346:e5b9:b805:7000.
         0.998235000 "rtsp.c:3032" Connection 1. AP2 Buffered Audio Stream.
         0.018830937 "audio_alsa.c:528" alsa: output format chosen is "S32".
         0.000705365 "audio_alsa.c:571" alsa: output speed chosen is 44100.
         2.144461145 "rtp.c:1279" Connection 1: Set Anchor Clock: d4a33d6407510008.
         0.000375312 "rtp.c:1385" Connection 1: Clock d4a33d6407510008 is now the new anchor clock and master clock. History: 2552.255936 milliseconds.
         0.000191302 "rtp.c:1470" Connection 1: NQPTP new master clock d4a33d6407510008.
         7.941386039 "player.c:2460" sync error ms net sync ppm all sync ppm     packets min DAC queue min buffers max buffers output fps (r) output fps (c)
         0.000228698 "player.c:2460"         -0.54          0.0          0.0        1003          7230          10          63            N/A            N/A
         8.005015830 "player.c:2460"         -1.03          0.0          0.0        2006          8523          62          63       44099.91       44101.05
         8.007917810 "player.c:2460"         -1.54          0.0          0.0        3009          8503          62          63       44100.07       44101.21
         8.003721351 "player.c:2460"         -1.61          0.0          0.0        4012          8503          62          62       44100.08       44101.22
         6.129252706 "player.c:2627" Large positive sync error of: 15324 frames (0.347483 seconds), with frame: 1316654425.
         7.896210465 "player.c:2460"          0.89        -11.3         11.3        5015          8505          62          63            N/A            N/A
         8.005629008 "player.c:2460"         -0.35          0.0          0.0        6018          8548          62          63       44100.26       44101.41
         8.001625153 "player.c:2460"         -0.63          0.0          0.0        7021          8541          62          63       44100.08       44101.24
         9.111658382 "audio_alsa.c:1745" alsa: recovering from a previous underrun.
         3.322103072 "player.c:2460"         -0.28          0.0          0.0        8024          8528          62          63            N/A            N/A
         8.007282132 "player.c:2460"         -0.39          0.0          0.0        9027          8559          62          62       44100.33       44101.50
         8.006463122 "player.c:2460"         -0.44          0.0          0.0       10030          8546          62          63       44100.22       44101.39
         8.004048434 "player.c:2460"         -0.89          0.0          0.0       11033          8528          62          63       44100.17       44101.34
         8.010495258 "player.c:2460"         -0.84          0.0          0.0       12036          8526          62          63       44100.16       44101.33
         8.000863486 "player.c:2460"         -0.95          0.0          0.0       13039          8529          62          63       44100.12       44101.29
         8.006313435 "player.c:2460"         -0.89          0.0          0.0       14042          8537          62          63       44100.14       44101.32
         8.005441976 "player.c:2460"         -1.23          0.0          0.0       15045          8499          62          63       44100.13       44101.31
         8.008363174 "player.c:2460"         -1.16          0.0          0.0       16048          8526          62          63       44100.13       44101.31
         8.004834788 "player.c:2460"         -1.27          0.0          0.0       17051          8516          62          63       44100.13       44101.31
         8.008846612 "player.c:2460"         -1.32          2.8          2.8       18054          8389          61          63       44100.13       44101.31
         8.002855726 "player.c:2460"         -1.54          0.0          0.0       19057          8510          62          62       44100.13       44101.31
         8.008743747 "player.c:2460"         -1.61          0.0          0.0       20060          8489          62          63       44100.12       44101.30
         8.001638643 "player.c:2460"         -1.62          0.0          0.0       21063          8500          62          63       44100.12       44101.30
         8.007701351 "player.c:2460"         -1.85          0.0          0.0       22066          8433          62          63       44100.12       44101.30
         8.005058382 "player.c:2460"         -1.94          5.7          5.7       23069          8225          61          63       44100.13       44101.31
         8.008556872 "player.c:2460"         -1.96         19.8         19.8       24072          8295          61          63       44100.11       44101.29
         8.003157549 "player.c:2460"         -1.78          5.7          5.7       25075          8189          61          62       44100.13       44101.31
         8.006174268 "player.c:2460"         -1.96         34.0         34.0       26078          8281          61          63       44100.13       44101.25
         8.008094789 "player.c:2460"         -1.87          0.0          0.0       27081          8490          62          63       44100.12       44101.12
         8.007297184 "player.c:2460"         -2.00         31.2         31.2       28084          8195          61          63       44100.13       44101.02
         8.006838330 "player.c:2460"         -1.93         19.8         19.8       29087          8311          61          62       44100.12       44100.92
         8.000161924 "player.c:2460"         -1.86          2.8          2.8       30090          8178          61          63       44100.12       44100.84
         8.006542237 "player.c:2460"         -1.96         25.5         25.5       31093          8279          61          63       44100.12       44100.77
         8.006305518 "player.c:2460"         -1.92         14.2         14.2       32096          8196          61          63       44100.13       44100.71
         8.005492601 "player.c:2460"         -1.97         19.8         19.8       33099          8238          61          63       44100.12       44100.66
         8.720935153 "player.c:1118" Gone past starting time for 1576087460 by 2037620142 nanoseconds.
         0.043462760 "player.c:2627" Large positive sync error of: 31009 frames (0.703152 seconds), with frame: 1576179716.
         5.910529946 "player.c:2460"          6.41         45.3         45.3       34102          8033           0          63            N/A            N/A
         8.005704268 "player.c:2460"          0.56          0.0          0.0       35105          8598          62          63       44100.00       44099.34
         8.006846924 "player.c:2460"          0.93          0.0          0.0       36108          8613          62          63       44100.05       44099.41
         8.003815830 "player.c:2460"          0.69          0.0          0.0       37111          8605          62          63       44100.07       44099.46
         8.005590466 "player.c:2460"          0.70          0.0          0.0       38114          8608          62          63       44100.06       44099.48
         8.005170830 "player.c:2460"          0.38          0.0          0.0       39117          8591          62          63       44100.09       44099.53
         8.008393747 "player.c:2460"          0.27          0.0          0.0       40120          8587          62          62       44100.08       44099.54
         8.004128799 "player.c:2460"         -0.05          0.0          0.0       41123          8574          62          63       44100.09       44099.57
         8.007492861 "player.c:2460"         -0.09          0.0          0.0       42126          8570          62          63       44100.10       44099.61
         7.331317393 "player.c:2627" Large positive sync error of: 10508 frames (0.238277 seconds), with frame: 3839803676.
         2.340883593 "player.c:2460"          0.67        -11.3         11.3       43129          8549          62          63            N/A            N/A
         4.647910728 "player.c:1642" Connection 1: Playback Stopped. Total playing time 00:06:10. Input: 0.00 frames per second.
         0.020600000 "ptp-utilities.c:171" ptp_shm_interface_close
         0.000270729 "shairport.c:1576" exit_function exit

Hope that helps!

handcc commented 2 years ago

I also just updated to the latest version of NQPTP and Shairport Sync, and am affected by this issue. Audio reliably cuts out after a few minutes, I have to disconnect and reconnect the source device to resume playback.

$ pi@raspberrypi:~ $ shairport-sync -vu --statistics
         0.000603426 "shairport.c:1906" Started in Airplay 2 mode with features 0x405c4a00,0x1c340 on device "dc:a6:32:a3:9c:1b"!
         0.000119000 "shairport.c:1949" software version: "4.1-dev-216-g713492a7-AirPlay2-alac-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
         0.000020148 "shairport.c:1955" log verbosity is 1.
         0.000041519 "audio_alsa.c:1002" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000040148 "audio_alsa.c:1156" alsa output rate is 44100 frames per second
         0.000023185 "audio_alsa.c:1291" alsa: disable_standby_mode is "never".
         0.000015278 "audio_alsa.c:1295" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000015963 "audio_alsa.c:1297" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000020407 "audio_alsa.c:1337" alsa: output device name is "hw:CARD=XMC1,DEV=0".
         0.000202815 "shairport.c:1984" libsodium initialised.
         0.000294870 "shairport.c:2034" disable resend requests is off.
         0.000023852 "shairport.c:2035" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000019537 "shairport.c:2039" statistics_requester status is 1.
         0.000016445 "shairport.c:2044" rtsp listening port is 7000.
         0.000014574 "shairport.c:2045" udp base port is 6001.
         0.000014018 "shairport.c:2046" udp port range is 10.
         0.000014260 "shairport.c:2047" player name is "RPi-AirPlay".
         0.000015648 "shairport.c:2048" backend is "alsa".
         0.000014370 "shairport.c:2049" run_this_before_play_begins action is "(null)".
         0.000014463 "shairport.c:2050" run_this_after_play_ends action is "(null)".
         0.000014870 "shairport.c:2051" wait-cmd status is 0.
         0.000014223 "shairport.c:2052" run_this_before_play_begins may return output is 0.
         0.000016000 "shairport.c:2053" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000015981 "shairport.c:2055" run_this_before_entering_active_state action is  "(null)".
         0.000014482 "shairport.c:2057" run_this_after_exiting_active_state action is  "(null)".
         0.000014333 "shairport.c:2059" active_state_timeout is  10.000000 seconds.
         0.000016833 "shairport.c:2060" mdns backend "(null)".
         0.000014167 "shairport.c:2062" interpolation setting is "auto".
         0.000015852 "shairport.c:2066" interpolation soxr_delay_threshold is 30.
         0.000017092 "shairport.c:2067" resync time is 0.050000 seconds.
         0.000016408 "shairport.c:2068" allow a session to be interrupted: 0.
         0.000014352 "shairport.c:2069" busy timeout time is 0.
         0.000013963 "shairport.c:2070" drift tolerance is 0.001995 seconds.
         0.000014722 "shairport.c:2071" password is "(null)".
         0.000013889 "shairport.c:2072" ignore_volume_control is 1.
         0.000014481 "shairport.c:2076" volume_max_db is not set
         0.000015241 "shairport.c:2077" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000016167 "shairport.c:2079" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000016277 "shairport.c:2083" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000014889 "shairport.c:2085" disable_synchronization is 0.
         0.000013945 "shairport.c:2086" use_mmap_if_available is 1.
         0.000014426 "shairport.c:2087" output_format automatic selection is disabled.
         0.000014407 "shairport.c:2090" output_format is "S24_3LE".
         0.000014000 "shairport.c:2091" output_rate automatic selection is disabled.
         0.000015463 "shairport.c:2094" output_rate is 44100.
         0.000014167 "shairport.c:2095" audio backend desired buffer length is 0.200000 seconds.
         0.000014963 "shairport.c:2097" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000015407 "shairport.c:2099" audio backend latency offset is 0.000000 seconds.
         0.000014741 "shairport.c:2101" audio backend silence lead-in time is "auto".
         0.000013981 "shairport.c:2105" zeroconf regtype is "_raop._tcp".
         0.000015704 "shairport.c:2106" decoders_supported field is 3.
         0.000014352 "shairport.c:2107" use_apple_decoder is 1.
         0.000014055 "shairport.c:2108" alsa_use_hardware_mute is 0.
         0.000014019 "shairport.c:2112" no special mdns service interface was requested.
         0.000028241 "shairport.c:2115" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000019333 "shairport.c:2145" loudness is 0.
         0.000014389 "shairport.c:2146" loudness reference level is -20.000000
         0.005477185 "shairport.c:2228" NQPTP is online.
         1.495489388 "shairport.c:221" "soxr" interpolation has been chosen.
         5.229471904 "rtsp.c:2645" Connection 1: AP2 PTP connection from 192.168.1.112:56950 to self at 192.168.1.223:7000.
         0.270726241 "rtsp.c:3032" Connection 1. AP2 Buffered Audio Stream.
         0.303414055 "rtp.c:1279" Connection 1: Set Anchor Clock: d81c79ee45af0008.
         1.095926703 "rtp.c:1385" Connection 1: Clock d81c79ee45af0008 is now the new anchor clock and master clock. History: 1500.181221 milliseconds.
         0.000178371 "rtp.c:1470" Connection 1: NQPTP new master clock d81c79ee45af0008.
         7.926375902 "player.c:2460" sync error ms net sync ppm all sync ppm     packets min DAC queue min buffers max buffers output fps (r) output fps (c)
         0.000194130 "player.c:2460"          2.52        -60.1         60.1        1003          7455           0          62            N/A            N/A
         8.004718495 "player.c:2460"          1.54        -19.8         19.8        2006          8613          62          62       44102.43       44102.84
         8.006373255 "player.c:2460"          1.40         -5.7          5.7        3009          8606          62          62       44099.70       44100.11
         8.003777625 "player.c:2460"          1.57        -17.0         17.0        4012          8630          62          62       44100.28       44100.70
         8.008640069 "player.c:2460"          1.54         -5.7          5.7        5015          8621          62          63       44099.27       44099.68
         8.004101569 "player.c:2460"          1.59        -17.0         17.0        6018          8617          62          62       44099.02       44099.43
         8.003339477 "player.c:2460"          1.52        -11.3         11.3        7021          8615          62          62       44099.03       44099.44
         8.006760106 "player.c:2460"          1.55         -8.5          8.5        8024          8618          62          62       44099.11       44099.52
         8.009251662 "player.c:2460"          1.48        -17.0         17.0        9027          8617          62          62       44099.37       44099.78
         8.001864847 "player.c:2460"          1.45        -11.3         11.3       10030          8613          62          62       44099.37       44099.77
         8.006631366 "player.c:2460"          1.49         -8.5          8.5       11033          8613          62          62       44099.06       44099.47
         8.863096902 "player.c:2460"          0.07         -2.8          2.8       12036          8539          62          62            N/A            N/A
         8.007618088 "player.c:2460"         -0.42          0.0          0.0       13039          8537          62          62       44102.80       44103.21
         8.008598384 "player.c:2460"         -0.44          0.0          0.0       14042          8529          62          62       44100.08       44100.49
         8.006010921 "player.c:2460"         -0.34          0.0          0.0       15045          8534          62          62       44100.01       44100.42
         8.004780014 "player.c:2460"         -0.28          0.0          0.0       16048          8540          62          62       44100.82       44101.23
         8.006802384 "player.c:2460"         -0.27          0.0          0.0       17051          8544          62          63       44099.61       44100.02
         8.002067995 "player.c:2460"         -0.17          0.0          0.0       18054          8542          62          62       44099.40       44099.81
         8.009209144 "player.c:2460"         -0.14          0.0          0.0       19057          8545          62          62       44099.66       44100.07
         8.004462810 "player.c:2460"         -0.14          0.0          0.0       20060          8541          62          62       44099.81       44100.22
         8.004758606 "player.c:2460"         -0.04          0.0          0.0       21063          8552          62          62       44099.21       44099.62
         8.006763828 "player.c:2460"          0.02          0.0          0.0       22066          8545          62          62       44099.61       44100.02
         8.005150588 "player.c:2460"          0.06          0.0          0.0       23069          8560          62          62       44099.40       44099.81
         8.004854199 "player.c:2460"          0.04          0.0          0.0       24072          8549          62          62       44099.68       44100.08
         8.009938570 "player.c:2460"          0.06          0.0          0.0       25075          8551          62          62       44099.82       44100.23
         8.002780180 "player.c:2460"          0.03          0.0          0.0       26078          8552          62          63       44099.37       44099.78
         8.007511977 "player.c:2460"         -0.15          0.0          0.0       27081          8541          62          62       44099.69       44100.10
         8.004696106 "player.c:2460"          0.19          0.0          0.0       28084          8558          62          62       44099.33       44099.74
         8.007738773 "player.c:2460"          0.39          0.0          0.0       29087          8572          62          62       44099.53       44099.94
         8.003551736 "player.c:2460"          0.41          0.0          0.0       30090          8562          62          63       44099.38       44099.79
         8.009117958 "player.c:2460"          0.48          0.0          0.0       31093          8569          62          63       44099.34       44099.75
         8.005459532 "player.c:2460"          0.45          0.0          0.0       32096          8574          62          62       44099.56       44099.97
         8.006603255 "player.c:2460"          0.51          0.0          0.0       33099          8561          62          62       44099.38       44099.78
         8.001733458 "player.c:2460"          0.52          0.0          0.0       34102          8575          62          63       44099.38       44099.78
         8.005996125 "player.c:2460"          0.63          0.0          0.0       35105          8573          62          62       44099.40       44099.81
         8.007300032 "player.c:2460"          0.79          0.0          0.0       36108          8584          62          63       44099.50       44099.90
         8.007734070 "player.c:2460"          0.80          0.0          0.0       37111          8590          62          62       44099.24       44099.65
         8.002287032 "player.c:2460"          0.91          0.0          0.0       38114          8594          62          62       44099.48       44099.88
         8.010045680 "player.c:2460"          0.97          0.0          0.0       39117          8587          62          63       44099.38       44099.78
         8.002777773 "player.c:2460"          0.96          0.0          0.0       40120          8593          62          62       44099.32       44099.72
         8.842945643 "player.c:2460"          0.26          0.0          0.0       41123          8548           0          62            N/A            N/A
         8.005720792 "player.c:2460"         -0.06          0.0          0.0       42126          8548          62          62       44097.27       44097.67
         8.006936865 "player.c:2460"         -0.02          0.0          0.0       43129          8549          62          62       44097.77       44098.17
         8.005079847 "player.c:2460"         -0.00          0.0          0.0       44132          8542          62          62       44099.01       44099.41
         8.007832792 "player.c:2460"          0.04          0.0          0.0       45135          8553          62          62       44099.71       44100.11
         8.001662754 "player.c:2460"         -0.02          0.0          0.0       46138          8550          62          62       44098.84       44099.24
         9.344528161 "player.c:2460"         -0.38          0.0          0.0       47141          8526          62          62            N/A            N/A
         8.005165422 "player.c:2460"         -0.33          0.0          0.0       48144          8534          62          62       44100.43       44100.83
         8.009567698 "player.c:2460"         -0.36          0.0          0.0       49147          8527          62          62       44097.59       44097.99
         8.002646385 "player.c:2460"         -0.25          0.0          0.0       50150          8534          62          62       44099.70       44100.10
         8.008266106 "player.c:2460"         -0.15          0.0          0.0       51153          8537          62          63       44098.20       44098.60
         8.003075273 "player.c:2460"         -0.07          0.0          0.0       52156          8543          62          62       44098.64       44099.04
         8.010745884 "player.c:2460"         -0.10          0.0          0.0       53159          8536          62          62       44098.37       44098.77
         8.002135032 "player.c:2460"          0.02          0.0          0.0       54162          8550          62          62       44098.28       44098.68
         8.007337607 "player.c:2460"          0.05          0.0          0.0       55165          8549          62          62       44099.20       44099.60
         8.347684698 "player.c:2627" Large positive sync error of: 3631 frames (0.082336 seconds), with frame: 542043933.
         0.010670223 "common.c:1544" Timed out waiting for a mutex, having waited 0.010064 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000564611 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010631334 sec.
         0.584381185 "player.c:2627" Large positive sync error of: 4892 frames (0.110930 seconds), with frame: 542070333.
         0.010724944 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005181185 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015264481 sec.
         0.584463426 "player.c:2627" Large positive sync error of: 4956 frames (0.112381 seconds), with frame: 542096733.
         0.011068296 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004461982 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014546870 sec.
         0.580995351 "player.c:2627" Large positive sync error of: 4843 frames (0.109819 seconds), with frame: 542123133.
         0.010766352 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008230315 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018316611 sec.
         0.582764981 "player.c:2627" Large positive sync error of: 4911 frames (0.111361 seconds), with frame: 542149533.
         0.010744778 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006498518 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016586000 sec.
         0.581503833 "player.c:2627" Large positive sync error of: 5077 frames (0.115125 seconds), with frame: 542175933.
         0.010759537 "common.c:1544" Timed out waiting for a mutex, having waited 0.010113 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007872315 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017991611 sec.
         0.577077888 "player.c:2627" Large positive sync error of: 4893 frames (0.110952 seconds), with frame: 542202333.
         0.010343149 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002461333 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012547944 sec.
         0.589173592 "player.c:2627" Large positive sync error of: 4978 frames (0.112880 seconds), with frame: 542228733.
         0.010721389 "common.c:1544" Timed out waiting for a mutex, having waited 0.010083 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.010105963 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020194759 sec.
         0.576263111 "player.c:2627" Large positive sync error of: 4862 frames (0.110249 seconds), with frame: 542255133.
         0.010754555 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002988611 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013074926 sec.
         0.586361241 "player.c:2627" Large positive sync error of: 5083 frames (0.115261 seconds), with frame: 542281533.
         0.010691148 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002982352 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013069129 sec.
         0.583879648 "player.c:2627" Large positive sync error of: 4961 frames (0.112494 seconds), with frame: 542307933.
         0.010794500 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005331759 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015416351 sec.
         0.584128185 "player.c:2627" Large positive sync error of: 4953 frames (0.112313 seconds), with frame: 542334333.
         0.010553037 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005321703 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015413186 sec.
         0.580875741 "player.c:2627" Large positive sync error of: 4815 frames (0.109184 seconds), with frame: 542360733.
         0.010319722 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008894000 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018988797 sec.
         0.579186685 "player.c:2627" Large positive sync error of: 4901 frames (0.111134 seconds), with frame: 542387133.
         0.010629981 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.010104945 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020192555 sec.
         0.576858037 "player.c:2627" Large positive sync error of: 4909 frames (0.111315 seconds), with frame: 542413533.
         0.010558814 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002594574 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012680926 sec.
         0.587785056 "player.c:2627" Large positive sync error of: 4884 frames (0.110748 seconds), with frame: 542439933.
         0.010620074 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001597907 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011684240 sec.
         0.583623592 "player.c:2627" Large positive sync error of: 4934 frames (0.111882 seconds), with frame: 542466333.
         0.010815408 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005543092 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015634463 sec.
         0.582299481 "player.c:2627" Large positive sync error of: 4877 frames (0.110590 seconds), with frame: 542492733.
         0.010748778 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006959704 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017046000 sec.
         0.580799018 "player.c:2627" Large positive sync error of: 4835 frames (0.109637 seconds), with frame: 542519133.
         0.010740667 "common.c:1544" Timed out waiting for a mutex, having waited 0.010110 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008571166 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018687352 sec.
         0.583470352 "player.c:2627" Large positive sync error of: 5118 frames (0.116054 seconds), with frame: 542545533.
         0.011205333 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005216037 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015302537 sec.
         0.586093648 "player.c:2627" Large positive sync error of: 4820 frames (0.109297 seconds), with frame: 542572285.
         0.010702982 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003201629 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013287963 sec.
         0.587768778 "player.c:2627" Large positive sync error of: 4905 frames (0.111224 seconds), with frame: 542598685.
         0.010398833 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001841222 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011928352 sec.
         0.585501407 "player.c:2627" Large positive sync error of: 5029 frames (0.114036 seconds), with frame: 542625085.
         0.010650741 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003855926 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013941815 sec.
         0.583292314 "player.c:2627" Large positive sync error of: 4910 frames (0.111338 seconds), with frame: 542651485.
         0.010906019 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005813778 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015900259 sec.
         0.581154777 "player.c:2627" Large positive sync error of: 4832 frames (0.109569 seconds), with frame: 542677885.
         0.010792278 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008062722 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018149204 sec.
         0.581042389 "player.c:2627" Large positive sync error of: 4868 frames (0.110385 seconds), with frame: 542704285.
         0.010758314 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008192260 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018278463 sec.
         0.579119425 "player.c:2627" Large positive sync error of: 5003 frames (0.113447 seconds), with frame: 542730685.
         0.010707482 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000189815 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010276426 sec.
         0.586922758 "player.c:2627" Large positive sync error of: 4863 frames (0.110272 seconds), with frame: 542757085.
         0.010610741 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002495315 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012582815 sec.
         0.584313814 "player.c:2627" Large positive sync error of: 4749 frames (0.107687 seconds), with frame: 542783485.
         0.010871389 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004823630 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014912315 sec.
         0.585344759 "player.c:2627" Large positive sync error of: 5024 frames (0.113923 seconds), with frame: 542809885.
         0.010547278 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004133926 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014224852 sec.
         0.584634258 "player.c:2627" Large positive sync error of: 4987 frames (0.113084 seconds), with frame: 542836285.
         0.010320889 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005098667 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015191129 sec.
         0.584118907 "player.c:2627" Large positive sync error of: 4937 frames (0.111950 seconds), with frame: 542862685.
         0.010256611 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005634537 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015727019 sec.
         0.578985352 "player.c:2627" Large positive sync error of: 4730 frames (0.107256 seconds), with frame: 542889085.
         0.010251240 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000761426 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010853852 sec.
         0.591039056 "player.c:2627" Large positive sync error of: 4949 frames (0.112222 seconds), with frame: 542915485.
         0.010302666 "common.c:1544" Timed out waiting for a mutex, having waited 0.010089 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008664630 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018761037 sec.
         0.579367018 "player.c:2627" Large positive sync error of: 4940 frames (0.112018 seconds), with frame: 542941885.
         0.010365148 "common.c:1544" Timed out waiting for a mutex, having waited 0.010083 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.010275945 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020367092 sec.
         0.575554870 "player.c:2627" Large positive sync error of: 4750 frames (0.107710 seconds), with frame: 542968285.
         0.010581981 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003786315 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013871907 sec.
         0.586825074 "player.c:2627" Large positive sync error of: 4862 frames (0.110249 seconds), with frame: 542994685.
         0.010850796 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002298926 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012386555 sec.
         0.586207611 "player.c:2627" Large positive sync error of: 5072 frames (0.115011 seconds), with frame: 543021085.
         0.010909574 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002889722 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012977518 sec.
         0.583026777 "player.c:2627" Large positive sync error of: 4951 frames (0.112268 seconds), with frame: 543047485.
         0.010816778 "common.c:1544" Timed out waiting for a mutex, having waited 0.010088 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006163630 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016258834 sec.
         0.582985499 "player.c:2627" Large positive sync error of: 4925 frames (0.111678 seconds), with frame: 543073885.
         0.010684556 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006336130 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016422074 sec.
         0.581772055 "player.c:2627" Large positive sync error of: 4878 frames (0.110612 seconds), with frame: 543100285.
         0.010745185 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007493630 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017579852 sec.
         0.576751129 "player.c:2627" Large positive sync error of: 4883 frames (0.110726 seconds), with frame: 543126685.
         0.010739148 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002581148 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012667315 sec.
         0.586475611 "player.c:2627" Large positive sync error of: 4851 frames (0.110000 seconds), with frame: 543153085.
         0.010888204 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002573203 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012659352 sec.
         0.587237778 "player.c:2627" Large positive sync error of: 4889 frames (0.110862 seconds), with frame: 543179485.
         0.010377500 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002416370 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012501722 sec.
         0.583279092 "player.c:2627" Large positive sync error of: 4944 frames (0.112109 seconds), with frame: 543205885.
         0.010252186 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006477907 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016568408 sec.
         0.583234777 "player.c:2627" Large positive sync error of: 4916 frames (0.111474 seconds), with frame: 543232285.
         0.011020297 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005750185 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015835982 sec.
         0.583278092 "player.c:2627" Large positive sync error of: 4926 frames (0.111701 seconds), with frame: 543258685.
         0.011076463 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005645815 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015735685 sec.
         0.583675296 "player.c:2627" Large positive sync error of: 4933 frames (0.111859 seconds), with frame: 543285085.
         0.010695574 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005632222 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015717777 sec.
         0.578316629 "player.c:2627" Large positive sync error of: 4958 frames (0.112426 seconds), with frame: 543311485.
         0.010320111 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001369260 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011457241 sec.
         0.589421314 "player.c:2627" Large positive sync error of: 4954 frames (0.112336 seconds), with frame: 543337885.
         0.010557315 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.010023593 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020117407 sec.
         0.578329796 "player.c:2627" Large positive sync error of: 4937 frames (0.111950 seconds), with frame: 543364285.
         0.010434870 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.011243667 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.021331482 sec.
         0.578048499 "player.c:2627" Large positive sync error of: 4939 frames (0.111995 seconds), with frame: 543390685.
         0.010439389 "common.c:1544" Timed out waiting for a mutex, having waited 0.010243 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001593556 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011843796 sec.
         0.584771814 "player.c:2627" Large positive sync error of: 4973 frames (0.112766 seconds), with frame: 543417085.
         0.011040833 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004261926 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014353130 sec.
         0.582496019 "player.c:2627" Large positive sync error of: 4935 frames (0.111905 seconds), with frame: 543443485.
         0.010491925 "common.c:1544" Timed out waiting for a mutex, having waited 0.010093 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006958593 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017057704 sec.
         0.584185852 "player.c:2627" Large positive sync error of: 4975 frames (0.112812 seconds), with frame: 543469885.
         0.010573814 "common.c:1544" Timed out waiting for a mutex, having waited 0.010093 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005251649 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015351389 sec.
         0.580500407 "player.c:2627" Large positive sync error of: 5019 frames (0.113810 seconds), with frame: 543496285.
         0.010458759 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.009039444 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.019131148 sec.
         0.579366259 "player.c:2627" Large positive sync error of: 4929 frames (0.111769 seconds), with frame: 543522685.
         0.010237000 "common.c:1544" Timed out waiting for a mutex, having waited 0.010089 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.010397574 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020494000 sec.
         0.575368778 "player.c:2627" Large positive sync error of: 4731 frames (0.107279 seconds), with frame: 543549085.
         0.010231407 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004478537 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014571259 sec.
         0.585147796 "player.c:2627" Large positive sync error of: 4915 frames (0.111451 seconds), with frame: 543575485.
         0.010987352 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003697352 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013785759 sec.
         0.586342925 "player.c:2627" Large positive sync error of: 5065 frames (0.114853 seconds), with frame: 543601885.
         0.010710260 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002944796 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013031463 sec.
         0.583834592 "player.c:2627" Large positive sync error of: 4978 frames (0.112880 seconds), with frame: 543628285.
         0.010720556 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005450815 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015537963 sec.
         0.581950258 "player.c:2627" Large positive sync error of: 4867 frames (0.110363 seconds), with frame: 543654685.
         0.010807963 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007250334 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017343685 sec.
         0.578362925 "player.c:2627" Large positive sync error of: 4726 frames (0.107166 seconds), with frame: 543681085.
         0.010728760 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000910759 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010997704 sec.
         0.587966111 "player.c:2627" Large positive sync error of: 4918 frames (0.111519 seconds), with frame: 543707485.
         0.010644407 "common.c:1544" Timed out waiting for a mutex, having waited 0.010077 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001390926 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011474814 sec.
         0.588320870 "player.c:2627" Large positive sync error of: 4933 frames (0.111859 seconds), with frame: 543733885.
         0.010802148 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000917500 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011003908 sec.
         0.587406203 "player.c:2627" Large positive sync error of: 4909 frames (0.111315 seconds), with frame: 543760285.
         0.010756186 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001810111 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011903260 sec.
         0.587567481 "player.c:2627" Large positive sync error of: 4901 frames (0.111134 seconds), with frame: 543786685.
         0.010568407 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001878815 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011965907 sec.
         0.583500796 "player.c:2627" Large positive sync error of: 4973 frames (0.112766 seconds), with frame: 543813085.
         0.010689204 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005805389 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.015897166 sec.
         0.583248981 "player.c:2627" Large positive sync error of: 4913 frames (0.111406 seconds), with frame: 543839485.
         0.010830185 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.005924667 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016011426 sec.
         0.582228388 "player.c:2627" Large positive sync error of: 4903 frames (0.111179 seconds), with frame: 543865885.
         0.010683315 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007096833 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017188315 sec.
         0.577623759 "player.c:2627" Large positive sync error of: 4702 frames (0.106621 seconds), with frame: 543892285.
         0.010513296 "common.c:1544" Timed out waiting for a mutex, having waited 0.010077 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001818130 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011902722 sec.
         0.587320055 "player.c:2627" Large positive sync error of: 4961 frames (0.112494 seconds), with frame: 543918685.
         0.010600426 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002151426 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012243667 sec.
         0.169942963 "player.c:1636" Connection 1: Playback Stopped. Total playing time 00:08:16. Input: 5910378.57,  Output: 44099.20 (raw), 44099.60 (corrected) frames per second.
         0.973604648 "rtsp.c:2667" Connection 2: Remote Control connection from 192.168.1.112:56981 to self at 192.168.1.223:7000.

> pi@raspberrypi:~ $ shairport-sync -vu --statistics
         0.000810296 "shairport.c:1906" Started in Airplay 2 mode with features 0x405c4a00,0x1c340 on device "dc:a6:32:a3:9c:1b"!
         0.000164759 "shairport.c:1949" software version: "4.1-dev-216-g713492a7-AirPlay2-alac-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
         0.000031185 "shairport.c:1955" log verbosity is 1.
         0.000032056 "audio_alsa.c:1002" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000052648 "audio_alsa.c:1156" alsa output rate is 44100 frames per second
         0.000034130 "audio_alsa.c:1291" alsa: disable_standby_mode is "never".
         0.000025185 "audio_alsa.c:1295" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000026370 "audio_alsa.c:1297" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000060760 "audio_alsa.c:1337" alsa: output device name is "hw:CARD=XMC1,DEV=0".
         0.000282703 "shairport.c:1984" libsodium initialised.
         0.000406630 "shairport.c:2034" disable resend requests is off.
         0.000033555 "shairport.c:2035" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000029056 "shairport.c:2039" statistics_requester status is 1.
         0.000024352 "shairport.c:2044" rtsp listening port is 7000.
         0.000024148 "shairport.c:2045" udp base port is 6001.
         0.000023963 "shairport.c:2046" udp port range is 10.
         0.000023704 "shairport.c:2047" player name is "RPi-AirPlay".
         0.000023518 "shairport.c:2048" backend is "alsa".
         0.000023908 "shairport.c:2049" run_this_before_play_begins action is "(null)".
         0.000024463 "shairport.c:2050" run_this_after_play_ends action is "(null)".
         0.000024314 "shairport.c:2051" wait-cmd status is 0.
         0.000025463 "shairport.c:2052" run_this_before_play_begins may return output is 0.
         0.000024926 "shairport.c:2053" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000024241 "shairport.c:2055" run_this_before_entering_active_state action is  "(null)".
         0.000023741 "shairport.c:2057" run_this_after_exiting_active_state action is  "(null)".
         0.000023981 "shairport.c:2059" active_state_timeout is  10.000000 seconds.
         0.000027334 "shairport.c:2060" mdns backend "(null)".
         0.000023185 "shairport.c:2062" interpolation setting is "auto".
         0.000024018 "shairport.c:2066" interpolation soxr_delay_threshold is 30.
         0.000023834 "shairport.c:2067" resync time is 0.050000 seconds.
         0.000024592 "shairport.c:2068" allow a session to be interrupted: 0.
         0.000024426 "shairport.c:2069" busy timeout time is 0.
         0.000023241 "shairport.c:2070" drift tolerance is 0.001995 seconds.
         0.000024889 "shairport.c:2071" password is "(null)".
         0.000023296 "shairport.c:2072" ignore_volume_control is 1.
         0.000023926 "shairport.c:2076" volume_max_db is not set
         0.000023518 "shairport.c:2077" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000024871 "shairport.c:2079" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000024629 "shairport.c:2083" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000024982 "shairport.c:2085" disable_synchronization is 0.
         0.000023926 "shairport.c:2086" use_mmap_if_available is 1.
         0.000023889 "shairport.c:2087" output_format automatic selection is disabled.
         0.000024129 "shairport.c:2090" output_format is "S24_3LE".
         0.000023426 "shairport.c:2091" output_rate automatic selection is disabled.
         0.000024130 "shairport.c:2094" output_rate is 44100.
         0.000023481 "shairport.c:2095" audio backend desired buffer length is 0.200000 seconds.
         0.000024945 "shairport.c:2097" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000025518 "shairport.c:2099" audio backend latency offset is 0.000000 seconds.
         0.000024834 "shairport.c:2101" audio backend silence lead-in time is "auto".
         0.000023777 "shairport.c:2105" zeroconf regtype is "_raop._tcp".
         0.000023538 "shairport.c:2106" decoders_supported field is 3.
         0.000023425 "shairport.c:2107" use_apple_decoder is 1.
         0.000024223 "shairport.c:2108" alsa_use_hardware_mute is 0.
         0.000023944 "shairport.c:2112" no special mdns service interface was requested.
         0.000046833 "shairport.c:2115" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000029612 "shairport.c:2145" loudness is 0.
         0.000024240 "shairport.c:2146" loudness reference level is -20.000000
         0.005597000 "shairport.c:2228" NQPTP is online.
         1.495877111 "shairport.c:221" "soxr" interpolation has been chosen.
         8.135679032 "rtsp.c:2645" Connection 1: AP2 PTP connection from 192.168.1.112:57048 to self at 192.168.1.223:7000.
         6.261472792 "rtsp.c:3032" Connection 1. AP2 Buffered Audio Stream.
         0.271944907 "rtp.c:1279" Connection 1: Set Anchor Clock: d81c79ee45af0008.
         0.000528852 "rtp.c:1385" Connection 1: Clock d81c79ee45af0008 is now the new anchor clock and master clock. History: 6225.814108 milliseconds.
         0.000177852 "rtp.c:1470" Connection 1: NQPTP new master clock d81c79ee45af0008.
         8.296191717 "player.c:2460" sync error ms net sync ppm all sync ppm     packets min DAC queue min buffers max buffers output fps (r) output fps (c)
         0.000244112 "player.c:2460"         -0.59          0.0          0.0        1003          6690          62          63            N/A            N/A
         8.002589995 "player.c:2460"         -0.33          0.0          0.0        2006          8529          62          62       44101.51       44101.91
         8.008921365 "player.c:2460"         -0.14          0.0          0.0        3009          8544          62          62       44100.17       44100.56
         8.804751791 "player.c:2460"         -0.35          0.0          0.0        4012          8527          62          62            N/A            N/A
         8.003891681 "player.c:2460"         -0.62          0.0          0.0        5015          8524          62          62       44099.98       44100.37
         8.006800125 "player.c:2460"         -0.51          0.0          0.0        6018          8526          62          62       44097.31       44097.70
         8.008495347 "player.c:2460"         -0.48          0.0          0.0        7021          8530          62          62       44098.89       44099.28
         8.002912680 "player.c:2460"         -0.48          0.0          0.0        8024          8532          62          62       44099.65       44100.05
         8.757525088 "player.c:2460"          0.18          0.0          0.0        9027          8533          62          62            N/A            N/A
         8.007759180 "player.c:2460"          0.50          0.0          0.0       10030          8567          62          62       44102.65       44103.05
         8.006267403 "player.c:2460"          0.54          0.0          0.0       11033          8566          62          62       44100.21       44100.60
         8.005978717 "player.c:2460"          0.55          0.0          0.0       12036          8577          62          62       44100.42       44100.82
         8.001881810 "player.c:2460"          0.66          0.0          0.0       13039          8579          62          62       44099.76       44100.15
         8.007939884 "player.c:2460"          0.67          0.0          0.0       14042          8585          62          62       44099.15       44099.55
         8.004716033 "player.c:2460"          0.85          0.0          0.0       15045          8586          62          62       44100.02       44100.41
         8.008083939 "player.c:2460"          0.83          0.0          0.0       16048          8578          62          62       44100.03       44100.42
         8.003730199 "player.c:2460"          0.76          0.0          0.0       17051          8586          62          62       44099.00       44099.39
         8.004658644 "player.c:2460"          0.91          0.0          0.0       18054          8587          62          62       44099.45       44099.85
         8.007266291 "player.c:2460"          0.98          0.0          0.0       19057          8589          62          63       44099.23       44099.63
         9.415208068 "player.c:2460"          0.17          0.0          0.0       20060          8519          62          62            N/A            N/A
         8.005416218 "player.c:2460"          0.33          0.0          0.0       21063          8567          62          62       44099.07       44099.46
         8.005254791 "player.c:2460"          0.36          0.0          0.0       22066          8567          62          62       44099.49       44099.88
         8.813817754 "player.c:2460"          0.26          0.0          0.0       23069          8549          62          62            N/A            N/A
         8.005767440 "player.c:2460"         -0.60          0.0          0.0       24072          8519          62          63       44096.37       44096.76
         9.759361402 "player.c:2460"         -0.48          0.0          0.0       25075          8523          62          62            N/A            N/A
         8.004164236 "player.c:2460"          0.42          0.0          0.0       26078          8564          62          62       44107.21       44107.61
         8.004212643 "player.c:2460"          0.53          0.0          0.0       27081          8571          62          63       44102.61       44103.01
         8.007750292 "player.c:2460"          0.55          0.0          0.0       28084          8570          62          62       44099.21       44099.61
         8.009131013 "player.c:2460"          0.55          0.0          0.0       29087          8569          62          62       44099.05       44099.44
         8.001473718 "player.c:2460"          0.52          0.0          0.0       30090          8570          62          62       44100.48       44100.88
         8.006753439 "player.c:2460"          0.53          0.0          0.0       31093          8580          62          62       44099.47       44099.86
         8.008456681 "player.c:2460"          0.64          0.0          0.0       32096          8583          62          62       44100.07       44100.46
         8.004026014 "player.c:2460"          0.81          0.0          0.0       33099          8586          62          62       44099.25       44099.65
         8.005356476 "player.c:2460"          0.83          0.0          0.0       34102          8592          62          62       44099.87       44100.27
         8.005457310 "player.c:2460"          0.75          0.0          0.0       35105          8584          62          62       44099.77       44100.16
         8.009463366 "player.c:2460"          0.95          0.0          0.0       36108          8581          62          63       44099.31       44099.70
         8.002845995 "player.c:2460"          1.06          0.0          0.0       37111          8590          62          62       44099.47       44099.87
         8.008321514 "player.c:2460"          1.01          0.0          0.0       38114          8587          62          63       44099.43       44099.82
         8.005144866 "player.c:2460"          1.02          0.0          0.0       39117          8593          62          62       44099.26       44099.65
         8.004249236 "player.c:2460"          0.95          0.0          0.0       40120          8598          62          63       44099.40       44099.79
         8.008767161 "player.c:2460"          1.02          0.0          0.0       41123          8594          62          62       44099.25       44099.65
         8.004949051 "player.c:2460"          1.04          0.0          0.0       42126          8603          62          62       44099.35       44099.74
         8.003843032 "player.c:2460"          1.31          0.0          0.0       43129          8606          62          62       44099.39       44099.79
         8.005330162 "player.c:2460"          1.38          0.0          0.0       44132          8613          62          62       44099.50       44099.90
         8.007646718 "player.c:2460"          1.38         -5.7          5.7       45135          8605          62          63       44099.38       44099.78
         8.924510532 "player.c:2460"          0.68          0.0          0.0       46138          8533           0          63            N/A            N/A
         8.005510347 "player.c:2460"         -0.42          0.0          0.0       47141          8532          62          62       44098.56       44098.95
         8.007622273 "player.c:2460"         -0.41          0.0          0.0       48144          8524          62          62       44101.00       44101.39
         8.005386717 "player.c:2460"         -0.38          0.0          0.0       49147          8528          62          62       44100.41       44100.80
         8.005051829 "player.c:2460"         -0.42          0.0          0.0       50150          8530          62          62       44099.53       44099.92
         8.008862495 "player.c:2460"         -0.36          0.0          0.0       51153          8531          62          63       44098.75       44099.15
         8.007049328 "player.c:2460"         -0.22          0.0          0.0       52156          8541          62          62       44099.26       44099.65
         8.000874033 "player.c:2460"         -0.18          0.0          0.0       53159          8546          62          62       44098.87       44099.26
        10.097408234 "player.c:2460"          0.03          0.0          0.0       54162          8555          62          62            N/A            N/A
         8.005024662 "player.c:2460"          0.20          0.0          0.0       55165          8563          62          62       44101.97       44102.36
         8.010320144 "player.c:2460"          0.06          0.0          0.0       56168          8554          62          62       44098.60       44099.00
         8.001786328 "player.c:2460"          0.11          0.0          0.0       57171          8555          62          62       44100.41       44100.80
         8.009292736 "player.c:2460"          0.16          0.0          0.0       58174          8555          62          62       44099.53       44099.92
         8.006221199 "player.c:2460"          0.19          0.0          0.0       59177          8563          62          62       44099.37       44099.76
         8.005279977 "player.c:2460"          0.24          0.0          0.0       60180          8564          62          62       44099.43       44099.83
         8.003316569 "player.c:2460"          0.25          0.0          0.0       61183          8561          62          62       44099.35       44099.74
         8.008533329 "player.c:2460"          0.33          0.0          0.0       62186          8564          62          63       44099.68       44100.07
         8.002351199 "player.c:2460"          0.38          0.0          0.0       63189          8566          62          62       44099.24       44099.64
         8.010671995 "player.c:2460"          0.42          0.0          0.0       64192          8572          62          62       44099.59       44099.98
         8.003994865 "player.c:2460"          0.45          0.0          0.0       65195          8572          62          63       44099.55       44099.95
         8.003456940 "player.c:2460"          0.48          0.0          0.0       66198          8569          62          63       44099.36       44099.75
         8.006781532 "player.c:2460"          0.53          0.0          0.0       67201          8570          62          62       44099.71       44100.11
         8.005015625 "player.c:2460"          0.61          0.0          0.0       68204          8579          62          62       44099.22       44099.61
         8.007455496 "player.c:2460"          0.68          0.0          0.0       69207          8582          62          62       44099.57       44099.96
         8.004662643 "player.c:2460"          0.74          0.0          0.0       70210          8583          62          63       44099.23       44099.62
         8.006333365 "player.c:2460"          0.78          0.0          0.0       71213          8587          62          62       44099.16       44099.56
         8.004159570 "player.c:2460"          0.79          0.0          0.0       72216          8584          62          62       44099.39       44099.79
         8.009136551 "player.c:2460"          0.91          0.0          0.0       73219          8587          62          62       44099.53       44099.92
         8.004296587 "player.c:2460"          1.01          0.0          0.0       74222          8597          62          63       44099.43       44099.82
         8.006850533 "player.c:2460"          1.03          0.0          0.0       75225          8595          62          63       44099.19       44099.58
         8.005149902 "player.c:2460"          1.06          0.0          0.0       76228          8600          62          62       44099.25       44099.64
         8.006166773 "player.c:2460"          1.07          0.0          0.0       77231          8595          62          62       44099.43       44099.82
         8.004678810 "player.c:2460"          1.21          0.0          0.0       78234          8602          62          63       44099.23       44099.62
         8.006038310 "player.c:2460"          1.25          0.0          0.0       79237          8605          62          63       44099.25       44099.64
         8.007410329 "player.c:2460"          1.35          0.0          0.0       80240          8614          62          63       44099.27       44099.66
         8.007191625 "player.c:2460"          1.42         -2.8          2.8       81243          8608          62          62       44099.20       44099.59
         8.003638051 "player.c:2460"          1.39          0.0          0.0       82246          8613          62          62       44099.25       44099.64
         8.006060124 "player.c:2460"          1.38         -5.7          5.7       83249          8611          62          62       44099.26       44099.66
         8.006992329 "player.c:2460"          1.41         -2.8          2.8       84252          8609          62          62       44099.40       44099.79
         8.003179847 "player.c:2460"          1.45         -5.7          5.7       85255          8608          62          62       44099.41       44099.80
         8.009289180 "player.c:2460"          1.38         -5.7          5.7       86258          8610          62          62       44099.34       44099.73
         8.004058607 "player.c:2460"          1.39         -2.8          2.8       87261          8610          62          62       44099.30       44099.69
         8.006977828 "player.c:2460"          1.43         -2.8          2.8       88264          8613          62          62       44099.28       44099.67
         8.007088829 "player.c:2460"          1.45         -2.8          2.8       89267          8606          62          62       44099.37       44099.76
         8.002693810 "player.c:2460"          1.42          0.0          0.0       90270          8611          62          63       44099.21       44099.60
         8.008169662 "player.c:2460"          1.49         -5.7          5.7       91273          8617          62          62       44099.23       44099.62
         8.005364328 "player.c:2460"          1.50         -8.5          8.5       92276          8611          62          62       44099.23       44099.62
         8.006786107 "player.c:2460"          1.52         -5.7          5.7       93279          8617          62          62       44099.22       44099.61
         8.004505643 "player.c:2460"          1.46         -2.8          2.8       94282          8625          62          62       44099.37       44099.76
         8.004094329 "player.c:2460"          1.41         -5.7          5.7       95285          8621          62          62       44099.35       44099.74
         8.007599069 "player.c:2460"          1.43         -8.5          8.5       96288          8618          62          62       44099.23       44099.62
         8.005108958 "player.c:2460"          1.50         -2.8          2.8       97291          8615          62          62       44099.27       44099.66
         8.007350199 "player.c:2460"          1.56        -19.8         19.8       98294          8623          62          62       44099.28       44099.68
         8.008248940 "player.c:2460"          1.47         -5.7          5.7       99297          8614          62          62       44099.28       44099.68
         8.004529180 "player.c:2460"          1.47         -8.5          8.5      100300          8607          62          62       44099.31       44099.70
         8.005681218 "player.c:2460"          1.47         -8.5          8.5      101303          8619          62          62       44099.27       44099.67
         8.003534069 "player.c:2460"          1.49         -5.7          5.7      102306          8612          62          63       44099.33       44099.72
         8.005420754 "player.c:2460"          1.45         -5.7          5.7      103309          8616          62          62       44099.23       44099.63
         8.009028922 "player.c:2460"          1.45         -2.8          2.8      104312          8610          62          62       44099.32       44099.71
         8.004639124 "player.c:2460"          1.47         -8.5          8.5      105315          8621          62          62       44099.23       44099.62
         8.003464348 "player.c:2460"          1.43         -8.5          8.5      106318          8617          62          62       44099.30       44099.70
         8.005882273 "player.c:2460"          1.45          0.0          0.0      107321          8612          62          62       44099.31       44099.71
         8.007446069 "player.c:2460"          1.47         -5.7          5.7      108324          8613          62          62       44099.33       44099.72
         8.006415384 "player.c:2460"          1.48         -5.7          5.7      109327          8617          62          62       44099.30       44099.69
         8.003721884 "player.c:2460"          1.57         -8.5          8.5      110330          8621          62          62       44099.31       44099.71
         8.010853532 "player.c:2460"          1.50        -11.3         11.3      111333          8624          62          62       44099.27       44099.66
         8.818672458 "player.c:2460"          0.62         -8.5          8.5      112336          8520           0          62            N/A            N/A
         8.003304755 "player.c:2460"         -0.65          0.0          0.0      113339          8518          62          62       44098.94       44099.34
         8.005374643 "player.c:2460"         -0.68          0.0          0.0      114342          8518          62          62       44099.10       44099.49
         8.008306014 "player.c:2460"         -0.61          0.0          0.0      115345          8520          62          62       44100.67       44101.06
         8.002122995 "player.c:2460"         -0.54          0.0          0.0      116348          8525          62          62       44099.80       44100.19
         8.007357069 "player.c:2460"         -0.51          0.0          0.0      117351          8523          62          62       44099.98       44100.37
         8.004795255 "player.c:2460"         -0.50          0.0          0.0      118354          8531          62          62       44099.58       44099.97
         8.005071662 "player.c:2460"         -0.45          0.0          0.0      119357          8531          62          62       44099.18       44099.57
         8.009030495 "player.c:2460"         -0.40          0.0          0.0      120360          8532          62          62       44099.17       44099.56
         8.007015162 "player.c:2460"         -0.36          0.0          0.0      121363          8537          62          62       44099.07       44099.46
         8.001807439 "player.c:2460"         -0.34          0.0          0.0      122366          8535          62          63       44099.56       44099.95
         8.005763496 "player.c:2460"         -0.27          0.0          0.0      123369          8539          62          62       44099.26       44099.65
         8.010610995 "player.c:2460"         -0.20          0.0          0.0      124372          8541          62          62       44099.20       44099.59
         8.003745180 "player.c:2460"         -0.14          0.0          0.0      125375          8548          62          62       44099.65       44100.04
         8.008465347 "player.c:2460"         -0.12          0.0          0.0      126378          8552          62          62       44099.54       44099.93
         8.005402273 "player.c:2460"         -0.16          0.0          0.0      127381          8540          62          62       44099.18       44099.57
         8.002927644 "player.c:2460"         -0.16          0.0          0.0      128384          8540          62          62       44099.29       44099.68
         8.891478087 "player.c:2460"          0.18          0.0          0.0      129387          8557          62          63            N/A            N/A
         9.130971698 "player.c:2460"         -0.11          0.0          0.0      130390          8545          62          62            N/A            N/A
         8.008550125 "player.c:2460"         -0.10          0.0          0.0      131393          8540          62          62       44101.16       44101.55
         8.004715569 "player.c:2460"         -0.08          0.0          0.0      132396          8534          62          62       44100.25       44100.65
         8.003213681 "player.c:2460"         -0.10          0.0          0.0      133399          8542          62          62       44100.02       44100.41
         8.008564273 "player.c:2460"         -0.11          0.0          0.0      134402          8542          62          62       44099.37       44099.76
         8.002146421 "player.c:2460"         -0.05          0.0          0.0      135405          8554          62          62       44099.91       44100.30
         8.007659162 "player.c:2460"          0.17          0.0          0.0      136408          8550          62          62       44099.61       44100.00
         8.007991495 "player.c:2460"          0.26          0.0          0.0      137411          8566          62          62       44099.89       44100.28
         8.006684995 "player.c:2460"          0.28          0.0          0.0      138414          8555          62          62       44099.33       44099.72
         8.003379070 "player.c:2460"          0.30          0.0          0.0      139417          8563          62          62       44099.70       44100.09
         8.005248532 "player.c:2460"          0.24          0.0          0.0      140420          8558          62          63       44099.74       44100.13
         8.004206958 "player.c:2460"          0.30          0.0          0.0      141423          8566          62          62       44099.57       44099.96
         8.007634255 "player.c:2460"          0.39          0.0          0.0      142426          8563          62          62       44099.43       44099.82
         8.005326328 "player.c:2460"          0.40          0.0          0.0      143429          8565          62          62       44099.49       44099.88
         8.005948181 "player.c:2460"          0.37          0.0          0.0      144432          8568          62          62       44099.19       44099.58
         8.005412569 "player.c:2460"          0.32          0.0          0.0      145435          8570          62          62       44099.51       44099.90
         8.006436569 "player.c:2460"          0.39          0.0          0.0      146438          8563          62          62       44099.33       44099.72
         8.006720310 "player.c:2460"          0.23          0.0          0.0      147441          8553          62          62       44099.38       44099.77
         8.004062755 "player.c:2460"          0.38          0.0          0.0      148444          8566          62          62       44099.59       44099.98
         8.008573625 "player.c:2460"          0.48          0.0          0.0      149447          8575          62          62       44099.22       44099.61
         8.003787106 "player.c:2460"          0.56          0.0          0.0      150450          8578          62          62       44099.53       44099.92
         8.009822921 "player.c:2460"          0.54          0.0          0.0      151453          8579          62          62       44099.26       44099.65
         8.006616032 "player.c:2460"          0.56          0.0          0.0      152456          8573          62          62       44099.29       44099.68
         8.005125014 "player.c:2460"          0.53          0.0          0.0      153459          8568          62          62       44099.41       44099.80
         8.003734384 "player.c:2460"          0.44          0.0          0.0      154462          8570          62          62       44099.44       44099.83
         8.007276625 "player.c:2460"          0.25          0.0          0.0      155465          8558          62          63       44099.31       44099.70
         8.004136569 "player.c:2460"          0.31          0.0          0.0      156468          8557          62          62       44099.44       44099.83
         8.006503514 "player.c:2460"          0.34          0.0          0.0      157471          8567          62          62       44099.33       44099.72
         8.008760588 "player.c:2460"          0.25          0.0          0.0      158474          8559          62          62       44099.40       44099.79
         8.002242754 "player.c:2460"          0.30          0.0          0.0      159477          8570          62          63       44099.28       44099.67
         8.005061551 "player.c:2460"          0.37          0.0          0.0      160480          8554          62          63       44099.36       44099.75
         8.010698125 "player.c:2460"          0.50          0.0          0.0      161483          8571          62          62       44099.27       44099.66
         8.004135143 "player.c:2460"          0.50          0.0          0.0      162486          8572          62          62       44099.25       44099.64
         8.006641959 "player.c:2460"          0.63          0.0          0.0      163489          8574          62          62       44099.28       44099.67
         8.002097680 "player.c:2460"          0.65          0.0          0.0      164492          8570          62          62       44099.37       44099.76
         8.007464273 "player.c:2460"          0.62          0.0          0.0      165495          8585          62          63       44099.25       44099.64
         8.009270143 "player.c:2460"          0.57          0.0          0.0      166498          8573          62          62       44099.31       44099.70
         8.002591681 "player.c:2460"          0.56          0.0          0.0      167501          8579          62          62       44099.29       44099.68
         8.004659847 "player.c:2460"          0.52          0.0          0.0      168504          8568          62          62       44099.30       44099.69
         8.006102014 "player.c:2460"          0.50          0.0          0.0      169507          8581          62          63       44099.31       44099.70
         8.006725773 "player.c:2460"          0.64          0.0          0.0      170510          8578          62          63       44099.31       44099.70
         8.005858902 "player.c:2460"          0.67          0.0          0.0      171513          8585          62          63       44099.36       44099.75
         8.007000996 "player.c:2460"          0.63          0.0          0.0      172516          8579          62          62       44099.34       44099.73
         8.008500384 "player.c:2460"          0.53          0.0          0.0      173519          8571          62          62       44099.29       44099.68
         8.005696828 "player.c:2460"          0.57          0.0          0.0      174522          8572          62          62       44099.25       44099.64
         8.003800699 "player.c:2460"          0.68          0.0          0.0      175525          8581          62          62       44099.26       44099.65
         8.007153736 "player.c:2460"          0.69          0.0          0.0      176528          8582          62          62       44099.22       44099.61
         8.003679681 "player.c:2460"          0.68          0.0          0.0      177531          8577          62          62       44099.37       44099.76
         8.004697773 "player.c:2460"          0.63          0.0          0.0      178534          8583          62          62       44099.25       44099.64
         8.008192958 "player.c:2460"          0.55          0.0          0.0      179537          8577          62          62       44099.26       44099.65
         8.007298495 "player.c:2460"          0.62          0.0          0.0      180540          8571          62          62       44099.39       44099.78
         8.001910884 "player.c:2460"          0.60          0.0          0.0      181543          8581          62          62       44099.27       44099.66
         8.010876773 "player.c:2460"          0.61          0.0          0.0      182546          8576          62          62       44099.32       44099.71
         8.003530643 "player.c:2460"          0.52          0.0          0.0      183549          8567          62          63       44099.36       44099.75
         8.008321218 "player.c:2460"          0.60          0.0          0.0      184552          8583          62          62       44099.36       44099.75
         8.002909347 "player.c:2460"          0.65          0.0          0.0      185555          8582          62          62       44099.31       44099.70
         8.005924292 "player.c:2460"          0.71          0.0          0.0      186558          8577          62          62       44099.24       44099.63
         8.005476013 "player.c:2460"          0.83          0.0          0.0      187561          8591          62          63       44099.32       44099.71
         8.006255107 "player.c:2460"          0.87          0.0          0.0      188564          8586          62          62       44099.29       44099.68
         8.006709384 "player.c:2460"          0.88          0.0          0.0      189567          8585          62          62       44099.24       44099.63
         8.007888717 "player.c:2460"          0.84          0.0          0.0      190570          8578          62          62       44099.27       44099.66
         8.003834162 "player.c:2460"          0.72          0.0          0.0      191573          8587          62          63       44099.28       44099.67
         8.003735569 "player.c:2460"          0.72          0.0          0.0      192576          8586          62          62       44099.24       44099.63
         8.010499162 "player.c:2460"          0.66          0.0          0.0      193579          8579          62          62       44099.28       44099.67
         8.005390236 "player.c:2460"          0.55          0.0          0.0      194582          8579          62          62       44099.29       44099.68
         8.005759070 "player.c:2460"          0.64          0.0          0.0      195585          8579          62          63       44099.33       44099.72
         8.006158828 "player.c:2460"          0.66          0.0          0.0      196588          8582          62          62       44099.32       44099.71
         8.002249921 "player.c:2460"          0.76          0.0          0.0      197591          8582          62          63       44099.28       44099.67
         8.008438347 "player.c:2460"          0.79          0.0          0.0      198594          8586          62          63       44099.26       44099.65
         8.004644403 "player.c:2460"          0.84          0.0          0.0      199597          8582          62          62       44099.33       44099.72
         8.007862440 "player.c:2460"          0.87          0.0          0.0      200600          8593          62          63       44099.24       44099.63
         8.004023624 "player.c:2460"          0.95          0.0          0.0      201603          8594          62          62       44099.23       44099.62
         8.003810755 "player.c:2460"          0.99          0.0          0.0      202606          8598          62          62       44099.24       44099.63
         8.006507477 "player.c:2460"          1.02          0.0          0.0      203609          8596          62          62       44099.27       44099.66
         8.005941513 "player.c:2460"          1.01          0.0          0.0      204612          8591          62          63       44099.27       44099.66
         8.005953940 "player.c:2460"          1.11          0.0          0.0      205615          8593          62          63       44099.24       44099.63
         8.007222736 "player.c:2460"          1.22          0.0          0.0      206618          8598          62          62       44099.26       44099.65
         8.006771755 "player.c:2460"          1.25          0.0          0.0      207621          8602          62          62       44099.26       44099.65
         8.006556661 "player.c:2460"          1.05          0.0          0.0      208624          8587          62          62       44099.23       44099.62
         8.006282773 "player.c:2460"          1.11          0.0          0.0      209627          8602          62          62       44099.27       44099.66
         8.005669588 "player.c:2460"          1.23          0.0          0.0      210630          8600          62          63       44099.25       44099.64
         8.005056255 "player.c:2460"          1.30          0.0          0.0      211633          8600          62          62       44099.27       44099.66
         8.004648254 "player.c:2460"          1.31          0.0          0.0      212636          8610          62          62       44099.28       44099.67
         8.006244921 "player.c:2460"          1.30          0.0          0.0      213639          8608          62          62       44099.32       44099.71
         8.004339699 "player.c:2460"          1.35          0.0          0.0      214642          8609          62          62       44099.29       44099.68
         8.005836644 "player.c:2460"          1.36          0.0          0.0      215645          8610          62          62       44099.32       44099.71
         8.006328365 "player.c:2460"          1.42          0.0          0.0      216648          8605          62          62       44099.29       44099.68
         8.010388773 "player.c:2460"          1.43         -2.8          2.8      217651          8615          62          62       44099.30       44099.69
         8.004681921 "player.c:2460"          1.46          0.0          0.0      218654          8601          62          62       44099.29       44099.68
         8.004349848 "player.c:2460"          1.50        -14.2         14.2      219657          8622          62          62       44099.27       44099.66
         8.003970198 "player.c:2460"          1.47         -2.8          2.8      220660          8606          62          62       44099.31       44099.70
         8.009366662 "player.c:2460"          1.46          0.0          0.0      221663          8618          62          62       44099.29       44099.68
         8.004351977 "player.c:2460"          1.41          0.0          0.0      222666          8615          62          63       44099.25       44099.64
         8.006027903 "player.c:2460"          1.48         -8.5          8.5      223669          8617          62          62       44099.26       44099.65
         8.867140254 "player.c:2460"          0.62         -2.8          2.8      224672          8541           0          62            N/A            N/A
         8.005355736 "player.c:2460"         -0.49          0.0          0.0      225675          8535          62          62       44100.77       44101.16
         8.005976939 "player.c:2460"         -0.57          0.0          0.0      226678          8519          62          63       44100.10       44100.49
         8.004453903 "player.c:2460"         -0.47          0.0          0.0      227681          8531          62          62       44098.71       44099.09
         8.007975514 "player.c:2460"         -0.36          0.0          0.0      228684          8535          62          62       44099.24       44099.63
         8.006306884 "player.c:2460"         -0.27          0.0          0.0      229687          8536          62          62       44099.03       44099.42
         8.002049902 "player.c:2460"         -0.28          0.0          0.0      230690          8543          62          62       44098.90       44099.28
         8.005030255 "player.c:2460"         -0.20          0.0          0.0      231693          8539          62          62       44099.22       44099.60
         8.005785217 "player.c:2460"         -0.17          0.0          0.0      232696          8551          62          62       44099.55       44099.94
         8.008192699 "player.c:2460"         -0.07          0.0          0.0      233699          8537          62          62       44099.55       44099.94
         8.008193051 "player.c:2460"          0.05          0.0          0.0      234702          8553          62          63       44099.06       44099.44
         8.005481051 "player.c:2460"          0.02          0.0          0.0      235705          8553          62          62       44099.03       44099.42
         8.003942366 "player.c:2460"          0.07          0.0          0.0      236708          8553          62          62       44099.07       44099.46
         8.005939291 "player.c:2460"          0.05          0.0          0.0      237711          8550          62          63       44099.16       44099.55
         8.003298884 "player.c:2460"          0.11          0.0          0.0      238714          8556          62          62       44099.15       44099.54
         8.008006162 "player.c:2460"          0.20          0.0          0.0      239717          8562          62          62       44099.24       44099.63
         8.003864958 "player.c:2460"          0.21          0.0          0.0      240720          8562          62          62       44099.25       44099.64
         8.008522699 "player.c:2460"          0.25          0.0          0.0      241723          8562          62          62       44099.16       44099.55
         8.007064310 "player.c:2460"          0.30          0.0          0.0      242726          8562          62          62       44099.11       44099.50
         9.020034847 "player.c:2460"         -0.47          0.0          0.0      243729          8523           0          62            N/A            N/A
         8.010445569 "player.c:2460"         -0.52          0.0          0.0      244732          8529          62          62       44094.60       44094.99
         9.189822754 "player.c:2460"         -0.34          0.0          0.0      245735          8524          62          62            N/A            N/A
         8.002763088 "player.c:2460"         -0.31          0.0          0.0      246738          8536          62          62       44096.41       44096.80
         8.009404476 "player.c:2460"         -0.28          0.0          0.0      247741          8538          62          63       44099.18       44099.57
         8.007153551 "player.c:2460"         -0.15          0.0          0.0      248744          8549          62          63       44098.42       44098.81
         8.005605569 "player.c:2460"         -0.10          0.0          0.0      249747          8545          62          62       44098.29       44098.68
         8.005966014 "player.c:2460"         -0.08          0.0          0.0      250750          8544          62          62       44098.65       44099.04
         8.001916366 "player.c:2460"         -0.06          0.0          0.0      251753          8538          62          62       44099.43       44099.82
         8.008817810 "player.c:2460"         -0.03          0.0          0.0      252756          8551          62          62       44098.85       44099.24
         8.003808458 "player.c:2460"          0.03          0.0          0.0      253759          8557          62          62       44099.12       44099.51
         8.004260384 "player.c:2460"          0.14          0.0          0.0      254762          8549          62          63       44098.81       44099.20
         8.007011218 "player.c:2460"          0.11          0.0          0.0      255765          8557          62          62       44098.77       44099.16
         8.007609087 "player.c:2460"          0.18          0.0          0.0      256768          8566          62          62       44099.21       44099.60
         8.005769736 "player.c:2460"          0.28          0.0          0.0      257771          8566          62          62       44098.97       44099.36
         8.005787477 "player.c:2460"          0.24          0.0          0.0      258774          8555          62          63       44099.20       44099.59
         8.004674699 "player.c:2460"          0.20          0.0          0.0      259777          8569          62          63       44099.23       44099.62
         8.007772310 "player.c:2460"          0.25          0.0          0.0      260780          8557          62          62       44099.07       44099.46
         8.006979754 "player.c:2460"          0.39          0.0          0.0      261783          8570          62          62       44099.05       44099.44
         8.006709033 "player.c:2460"          0.38          0.0          0.0      262786          8577          62          62       44099.37       44099.76
         8.005098514 "player.c:2460"          0.42          0.0          0.0      263789          8566          62          62       44099.21       44099.60
         8.005525254 "player.c:2460"          0.51          0.0          0.0      264792          8571          62          62       44099.13       44099.52
         8.004382069 "player.c:2460"          0.61          0.0          0.0      265795          8577          62          63       44099.03       44099.42
         8.004149514 "player.c:2460"          0.64          0.0          0.0      266798          8579          62          62       44099.00       44099.39
         8.008191069 "player.c:2460"          0.72          0.0          0.0      267801          8585          62          62       44099.02       44099.41
         8.005774347 "player.c:2460"          0.70          0.0          0.0      268804          8579          62          63       44099.09       44099.48
         8.007469199 "player.c:2460"          0.77          0.0          0.0      269807          8589          62          62       44099.14       44099.52
         8.002378329 "player.c:2460"          0.86          0.0          0.0      270810          8593          62          62       44099.16       44099.55
         8.005244347 "player.c:2460"          0.93          0.0          0.0      271813          8591          62          62       44099.22       44099.61
         8.005580032 "player.c:2460"          1.02          0.0          0.0      272816          8595          62          62       44099.18       44099.57
         8.008081014 "player.c:2460"          1.03          0.0          0.0      273819          8598          62          62       44099.07       44099.46
         8.004158903 "player.c:2460"          1.10          0.0          0.0      274822          8605          62          62       44099.16       44099.55
         8.006916902 "player.c:2460"          1.15          0.0          0.0      275825          8608          62          62       44099.16       44099.55
         8.006682699 "player.c:2460"          1.19          0.0          0.0      276828          8600          62          63       44099.33       44099.72
         8.004153088 "player.c:2460"          1.14          0.0          0.0      277831          8594          62          62       44099.30       44099.69
         8.009321329 "player.c:2460"          1.24          0.0          0.0      278834          8606          62          62       44099.23       44099.61
         8.004450773 "player.c:2460"          1.29          0.0          0.0      279837          8610          62          62       44099.13       44099.52
         8.005129976 "player.c:2460"          1.37          0.0          0.0      280840          8612          62          62       44099.17       44099.56
         8.005486125 "player.c:2460"          1.34          0.0          0.0      281843          8614          62          62       44099.16       44099.55
         8.005800384 "player.c:2460"          1.43          0.0          0.0      282846          8613          62          62       44099.23       44099.62
         8.007892847 "player.c:2460"          1.46         -5.7          5.7      283849          8615          62          62       44099.15       44099.54
         8.007526644 "player.c:2460"          1.47         -5.7          5.7      284852          8615          62          62       44099.17       44099.56
         8.005407810 "player.c:2460"          1.50         -5.7          5.7      285855          8618          62          62       44099.29       44099.67
         8.003858569 "player.c:2460"          1.51         -5.7          5.7      286858          8618          62          62       44099.19       44099.58
         8.005916884 "player.c:2460"          1.43          0.0          0.0      287861          8611          62          62       44099.20       44099.59
         8.007920329 "player.c:2460"          1.48         -8.5          8.5      288864          8610          62          63       44099.16       44099.55
         8.003694902 "player.c:2460"          1.45         -8.5          8.5      289867          8610          62          63       44099.18       44099.57
         8.007606199 "player.c:2460"          1.43         -5.7          5.7      290870          8613          62          63       44099.19       44099.58
         8.002665681 "player.c:2460"          1.51         -5.7          5.7      291873          8618          62          62       44099.28       44099.67
         8.007442773 "player.c:2460"          1.41          0.0          0.0      292876          8612          62          63       44099.18       44099.57
         8.006264680 "player.c:2460"          1.47        -11.3         11.3      293879          8620          62          62       44099.17       44099.56
         8.005301384 "player.c:2460"          1.47         -5.7          5.7      294882          8615          62          63       44099.19       44099.58
         8.004393107 "player.c:2460"          1.45        -11.3         11.3      295885          8615          62          62       44099.20       44099.59
         8.005518606 "player.c:2460"          1.50         -8.5          8.5      296888          8616          62          62       44099.20       44099.59
         8.008345829 "player.c:2460"          1.54        -17.0         17.0      297891          8623          62          62       44099.19       44099.58
         8.005799958 "player.c:2460"          1.58        -14.2         14.2      298894          8624          62          62       44099.24       44099.63
         8.006291606 "player.c:2460"          1.51        -14.2         14.2      299897          8618          62          63       44099.21       44099.60
         8.006043477 "player.c:2460"          1.40          0.0          0.0      300900          8609          62          62       44099.21       44099.60
         8.006509347 "player.c:2460"          1.40          0.0          0.0      301903          8616          62          62       44099.18       44099.57
         8.006662347 "player.c:2460"          1.45         -5.7          5.7      302906          8612          62          62       44099.28       44099.67
         8.004127236 "player.c:2460"          1.43          0.0          0.0      303909          8610          62          63       44099.25       44099.64
         8.003808958 "player.c:2460"          1.38         -5.7          5.7      304912          8606          62          62       44099.19       44099.58
         8.008272551 "player.c:2460"          1.39          0.0          0.0      305915          8612          62          62       44099.27       44099.66
         8.004168365 "player.c:2460"          1.40         -2.8          2.8      306918          8616          62          62       44099.25       44099.64
         8.009373088 "player.c:2460"          1.43         -2.8          2.8      307921          8618          62          62       44099.19       44099.58
         8.005220477 "player.c:2460"          1.46         -5.7          5.7      308924          8613          62          62       44099.22       44099.61
         8.006781403 "player.c:2460"          1.47         -8.5          8.5      309927          8612          62          62       44099.22       44099.61
         8.002254791 "player.c:2460"          1.46         -5.7          5.7      310930          8615          62          62       44099.26       44099.65
         8.009593273 "player.c:2460"          1.47         -5.7          5.7      311933          8618          62          62       44099.19       44099.58
         8.002496699 "player.c:2460"          1.52         -8.5          8.5      312936          8613          62          62       44099.26       44099.65
         8.007870199 "player.c:2460"          1.46         -5.7          5.7      313939          8614          62          62       44099.22       44099.61
         8.004390180 "player.c:2460"          1.46         -8.5          8.5      314942          8607          62          63       44099.26       44099.65
         8.006352718 "player.c:2460"          1.45         -2.8          2.8      315945          8624          62          62       44099.24       44099.63
         8.003315143 "player.c:2460"          1.52         -5.7          5.7      316948          8613          62          62       44099.22       44099.61
         8.007003736 "player.c:2460"          1.46         -5.7          5.7      317951          8602          62          62       44099.21       44099.60
         8.009081014 "player.c:2460"          1.45          0.0          0.0      318954          8614          62          62       44099.20       44099.59
         8.002841069 "player.c:2460"          1.47         -2.8          2.8      319957          8615          62          62       44099.24       44099.63
         8.007487699 "player.c:2460"          1.43        -11.3         11.3      320960          8606          62          62       44099.24       44099.63
         8.004202070 "player.c:2460"          1.27          0.0          0.0      321963          8605          62          62       44099.22       44099.61
         8.006362995 "player.c:2460"          1.31          0.0          0.0      322966          8619          62          62       44099.20       44099.59
         8.007988291 "player.c:2460"          1.39          0.0          0.0      323969          8607          62          62       44099.22       44099.61
         8.007318162 "player.c:2460"          1.47        -14.2         14.2      324972          8612          62          62       44099.18       44099.57
         8.003319588 "player.c:2460"          1.48         -8.5          8.5      325975          8611          62          62       44099.25       44099.64
         8.007165736 "player.c:2460"          1.39          0.0          0.0      326978          8608          62          62       44099.27       44099.66
         8.007086551 "player.c:2460"          1.48        -14.2         14.2      327981          8610          62          62       44099.25       44099.64
         8.005487217 "player.c:2460"          1.39         -2.8          2.8      328984          8612          62          62       44099.25       44099.64
         8.003188514 "player.c:2460"          1.39          0.0          0.0      329987          8607          62          63       44099.25       44099.63
         8.005888254 "player.c:2460"          1.46        -11.3         11.3      330990          8621          62          62       44099.26       44099.65
         8.006769736 "player.c:2460"          1.43         -5.7          5.7      331993          8620          62          62       44099.21       44099.60
         8.007824847 "player.c:2460"          1.43         -8.5          8.5      332996          8607          62          62       44099.25       44099.63
         8.003460051 "player.c:2460"          1.32          0.0          0.0      333999          8604          62          63       44099.22       44099.61
         8.008192755 "player.c:2460"          1.22          0.0          0.0      335002          8603          62          62       44099.23       44099.62
         8.005037162 "player.c:2460"          1.25          0.0          0.0      336005          8606          62          62       44099.21       44099.60
         8.003130847 "player.c:2460"          1.36          0.0          0.0      337008          8607          62          63       44099.22       44099.61
         8.007996106 "player.c:2460"          1.41          0.0          0.0      338011          8611          62          62       44099.19       44099.58
         8.007053755 "player.c:2460"          1.42         -5.7          5.7      339014          8609          62          62       44099.21       44099.60
         8.003623384 "player.c:2460"          1.49         -5.7          5.7      340017          8610          62          62       44099.25       44099.64
         8.007166569 "player.c:2460"          1.45         -5.7          5.7      341020          8612          62          62       44099.27       44099.65
         8.006806310 "player.c:2460"          1.39         -2.8          2.8      342023          8605          62          62       44099.22       44099.61
         8.002886217 "player.c:2460"          1.40          0.0          0.0      343026          8613          62          63       44099.20       44099.58
         8.006921014 "player.c:2460"          1.37         -2.8          2.8      344029          8608          62          62       44099.24       44099.63
         8.006008810 "player.c:2460"          1.38         -2.8          2.8      345032          8610          62          63       44099.24       44099.63
         8.004674736 "player.c:2460"          1.36          0.0          0.0      346035          8607          62          62       44099.20       44099.59
         8.010285699 "player.c:2460"          1.41         -8.5          8.5      347038          8612          62          63       44099.25       44099.64
         8.003472347 "player.c:2460"          1.43         -8.5          8.5      348041          8608          62          62       44099.23       44099.62
         8.007926829 "player.c:2460"          1.39          0.0          0.0      349044          8610          62          63       44099.26       44099.65
         8.003689495 "player.c:2460"          1.45         -2.8          2.8      350047          8618          62          62       44099.23       44099.62
         8.008725810 "player.c:2460"          1.42          0.0          0.0      351050          8619          62          62       44099.25       44099.64
         8.002105125 "player.c:2460"          1.48         -2.8          2.8      352053          8610          62          62       44099.22       44099.61
         8.005403625 "player.c:2460"          1.54         -8.5          8.5      353056          8615          62          62       44099.22       44099.61
         8.009675310 "player.c:2460"          1.46        -19.8         19.8      354059          8613          61          62       44099.23       44099.61
         8.003249347 "player.c:2460"          1.34          0.0          0.0      355062          8606          62          62       44099.23       44099.61
         8.008640421 "player.c:2460"          1.40          0.0          0.0      356065          8607          62          62       44099.21       44099.60
         8.006237569 "player.c:2460"          1.44         -2.8          2.8      357068          8617          62          63       44099.23       44099.62
         8.003133570 "player.c:2460"          1.39          0.0          0.0      358071          8606          62          62       44099.20       44099.59
         8.007476069 "player.c:2460"          1.42          0.0          0.0      359074          8612          62          62       44099.25       44099.64
         8.005704940 "player.c:2460"          1.42          0.0          0.0      360077          8612          62          62       44099.23       44099.62
         8.006069513 "player.c:2460"          1.48         -5.7          5.7      361080          8615          62          62       44099.23       44099.62
         8.002747051 "player.c:2460"          1.46        -11.3         11.3      362083          8620          62          63       44099.22       44099.61
         8.005323921 "player.c:2460"          1.52        -11.3         11.3      363086          8611          62          62       44099.22       44099.61
         8.010486440 "player.c:2460"          1.53        -14.2         14.2      364089          8615          62          62       44099.26       44099.65
         8.005818236 "player.c:2460"          1.41         -5.7          5.7      365092          8612          62          62       44099.23       44099.62
         8.006500254 "player.c:2460"          1.42          0.0          0.0      366095          8605          62          62       44099.26       44099.65
         8.002940144 "player.c:2460"          1.41         -2.8          2.8      367098          8613          62          62       44099.23       44099.62
         8.008491069 "player.c:2460"          1.43         -5.7          5.7      368101          8617          62          63       44099.26       44099.65
         8.005631143 "player.c:2460"          1.41         -2.8          2.8      369104          8617          62          62       44099.21       44099.60
         8.003763866 "player.c:2460"          1.46         -5.7          5.7      370107          8608          62          62       44099.22       44099.61
         8.003780125 "player.c:2460"          1.45         -5.7          5.7      371110          8612          62          63       44099.26       44099.65
         8.007570903 "player.c:2460"          1.47         -5.7          5.7      372113          8618          62          62       44099.23       44099.62
         8.004339569 "player.c:2460"          1.43          0.0          0.0      373116          8609          62          62       44099.21       44099.60
         8.009453588 "player.c:2460"          1.38          0.0          0.0      374119          8603          62          62       44099.26       44099.65
         5.109932626 "player.c:2627" Large positive sync error of: 3377 frames (0.076576 seconds), with frame: 3531848118.
         0.010979315 "common.c:1544" Timed out waiting for a mutex, having waited 0.010064 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.009468000 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.019535592 sec.
         0.579770703 "player.c:2627" Large positive sync error of: 4890 frames (0.110884 seconds), with frame: 3531874518.
         0.010608408 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.009914092 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020001166 sec.
         0.578873296 "player.c:2627" Large positive sync error of: 5013 frames (0.113673 seconds), with frame: 3531900918.
         0.010639204 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000464815 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010552185 sec.
         0.587594703 "player.c:2627" Large positive sync error of: 4871 frames (0.110454 seconds), with frame: 3531927318.
         0.010212778 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002207130 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012294389 sec.
         0.587347555 "player.c:2627" Large positive sync error of: 4885 frames (0.110771 seconds), with frame: 3531953718.
         0.010737592 "common.c:1544" Timed out waiting for a mutex, having waited 0.010079 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001921315 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012008037 sec.
         0.585098315 "player.c:2627" Large positive sync error of: 5027 frames (0.113991 seconds), with frame: 3531980118.
         0.010568611 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004335907 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014422185 sec.
         0.582688426 "player.c:2627" Large positive sync error of: 4899 frames (0.111088 seconds), with frame: 3532006518.
         0.011139481 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006198185 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016284241 sec.
         0.590024889 "player.c:2627" Large positive sync error of: 4849 frames (0.109955 seconds), with frame: 3532033270.
         0.010589278 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.009397778 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.019485704 sec.
         0.576361944 "player.c:2627" Large positive sync error of: 4870 frames (0.110431 seconds), with frame: 3532059670.
         0.010353444 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003295667 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013380111 sec.
         0.588976148 "player.c:2627" Large positive sync error of: 4946 frames (0.112154 seconds), with frame: 3532086070.
         0.010967537 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000071277 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010162723 sec.
         0.588382889 "player.c:2627" Large positive sync error of: 4911 frames (0.111361 seconds), with frame: 3532112470.
         0.010376981 "common.c:1544" Timed out waiting for a mutex, having waited 0.010077 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001230797 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011314574 sec.
         0.586143444 "player.c:2627" Large positive sync error of: 5075 frames (0.115079 seconds), with frame: 3532138870.
         0.010530852 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003303426 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013388463 sec.
         0.585404870 "player.c:2627" Large positive sync error of: 5032 frames (0.114104 seconds), with frame: 3532165270.
         0.010516851 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004152926 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014240260 sec.
         0.583368963 "player.c:2627" Large positive sync error of: 4952 frames (0.112290 seconds), with frame: 3532191670.
         0.010605130 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006001129 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016087908 sec.
         0.579342722 "player.c:2627" Large positive sync error of: 4752 frames (0.107755 seconds), with frame: 3532218070.
         0.010344945 "common.c:1544" Timed out waiting for a mutex, having waited 0.010082 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.020296444 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.030387408 sec.
         0.566917481 "player.c:2627" Large positive sync error of: 4706 frames (0.106712 seconds), with frame: 3532244470.
         0.010428037 "common.c:1544" Timed out waiting for a mutex, having waited 0.010243 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002765130 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013015815 sec.
         0.590522129 "player.c:2627" Large positive sync error of: 5026 frames (0.113968 seconds), with frame: 3532270870.
         0.010737148 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008649296 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018741574 sec.
         0.577904204 "player.c:2627" Large positive sync error of: 4947 frames (0.112177 seconds), with frame: 3532297270.
         0.010575963 "common.c:1544" Timed out waiting for a mutex, having waited 0.010087 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001617148 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011710408 sec.
         0.584767055 "player.c:2627" Large positive sync error of: 4975 frames (0.112812 seconds), with frame: 3532323670.
         0.010331815 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004901944 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014994463 sec.
         0.582974056 "player.c:2627" Large positive sync error of: 4937 frames (0.111950 seconds), with frame: 3532350070.
         0.010269018 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006747463 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016840444 sec.
         0.584042500 "player.c:2627" Large positive sync error of: 4939 frames (0.111995 seconds), with frame: 3532376470.
         0.594771203 "player.c:2627" Large positive sync error of: 4697 frames (0.106508 seconds), with frame: 3532402870.
         0.010587574 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000611704 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010705371 sec.
         0.588844981 "player.c:2627" Large positive sync error of: 4866 frames (0.110340 seconds), with frame: 3532429270.
         0.010600167 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000476240 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010564611 sec.
         0.586883519 "player.c:2627" Large positive sync error of: 4880 frames (0.110658 seconds), with frame: 3532455670.
         0.010565203 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002575889 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012662296 sec.
         0.587162203 "player.c:2627" Large positive sync error of: 4884 frames (0.110748 seconds), with frame: 3532482070.
         0.010374019 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002465426 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012552555 sec.
         0.588454518 "player.c:2627" Large positive sync error of: 4931 frames (0.111814 seconds), with frame: 3532508470.
         0.011406611 "common.c:1544" Timed out waiting for a mutex, having waited 0.010394 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000155000 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010558352 sec.
        46.752111713 "player.c:1636" Connection 1: Playback Stopped. Total playing time 00:51:08. Input: 430306.92,  Output: 44099.26 (raw), 44099.65 (corrected) frames per second.
        14.071837566 "rtsp.c:2667" Connection 2: Remote Control connection from 192.168.1.112:57145 to self at 192.168.1.223:7000.
         3.779561535 "rtsp.c:2645" Connection 3: AP2 PTP connection from 192.168.1.112:57148 to self at 192.168.1.223:7000.
         3.696025831 "rtsp.c:3032" Connection 3. AP2 Buffered Audio Stream.
         0.211922370 "rtp.c:1279" Connection 3: Set Anchor Clock: d81c79ee45af0008.
         0.000647667 "rtp.c:1385" Connection 3: Clock d81c79ee45af0008 is now the new anchor clock and master clock. History: 3612.867109 milliseconds.
         0.000173463 "rtp.c:1470" Connection 3: NQPTP new master clock d81c79ee45af0008.
         8.295254883 "player.c:2460" sync error ms net sync ppm all sync ppm     packets min DAC queue min buffers max buffers output fps (r) output fps (c)
         0.000164945 "player.c:2460"         -1.09          2.9          2.9        1003          6741          62          62            N/A            N/A
         8.009184569 "player.c:2460"         -1.14          2.8          2.8        2006          8501          62          62       44097.87       44098.26
         8.001543070 "player.c:2460"         -1.09          0.0          0.0        3009          8505          62          62       44099.23       44099.61
         8.005464791 "player.c:2460"         -1.02          0.0          0.0        4012          8505          62          62       44099.01       44099.40
         8.009449717 "player.c:2460"         -0.95          0.0          0.0        5015          8510          62          62       44099.34       44099.73
         8.006123107 "player.c:2460"         -0.96          0.0          0.0        6018          8510          62          63       44099.30       44099.69
         8.003965551 "player.c:2460"         -0.94          0.0          0.0        7021          8512          62          62       44099.46       44099.85
         8.008089754 "player.c:2460"         -0.84          0.0          0.0        8024          8507          62          62       44098.87       44099.25
         8.003653792 "player.c:2460"         -0.82          0.0          0.0        9027          8509          62          62       44099.12       44099.51
         8.007865791 "player.c:2460"         -0.72          0.0          0.0       10030          8515          62          62       44099.48       44099.86
         8.004252273 "player.c:2460"         -0.66          0.0          0.0       11033          8518          62          62       44099.17       44099.56
         8.008086773 "player.c:2460"         -0.57          0.0          0.0       12036          8528          62          62       44099.32       44099.71
         8.003660903 "player.c:2460"         -0.57          0.0          0.0       13039          8519          62          62       44099.11       44099.50
         8.005874588 "player.c:2460"         -0.51          0.0          0.0       14042          8531          62          62       44099.17       44099.56
         8.008484347 "player.c:2460"         -0.51          0.0          0.0       15045          8530          62          62       44099.45       44099.84
         8.002374939 "player.c:2460"         -0.53          0.0          0.0       16048          8535          62          62       44099.20       44099.59
         8.005370551 "player.c:2460"         -0.44          0.0          0.0       17051          8528          62          62       44099.20       44099.59
         8.007504384 "player.c:2460"         -0.43          0.0          0.0       18054          8537          62          62       44099.19       44099.58
         8.004670958 "player.c:2460"         -0.36          0.0          0.0       19057          8534          62          62       44099.22       44099.61
         8.007192996 "player.c:2460"         -0.28          0.0          0.0       20060          8542          62          62       44099.35       44099.73
         8.004771421 "player.c:2460"         -0.18          0.0          0.0       21063          8545          62          63       44099.26       44099.65
         8.005096125 "player.c:2460"         -0.18          0.0          0.0       22066          8537          62          62       44099.41       44099.80
         8.008756032 "player.c:2460"         -0.14          0.0          0.0       23069          8539          62          62       44099.20       44099.59
         8.007576180 "player.c:2460"         -0.13          0.0          0.0       24072          8548          62          62       44099.22       44099.61
         8.002752922 "player.c:2460"         -0.07          0.0          0.0       25075          8544          62          63       44099.17       44099.56
        17.499457045 "player.c:2627" Large positive sync error of: 3606 frames (0.081769 seconds), with frame: 4205115056.
         0.010784907 "common.c:1544" Timed out waiting for a mutex, having waited 0.010063 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.002532389 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.012599556 sec.
         0.581560629 "player.c:2627" Large positive sync error of: 4843 frames (0.109819 seconds), with frame: 4205141456.
         0.010730056 "common.c:1544" Timed out waiting for a mutex, having waited 0.010117 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008027129 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018152166 sec.
         0.579809426 "player.c:2627" Large positive sync error of: 4867 frames (0.110363 seconds), with frame: 4205167856.
         0.010394185 "common.c:1544" Timed out waiting for a mutex, having waited 0.010085 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.009756389 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.019848759 sec.
         0.579900185 "player.c:2627" Large positive sync error of: 4838 frames (0.109705 seconds), with frame: 4205194256.
         0.011586574 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008521296 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018614630 sec.
         0.589492389 "player.c:2627" Large positive sync error of: 5091 frames (0.115442 seconds), with frame: 4205221008.
         0.010611370 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.009898167 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.019992685 sec.
         0.576070925 "player.c:2627" Large positive sync error of: 4858 frames (0.110159 seconds), with frame: 4205247408.
         0.010380074 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.003535908 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.013621611 sec.
         0.584676500 "player.c:2627" Large positive sync error of: 4915 frames (0.111451 seconds), with frame: 4205273808.
         0.010646518 "common.c:1544" Timed out waiting for a mutex, having waited 0.010082 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.004713037 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.014801759 sec.
         0.580703000 "player.c:2627" Large positive sync error of: 4845 frames (0.109864 seconds), with frame: 4205300208.
         0.010541629 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008748241 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018836166 sec.
         0.581207055 "player.c:2627" Large positive sync error of: 4841 frames (0.109773 seconds), with frame: 4205326608.
         0.010689389 "common.c:1544" Timed out waiting for a mutex, having waited 0.010078 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.008094074 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.018179981 sec.
         0.579221518 "player.c:2627" Large positive sync error of: 4847 frames (0.109909 seconds), with frame: 4205353008.
         0.010637574 "common.c:1544" Timed out waiting for a mutex, having waited 0.010084 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.010167149 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.020260667 sec.
         0.577775796 "player.c:2627" Large positive sync error of: 4949 frames (0.112222 seconds), with frame: 4205379408.
         0.010533833 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001696444 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011786111 sec.
         0.587741889 "player.c:2627" Large positive sync error of: 4856 frames (0.110113 seconds), with frame: 4205405808.
         0.010680574 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001594537 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011683833 sec.
         0.588058944 "player.c:2627" Large positive sync error of: 5087 frames (0.115351 seconds), with frame: 4205432208.
         0.010821889 "common.c:1544" Timed out waiting for a mutex, having waited 0.010080 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.001114241 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.011202963 sec.
         0.582336814 "player.c:2627" Large positive sync error of: 4843 frames (0.109819 seconds), with frame: 4205458608.
         0.010680111 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007026963 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017116167 sec.
         0.582094037 "player.c:2627" Large positive sync error of: 4852 frames (0.110023 seconds), with frame: 4205485008.
         0.010646315 "common.c:1544" Timed out waiting for a mutex, having waited 0.010086 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007223203 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017317129 sec.
         0.581917648 "player.c:2627" Large positive sync error of: 4850 frames (0.109977 seconds), with frame: 4205511408.
         0.010669334 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007422074 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017511352 sec.
         0.582388296 "player.c:2627" Large positive sync error of: 5108 frames (0.115828 seconds), with frame: 4205537808.
         0.010584518 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007027148 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017116537 sec.
         0.578403333 "player.c:2627" Large positive sync error of: 4925 frames (0.111678 seconds), with frame: 4205564208.
         0.010936611 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000667556 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010756833 sec.
         0.588157592 "player.c:2627" Large positive sync error of: 4894 frames (0.110975 seconds), with frame: 4205590608.
         0.011216852 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.000632852 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.010720666 sec.
         0.593233111 "player.c:2627" Large positive sync error of: 4870 frames (0.110431 seconds), with frame: 4205617360.
         0.010615463 "common.c:1544" Timed out waiting for a mutex, having waited 0.010088 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.006133444 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.016227482 sec.
         0.581827777 "player.c:2627" Large positive sync error of: 4867 frames (0.110363 seconds), with frame: 4205643760.
         0.011085149 "common.c:1544" Timed out waiting for a mutex, having waited 0.010081 seconds with a maximum waiting time of 0.010000 seconds. "rtp.c:2378".
         0.007095666 "common.c:1605" Mutex_lock "&conn->flush_mutex" at "rtp.c:2378" expected max wait: 0.010000000, actual wait: 0.017186630 sec.

mikebrady commented 2 years ago

Thanks for the reports. @handcc, what are you running Shairport Sync on, please?

Also, if you use a different music source (e.g. an iPhone instead of a HomePod 0G; a Mac instead of an iPhone), does the problem persist?

Meantime, I'll be trying to reproduce these issues here. Unfortunately, I only have a Pi4 for the next few weeks.

mikebrady commented 2 years ago

Just a quick suggestion to make sure you have only one copy of nqptp running. It's very unlikely, but it's a quick check:

$ ps aux | grep nqptp | grep -v grep
root         665  0.5  0.0   2284   564 ?        SLs  Mar10   5:19 /usr/local/bin/nqptp

handcc commented 2 years ago

I am running on a Pi4 with the latest version of Bullseye.

pi@raspberrypi:~ $ ps aux | grep nqptp | grep -v grep root 446 0.5 0.0 2204 464 ? SLs Mar09 6:58 /usr/local/bin/nqptp

I'll test from another source later today.

mikebrady commented 2 years ago

Thanks. I've tried my Pi4 on a [limted] number of different networks and with different sources today and it's working like a champ. So I'm wondering if there is any history of network issues at your end? NQPTP doesn't currently have any metrics for perceived network quality, unfortunately.

mikebrady commented 2 years ago

Just another suggestion -- if you are getting Apple Music losslessly, is it possible that it's not coming in quickly enough? It's another quick test -- just by switching off lossless and/or high-resolution on the HomePod / iPhone or Mac, you can quickly tell if it makes a difference...

handcc commented 2 years ago

My network is pretty solid. I tested again using another device and also the original device, so far so good. Will report back if that changes.

handcc commented 2 years ago

I've found I can make it happen somewhat reliably by streaming apple music lossless and skipping tracks. If I let a song start playing, and skip to next track is happens ~20% of the time. Does not appear to happen when streaming AAC.

mikebrady commented 2 years ago

I've found I can make it happen somewhat reliably by streaming apple music lossless and skipping tracks. If I let a song start playing, and skip to next track is happens ~20% of the time. Does not appear to happen when streaming AAC.

That's interesting, thanks. I'll see if I can manufacture a few scenarios...

handcc commented 2 years ago

I'm also able to reliably make it happen using Overcast (podcast player) when using the 30 second skip forward/back.

mikebrady commented 2 years ago

Thanks. It would be great to see the statistics logged during these events.

To that end, I've just pushed an update to the development branch to include the minimum buffer size for Buffered Audio streams. This would give us an idea about whether audio is arriving quickly enough at the Shairport Sync device.

The iOS Music app plays Buffered Audio streams and Overcast uses Realtime Audio streams.

For Realtime Audio streams, the statistics log already includes the minimum and maximum number of audio frames -- which are received directly from the source -- waiting to be played, so again it should give some insight into the timeliness of audio arriving at Shairport Sync.

So if you got a chance to log statistics during these issues, it could be illuminating!

mikebrady commented 2 years ago

Actually, Overcast seems to use both Buffered Audio and Realtime Audio. Interesting.

mikebrady commented 2 years ago

@handcc, one of the things that is pretty odd about the logs is that the interval between the sync errors is always 26,400 frames, which is exactly 75 packets of 352 frames each. That is pretty remarkable, and I can't explain it, except that it might happen if the output device -- presumably a DAC -- had suddenly stopped accepting packets. This is very unlikely, of course, but not completely impossible. So, could you say what the output device is, please?

Update. Well I can sort-of rationalise the 75 packets: it's the number of packets in the buffer, which will be flushed, plus another 100 ms of flushing. Each packet is 352 frames, taking 352/44100 seconds, approximately 7.981 milliseconds. Thus 100 ms is approximately 12 frames. Shairport Sync responds to the large positive sync error by deleting all 63 packets that are buffered plus 12 due to the extra 100 ms, giving 75 packets in all. So, if the output device suddenly refused to accept packets, it could account for the behaviour. Possibly. Whaddyathink?

handcc commented 2 years ago

Thanks for the prompt response and support. Output device is an XMC-1 AVR, connected via USB, essentially a USB DAC. Haven't had problems in the past.

I upgraded to the latest dev version. I am no longer getting the errors or interruption on playback, and instead I'm seeing these "rtp.c:1946" buffered_read: waiting for ### bytes." where I believe the errors would have occurred before, and playback is not interrupted. Appears the update has resolved the issue.

 pi@raspberrypi:~ $ shairport-sync -vu --statistics
         0.000575112 "shairport.c:1924" Started in Airplay 2 mode with features 0x405c4a00,0x1c340 on device "dc:a6:32:a3:9c:1b"!
         0.000118851 "shairport.c:1967" software version: "4.1-dev-235-g1df7939d-AirPlay2-alac-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc"
         0.000020093 "shairport.c:1973" log verbosity is 1.
         0.000042667 "audio_alsa.c:1002" alsa: alsa_maximum_stall_time of 0.200000 sec.
         0.000039129 "audio_alsa.c:1156" alsa output rate is 44100 frames per second
         0.000022500 "audio_alsa.c:1291" alsa: disable_standby_mode is "never".
         0.000015241 "audio_alsa.c:1295" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
         0.000015426 "audio_alsa.c:1297" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
         0.000020667 "audio_alsa.c:1337" alsa: output device name is "hw:CARD=XMC1,DEV=0".
         0.000208037 "shairport.c:2002" libsodium initialised.
         0.000288926 "shairport.c:2052" disable resend requests is off.
         0.000023037 "shairport.c:2053" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000019703 "shairport.c:2057" statistics_requester status is 1.
         0.000016408 "shairport.c:2062" rtsp listening port is 7000.
         0.000016240 "shairport.c:2063" udp base port is 6001.
         0.000017741 "shairport.c:2064" udp port range is 10.
         0.000016000 "shairport.c:2065" player name is "RPi-AirPlay".
         0.000016000 "shairport.c:2066" backend is "alsa".
         0.000017241 "shairport.c:2067" run_this_before_play_begins action is "(null)".
         0.000016537 "shairport.c:2068" run_this_after_play_ends action is "(null)".
         0.000016444 "shairport.c:2069" wait-cmd status is 0.
         0.000016371 "shairport.c:2070" run_this_before_play_begins may return output is 0.
         0.000016185 "shairport.c:2071" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000016444 "shairport.c:2073" run_this_before_entering_active_state action is  "(null)".
         0.000016130 "shairport.c:2075" run_this_after_exiting_active_state action is  "(null)".
         0.000016259 "shairport.c:2077" active_state_timeout is  10.000000 seconds.
         0.000018556 "shairport.c:2078" mdns backend "(null)".
         0.000015981 "shairport.c:2080" interpolation setting is "auto".
         0.000016074 "shairport.c:2084" interpolation soxr_delay_threshold is 30.
         0.000016426 "shairport.c:2085" resync time is 0.050000 seconds.
         0.000016426 "shairport.c:2086" allow a session to be interrupted: 0.
         0.000015945 "shairport.c:2087" busy timeout time is 0.
         0.000015889 "shairport.c:2088" drift tolerance is 0.001995 seconds.
         0.000016296 "shairport.c:2089" password is "(null)".
         0.000015667 "shairport.c:2090" ignore_volume_control is 1.
         0.000016092 "shairport.c:2094" volume_max_db is not set
         0.000016167 "shairport.c:2095" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000016722 "shairport.c:2097" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000016519 "shairport.c:2101" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000016277 "shairport.c:2103" disable_synchronization is 0.
         0.000015889 "shairport.c:2104" use_mmap_if_available is 1.
         0.000015741 "shairport.c:2105" output_format automatic selection is disabled.
         0.000016259 "shairport.c:2108" output_format is "S24_3LE".
         0.000015667 "shairport.c:2109" output_rate automatic selection is disabled.
         0.000016315 "shairport.c:2112" output_rate is 44100.
         0.000015759 "shairport.c:2113" audio backend desired buffer length is 0.200000 seconds.
         0.000016944 "shairport.c:2115" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
         0.000017260 "shairport.c:2117" audio backend latency offset is 0.000000 seconds.
         0.000016592 "shairport.c:2119" audio backend silence lead-in time is "auto".
         0.000015871 "shairport.c:2123" zeroconf regtype is "_raop._tcp".
         0.000016222 "shairport.c:2124" decoders_supported field is 3.
         0.000017222 "shairport.c:2125" use_apple_decoder is 1.
         0.000015685 "shairport.c:2126" alsa_use_hardware_mute is 0.
         0.000016037 "shairport.c:2130" no special mdns service interface was requested.
         0.000031130 "shairport.c:2133" configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf".
         0.000018907 "shairport.c:2163" loudness is 0.
         0.000015889 "shairport.c:2164" loudness reference level is -20.000000
         0.005518315 "shairport.c:2246" NQPTP is online.
         1.497104221 "shairport.c:221" "soxr" interpolation has been chosen.
         1.120707555 "rtsp.c:2652" Connection 1: AP2 PTP connection from 192.168.1.112:57582 to self at 192.168.1.223:7000.
         0.348565630 "rtsp.c:3040" Connection 1. AP2 Buffered Audio Stream.
         0.129066537 "rtsp.c:2674" Connection 2: Remote Control connection from 192.168.1.112:57584 to self at 192.168.1.223:7000.
         0.140300611 "rtp.c:1279" Connection 1: Set Anchor Clock: d81c79ee45af0008.
         1.137106629 "rtp.c:1385" Connection 1: Clock d81c79ee45af0008 is now the new anchor clock and master clock. History: 1500.834944 milliseconds.
         0.000152518 "rtp.c:1470" Connection 1: NQPTP new master clock d81c79ee45af0008.
         7.924027977 "player.c:2472" sync error ms net sync ppm all sync ppm     packets min DAC queue min buffer size output fps (r) output fps (c)
         0.000256037 "player.c:2472"          2.72       -120.2        120.2        1003          7502           1852k            N/A            N/A
         8.003186347 "player.c:2472"          1.62        -51.0         51.0        2006          8621           3873k       44097.27       44097.43
         8.007752699 "player.c:2472"          1.52         -8.5          8.5        3009          8623           3859k       44100.00       44100.16
         8.002397866 "player.c:2472"          1.42         -2.8          2.8        4012          8604           3859k       44098.56       44098.72
         8.008035624 "player.c:2472"          1.28          0.0          0.0        5015          8608           3881k       44099.03       44099.19
         8.007789477 "player.c:2472"          1.29          0.0          0.0        6018          8613           3859k       44098.71       44098.87
         8.003687310 "player.c:2472"          1.30          0.0          0.0        7021          8613           3859k       44099.12       44099.28
         8.848576217 "player.c:2472"          0.63          0.0          0.0        8024          8538               0            N/A            N/A
         8.005744421 "player.c:2472"         -0.34          0.0          0.0        9027          8526           3851k       44102.76       44102.91
         8.005532551 "player.c:2472"         -0.29          0.0          0.0       10030          8533           3750k       44097.82       44097.98
         5.295475497 "rtp.c:1946" buffered_read: waiting for 845 bytes.
         3.612455183 "player.c:2472"         -0.25          0.0          0.0       11033          8539               0            N/A            N/A
         8.005057588 "player.c:2472"         -0.39          0.0          0.0       12036          8527           3756k       44097.43       44097.59
         8.006482162 "player.c:2472"         -0.27          0.0          0.0       13039          8532           3662k       44099.25       44099.40
         8.004959087 "player.c:2472"         -0.31          0.0          0.0       14042          8537           3658k       44098.74       44098.90
         8.006421273 "player.c:2472"         -0.38          0.0          0.0       15045          8526           3655k       44098.46       44098.62
         0.753123352 "rtp.c:1946" buffered_read: waiting for 799 bytes.
         9.225898587 "player.c:2472"         -0.30          0.0          0.0       16048          8540               0            N/A            N/A
         8.009312329 "player.c:2472"         -0.15          0.0          0.0       17051          8549           3704k       44101.72       44101.88
         8.005503421 "player.c:2472"         -0.19          0.0          0.0       18054          8543           3685k       44102.50       44102.65
         8.006519699 "player.c:2472"         -0.21          0.0          0.0       19057          8546           3714k       44100.23       44100.38
         8.004158106 "player.c:2472"         -0.40          0.0          0.0       20060          8530           3733k       44099.75       44099.91
         9.028411087 "player.c:2472"          0.26          0.0          0.0       21063          8554               0            N/A            N/A
         8.005638569 "player.c:2472"          0.68          0.0          0.0       22066          8574           3756k       44103.33       44103.49
         8.010346848 "player.c:2472"          0.65          0.0          0.0       23069          8574           3810k       44098.77       44098.92
         8.003125810 "player.c:2472"          0.56          0.0          0.0       24072          8573           3751k       44099.28       44099.43
         8.008590069 "player.c:2472"          0.59          0.0          0.0       25075          8571           3747k       44098.65       44098.81
         8.949132569 "player.c:2472"         -0.42          0.0          0.0       26078          8518             59k            N/A            N/A
         8.008408865 "player.c:2472"         -0.48          0.0          0.0       27081          8526           3744k       44102.70       44102.86
         8.003253903 "player.c:2472"         -0.62          0.0          0.0       28084          8516           3762k       44100.88       44101.03
         8.009460569 "player.c:2472"         -0.56          0.0          0.0       29087          8523           3736k       44099.49       44099.64
         9.677425920 "player.c:2472"         -0.44          0.0          0.0       30090          8520             23k            N/A            N/A
         9.885945531 "player.c:2472"         -0.03          0.0          0.0       31093          8521               0            N/A            N/A
         7.132220496 "rtp.c:1946" buffered_read: waiting for 721 bytes.
         4.051728257 "player.c:2472"         -0.28          0.0          0.0       32096          8521               0            N/A            N/A
         8.006895773 "player.c:2472"         -0.53          0.0          0.0       33099          8522           3125k       44104.66       44104.82
         8.003937866 "player.c:2472"         -0.71          0.0          0.0       34102          8509           2876k       44101.85       44102.01
^C         8.767315717 "player.c:1636" Connection 1: Playback Stopped. Total playing time 00:04:54. Input: 7569913.70,  Output: 44101.85 (raw), 44102.01 (corrected) frames per second.
         0.010092111 "ptp-utilities.c:171" ptp_shm_interface_close
         0.000604833 "shairport.c:1594" exit_function exit

mikebrady commented 2 years ago

Thanks for your work -- I'll take a careful look at the logs.

mikebrady commented 2 years ago

It's good to hear that the problem seems to have gone away.

I've pushed an update which will log more information about those large positive sync errors -- it will now also give the total number of audio frames sent to the output device and also the current delay on the output device, i.e. the number of frames waiting to be output. Together, these should indicate if the output device had somehow stalled.

grappelli commented 2 years ago

Excuse me, I was away from home since creating this report but having be following this thread and so rebuilt both nqptp and shairport-sync respectively to:

Version: 1.1-dev-132-gc91a2bb. Shared Memory Interface Version: 7.

4.1-dev-241-gace5537a-AirPlay2-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc

Everything has been keeping in sync for the last few of hours since doing so and the change is night and day. I have been using apple music lossless in all ocasions. As far as I am concerned the issue is resolved.

thanks

github-actions[bot] commented 2 years ago

This issue has been inactive for 45 days so will be closed 7 days from now. To prevent this, please remove the "stale" label or post a comment.

mikebrady / shairport-sync

Airplay 2 consistently going out of sync #1447