philippe44 / AirConnect

Use AirPlay to stream to UPnP/Sonos & Chromecast devices
Other
3.52k stars 218 forks source link

Sonos Play:1 No Longer Working with AirConnect #460

Closed emperor-norton closed 1 year ago

emperor-norton commented 1 year ago

I've been using AirConnect fine for several years (thank you!) but today suddenly no music which makes me sad. I am not very technical so I cannot parse all the notes from the terminal. Mostly I've tried turning everything on and off again, as well as downloading a newer build. Any thoughts?

[22:03:47.532976] main:1415 Starting airupnp version: v0.2.43.1 (Jan 14 2021 @ 22:18:20) [22:03:47.533841] main:1423 no config file, using defaults [22:03:47.535537] Start:1127 Binding to 192.168.1.41:49152 [22:03:47.567256] AddMRDevice:1005 [0x109301000]: adding renderer (Kitchen) [22:03:47.580478] MasterHandler:668 [0x109301000]: subscribe success [22:03:56.667278] rtsp_thread:356 got RTSP connection 11 [22:03:56.669198] handle_rtsp:404 [0x7f9dc91004a0]: challenge n7jFDFv5NrlL33HgIBFU5A== [22:03:56.673653] handle_rtsp:397 [0x7f9dc91004a0]: received ANNOUNCE

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 2

[22:03:56.677499] handle_rtsp:397 [0x7f9dc91004a0]: received SETUP [22:03:56.677741] hairtunes_init:406 [0x1092e9000]: UDP port-0 50977 [22:03:56.677761] hairtunes_init:406 [0x1092e9000]: UDP port-1 61385 [22:03:56.677776] hairtunes_init:406 [0x1092e9000]: UDP port-2 55659 [22:03:56.677796] hairtunes_init:424 [0x1092e9000]: HTTP listening port 49876

RTSP/1.0 200 OK Transport: RTP/AVP/UDP;unicast;mode=record;control_port=61385;timing_port=55659;server_port=50977 Session: DEADBEEF Audio-Jack-Status: connected; type=analog CSeq: 3

[22:03:56.678965] handle_rtsp:397 [0x7f9dc91004a0]: received RECORD [22:03:56.678984] hairtunes_record:527 [0x1092e9000]: record 0 0

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 4

[22:03:56.680297] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER [22:03:56.680376] handle_rtsp:567 [0x7f9dc91004a0]: SET PARAMETER volume -24.299999 [22:03:56.680389] CtrlSetVolume:245 [0x109301000]: uPNP volume 19 (cookie 0x0) [22:03:56.680511] HandleRAOP:376 [0x109301000]: Volume[0..100] 19:19

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 5

[22:03:56.681745] rtp_thread_func:759 [0x1092e9000]: 1st sync packet received [22:03:56.683202] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 6

[22:03:56.684057] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 7

[22:03:56.684893] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER [22:03:56.684925] handle_rtsp:584 [0x7f9dc91004a0]: received metadata artist: album:
title: As Everything Unfolds - Closure (FULL ALBUM) By. HansStudioMusic [HSM]

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 8

[22:03:56.710687] search_remote_cb:650 [0x7f9dc91004a0]: found ActiveRemote for 60F31E656248F1EF at 192.168.1.41:49600 [22:03:56.710710] rtp_thread_func:759 [0x1092e9000]: 1st sync packet received [22:03:56.711373] handle_rtsp:397 [0x7f9dc91004a0]: received FLUSH [22:03:56.711389] hairtunes_flush:497 [0x1092e9000]: FLUSH ignored as same as RECORD (22875 - 2700615211) [22:03:56.711392] hairtunes_flush:509 [0x1092e9000]: flush 22875 2700615211

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 9

[22:03:56.712127] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 10

[22:03:56.712864] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 11

[22:03:56.713590] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER [22:03:56.713605] handle_rtsp:584 [0x7f9dc91004a0]: received metadata artist: album:
title: As Everything Unfolds - Closure (FULL ALBUM) By. HansStudioMusic [HSM]

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 12

[22:03:56.741444] flac_init:220 [0x1092e9000]: Using FLAC-0 (0x7f9dc9000180) [22:03:56.741697] buffer_put_packet:643 [0x1092e9000]: fill [level:1] [W:22875 R:22875] [22:03:56.801156] AVTSetURI:91 [0x109301000]: uPNP setURI http://192.168.1.41:49876/stream.flc (cookie 0x1) [22:03:56.801357] AVTPlay:151 [0x109301000]: uPNP play (cookie 0x2) [22:03:56.838460] http_thread_func:1082 [0x1092e9000]: got HTTP connection 17 (silent frames 0) [22:03:56.840030] handle_http:1267 [0x1092e9000]: received GET HTTP/1.1 CONNECTION: close Host: 192.168.1.41:49876 ACCEPT: / USER-AGENT: Linux UPnP/1.0 Sonos/72.2-39150 (ZPS12) X-Sonos-SWGen: 2 X-Sonos-Firmware: 72.2-39150 X-Sonos-Muse-Api: 1.33.2 X-Sonos-Id-Hash: NoCT4JARL3pvfWRyWIjs1nj/eCBX7Ili2ntiE/wu92U=

