Tidal Connect crashes very often, Pi 3 b+

mervinio · July 27, 2021, 9:35am

We have launched a new alsa backend for tidal connect, that could cause the issue. Can you please tell me what track you were playing and what stream quality? Thanks in advance!

dannydd · July 27, 2021, 1:09pm

Hard to say, it seems to happen when switching songs. I too have a Topping D70s and am connected USB (MQA enabled). I am unable to reproduce it now as I reverted back to 2.8

buggyglint · July 27, 2021, 2:32pm

Hard to say, it seems to happen when switching songs. I too have a Topping D70s and am connected USB (MQA enabled). I am unable to reproduce it now as I reverted back to 2.8

Yes, it would happen when switching songs in version 2.9 and up. Upon reverting to 2.882, I as well, am not having any issues. Although, I’m still able to crash it if I switch songs very rapidly.

BigManz · July 28, 2021, 2:15am

I’m having the same issue as well. Started today for me… some of my playlists wont play at all while others will play a song or two and fail. Only happens with Tidal Connect…

Hardware:
Volumio Version: 2.907
Hardware: Raspberry Pi 4 8GB
DAC: Schiit Asgard 3 w/ Multibit

Song that I tried to play when it crashed:

{“status”:“play”,“title”:“7 Years”,“artist”:“Lukas Graham”,“album”:“Lukas Graham”,“albumart”:"/albumart?sectionimage=music_service/tidalconnect/images/tidal-logo.png",“uri”:"",“trackType”:“tidal”,“seek”:7501,“duration”:237,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“repeat”:false,“repeatSingle”:false,“consume”:false,“volume”:100,“mute”:false,“disableVolumeControl”:true,“stream”:false,“updatedb”:false,“volatile”:true,“service”:“tidalconnect”}

What I saw in the logs when no sound came out and Tidal Connect went offline:

Jul 28 02:07:17 asgard vtcs[21019]: Floating point exception
Jul 28 02:07:17 asgard systemd[1]: vtcs.service: main process exited, code=exited, status=136/n/a
Jul 28 02:07:17 asgard systemd[1]: Unit vtcs.service entered failed state

root@asgard:/home/volumio# volumio endpointstest
TESTING REMOTE ENDPOINTS
https://google.com, 393 ms: OK
https://www.googleapis.com, 208 ms: OK
https://securetoken.googleapis.com, 241 ms: OK
https://myvolumio.firebaseio.com, 339 ms: OK
https://functions.volumio.cloud, 463 ms: OK
https://oauth-performer.dfs.volumio.org, 590 ms: OK
https://browsing-performer.dfs.volumio.org, 559 ms: OK
http://cddb.volumio.org, 989 ms: OK
https://functions.volumio.cloud, 486 ms: OK
http://pushupdates.volumio.org, 390 ms: OK
http://plugins.volumio.org, 717 ms: OK
https://database.volumio.cloud, 487 ms: OK
https://radio-directory.firebaseapp.com, 258 ms: OK

REMOTE ENDPOINTS TEST OK, all Endpoints are reachable

I agree with @buggyglint, fast switching of songs broke it on 2.882 but 2.907 is driving me bonkers, doesn’t seem to want to play anything I like LOL.

Please let me know if you need anything else

BigManz · July 29, 2021, 2:33pm

nudge
bump

Is anything being done about this?
I tried downgrading to an older image that I had kicking around (2.882) and I was still having issues with Tidal Connect showing up. Spotify Connect works without any issues.

Is there another issue at play here?

BigManz · July 31, 2021, 4:19pm

Are there any updates? Here are fresh logs with the beta version of Volumio installed.
logs.volumio.org/volumiobuster/gX8XJKr.html
3.080 is what I’m running on the Pi4 8GB w/ Schiit Asgard w/ Multibit DAC connected via USB

dvo · July 31, 2021, 4:34pm

3.080 has a defect so should not be used next week there will be a new release.

BigManz · July 31, 2021, 5:06pm

Thanks @dvo
Is the defect specific to Tidal?

dvo · July 31, 2021, 5:07pm

3.080 does not work properly. A bug in audio output pipe results on no sound in most of cases or strange behaviour. i wanted to switch to 3.080 and asked if a other fault was still present in it and heard this.

BigManz · July 31, 2021, 5:16pm

Thanks for the details. I’ve been having issues with Tidal Connect for awhile now even on 2.907 so that’s why I tried 3.080. Guess I’ll just keep waiting lol

dvo · July 31, 2021, 5:18pm

we are trying to get all back in order but the switch to 3.xx is a lot of work that’s why we are still in beta. filtering all the quircks and bugs out of it.

