-- Logs begin at Sat 2024-11-30 18:29:04 CET, end at Sat 2024-11-30 18:37:39 CET. -- Nov 30 18:36:00 volumio go-librespot[1481]: time="2024-11-30T18:36:00+01:00" level=debug msg="fetched chunk 24/24, size: 77968" uri="spotify:track:7m2ZeXTKhW8e4MYEIYh2pT" Nov 30 18:36:05 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:36:06 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 30 18:36:06 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 30 18:36:10 volumio volumio[682]: info: Starting Uninstall of plugin music_service - minidlna Nov 30 18:36:10 volumio volumio[682]: info: Uninstalling plugin minidlna Nov 30 18:36:10 volumio volumio[682]: info: minidlna: Stopping minidlna.service Nov 30 18:36:10 volumio sudo[2094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop minidlna.service Nov 30 18:36:10 volumio sudo[2094]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 18:36:10 volumio systemd[1]: Stopping MiniDLNA lightweight DLNA/UPnP-AV server... Nov 30 18:36:10 volumio systemd[1]: minidlna.service: Succeeded. Nov 30 18:36:10 volumio systemd[1]: Stopped MiniDLNA lightweight DLNA/UPnP-AV server. Nov 30 18:36:11 volumio sudo[2094]: pam_unix(sudo:session): session closed for user root Nov 30 18:36:11 volumio volumio[682]: info: minidlna: systemctl stop minidlna.service succeeded. Nov 30 18:36:11 volumio volumio[682]: info: Disabling plugin minidlna Nov 30 18:36:11 volumio volumio[682]: info: Checking if uninstall.sh is present Nov 30 18:36:11 volumio volumio[682]: info: Executing uninstall.sh Nov 30 18:36:11 volumio sudo[2100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/minidlna/uninstall.sh Nov 30 18:36:11 volumio sudo[2100]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 18:36:13 volumio go-librespot[1481]: time="2024-11-30T18:36:13+01:00" level=debug msg="prefetching next track" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=debug msg="selected format OGG_VORBIS_320 (e8a8fcc0f9c383037b8ead9366e65510de1d35ef)" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=debug msg="requested aes key for file e8a8fcc0f9c383037b8ead9366e65510de1d35ef, gid: 3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=debug msg="fetched first chunk of 25, total size is 13017048 bytes" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=info msg="prefetched track \"Can't Hold Us (feat. Ray Dalton)\" (duration: 258342ms)" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:14 volumio go-librespot[1481]: time="2024-11-30T18:36:14+01:00" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:26 volumio systemd[1]: Reloading. Nov 30 18:36:27 volumio systemd[1]: /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. Nov 30 18:36:28 volumio systemd[1]: serial-getty@ttyAMA0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Nov 30 18:36:28 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Nov 30 18:36:29 volumio systemd[1]: Reloading. Nov 30 18:36:30 volumio systemd[1]: /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. Nov 30 18:36:41 volumio systemd[1]: Reloading. Nov 30 18:36:41 volumio go-librespot[1481]: time="2024-11-30T18:36:41+01:00" level=trace msg="emitting websocket event: not_playing" Nov 30 18:36:41 volumio go-librespot[1481]: time="2024-11-30T18:36:41+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:41 volumio volumio[682]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:7m2ZeXTKhW8e4MYEIYh2pT","play_origin":"collection-songs"}} Nov 30 18:36:42 volumio volumio[682]: error: Failed to decode event: not_playing Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:7m2ZeXTKhW8e4MYEIYh2pT","play_origin":"collection-songs"}} Nov 30 18:36:42 volumio volumio[682]: error: Failed to decode event: not_playing Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=trace msg="emitting websocket event: will_play" Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","play_origin":"collection-songs"}} Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","play_origin":"collection-songs"}} Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=info msg="loaded track \"Can't Hold Us (feat. Ray Dalton)\" (paused: false, position: 0ms, duration: 258342ms, prefetched: true)" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=trace msg="scheduling prefetch in 227s" Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=trace msg="emitting websocket event: metadata" Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","name":"Can't Hold Us (feat. Ray Dalton)","artist_names":["Macklemore","Ryan Lewis","Macklemore \u0026 Ryan Lewis","Ray Dalton"],"album_name":"The Heist","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0298a02fef3a8b1d80a0f164ec","position":0,"duration":258342,"release_date":"year:2012 month:10 day:9","track_number":2,"disc_number":1}} Nov 30 18:36:42 volumio systemd[1]: /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. Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 18:36:42 volumio go-librespot[1481]: time="2024-11-30T18:36:42+01:00" level=trace msg="emitting websocket event: playing" Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","play_origin":"collection-songs"}} Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Can't Hold Us (feat. Ray Dalton)","artist":"Macklemore, Ryan Lewis, Macklemore & Ryan Lewis, Ray Dalton","album":"The Heist","albumart":"https://i.scdn.co/image/ab67616d00001e0298a02fef3a8b1d80a0f164ec","uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","trackType":"spotify","seek":0,"duration":258,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:36:42 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","play_origin":"collection-songs"}} Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Can't Hold Us (feat. Ray Dalton)","artist":"Macklemore, Ryan Lewis, Macklemore & Ryan Lewis, Ray Dalton","album":"The Heist","albumart":"https://i.scdn.co/image/ab67616d00001e0298a02fef3a8b1d80a0f164ec","uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","trackType":"spotify","seek":0,"duration":258,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:36:42 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Can't Hold Us (feat. Ray Dalton)","artist":"Macklemore, Ryan Lewis, Macklemore & Ryan Lewis, Ray Dalton","album":"The Heist","albumart":"https://i.scdn.co/image/ab67616d00001e0298a02fef3a8b1d80a0f164ec","uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","trackType":"spotify","seek":0,"duration":258,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:36:42 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Can't Hold Us (feat. Ray Dalton)","artist":"Macklemore, Ryan Lewis, Macklemore & Ryan Lewis, Ray Dalton","album":"The Heist","albumart":"https://i.scdn.co/image/ab67616d00001e0298a02fef3a8b1d80a0f164ec","uri":"spotify:track:3bidbhpOYeV4knp8AIu8Xn","trackType":"spotify","seek":0,"duration":258,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:36:42 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:36:42 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:36:42 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:36:43 volumio systemd[1]: Reloading. Nov 30 18:36:44 volumio systemd[1]: /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. Nov 30 18:36:48 volumio systemd[1]: Reloading. Nov 30 18:36:49 volumio systemd[1]: /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. Nov 30 18:36:50 volumio go-librespot[1481]: time="2024-11-30T18:36:50+01:00" level=debug msg="fetched chunk 4/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:36:59 volumio systemd[1]: Reloading. Nov 30 18:37:00 volumio systemd[1]: /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. Nov 30 18:37:00 volumio go-librespot[1481]: time="2024-11-30T18:37:00+01:00" level=debug msg="fetched chunk 5/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:37:01 volumio sudo[2100]: pam_unix(sudo:session): session closed for user root Nov 30 18:37:01 volumio volumio[682]: info: Uninstall script completed Nov 30 18:37:01 volumio volumio[682]: info: Removing plugin minidlna from configuration Nov 30 18:37:02 volumio volumio[682]: info: Successfully removed minidlna configuration files Nov 30 18:37:02 volumio volumio[682]: info: Plugin folders cleanup Nov 30 18:37:02 volumio volumio[682]: info: Scanning into folder /volumio/app/plugins/ Nov 30 18:37:02 volumio volumio[682]: info: Scanning category audio_interface Nov 30 18:37:02 volumio volumio[682]: info: Scanning category miscellanea Nov 30 18:37:02 volumio volumio[682]: info: Scanning category music_service Nov 30 18:37:02 volumio volumio[682]: info: Scanning category plugins.json Nov 30 18:37:02 volumio volumio[682]: info: Scanning category system_controller Nov 30 18:37:02 volumio volumio[682]: info: Scanning category user_interface Nov 30 18:37:02 volumio volumio[682]: info: Scanning into folder /data/plugins/ Nov 30 18:37:02 volumio volumio[682]: info: Scanning category music_service Nov 30 18:37:02 volumio volumio[682]: info: Cleaning folder for minidlna Nov 30 18:37:02 volumio volumio[682]: info: Plugin folders cleanup completed Nov 30 18:37:03 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 30 18:37:03 volumio volumio[682]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.1","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true}] Nov 30 18:37:03 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 30 18:37:10 volumio go-librespot[1481]: time="2024-11-30T18:37:10+01:00" level=debug msg="fetched chunk 6/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:37:18 volumio volumio[682]: verbose: New Socket.io Connection to 192.168.2.81 from 192.168.2.94 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: Received Get System Info Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 18:37:18 volumio volumio[682]: info: Discovery: Getting this device information Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetVisibleSources Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 30 18:37:18 volumio volumio[682]: info: Received Get System Info Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 18:37:18 volumio volumio[682]: info: Discovery: Getting this device information Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:18 volumio volumio[682]: info: Listing playlists Nov 30 18:37:18 volumio volumio[682]: info: CoreCommandRouter::volumioGetQueue Nov 30 18:37:18 volumio volumio[682]: info: CoreStateMachine::getQueue Nov 30 18:37:18 volumio volumio[682]: info: CorePlayQueue::getQueue Nov 30 18:37:19 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 30 18:37:20 volumio go-librespot[1481]: time="2024-11-30T18:37:20+01:00" level=debug msg="fetched chunk 7/24, size: 524288" uri="spotify:track:3bidbhpOYeV4knp8AIu8Xn" Nov 30 18:37:22 volumio volumio[682]: info: CoreCommandRouter::volumioGetState Nov 30 18:37:23 volumio volumio[682]: info: CoreCommandRouter::volumioNext Nov 30 18:37:23 volumio volumio[682]: info: CoreStateMachine::next Nov 30 18:37:23 volumio volumio[682]: info: Spotify next Nov 30 18:37:23 volumio volumio[682]: info: Sending Spotify command to local API: /player/next Nov 30 18:37:23 volumio go-librespot[1481]: time="2024-11-30T18:37:23+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:23 volumio go-librespot[1481]: time="2024-11-30T18:37:23+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 18:37:23 volumio go-librespot[1481]: time="2024-11-30T18:37:23+01:00" level=trace msg="emitting websocket event: will_play" Nov 30 18:37:23 volumio volumio[682]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","play_origin":"collection-songs"}} Nov 30 18:37:23 volumio volumio[682]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","play_origin":"collection-songs"}} Nov 30 18:37:23 volumio go-librespot[1481]: time="2024-11-30T18:37:23+01:00" level=debug msg="selected format OGG_VORBIS_320 (af38b3839a4ab404f3821eecc8d9bea289afb19f)" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:23 volumio go-librespot[1481]: time="2024-11-30T18:37:23+01:00" level=debug msg="requested aes key for file af38b3839a4ab404f3821eecc8d9bea289afb19f, gid: 79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:23 volumio go-librespot[1481]: time="2024-11-30T18:37:23+01:00" level=debug msg="fetched first chunk of 22, total size is 11061380 bytes" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=info msg="loaded track \"Marble Machine\" (paused: false, position: 0ms, duration: 243782ms, prefetched: false)" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=trace msg="scheduling prefetch in 213s" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=trace msg="emitting websocket event: metadata" Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","name":"Marble Machine","artist_names":["Wintergatan"],"album_name":"Marble Machine","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0268ffb3a6ca293dba296d9410","position":0,"duration":243782,"release_date":"year:2016 month:3 day:1","track_number":1,"disc_number":1}} Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","name":"Marble Machine","artist_names":["Wintergatan"],"album_name":"Marble Machine","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0268ffb3a6ca293dba296d9410","position":0,"duration":243782,"release_date":"year:2016 month:3 day:1","track_number":1,"disc_number":1}} Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=trace msg="emitting websocket event: playing" Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","play_origin":"collection-songs"}} Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Marble Machine","artist":"Wintergatan","album":"Marble Machine","albumart":"https://i.scdn.co/image/ab67616d00001e0268ffb3a6ca293dba296d9410","uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","trackType":"spotify","seek":0,"duration":243,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:37:24 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","play_origin":"collection-songs"}} Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Marble Machine","artist":"Wintergatan","album":"Marble Machine","albumart":"https://i.scdn.co/image/ab67616d00001e0268ffb3a6ca293dba296d9410","uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","trackType":"spotify","seek":0,"duration":243,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:37:24 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:37:24 volumio go-librespot[1481]: time="2024-11-30T18:37:24+01:00" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Marble Machine","artist":"Wintergatan","album":"Marble Machine","albumart":"https://i.scdn.co/image/ab67616d00001e0268ffb3a6ca293dba296d9410","uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","trackType":"spotify","seek":1000,"duration":243,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:37:24 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: {"status":"play","service":"spop","title":"Marble Machine","artist":"Wintergatan","album":"Marble Machine","albumart":"https://i.scdn.co/image/ab67616d00001e0268ffb3a6ca293dba296d9410","uri":"spotify:track:79PEMaBeMMkeNfcF7f0iWE","trackType":"spotify","seek":1000,"duration":243,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::servicePushState Nov 30 18:37:24 volumio volumio[682]: info: CoreStateMachine::pushState Nov 30 18:37:24 volumio volumio[682]: info: CoreCommandRouter::volumioPushState Nov 30 18:37:24 volumio volumio[682]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 30 18:37:27 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 18:37:27 volumio volumio[682]: info: Preload queue cleared Nov 30 18:37:28 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 18:37:28 volumio volumio[682]: error: Error browsing0:Error: Did not get any response from server: Nov 30 18:37:28 volumio volumio[682]: error: Failed to execute browseSource: Nov 30 18:37:28 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 18:37:28 volumio volumio[682]: error: Error browsing0:Error: Did not get any response from server: Nov 30 18:37:28 volumio volumio[682]: error: Failed to execute browseSource: Nov 30 18:37:29 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 18:37:30 volumio volumio[682]: info: Preload queue cleared Nov 30 18:37:33 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 18:37:33 volumio volumio[682]: info: Preload queue cleared Nov 30 18:37:34 volumio go-librespot[1481]: time="2024-11-30T18:37:34+01:00" level=debug msg="fetched chunk 4/21, size: 524288" uri="spotify:track:79PEMaBeMMkeNfcF7f0iWE" Nov 30 18:37:37 volumio volumio[682]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 18:37:37 volumio volumio[682]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 18:37:37 volumio volumio[682]: TypeError: Cannot read property 'length' of undefined Nov 30 18:37:37 volumio volumio[682]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 30 18:37:37 volumio volumio[682]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 30 18:37:37 volumio volumio[682]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 30 18:37:37 volumio volumio[682]: at Parser.emit (events.js:315:20) Nov 30 18:37:37 volumio volumio[682]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 30 18:37:37 volumio volumio[682]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 30 18:37:37 volumio volumio[682]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 30 18:37:37 volumio volumio[682]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 30 18:37:37 volumio volumio[682]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 30 18:37:37 volumio volumio[682]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 30 18:37:37 volumio volumio[682]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 30 18:37:37 volumio volumio[682]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 30 18:37:37 volumio volumio[682]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 30 18:37:37 volumio volumio[682]: at IncomingMessage.emit (events.js:327:22) Nov 30 18:37:37 volumio volumio[682]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 30 18:37:37 volumio volumio[682]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 30 18:37:37 volumio volumio[682]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 18:37:39 volumio sudo[2444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-30 18:36 Nov 30 18:37:39 volumio sudo[2444]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"