mikebrady / shairport-sync

AirPlay and AirPlay 2 audio player
Other
7.29k stars 574 forks source link

Shairport works on first airplay but then doesn't work if you try to connect again #1203

Closed danyal closed 3 years ago

danyal commented 3 years ago

Hi, I'm running shareport on OSX (installed via brew). When I run it, I can connect from my phone no problem and stream music. If I disconnect airplay on my phone and then try connecting again, it show it as connected but I don't get any sound. If I do it a 3rd time it won't even connect. Any ideas? I've included verbose 3 logs below.

0.000267086 "shairport.c:461" looking for configuration file at full path "/Users/danyal/test.conf"
         0.000245024 "shairport.c:1729" Started!
         0.000032205 "shairport.c:1756" software version: "3.3.8-libdaemon-OpenSSL-dns_sd-ao-pa-stdout-pipe-soxr-metadata-sysconfdir:/usr/local/etc/shairport-sync"
         0.000004560 "shairport.c:1762" log verbosity is 3.
         0.041488435 "shairport.c:1777" The processor is running little-endian.
         0.000015438 "shairport.c:1810" disable resend requests is off.
         0.000003690 "shairport.c:1814" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
         0.000003788 "shairport.c:1815" statistics_requester status is 0.
         0.000002934 "shairport.c:1817" daemon status is 0.
         0.000003278 "shairport.c:1818" daemon pid file path is "/usr/local/var/run/shairport-sync.pid".
         0.000003147 "shairport.c:1820" rtsp listening port is 5000.
         0.000002660 "shairport.c:1821" udp base port is 6001.
         0.000002786 "shairport.c:1822" udp port range is 10.
         0.000002715 "shairport.c:1823" player name is "mac-mini".
         0.000002632 "shairport.c:1824" backend is "ao".
         0.000003077 "shairport.c:1825" run_this_before_play_begins action is "(null)".
         0.000002871 "shairport.c:1826" run_this_after_play_ends action is "(null)".
         0.000002673 "shairport.c:1827" wait-cmd status is 0.
         0.000002551 "shairport.c:1828" run_this_before_play_begins may return output is 0.
         0.000002682 "shairport.c:1829" run_this_if_an_unfixable_error_is_detected action is "(null)".
         0.000002874 "shairport.c:1830" run_this_before_entering_active_state action is  "(null)".
         0.000002676 "shairport.c:1831" run_this_after_exiting_active_state action is  "(null)".
         0.000002903 "shairport.c:1832" active_state_timeout is  10.000000 seconds.
         0.000002923 "shairport.c:1833" mdns backend "(null)".
         0.000002549 "shairport.c:1834" userSuppliedLatency is 0.
         0.000002531 "shairport.c:1837" interpolation setting is "auto".
         0.000003139 "shairport.c:1838" interpolation soxr_delay_threshold is 30.
         0.000006228 "shairport.c:1839" resync time is 0.050000 seconds.
         0.000002987 "shairport.c:1840" allow a session to be interrupted: 0.
         0.000002777 "shairport.c:1841" busy timeout time is 120.
         0.000002611 "shairport.c:1842" drift tolerance is 0.001995 seconds.
         0.000002737 "shairport.c:1843" password is "(null)".
         0.000002578 "shairport.c:1844" ignore_volume_control is 0.
         0.000002703 "shairport.c:1848" volume_max_db is not set
         0.000002471 "shairport.c:1850" volume range in dB (zero means use the range specified by the mixer): 0.
         0.000002957 "shairport.c:1854" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
         0.000003051 "shairport.c:1856" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
         0.000003099 "shairport.c:1857" disable_synchronization is 0.
         0.000002498 "shairport.c:1858" use_mmap_if_available is 1.
         0.000002464 "shairport.c:1860" output_format automatic selection is enabled.
         0.000002766 "shairport.c:1864" output_rate automatic selection is enabled.
         0.000002714 "shairport.c:1868" audio backend desired buffer length is 1.000000 seconds.
         0.000002853 "shairport.c:1870" audio_backend_buffer_interpolation_threshold_in_seconds is 0.000000 seconds.
         0.000002892 "shairport.c:1871" audio backend latency offset is 0.000000 seconds.
         0.000002714 "shairport.c:1873" audio backend silence lead-in time is "auto".
         0.000002721 "shairport.c:1877" zeroconf regtype is "_raop._tcp".
         0.000002623 "shairport.c:1878" decoders_supported field is 1.
         0.000002510 "shairport.c:1879" use_apple_decoder is 0.
         0.000002563 "shairport.c:1880" alsa_use_hardware_mute is 0.
         0.000003030 "shairport.c:1884" no special mdns service interface was requested.
         0.000051539 "shairport.c:1888" configuration file name "test.conf" resolves to "/Users/danyal/test.conf".
         0.000005701 "shairport.c:1894" metadata enabled is 1.
         0.000002727 "shairport.c:1895" metadata pipename is "/tmp/shairport-sync-metadata".
         0.000002737 "shairport.c:1897" metadata socket address is "(null)" port 0.
         0.000002774 "shairport.c:1898" metadata socket packet size is "500".
         0.000002729 "shairport.c:1899" get-coverart is 1.
         0.000002761 "shairport.c:1917" loudness is 0.
         0.000002600 "shairport.c:1918" loudness reference level is -20.000000
         0.000088146 "rtsp.c:1665" metadata pipe name is "/tmp/shairport-sync-metadata".
         0.000174609 "rtsp.c:158" Creating metadata queue "multicast".
         0.000004022 "rtsp.c:158" Creating metadata queue "pipe".
         0.000457638 "mdns.c:119" Can't start a DACP monitor -- no mdns_dacp_monitor start registered.
         1.499418404 "shairport.c:194" soxr_delay_index: 1.
         0.000022211 "shairport.c:201" "soxr" interpolation has been chosen.
        13.115963573 "rtsp.c:2999" Connection 1: new connection from [fe80::1486:9880:106:1503]:52848 to self at [fe80::1044:2655:a073:45f2]:5000.
         0.000078613 "rtsp.c:3021" Successfully created RTSP receiver thread 1.
         0.000093380 "rtsp.c:2982" Connection 2: new connection from 192.168.1.72:52849 to self at 192.168.1.25:5000.
         0.000030617 "rtsp.c:3021" Successfully created RTSP receiver thread 2.
         0.004088296 "rtsp.c:655" Connection 2: -- connection closed.
         0.000053001 "rtsp.c:2778" Connection 2: Terminate RTSP connection.
         0.000014117 "rtsp.c:475" msg_init message 1
         0.000025190 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000014586 "rtsp.c:2533" Connection 2: rtsp_conversation_thread_func_cleanup_function called.
         0.000022599 "rtsp.c:2537" Closing timing, control and audio sockets...
         0.000006520 "rtsp.c:2546" Connection 2: closing fd 8.
         0.000021932 "rtsp.c:610"     CSeq: 0.
         0.000008883 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006780 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000006753 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006756 "rtsp.c:475" msg_init message 2
         0.000005696 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005455 "rtsp.c:507"   Type: "CSeq", content: "0"
         0.000005245 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000010739 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005620 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000000308 "rtsp.c:2548" Connection 2: closed fd 8.
         0.000006783 "rtsp.c:901" Connection 1: OPTIONS
         0.000044142 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000006450 "rtsp.c:507"   Type: "CSeq", content: "0"
         0.000005089 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005021 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000005982 "rtsp.c:2582" Cancel watchdog thread.
         0.000032802 "rtsp.c:2584" Join watchdog thread.
         0.000030674 "rtsp.c:556" msg_free freed message 2
         0.000010944 "rtsp.c:556" msg_free freed message 1
         0.000001946 "rtsp.c:313" Connection 2: Watchdog Exit.
         0.000064945 "rtsp.c:2586" Delete watchdog mutex.
         0.000011400 "rtsp.c:2589" Connection 2: Checking play lock.
         0.000006967 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:2590".
         0.000030887 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:2595".
         0.000006362 "rtsp.c:2597" Connection 2: terminated.
         2.045259218 "rtsp.c:475" msg_init message 3
         0.000030136 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000027128 "rtsp.c:610"     CSeq: 1.
         0.000003566 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000003228 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000003117 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000003627 "rtsp.c:475" msg_init message 4
         0.000003071 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000002928 "rtsp.c:507"   Type: "CSeq", content: "1"
         0.000002996 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000002666 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000002577 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000003667 "rtsp.c:901" Connection 1: OPTIONS
         0.000003250 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000002876 "rtsp.c:507"   Type: "CSeq", content: "1"
         0.000002957 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000003155 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000026663 "rtsp.c:556" msg_free freed message 4
         0.000007824 "rtsp.c:556" msg_free freed message 3
         0.062581796 "rtsp.c:475" msg_init message 5
         0.000022236 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000005729 "rtsp.c:610"     CSeq: 2.
         0.000004017 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000003308 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000003580 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000003836 "rtsp.c:475" msg_init message 6
         0.000003304 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000003191 "rtsp.c:507"   Type: "CSeq", content: "2"
         0.000002990 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003056 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000003115 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000004007 "rtsp.c:901" Connection 1: OPTIONS
         0.000003367 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000002968 "rtsp.c:507"   Type: "CSeq", content: "2"
         0.000003183 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000002848 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000025626 "rtsp.c:556" msg_free freed message 6
         0.000007859 "rtsp.c:556" msg_free freed message 5
         0.004389572 "rtsp.c:475" msg_init message 7
         0.000024560 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000005630 "rtsp.c:610"     Apple-Challenge: n1kKgkGgoKJxr9ZDKGRVRg==.
         0.000003447 "rtsp.c:610"     CSeq: 3.
         0.000003293 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000003056 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000002883 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000003975 "rtsp.c:475" msg_init message 8
         0.000003064 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000003010 "rtsp.c:507"   Type: "Apple-Challenge", content: "n1kKgkGgoKJxr9ZDKGRVRg=="
         0.000003062 "rtsp.c:507"   Type: "CSeq", content: "3"
         0.000002641 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003118 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000002562 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.002715503 "rtsp.c:901" Connection 1: OPTIONS
         0.000012375 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000014138 "rtsp.c:507"   Type: "Apple-Response", content: "tOORciDicPfQZ01m/5jFSCzsPq+RpJT65cSeVdQyI2mkugU1v67Hh0tEKtkFmQj7tSC65IidILaEaxAmCDPcQuEECwMxwQzROECna/0rbI+uxlMDMm7I9vC+6bbaAi96WCBBId6v/arW9/5ydorEwACSUoVxlUJZ6Kwmc7hSPrdplku4BydaOO8aCZ3kR3Fp1R2p+FHfEzc5s+q67i5ZH9rnb9R7xeBKTwkUZUzGuZrYOWfX/TWHtd0kkwGH2UG8Wg4TbpWEJyzrF38jcG/PcqVeMVt88y3wRAhzO77/WigwTXGFM+tnEXy5cF2eAc7X+V3xD4gLTef+Tb4VZt0QXg"
         0.000004429 "rtsp.c:507"   Type: "CSeq", content: "3"
         0.000002758 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000002782 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000028889 "rtsp.c:556" msg_free freed message 8
         0.000005970 "rtsp.c:556" msg_free freed message 7
         0.007338089 "rtsp.c:475" msg_init message 9
         0.000012902 "rtsp.c:580" RTSP Message Received: "ANNOUNCE rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000005742 "rtsp.c:610"     Content-Length: 674.
         0.000003862 "rtsp.c:610"     Content-Type: application/sdp.
         0.000003275 "rtsp.c:610"     CSeq: 4.
         0.000003138 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000003102 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000002947 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000012239 "rtsp.c:475" msg_init message 10
         0.000003231 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "ANNOUNCE":
         0.000003048 "rtsp.c:507"   Type: "Content-Length", content: "674"
         0.000002938 "rtsp.c:507"   Type: "Content-Type", content: "application/sdp"
         0.000002675 "rtsp.c:507"   Type: "CSeq", content: "4"
         0.000002663 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000002986 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000002795 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000003672 "rtsp.c:1964" Connection 1: ANNOUNCE
         0.000003551 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:1972".
         0.000004749 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:1992".
         0.000003409 "rtsp.c:2019" Connection 1: ANNOUNCE has acquired play lock.
         0.000002764 "common.c:254" Resetting UDP Port Suggestion to 6001
         0.000010362 "rtsp.c:2121" Minimum latency 11025 specified
         0.000003851 "rtsp.c:2126" Maximum latency 88200 specified
         0.001342832 "rtsp.c:2162" An ALAC stream has been detected.
         0.000026026 "rtsp.c:2225" Play connection from user agent "AirPlay/545.22.21" on RTSP conversation thread 1.
         0.000004166 "rtsp.c:2234" AirPlay version 545 detected.
         0.000003383 "rtsp.c:459" msg_free increment reference counter message 9 to 2.
         0.000018444 "rtsp.c:459" msg_free increment reference counter message 9 to 3.
         0.000005510 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000003058 "rtsp.c:507"   Type: "CSeq", content: "4"
         0.000002679 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000003968 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000005717 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000014789 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 736e7561, length 17, message 9.
         0.000004856 "rtsp.c:556" msg_free freed message 10
         0.000002249 "rtsp.c:541" msg_free decrement reference counter message 9 to 2
         0.000008374 "rtsp.c:1529"      pipe: type 73736e63, code 736e7561, length 17, message 9.
         0.000023064 "rtsp.c:1572"                                                                     multicast: done.
         0.000030758 "rtsp.c:541" msg_free decrement reference counter message 9 to 1
         0.000241133 "rtsp.c:1534"      pipe: done.
         0.000009916 "rtsp.c:556" msg_free freed message 9
         0.004511373 "rtsp.c:475" msg_init message 11
         0.000010781 "rtsp.c:580" RTSP Message Received: "SETUP rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000005387 "rtsp.c:610"     Transport: RTP/AVP/UDP;unicast;mode=record;timing_port=53797;control_port=52265.
         0.000003847 "rtsp.c:610"     CSeq: 5.
         0.000003240 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000003291 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000003032 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000003879 "rtsp.c:475" msg_init message 12
         0.000002832 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SETUP":
         0.000002997 "rtsp.c:507"   Type: "Transport", content: "RTP/AVP/UDP;unicast;mode=record;timing_port=53797;control_port=52265"
         0.000003036 "rtsp.c:507"   Type: "CSeq", content: "5"
         0.000002730 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003047 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000002705 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000003606 "rtsp.c:969" Connection 1: SETUP
         0.000003444 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000004877 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000003179 "rtsp.c:976" Connection 1: SETUP -- Active-Remote string seen: "1013678422".
         0.000003130 "rtsp.c:459" msg_free increment reference counter message 11 to 2.
         0.000005478 "rtsp.c:459" msg_free increment reference counter message 11 to 3.
         0.000004452 "rtsp.c:995" Connection 1: SETUP -- DACP-ID string seen: "24D9CC9810411CDF".
         0.000003199 "rtsp.c:459" msg_free increment reference counter message 11 to 4.
         0.000005211 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000011747 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 61637265, length 10, message 11.
         0.000005712 "rtsp.c:1572"                                                                     multicast: done.
         0.000003489 "rtsp.c:541" msg_free decrement reference counter message 11 to 3
         0.000004541 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000010092 "rtsp.c:1529"      pipe: type 73736e63, code 61637265, length 10, message 11.
         0.000011234 "rtsp.c:459" msg_free increment reference counter message 11 to 4.
         0.000012150 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000001874 "rtp.c:931" rtp_setup: cport=52265 tport=53797.
         0.000022725 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 64616964, length 16, message 11.
         0.000025080 "rtp.c:968" Connection 1: SETUP -- Connection from fe80::1486:9880:106:1503 to self at fe80::1044:2655:a073:45f2.
         0.000019539 "rtsp.c:1572"                                                                     multicast: done.
         0.000008631 "rtsp.c:541" msg_free decrement reference counter message 11 to 3
         0.000007571 "rtsp.c:1534"      pipe: done.
         0.000005985 "rtsp.c:541" msg_free decrement reference counter message 11 to 2
         0.000003057 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000002814 "rtsp.c:1529"      pipe: type 73736e63, code 64616964, length 16, message 11.
         0.000091141 "rtp.c:1026" listening for audio, control and timing on ports 6003, 6001, 6002.
         0.000014625 "rtsp.c:1534"      pipe: done.
         0.000002075 "rtsp.c:1062" Connection 1: SETUP DACP-ID "24D9CC9810411CDF" from fe80::1486:9880:106:1503 to fe80::1044:2655:a073:45f2 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
         0.000003519 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000008413 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 636c6970, length 24.
         0.000002363 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000003230 "rtsp.c:1572"                                                                     multicast: done.
         0.000003442 "rtsp.c:541" msg_free decrement reference counter message 11 to 1
         0.000058172 "rtsp.c:507"   Type: "CSeq", content: "5"
         0.000016447 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000010037 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 73766970, length 25.
         0.000007679 "rtsp.c:1572"                                                                     multicast: done.
         0.000012132 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000017637 "rtsp.c:507"   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
         0.000005064 "rtsp.c:507"   Type: "Session", content: "1"
         0.000012023 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000010997 "rtsp.c:1531"      pipe: type 73736e63, code 636c6970, length 24.
         0.000018499 "rtsp.c:556" msg_free freed message 12
         0.000012562 "rtsp.c:556" msg_free freed message 11
         0.000081620 "rtsp.c:1534"      pipe: done.
         0.000009186 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000003207 "rtsp.c:1531"      pipe: type 73736e63, code 73766970, length 25.
         0.000090243 "rtsp.c:1534"      pipe: done.
         0.093349206 "rtsp.c:475" msg_init message 13
         0.000036370 "rtsp.c:580" RTSP Message Received: "RECORD rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000010705 "rtsp.c:610"     CSeq: 6.
         0.000007152 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006110 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005822 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006455 "rtsp.c:475" msg_init message 14
         0.000005473 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "RECORD":
         0.000005726 "rtsp.c:507"   Type: "CSeq", content: "6"
         0.000005632 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000004973 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004795 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007239 "rtsp.c:855" Connection 1: RECORD
         0.000006794 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000008669 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000020547 "common.c:1390" mutex_lock "&activity_monitor_mutex" at "activity_monitor.c:115".
         0.000008110 "activity_monitor.c:64" abeg
         0.000051273 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000020804 "player.c:3120" pbeg
         0.000015336 "player.c:1720" No latency has (yet) been specified. Setting 88,200 (2 seconds) frames as a default.
         0.000007466 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000011965 "rtsp.c:1531"      pipe: type 73736e63, code 61626567, length 0.
         0.000063240 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 61626567, length 0.
         0.000002618 "rtsp.c:1572"                                                                     multicast: done.
         0.000012630 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000031401 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000025192 "rtsp.c:507"   Type: "CSeq", content: "6"
         0.000026219 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000015097 "player.c:1781" Output frame bytes is 4.
         0.000012150 "player.c:1786" dac_buffer_queue_minimum_length is 0 frames.
         0.000021631 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70626567, length 0.
         0.000019641 "rtsp.c:1572"                                                                     multicast: done.
         0.000018939 "player.c:1881" Output bit depth is 16.
         0.000127465 "rtsp.c:1534"      pipe: done.
         0.000021824 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000007406 "player.c:1888" Dithering will be enabled because the output volume is being altered in software
         0.000001577 "rtsp.c:507"   Type: "Audio-Latency", content: "11025"
         0.000026522 "rtsp.c:1531"      pipe: type 73736e63, code 70626567, length 0.
         0.000124118 "rtsp.c:556" msg_free freed message 14
         0.000009145 "mdns.c:133" Can't set dacp_id -- no mdns_dacp_set_id registered.
         0.000014797 "rtsp.c:556" msg_free freed message 13
         0.000001779 "player.c:2004" Set initial volume to -18.000000.
         0.000018811 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000028033 "loudness.c:47" Volume: -37.6 dB - Loudness gain @10Hz: 8.8 dB
         0.000016211 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -18.000000, software_attenuation: -3755.700000, hardware_attenuation: 0.000000, muting is disabled.
         0.000009931 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000002358 "player.c:2007" Play begin
         0.000004331 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000015476 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000040690 "rtsp.c:1572"                                                                     multicast: done.
         0.000119967 "rtsp.c:1534"      pipe: done.
         0.000036394 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000010390 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000174965 "rtsp.c:1534"      pipe: done.
         0.005017840 "rtp.c:628" clock synchronisation request: return time is    5.427 milliseconds.
         0.000062745 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.000205386 "rtsp.c:475" msg_init message 15
         0.000019777 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000010441 "rtsp.c:610"     Content-Length: 20.
         0.000006671 "rtsp.c:610"     Content-Type: text/parameters.
         0.000006041 "rtsp.c:610"     CSeq: 7.
         0.000006178 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006052 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000007106 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006971 "rtsp.c:475" msg_init message 16
         0.000005509 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000005708 "rtsp.c:507"   Type: "Content-Length", content: "20"
         0.000005212 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000005074 "rtsp.c:507"   Type: "CSeq", content: "7"
         0.000004994 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005056 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004751 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007265 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000031874 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000009507 "loudness.c:47" Volume: -43.3 dB - Loudness gain @10Hz: 11.7 dB
         0.000024262 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -20.000000, software_attenuation: -4333.500000, hardware_attenuation: 0.000000, muting is disabled.
         0.000032167 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000018971 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000015968 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005314 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000013310 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000001999 "rtsp.c:507"   Type: "CSeq", content: "7"
         0.000012944 "rtsp.c:1572"                                                                     multicast: done.
         0.000010437 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000022165 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000104987 "rtsp.c:556" msg_free freed message 16
         0.000014939 "rtsp.c:556" msg_free freed message 15
         0.000157274 "rtsp.c:1534"      pipe: done.
         0.033226052 "player.c:466" syncing to seqno 59920.
         0.000054584 "player.c:247" Hammerton Decoder used on encrypted audio.
         0.002074853 "rtsp.c:475" msg_init message 17
         0.000021455 "rtsp.c:580" RTSP Message Received: "FLUSH rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000007314 "rtsp.c:610"     RTP-Info: seq=59919;rtptime=405966698.
         0.000004815 "rtsp.c:610"     CSeq: 8.
         0.000004463 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000004427 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000004156 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000004508 "rtsp.c:475" msg_init message 18
         0.000003906 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "FLUSH":
         0.000004018 "rtsp.c:507"   Type: "RTP-Info", content: "seq=59919;rtptime=405966698"
         0.000003769 "rtsp.c:507"   Type: "CSeq", content: "8"
         0.000003808 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003616 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000003438 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000005332 "rtsp.c:930" Connection 1: FLUSH
         0.000005172 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000006502 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000024243 "player.c:3087" player_flush
         0.000004046 "player.c:3078" do_flush: flush to 405966698.
         0.000004702 "common.c:1390" mutex_lock "&conn->flush_mutex" at "player.c:3079".
         0.000005849 "common.c:1413" mutex_unlock "&conn->flush_mutex" at "player.c:3083".
         0.000003889 "player.c:3090" pfls
         0.000013709 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000006423 "rtsp.c:507"   Type: "CSeq", content: "8"
         0.000005142 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000001416 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000001783 "rtsp.c:1531"      pipe: type 73736e63, code 70666c73, length 9.
         0.000010030 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000020026 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70666c73, length 9.
         0.000006260 "rtsp.c:1572"                                                                     multicast: done.
         0.000002485 "rtsp.c:556" msg_free freed message 18
         0.000012285 "rtsp.c:556" msg_free freed message 17
         0.000189134 "rtsp.c:1534"      pipe: done.
         0.003766176 "player.c:1005" flush request: flush frame 405966698 expired -- buffer contains 352 frames, from 405967050 to 405967401
         0.000026231 "player.c:1029" flush request: request dropped.
         0.262000615 "rtp.c:628" clock synchronisation request: return time is    5.035 milliseconds.
         0.000037070 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.299389650 "rtp.c:628" clock synchronisation request: return time is    4.297 milliseconds.
         0.000037579 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.310529892 "rtp.c:628" clock synchronisation request: return time is   14.049 milliseconds.
         0.000032228 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.299611026 "rtp.c:628" clock synchronisation request: return time is    9.001 milliseconds.
         0.000034339 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.356015466 "rtp.c:628" clock synchronisation request: return time is   60.823 milliseconds.
         0.000023679 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.043372591 "player.c:1068" pffr
         0.000027037 "common.c:1390" mutex_lock "&the_queue->pc_queue_lock" at "rtsp.c:212".
         0.000012451 "common.c:1390" mutex_lock "&the_queue->pc_queue_lock" at "rtsp.c:212".
         0.000008822 "player.c:1110" first_packet_time set for frame 405967050.
         0.000002643 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000018839 "rtsp.c:1531"      pipe: type 73736e63, code 70666672, length 0.
         0.000007255 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000037224 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70666672, length 0.
         0.000011124 "rtsp.c:1572"                                                                     multicast: done.
         0.000235672 "rtsp.c:1534"      pipe: done.
         0.023238332 "rtsp.c:475" msg_init message 19
         0.000035305 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000010935 "rtsp.c:610"     RTP-Info: rtptime=405947842.
         0.000007047 "rtsp.c:610"     Content-Length: 57277.
         0.000006473 "rtsp.c:610"     Content-Type: image/jpeg.
         0.000005784 "rtsp.c:610"     CSeq: 9.
         0.000005892 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000005978 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005651 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.081600637 "rtsp.c:475" msg_init message 20
         0.000029671 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000009926 "rtsp.c:507"   Type: "RTP-Info", content: "rtptime=405947842"
         0.000008412 "rtsp.c:507"   Type: "Content-Length", content: "57277"
         0.000008043 "rtsp.c:507"   Type: "Content-Type", content: "image/jpeg"
         0.000007032 "rtsp.c:507"   Type: "CSeq", content: "9"
         0.000005092 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005016 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004809 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000015743 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000006945 "rtsp.c:459" msg_free increment reference counter message 19 to 2.
         0.000012544 "rtsp.c:459" msg_free increment reference counter message 19 to 3.
         0.000002100 "rtsp.c:459" msg_free increment reference counter message 19 to 4.
         0.000010616 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000020527 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000008422 "rtsp.c:1529"      pipe: type 73736e63, code 70637374, length 9, message 19.
         0.000005241 "rtsp.c:459" msg_free increment reference counter message 19 to 5.
         0.000028169 "rtsp.c:459" msg_free increment reference counter message 19 to 6.
         0.000007221 "rtsp.c:459" msg_free increment reference counter message 19 to 7.
         0.000005963 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005569 "rtsp.c:507"   Type: "CSeq", content: "9"
         0.000016295 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000014583 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 70637374, length 9, message 19.
         0.000027677 "rtsp.c:1572"                                                                     multicast: done.
         0.000020699 "rtsp.c:541" msg_free decrement reference counter message 19 to 6
         0.000026410 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000009907 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 50494354, length 57277, message 19.
         0.000002686 "rtsp.c:556" msg_free freed message 20
         0.000019427 "rtsp.c:541" msg_free decrement reference counter message 19 to 5
         0.000029526 "rtsp.c:1572"                                                                     multicast: done.
         0.000049604 "rtsp.c:541" msg_free decrement reference counter message 19 to 4
         0.000013043 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000009759 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 7063656e, length 9, message 19.
         0.000011143 "rtsp.c:1572"                                                                     multicast: done.
         0.000008880 "rtsp.c:541" msg_free decrement reference counter message 19 to 3
         0.000024947 "rtsp.c:1534"      pipe: done.
         0.000012364 "rtsp.c:541" msg_free decrement reference counter message 19 to 2
         0.000005776 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000005742 "rtsp.c:1529"      pipe: type 73736e63, code 50494354, length 57277, message 19.
         0.000171636 "rtsp.c:1534"      pipe: done.
         0.000019309 "rtsp.c:541" msg_free decrement reference counter message 19 to 1
         0.000008941 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000013883 "rtsp.c:1529"      pipe: type 73736e63, code 7063656e, length 9, message 19.
         0.000281216 "rtsp.c:1534"      pipe: done.
         0.000028288 "rtsp.c:556" msg_free freed message 19
         0.003431021 "rtsp.c:475" msg_init message 21
         0.000018208 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000007914 "rtsp.c:610"     RTP-Info: rtptime=405953122.
         0.000005096 "rtsp.c:610"     Content-Length: 40.
         0.000004605 "rtsp.c:610"     Content-Type: text/parameters.
         0.000004682 "rtsp.c:610"     CSeq: 10.
         0.000004601 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000004372 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000004182 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000005748 "rtsp.c:475" msg_init message 22
         0.000004401 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000004246 "rtsp.c:507"   Type: "RTP-Info", content: "rtptime=405953122"
         0.000003953 "rtsp.c:507"   Type: "Content-Length", content: "40"
         0.000004008 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000003881 "rtsp.c:507"   Type: "CSeq", content: "10"
         0.000003775 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003728 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000003665 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006220 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000012913 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000004394 "rtsp.c:507"   Type: "CSeq", content: "10"
         0.000003648 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000016828 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000007918 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000014786 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70726772, length 29.
         0.000010059 "rtsp.c:1572"                                                                     multicast: done.
         0.000006385 "rtsp.c:1531"      pipe: type 73736e63, code 70726772, length 29.
         0.000000827 "rtsp.c:556" msg_free freed message 22
         0.000027891 "rtsp.c:556" msg_free freed message 21
         0.000126605 "rtsp.c:1534"      pipe: done.
         0.004164579 "rtsp.c:475" msg_init message 23
         0.000030132 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000008501 "rtsp.c:610"     RTP-Info: rtptime=405953122.
         0.000005230 "rtsp.c:610"     Content-Length: 182.
         0.000005181 "rtsp.c:610"     Content-Type: application/x-dmap-tagged.
         0.000004434 "rtsp.c:610"     CSeq: 11.
         0.000004817 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000004268 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000004443 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000005347 "rtsp.c:475" msg_init message 24
         0.000004333 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000004383 "rtsp.c:507"   Type: "RTP-Info", content: "rtptime=405953122"
         0.000004287 "rtsp.c:507"   Type: "Content-Length", content: "182"
         0.000004025 "rtsp.c:507"   Type: "Content-Type", content: "application/x-dmap-tagged"
         0.000003758 "rtsp.c:507"   Type: "CSeq", content: "11"
         0.000003898 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000004031 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000003944 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000005698 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000004717 "rtsp.c:1906" received metadata tags in SET_PARAMETER request.
         0.000004390 "rtsp.c:459" msg_free increment reference counter message 23 to 2.
         0.000011572 "rtsp.c:459" msg_free increment reference counter message 23 to 3.
         0.000007379 "rtsp.c:459" msg_free increment reference counter message 23 to 4.
         0.000004027 "rtsp.c:459" msg_free increment reference counter message 23 to 5.
         0.000004012 "rtsp.c:459" msg_free increment reference counter message 23 to 6.
         0.000004536 "rtsp.c:459" msg_free increment reference counter message 23 to 7.
         0.000003976 "rtsp.c:459" msg_free increment reference counter message 23 to 8.
         0.000005304 "rtsp.c:289" metadata queue- "pipe" 2/500.
         0.000007947 "rtsp.c:289" metadata queue- "multicast" 2/500.
         0.000017206 "rtsp.c:1529"      pipe: type 73736e63, code 6d647374, length 9, message 23.
         0.000003681 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 6d647374, length 9, message 23.
         0.000007767 "rtsp.c:1572"                                                                     multicast: done.
         0.000005480 "rtsp.c:541" msg_free decrement reference counter message 23 to 7
         0.000004836 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000004263 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6d706572, length 8, message 23.
         0.000001408 "rtsp.c:1572"                                                                     multicast: done.
         0.000003751 "rtsp.c:459" msg_free increment reference counter message 23 to 8.
         0.000018154 "rtsp.c:459" msg_free increment reference counter message 23 to 9.
         0.000005334 "rtsp.c:459" msg_free increment reference counter message 23 to 10.
         0.000004740 "rtsp.c:459" msg_free increment reference counter message 23 to 11.
         0.000007705 "rtsp.c:459" msg_free increment reference counter message 23 to 12.
         0.000004285 "rtsp.c:459" msg_free increment reference counter message 23 to 13.
         0.000003972 "rtsp.c:459" msg_free increment reference counter message 23 to 14.
         0.000005880 "rtsp.c:459" msg_free increment reference counter message 23 to 15.
         0.000007244 "rtsp.c:459" msg_free increment reference counter message 23 to 16.
         0.000004091 "rtsp.c:459" msg_free increment reference counter message 23 to 17.
         0.000007065 "rtsp.c:459" msg_free increment reference counter message 23 to 18.
         0.000007674 "rtsp.c:459" msg_free increment reference counter message 23 to 19.
         0.000007915 "rtsp.c:459" msg_free increment reference counter message 23 to 20.
         0.000004058 "rtsp.c:459" msg_free increment reference counter message 23 to 21.
         0.000007330 "rtsp.c:459" msg_free increment reference counter message 23 to 22.
         0.000007118 "rtsp.c:459" msg_free increment reference counter message 23 to 23.
         0.000007556 "rtsp.c:459" msg_free increment reference counter message 23 to 24.
         0.000007546 "rtsp.c:459" msg_free increment reference counter message 23 to 25.
         0.000007141 "rtsp.c:459" msg_free increment reference counter message 23 to 26.
         0.000007191 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000004541 "rtsp.c:507"   Type: "CSeq", content: "11"
         0.000004031 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000014088 "rtsp.c:541" msg_free decrement reference counter message 23 to 25
         0.000009178 "rtsp.c:289" metadata queue- "multicast" 12/500.
         0.000004339 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173616c, length 14, message 23.
         0.000004940 "rtsp.c:1572"                                                                     multicast: done.
         0.000006611 "rtsp.c:556" msg_free freed message 24
         0.000011424 "rtsp.c:1534"      pipe: done.
         0.000003425 "rtsp.c:541" msg_free decrement reference counter message 23 to 24
         0.000032985 "rtsp.c:541" msg_free decrement reference counter message 23 to 23
         0.000014286 "rtsp.c:289" metadata queue- "multicast" 11/500.
         0.000004862 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 61736172, length 5, message 23.
         0.000005476 "rtsp.c:1572"                                                                     multicast: done.
         0.000004327 "rtsp.c:541" msg_free decrement reference counter message 23 to 22
         0.000003953 "rtsp.c:289" metadata queue- "multicast" 10/500.
         0.000003910 "rtsp.c:1568"                                                                     multicast: type 636f7265, code 61736370, length 0.
         0.000004635 "rtsp.c:1572"                                                                     multicast: done.
         0.000003914 "rtsp.c:289" metadata queue- "multicast" 9/500.
         0.000000294 "rtsp.c:541" msg_free decrement reference counter message 23 to 21
         0.000071770 "rtsp.c:289" metadata queue- "pipe" 13/500.
         0.000011320 "rtsp.c:1529"      pipe: type 636f7265, code 6d706572, length 8, message 23.
         0.000005882 "rtsp.c:1568"                                                                     multicast: type 636f7265, code 6173676e, length 0.
         0.000020962 "rtsp.c:1572"                                                                     multicast: done.
         0.000007820 "rtsp.c:289" metadata queue- "multicast" 8/500.
         0.000005526 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6d696e6d, length 29, message 23.
         0.000005835 "rtsp.c:1572"                                                                     multicast: done.
         0.000004481 "rtsp.c:541" msg_free decrement reference counter message 23 to 20
         0.000004383 "rtsp.c:289" metadata queue- "multicast" 7/500.
         0.000004297 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173746e, length 2, message 23.
         0.000271570 "rtsp.c:1572"                                                                     multicast: done.
         0.000012358 "rtsp.c:541" msg_free decrement reference counter message 23 to 19
         0.000005325 "rtsp.c:289" metadata queue- "multicast" 6/500.
         0.000069815 "rtsp.c:1534"      pipe: done.
         0.000017791 "rtsp.c:541" msg_free decrement reference counter message 23 to 18
         0.000004907 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 61737463, length 2, message 23.
         0.000016360 "rtsp.c:1572"                                                                     multicast: done.
         0.000008185 "rtsp.c:541" msg_free decrement reference counter message 23 to 17
         0.000009890 "rtsp.c:289" metadata queue- "pipe" 12/500.
         0.000009068 "rtsp.c:289" metadata queue- "multicast" 5/500.
         0.000011023 "rtsp.c:1529"      pipe: type 636f7265, code 6173616c, length 14, message 23.
         0.000009544 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173646e, length 2, message 23.
         0.000014443 "rtsp.c:1572"                                                                     multicast: done.
         0.000004594 "rtsp.c:541" msg_free decrement reference counter message 23 to 16
         0.000018995 "rtsp.c:289" metadata queue- "multicast" 4/500.
         0.000105503 "rtsp.c:1534"      pipe: done.
         0.000010281 "rtsp.c:541" msg_free decrement reference counter message 23 to 15
         0.000005471 "rtsp.c:289" metadata queue- "pipe" 11/500.
         0.000004627 "rtsp.c:1529"      pipe: type 636f7265, code 61736172, length 5, message 23.
         0.000010971 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 61736463, length 2, message 23.
         0.000026945 "rtsp.c:1572"                                                                     multicast: done.
         0.000007778 "rtsp.c:541" msg_free decrement reference counter message 23 to 14
         0.000005301 "rtsp.c:289" metadata queue- "multicast" 3/500.
         0.000005107 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173646b, length 1, message 23.
         0.000005401 "rtsp.c:1572"                                                                     multicast: done.
         0.000004356 "rtsp.c:541" msg_free decrement reference counter message 23 to 13
         0.000004179 "rtsp.c:289" metadata queue- "multicast" 2/500.
         0.000003983 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 63617073, length 1, message 23.
         0.000095537 "rtsp.c:1572"                                                                     multicast: done.
         0.000012702 "rtsp.c:541" msg_free decrement reference counter message 23 to 12
         0.000005529 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000037364 "rtsp.c:1534"      pipe: done.
         0.000017220 "rtsp.c:541" msg_free decrement reference counter message 23 to 11
         0.000007076 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173746d, length 4, message 23.
         0.000012594 "rtsp.c:1572"                                                                     multicast: done.
         0.000008442 "rtsp.c:289" metadata queue- "pipe" 10/500.
         0.000009761 "rtsp.c:541" msg_free decrement reference counter message 23 to 10
         0.000010427 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000004848 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 6d64656e, length 9, message 23.
         0.000004848 "rtsp.c:1572"                                                                     multicast: done.
         0.000009943 "rtsp.c:1531"      pipe: type 636f7265, code 61736370, length 0.
         0.000004104 "rtsp.c:541" msg_free decrement reference counter message 23 to 9
         0.000120438 "rtsp.c:1534"      pipe: done.
         0.000012319 "rtsp.c:289" metadata queue- "pipe" 9/500.
         0.000004859 "rtsp.c:1531"      pipe: type 636f7265, code 6173676e, length 0.
         0.000094091 "rtsp.c:1534"      pipe: done.
         0.000008327 "rtsp.c:289" metadata queue- "pipe" 8/500.
         0.000004337 "rtsp.c:1529"      pipe: type 636f7265, code 6d696e6d, length 29, message 23.
         0.000092044 "rtsp.c:1534"      pipe: done.
         0.000008051 "rtsp.c:541" msg_free decrement reference counter message 23 to 8
         0.000004348 "rtsp.c:289" metadata queue- "pipe" 7/500.
         0.000004205 "rtsp.c:1529"      pipe: type 636f7265, code 6173746e, length 2, message 23.
         0.000087310 "rtsp.c:1534"      pipe: done.
         0.000007784 "rtsp.c:541" msg_free decrement reference counter message 23 to 7
         0.000004204 "rtsp.c:289" metadata queue- "pipe" 6/500.
         0.000003951 "rtsp.c:1529"      pipe: type 636f7265, code 61737463, length 2, message 23.
         0.000103575 "rtsp.c:1534"      pipe: done.
         0.000007718 "rtsp.c:541" msg_free decrement reference counter message 23 to 6
         0.000004208 "rtsp.c:289" metadata queue- "pipe" 5/500.
         0.000003964 "rtsp.c:1529"      pipe: type 636f7265, code 6173646e, length 2, message 23.
         0.000179281 "rtsp.c:1534"      pipe: done.
         0.000014783 "rtsp.c:541" msg_free decrement reference counter message 23 to 5
         0.000005517 "rtsp.c:289" metadata queue- "pipe" 4/500.
         0.000004935 "rtsp.c:1529"      pipe: type 636f7265, code 61736463, length 2, message 23.
         0.000122583 "rtsp.c:1534"      pipe: done.
         0.000010972 "rtsp.c:541" msg_free decrement reference counter message 23 to 4
         0.000004107 "rtsp.c:289" metadata queue- "pipe" 3/500.
         0.000003815 "rtsp.c:1529"      pipe: type 636f7265, code 6173646b, length 1, message 23.
         0.000092333 "rtsp.c:1534"      pipe: done.
         0.000007102 "rtsp.c:541" msg_free decrement reference counter message 23 to 3
         0.000003615 "rtsp.c:289" metadata queue- "pipe" 2/500.
         0.000003633 "rtsp.c:1529"      pipe: type 636f7265, code 63617073, length 1, message 23.
         0.000083010 "rtsp.c:1534"      pipe: done.
         0.000009119 "rtsp.c:541" msg_free decrement reference counter message 23 to 2
         0.000003694 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000003567 "rtsp.c:1529"      pipe: type 636f7265, code 6173746d, length 4, message 23.
         0.000080877 "rtsp.c:1534"      pipe: done.
         0.000006787 "rtsp.c:541" msg_free decrement reference counter message 23 to 1
         0.000003544 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000003586 "rtsp.c:1529"      pipe: type 73736e63, code 6d64656e, length 9, message 23.
         0.000080508 "rtsp.c:1534"      pipe: done.
         0.000012578 "rtsp.c:556" msg_free freed message 23
         0.087783876 "rtp.c:628" clock synchronisation request: return time is    4.458 milliseconds.
         0.000036852 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.110582793 "player.c:1287" prsm
         0.000050849 "common.c:1390" mutex_lock "&the_queue->pc_queue_lock" at "rtsp.c:212".
         0.000054975 "common.c:1390" mutex_lock "&the_queue->pc_queue_lock" at "rtsp.c:212".
         0.000004116 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000040687 "rtsp.c:1531"      pipe: type 73736e63, code 7072736d, length 0.
         0.000005239 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000017577 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 7072736d, length 0.
         0.000011061 "rtsp.c:1572"                                                                     multicast: done.
         0.000297973 "rtsp.c:1534"      pipe: done.
         0.163114220 "rtsp.c:475" msg_init message 25
         0.000031426 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010776 "rtsp.c:610"     CSeq: 12.
         0.000006642 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006463 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000006039 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006404 "rtsp.c:475" msg_init message 26
         0.000005332 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005671 "rtsp.c:507"   Type: "CSeq", content: "12"
         0.000005125 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005010 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005040 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006651 "rtsp.c:901" Connection 1: OPTIONS
         0.000006379 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000006914 "rtsp.c:507"   Type: "CSeq", content: "12"
         0.000005196 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004920 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000033883 "rtsp.c:556" msg_free freed message 26
         0.000011405 "rtsp.c:556" msg_free freed message 25
         2.050554236 "rtsp.c:475" msg_init message 27
         0.000027164 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000009964 "rtsp.c:610"     CSeq: 13.
         0.000007160 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006280 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005769 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006778 "rtsp.c:475" msg_init message 28
         0.000005438 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005710 "rtsp.c:507"   Type: "CSeq", content: "13"
         0.000005363 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005143 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005014 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006931 "rtsp.c:901" Connection 1: OPTIONS
         0.000006067 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005206 "rtsp.c:507"   Type: "CSeq", content: "13"
         0.000005130 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005274 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000050727 "rtsp.c:556" msg_free freed message 28
         0.000028562 "rtsp.c:556" msg_free freed message 27
         0.695349678 "rtp.c:628" clock synchronisation request: return time is   21.602 milliseconds.
         0.000027365 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         1.321512672 "rtsp.c:475" msg_init message 29
         0.000025249 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000007581 "rtsp.c:610"     CSeq: 14.
         0.000005454 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000004806 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000004285 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006309 "rtsp.c:475" msg_init message 30
         0.000004268 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000004266 "rtsp.c:507"   Type: "CSeq", content: "14"
         0.000004088 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003918 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000003874 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000005365 "rtsp.c:901" Connection 1: OPTIONS
         0.000004910 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000004189 "rtsp.c:507"   Type: "CSeq", content: "14"
         0.000004230 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004153 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000035187 "rtsp.c:556" msg_free freed message 30
         0.000009723 "rtsp.c:556" msg_free freed message 29
         1.701712158 "rtp.c:628" clock synchronisation request: return time is   39.822 milliseconds.
         0.000028431 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.122486624 "rtsp.c:475" msg_init message 31
         0.000051276 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000021024 "rtsp.c:610"     Content-Length: 20.
         0.000048339 "rtsp.c:610"     Content-Type: text/parameters.
         0.000009724 "rtsp.c:610"     CSeq: 15.
         0.000006872 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006156 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005555 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007553 "rtsp.c:475" msg_init message 32
         0.000005836 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000005986 "rtsp.c:507"   Type: "Content-Length", content: "20"
         0.000005240 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000005403 "rtsp.c:507"   Type: "CSeq", content: "15"
         0.000006286 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000004995 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004796 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007304 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000009911 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000009202 "loudness.c:47" Volume: -37.9 dB - Loudness gain @10Hz: 9.0 dB
         0.000021666 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -18.125000, software_attenuation: -3791.812500, hardware_attenuation: 0.000000, muting is disabled.
         0.000010611 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000006653 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005339 "rtsp.c:507"   Type: "CSeq", content: "15"
         0.000004900 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000002685 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000006169 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000015401 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000000477 "rtsp.c:556" msg_free freed message 32
         0.000018628 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000020621 "rtsp.c:1572"                                                                     multicast: done.
         0.000035883 "rtsp.c:556" msg_free freed message 31
         0.000213210 "rtsp.c:1534"      pipe: done.
         0.272377196 "rtsp.c:475" msg_init message 33
         0.000035475 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010186 "rtsp.c:610"     CSeq: 16.
         0.000006853 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006451 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005688 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007081 "rtsp.c:475" msg_init message 34
         0.000005560 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005905 "rtsp.c:507"   Type: "CSeq", content: "16"
         0.000005424 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005033 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004787 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006974 "rtsp.c:901" Connection 1: OPTIONS
         0.000006245 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005205 "rtsp.c:507"   Type: "CSeq", content: "16"
         0.000004883 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005100 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000051576 "rtsp.c:556" msg_free freed message 34
         0.000011440 "rtsp.c:556" msg_free freed message 33
         0.137945091 "rtsp.c:475" msg_init message 35
         0.000033366 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000010393 "rtsp.c:610"     Content-Length: 20.
         0.000006600 "rtsp.c:610"     Content-Type: text/parameters.
         0.000006158 "rtsp.c:610"     CSeq: 17.
         0.000006025 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000005903 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005559 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007727 "rtsp.c:475" msg_init message 36
         0.000005586 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000005682 "rtsp.c:507"   Type: "Content-Length", content: "20"
         0.000005375 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000005070 "rtsp.c:507"   Type: "CSeq", content: "17"
         0.000005210 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005231 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005172 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007876 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000009371 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000009386 "loudness.c:47" Volume: -32.5 dB - Loudness gain @10Hz: 6.3 dB
         0.000019801 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -16.250000, software_attenuation: -3250.125000, hardware_attenuation: 0.000000, muting is disabled.
         0.000010224 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000002440 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005676 "rtsp.c:507"   Type: "CSeq", content: "17"
         0.000002260 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000006587 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000004489 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000034664 "rtsp.c:556" msg_free freed message 36
         0.000012183 "rtsp.c:556" msg_free freed message 35
         0.000000829 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000017470 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000024911 "rtsp.c:1572"                                                                     multicast: done.
         0.000246160 "rtsp.c:1534"      pipe: done.
         0.517588346 "rtsp.c:475" msg_init message 37
         0.000032048 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000010983 "rtsp.c:610"     Content-Length: 20.
         0.000006724 "rtsp.c:610"     Content-Type: text/parameters.
         0.000006361 "rtsp.c:610"     CSeq: 18.
         0.000006052 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006174 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005493 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000009517 "rtsp.c:475" msg_init message 38
         0.000005538 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000005592 "rtsp.c:507"   Type: "Content-Length", content: "20"
         0.000005295 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000005157 "rtsp.c:507"   Type: "CSeq", content: "18"
         0.000005236 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005361 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005043 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007458 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000009677 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000009469 "loudness.c:47" Volume: -27.1 dB - Loudness gain @10Hz: 3.5 dB
         0.000022416 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -14.374999, software_attenuation: -2708.437224, hardware_attenuation: 0.000000, muting is disabled.
         0.000012137 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000001928 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005261 "rtsp.c:507"   Type: "CSeq", content: "18"
         0.000004783 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000000644 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004446 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000023378 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000019150 "rtsp.c:1572"                                                                     multicast: done.
         0.000057524 "rtsp.c:556" msg_free freed message 38
         0.000041798 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000038356 "rtsp.c:556" msg_free freed message 37
         0.000239124 "rtsp.c:1534"      pipe: done.
         0.768909850 "rtsp.c:475" msg_init message 39
         0.000045924 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000010657 "rtsp.c:610"     Content-Length: 20.
         0.000006918 "rtsp.c:610"     Content-Type: text/parameters.
         0.000006132 "rtsp.c:610"     CSeq: 19.
         0.000054706 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000008440 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005934 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007644 "rtsp.c:475" msg_init message 40
         0.000007636 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
         0.000005642 "rtsp.c:507"   Type: "Content-Length", content: "20"
         0.000005143 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000005011 "rtsp.c:507"   Type: "CSeq", content: "19"
         0.000004941 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005087 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004927 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007290 "rtsp.c:1873" Connection 1: SET_PARAMETER
         0.000010212 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000019946 "loudness.c:47" Volume: -32.5 dB - Loudness gain @10Hz: 6.3 dB
         0.000021390 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -16.250000, software_attenuation: -3250.125000, hardware_attenuation: 0.000000, muting is disabled.
         0.000010760 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000006763 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005073 "rtsp.c:507"   Type: "CSeq", content: "19"
         0.000004908 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000007613 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000032670 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000004076 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000001997 "rtsp.c:556" msg_free freed message 40
         0.000028193 "rtsp.c:556" msg_free freed message 39
         0.000022888 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000020648 "rtsp.c:1572"                                                                     multicast: done.
         0.000188876 "rtsp.c:1534"      pipe: done.
         0.416696575 "rtsp.c:475" msg_init message 41
         0.000035212 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010411 "rtsp.c:610"     CSeq: 20.
         0.000007089 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006083 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000006025 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006700 "rtsp.c:475" msg_init message 42
         0.000005778 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005664 "rtsp.c:507"   Type: "CSeq", content: "20"
         0.000005292 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005059 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005058 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007186 "rtsp.c:901" Connection 1: OPTIONS
         0.000006210 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005383 "rtsp.c:507"   Type: "CSeq", content: "20"
         0.000005223 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005195 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000048318 "rtsp.c:556" msg_free freed message 42
         0.000012330 "rtsp.c:556" msg_free freed message 41
         0.733248842 "rtp.c:628" clock synchronisation request: return time is    6.550 milliseconds.
         0.000031114 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         1.579866834 "rtsp.c:475" msg_init message 43
         0.000033137 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010241 "rtsp.c:610"     CSeq: 21.
         0.000006927 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006037 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005651 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007361 "rtsp.c:475" msg_init message 44
         0.000005375 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005891 "rtsp.c:507"   Type: "CSeq", content: "21"
         0.000005325 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005035 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004882 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006796 "rtsp.c:901" Connection 1: OPTIONS
         0.000006481 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005644 "rtsp.c:507"   Type: "CSeq", content: "21"
         0.000004929 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000015481 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000041642 "rtsp.c:556" msg_free freed message 44
         0.000011841 "rtsp.c:556" msg_free freed message 43
         1.419171392 "rtp.c:628" clock synchronisation request: return time is    4.336 milliseconds.
         0.000036579 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.385006416 "rtsp.c:475" msg_init message 45
         0.000031492 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000009957 "rtsp.c:610"     CSeq: 22.
         0.000006969 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006357 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000006172 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006371 "rtsp.c:475" msg_init message 46
         0.000005528 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005599 "rtsp.c:507"   Type: "CSeq", content: "22"
         0.000005245 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005101 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005194 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007030 "rtsp.c:901" Connection 1: OPTIONS
         0.000006379 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005319 "rtsp.c:507"   Type: "CSeq", content: "22"
         0.000005245 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004999 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000055426 "rtsp.c:556" msg_free freed message 46
         0.000011481 "rtsp.c:556" msg_free freed message 45
         2.031111428 "rtsp.c:475" msg_init message 47
         0.000032099 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000033654 "rtsp.c:610"     CSeq: 23.
         0.000017711 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000005652 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000004915 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000005873 "rtsp.c:475" msg_init message 48
         0.000004440 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000004791 "rtsp.c:507"   Type: "CSeq", content: "23"
         0.000004096 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000003882 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000003805 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000005429 "rtsp.c:901" Connection 1: OPTIONS
         0.000004653 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000003898 "rtsp.c:507"   Type: "CSeq", content: "23"
         0.000003809 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000003734 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000045453 "rtsp.c:556" msg_free freed message 48
         0.000036130 "rtsp.c:556" msg_free freed message 47
         0.586445704 "rtp.c:628" clock synchronisation request: return time is    3.833 milliseconds.
         0.000034816 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         1.510567445 "rtsp.c:475" msg_init message 49
         0.000045553 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010039 "rtsp.c:610"     CSeq: 24.
         0.000006602 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006250 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000005967 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006735 "rtsp.c:475" msg_init message 50
         0.000005647 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005798 "rtsp.c:507"   Type: "CSeq", content: "24"
         0.000005160 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005026 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004842 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006831 "rtsp.c:901" Connection 1: OPTIONS
         0.000006119 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005684 "rtsp.c:507"   Type: "CSeq", content: "24"
         0.000004831 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004755 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000044479 "rtsp.c:556" msg_free freed message 50
         0.000011551 "rtsp.c:556" msg_free freed message 49
         1.553663773 "rtp.c:628" clock synchronisation request: return time is   66.043 milliseconds.
         0.000019953 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.082049045 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7978.8,    26748.5,   535379.8.
         0.203509932 "rtsp.c:475" msg_init message 51
         0.000035834 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010257 "rtsp.c:610"     CSeq: 25.
         0.000006900 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006326 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000006934 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006820 "rtsp.c:475" msg_init message 52
         0.000005714 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "OPTIONS":
         0.000005759 "rtsp.c:507"   Type: "CSeq", content: "25"
         0.000005323 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005099 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000005669 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007020 "rtsp.c:901" Connection 1: OPTIONS
         0.000006103 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005292 "rtsp.c:507"   Type: "CSeq", content: "25"
         0.000005787 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004936 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000045850 "rtsp.c:556" msg_free freed message 52
         0.000011504 "rtsp.c:556" msg_free freed message 51
         0.947784936 "rtsp.c:475" msg_init message 53
         0.000036506 "rtsp.c:580" RTSP Message Received: "TEARDOWN rtsp://fe80::1044:2655:a073:45f2/8687071347903318423 RTSP/1.0".
         0.000011217 "rtsp.c:610"     CSeq: 26.
         0.000006801 "rtsp.c:610"     DACP-ID: 24D9CC9810411CDF.
         0.000006415 "rtsp.c:610"     Active-Remote: 1013678422.
         0.000006377 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006581 "rtsp.c:475" msg_init message 54
         0.000005464 "rtsp.c:2663" Connection 1: Received an RTSP Packet of type "TEARDOWN":
         0.000005557 "rtsp.c:507"   Type: "CSeq", content: "26"
         0.000005348 "rtsp.c:507"   Type: "DACP-ID", content: "24D9CC9810411CDF"
         0.000005125 "rtsp.c:507"   Type: "Active-Remote", content: "1013678422"
         0.000004893 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007259 "rtsp.c:911" Connection 1: TEARDOWN
         0.000007048 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000008905 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000007003 "rtsp.c:918" TEARDOWN: synchronously terminating the player thread of RTSP conversation thread 1 (2).
         0.000005960 "player.c:3130" player_stop
         0.000005420 "player.c:3132" player_thread cancel...
         0.000012778 "player.c:3134" player_thread join...
         0.000018220 "player.c:1632" Connection 1: player thread main loop exit via player_thread_cleanup_handler.
         0.000023220 "mdns.c:133" Can't set dacp_id -- no mdns_dacp_set_id registered.
         0.000006680 "player.c:1658" Cancelling timing, control and audio threads...
         0.000005617 "player.c:1659" Cancel timing thread.
         0.000011905 "player.c:1661" Join timing thread.
         0.000020987 "rtp.c:526" Timing Receiver Cleanup.
         0.000011313 "rtp.c:551" Cancel Timing Requester.
         0.000009731 "rtp.c:555" Join Timing Requester.
         0.000012184 "rtp.c:457" Connection 1: Timing Sender Cleanup.
         0.000081205 "rtp.c:557" Timing Receiver Cleanup Successful.
         0.000058899 "player.c:1663" Timing thread terminated.
         0.000012698 "player.c:1664" Cancel control thread.
         0.000008806 "player.c:1666" Join control thread.
         0.000016699 "rtp.c:232" Control Receiver Cleanup Done.
         0.000039513 "player.c:1668" Control thread terminated.
         0.000008618 "player.c:1669" Cancel audio thread.
         0.000007932 "player.c:1671" Join audio thread.
         0.000020896 "rtp.c:97" Audio Receiver Cleanup Done.
         0.000079089 "player.c:1673" Audio thread terminated.
         0.000158278 "common.c:1390" mutex_lock "&conn->reference_time_mutex" at "rtp.c:1052".
         0.000011290 "common.c:1413" mutex_unlock "&conn->reference_time_mutex" at "rtp.c:1055".
         0.000063704 "player.c:3141" player_thread joined.
         0.000020008 "player.c:3146" pend
         0.000020032 "common.c:1390" mutex_lock "&activity_monitor_mutex" at "activity_monitor.c:115".
         0.000013257 "rtsp.c:921" TEARDOWN: successful termination of playing thread of RTSP conversation thread 1.
         0.000006388 "rtsp.c:2706" Connection 1: RTSP Response:
         0.000005666 "rtsp.c:507"   Type: "CSeq", content: "26"
         0.000001513 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000000583 "rtsp.c:507"   Type: "Connection", content: "close"
         0.000004918 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000020860 "rtsp.c:1531"      pipe: type 73736e63, code 70656e64, length 0.
         0.000003958 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000025893 "rtsp.c:556" msg_free freed message 54
         0.000023902 "rtsp.c:556" msg_free freed message 53
         0.000000369 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70656e64, length 0.
         0.000025116 "rtsp.c:1572"                                                                     multicast: done.
         0.000203107 "rtsp.c:1534"      pipe: done.
         0.006016341 "rtsp.c:655" Connection 1: -- connection closed.
         0.000039019 "rtsp.c:2778" Connection 1: Terminate RTSP connection.
         0.000008016 "rtsp.c:2533" Connection 1: rtsp_conversation_thread_func_cleanup_function called.
         0.000006458 "rtsp.c:2537" Closing timing, control and audio sockets...
         0.000053084 "rtsp.c:2546" Connection 1: closing fd 7.
         0.000037327 "rtsp.c:2548" Connection 1: closed fd 7.
         0.000010047 "rtsp.c:2582" Cancel watchdog thread.
         0.000012899 "rtsp.c:2584" Join watchdog thread.
         0.000016045 "rtsp.c:313" Connection 1: Watchdog Exit.
         0.000081142 "rtsp.c:2586" Delete watchdog mutex.
         0.000012112 "rtsp.c:2589" Connection 1: Checking play lock.
         0.000006607 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:2590".
         0.000008354 "rtsp.c:2592" Connection 1: Unlocking play lock.
         0.000006117 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:2595".
         0.000010922 "rtsp.c:2597" Connection 1: terminated.
         6.841162261 "rtsp.c:397" found RTSP connection thread 1 in a non-running state.
         0.000053415 "rtsp.c:399" RTSP connection thread 1 deleted...
         0.000012935 "rtsp.c:397" found RTSP connection thread 2 in a non-running state.
         0.000013169 "rtsp.c:399" RTSP connection thread 2 deleted...
         0.000029967 "rtsp.c:2999" Connection 3: new connection from [fe80::1486:9880:106:1503]:52852 to self at [fe80::1044:2655:a073:45f2]:5000.
         0.000043778 "rtsp.c:3021" Successfully created RTSP receiver thread 3.
         0.000027179 "rtsp.c:2982" Connection 4: new connection from 192.168.1.72:52853 to self at 192.168.1.25:5000.
         0.000023798 "rtsp.c:3021" Successfully created RTSP receiver thread 4.
         0.000009392 "rtsp.c:475" msg_init message 55
         0.000042859 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.002039930 "rtsp.c:655" Connection 4: -- connection closed.
         0.000019265 "rtsp.c:2778" Connection 4: Terminate RTSP connection.
         0.000007431 "rtsp.c:2533" Connection 4: rtsp_conversation_thread_func_cleanup_function called.
         0.000007718 "rtsp.c:610"     CSeq: 0.
         0.000011631 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006006 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000004440 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006229 "rtsp.c:2537" Closing timing, control and audio sockets...
         0.000009571 "rtsp.c:2546" Connection 4: closing fd 8.
         0.000009033 "rtsp.c:475" msg_init message 56
         0.000016221 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000004886 "rtsp.c:507"   Type: "CSeq", content: "0"
         0.000004179 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000024928 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000009876 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007913 "rtsp.c:2548" Connection 4: closed fd 8.
         0.000009615 "rtsp.c:2582" Cancel watchdog thread.
         0.000006065 "rtsp.c:901" Connection 3: OPTIONS
         0.000015754 "rtsp.c:2584" Join watchdog thread.
         0.000000948 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000006967 "rtsp.c:507"   Type: "CSeq", content: "0"
         0.000005751 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000001622 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000018782 "rtsp.c:313" Connection 4: Watchdog Exit.
         0.000074231 "rtsp.c:556" msg_free freed message 56
         0.000017466 "rtsp.c:556" msg_free freed message 55
         0.000016064 "rtsp.c:2586" Delete watchdog mutex.
         0.000014055 "rtsp.c:2589" Connection 4: Checking play lock.
         0.000008776 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:2590".
         0.000009885 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:2595".
         0.000028929 "rtsp.c:2597" Connection 4: terminated.
         0.188851962 "rtsp.c:475" msg_init message 57
         0.000034767 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000009996 "rtsp.c:610"     CSeq: 1.
         0.000006803 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006170 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005750 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006863 "rtsp.c:475" msg_init message 58
         0.000005560 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005517 "rtsp.c:507"   Type: "CSeq", content: "1"
         0.000006829 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005045 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004784 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006683 "rtsp.c:901" Connection 3: OPTIONS
         0.000005875 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005119 "rtsp.c:507"   Type: "CSeq", content: "1"
         0.000004949 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005042 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000041452 "rtsp.c:556" msg_free freed message 58
         0.000011707 "rtsp.c:556" msg_free freed message 57
         0.004086088 "rtsp.c:475" msg_init message 59
         0.000035212 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000009740 "rtsp.c:610"     CSeq: 2.
         0.000006852 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006218 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005563 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006554 "rtsp.c:475" msg_init message 60
         0.000005618 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005504 "rtsp.c:507"   Type: "CSeq", content: "2"
         0.000007898 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005047 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004729 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006797 "rtsp.c:901" Connection 3: OPTIONS
         0.000006365 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005182 "rtsp.c:507"   Type: "CSeq", content: "2"
         0.000005077 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005007 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000046229 "rtsp.c:556" msg_free freed message 60
         0.000011050 "rtsp.c:556" msg_free freed message 59
         0.005144745 "rtsp.c:475" msg_init message 61
         0.000033350 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010001 "rtsp.c:610"     Apple-Challenge: jS7qcbDoncnxVFLK7sfGQw==.
         0.000006836 "rtsp.c:610"     CSeq: 3.
         0.000006414 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000005783 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005526 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006671 "rtsp.c:475" msg_init message 62
         0.000005611 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005682 "rtsp.c:507"   Type: "Apple-Challenge", content: "jS7qcbDoncnxVFLK7sfGQw=="
         0.000005626 "rtsp.c:507"   Type: "CSeq", content: "3"
         0.000005094 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000004951 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004667 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.002562124 "rtsp.c:901" Connection 3: OPTIONS
         0.000022361 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000006725 "rtsp.c:507"   Type: "Apple-Response", content: "piYZH53J9OtlRbAC93JFFUYUz8+mmJMS0EFPzn/l3Xz6rF9U9dQ/W5TwQcd1nsvI9hs3AWztS5cyiFuFM7kjWgJXCZHH4N0nm4zuZ4fbxMZBA9By1x88uDu2/rn16bRtF+r/rRQ7FJEPfAiryUKiwhf89ZgA1SIzqLeg2ZazVA87H8D3Ni0bR1RFTtGEAHv1jAg9Cne9EcWKDI+3e6OUCxyajCkio9YbE/K+BpOVB+bk6htCXi+SxsAwuQyao1ux7mkVmq9Nxo4pL9KzqPYp1Ta0ubObvfs/CDL4TkgxV4aoA5bO726IOvZaA6jub5pKSA77Ou4YKIjK36FZR64WSw"
         0.000008148 "rtsp.c:507"   Type: "CSeq", content: "3"
         0.000005296 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005121 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000048719 "rtsp.c:556" msg_free freed message 62
         0.000012070 "rtsp.c:556" msg_free freed message 61
         0.007692331 "rtsp.c:475" msg_init message 63
         0.000035153 "rtsp.c:580" RTSP Message Received: "ANNOUNCE rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000010908 "rtsp.c:610"     Content-Length: 674.
         0.000006880 "rtsp.c:610"     Content-Type: application/sdp.
         0.000006695 "rtsp.c:610"     CSeq: 4.
         0.000005956 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000005751 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005672 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007033 "rtsp.c:475" msg_init message 64
         0.000005651 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "ANNOUNCE":
         0.000005566 "rtsp.c:507"   Type: "Content-Length", content: "674"
         0.000005127 "rtsp.c:507"   Type: "Content-Type", content: "application/sdp"
         0.000004919 "rtsp.c:507"   Type: "CSeq", content: "4"
         0.000005007 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000004965 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004962 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007450 "rtsp.c:1964" Connection 3: ANNOUNCE
         0.000006636 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:1972".
         0.000008920 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:1992".
         0.000006662 "rtsp.c:2019" Connection 3: ANNOUNCE has acquired play lock.
         0.000005172 "common.c:254" Resetting UDP Port Suggestion to 6001
         0.000008903 "rtsp.c:2121" Minimum latency 11025 specified
         0.000005497 "rtsp.c:2126" Maximum latency 88200 specified
         0.002408207 "rtsp.c:2162" An ALAC stream has been detected.
         0.000015798 "rtsp.c:2225" Play connection from user agent "AirPlay/545.22.21" on RTSP conversation thread 3.
         0.000007524 "rtsp.c:2234" AirPlay version 545 detected.
         0.000006032 "rtsp.c:459" msg_free increment reference counter message 63 to 2.
         0.000014806 "rtsp.c:459" msg_free increment reference counter message 63 to 3.
         0.000009109 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005773 "rtsp.c:507"   Type: "CSeq", content: "4"
         0.000005177 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000014036 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000009288 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000005521 "rtsp.c:556" msg_free freed message 64
         0.000008204 "rtsp.c:541" msg_free decrement reference counter message 63 to 2
         0.000004671 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 736e7561, length 17, message 63.
         0.000016295 "rtsp.c:1529"      pipe: type 73736e63, code 736e7561, length 17, message 63.
         0.000009329 "rtsp.c:1572"                                                                     multicast: done.
         0.000043720 "rtsp.c:541" msg_free decrement reference counter message 63 to 1
         0.000269820 "rtsp.c:1534"      pipe: done.
         0.000020829 "rtsp.c:556" msg_free freed message 63
         0.006120636 "rtsp.c:475" msg_init message 65
         0.000035435 "rtsp.c:580" RTSP Message Received: "SETUP rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000011063 "rtsp.c:610"     Transport: RTP/AVP/UDP;unicast;mode=record;timing_port=57736;control_port=54308.
         0.000007266 "rtsp.c:610"     CSeq: 5.
         0.000006342 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006394 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005478 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006495 "rtsp.c:475" msg_init message 66
         0.000005570 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "SETUP":
         0.000005786 "rtsp.c:507"   Type: "Transport", content: "RTP/AVP/UDP;unicast;mode=record;timing_port=57736;control_port=54308"
         0.000006411 "rtsp.c:507"   Type: "CSeq", content: "5"
         0.000005442 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005096 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004822 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007319 "rtsp.c:969" Connection 3: SETUP
         0.000006991 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000009153 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000006384 "rtsp.c:976" Connection 3: SETUP -- Active-Remote string seen: "2287535949".
         0.000006747 "rtsp.c:459" msg_free increment reference counter message 65 to 2.
         0.000014230 "rtsp.c:459" msg_free increment reference counter message 65 to 3.
         0.000009457 "rtsp.c:995" Connection 3: SETUP -- DACP-ID string seen: "2356F4FA343F52FF".
         0.000005680 "rtsp.c:459" msg_free increment reference counter message 65 to 4.
         0.000005568 "rtsp.c:459" msg_free increment reference counter message 65 to 5.
         0.000007085 "rtp.c:931" rtp_setup: cport=54308 tport=57736.
         0.000002850 "rtp.c:968" Connection 3: SETUP -- Connection from fe80::1486:9880:106:1503 to self at fe80::1044:2655:a073:45f2.
         0.000006074 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000007028 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000019268 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 61637265, length 10, message 65.
         0.000016127 "rtsp.c:1529"      pipe: type 73736e63, code 61637265, length 10, message 65.
         0.000014398 "rtsp.c:1572"                                                                     multicast: done.
         0.000042903 "rtsp.c:541" msg_free decrement reference counter message 65 to 4
         0.000014563 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000010883 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 64616964, length 16, message 65.
         0.000011219 "rtsp.c:1572"                                                                     multicast: done.
         0.000017528 "rtsp.c:541" msg_free decrement reference counter message 65 to 3
         0.000001961 "rtp.c:1026" listening for audio, control and timing on ports 6003, 6001, 6002.
         0.000033521 "rtsp.c:1062" Connection 3: SETUP DACP-ID "2356F4FA343F52FF" from fe80::1486:9880:106:1503 to fe80::1044:2655:a073:45f2 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
         0.000001692 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000010799 "rtsp.c:507"   Type: "CSeq", content: "5"
         0.000005278 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004956 "rtsp.c:507"   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
         0.000005758 "rtsp.c:507"   Type: "Session", content: "1"
         0.000007044 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000017421 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 636c6970, length 24.
         0.000007319 "rtsp.c:1572"                                                                     multicast: done.
         0.000007625 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000005474 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 73766970, length 25.
         0.000000817 "rtsp.c:1572"                                                                     multicast: done.
         0.000005282 "rtsp.c:556" msg_free freed message 66
         0.000027399 "rtsp.c:541" msg_free decrement reference counter message 65 to 2
         0.000036968 "rtsp.c:1534"      pipe: done.
         0.000011946 "rtsp.c:541" msg_free decrement reference counter message 65 to 1
         0.000006334 "rtsp.c:289" metadata queue- "pipe" 2/500.
         0.000006284 "rtsp.c:1529"      pipe: type 73736e63, code 64616964, length 16, message 65.
         0.000128730 "rtsp.c:1534"      pipe: done.
         0.000019173 "rtsp.c:556" msg_free freed message 65
         0.000006070 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000005698 "rtsp.c:1531"      pipe: type 73736e63, code 636c6970, length 24.
         0.000122547 "rtsp.c:1534"      pipe: done.
         0.000010259 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000005408 "rtsp.c:1531"      pipe: type 73736e63, code 73766970, length 25.
         0.000113527 "rtsp.c:1534"      pipe: done.
         0.005704487 "rtsp.c:475" msg_init message 67
         0.000029526 "rtsp.c:580" RTSP Message Received: "RECORD rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000010132 "rtsp.c:610"     CSeq: 6.
         0.000006880 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006540 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005846 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007012 "rtsp.c:475" msg_init message 68
         0.000005442 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "RECORD":
         0.000005537 "rtsp.c:507"   Type: "CSeq", content: "6"
         0.000005350 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005295 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000005187 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007168 "rtsp.c:855" Connection 3: RECORD
         0.000006655 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000008887 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000008106 "common.c:1390" mutex_lock "&activity_monitor_mutex" at "activity_monitor.c:115".
         0.000070202 "player.c:3120" pbeg
         0.000021367 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000001059 "rtsp.c:507"   Type: "CSeq", content: "6"
         0.000001080 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000006795 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000000678 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000002962 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70626567, length 0.
         0.000007893 "player.c:1720" No latency has (yet) been specified. Setting 88,200 (2 seconds) frames as a default.
         0.000019128 "rtsp.c:1531"      pipe: type 73736e63, code 70626567, length 0.
         0.000020204 "rtsp.c:1572"                                                                     multicast: done.
         0.000011247 "rtsp.c:507"   Type: "Audio-Latency", content: "11025"
         0.000146868 "rtsp.c:556" msg_free freed message 68
         0.000019983 "rtsp.c:556" msg_free freed message 67
         0.000009111 "player.c:1781" Output frame bytes is 4.
         0.000015223 "player.c:1786" dac_buffer_queue_minimum_length is 0 frames.
         0.000019638 "player.c:1881" Output bit depth is 16.
         0.000008390 "player.c:1888" Dithering will be enabled because the output volume is being altered in software
         0.000114612 "mdns.c:133" Can't set dacp_id -- no mdns_dacp_set_id registered.
         0.000020580 "player.c:2004" Set initial volume to -16.250000.
         0.000005992 "rtsp.c:1534"      pipe: done.
         0.000005669 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000022031 "loudness.c:47" Volume: -32.5 dB - Loudness gain @10Hz: 6.3 dB
         0.000024913 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -16.250000, software_attenuation: -3250.125000, hardware_attenuation: 0.000000, muting is disabled.
         0.000005307 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000008506 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000015175 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000000988 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000002683 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000033394 "player.c:2007" Play begin
         0.000044610 "rtsp.c:1572"                                                                     multicast: done.
         0.000190559 "rtsp.c:1534"      pipe: done.
         0.000001590 "rtsp.c:475" msg_init message 69
         0.000028883 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.004356989 "rtp.c:628" clock synchronisation request: return time is    4.669 milliseconds.
         0.000008551 "rtsp.c:610"     Content-Length: 20.
         0.000012428 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.000006858 "rtsp.c:610"     Content-Type: text/parameters.
         0.000019618 "rtsp.c:610"     CSeq: 7.
         0.000005094 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000004966 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000004299 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006114 "rtsp.c:475" msg_init message 70
         0.000004948 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "SET_PARAMETER":
         0.000004328 "rtsp.c:507"   Type: "Content-Length", content: "20"
         0.000004009 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000004015 "rtsp.c:507"   Type: "CSeq", content: "7"
         0.000004069 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000003888 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000003675 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000005872 "rtsp.c:1873" Connection 3: SET_PARAMETER
         0.000008571 "common.c:1390" mutex_lock "&conn->volume_control_mutex" at "player.c:2841".
         0.000007725 "loudness.c:47" Volume: -43.3 dB - Loudness gain @10Hz: 11.7 dB
         0.000020730 "player.c:3051" player_volume_without_notification: volume mode is 0, airplay volume is -20.000000, software_attenuation: -4333.500000, hardware_attenuation: 0.000000, muting is disabled.
         0.000008281 "common.c:1413" mutex_unlock "&conn->volume_control_mutex" at "player.c:3068".
         0.000001359 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000004206 "rtsp.c:507"   Type: "CSeq", content: "7"
         0.000004040 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000003804 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000002537 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000028650 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70766f6c, length 25.
         0.000021020 "rtsp.c:1531"      pipe: type 73736e63, code 70766f6c, length 25.
         0.000007098 "rtsp.c:556" msg_free freed message 70
         0.000008856 "rtsp.c:1572"                                                                     multicast: done.
         0.000014408 "rtsp.c:556" msg_free freed message 69
         0.000304956 "rtsp.c:1534"      pipe: done.
         0.037379949 "player.c:466" syncing to seqno 45250.
         0.000113355 "player.c:247" Hammerton Decoder used on encrypted audio.
         0.000035603 "rtsp.c:475" msg_init message 71
         0.000066954 "rtsp.c:580" RTSP Message Received: "FLUSH rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000024363 "rtsp.c:610"     RTP-Info: seq=45249;rtptime=2639875553.
         0.000008981 "rtsp.c:610"     CSeq: 8.
         0.000007125 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006139 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000006205 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000009511 "rtsp.c:475" msg_init message 72
         0.000005896 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "FLUSH":
         0.000007092 "rtsp.c:507"   Type: "RTP-Info", content: "seq=45249;rtptime=2639875553"
         0.000008221 "rtsp.c:507"   Type: "CSeq", content: "8"
         0.000001775 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005642 "player.c:1068" pffr
         0.000007720 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000015685 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000028277 "common.c:1390" mutex_lock "&the_queue->pc_queue_lock" at "rtsp.c:212".
         0.000014337 "rtsp.c:930" Connection 3: FLUSH
         0.000042827 "common.c:1390" mutex_lock "&the_queue->pc_queue_lock" at "rtsp.c:212".
         0.000002594 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000018610 "player.c:1110" first_packet_time set for frame 2639875905.
         0.000012977 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000003972 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000003788 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000024765 "player.c:3087" player_flush
         0.000035004 "rtsp.c:1531"      pipe: type 73736e63, code 70666672, length 0.
         0.000012801 "player.c:3078" do_flush: flush to 2639875553.
         0.000031075 "common.c:1390" mutex_lock "&conn->flush_mutex" at "player.c:3079".
         0.000017360 "common.c:1413" mutex_unlock "&conn->flush_mutex" at "player.c:3083".
         0.000017612 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70666672, length 0.
         0.000024327 "rtsp.c:1572"                                                                     multicast: done.
         0.000010379 "player.c:3090" pfls
         0.000044908 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000009896 "rtsp.c:507"   Type: "CSeq", content: "8"
         0.000002003 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000020703 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70666c73, length 10.
         0.000019657 "rtsp.c:1572"                                                                     multicast: done.
         0.000006013 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000131901 "rtsp.c:556" msg_free freed message 72
         0.000018862 "rtsp.c:556" msg_free freed message 71
         0.000183638 "rtsp.c:1534"      pipe: done.
         0.000016049 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000006196 "rtsp.c:1531"      pipe: type 73736e63, code 70666c73, length 10.
         0.000147823 "rtsp.c:1534"      pipe: done.
         0.263687129 "rtp.c:628" clock synchronisation request: return time is    4.104 milliseconds.
         0.000033279 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.314883991 "rtp.c:628" clock synchronisation request: return time is   15.530 milliseconds.
         0.000036654 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.391519702 "rtp.c:628" clock synchronisation request: return time is  103.624 milliseconds.
         0.000037155 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.205707739 "rtp.c:628" clock synchronisation request: return time is    4.168 milliseconds.
         0.000036141 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.305801453 "rtp.c:628" clock synchronisation request: return time is    5.514 milliseconds.
         0.000028986 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.305658914 "rtp.c:628" clock synchronisation request: return time is    6.163 milliseconds.
         0.000036116 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.113267523 "rtsp.c:475" msg_init message 73
         0.000034698 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000010634 "rtsp.c:610"     RTP-Info: rtptime=2639871129.
         0.000006969 "rtsp.c:610"     Content-Length: 57277.
         0.000006029 "rtsp.c:610"     Content-Type: image/jpeg.
         0.000005589 "rtsp.c:610"     CSeq: 9.
         0.000005969 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000005842 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005471 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.081125124 "rtsp.c:475" msg_init message 74
         0.000035063 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "SET_PARAMETER":
         0.000007634 "rtsp.c:507"   Type: "RTP-Info", content: "rtptime=2639871129"
         0.000006738 "rtsp.c:507"   Type: "Content-Length", content: "57277"
         0.000005224 "rtsp.c:507"   Type: "Content-Type", content: "image/jpeg"
         0.000005676 "rtsp.c:507"   Type: "CSeq", content: "9"
         0.000005065 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005138 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004724 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007565 "rtsp.c:1873" Connection 3: SET_PARAMETER
         0.000006947 "rtsp.c:459" msg_free increment reference counter message 73 to 2.
         0.000014320 "rtsp.c:459" msg_free increment reference counter message 73 to 3.
         0.000008281 "rtsp.c:459" msg_free increment reference counter message 73 to 4.
         0.000005442 "rtsp.c:459" msg_free increment reference counter message 73 to 5.
         0.000005196 "rtsp.c:459" msg_free increment reference counter message 73 to 6.
         0.000005016 "rtsp.c:459" msg_free increment reference counter message 73 to 7.
         0.000005328 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000000416 "rtsp.c:507"   Type: "CSeq", content: "9"
         0.000005337 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005168 "rtsp.c:289" metadata queue- "pipe" 2/500.
         0.000002475 "rtsp.c:289" metadata queue- "multicast" 2/500.
         0.000022640 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 70637374, length 10, message 73.
         0.000017086 "rtsp.c:1572"                                                                     multicast: done.
         0.000027907 "rtsp.c:1529"      pipe: type 73736e63, code 70637374, length 10, message 73.
         0.000003324 "rtsp.c:556" msg_free freed message 74
         0.000128838 "rtsp.c:541" msg_free decrement reference counter message 73 to 6
         0.000031535 "rtsp.c:541" msg_free decrement reference counter message 73 to 5
         0.000019117 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000009837 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 50494354, length 57277, message 73.
         0.000035400 "rtsp.c:1572"                                                                     multicast: done.
         0.000019022 "rtsp.c:541" msg_free decrement reference counter message 73 to 4
         0.000007224 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000008686 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 7063656e, length 10, message 73.
         0.000007281 "rtsp.c:1572"                                                                     multicast: done.
         0.000005462 "rtsp.c:541" msg_free decrement reference counter message 73 to 3
         0.000026689 "rtsp.c:1534"      pipe: done.
         0.000011238 "rtsp.c:541" msg_free decrement reference counter message 73 to 2
         0.000222628 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000014269 "rtsp.c:1529"      pipe: type 73736e63, code 50494354, length 57277, message 73.
         0.000155684 "rtsp.c:1534"      pipe: done.
         0.000011627 "rtsp.c:541" msg_free decrement reference counter message 73 to 1
         0.000006405 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000005967 "rtsp.c:1529"      pipe: type 73736e63, code 7063656e, length 10, message 73.
         0.000133735 "rtsp.c:1534"      pipe: done.
         0.000018085 "rtsp.c:556" msg_free freed message 73
         0.037347143 "rtsp.c:475" msg_init message 75
         0.000026724 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000007194 "rtsp.c:610"     CSeq: 10.
         0.000005165 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000004809 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000004822 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000005123 "rtsp.c:475" msg_init message 76
         0.000004498 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000004319 "rtsp.c:507"   Type: "CSeq", content: "10"
         0.000004124 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000003962 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000003694 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000005585 "rtsp.c:901" Connection 3: OPTIONS
         0.000005021 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000003918 "rtsp.c:507"   Type: "CSeq", content: "10"
         0.000003791 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000003880 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000036364 "rtsp.c:556" msg_free freed message 76
         0.000008636 "rtsp.c:556" msg_free freed message 75
         0.007389450 "rtsp.c:475" msg_init message 77
         0.000029563 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000010640 "rtsp.c:610"     RTP-Info: rtptime=2639877465.
         0.000007137 "rtsp.c:610"     Content-Length: 43.
         0.000006101 "rtsp.c:610"     Content-Type: text/parameters.
         0.000006134 "rtsp.c:610"     CSeq: 11.
         0.000005804 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000005604 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005398 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007276 "rtsp.c:475" msg_init message 78
         0.000005884 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "SET_PARAMETER":
         0.000005694 "rtsp.c:507"   Type: "RTP-Info", content: "rtptime=2639877465"
         0.000005619 "rtsp.c:507"   Type: "Content-Length", content: "43"
         0.000005545 "rtsp.c:507"   Type: "Content-Type", content: "text/parameters"
         0.000004824 "rtsp.c:507"   Type: "CSeq", content: "11"
         0.000005036 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005083 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000005889 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007294 "rtsp.c:1873" Connection 3: SET_PARAMETER
         0.000018891 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005903 "rtsp.c:507"   Type: "CSeq", content: "11"
         0.000005035 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000019755 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000018289 "rtsp.c:556" msg_free freed message 78
         0.000005902 "rtsp.c:1531"      pipe: type 73736e63, code 70726772, length 32.
         0.000006008 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000041711 "rtsp.c:1568"                                                                     multicast: type 73736e63, code 70726772, length 32.
         0.000016757 "rtsp.c:1572"                                                                     multicast: done.
         0.000006755 "rtsp.c:556" msg_free freed message 77
         0.000186346 "rtsp.c:1534"      pipe: done.
         0.005467224 "rtsp.c:475" msg_init message 79
         0.000055672 "rtsp.c:580" RTSP Message Received: "SET_PARAMETER rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000010070 "rtsp.c:610"     RTP-Info: rtptime=2639877465.
         0.000005207 "rtsp.c:610"     Content-Length: 182.
         0.000006402 "rtsp.c:610"     Content-Type: application/x-dmap-tagged.
         0.000004335 "rtsp.c:610"     CSeq: 12.
         0.000004746 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000004693 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000004643 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007886 "rtsp.c:475" msg_init message 80
         0.000004721 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "SET_PARAMETER":
         0.000007729 "rtsp.c:507"   Type: "RTP-Info", content: "rtptime=2639877465"
         0.000004387 "rtsp.c:507"   Type: "Content-Length", content: "182"
         0.000005281 "rtsp.c:507"   Type: "Content-Type", content: "application/x-dmap-tagged"
         0.000003661 "rtsp.c:507"   Type: "CSeq", content: "12"
         0.000003796 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000004097 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000003728 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000008298 "rtsp.c:1873" Connection 3: SET_PARAMETER
         0.000005281 "rtsp.c:1906" received metadata tags in SET_PARAMETER request.
         0.000005701 "rtsp.c:459" msg_free increment reference counter message 79 to 2.
         0.000020361 "rtsp.c:459" msg_free increment reference counter message 79 to 3.
         0.000009298 "rtsp.c:459" msg_free increment reference counter message 79 to 4.
         0.000004235 "rtsp.c:459" msg_free increment reference counter message 79 to 5.
         0.000005070 "rtsp.c:459" msg_free increment reference counter message 79 to 6.
         0.000004326 "rtsp.c:459" msg_free increment reference counter message 79 to 7.
         0.000004248 "rtsp.c:459" msg_free increment reference counter message 79 to 8.
         0.000003955 "rtsp.c:459" msg_free increment reference counter message 79 to 9.
         0.000005245 "rtsp.c:289" metadata queue- "pipe" 3/500.
         0.000008169 "rtsp.c:289" metadata queue- "multicast" 3/500.
         0.000015727 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 6d647374, length 10, message 79.
         0.000009946 "rtsp.c:1572"                                                                     multicast: done.
         0.000026700 "rtsp.c:1529"      pipe: type 73736e63, code 6d647374, length 10, message 79.
         0.000002113 "rtsp.c:459" msg_free increment reference counter message 79 to 10.
         0.000053006 "rtsp.c:459" msg_free increment reference counter message 79 to 11.
         0.000010333 "rtsp.c:459" msg_free increment reference counter message 79 to 12.
         0.000008654 "rtsp.c:459" msg_free increment reference counter message 79 to 13.
         0.000004429 "rtsp.c:459" msg_free increment reference counter message 79 to 14.
         0.000007049 "rtsp.c:459" msg_free increment reference counter message 79 to 15.
         0.000004401 "rtsp.c:459" msg_free increment reference counter message 79 to 16.
         0.000139663 "rtsp.c:459" msg_free increment reference counter message 79 to 17.
         0.000016456 "rtsp.c:459" msg_free increment reference counter message 79 to 18.
         0.000005079 "rtsp.c:459" msg_free increment reference counter message 79 to 19.
         0.000007866 "rtsp.c:459" msg_free increment reference counter message 79 to 20.
         0.000004189 "rtsp.c:459" msg_free increment reference counter message 79 to 21.
         0.000009238 "rtsp.c:459" msg_free increment reference counter message 79 to 22.
         0.000007311 "rtsp.c:459" msg_free increment reference counter message 79 to 23.
         0.000004161 "rtsp.c:459" msg_free increment reference counter message 79 to 24.
         0.000007140 "rtsp.c:459" msg_free increment reference counter message 79 to 25.
         0.000004655 "rtsp.c:459" msg_free increment reference counter message 79 to 26.
         0.000003987 "rtsp.c:459" msg_free increment reference counter message 79 to 27.
         0.000005332 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000194978 "rtsp.c:507"   Type: "CSeq", content: "12"
         0.000016148 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005504 "rtsp.c:541" msg_free decrement reference counter message 79 to 26
         0.000196189 "rtsp.c:1534"      pipe: done.
         0.000022754 "rtsp.c:541" msg_free decrement reference counter message 79 to 25
         0.000009771 "rtsp.c:289" metadata queue- "pipe" 13/500.
         0.000026285 "rtsp.c:289" metadata queue- "multicast" 13/500.
         0.000013710 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6d706572, length 8, message 79.
         0.000011522 "rtsp.c:1529"      pipe: type 636f7265, code 6d706572, length 8, message 79.
         0.000009177 "rtsp.c:556" msg_free freed message 80
         0.000009141 "rtsp.c:541" msg_free decrement reference counter message 79 to 24
         0.000011071 "rtsp.c:1572"                                                                     multicast: done.
         0.000025676 "rtsp.c:541" msg_free decrement reference counter message 79 to 23
         0.000009609 "rtsp.c:289" metadata queue- "multicast" 12/500.
         0.000004923 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173616c, length 14, message 79.
         0.000005421 "rtsp.c:1572"                                                                     multicast: done.
         0.000004261 "rtsp.c:541" msg_free decrement reference counter message 79 to 22
         0.000004000 "rtsp.c:289" metadata queue- "multicast" 11/500.
         0.000004100 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 61736172, length 5, message 79.
         0.000004757 "rtsp.c:1572"                                                                     multicast: done.
         0.000004071 "rtsp.c:541" msg_free decrement reference counter message 79 to 21
         0.000028887 "rtsp.c:289" metadata queue- "multicast" 10/500.
         0.000327230 "rtsp.c:1534"      pipe: done.
         0.000016908 "rtsp.c:541" msg_free decrement reference counter message 79 to 20
         0.000006847 "rtsp.c:289" metadata queue- "pipe" 12/500.
         0.000010404 "rtsp.c:1568"                                                                     multicast: type 636f7265, code 61736370, length 0.
         0.000010991 "rtsp.c:1572"                                                                     multicast: done.
         0.000009764 "rtsp.c:289" metadata queue- "multicast" 9/500.
         0.000007642 "rtsp.c:1568"                                                                     multicast: type 636f7265, code 6173676e, length 0.
         0.000004973 "rtsp.c:1529"      pipe: type 636f7265, code 6173616c, length 14, message 79.
         0.000009019 "rtsp.c:1572"                                                                     multicast: done.
         0.000019669 "rtsp.c:289" metadata queue- "multicast" 8/500.
         0.000004596 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6d696e6d, length 29, message 79.
         0.000004729 "rtsp.c:1572"                                                                     multicast: done.
         0.000004614 "rtsp.c:541" msg_free decrement reference counter message 79 to 19
         0.000004580 "rtsp.c:289" metadata queue- "multicast" 7/500.
         0.000004115 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173746e, length 2, message 79.
         0.000004589 "rtsp.c:1572"                                                                     multicast: done.
         0.000004290 "rtsp.c:541" msg_free decrement reference counter message 79 to 18
         0.000004477 "rtsp.c:289" metadata queue- "multicast" 6/500.
         0.000003946 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 61737463, length 2, message 79.
         0.000004475 "rtsp.c:1572"                                                                     multicast: done.
         0.000004141 "rtsp.c:541" msg_free decrement reference counter message 79 to 17
         0.000004135 "rtsp.c:289" metadata queue- "multicast" 5/500.
         0.000003936 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173646e, length 2, message 79.
         0.000004392 "rtsp.c:1572"                                                                     multicast: done.
         0.000004336 "rtsp.c:541" msg_free decrement reference counter message 79 to 16
         0.000004009 "rtsp.c:289" metadata queue- "multicast" 4/500.
         0.000003840 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 61736463, length 2, message 79.
         0.000004432 "rtsp.c:1572"                                                                     multicast: done.
         0.000004235 "rtsp.c:541" msg_free decrement reference counter message 79 to 15
         0.000003947 "rtsp.c:289" metadata queue- "multicast" 3/500.
         0.000003858 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173646b, length 1, message 79.
         0.000004339 "rtsp.c:1572"                                                                     multicast: done.
         0.000004531 "rtsp.c:541" msg_free decrement reference counter message 79 to 14
         0.000005086 "rtsp.c:289" metadata queue- "multicast" 2/500.
         0.000004844 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 63617073, length 1, message 79.
         0.000004352 "rtsp.c:1572"                                                                     multicast: done.
         0.000004270 "rtsp.c:541" msg_free decrement reference counter message 79 to 13
         0.000004120 "rtsp.c:289" metadata queue- "multicast" 1/500.
         0.000003842 "rtsp.c:1563"                                                                     multicast: type 636f7265, code 6173746d, length 4, message 79.
         0.000006003 "rtsp.c:1572"                                                                     multicast: done.
         0.000004275 "rtsp.c:541" msg_free decrement reference counter message 79 to 12
         0.000000786 "rtsp.c:1534"      pipe: done.
         0.000010324 "rtsp.c:541" msg_free decrement reference counter message 79 to 11
         0.000005037 "rtsp.c:289" metadata queue- "pipe" 11/500.
         0.000004319 "rtsp.c:1529"      pipe: type 636f7265, code 61736172, length 5, message 79.
         0.000003486 "rtsp.c:289" metadata queue- "multicast" 0/500.
         0.000087855 "rtsp.c:1563"                                                                     multicast: type 73736e63, code 6d64656e, length 10, message 79.
         0.000013894 "rtsp.c:1572"                                                                     multicast: done.
         0.000005285 "rtsp.c:541" msg_free decrement reference counter message 79 to 10
         0.000043812 "rtsp.c:1534"      pipe: done.
         0.000008767 "rtsp.c:541" msg_free decrement reference counter message 79 to 9
         0.000004452 "rtsp.c:289" metadata queue- "pipe" 10/500.
         0.000004173 "rtsp.c:1531"      pipe: type 636f7265, code 61736370, length 0.
         0.000109069 "rtsp.c:1534"      pipe: done.
         0.000008370 "rtsp.c:289" metadata queue- "pipe" 9/500.
         0.000004514 "rtsp.c:1531"      pipe: type 636f7265, code 6173676e, length 0.
         0.000099020 "rtsp.c:1534"      pipe: done.
         0.000007861 "rtsp.c:289" metadata queue- "pipe" 8/500.
         0.000004095 "rtsp.c:1529"      pipe: type 636f7265, code 6d696e6d, length 29, message 79.
         0.000100773 "rtsp.c:1534"      pipe: done.
         0.000010355 "rtsp.c:541" msg_free decrement reference counter message 79 to 8
         0.000004468 "rtsp.c:289" metadata queue- "pipe" 7/500.
         0.000004082 "rtsp.c:1529"      pipe: type 636f7265, code 6173746e, length 2, message 79.
         0.000087809 "rtsp.c:1534"      pipe: done.
         0.000010759 "rtsp.c:541" msg_free decrement reference counter message 79 to 7
         0.000004303 "rtsp.c:289" metadata queue- "pipe" 6/500.
         0.000003902 "rtsp.c:1529"      pipe: type 636f7265, code 61737463, length 2, message 79.
         0.000086330 "rtsp.c:1534"      pipe: done.
         0.000007278 "rtsp.c:541" msg_free decrement reference counter message 79 to 6
         0.000004150 "rtsp.c:289" metadata queue- "pipe" 5/500.
         0.000003966 "rtsp.c:1529"      pipe: type 636f7265, code 6173646e, length 2, message 79.
         0.000085145 "rtsp.c:1534"      pipe: done.
         0.000007620 "rtsp.c:541" msg_free decrement reference counter message 79 to 5
         0.000004149 "rtsp.c:289" metadata queue- "pipe" 4/500.
         0.000003951 "rtsp.c:1529"      pipe: type 636f7265, code 61736463, length 2, message 79.
         0.000084796 "rtsp.c:1534"      pipe: done.
         0.000007397 "rtsp.c:541" msg_free decrement reference counter message 79 to 4
         0.000004099 "rtsp.c:289" metadata queue- "pipe" 3/500.
         0.000003909 "rtsp.c:1529"      pipe: type 636f7265, code 6173646b, length 1, message 79.
         0.000091429 "rtsp.c:1534"      pipe: done.
         0.000007366 "rtsp.c:541" msg_free decrement reference counter message 79 to 3
         0.000004235 "rtsp.c:289" metadata queue- "pipe" 2/500.
         0.000004154 "rtsp.c:1529"      pipe: type 636f7265, code 63617073, length 1, message 79.
         0.000083943 "rtsp.c:1534"      pipe: done.
         0.000009884 "rtsp.c:541" msg_free decrement reference counter message 79 to 2
         0.000004286 "rtsp.c:289" metadata queue- "pipe" 1/500.
         0.000003977 "rtsp.c:1529"      pipe: type 636f7265, code 6173746d, length 4, message 79.
         0.000084541 "rtsp.c:1534"      pipe: done.
         0.000007267 "rtsp.c:541" msg_free decrement reference counter message 79 to 1
         0.000004103 "rtsp.c:289" metadata queue- "pipe" 0/500.
         0.000003938 "rtsp.c:1529"      pipe: type 73736e63, code 6d64656e, length 10, message 79.
         0.000090776 "rtsp.c:1534"      pipe: done.
         0.000010372 "rtsp.c:556" msg_free freed message 79
         1.973057004 "rtsp.c:475" msg_init message 81
         0.000036061 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010489 "rtsp.c:610"     CSeq: 13.
         0.000007190 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006107 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000007649 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006736 "rtsp.c:475" msg_init message 82
         0.000005552 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005611 "rtsp.c:507"   Type: "CSeq", content: "13"
         0.000005283 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005244 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000005132 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006851 "rtsp.c:901" Connection 3: OPTIONS
         0.000006604 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005424 "rtsp.c:507"   Type: "CSeq", content: "13"
         0.000005184 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004812 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000046396 "rtsp.c:556" msg_free freed message 82
         0.000011914 "rtsp.c:556" msg_free freed message 81
         0.776838053 "rtp.c:628" clock synchronisation request: return time is    4.392 milliseconds.
         0.000036829 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         1.266722965 "rtsp.c:475" msg_init message 83
         0.000036126 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010181 "rtsp.c:610"     CSeq: 14.
         0.000006605 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006535 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005677 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006879 "rtsp.c:475" msg_init message 84
         0.000005420 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000008139 "rtsp.c:507"   Type: "CSeq", content: "14"
         0.000005328 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005016 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004957 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006790 "rtsp.c:901" Connection 3: OPTIONS
         0.000006318 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000006488 "rtsp.c:507"   Type: "CSeq", content: "14"
         0.000004822 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004854 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000041048 "rtsp.c:556" msg_free freed message 84
         0.000011471 "rtsp.c:556" msg_free freed message 83
         1.928255753 "rtp.c:628" clock synchronisation request: return time is  198.871 milliseconds.
         0.000038063 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.071485588 "rtsp.c:475" msg_init message 85
         0.000034829 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010057 "rtsp.c:610"     CSeq: 15.
         0.000006566 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006626 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005602 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006402 "rtsp.c:475" msg_init message 86
         0.000005670 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005734 "rtsp.c:507"   Type: "CSeq", content: "15"
         0.000005842 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005061 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004831 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006869 "rtsp.c:901" Connection 3: OPTIONS
         0.000006032 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005045 "rtsp.c:507"   Type: "CSeq", content: "15"
         0.000005358 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000006242 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000045442 "rtsp.c:556" msg_free freed message 86
         0.000011612 "rtsp.c:556" msg_free freed message 85
         2.003126756 "rtsp.c:475" msg_init message 87
         0.000035711 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010389 "rtsp.c:610"     CSeq: 16.
         0.000006589 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006710 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005854 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006841 "rtsp.c:475" msg_init message 88
         0.000005929 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005660 "rtsp.c:507"   Type: "CSeq", content: "16"
         0.000005884 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005147 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004931 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006868 "rtsp.c:901" Connection 3: OPTIONS
         0.000006136 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005110 "rtsp.c:507"   Type: "CSeq", content: "16"
         0.000005234 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005310 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000045421 "rtsp.c:556" msg_free freed message 88
         0.000011490 "rtsp.c:556" msg_free freed message 87
         0.736183544 "rtp.c:628" clock synchronisation request: return time is    6.011 milliseconds.
         0.000036331 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         1.374629955 "rtsp.c:475" msg_init message 89
         0.000031098 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000009943 "rtsp.c:610"     CSeq: 17.
         0.000006519 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006489 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005814 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007430 "rtsp.c:475" msg_init message 90
         0.000005806 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005594 "rtsp.c:507"   Type: "CSeq", content: "17"
         0.000005247 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000004967 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004922 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006801 "rtsp.c:901" Connection 3: OPTIONS
         0.000006375 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005170 "rtsp.c:507"   Type: "CSeq", content: "17"
         0.000005000 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005158 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000040561 "rtsp.c:556" msg_free freed message 90
         0.000011747 "rtsp.c:556" msg_free freed message 89
         1.629893208 "rtp.c:628" clock synchronisation request: return time is    5.495 milliseconds.
         0.000034430 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.410459396 "rtsp.c:475" msg_init message 91
         0.000034547 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010197 "rtsp.c:610"     CSeq: 18.
         0.000006657 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006611 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000005593 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006831 "rtsp.c:475" msg_init message 92
         0.000005722 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005718 "rtsp.c:507"   Type: "CSeq", content: "18"
         0.000005515 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005080 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000005106 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006797 "rtsp.c:901" Connection 3: OPTIONS
         0.000006395 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005988 "rtsp.c:507"   Type: "CSeq", content: "18"
         0.000005354 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000004947 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000039945 "rtsp.c:556" msg_free freed message 92
         0.000011846 "rtsp.c:556" msg_free freed message 91
         2.102225712 "rtsp.c:475" msg_init message 93
         0.000035206 "rtsp.c:580" RTSP Message Received: "OPTIONS * RTSP/1.0".
         0.000010894 "rtsp.c:610"     CSeq: 19.
         0.000007377 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006110 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000006073 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000007010 "rtsp.c:475" msg_init message 94
         0.000005564 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "OPTIONS":
         0.000005668 "rtsp.c:507"   Type: "CSeq", content: "19"
         0.000005197 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000004904 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000004995 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000006514 "rtsp.c:901" Connection 3: OPTIONS
         0.000006460 "rtsp.c:2706" Connection 3: RTSP Response:
         0.000005129 "rtsp.c:507"   Type: "CSeq", content: "19"
         0.000005353 "rtsp.c:507"   Type: "Server", content: "AirTunes/105.1"
         0.000005094 "rtsp.c:507"   Type: "Public", content: "ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER"
         0.000044431 "rtsp.c:556" msg_free freed message 94
         0.000011070 "rtsp.c:556" msg_free freed message 93
         0.488324020 "rtp.c:628" clock synchronisation request: return time is    4.254 milliseconds.
         0.000035397 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         0.206848972 "rtsp.c:475" msg_init message 95
         0.000035506 "rtsp.c:580" RTSP Message Received: "TEARDOWN rtsp://fe80::1044:2655:a073:45f2/2007045935244068460 RTSP/1.0".
         0.000010963 "rtsp.c:610"     CSeq: 20.
         0.000006986 "rtsp.c:610"     DACP-ID: 2356F4FA343F52FF.
         0.000006755 "rtsp.c:610"     Active-Remote: 2287535949.
         0.000008150 "rtsp.c:610"     User-Agent: AirPlay/545.22.21.
         0.000006927 "rtsp.c:475" msg_init message 96
         0.000005559 "rtsp.c:2663" Connection 3: Received an RTSP Packet of type "TEARDOWN":
         0.000005667 "rtsp.c:507"   Type: "CSeq", content: "20"
         0.000005236 "rtsp.c:507"   Type: "DACP-ID", content: "2356F4FA343F52FF"
         0.000005219 "rtsp.c:507"   Type: "Active-Remote", content: "2287535949"
         0.000005261 "rtsp.c:507"   Type: "User-Agent", content: "AirPlay/545.22.21"
         0.000007363 "rtsp.c:911" Connection 3: TEARDOWN
         0.000006859 "common.c:1390" mutex_lock "&playing_conn_lock" at "rtsp.c:304".
         0.000009150 "common.c:1413" mutex_unlock "&playing_conn_lock" at "rtsp.c:307".
         0.000006999 "rtsp.c:918" TEARDOWN: synchronously terminating the player thread of RTSP conversation thread 3 (2).
         0.000006062 "player.c:3130" player_stop
         0.000005210 "player.c:3132" player_thread cancel...
         0.000012126 "player.c:3134" player_thread join...
         2.998015914 "rtp.c:628" clock synchronisation request: return time is  205.433 milliseconds.
         0.000034202 "rtp.c:821" Time ping turnaround time: 205432644 ns -- it looks like a timing ping was lost.
         2.799762693 "rtp.c:628" clock synchronisation request: return time is    5.003 milliseconds.
         0.000036898 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         3.002609737 "rtp.c:628" clock synchronisation request: return time is    4.799 milliseconds.
         0.000036939 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         3.088466721 "rtp.c:628" clock synchronisation request: return time is   92.109 milliseconds.
         0.000036933 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         2.912649232 "rtp.c:628" clock synchronisation request: return time is    4.421 milliseconds.
         0.000036727 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         3.047682004 "rtp.c:628" clock synchronisation request: return time is   51.640 milliseconds.
         0.000030942 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
         2.964574975 "rtp.c:628" clock synchronisation request: return time is   13.587 milliseconds.
         0.000074395 "rtp.c:811" not enough samples to estimate drift -- remaining at 0.00 ppm.
mikebrady commented 3 years ago

Thanks for the post. I've edited it slightly for format. I am afraid I don't have any great experience of using Shairport Sync in the Mac. Maybe some other contributors would have some suggestions. (BTW, a verbosity of 3 gives way too much low level detail for a post like this.)

danyal commented 3 years ago

Thanks for the fast response. If helpful I can repost with verbosity 2. Have you ever seen this type of problem on other platforms before?

mikebrady commented 3 years ago

It's not something that happens often, no. At a guess, it sounds like a situation where the ao backend isn't closing down properly. That could be a fault with the backend itself or with the ao implementation.

danyal commented 3 years ago

I tried switching to 'pipe' as the audio backend (not sure where the audio is actually going) but this solved the problem. So it seems like it is related to AO.

mikebrady commented 3 years ago

Yeah, sorry not to be able to give you a more satisfactory outcome... Maybe someone else might be able to help more.

github-actions[bot] commented 3 years ago

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