BigManz · July 31, 2021, 5:21pm

I understand that
Just sad that its appears broken in 2.907 as well which is supposed to be stable. Using Tidal via Volumio works no issue, but I don’t have access to all the same playlists like I do in the app… so I’m missing a working Tidal Connect. Plus the playlists in general on Volumio for Tidal is just buggy.

Anyway I can help… always happy to do so.

dvo · July 31, 2021, 5:28pm

for now we have to wait for the new release i hope in time that more are back from vacation,
still a few weeks to go.

BigManz · August 1, 2021, 4:54pm

Downgraded to 2.882, at least I can play Tidal using Tidal connect for hours without an issue.
(My tracks / playlists are still messed, but Tidal Connect is more stable) I’ll wait until everyone comes back from vacay and help then I downgraded my subscription until I can get it stable on one device.

dvo · August 1, 2021, 8:27pm

Email to techsupport@volumio.org for help requests maybe they can shine a light on the problems. @DED

BigManz · August 5, 2021, 7:56pm

Thanks @dvo
Support didn’t do much, and I passed them these threads as well. @volumio maybe you’ll take a look… I’m happy to debug

I ran wireshark and I could see Spotify Connect advertising and replying to all mdns requests. However the tidal packet doesn’t seem right, and needs a kick in the butt to advertise itself. (Start and stop the service while in the Tidal app looking for devices)

6397	57.600263	192.168.1.92	224.0.0.251	MDNS	289	Standard query response 0x0000 PTR asgard._spotify-connect._tcp.local SRV 0 0 45739 asgard.local TXT A 192.168.1.92
1728	64.353122	192.168.1.92	224.0.0.251	MDNS	289	Standard query response 0x0000 PTR asgard._spotify-connect._tcp.local SRV 0 0 45739 asgard.local TXT A 192.168.1.92


1424	59.634103	192.168.1.92	224.0.0.251	MDNS	292	Standard query response 0x0000 TXT, cache flush PTR Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local SRV, cache flush 0 0 2019 asgard.local A, cache flush 192.168.1.92 PTR _tidalconnect._tcp.local
1387	58.403626	192.168.1.92	224.0.0.251	MDNS	231	Standard query 0x0000 ANY Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local, "QM" question SRV 0 0 2019 asgard.local TXT

BigManz · August 5, 2021, 11:57pm

Figured since I was playing around with pcaps that I would take a look on the raspberry pi itself and see what mDNS traffic is flowing out of the box. So when any client opens spotify you’ll see the mdns traffic flowing from the volumio raspberry pi. However with tidal connect its only when the service starts does it do any sort of broadcasting. Aside from that you’ll never see it again. This points to the problem being on the volumio side and not the network. Since I can see traffic from the one service over mdns and not from the other. I can even see my chromecasts hitting my pi

19:46:56.488289 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 5/0/0 PTR _tidalconnect._tcp.local., PTR Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local., (Cache flush) SRV asgard.local.:2019 0 0, (Cache flush) A 192.168.1.92, (Cache flush) TXT "mn=Volumio" "ca=1" "id=c27afdfa9e827e4d2973ad2e5f2dfd96" "fn=asgard" "ve=1" (250)
19:47:50.312738 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0 [2n] ANY (QM)? Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local. (189)
19:47:50.563486 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0 [2n] ANY (QM)? Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local. (189)
19:47:50.814237 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0 [2n] ANY (QM)? Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local. (189)
19:47:51.015178 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 5/0/0 (Cache flush) TXT "mn=Volumio" "ca=1" "id=c27afdfa9e827e4d2973ad2e5f2dfd96" "fn=asgard" "ve=1", PTR Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local., (Cache flush) SRV asgard.local.:2019 0 0, (Cache flush) A 192.168.1.92, PTR _tidalconnect._tcp.local. (250)
19:47:52.177357 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 5/0/0 (Cache flush) TXT "mn=Volumio" "ca=1" "id=c27afdfa9e827e4d2973ad2e5f2dfd96" "fn=asgard" "ve=1", PTR Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local., (Cache flush) SRV asgard.local.:2019 0 0, (Cache flush) A 192.168.1.92, PTR _tidalconnect._tcp.local. (250)
19:47:54.341147 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 5/0/0 (Cache flush) TXT "mn=Volumio" "ca=1" "id=c27afdfa9e827e4d2973ad2e5f2dfd96" "fn=asgard" "ve=1", PTR Volumio-c27afdfa9e827e4d2973ad2e5f2dfd96._tidalconnect._tcp.local., (Cache flush) SRV asgard.local.:2019 0 0, (Cache flush) A 192.168.1.92, PTR _tidalconnect._tcp.local. (250)

