Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Playback takes several seconds before it starts #5

Open
ManuelBu96 opened this issue Sep 10, 2024 · 5 comments
Open

Playback takes several seconds before it starts #5

ManuelBu96 opened this issue Sep 10, 2024 · 5 comments

Comments

@ManuelBu96
Copy link

First of all, thank you for the tool so that I can turn my Denon receiver into a Spotify player. Unfortunately, it sometimes takes longer than 20 seconds before the music starts playing. I can't quite understand why this is happening. The server on which the Docker container is running is practically not being used.

About the setup
Denon receiver connected via Ethernet
End device connected via 5GHz WiFi

This actually happens with all songs. What do you need to be able to help me with this?
@GioF71
Copy link
Owner

GioF71 commented Sep 10, 2024

Hello, can you please post:

a) your compose file
b) some specifications about your "end device"
c) container logs

I assume you are using the upnp version of the application, is that the case?

@GioF71
Copy link
Owner

GioF71 commented Sep 10, 2024

Also, which receiver are you using?

@GioF71
Copy link
Owner

GioF71 commented Sep 10, 2024

Related to this issue on the upstream project

@ManuelBu96
Copy link
Author

ManuelBu96 commented Sep 15, 2024 •
edited
Loading

Hello, can you please post:

a) your compose file b) some specifications about your "end device" c) container logs

I assume you are using the upnp version of the application, is that the case?

Yes, of course. Sorry for the late reply, I was away on business and was only able to gather all the information today.

a.)

version: "3"

volumes:
  config:

services:
  spotconnect-upnp:
    image: giof71/spotconnect:latest
    container_name: spotconnect-upnp
    network_mode: host
    environment:
      - SPOTCONNECT_MODE=upnp
      - PUID=1000
      - PGID=1000
    volumes:
      - config:/config
    restart: unless-stopped

b.)

Denon AVR 1912

c.)

