-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sun 2025-01-12 14:07:46 CET. -- Jan 12 14:06:03 volumio go-librespot[7705]: time="2025-01-12T14:06:03+01:00" level=debug msg="fetched chunk 25/25, size: 469496" uri="spotify:track:0conQaDPOoAziwlnJSOj29" Jan 12 14:06:03 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:07 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:11 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:15 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:19 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:22 volumio go-librespot[7705]: time="2025-01-12T14:06:22+01:00" level=debug msg="prefetching next track" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:22 volumio go-librespot[7705]: time="2025-01-12T14:06:22+01:00" level=debug msg="selected format OGG_VORBIS_320 (bb0d85f8980aa3a6f2b832e1879ed2247cdc666f)" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:22 volumio go-librespot[7705]: time="2025-01-12T14:06:22+01:00" level=debug msg="requested aes key for file bb0d85f8980aa3a6f2b832e1879ed2247cdc666f, gid: 4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:26 volumio go-librespot[7705]: time="2025-01-12T14:06:26+01:00" level=debug msg="fetched first chunk of 31, total size is 15768496 bytes" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:26 volumio go-librespot[7705]: time="2025-01-12T14:06:26+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:26 volumio go-librespot[7705]: time="2025-01-12T14:06:26+01:00" level=info msg="prefetched track \"Valley Of A Thousand Thoughts\" (duration: 392254ms)" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:26 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:30 volumio go-librespot[7705]: time="2025-01-12T14:06:30+01:00" level=debug msg="fetched chunk 1/30, size: 524288" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:30 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:33 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , editShare Jan 12 14:06:33 volumio volumio[7258]: info: Share Public successfully unmounted Jan 12 14:06:33 volumio sudo[11789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.1.2:Musica /mnt/NAS/Public Jan 12 14:06:33 volumio sudo[11789]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 14:06:33 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:34 volumio go-librespot[7705]: time="2025-01-12T14:06:34+01:00" level=debug msg="fetched chunk 3/30, size: 524288" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:36 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:38 volumio go-librespot[7705]: time="2025-01-12T14:06:38+01:00" level=debug msg="fetched chunk 2/30, size: 524288" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:39 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:43 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:47 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:51 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=trace msg="emitting websocket event: not_playing" Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:0conQaDPOoAziwlnJSOj29","play_origin":"album"}} Jan 12 14:06:51 volumio volumio[7258]: error: Failed to decode event: not_playing Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:0conQaDPOoAziwlnJSOj29","play_origin":"album"}} Jan 12 14:06:51 volumio volumio[7258]: error: Failed to decode event: not_playing Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=trace msg="emitting websocket event: will_play" Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","play_origin":"album"}} Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","play_origin":"album"}} Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=info msg="loaded track \"Valley Of A Thousand Thoughts\" (paused: false, position: 0ms, duration: 392254ms, prefetched: true)" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=trace msg="scheduling prefetch in 362s" Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=trace msg="emitting websocket event: metadata" Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","name":"Valley Of A Thousand Thoughts","artist_names":["Ozric Tentacles"],"album_name":"Erpland","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f0fd9294968deae9e8f33ab3","position":0,"duration":392254,"release_date":"year:1990","track_number":9,"disc_number":1}} Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","name":"Valley Of A Thousand Thoughts","artist_names":["Ozric Tentacles"],"album_name":"Erpland","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f0fd9294968deae9e8f33ab3","position":0,"duration":392254,"release_date":"year:1990","track_number":9,"disc_number":1}} Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 14:06:51 volumio go-librespot[7705]: time="2025-01-12T14:06:51+01:00" level=trace msg="emitting websocket event: playing" Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","play_origin":"album"}} Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: PUSH STATE SPOTIFY Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: {"status":"play","service":"spop","title":"Valley Of A Thousand Thoughts","artist":"Ozric Tentacles","album":"Erpland","albumart":"https://i.scdn.co/image/ab67616d00001e02f0fd9294968deae9e8f33ab3","uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","trackType":"spotify","seek":0,"duration":392,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 12 14:06:51 volumio volumio[7258]: info: CoreCommandRouter::servicePushState Jan 12 14:06:51 volumio volumio[7258]: info: CoreStateMachine::pushState Jan 12 14:06:51 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 14:06:51 volumio volumio[7258]: info: CoreCommandRouter::volumioPushState Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","play_origin":"album"}} Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: PUSH STATE SPOTIFY Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: {"status":"play","service":"spop","title":"Valley Of A Thousand Thoughts","artist":"Ozric Tentacles","album":"Erpland","albumart":"https://i.scdn.co/image/ab67616d00001e02f0fd9294968deae9e8f33ab3","uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","trackType":"spotify","seek":0,"duration":392,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 12 14:06:51 volumio volumio[7258]: info: CoreCommandRouter::servicePushState Jan 12 14:06:51 volumio volumio[7258]: info: CoreStateMachine::pushState Jan 12 14:06:51 volumio volumio[7258]: info: CoreCommandRouter::volumioPushState Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Jan 12 14:06:51 volumio volumio[7258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Jan 12 14:06:52 volumio volumio[7258]: SPOTIFY: PUSH STATE SPOTIFY Jan 12 14:06:52 volumio volumio[7258]: SPOTIFY: {"status":"play","service":"spop","title":"Valley Of A Thousand Thoughts","artist":"Ozric Tentacles","album":"Erpland","albumart":"https://i.scdn.co/image/ab67616d00001e02f0fd9294968deae9e8f33ab3","uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","trackType":"spotify","seek":0,"duration":392,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 12 14:06:52 volumio volumio[7258]: info: CoreCommandRouter::servicePushState Jan 12 14:06:52 volumio volumio[7258]: info: CoreStateMachine::pushState Jan 12 14:06:52 volumio volumio[7258]: info: CoreCommandRouter::volumioPushState Jan 12 14:06:52 volumio volumio[7258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Jan 12 14:06:52 volumio volumio[7258]: SPOTIFY: PUSH STATE SPOTIFY Jan 12 14:06:52 volumio volumio[7258]: SPOTIFY: {"status":"play","service":"spop","title":"Valley Of A Thousand Thoughts","artist":"Ozric Tentacles","album":"Erpland","albumart":"https://i.scdn.co/image/ab67616d00001e02f0fd9294968deae9e8f33ab3","uri":"spotify:track:4YV7Ir3B8fypM9Kic7yggX","trackType":"spotify","seek":0,"duration":392,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 12 14:06:52 volumio volumio[7258]: info: CoreCommandRouter::servicePushState Jan 12 14:06:52 volumio volumio[7258]: info: CoreStateMachine::pushState Jan 12 14:06:52 volumio volumio[7258]: info: CoreCommandRouter::volumioPushState Jan 12 14:06:52 volumio volumio[7258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Jan 12 14:06:55 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:06:59 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:03 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:07 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:09 volumio go-librespot[7705]: time="2025-01-12T14:07:09+01:00" level=debug msg="fetched chunk 4/30, size: 524288" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:07:11 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:22 volumio sudo[11789]: pam_unix(sudo:session): session closed for user root Jan 12 14:07:22 volumio volumio[7258]: info: An error occurred mounting the new share. Rolling back configuration Jan 12 14:07:23 volumio go-librespot[7705]: time="2025-01-12T14:07:23+01:00" level=debug msg="fetched chunk 5/30, size: 524288" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:07:23 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 14:07:29 volumio volumio[7258]: info: Retrieving Cloud Streaming UI Jan 12 14:07:29 volumio volumio[7258]: info: Getting Tidal Cloud Configuration Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 14:07:29 volumio volumio[7258]: info: Getting Qobuz Cloud Configuration Jan 12 14:07:29 volumio volumio[7258]: info: Asking plugin for UI Config Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 14:07:29 volumio volumio[7258]: info: Getting Spotify Cloud Configuration Jan 12 14:07:29 volumio volumio[7258]: info: Asking plugin for UI Config Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 14:07:29 volumio volumio[7258]: info: Saving Spotify Acccount Jan 12 14:07:29 volumio volumio[7258]: info: Got Tidal Cloud Configuration Jan 12 14:07:29 volumio volumio[7258]: info: Got it Jan 12 14:07:29 volumio volumio[7258]: info: Got it Jan 12 14:07:29 volumio volumio[7258]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 14:07:29 volumio volumio[7258]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::volumioGetBrowseSources Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::volumioGetBrowseSources Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::volumioGetBrowseSources Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:29 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 12 14:07:34 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:36 volumio go-librespot[7705]: time="2025-01-12T14:07:36+01:00" level=debug msg="fetched chunk 6/30, size: 524288" uri="spotify:track:4YV7Ir3B8fypM9Kic7yggX" Jan 12 14:07:37 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:38 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Jan 12 14:07:39 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 12 14:07:40 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jan 12 14:07:40 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jan 12 14:07:41 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 14:07:45 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jan 12 14:07:45 volumio volumio[7258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jan 12 14:07:45 volumio volumio[7258]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 14:07:45 volumio volumio[7258]: Error: dns service error: unknown Jan 12 14:07:45 volumio volumio[7258]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Jan 12 14:07:45 volumio volumio[7258]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Jan 12 14:07:45 volumio volumio[7258]: errorCode: -65537 Jan 12 14:07:45 volumio volumio[7258]: } Jan 12 14:07:45 volumio volumio[7258]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 14:07:46 volumio sudo[11876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-12 14:06 Jan 12 14:07:46 volumio sudo[11876]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:19:36 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="43b87fbef9c19ede18711bdf23c439c5"