Compared to me opening Spotify, and you’ll see the Spotify Connect client letting everyone know its there.

> 19:53:38.936442 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 1/0/0 (Cache flush) A 192.168.1.92 (40)
> 19:53:40.936422 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 4/0/0 PTR asgard._spotify-connect._tcp.local., SRV asgard.local.:41657 0 0, TXT "VERSION=1.0" "CPath=/", A 192.168.1.92 (247)
> 19:53:40.936796 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 1/0/0 (Cache flush) A 192.168.1.92 (40)
> 19:53:42.936217 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 4/0/0 PTR asgard._spotify-connect._tcp.local., SRV asgard.local.:41657 0 0, TXT "VERSION=1.0" "CPath=/", A 192.168.1.92 (247)
> 19:53:42.936472 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 1/0/0 (Cache flush) A 192.168.1.92 (40)
> 19:53:44.935423 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 4/0/0 PTR asgard._spotify-connect._tcp.local., SRV asgard.local.:41657 0 0, TXT "VERSION=1.0" "CPath=/", A 192.168.1.92 (247)
> 19:53:44.935698 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 1/0/0 (Cache flush) A 192.168.1.92 (40)
> 19:53:46.937083 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 4/0/0 PTR asgard._spotify-connect._tcp.local., SRV asgard.local.:41657 0 0, TXT "VERSION=1.0" "CPath=/", A 192.168.1.92 (247)
> 19:53:46.937341 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 1/0/0 (Cache flush) A 192.168.1.92 (40)
> 19:53:48.950827 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 4/0/0 PTR asgard._spotify-connect._tcp.local., SRV asgard.local.:41657 0 0, TXT "VERSION=1.0" "CPath=/", A 192.168.1.92 (247)
> 19:53:48.951140 IP asgard.mydomainremoved.mdns > 224.0.0.251.mdns: 0*- [0q] 1/0/0 (Cache flush) A 192.168.1.92 (40)

Hope some of this helps…

raitech · December 26, 2021, 5:30pm

Just to cite another two threads about this, or at least related:

I’m on Volumio Premium trial just to listen Tidal Connect HiFi.

When I switch to “normal” quality on Tidal app, it plays joyfully. When a turn it to HiFi, it just stops. Volumio web interface says it’s playing, but Tidal app (on my Android phone or iPad, doesn’t matter) stalls - it doesn’t move the progress bar or hangs with a moving circle around play button.

Here is an excerpt my Live log from Volumio 3.175.

Starting Live Log...

info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioGetQueue
info: CoreStateMachine::getQueue
info: CorePlayQueue::getQueue
info: CoreCommandRouter::executeOnPlugin: system , getHwuuid
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: Currently active: mpd
info: Stopping currently active service
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined

info: TidalConnect Active
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: Currently active: mpd
info: Setting Volatile state to tidalconnect
info: CoreStateMachine::setConsumeUpdateService undefined
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:35:43.316] [tisoc] [warning] [PlaybackControllerImpl.cpp:472] Illegal state:1
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
Under-voltage detected! (0x00050005)
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:35:44.109] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
VTCS: PCM: volumioMultiRoomServer RATE: 44100 FORMAT: S16_LE CHANNELS: 2 PERIODSIZE: 4096 BUFFERSIZE: 32768
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Executing endpoint metavolumio
info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
info: Executing endpoint metavolumio
info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
info: Executing endpoint metavolumio
info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Voltage normalised (0x00000000)
Connection to us1.myvolumio.org closed by remote host.
ssh exited with error status 255; restarting ssh
starting ssh (count 7)
ssh child pid is 15033
ssh: connect to host us1.myvolumio.org port 2222: Connection refused
ssh exited with error status 255; restarting ssh
starting ssh (count 8)
ssh child pid is 15034
ssh: connect to host us1.myvolumio.org port 2222: Connection refused
ssh exited with error status 255; restarting ssh
starting ssh (count 9)
ssh child pid is 15035
Warning: Permanently added '[us1.myvolumio.org]:2222,[162.243.167.188]:2222' (RSA) to the list of known hosts.
info: CALLMETHOD: system_controller system enableSSH true
info: CoreCommandRouter::executeOnPlugin: system , enableSSH
 volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start ssh.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Starting OpenBSD Secure Shell server...
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
Server listening on 0.0.0.0 port 22.
Server listening on :: port 22.
Started OpenBSD Secure Shell server.
pam_unix(sudo:session): session closed for user root
 volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable ssh.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Reloading.
/lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed.
Starting Daily apt download activities...
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
Reloading.
Under-voltage detected! (0x00050005)
/lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
apt-daily.service: Succeeded.
Started Daily apt download activities.
Reloading.
/lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
pam_unix(sudo:session): session closed for user root
info: enable SSH service success
Voltage normalised (0x00000000)
Accepted password for volumio from XXX.YYY.ZZZ.177 port 58752 ssh2
pam_unix(sshd:session): session opened for user volumio by (uid=0)
Created slice User Slice of UID 1000.
Starting User Runtime Directory /run/user/1000...
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
New session 1 of user volumio.
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
------------------------------------ BT MESSAGE: BT STATUS: waiting
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
Started User Runtime Directory /run/user/1000.
Starting User Manager for UID 1000...
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
pam_unix(systemd-user:session): session opened for user volumio by (uid=0)
Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Listening on GnuPG network certificate management daemon.
Listening on GnuPG cryptographic agent and passphrase cache.
Reached target Paths.
Listening on GnuPG cryptographic agent (ssh-agent emulation).
mpd.socket: Failed to create listening socket ([::]:6600): Address already in use
mpd.socket: Failed to listen on sockets: Address already in use
mpd.socket: Failed with result 'resources'.
Failed to listen on mpd.socket.
Listening on Sound System.
Starting D-Bus User Message Bus Socket.
Reached target Timers.
Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Listening on D-Bus User Message Bus Socket.
Reached target Sockets.
Reached target Basic System.
Started User Manager for UID 1000.
Starting Music Player Daemon...
Started Session 1 of user volumio.
Dec 26 16:38 : exception: Failed to bind to '[::]:6600'
Dec 26 16:38 : exception: nested: Failed to bind socket: Address already in use
mpd.service: Main process exited, code=exited, status=1/FAILURE
mpd.service: Failed with result 'exit-code'.
Failed to start Music Player Daemon.
Reached target Default.
Startup finished in 1.163s.
 volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/su -
