mikebrady / shairport-sync

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

[Bug]: Cannot connect to Shairport-Sync Airplay2 development version. #1525

Closed danielgoodell closed 2 years ago

danielgoodell commented 2 years ago

What happened?

I recently decided to try out the latest Shairport-Sync development version to see how Airplay 2 was working.

I built it on a Raspberry Pi Zero W with the latest Rapbian Lite OS. everything seemed to go smoothly and had no trouble building and installing. I connected to it from an iPhone 11 pro with IOS 15.6.1 and it played sound through the USB DAC. Then, I disconnected and could not reconnect again no matter what I did (stopping, restarting, reinstalling, etc.) Every time I try to connect the phone just says "unable to connect". If I remove it and install the normal shairport-sync airplay 1 package it works fine. I also have raspotify on there it plays just fine as well. I have no clue.

I attached a log of a failed connection attempt with the verbosity level set to 3.

Relevant log output

Aug 26 21:43:46 audiopi shairport-sync[2042]:          1.087189000 "rtsp.c:753" mutex_lock "&conns_lock".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.005967000 "rtsp.c:756" found RTSP connection thread 4 in a non-running state.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000221000 "rtsp.c:759" Connection 4: deleted in cleanup.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000127000 "common.c:1553" mutex_unlock "&conns_lock" at "rtsp.c:764".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000281000 "rtsp.c:5361" Connection 5: new connection from fe80::c21:2e8a:df61:99b2:49191 to self at ::12f7:a304:eb73:409d:7000.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000304000 "rtsp.c:5377" Successfully created RTSP receiver thread 5.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000139000 "rtsp.c:693" mutex_lock "&conns_lock".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000119000 "common.c:1553" mutex_unlock "&conns_lock" at "rtsp.c:715".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000484000 "rtsp.c:814" msg_init message 57
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000180000 "rtsp.c:923" RTSP Message Received: "GET /info RTSP/1.0".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000137000 "rtsp.c:954"     X-Apple-ProtocolVersion: 1.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000117000 "rtsp.c:954"     Content-Length: 70.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000114000 "rtsp.c:954"     Content-Type: application/x-apple-binary-plist.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000108000 "rtsp.c:954"     CSeq: 0.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000123000 "rtsp.c:814" msg_init message 58
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000111000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "GET":
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:4983"   Type: "X-Apple-ProtocolVersion", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:4983"   Type: "Content-Length", content: "70"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:4983"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:4983"   Type: "CSeq", content: "0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000187000 "rtsp.c:4983"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>qualifier</key>
                                                      <array>
                                                              <string>txtAirPlay</string>
                                                      </array>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000131000 "rtsp.c:1931" Connection 5: GET /info :: Content-Length 70
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000107000 "rtsp.c:1933" GET request
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:1933"   Type: "X-Apple-ProtocolVersion", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:1933"   Type: "Content-Length", content: "70"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:1933"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.006708000 "rtsp.c:1933"   Type: "CSeq", content: "0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000180000 "rtsp.c:1933"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000187000 "rtsp.c:1933"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>qualifier</key>
                                                      <array>
                                                              <string>txtAirPlay</string>
                                                      </array>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000127000 "rtsp.c:1592" GET /info:
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:1592"   Type: "X-Apple-ProtocolVersion", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:1592"   Type: "Content-Length", content: "70"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:1592"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000108000 "rtsp.c:1592"   Type: "CSeq", content: "0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:1592"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000155000 "rtsp.c:1592"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>qualifier</key>
                                                      <array>
                                                              <string>txtAirPlay</string>
                                                      </array>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000123000 "rtsp.c:1601" Connection 5: GET_INFO: Source AirPlay Version is: 620.8.2.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000138000 "rtsp.c:1624" GET /info Stage 1: qualifier: txtAirPlay
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.008102000 "rtsp.c:1706" GET /info Stage 1 Response:
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000222000 "rtsp.c:1706"   Response Code: 501.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000116000 "rtsp.c:1706"   Type: "CSeq", content: "0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:1706"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:1706"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000592000 "rtsp.c:1706"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>audioLatencies</key>
                                                      <array>
                                                              <dict>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>100</integer>
                                                              </dict>
                                                              <dict>
                                                                      <key>audioType</key>
                                                                      <string>default</string>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>100</integer>
                                                              </dict>
                                                              <dict>
                                                                      <key>audioType</key>
                                                                      <string>media</string>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>100</integer>
                                                              </dict>
                                                              <dict>
                                                                      <key>audioType</key>
                                                                      <string>media</string>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>102</integer>
                                                              </dict>
                                                      </array>
                                                      <key>keepAliveLowPower</key>
                                                      <true/>
                                                      <key>keepAliveSendStatsAsBody</key>
                                                      <true/>
                                                      <key>manufacturer</key>
                                                      <string>Shairport Sync</string>
                                                      <key>nameIsFactoryDefault</key>
                                                      <false/>
                                                      <key>protocolVersion</key>
                                                      <string>1.1</string>
                                                      <key>sdk</key>
                                                      <string>AirPlay;2.0.2</string>
                                                      <key>sourceVersion</key>
                                                      <string>366.0</string>
                                                      <key>statusFlags</key>
                                                      <integer>4</integer>
                                                      <key>txtAirPlay</key>
                                                      <data>
                                                      BWFjbD0wGmRldmljZWlkPWI4OjI3OmViOjk5OmEwOjdmG2ZlYXR1cmVzPTB4NDA1QzRB
                                                      MDAsMHgxQzM0MAdyc2Y9MHgwCWZsYWdzPTB4NBRtb2RlbD1TaGFpcnBvcnQgU3luYw1t
                                                      YW51ZmFjdHVyZXI9DXNlcmlhbE51bWJlcj0NcHJvdG92ZXJzPTEuMQ1zcmN2ZXJzPTM2
                                                      Ni4wJ3BpPWI0ODAxN2Q0LWE2ZjItNGM1MC05MTI3LTlkNjBiZDMxNWRmOShnaWQ9YjQ4
                                                      MDE3ZDQtYTZmMi00YzUwLTkxMjctOWQ2MGJkMzE1ZGY5BmdjZ2w9MENwaz04YmIzNzYx
                                                      ODdmYWQyNmYwNjc5YTQxMGRkMGNkZGFmYjY4ZGRmMjlmZGI0NzA0ZDRjMjFkZWZmYzIw
                                                      ZmQ3N2I5
                                                      </data>
                                                      <key>features</key>
                                                      <integer>496155701824000</integer>
                                                      <key>deviceID</key>
                                                      <string>b8:27:eb:99:a0:7f</string>
                                                      <key>pi</key>
                                                      <string>b48017d4-a6f2-4c50-9127-9d60bd315df9</string>
                                                      <key>name</key>
                                                      <string>Audiopi</string>
                                                      <key>model</key>
                                                      <string>Shairport Sync</string>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000235000 "rtsp.c:5042" Connection 5: RTSP Response:
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000113000 "rtsp.c:5043"   Response Code: 200.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:5043"   Type: "CSeq", content: "0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:5043"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:5043"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000563000 "rtsp.c:5043"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>audioLatencies</key>
                                                      <array>
                                                              <dict>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>100</integer>
                                                              </dict>
                                                              <dict>
                                                                      <key>audioType</key>
                                                                      <string>default</string>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>100</integer>
                                                              </dict>
                                                              <dict>
                                                                      <key>audioType</key>
                                                                      <string>media</string>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>100</integer>
                                                              </dict>
                                                              <dict>
                                                                      <key>audioType</key>
                                                                      <string>media</string>
                                                                      <key>inputLatencyMicros</key>
                                                                      <integer>0</integer>
                                                                      <key>outputLatencyMicros</key>
                                                                      <integer>400000</integer>
                                                                      <key>type</key>
                                                                      <integer>102</integer>
                                                              </dict>
                                                      </array>
                                                      <key>keepAliveLowPower</key>
                                                      <true/>
                                                      <key>keepAliveSendStatsAsBody</key>
                                                      <true/>
                                                      <key>manufacturer</key>
                                                      <string>Shairport Sync</string>
                                                      <key>nameIsFactoryDefault</key>
                                                      <false/>
                                                      <key>protocolVersion</key>
                                                      <string>1.1</string>
                                                      <key>sdk</key>
                                                      <string>AirPlay;2.0.2</string>
                                                      <key>sourceVersion</key>
                                                      <string>366.0</string>
                                                      <key>statusFlags</key>
                                                      <integer>4</integer>
                                                      <key>txtAirPlay</key>
                                                      <data>
                                                      BWFjbD0wGmRldmljZWlkPWI4OjI3OmViOjk5OmEwOjdmG2ZlYXR1cmVzPTB4NDA1QzRB
                                                      MDAsMHgxQzM0MAdyc2Y9MHgwCWZsYWdzPTB4NBRtb2RlbD1TaGFpcnBvcnQgU3luYw1t
                                                      YW51ZmFjdHVyZXI9DXNlcmlhbE51bWJlcj0NcHJvdG92ZXJzPTEuMQ1zcmN2ZXJzPTM2
                                                      Ni4wJ3BpPWI0ODAxN2Q0LWE2ZjItNGM1MC05MTI3LTlkNjBiZDMxNWRmOShnaWQ9YjQ4
                                                      MDE3ZDQtYTZmMi00YzUwLTkxMjctOWQ2MGJkMzE1ZGY5BmdjZ2w9MENwaz04YmIzNzYx
                                                      ODdmYWQyNmYwNjc5YTQxMGRkMGNkZGFmYjY4ZGRmMjlmZGI0NzA0ZDRjMjFkZWZmYzIw
                                                      ZmQ3N2I5
                                                      </data>
                                                      <key>features</key>
                                                      <integer>496155701824000</integer>
                                                      <key>deviceID</key>
                                                      <string>b8:27:eb:99:a0:7f</string>
                                                      <key>pi</key>
                                                      <string>b48017d4-a6f2-4c50-9127-9d60bd315df9</string>
                                                      <key>name</key>
                                                      <string>Audiopi</string>
                                                      <key>model</key>
                                                      <string>Shairport Sync</string>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000198000 "rtsp.c:1455" Responding with content of length 905
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.005366000 "rtsp.c:899" msg_free freed message 58
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000217000 "rtsp.c:899" msg_free freed message 57
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.030004000 "rtsp.c:814" msg_init message 59
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000195000 "rtsp.c:923" RTSP Message Received: "POST /pair-verify RTSP/1.0".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000121000 "rtsp.c:954"     X-Apple-AbsoluteTime: 683257425.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000107000 "rtsp.c:954"     X-Apple-HKP: 6.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000114000 "rtsp.c:954"     X-Apple-Client-Name: iPhone Camera.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000105000 "rtsp.c:954"     X-Apple-PD: 1.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:954"     Content-Length: 37.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000107000 "rtsp.c:954"     Content-Type: application/octet-stream.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000114000 "rtsp.c:954"     CSeq: 1.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000121000 "rtsp.c:814" msg_init message 60
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000116000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "POST":
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:4983"   Type: "X-Apple-AbsoluteTime", content: "683257425"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:4983"   Type: "X-Apple-HKP", content: "6"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:4983"   Type: "X-Apple-Client-Name", content: "iPhone Camera"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:4983"   Type: "X-Apple-PD", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:4983"   Type: "Content-Length", content: "37"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:4983"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:4983"   Type: "CSeq", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000116000 "rtsp.c:4983"   No Content Plist. Content length: 37.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000119000 "rtsp.c:2091" Connection 5: pair-verify Content-Length 37
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.014420000 "rtsp.c:2127" pair-verify response
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000194000 "rtsp.c:2127"   Response Code: 200.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:2127"   Type: "CSeq", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:2127"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.002526000 "rtsp.c:2127"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000137000 "rtsp.c:2127"   No Content Plist. Content length: 140.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000114000 "rtsp.c:5042" Connection 5: RTSP Response:
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000108000 "rtsp.c:5043"   Response Code: 200.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:5043"   Type: "CSeq", content: "1"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:5043"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000115000 "rtsp.c:5043"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:5043"   No Content Plist. Content length: 140.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000120000 "rtsp.c:1455" Responding with content of length 140
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.002465000 "rtsp.c:899" msg_free freed message 60
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000208000 "rtsp.c:899" msg_free freed message 59
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.012917000 "rtsp.c:814" msg_init message 61
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000195000 "rtsp.c:923" RTSP Message Received: "POST /pair-setup RTSP/1.0".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000123000 "rtsp.c:954"     X-Apple-AbsoluteTime: 683257426.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000116000 "rtsp.c:954"     X-Apple-HKP: 4.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:954"     X-Apple-Client-Name: iPhone Camera.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000105000 "rtsp.c:954"     Content-Length: 9.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000110000 "rtsp.c:954"     Content-Type: application/x-apple-binary-plist.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:954"     CSeq: 2.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000276000 "rtsp.c:814" msg_init message 62
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000134000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "POST":
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:4983"   Type: "X-Apple-AbsoluteTime", content: "683257426"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:4983"   Type: "X-Apple-HKP", content: "4"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:4983"   Type: "X-Apple-Client-Name", content: "iPhone Camera"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000395000 "rtsp.c:4983"   Type: "Content-Length", content: "9"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000113000 "rtsp.c:4983"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:4983"   Type: "CSeq", content: "2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000116000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000105000 "rtsp.c:4983"   No Content Plist. Content length: 9.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000117000 "rtsp.c:2135" Connection 5: pair-setup Content-Length 9
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.555004000 "rtsp.c:2173" pair-setup response
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.002299000 "rtsp.c:2173"   Response Code: 200.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.001922000 "rtsp.c:2173"   Type: "CSeq", content: "2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.002286000 "rtsp.c:2173"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000206000 "rtsp.c:2173"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000109000 "rtsp.c:2173"   No Content Plist. Content length: 409.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000105000 "rtsp.c:5042" Connection 5: RTSP Response:
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:5043"   Response Code: 200.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:5043"   Type: "CSeq", content: "2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:5043"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.002934000 "rtsp.c:5043"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000136000 "rtsp.c:5043"   No Content Plist. Content length: 409.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000123000 "rtsp.c:1455" Responding with content of length 409
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.002653000 "rtsp.c:899" msg_free freed message 62
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000212000 "rtsp.c:899" msg_free freed message 61
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.154561000 "rtsp.c:814" msg_init message 63
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000211000 "rtsp.c:923" RTSP Message Received: "POST /pair-setup RTSP/1.0".
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000131000 "rtsp.c:954"     X-Apple-AbsoluteTime: 683257426.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000109000 "rtsp.c:954"     X-Apple-HKP: 4.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000115000 "rtsp.c:954"     X-Apple-Client-Name: iPhone Camera.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000108000 "rtsp.c:954"     Content-Length: 457.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000113000 "rtsp.c:954"     Content-Type: application/x-apple-binary-plist.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000111000 "rtsp.c:954"     CSeq: 3.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000122000 "rtsp.c:814" msg_init message 64
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000109000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "POST":
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000110000 "rtsp.c:4983"   Type: "X-Apple-AbsoluteTime", content: "683257426"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:4983"   Type: "X-Apple-HKP", content: "4"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:4983"   Type: "X-Apple-Client-Name", content: "iPhone Camera"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.001230000 "rtsp.c:4983"   Type: "Content-Length", content: "457"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000131000 "rtsp.c:4983"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:4983"   Type: "CSeq", content: "3"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000102000 "rtsp.c:4983"   No Content Plist. Content length: 457.
Aug 26 21:43:46 audiopi shairport-sync[2042]:          0.000118000 "rtsp.c:2135" Connection 5: pair-setup Content-Length 457
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.214584000 "rtsp.c:2173" pair-setup response
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.010156000 "rtsp.c:2173"   Response Code: 200.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000210000 "rtsp.c:2173"   Type: "CSeq", content: "3"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000109000 "rtsp.c:2173"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:2173"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:2173"   No Content Plist. Content length: 69.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:5042" Connection 5: RTSP Response:
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000105000 "rtsp.c:5043"   Response Code: 200.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:5043"   Type: "CSeq", content: "3"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:5043"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000096000 "rtsp.c:5043"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:5043"   No Content Plist. Content length: 69.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000126000 "rtsp.c:1455" Responding with content of length 69
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.006700000 "rtsp.c:899" msg_free freed message 64
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000209000 "rtsp.c:899" msg_free freed message 63
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.130652000 "rtsp.c:814" msg_init message 65
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000208000 "rtsp.c:923" RTSP Message Received: "POST /fp-setup RTSP/1.0".
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000125000 "rtsp.c:954"     X-Apple-ET: 32.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000107000 "rtsp.c:954"     Content-Length: 16.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:954"     Content-Type: application/octet-stream.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:954"     CSeq: 4.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000121000 "rtsp.c:814" msg_init message 66
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000116000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "POST":
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000108000 "rtsp.c:4983"   Type: "X-Apple-ET", content: "32"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:4983"   Type: "Content-Length", content: "16"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:4983"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:4983"   Type: "CSeq", content: "4"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:4983"   No Content Plist. Content length: 16.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000129000 "rtsp.c:5042" Connection 5: RTSP Response:
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.009369000 "rtsp.c:5043"   Response Code: 200.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000195000 "rtsp.c:5043"   Type: "CSeq", content: "4"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:5043"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:5043"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:5043"   No Content Plist. Content length: 142.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000120000 "rtsp.c:1455" Responding with content of length 142
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000975000 "rtsp.c:899" msg_free freed message 66
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000202000 "rtsp.c:899" msg_free freed message 65
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.003993000 "rtsp.c:814" msg_init message 67
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000188000 "rtsp.c:923" RTSP Message Received: "POST /fp-setup RTSP/1.0".
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000121000 "rtsp.c:954"     X-Apple-ET: 32.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000117000 "rtsp.c:954"     Content-Length: 164.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000107000 "rtsp.c:954"     Content-Type: application/octet-stream.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000111000 "rtsp.c:954"     CSeq: 5.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000128000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000124000 "rtsp.c:814" msg_init message 68
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000110000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "POST":
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:4983"   Type: "X-Apple-ET", content: "32"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000096000 "rtsp.c:4983"   Type: "Content-Length", content: "164"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:4983"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:4983"   Type: "CSeq", content: "5"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:4983"   No Content Plist. Content length: 164.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000122000 "rtsp.c:5042" Connection 5: RTSP Response:
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000103000 "rtsp.c:5043"   Response Code: 200.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:5043"   Type: "CSeq", content: "5"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:5043"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:5043"   Type: "Content-Type", content: "application/octet-stream"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:5043"   No Content Plist. Content length: 32.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000118000 "rtsp.c:1455" Responding with content of length 32
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.002589000 "rtsp.c:899" msg_free freed message 68
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000211000 "rtsp.c:899" msg_free freed message 67
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.003915000 "rtsp.c:814" msg_init message 69
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000195000 "rtsp.c:923" RTSP Message Received: "SETUP rtsp://::12f7:a304:eb73:409d/6406275098645449015 RTSP/1.0".
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000124000 "rtsp.c:954"     Content-Length: 425.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000120000 "rtsp.c:954"     Content-Type: application/x-apple-binary-plist.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000107000 "rtsp.c:954"     CSeq: 6.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:954"     User-Agent: AirPlay/620.8.2.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000128000 "rtsp.c:814" msg_init message 70
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000112000 "rtsp.c:4981" Connection 5: Received an RTSP Packet of type "SETUP":
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000123000 "rtsp.c:4983"   Type: "Content-Length", content: "425"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:4983"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:4983"   Type: "CSeq", content: "6"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:4983"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000308000 "rtsp.c:4983"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>timingProtocol</key>
                                                      <string>None</string>
                                                      <key>name</key>
                                                      <string>iPhone Camera</string>
                                                      <key>isRemoteControlOnly</key>
                                                      <true/>
                                                      <key>osName</key>
                                                      <string>iPhone OS</string>
                                                      <key>sessionUUID</key>
                                                      <string>58E7A942-A431-4937-B38F-215C97066CFA</string>
                                                      <key>osBuildVersion</key>
                                                      <string>19G82</string>
                                                      <key>sourceVersion</key>
                                                      <string>620.8.2</string>
                                                      <key>osVersion</key>
                                                      <string>15.6.1</string>
                                                      <key>internalBuild</key>
                                                      <false/>
                                                      <key>deviceID</key>
                                                      <string>9C:E6:5E:15:47:A9</string>
                                                      <key>model</key>
                                                      <string>iPhone9,3</string>
                                                      <key>diagnosticsAndUsage</key>
                                                      <true/>
                                                      <key>macAddress</key>
                                                      <string>96:B6:47:15:78:AD</string>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000163000 "rtsp.c:2733" Connection 5: SETUP (AirPlay 2)
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000222000 "rtsp.c:2744" Connection 5 SETUP: No "streams" array has been found -- create an event thread and open a TCP port.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000125000 "rtsp.c:2775" Connection 5: SETUP: a "None" setup detected.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000109000 "rtsp.c:2782" Connection 5: Remote Control connection from fe80::c21:2e8a:df61:99b2:49191 to self at ::12f7:a304:eb73:409d:7000.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000121000 "rtsp.c:2974" SETUP (no stream) "isRemoteControlOnly" message
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:2974"   Type: "Content-Length", content: "425"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000101000 "rtsp.c:2974"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:2974"   Type: "CSeq", content: "6"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000096000 "rtsp.c:2974"   Type: "User-Agent", content: "AirPlay/620.8.2"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.004598000 "rtsp.c:2974"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>timingProtocol</key>
                                                      <string>None</string>
                                                      <key>name</key>
                                                      <string>iPhone Camera</string>
                                                      <key>isRemoteControlOnly</key>
                                                      <true/>
                                                      <key>osName</key>
                                                      <string>iPhone OS</string>
                                                      <key>sessionUUID</key>
                                                      <string>58E7A942-A431-4937-B38F-215C97066CFA</string>
                                                      <key>osBuildVersion</key>
                                                      <string>19G82</string>
                                                      <key>sourceVersion</key>
                                                      <string>620.8.2</string>
                                                      <key>osVersion</key>
                                                      <string>15.6.1</string>
                                                      <key>internalBuild</key>
                                                      <false/>
                                                      <key>deviceID</key>
                                                      <string>9C:E6:5E:15:47:A9</string>
                                                      <key>model</key>
                                                      <string>iPhone9,3</string>
                                                      <key>diagnosticsAndUsage</key>
                                                      <true/>
                                                      <key>macAddress</key>
                                                      <string>96:B6:47:15:78:AD</string>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000337000 "rtsp.c:2988" Connection 5 SETUP (RC): TCP Remote Control event port opened: 47265.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000343000 "rtsp.c:723" mutex_lock "&conns_lock".
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000151000 "common.c:1553" mutex_unlock "&conns_lock" at "rtsp.c:745".
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000394000 "rtsp.c:3257"  SETUP response
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000153000 "rtsp.c:3257"   Response Code: 200.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000121000 "rtsp.c:3257"   Type: "CSeq", content: "6"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:3257"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000099000 "rtsp.c:3257"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000192000 "rtsp.c:3257"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>eventPort</key>
                                                      <integer>47265</integer>
                                                      <key>timingPort</key>
                                                      <integer>0</integer>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000125000 "rtsp.c:5039" Connection 5 (RC): RTSP Response:
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000110000 "rtsp.c:5040"   Response Code: 200.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000100000 "rtsp.c:5040"   Type: "CSeq", content: "6"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000097000 "rtsp.c:5040"   Type: "Server", content: "AirTunes/366.0"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000098000 "rtsp.c:5040"   Type: "Content-Type", content: "application/x-apple-binary-plist"
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000186000 "rtsp.c:5040"   Content Plist (as XML):
                                              --
                                              <?xml version="1.0" encoding="UTF-8"?>
                                              <!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
                                              <plist version="1.0">
                                              <dict>
                                                      <key>eventPort</key>
                                                      <integer>47265</integer>
                                                      <key>timingPort</key>
                                                      <integer>0</integer>
                                              </dict>
                                              </plist>
                                              --
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000140000 "rtsp.c:1455" Responding with content of length 76
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.007337000 "rtp.c:1577" Connection 5 (RC): AP2 Event Receiver started
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000334000 "rtsp.c:899" msg_free freed message 70
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000157000 "rtsp.c:899" msg_free freed message 69
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.005207000 "rtsp.c:1268" Connection 5: -- connection closed.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000211000 "rtsp.c:5114" Connection 5: Terminate RTSP connection.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000118000 "rtsp.c:4825" Connection 5: rtsp_conversation_thread_func_cleanup_function called.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000104000 "rtsp.c:2545" Connection 5: TEARDOWN a Remote Control stream connection.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000195000 "rtsp.c:2555" Connection 5: TEARDOWN Close Data Socket.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000122000 "rtsp.c:2563" Connection 5: TEARDOWN Delete Event Thread.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000381000 "rtp.c:1571" Connection 5: AP2 Event Receiver Cleanup.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000546000 "rtsp.c:2569" Connection 5: TEARDOWN Close Event Socket.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000263000 "rtsp.c:4839" Connection 5 terminating:Closing timing, control and audio sockets...
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000140000 "rtsp.c:4852" Connection 5 terminating: closing fd 9.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000676000 "rtsp.c:4854" Connection 5 terminating: closed fd 9.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000177000 "rtsp.c:4856" Connection 5: terminating connection from fe80::c21:2e8a:df61:99b2:49191 to self at ::12f7:a304:eb73:409d:7000.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000151000 "rtsp.c:4905" Cancel watchdog thread.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000436000 "rtsp.c:641" Connection 5: Watchdog Exit.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.002533000 "rtsp.c:4907" Join watchdog thread.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000204000 "rtsp.c:4909" Delete watchdog mutex.
Aug 26 21:43:47 audiopi shairport-sync[2042]:          0.000106000 "rtsp.c:4915" Connection 5: Closed.