[22:03:56.840088] handle_http:1313 [0x1092e9000]: responding: HTTP/1.0 200 OK Server: HairTunes Content-Type: audio/flac Connection: close

[22:03:56.840098] _buffer_get_frame:983 [0x1092e9000]: drain [level:13 gap:1619] [W:22888 R:22875] [R:0 S:0 F:0] [22:03:57.216821] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER [22:03:57.216849] handle_rtsp:584 [0x7f9dc91004a0]: received metadata artist: Hans Scene Music album:
title: As Everything Unfolds - Closure (FULL ALBUM) By. HansStudioMusic [HSM]

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 13

[22:03:57.217612] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 14

[22:03:57.224806] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 15

[22:03:57.584592] ActionHandler:530 [0x109301000]: uPNP transition [22:03:58.350137] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER [22:03:58.350166] handle_rtsp:584 [0x7f9dc91004a0]: received metadata artist: Hans Scene Music album:
title: As Everything Unfolds - Closure (FULL ALBUM) By. HansStudioMusic [HSM]

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 16

[22:03:58.350934] handle_rtsp:397 [0x7f9dc91004a0]: received SET_PARAMETER

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 17

[22:04:00.822276] buffer_put_packet:643 [0x1092e9000]: fill [level:4] [W:23387 R:23384] [22:04:00.826491] _buffer_get_frame:983 [0x1092e9000]: drain [level:1 gap:1719] [W:23388 R:23387] [R:0 S:0 F:0] [22:04:04.930815] buffer_put_packet:643 [0x1092e9000]: fill [level:1] [W:23899 R:23899] [22:04:04.937962] _buffer_get_frame:983 [0x1092e9000]: drain [level:4 gap:1695] [W:23903 R:23899] [R:0 S:0 F:0] [22:04:09.010622] buffer_put_packet:643 [0x1092e9000]: fill [level:1] [W:24411 R:24411] [22:04:09.017583] _buffer_get_frame:983 [0x1092e9000]: drain [level:1 gap:1702] [W:24412 R:24411] [R:0 S:0 F:0] [22:04:09.038872] read_line:1214 fd: 17 read error: Connection reset by peer [22:04:09.038909] http_parse:1130 cannot read method [22:04:09.038925] http_thread_func:1101 HTTP close 17 [22:04:09.038956] http_thread_func:1082 [0x1092e9000]: got HTTP connection 17 (silent frames 0) [22:04:09.039757] handle_http:1267 [0x1092e9000]: received HEAD HTTP/1.1 CONNECTION: close Host: 192.168.1.41:49876 USER-AGENT: Linux UPnP/1.0 Sonos/72.2-39150 (ZPS12) X-Sonos-SWGen: 2 X-Sonos-Firmware: 72.2-39150 X-Sonos-Muse-Api: 1.33.2 X-Sonos-Id-Hash: NoCT4JARL3pvfWRyWIjs1nj/eCBX7Ili2ntiE/wu92U=

[22:04:09.039800] handle_http:1313 [0x1092e9000]: responding: HTTP/1.0 200 OK Server: HairTunes Content-Type: audio/flac Connection: close

[22:04:09.039826] http_thread_func:1101 HTTP close 17 [22:04:09.636364] raop_notify:325 [0x7f9dc91004a0]: sending airplay remote GET /ctrl-int/1/stop HTTP/1.0 Active-Remote: 2939638900 Connection: close

<== received ==> HTTP/1.1 200 OK Date: Thu, 06 Apr 2023 05:04:09 GMT Content-Length: 0

[22:04:09.636422] ActionHandler:535 [0x109301000]: uPNP stopped [22:04:13.090529] buffer_put_packet:643 [0x1092e9000]: fill [level:511] [W:24923 R:24413] [22:04:17.170106] buffer_put_packet:643 [0x1092e9000]: fill [level:1023] [W:25435 R:24413] [22:04:19.671344] handle_rtsp:397 [0x7f9dc91004a0]: received TEARDOWN

[22:04:19.711996] AVTStop:217 [0x109301000]: uPNP stop (cookie 0x29)

RTSP/1.0 200 OK Audio-Jack-Status: connected; type=analog CSeq: 29

[22:04:19.714687] rtsp_thread:371 RTSP close 11 [22:04:24.659790] ActionHandler:535 [0x109301000]: uPNP stopped [22:04:27.008023] MasterHandler:645 [0x109301000]: Auto-renewal failed, re-subscribing [22:04:27.030460] MasterHandler:668 [0x109301000]: subscribe success


Sonos OS: S2 Version: 15.2 (build 72239150) Hardware Version: 1.20.1.6-1.2 Series ID: A200 IP Address: 192.168.1.62 WM: 1

pwt commented 1 year ago

This is due to a Sonos breaking change in 15.2. You need to switch to using WAV encoding instead of the default FLAC. It's working very well for me.

See the following in the Config file parameters section of the README:

codec <mp3[:] | flc[:0..9] | wav | pcm> : format used to send HTTP audio. FLAC is recommended but uses more CPU (pcm only available for UPnP). For example, mp3:320 for 320Kb/s MP3 encoding.

emperor-norton commented 1 year ago

That fixed it! Many thanks.