Attaching to spotconnect-upnp
spotconnect-upnp  | Ensuring user with uid:[1000] gid:[1000] exists ...
spotconnect-upnp  | Group with gid [1000] name [spotc] already exists.
spotconnect-upnp  | user with uid [1000] name [spotc] already exists.
spotconnect-upnp  | Using SpotConnect upnp version [0.9.2]
spotconnect-upnp  | VORBIS_BITRATE not set, using 320
spotconnect-upnp  | NETWORK_SELECT=
spotconnect-upnp  | ENABLE_AUTO_NETWORK=[]
spotconnect-upnp  | Automatically setting network ...
spotconnect-upnp  | Automatically setting network [Done]
spotconnect-upnp  | Command Line: [/app/bin/spotupnp-linux -r 320 -x /config/config.xml -I -j -k -Z -b 192.168.61.4]
spotconnect-upnp  | [15:32:02.308] main:1517 Starting spotupnp version: v0.9.2 (Mar  5 2024 @ 17:24:36)
spotconnect-upnp  | [15:32:02.310] Start:1222 Binding to iface [email protected]:0
spotconnect-upnp  | [15:32:02.310] Start:1236 Binding to 192.168.61.4:49152
spotconnect-upnp  | [15:32:05.537] AddMRDevice:1148 [0x7f3a78438010]: adding renderer (DENON:[AVR-1912]) with mac BBBB28C02856
spotconnect-upnp  | [15:32:05.542] MasterHandler:740 [0x7f3a78438010]: subscribe success
spotconnect-upnp  | [15:32:05.548] ProcessEvent:471 [0x7f3a78438010]: UPnP Volume local change 14:-1 (master)
spotconnect-upnp  | [15:32:06.973] ProcessEvent:471 [0x7f3a78438010]: UPnP Volume local change 13:-1 (master)
spotconnect-upnp  | [15:32:07.762] ProcessEvent:471 [0x7f3a78438010]: UPnP Volume local change 12:-1 (master)
spotconnect-upnp  | [15:32:05.549] I spotify.cpp:566: Reusable credentials mode
spotconnect-upnp  | [15:32:05.549] I spotify.cpp:581: Spotify client launched for DENON:[AVR-1912]+
spotconnect-upnp  | [15:32:05.624] D Session.cpp:67: Connecting with AP <ap-gew4.spotify.com:4070>
spotconnect-upnp  | [15:32:05.645] D PlainConnection.cpp:101: Connected to spotify server
spotconnect-upnp  | [15:32:05.681] I Session.cpp:43: Received APHello response
spotconnect-upnp  | [15:32:05.701] D Session.cpp:48: Received shannon keys
spotconnect-upnp  | [15:32:05.747] D Session.cpp:87: Authorization successful
spotconnect-upnp  | [15:32:05.748] I MercurySession.cpp:42: Received packet, command: 4
spotconnect-upnp  | [15:32:05.748] D TimeProvider.cpp:15: Time synced with spotify servers
spotconnect-upnp  | [15:32:05.748] I MercurySession.cpp:42: Received packet, command: 2
spotconnect-upnp  | [15:32:05.748] I MercurySession.cpp:42: Received packet, command: 118
spotconnect-upnp  | [15:32:05.748] D MercurySession.cpp:251: Executing Mercury Request, type SUB
spotconnect-upnp  | [15:32:05.748] I MercurySession.cpp:42: Received packet, command: 27
spotconnect-upnp  | [15:32:05.748] D MercurySession.cpp:153: Received country code DE
spotconnect-upnp  | [15:32:05.748] I MercurySession.cpp:42: Received packet, command: 80
spotconnect-upnp  | [15:32:05.749] I MercurySession.cpp:42: Received packet, command: 31
spotconnect-upnp  | [15:32:05.749] I MercurySession.cpp:42: Received packet, command: 105
spotconnect-upnp  | [15:32:05.762] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:32:05.820] I MercurySession.cpp:42: Received packet, command: 74
spotconnect-upnp  | [15:32:05.820] I MercurySession.cpp:42: Received packet, command: 179
spotconnect-upnp  | [15:32:05.820] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:05.820] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:05.820] D SpircHandler.cpp:61: Sent kMessageTypeHello!
spotconnect-upnp  | [15:32:05.848] I AccessKeyFetcher.cpp:99: Access token expired, fetching new one... 237
spotconnect-upnp  | [15:32:05.877] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:32:05.877] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:32:05.877] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:32:05.877] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:05.877] D SpircHandler.cpp:132: Notify frame
spotconnect-upnp  | [15:32:05.877] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:32:05.877] D SpircHandler.cpp:132: Notify frame
spotconnect-upnp  | [15:32:05.877] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:05.957] I AccessKeyFetcher.cpp:114: Access token sucessfully fetched
spotconnect-upnp  | [15:32:06.973] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:07.020] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:07.020] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:07.763] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:07.809] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:07.809] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:08.420] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:32:08.420] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:32:08.420] D SpircHandler.cpp:132: Notify frame
spotconnect-upnp  | [15:32:11.067] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:32:11.067] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:32:11.067] D 15:32:11.376] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:32:11.465] shadowRequest:341 [0x7f3a78438010]: spotify LOAD request
spotconnect-upnp  | [15:32:11.465] AVTSetURI:69 [0x7f3a78438010]: uPNP setURI http://192.168.61.4:48699/spotupnp.flac?id=bbbb5628c028_0 (cookie (nil))
spotconnect-upnp  | [15:32:11.465] shadowRequest:355 [0x7f3a78438010]: spotify play request
spotconnect-upnp  | [15:32:11.465] AVTPlay:123 [0x7f3a78438010]: uPNP play (cookie 0x1)
spotconnect-upnp  | ;33mSpircHandler.cpp:179: Load frame 22!
spotconnect-upnp  | [15:32:11.068] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:11.068] I TrackPlayer.cpp:98: Resetting state
spotconnect-upnp  | [15:32:11.100] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:32:11.105] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:11.105] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:11.164] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:11.164] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:11.164] I TrackQueue.cpp:162: Track name: The Emptiness Machine
spotconnect-upnp  | [15:32:11.164] I TrackQueue.cpp:163: Track duration: 190427
spotconnect-upnp  | [15:32:11.164] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:32:11.164] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:32:11.181] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:32:11.181] I TrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:32:11.182] I TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:32:11.264] I TrackQueue.cpp:305: Received CDN URL, https://audio-ak-spotify-com.akamaized.net/audio/bfc2a6eec11894b657a60025873490b2b7232e94?__token__=exp=1726500731~hmac=125729512893eac70ef62f1cca6b12c1d4ad5d3b20d6b82da4b54cc56f2d08d1
spotconnect-upnp  | [15:32:11.264] I TrackPlayer.cpp:171: Got track ID=bfc2a6eec11894b657a60025873490b2b7232e94
spotconnect-upnp  | [15:32:11.265] I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-ak-spotify-com.akamaized.net/audio/bfc2a6eec11894b657a60025873490b2b7232e94?__token__=exp=1726500731~hmac=125729512893eac70ef62f1cca6b12c1d4ad5d3b20d6b82da4b54cc56f2d08d1
spotconnect-upnp  | [15:32:11.365] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:32:11.376] I CDNAudioFile.cpp:70: Header and footer bytes received
spotconnect-upnp  | [15:32:11.376] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:11.376] I spotify.cpp:300: new track will start at 85192
spotconnect-upnp  | [15:32:11.377] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:11.377] I spotify.cpp:322: Play
spotconnect-upnp  | [15:32:11.382] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:11.382] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:11.382] I TrackQueue.cpp:162: Track name: Angels
spotconnect-upnp  | [15:32:11.382] I TrackQueue.cpp:163: Track duration: 240440
spotconnect-upnp  | [15:32:11.382] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:32:11.382] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:32:11.413] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:32:11.413] I TrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:32:11.413] I TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:32:11.464] I TrackPlayer.cpp:206: Playing
spotconnect-upnp  | [15:32:11.464] I spotify.cpp:179: trackUniqueId update  => bfc2a6eec11894b657a60025873490b2b7232e94
spotconnect-upnp  | [15:32:11.464] I spotify.cpp:248: new track id 5cf0d04b16e34ef89602aed76e3b3fcc => <The Emptiness Machine>
spotconnect-upnp  | [15:32:11.465] I HTTPstreamer.cpp:192: Bound to port 48699
spotconnect-upnp  | [15:32:11.465] I spotify.cpp:256: loading with id bbbb5628c028_0
spotconnect-upnp  | [15:32:11.472] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:11.472] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:11.472] D MercurySession.cpp:174: Received mercury pac[15:32:15.544] ActionHandler:546 [0x7f3a78438010]: uPNP transition
spotconnect-upnp  | [15:32:57.933] CtrlSetVolume:205 [0x7f3a78438010]: uPNP volume 31 (cookie 0x57)
spotconnect-upnp  | [15:32:57.933] shadowRequest:390 [0x7f3a78438010]: Volume[0..100] 31
spotconnect-upnp  | [15:33:02.873] CtrlSetVolume:205 [0x7f3a78438010]: uPNP volume 61 (cookie 0x63)
spotconnect-upnp  | [15:33:02.873] shadowRequest:390 [0x7f3a78438010]: Volume[0..100] 61
spotconnect-upnp  | [15:33:09.057] CtrlSetVolume:205 [0x7f3a78438010]: uPNP volume 40 (cookie 0x71)
spotconnect-upnp  | [15:33:09.057] shadowRequest:390 [0x7f3a78438010]: Volume[0..100] 39
spotconnect-upnp  | [15:33:11.093] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:33:11.093] AVTStop:180 [0x7f3a78438010]: uPNP stop (cookie 0x78)
spotconnect-upnp  | ket
spotconnect-upnp  | [15:32:11.472] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:11.520] I TrackQueue.cpp:305: Received CDN URL, https://audio-ak-spotify-com.akamaized.net/audio/5a48faba4b482fa2f088886a87bf60ec6c5a8a01?__token__=exp=1726500731~hmac=2622f5ac5c5dee4dad7f95d4d5b3433a8d648a37abe49cb39bc2f945d7e92752
spotconnect-upnp  | [15:32:11.620] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:32:11.638] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:11.638] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:32:11.638] I TrackQueue.cpp:162: Track name: drywall
spotconnect-upnp  | [15:32:11.638] I TrackQueue.cpp:163: Track duration: 222739
spotconnect-upnp  | [15:32:11.638] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:32:11.638] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:32:11.656] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:32:11.656] I TrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:32:11.656] I TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:32:11.757] I TrackQueue.cpp:305: Received CDN URL, https://audio-ak-spotify-com.akamaized.net/audio/b9374ad365b6f35fd2f638802ae08ba19b0d7134?__token__=exp=1726500731~hmac=208055410680f1891241deb01912cefb5b4db95c34d422144d96343e746b454f
spotconnect-upnp  | [15:32:57.932] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:32:57.933] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:32:57.933] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:32:57.971] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:32:57.971] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:02.872] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:33:02.872] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:02.873] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:02.974] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:02.974] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:09.056] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:33:09.056] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:09.057] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:09.109] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:09.109] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:11.093] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:33:11.093] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:11.093] I TrackPlayer.cpp:98: Resetting state
spotconnect-upnp  | [15:33:11.093] I spotify.cpp:340: next/prev
spotconnect-upnp  | [15:33:11.100] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:33:11.117] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:11.117] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:11.117] I TrackQueue.cpp:162: Track name: The Emptiness Machine
spotconnect-upnp  | [15:33:11.117] I TrackQueue.cpp:163: Track duration: 190427
spotconnect-upnp  | [15:33:11.117] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:33:11.117] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:33:11.131] I TrackPlayer.cpp:255: Playing done
spotconnect-upnp  | [15:33:11.135] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:33:11.135] I 15:33:11.312] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:33:11.407] shadowRequest:341 [0x7f3a78438010]: spotify LOAD request
spotconnect-upnp  | [15:33:11.407] AVTSetURI:69 [0x7f3a78438010]: uPNP setURI http://192.168.61.4:49831/spotupnp.flac?id=bbbb5628c028_1 (cookie 0x79)
spotconnect-upnp  | [15:33:11.408] shadowRequest:355 [0x7f3a78438010]: spotify play request
spotconnect-upnp  | [15:33:11.408] AVTPlay:123 [0x7f3a78438010]: uPNP play (cookie 0x7a)
spotconnect-upnp  | [15:33:14.619] ActionHandler:568 [0x7f3a78438010]: uPNP playing
spotconnect-upnp  | ;36mTrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:33:11.135] I TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:33:11.206] I TrackQueue.cpp:305: Received CDN URL, https://audio-ak-spotify-com.akamaized.net/audio/bfc2a6eec11894b657a60025873490b2b7232e94?__token__=exp=1726500791~hmac=5b6f9f51a3d927ebcb2a58a839ddf9cdea8f17ef4acadc356922a3d439dfd084
spotconnect-upnp  | [15:33:11.206] I TrackPlayer.cpp:171: Got track ID=bfc2a6eec11894b657a60025873490b2b7232e94
spotconnect-upnp  | [15:33:11.206] I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-ak-spotify-com.akamaized.net/audio/bfc2a6eec11894b657a60025873490b2b7232e94?__token__=exp=1726500791~hmac=5b6f9f51a3d927ebcb2a58a839ddf9cdea8f17ef4acadc356922a3d439dfd084
spotconnect-upnp  | [15:33:11.312] I CDNAudioFile.cpp:70: Header and footer bytes received
spotconnect-upnp  | [15:33:11.312] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:11.312] I spotify.cpp:300: new track will start at 0
spotconnect-upnp  | [15:33:11.351] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:11.351] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:11.355] I HTTPstreamer.cpp:208: HTTP streamer bbbb5628c028_0 deleted
spotconnect-upnp  | [15:33:11.357] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:11.357] I spotify.cpp:322: Play
spotconnect-upnp  | [15:33:11.393] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:11.393] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:11.404] I TrackPlayer.cpp:206: Playing
spotconnect-upnp  | [15:33:11.407] I spotify.cpp:179: trackUniqueId update  => bfc2a6eec11894b657a60025873490b2b7232e94
spotconnect-upnp  | [15:33:11.407] I spotify.cpp:248: new track id 5cf0d04b16e34ef89602aed76e3b3fcc => <The Emptiness Machine>
spotconnect-upnp  | [15:33:11.407] I HTTPstreamer.cpp:192: Bound to port 49831
spotconnect-upnp  | [15:33:11.407] I spotify.cpp:256: loading with id bbbb5628c028_1
spotconnect-upnp  | [15:33:12.524] I HTTPstreamer.cpp:562: got HTTP connection 10
spotconnect-upnp  | [15:33:12.524] I HTTPstreamer.cpp:280: HTTP received =>
spotconnect-upnp  | GET /spotupnp.flac?id=bbbb5628c028_1 HTTP/1.1
spotconnect-upnp  | Host: 192.168.61.4:49831
spotconnect-upnp  | Icy-MetaData: 1
spotconnect-upnp  | Connection: close
spotconnect-upnp  | transferMode.dlna.org: Streaming
spotconnect-upnp  | User-Agent: WinampMPEG/2.8
spotconnect-upnp  | Accept: */*
spotconnect-upnp  |
spotconnect-upnp  |
spotconnect-upnp  | [15:33:12.524] I HTTPstreamer.cpp:429: HTTP response =>
spotconnect-upnp  | HTTP/1.1 200 OK
spotconnect-upnp  | Transfer-Encoding: chunked
spotconnect-upnp  | Server: spot-connect
spotconnect-upnp  | Accept-Ranges: bytes
spotconnect-upnp  | Content-Type: audio/flac
spotconnect-upnp  | Connection: close
spotconnect-upnp  |
spotconnect-upnp  |
spotconnect-upnp  | [15:33:15.368] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:15.368] I spotify.cpp:406: started track id 5cf0d04b16e34ef89602aed76e3b3fcc => <The Emptiness Machine>
spotconnect-upnp  | [15:33:15.369] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:15.369] I spotify.cpp:491: track bbbb5628c028_1 started by URL (1)
spotconnect-upnp  | [15:33:15.369] I spotify.cpp:444: adjusting real position 0 from 0 (offset is 0)
spotconnect-upnp  | [15:33:15.369] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:15.407] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:15.407] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:15.422] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:15.422] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:15.437] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:15.437] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:23.836] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | 15:33:23.837] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:33:23.837] AVTStop:180 [0x7f3a78438010]: uPNP stop (cookie 0x94)
spotconnect-upnp  | [15:33:23.838] shadowRequest:341 [0x7f3a78438010]: spotify LOAD request
spotconnect-upnp  | [15:33:23.838] AVTSetURI:69 [0x7f3a78438010]: uPNP setURI http://192.168.61.4:49831/spotupnp.flac?id=bbbb5628c028_1 (cookie 0x95)
spotconnect-upnp  | [15:33:23.838] shadowRequest:355 [0x7f3a78438010]: spotify play request
spotconnect-upnp  | [15:33:23.838] AVTPlay:123 [0x7f3a78438010]: uPNP play (cookie 0x95)
spotconnect-upnp  | [15:33:24.378] ActionHandler:546 [0x7f3a78438010]: uPNP transition
spotconnect-upnp  | [15:33:25.630] ActionHandler:568 [0x7f3a78438010]: uPNP playing
spotconnect-upnp  | [15:33:28.594] shadowRequest:364 [0x7f3a78438010]: spotify pause request
spotconnect-upnp  | [15:33:28.594] AVTBasic:167 [0x7f3a78438010]: uPNP Pause (cookie 0xa2)
spotconnect-upnp  | [15:33:28.879] ActionHandler:572 [0x7f3a78438010]: uPNP pause
spotconnect-upnp  | [15:33:31.404] shadowRequest:355 [0x7f3a78438010]: spotify play request
spotconnect-upnp  | [15:33:31.404] AVTPlay:123 [0x7f3a78438010]: uPNP play (cookie 0xa7)
spotconnect-upnp  | [15:33:31.635] ActionHandler:568 [0x7f3a78438010]: uPNP playing
spotconnect-upnp  | [15:33:36.641] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:33:36.641] AVTStop:180 [0x7f3a78438010]: uPNP stop (cookie 0xb5)
spotconnect-upnp  | 0m[15:33:23.836] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:23.836] I TrackPlayer.cpp:107: Seeking...
spotconnect-upnp  | [15:33:23.836] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:23.837] I spotify.cpp:362: seeking from streamer bbbb5628c028_1 at 79406
spotconnect-upnp  | [15:33:23.891] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:23.892] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:24.434] I HTTPstreamer.cpp:579: HTTP close 10 (sent:0)
spotconnect-upnp  | [15:33:24.487] I HTTPstreamer.cpp:562: got HTTP connection 10
spotconnect-upnp  | [15:33:24.490] I HTTPstreamer.cpp:280: HTTP received =>
spotconnect-upnp  | GET /spotupnp.flac?id=bbbb5628c028_1 HTTP/1.1
spotconnect-upnp  | Host: 192.168.61.4:49831
spotconnect-upnp  | Icy-MetaData: 1
spotconnect-upnp  | Connection: close
spotconnect-upnp  | transferMode.dlna.org: Streaming
spotconnect-upnp  | User-Agent: WinampMPEG/2.8
spotconnect-upnp  | Accept: */*
spotconnect-upnp  |
spotconnect-upnp  |
spotconnect-upnp  | [15:33:24.490] I HTTPstreamer.cpp:429: HTTP response =>
spotconnect-upnp  | HTTP/1.1 200 OK
spotconnect-upnp  | Transfer-Encoding: chunked
spotconnect-upnp  | Server: spot-connect
spotconnect-upnp  | Accept-Ranges: bytes
spotconnect-upnp  | Content-Type: audio/flac
spotconnect-upnp  | Connection: close
spotconnect-upnp  |
spotconnect-upnp  |
spotconnect-upnp  | [15:33:26.633] I spotify.cpp:444: adjusting real position 1000 from 0 (offset is -79406)
spotconnect-upnp  | [15:33:26.633] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:26.682] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:26.682] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:28.593] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:33:28.593] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:28.593] D SpircHandler.cpp:287: External pause command
spotconnect-upnp  | [15:33:28.593] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:28.593] I spotify.cpp:322: Pause
spotconnect-upnp  | [15:33:28.632] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:28.632] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:31.403] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:33:31.403] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:31.404] D SpircHandler.cpp:290: External play command
spotconnect-upnp  | [15:33:31.404] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:31.404] I spotify.cpp:322: Play
spotconnect-upnp  | [15:33:31.503] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:31.504] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:36.641] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:33:36.641] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:33:36.641] I TrackPlayer.cpp:98: Resetting state
spotconnect-upnp  | [15:33:36.641] I spotify.cpp:340: next/prev
spotconnect-upnp  | [15:33:36.653] I TrackPlayer.cpp:255: Playing done
spotconnect-upnp  | [15:33:36.700] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:33:36.730] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:36.730] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:36.730] I TrackQueue.cpp:162: Track name: The Emptiness Machine
spotconnect-upnp  | [15:33:36.730] I TrackQueue.cpp:163: Track duration: 190427
spotconnect-upnp  | [15:33:36.730] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:33:36.730] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:33:36.747] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:33:36.747] I TrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:33:36.747] I[15:33:36.959] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:33:37.039] shadowRequest:341 [0x7f3a78438010]: spotify LOAD request
spotconnect-upnp  | [15:33:37.039] AVTSetURI:69 [0x7f3a78438010]: uPNP setURI http://192.168.61.4:35349/spotupnp.flac?id=bbbb5628c028_2 (cookie 0xb6)
spotconnect-upnp  | [15:33:37.039] shadowRequest:355 [0x7f3a78438010]: spotify play request
spotconnect-upnp  | [15:33:37.039] AVTPlay:123 [0x7f3a78438010]: uPNP play (cookie 0xb7)
spotconnect-upnp  | [15:33:37.139] ActionHandler:546 [0x7f3a78438010]: uPNP transition
spotconnect-upnp  | [15:33:38.652] ActionHandler:568 [0x7f3a78438010]: uPNP playing
spotconnect-upnp  |  TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:33:36.806] E HTTPstreamer.cpp:523: HTTP error 32 for bbbb5628c028_1 => send 5588 / 16384 (10)
spotconnect-upnp  | [15:33:36.806] I HTTPstreamer.cpp:602: early closing socket 10 (sent:1982464)
spotconnect-upnp  | [15:33:36.847] I TrackQueue.cpp:305: Received CDN URL, https://audio-ak-spotify-com.akamaized.net/audio/bfc2a6eec11894b657a60025873490b2b7232e94?__token__=exp=1726500816~hmac=5fade6e96f8c2760f25a09ddaf2bc744226a4e0a5f8fe9533de314bd37cfef1d
spotconnect-upnp  | [15:33:36.847] I TrackPlayer.cpp:171: Got track ID=bfc2a6eec11894b657a60025873490b2b7232e94
spotconnect-upnp  | [15:33:36.847] I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-ak-spotify-com.akamaized.net/audio/bfc2a6eec11894b657a60025873490b2b7232e94?__token__=exp=1726500816~hmac=5fade6e96f8c2760f25a09ddaf2bc744226a4e0a5f8fe9533de314bd37cfef1d
spotconnect-upnp  | [15:33:36.959] I CDNAudioFile.cpp:70: Header and footer bytes received
spotconnect-upnp  | [15:33:36.959] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:36.959] I spotify.cpp:300: new track will start at 0
spotconnect-upnp  | [15:33:37.002] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:37.003] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:37.006] I HTTPstreamer.cpp:208: HTTP streamer bbbb5628c028_1 deleted
spotconnect-upnp  | [15:33:37.006] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:37.006] I spotify.cpp:322: Play
spotconnect-upnp  | [15:33:37.038] I TrackPlayer.cpp:206: Playing
spotconnect-upnp  | [15:33:37.039] I spotify.cpp:179: trackUniqueId update  => bfc2a6eec11894b657a60025873490b2b7232e94
spotconnect-upnp  | [15:33:37.039] I spotify.cpp:248: new track id 5cf0d04b16e34ef89602aed76e3b3fcc => <The Emptiness Machine>
spotconnect-upnp  | [15:33:37.039] I HTTPstreamer.cpp:192: Bound to port 35349
spotconnect-upnp  | [15:33:37.039] I spotify.cpp:256: loading with id bbbb5628c028_2
spotconnect-upnp  | [15:33:37.050] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:37.050] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:37.217] I HTTPstreamer.cpp:562: got HTTP connection 10
spotconnect-upnp  | [15:33:37.218] I HTTPstreamer.cpp:280: HTTP received =>
spotconnect-upnp  | GET /spotupnp.flac?id=bbbb5628c028_2 HTTP/1.1
spotconnect-upnp  | Host: 192.168.61.4:35349
spotconnect-upnp  | Icy-MetaData: 1
spotconnect-upnp  | Connection: close
spotconnect-upnp  | transferMode.dlna.org: Streaming
spotconnect-upnp  | User-Agent: WinampMPEG/2.8
spotconnect-upnp  | Accept: */*
spotconnect-upnp  |
spotconnect-upnp  |
spotconnect-upnp  | [15:33:37.218] I HTTPstreamer.cpp:429: HTTP response =>
spotconnect-upnp  | HTTP/1.1 200 OK
spotconnect-upnp  | Transfer-Encoding: chunked
spotconnect-upnp  | Server: spot-connect
spotconnect-upnp  | Accept-Ranges: bytes
spotconnect-upnp  | Content-Type: audio/flac
spotconnect-upnp  | Connection: close
spotconnect-upnp  |
spotconnect-upnp  |
spotconnect-upnp  | [15:33:39.640] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:39.641] I spotify.cpp:406: started track id 5cf0d04b16e34ef89602aed76e3b3fcc => <The Emptiness Machine>
spotconnect-upnp  | [15:33:39.641] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:39.641] I spotify.cpp:491: track bbbb5628c028_2 started by URL (1)
spotconnect-upnp  | [15:33:39.641] I spotify.cpp:444: adjusting real position 1000 from 0 (offset is 0)
spotconnect-upnp  | [15:33:39.641] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:33:39.694] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:39.694] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:39.709] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:33:39.709] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:33:39.724] I MercurySession.cpp:42: Received packet, command: 178

If the song starts in the middle, I can't hear any sound. Only when I restart the song can I hear anything. Once there is sound and I jump around in the song, it works straight away and I don't have any problems.

spotconnect-upnp  | [15:41:53.763] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:41:53.763] I spotify.cpp:406: started track id 9f7cb02f3ece4a53ab64009c51e65036 => <Angels>
spotconnect-upnp  | [15:41:53.764] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:41:53.764] I spotify.cpp:491: track bbbb5628c028_9 started by URL (1)
spotconnect-upnp  | [15:41:53.764] I spotify.cpp:444: adjusting real position 0 from 0 (offset is 0)
spotconnect-upnp  | [15:41:53.764] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:41:53.821] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:41:53.821] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:41:53.835] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:41:53.836] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:41:53.851] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:41:53.851] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:41:56.760] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:41:56.760] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:41:56.760] D SpircHandler.cpp:287: External pause command
spotconnect-upnp  | [15:41:56.760] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:41:56.760] I spotify.cpp:322: Pause
spotconnect-upnp  | [15:41:56.797] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:41:56.798] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:42:04.424] I MercurySession.cpp:42: Received packet, command: 181
spotconnect-upnp  | [15:42:04.424] D SpircHandler.cpp:69: Received subscription response
spotconnect-upnp  | [15:42:04.424] D SpircHandler.cpp:179: Load frame 22!
spotconnect-upnp  | [15:42:04.424] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:42:04.425] I TrackPlayer.cpp:98: Resetting state
spotconnect-upnp  | [15:42:04.461] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:42:04.461] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:42:04.467] I TrackPlayer.cpp:255: Playing done
spotconnect-upnp  | [15:42:04.500] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:42:04.518] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:42:04.518] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:42:04.518] I TrackQueue.cpp:162: Track name: drywall
spotconnect-upnp  | [15:42:04.518] I TrackQueue.cpp:163: Track duration: 222739
spotconnect-upnp  | [15:42:04.519] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:42:04.519] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:42:04.536] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:42:04.536] I TrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:42:04.537] I TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:42:04.629] I TrackQueue.cpp:305: Received CDN URL, https://aud[15:42:04.748] shadowRequest:324 [0x7f3a78438010]: Stop
spotconnect-upnp  | [15:42:04.748] AVTStop:180 [0x7f3a78438010]: uPNP stop (cookie 0x4fd)
spotconnect-upnp  | io-ak-spotify-com.akamaized.net/audio/b9374ad365b6f35fd2f638802ae08ba19b0d7134?__token__=exp=1726501324~hmac=2f3bd22a7bf9a6ff30317046607eb0fa9b11c2815fab4935cf3359420cd220f2
spotconnect-upnp  | [15:42:04.629] I TrackPlayer.cpp:171: Got track ID=b9374ad365b6f35fd2f638802ae08ba19b0d7134
spotconnect-upnp  | [15:42:04.629] I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-ak-spotify-com.akamaized.net/audio/b9374ad365b6f35fd2f638802ae08ba19b0d7134?__token__=exp=1726501324~hmac=2f3bd22a7bf9a6ff30317046607eb0fa9b11c2815fab4935cf3359420cd220f2
spotconnect-upnp  | [15:42:04.729] D MercurySession.cpp:251: Executing Mercury Request, type GET
spotconnect-upnp  | [15:42:04.747] I MercurySession.cpp:42: Received packet, command: 178
spotconnect-upnp  | [15:42:04.747] D MercurySession.cpp:174: Received mercury packet
spotconnect-upnp  | [15:42:04.747] I TrackQueue.cpp:162: Track name: Tel Aviv
spotconnect-upnp  | [15:42:04.747] I TrackQueue.cpp:163: Track duration: 202586
spotconnect-upnp  | [15:42:04.747] D TrackQueue.cpp:165: trackInfo.restriction.size() = 1
spotconnect-upnp  | [15:42:04.747] D TrackQueue.cpp:216: File format: 2
spotconnect-upnp  | [15:42:04.747] I CDNAudioFile.cpp:70: Header and footer bytes received
spotconnect-upnp  | [15:42:04.748] D MercurySession.cpp:251: Executing Mercury Request, type SEND
spotconnect-upnp  | [15:42:04.748] I spotify.cpp:300: new track will start at 0
spotconnect-upnp  | [15:42:04.764] I MercurySession.cpp:42: Received packet, command: 13
spotconnect-upnp  | [15:42:04.764] I TrackQueue.cpp:256: Got audio key
spotconnect-upnp  | [15:42:04.764] I TrackQueue.cpp:279: Received access key, fetching CDN URL...
spotconnect-upnp  | [15:42:04.820] I MercurySession.cpp:42: Received packet, command: 178

If I also make changes to the queue, the music playback also stops.

Do you have an explanation?

@GioF71
Copy link
Owner

GioF71 commented Sep 15, 2024

Hello, I just tried to reproduce the issue, and this does not happen to me. The UPnP/DLNA player embedded in the receiver might have its quirks as the author of SpotConnect says here. After your ticket, I have tried to extend my container so that it can support almost all of the options of the upstream project, in terms of content length and transfer modes. You can probably try some of the new settings and see if you can find a solution. I don't have the same device of course so I can't help directly. Maybe the author of SpotConnect will give you some hint.

In my case spotconnect is running on mpd+upmpdcli, which is probably 'better' than the players that are embedded in a receiver like yours.
I was asking you about the device you use to run SpotConnect, because, if it is maybe a raspberry pi, you can consider adding a hat (with rca outputs or optical/coax outputs) and maybe install moode on it. You would get a mpd+upmpdcli renderer, along with librespot (implementation of SpotifyConnect), Squeezelite, etc. And you could still run SpotConnect on it with docker, should you want to do that. That would probably give you much wider flexibility than your current solution.

Cheers

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@GioF71 @ManuelBu96