Version?

4.1-dev-515-g3354f66c-AirPlay2-OpenSSL-Avahi-ALSA-soxr-sysconfdir:/etc

Check previous issues

mikebrady commented 2 years ago

Thanks for the post. Verbosity of 3 is too much -- a verbosity of 1 or 2 is fine, thanks.

It it possible that you were alternating the AirPlay 1 and AirPlay 2 versions on the same machine within a short time of each other? I know that clients such as the Music app get confused by this -- it seems to take a good few minutes to settle down.

If you enable statistics and a verbosity of 1, you should see if/when a connection is made to Shairport Sync, something like this:

Aug 27 11:51:03 ubuntu2004 shairport-sync[867]:          2.981795376 "rtsp.c:3154" Connection 3. AP2 Buffered Audio Stream.
Aug 27 11:51:04 ubuntu2004 shairport-sync[867]:          1.011642876 "player.c:2652" Connection 3: Playback Started -- AirPlay 2 Buffered.
Aug 27 11:51:12 ubuntu2004 shairport-sync[867]:          7.892937253 "player.c:2489" Sync Error ms | Net Sync PPM | All Sync PPM | Min DAC Queue | Min Buffer Size | Output FPS (r) | Output FPS (c)
Aug 27 11:51:12 ubuntu2004 shairport-sync[867]:          0.000096875 "player.c:2489"         -5.32            0.0            0.0            5668              125k              N/A              N/A
...