pam_unix(sudo:session): session opened for user root by volumio(uid=0)
(to root) volumio on pts/0
pam_unix(su-l:session): session opened for user root by volumio(uid=0)
[2021-12-26 16:38:55.176] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:38:55.176] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:38:55.409] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:38:55.409] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:38:55.624] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:38:55.625] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:38:55.627] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
Under-voltage detected! (0x00050005)
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Unknown command: notifyPlaybackError
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
Voltage normalised (0x00000000)
[2021-12-26 16:40:42] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:40:43.106] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
[2021-12-26 16:41:23] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:41:23.145] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
[2021-12-26 16:42:02] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:42:03.011] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
Under-voltage detected! (0x00050005)
[2021-12-26 16:42:16.870] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
VTCS: PCM: volumioMultiRoomServer RATE: 44100 FORMAT: S16_LE CHANNELS: 2 PERIODSIZE: 4096 BUFFERSIZE: 32768
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:42:19.649] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:42:19.649] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:42:20.010] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:42:20.011] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:42:20.246] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:42:20.247] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:42:20.247] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
info: Unknown command: notifyPlaybackError
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
Voltage normalised (0x00000000)
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
pam_unix(su-l:session): session closed for user root
pam_unix(sudo:session): session closed for user root
Received disconnect from XXX.YYY.ZZZ.177 port 58752:11: disconnected by user
Disconnected from user volumio XXX.YYY.ZZZ.177 port 58752
pam_unix(sshd:session): session closed for user volumio
Session 1 logged out. Waiting for processes to exit.
session-1.scope: Succeeded.
Removed session 1.
Stopping User Manager for UID 1000...
Stopped target Default.
Stopped target Basic System.
Stopped target Paths.
Stopped target Timers.
Stopped target Sockets.
gpg-agent-browser.socket: Succeeded.
Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
gpg-agent-extra.socket: Succeeded.
Closed GnuPG cryptographic agent and passphrase cache (restricted).
gpg-agent-ssh.socket: Succeeded.
Closed GnuPG cryptographic agent (ssh-agent emulation).
dirmngr.socket: Succeeded.
Closed GnuPG network certificate management daemon.
pulseaudio.socket: Succeeded.
Closed Sound System.
dbus.socket: Succeeded.
Closed D-Bus User Message Bus Socket.
------------------------------------ BT MESSAGE: BT STATUS: running
gpg-agent.socket: Succeeded.
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
Closed GnuPG cryptographic agent and passphrase cache.
Reached target Shutdown.
systemd-exit.service: Succeeded.
Started Exit the Session.
Reached target Exit the Session.
pam_unix(systemd-user:session): session closed for user volumio
user@1000.service: Succeeded.
Stopped User Manager for UID 1000.
Stopping User Runtime Directory /run/user/1000...
------------------------------------ BT MESSAGE: BT STATUS: running
BT PLUGIN MESSAGE: Playing: false
BT PLUGIN MESSAGE: VOLATILE: tidalconnect
BT PLUGIN MESSAGE: STATE:undefined
run-user-1000.mount: Succeeded.
user-runtime-dir@1000.service: Succeeded.
Stopped User Runtime Directory /run/user/1000.
Removed slice User Slice of UID 1000.
[2021-12-26 16:43:37] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:43:37.778] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:43:53.368] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:53.369] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:43:53.578] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:53.579] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:43:53.811] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:53.812] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:43:54.310] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:54.311] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
rpi_firmware_get_throttled: 1 callbacks suppressed
Under-voltage detected! (0x00050005)
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:43:55.308] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:55.310] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:43:55.600] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:55.601] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:43:55.878] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:43:55.880] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:43:55.883] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
info: Unknown command: notifyPlaybackError
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
VTCS: PCM: volumioMultiRoomServer RATE: 44100 FORMAT: S16_LE CHANNELS: 2 PERIODSIZE: 4096 BUFFERSIZE: 32768
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
rpi_firmware_get_throttled: 1 callbacks suppressed
Voltage normalised (0x00000000)
Under-voltage detected! (0x00050005)
Voltage normalised (0x00000000)
Under-voltage detected! (0x00050005)
Voltage normalised (0x00000000)
[2021-12-26 16:47:11.989] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:47:11.990] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:47:12.589] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:47:12.590] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:47:13.376] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:47:13.379] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:47:13.379] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Unknown command: notifyPlaybackError
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
[2021-12-26 16:48:42] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:48:42.957] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
[2021-12-26 16:49:58] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:49:58.924] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
[2021-12-26 16:50:37] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:50:37.945] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
[2021-12-26 16:51:17] [info] asio async_shutdown error: asio.misc:2 (End of file)
[2021-12-26 16:51:17.978] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
[2021-12-26 16:53:51] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
[2021-12-26 16:53:51] [info] asio async_shutdown error: asio.system:32 (Broken pipe)
Under-voltage detected! (0x00050005)
Voltage normalised (0x00000000)
[2021-12-26 16:58:26.571] [tisoc] [warning] [PlaybackControllerImpl.cpp:859] Not send NotifyMediaChanged(media_info is null)
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
VTCS: PCM: volumioMultiRoomServer RATE: 44100 FORMAT: S16_LE CHANNELS: 2 PERIODSIZE: 4096 BUFFERSIZE: 32768
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
Under-voltage detected! (0x00050005)
Voltage normalised (0x00000000)
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
Under-voltage detected! (0x00050005)
[2021-12-26 16:59:18.302] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:59:18.304] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:59:19.342] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:59:19.344] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:59:20.396] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 16:59:20.397] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 16:59:20.402] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
...
[2021-12-26 17:10:34.184] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 17:10:34.186] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 17:10:34.194] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data!
[2021-12-26 17:10:34.200] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data!
[2021-12-26 17:10:34.205] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data!
...
[2021-12-26 17:12:49.623] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data!
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: Pushing metadata
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[2021-12-26 17:12:50.265] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 17:12:50.269] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 17:12:50.586] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 17:12:50.588] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 17:12:50.915] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
[2021-12-26 17:12:50.916] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
[2021-12-26 17:12:50.917] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
info: Unknown command: notifyPlaybackError
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState

It’s running on a Raspberry Pi 3B+, over WiFi (tried with 2.4 and 5.8 GHz networks, same behavior). And it’s plugged into a Topping E30 DAC, via USB.

raitech · December 26, 2021, 6:02pm

Well, the problem happens without the DAC (using the not that great sounding 3.5mm jack).

Tested with just cabled network connection, and the problem stills.

Normal and High quality plays nicely, HiFi does not.

Jacob_Rodgers · December 29, 2021, 9:58pm

@raitech I am getting similar behavior with Tidal Connect, mainly the part where the Tidal app just shows a spinning circle and in the log I have the following output:

Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.151] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.151] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.301] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.302] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.415] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed:  Stream error in the HTTP/2 framing layer  -  HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.416] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response!
Dec 29 21:46:25 volumio vtcs[1024]: [2021-12-29 21:46:25.418] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached!
Dec 29 21:46:25 volumio volumio[674]: info: Unknown command: notifyPlaybackError

I see you have the same excerpt in your log.