It may also be an AP2 Realtime Stream, beginning like this:

Aug 27 11:53:03 ubuntu2004 shairport-sync[867]:          0.050228958 "rtsp.c:3100" Connection 4. AP2 Realtime Audio Stream.
Aug 27 11:53:04 ubuntu2004 shairport-sync[867]:          0.664477042 "rtsp.c:3226" Connection 5 SETUP (RC): TCP Remote Control data port opened: 44191.
Aug 27 11:53:05 ubuntu2004 shairport-sync[867]:          1.315551543 "player.c:2649" Connection 4: Playback Started -- AirPlay 2 Realtime.
Aug 27 11:53:13 ubuntu2004 shairport-sync[867]:          1.073949334 "player.c:2489" Sync Error ms | Net Sync PPM | All Sync PPM | Missing |   Late | Too Late | Resend Reqs | Min DAC Queue | Min Buffers | Max Buffers | Received FPS | Output FPS (r) | Output FPS (c)
...
danielgoodell commented 2 years ago

So I just tried again with a fresh install of raspbian lite on a completely difference device, a raspberry pi 2.

I built exactly per the instructions, and then started it with "shairport-sync -v --statistics"

Then, I connected to it from an iPhone. It connected with no problem and I played some music with no problem.

Then, I disconnected the phone from the shairport-sync, waited a moment, and then tried to reconnect. The phone immediately says "unable to connect to audiopi2" and shairport-sync produces no additional output on the screen during this failed attempt to connect.

Here is the entire output from everything I said above: shairport-sync -v --statistics.txt .

Airplay 1 has never been on this device, nor do I even have any Airplay 1 devices afaik. So there was definitely no alternating between airplay 1 & 2 receivers in this case.

If I start it with "shairport-sync -vv --statistics" and attempt to connect to it, then the failed connection attempt log output looks like this: shairport-sync -vv --statistics.txt

For shairport-sync to display any output from a failed connection attempt, it must be started with at least -vv.

mikebrady commented 2 years ago

Thanks for your very thorough work! Let me try to make some sense of what you have found.

mikebrady commented 2 years ago

Just as a matter of interest, if you had disconnected and waited a while — a few minutes up to say 10 minutes — could you ever reconnect?

danielgoodell commented 2 years ago

Nope. I just tried reconnecting to the same one now and it still doesn't work. Stopping and restarting shairport-sync or restarting the computer seem to have no impact.

mikebrady commented 2 years ago

Stopping and restarting shairport-sync or restarting the computer seem to have no impact.

That is so weird!

mikebrady commented 2 years ago

Could you post the output of ifconfig on your Shairport Sync device, please?

I realise it is a slight security issue, in that you'd be publicising your MAC addresses, so perhaps don't publicise all of it. The component I'm most interested in is the one that is most similar to this:

::6b80:ee6c:9bb1:1ec0

It looks very odd to me, and I wonder where it's coming from.

Update: there's a similar odd-looking IP number in the first log: ::12f7:a304:eb73:409d. (Search for new connection at.)

danielgoodell commented 2 years ago

I'll be reckless and just paste complete output of ifconfig. This is from the first device I used, the raspberry pi zero w:

pi@audiopi:~ $ ifconfig
lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet 127.0.0.1  netmask 255.0.0.0
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 97  bytes 40506 (39.5 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 97  bytes 40506 (39.5 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 192.168.0.163  netmask 255.255.255.0  broadcast 192.168.0.255
        inet6 fe80::d7d7:77cd:38bb:4719  prefixlen 64  scopeid 0x20<link>
        inet6 ::12f7:a304:eb73:409d  prefixlen 64  scopeid 0x0<global>
        ether b8:27:eb:99:a0:7f  txqueuelen 1000  (Ethernet)
        RX packets 3454  bytes 436576 (426.3 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 589  bytes 138763 (135.5 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
danielgoodell commented 2 years ago

Some additional info: I just did the same thing on a Xubuntu install running in Virtualbox and it worked flawlessly. I could disconnect and reconnect multiple times.

I also tried all of this on a raspberry pi 3 and had the same problems. The problem seems to be specific to any raspberry pi or perhaps something to do with the latest Rapsbian OS. I may try an older version next.

mikebrady commented 2 years ago

Thanks. I see the strange IPv6 IP number is there. This is it:

inet6 ::12f7:a304:eb73:409d  prefixlen 64  scopeid 0x0<global>

My suspicion would fall on whatever is generating those odd IPv6 addresses, because they look illegal. Could there be a router or something that might be faulty or misconfigured?

danielgoodell commented 2 years ago

Yup, that was it! Ipv6 wasn't working right on my router, probably ever since I switched to a new internet service provider. I fixed it and now it works flawlessly. I don't think I would have figured out that was the problem. Thanks!

mikebrady commented 2 years ago

Yup, that was it! Ipv6 wasn't working right on my router, probably ever since I switched to a new internet service provider. I fixed it and now it works flawlessly. I don't think I would have figured out that was the problem. Thanks!

Excellent stuff!