-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-03-02 14:02:45 CET. -- Mar 02 14:01:02 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:01:02 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:1JsnraXeS2KK3dgwNR9ARf Mar 02 14:01:04 volumio volumio[879]: info: Preload queue cleared Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:0IANgBgdiyhHg0gXdN8zdW Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:6kTLaHlPyY0pJUHACBh6Sn Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:5ZHdsygHWGRxv0XIzDjwJd Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:2vQKyIH0oaQtxlDpPTr3qn Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:4fYf1ErB3P53WK1jLKof7e Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:758BC5O0q8weUpXuNp9irE Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:5N4jEy9WkdnnlJncg85biz Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:0qv3m8DjWP17NvTwiBpfm8 Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:6uDRdQUVkjtfTCmEa6Twwk Mar 02 14:01:04 volumio volumio[879]: info: Preloading song: spotify:track:4BskHUiLvu3uOrTjImOVr5 Mar 02 14:01:04 volumio volumio[879]: info: Preload queue cleared Mar 02 14:01:04 volumio volumio[879]: info: Preload queue cleared Mar 02 14:01:09 volumio volumio[879]: Searching plugin music_service/spop Mar 02 14:01:09 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 02 14:01:10 volumio volumio[879]: info: All search sources collected, pushing search results Mar 02 14:01:11 volumio volumio[879]: Searching plugin music_service/spop Mar 02 14:01:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 02 14:01:13 volumio volumio[879]: info: All search sources collected, pushing search results Mar 02 14:01:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:01:20 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:2lvSRTHGGfaBg2Q6noxK9U Mar 02 14:01:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:01:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:01:20 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:01:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:01:20 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:01:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:01:21 volumio volumio[879]: info: Preload queue cleared Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:4QjTXTltTGPDOYFwB1fuBG Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:0gUxr28CyYCcfklvFl2P7G Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:1GSRHL3aMQMVsVkd34xe2D Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:0mQ5KGJsKUxvXSME6AQuCO Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:7tR6rV0pQcD7P4sqXxNe4V Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:0kynk5ylndd2o2dDgF1xtR Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:6qpZjWW76Y3t8clocQUhfy Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:2v7buDIEeeUCvqmZBjelvT Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:5ycRcdIGidH72eUUNXkAb9 Mar 02 14:01:21 volumio volumio[879]: info: Preloading song: spotify:track:39A36CXUzGgVaZYI7ksR8j Mar 02 14:01:21 volumio volumio[879]: info: Preload queue cleared Mar 02 14:01:21 volumio volumio[879]: info: Preload queue cleared Mar 02 14:01:21 volumio volumio[879]: info: No valid Plugin REST Endpoint Mar 02 14:01:38 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:01:38 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:2ccGg6nokDZmmKrEIdb2Bl Mar 02 14:01:38 volumio systemd[1]: Starting Cleanup of Temporary Directories... Mar 02 14:01:38 volumio systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Mar 02 14:01:38 volumio systemd[1]: Started Cleanup of Temporary Directories. Mar 02 14:01:39 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'url' of undefined Mar 02 14:01:39 volumio volumio[879]: at /data/plugins/music_service/spop/index.js:2434:60 Mar 02 14:01:39 volumio volumio[879]: at runMicrotasks () Mar 02 14:01:39 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 02 14:01:39 volumio volumio[879]: (Use `node --trace-warnings ...` to show where the warning was created) Mar 02 14:01:39 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Mar 02 14:01:39 volumio volumio[879]: (node:879) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Mar 02 14:01:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:01:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:01:50 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:01:50 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:01:50 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:01:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:01:52 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:01:52 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:2ccGg6nokDZmmKrEIdb2Bl Mar 02 14:01:54 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'url' of undefined Mar 02 14:01:54 volumio volumio[879]: at /data/plugins/music_service/spop/index.js:2434:60 Mar 02 14:01:54 volumio volumio[879]: at runMicrotasks () Mar 02 14:01:54 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 02 14:01:54 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Mar 02 14:01:55 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:01:55 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:2ccGg6nokDZmmKrEIdb2Bl Mar 02 14:01:57 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'url' of undefined Mar 02 14:01:57 volumio volumio[879]: at /data/plugins/music_service/spop/index.js:2434:60 Mar 02 14:01:57 volumio volumio[879]: at runMicrotasks () Mar 02 14:01:57 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 02 14:01:57 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3) Mar 02 14:01:57 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:01:57 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:2ccGg6nokDZmmKrEIdb2Bl Mar 02 14:01:58 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'url' of undefined Mar 02 14:01:58 volumio volumio[879]: at /data/plugins/music_service/spop/index.js:2434:60 Mar 02 14:01:58 volumio volumio[879]: at runMicrotasks () Mar 02 14:01:58 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 02 14:01:58 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4) Mar 02 14:02:01 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:02:01 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:2ccGg6nokDZmmKrEIdb2Bl Mar 02 14:02:02 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'url' of undefined Mar 02 14:02:02 volumio volumio[879]: at /data/plugins/music_service/spop/index.js:2434:60 Mar 02 14:02:02 volumio volumio[879]: at runMicrotasks () Mar 02 14:02:02 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Mar 02 14:02:02 volumio volumio[879]: (node:879) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 5) Mar 02 14:02:03 volumio volumio[879]: info: CoreCommandRouter::volumioPlay Mar 02 14:02:03 volumio volumio[879]: info: CoreStateMachine::play index undefined Mar 02 14:02:03 volumio volumio[879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 14:02:03 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:03 volumio volumio[879]: info: CoreStateMachine::startPlaybackTimer Mar 02 14:02:03 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:03 volumio volumio[879]: info: [1740920523123] ControllerSpotify::clearAddPlayTrack Mar 02 14:02:03 volumio volumio[879]: info: Sending Spotify command with payload to local API: /player/play Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="loading track spotify:track:7v988mfEEq6srOAUK2cQRM (paused: false, position: 0ms)" Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=trace msg="emitting websocket event: will_play" Mar 02 14:02:03 volumio volumio[879]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","play_origin":"go-librespot"}} Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2038" Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:7v988mfEEq6srOAUK2cQRM" Mar 02 14:02:03 volumio go-librespot[1281]: time="2025-03-02T14:02:03+01:00" level=debug msg="requested aes key for file ee18c33ed6ba44d44c70138e31736b0bbf5cdad9, gid: 7v988mfEEq6srOAUK2cQRM" Mar 02 14:02:04 volumio go-librespot[1281]: time="2025-03-02T14:02:04+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1463" Mar 02 14:02:04 volumio go-librespot[1281]: time="2025-03-02T14:02:04+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 02 14:02:04 volumio go-librespot[1281]: time="2025-03-02T14:02:04+01:00" level=debug msg="fetched first chunk of 19, total size is 9801632 bytes" Mar 02 14:02:04 volumio go-librespot[1281]: time="2025-03-02T14:02:04+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Mar 02 14:02:04 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 14:02:04 volumio go-librespot[1281]: time="2025-03-02T14:02:04+01:00" level=info msg="loaded track \"Carmex\" (uri: spotify:track:7v988mfEEq6srOAUK2cQRM, paused: false, position: 0ms, duration: 285346ms)" Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=debug msg="fetched chunk 3/18, size: 524288" Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=trace msg="emitting websocket event: metadata" Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","name":"Carmex","artist_names":["KARAŚ/ROGUCKI"],"album_name":"Czułe Kontyngenty","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023e5163a2ab4f714b42aa6504","position":0,"duration":285346,"release_date":"year:2022 month:9 day:23","track_number":1,"disc_number":1}} Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=trace msg="emitting websocket event: playing" Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","play_origin":"go-librespot"}} Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: {"status":"play","service":"spop","title":"Carmex","artist":"KARAŚ/ROGUCKI","album":"Czułe Kontyngenty","albumart":"https://i.scdn.co/image/ab67616d00001e023e5163a2ab4f714b42aa6504","uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","trackType":"spotify","seek":0,"duration":285,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState Mar 02 14:02:05 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:05 volumio volumio[879]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Carmex","artist":"KARAŚ/ROGUCKI","album":"Czułe Kontyngenty","albumart":"https://i.scdn.co/image/ab67616d00001e023e5163a2ab4f714b42aa6504","uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","trackType":"spotify","seek":0,"duration":285,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:05 volumio volumio[879]: verbose: CURRENT POSITION 0 Mar 02 14:02:05 volumio volumio[879]: info: CoreStateMachine::syncState stateService play Mar 02 14:02:05 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus stop Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=debug msg="fetched chunk 2/18, size: 524288" Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: {"status":"play","service":"spop","title":"Carmex","artist":"KARAŚ/ROGUCKI","album":"Czułe Kontyngenty","albumart":"https://i.scdn.co/image/ab67616d00001e023e5163a2ab4f714b42aa6504","uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","trackType":"spotify","seek":0,"duration":285,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState Mar 02 14:02:05 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:05 volumio volumio[879]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Carmex","artist":"KARAŚ/ROGUCKI","album":"Czułe Kontyngenty","albumart":"https://i.scdn.co/image/ab67616d00001e023e5163a2ab4f714b42aa6504","uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","trackType":"spotify","seek":0,"duration":285,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:05 volumio volumio[879]: verbose: CURRENT POSITION 0 Mar 02 14:02:05 volumio volumio[879]: info: CoreStateMachine::syncState stateService play Mar 02 14:02:05 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus play Mar 02 14:02:05 volumio volumio[879]: info: Received an update from plugin. extracting info from payload Mar 02 14:02:05 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:05 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:05 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:05 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:05 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Mar 02 14:02:05 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Mar 02 14:02:05 volumio go-librespot[1281]: time="2025-03-02T14:02:05+01:00" level=debug msg="fetched chunk 1/18, size: 524288" Mar 02 14:02:15 volumio sudo[3596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 02 14:02:15 volumio sudo[3596]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 14:02:15 volumio sudo[3596]: pam_unix(sudo:session): session closed for user root Mar 02 14:02:15 volumio sudo[3598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 02 14:02:15 volumio sudo[3598]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 14:02:15 volumio sudo[3598]: pam_unix(sudo:session): session closed for user root Mar 02 14:02:15 volumio volumio[879]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 14; 22101316G Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6943.137 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 02 14:02:15 volumio sudo[3602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 02 14:02:15 volumio sudo[3602]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 14:02:15 volumio sudo[3602]: pam_unix(sudo:session): session closed for user root Mar 02 14:02:15 volumio sudo[3605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 02 14:02:15 volumio sudo[3605]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 14:02:15 volumio sudo[3605]: pam_unix(sudo:session): session closed for user root Mar 02 14:02:15 volumio volumio[879]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.92 UA: Mozilla/5.0 (Linux; Android 14; 22101316G Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6943.137 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::volumioGetVisibleSources Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:15 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::volumioGetQueue Mar 02 14:02:15 volumio volumio[879]: info: CoreStateMachine::getQueue Mar 02 14:02:15 volumio volumio[879]: info: CorePlayQueue::getQueue Mar 02 14:02:15 volumio volumio[879]: info: Listing playlists Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 02 14:02:15 volumio volumio[879]: info: Received Get System Info Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:02:15 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:15 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:15 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 02 14:02:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 02 14:02:16 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 02 14:02:17 volumio go-librespot[1281]: time="2025-03-02T14:02:17+01:00" level=debug msg="fetched chunk 4/18, size: 524288" Mar 02 14:02:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 02 14:02:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 02 14:02:17 volumio volumio[879]: info: Received Get System Info Mar 02 14:02:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:02:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:02:17 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:02:17 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:17 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:02:18 volumio volumio[879]: info: VolumeController::SetAlsaVolume76 Mar 02 14:02:18 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:18 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 70 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 76 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 02 14:02:18 volumio volumio[879]: info: Setting Spotify Volume from Volumio: 76 Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 02 14:02:18 volumio volumio[879]: info: Received Get System Info Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:02:18 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:18 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:02:18 volumio volumio[879]: info: VolumeController::SetAlsaVolume95 Mar 02 14:02:18 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:18 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 76 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 95 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 02 14:02:18 volumio volumio[879]: info: Setting Spotify Volume from Volumio: 95 Mar 02 14:02:18 volumio volumio[879]: info: VolumeController::SetAlsaVolume96 Mar 02 14:02:18 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:18 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:18 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 95 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 96 Mar 02 14:02:18 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 02 14:02:19 volumio volumio[879]: info: VolumeController::SetAlsaVolume91 Mar 02 14:02:19 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:19 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:19 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:19 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 95 Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 91 Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 02 14:02:19 volumio volumio[879]: info: Setting Spotify Volume from Volumio: 91 Mar 02 14:02:19 volumio volumio[879]: info: VolumeController::SetAlsaVolume90 Mar 02 14:02:19 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:19 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:19 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:19 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 91 Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 90 Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 02 14:02:19 volumio volumio[879]: info: VolumeController::SetAlsaVolume+ Mar 02 14:02:19 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:19 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:19 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:19 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:19 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 91 Mar 02 14:02:20 volumio volumio[879]: info: VolumeController::SetAlsaVolume+ Mar 02 14:02:20 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:20 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 91 Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 92 Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:02:20 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:20 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: SETTING SPOTIFY VOLUME 91 Mar 02 14:02:20 volumio volumio[879]: info: Sending Spotify command with payload to local API: /player/volume Mar 02 14:02:20 volumio go-librespot[1281]: time="2025-03-02T14:02:20+01:00" level=debug msg="update volume to 59636/65535" Mar 02 14:02:20 volumio go-librespot[1281]: time="2025-03-02T14:02:20+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 02 14:02:20 volumio go-librespot[1281]: time="2025-03-02T14:02:20+01:00" level=trace msg="emitting websocket event: volume" Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: received: {"type":"volume","data":{"value":91,"max":100}} Mar 02 14:02:20 volumio volumio[879]: SPOTIFY: RECEIVED SPOTIFY VOLUME 91 Mar 02 14:02:20 volumio volumio[879]: info: VolumeController::SetAlsaVolume65 Mar 02 14:02:20 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:20 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:20 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:21 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 02 14:02:21 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 91 Mar 02 14:02:21 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 65 Mar 02 14:02:21 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 02 14:02:21 volumio volumio[879]: info: Setting Spotify Volume from Volumio: 65 Mar 02 14:02:22 volumio volumio[879]: info: VolumeController::SetAlsaVolume+ Mar 02 14:02:22 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:22 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:22 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:22 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 65 Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 66 Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 02 14:02:22 volumio volumio[879]: info: VolumeController::SetAlsaVolume+ Mar 02 14:02:22 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:22 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:22 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:22 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: SETTING SPOTIFY VOLUME 65 Mar 02 14:02:22 volumio volumio[879]: info: Sending Spotify command with payload to local API: /player/volume Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: SPOTIFY VOLUME 65 Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: VOLUMIO VOLUME 67 Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 02 14:02:22 volumio volumio[879]: info: Setting Spotify Volume from Volumio: 67 Mar 02 14:02:22 volumio go-librespot[1281]: time="2025-03-02T14:02:22+01:00" level=debug msg="update volume to 42597/65535" Mar 02 14:02:22 volumio go-librespot[1281]: time="2025-03-02T14:02:22+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 02 14:02:22 volumio go-librespot[1281]: time="2025-03-02T14:02:22+01:00" level=trace msg="emitting websocket event: volume" Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: received: {"type":"volume","data":{"value":65,"max":100}} Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: RECEIVED SPOTIFY VOLUME 65 Mar 02 14:02:22 volumio volumio[879]: info: Setting Volumio Volume from Spotify: 65 Mar 02 14:02:22 volumio volumio[879]: info: VolumeController::SetAlsaVolume65 Mar 02 14:02:22 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:22 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:22 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:22 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:22 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 02 14:02:24 volumio volumio[879]: SPOTIFY: SETTING SPOTIFY VOLUME 67 Mar 02 14:02:24 volumio volumio[879]: info: Sending Spotify command with payload to local API: /player/volume Mar 02 14:02:24 volumio go-librespot[1281]: time="2025-03-02T14:02:24+01:00" level=debug msg="update volume to 43908/65535" Mar 02 14:02:24 volumio go-librespot[1281]: time="2025-03-02T14:02:24+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 02 14:02:24 volumio go-librespot[1281]: time="2025-03-02T14:02:24+01:00" level=trace msg="emitting websocket event: volume" Mar 02 14:02:24 volumio volumio[879]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Mar 02 14:02:24 volumio volumio[879]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Mar 02 14:02:24 volumio volumio[879]: info: Setting Volumio Volume from Spotify: 67 Mar 02 14:02:24 volumio volumio[879]: info: VolumeController::SetAlsaVolume67 Mar 02 14:02:24 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:24 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:24 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:24 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:24 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 Mar 02 14:02:25 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 02 14:02:26 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 02 14:02:26 volumio volumio[879]: info: In handleBrowseUri, curUri=spotify:artist:6sWTvfuMTjUrrltReAV5yJ Mar 02 14:02:28 volumio volumio[879]: info: Preload queue cleared Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:59Rb3QAeAy2OwEQfA2cSp3 Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:5F2Uo73VTPFi083dnlqX1Q Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:4mjolWWkINqUWacCDxqzty Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:7yNr4ysdPPHSwYBgPVfRyY Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:37daQfISKP6ZsFwBpEUJpM Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:7lO0oBJBFN8WQWE6qwt11y Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:51rcvpD6su5kXFaD7QQxvy Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:52NlPfCxpypKicVRGzXAcP Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:4iaWIMhVAoj93PLOGmtiMp Mar 02 14:02:28 volumio volumio[879]: info: Preloading song: spotify:track:23kMX2ZshO5ydoZ81Ew06W Mar 02 14:02:28 volumio volumio[879]: info: Preload queue cleared Mar 02 14:02:28 volumio volumio[879]: info: Preload queue cleared Mar 02 14:02:28 volumio volumio[879]: info: No valid Plugin REST Endpoint Mar 02 14:02:30 volumio volumio[879]: info: Preload queue cleared Mar 02 14:02:30 volumio volumio[879]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::ClearQueue Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::stop Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::stPlaybackTimer Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::updateTrackBlock Mar 02 14:02:30 volumio volumio[879]: info: CorePlayQueue::getTrackBlock Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:30 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:30 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:30 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::serviceStop Mar 02 14:02:30 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Mar 02 14:02:30 volumio volumio[879]: info: CoreCommandRouter::serviceStop Mar 02 14:02:30 volumio volumio[879]: info: Spotify Stop Mar 02 14:02:30 volumio volumio[879]: SPOTIFY: SPOTIFY STOP Mar 02 14:02:30 volumio volumio[879]: SPOTIFY: {"status":"play","position":0,"title":"Carmex","artist":"KARAŚ/ROGUCKI","album":"Czułe Kontyngenty","albumart":"https://i.scdn.co/image/ab67616d0000b2733e5163a2ab4f714b42aa6504","uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","trackType":"spotify","codec":"ogg","seek":18540,"duration":285,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":true,"repeatSingle":false,"consume":false,"volume":67,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Mar 02 14:02:30 volumio volumio[879]: info: Sending Spotify command to local API: /player/pause Mar 02 14:02:30 volumio volumio[879]: info: CorePlayQueue::clearPlayQueue Mar 02 14:02:30 volumio volumio[879]: info: CorePlayQueue::saveQueue Mar 02 14:02:30 volumio volumio[879]: info: CoreCommandRouter::volumioPushQueue Mar 02 14:02:30 volumio volumio[879]: info: CoreStateMachine::addQueueItems Mar 02 14:02:30 volumio volumio[879]: info: CorePlayQueue::addQueueItems Mar 02 14:02:30 volumio volumio[879]: info: Preload queue cleared Mar 02 14:02:30 volumio volumio[879]: info: Adding Item to queue: spotify:track:59Rb3QAeAy2OwEQfA2cSp3 Mar 02 14:02:30 volumio volumio[879]: info: Exploding uri spotify:track:59Rb3QAeAy2OwEQfA2cSp3 in service spop Mar 02 14:02:30 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:59Rb3QAeAy2OwEQfA2cSp3 Mar 02 14:02:30 volumio volumio[879]: info: Adding Item to queue: spotify:track:5F2Uo73VTPFi083dnlqX1Q Mar 02 14:02:30 volumio volumio[879]: info: Exploding uri spotify:track:5F2Uo73VTPFi083dnlqX1Q in service spop Mar 02 14:02:30 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:5F2Uo73VTPFi083dnlqX1Q Mar 02 14:02:30 volumio volumio[879]: info: Adding Item to queue: spotify:track:4mjolWWkINqUWacCDxqzty Mar 02 14:02:30 volumio volumio[879]: info: Exploding uri spotify:track:4mjolWWkINqUWacCDxqzty in service spop Mar 02 14:02:30 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:4mjolWWkINqUWacCDxqzty Mar 02 14:02:30 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 Mar 02 14:02:30 volumio go-librespot[1281]: time="2025-03-02T14:02:30+01:00" level=debug msg="pause track at 26124ms" Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:59Rb3QAeAy2OwEQfA2cSp3","service":"spop","name":"Ten o Tobie film","artist":"Dzem","album":"Numero Uno","type":"song","duration":263,"albumart":"https://i.scdn.co/image/ab67616d0000b2739f8f5c468c897c771877f857","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5F2Uo73VTPFi083dnlqX1Q","service":"spop","name":"Dbaj o miłość","artist":"Tadeusz Nalepa","album":"To moj blues","type":"song","duration":471,"albumart":"https://i.scdn.co/image/ab67616d0000b273209cc4f6175b3ff1ab33bfbf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4mjolWWkINqUWacCDxqzty","service":"spop","name":"Noc jak owoc","artist":"Tadeusz Nalepa","album":"Numero Uno","type":"song","duration":373,"albumart":"https://i.scdn.co/image/ab67616d0000b2739f8f5c468c897c771877f857","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: info: CoreCommandRouter::volumioPushQueue Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::saveQueue Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::updateTrackBlock Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::getTrackBlock Mar 02 14:02:31 volumio volumio[879]: info: CoreCommandRouter::volumioPlay Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::play index 2 Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::addQueueItems Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::addQueueItems Mar 02 14:02:31 volumio volumio[879]: info: Preload queue cleared Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:7yNr4ysdPPHSwYBgPVfRyY Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:7yNr4ysdPPHSwYBgPVfRyY in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:7yNr4ysdPPHSwYBgPVfRyY Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:37daQfISKP6ZsFwBpEUJpM Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:37daQfISKP6ZsFwBpEUJpM in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:37daQfISKP6ZsFwBpEUJpM Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:7lO0oBJBFN8WQWE6qwt11y Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:7lO0oBJBFN8WQWE6qwt11y in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:7lO0oBJBFN8WQWE6qwt11y Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:51rcvpD6su5kXFaD7QQxvy Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:51rcvpD6su5kXFaD7QQxvy in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:51rcvpD6su5kXFaD7QQxvy Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:52NlPfCxpypKicVRGzXAcP Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:52NlPfCxpypKicVRGzXAcP in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:52NlPfCxpypKicVRGzXAcP Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:4iaWIMhVAoj93PLOGmtiMp Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:4iaWIMhVAoj93PLOGmtiMp in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:4iaWIMhVAoj93PLOGmtiMp Mar 02 14:02:31 volumio volumio[879]: info: Adding Item to queue: spotify:track:23kMX2ZshO5ydoZ81Ew06W Mar 02 14:02:31 volumio volumio[879]: info: Exploding uri spotify:track:23kMX2ZshO5ydoZ81Ew06W in service spop Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: EXPLODING URI:spotify:track:23kMX2ZshO5ydoZ81Ew06W Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::stop Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::play index undefined Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::startPlaybackTimer Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:31 volumio volumio[879]: info: [1740920551199] ControllerSpotify::clearAddPlayTrack Mar 02 14:02:31 volumio volumio[879]: info: Sending Spotify command with payload to local API: /player/play Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="fetched chunk 5/18, size: 524288" Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=trace msg="emitting websocket event: paused" Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7v988mfEEq6srOAUK2cQRM","play_origin":"go-librespot"}} Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:31 volumio volumio[879]: info: CoreCommandRouter::servicePushState Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:31 volumio volumio[879]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:31 volumio volumio[879]: verbose: CURRENT POSITION 2 Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::syncState stateService pause Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus stop Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:31 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:31 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="loading track spotify:track:4mjolWWkINqUWacCDxqzty (paused: false, position: 0ms)" Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7yNr4ysdPPHSwYBgPVfRyY","service":"spop","name":"Naprzód czy w tył","artist":"Tadeusz Nalepa","album":"Numero Uno","type":"song","duration":318,"albumart":"https://i.scdn.co/image/ab67616d0000b2739f8f5c468c897c771877f857","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=trace msg="emitting websocket event: will_play" Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4mjolWWkINqUWacCDxqzty","play_origin":"go-librespot"}} Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7lO0oBJBFN8WQWE6qwt11y","service":"spop","name":"Nie żałuj mnie","artist":"Tadeusz Nalepa","album":"To moj blues","type":"song","duration":319,"albumart":"https://i.scdn.co/image/ab67616d0000b273209cc4f6175b3ff1ab33bfbf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:37daQfISKP6ZsFwBpEUJpM","service":"spop","name":"Zostań w moim śnie","artist":"Tadeusz Nalepa","album":"Numero Uno","type":"song","duration":285,"albumart":"https://i.scdn.co/image/ab67616d0000b2739f8f5c468c897c771877f857","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4iaWIMhVAoj93PLOGmtiMp","service":"spop","name":"Hołd","artist":"Tadeusz Nalepa","album":"To moj blues","type":"song","duration":360,"albumart":"https://i.scdn.co/image/ab67616d0000b273209cc4f6175b3ff1ab33bfbf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4mjolWWkINqUWacCDxqzty" Mar 02 14:02:31 volumio go-librespot[1281]: time="2025-03-02T14:02:31+01:00" level=debug msg="requested aes key for file 74e9217b5c2767fc28138ebd770cbacba0eecb50, gid: 4mjolWWkINqUWacCDxqzty" Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:51rcvpD6su5kXFaD7QQxvy","service":"spop","name":"Pójdziesz tylko z cieniem","artist":"Tadeusz Nalepa","album":"Numero Uno","type":"song","duration":319,"albumart":"https://i.scdn.co/image/ab67616d0000b2739f8f5c468c897c771877f857","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:23kMX2ZshO5ydoZ81Ew06W","service":"spop","name":"Zasady gry","artist":"Tadeusz Nalepa","album":"To moj blues","type":"song","duration":191,"albumart":"https://i.scdn.co/image/ab67616d0000b273209cc4f6175b3ff1ab33bfbf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:52NlPfCxpypKicVRGzXAcP","service":"spop","name":"Modlitwa (Live at Teatr Wielki w Łodzi, 1986)","artist":"Tadeusz Nalepa","album":"Live 1986","type":"song","duration":522,"albumart":"https://i.scdn.co/image/ab67616d0000b2738736a72c220106d9d07d24c1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 02 14:02:31 volumio volumio[879]: info: CoreCommandRouter::volumioPushQueue Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::saveQueue Mar 02 14:02:31 volumio volumio[879]: info: CoreStateMachine::updateTrackBlock Mar 02 14:02:31 volumio volumio[879]: info: CorePlayQueue::getTrackBlock Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=debug msg="fetched first chunk of 32, total size is 16681888 bytes" Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Mar 02 14:02:32 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=info msg="loaded track \"Noc jak owoc\" (uri: spotify:track:4mjolWWkINqUWacCDxqzty, paused: false, position: 0ms, duration: 373640ms)" Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=trace msg="emitting websocket event: metadata" Mar 02 14:02:32 volumio volumio[879]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4mjolWWkINqUWacCDxqzty","name":"Noc jak owoc","artist_names":["Tadeusz Nalepa","Grażyna Dramowicz","Dzem"],"album_name":"Numero Uno","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029f8f5c468c897c771877f857","position":0,"duration":373640,"release_date":"year:1988 month:2 day:26","track_number":2,"disc_number":1}} Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=debug msg="fetched chunk 1/31, size: 524288" Mar 02 14:02:32 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 14:02:32 volumio go-librespot[1281]: time="2025-03-02T14:02:32+01:00" level=trace msg="emitting websocket event: playing" Mar 02 14:02:32 volumio volumio[879]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4mjolWWkINqUWacCDxqzty","play_origin":"go-librespot"}} Mar 02 14:02:32 volumio volumio[879]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 14:02:32 volumio volumio[879]: SPOTIFY: {"status":"play","service":"spop","title":"Noc jak owoc","artist":"Tadeusz Nalepa, Grażyna Dramowicz, Dzem","album":"Numero Uno","albumart":"https://i.scdn.co/image/ab67616d00001e029f8f5c468c897c771877f857","uri":"spotify:track:4mjolWWkINqUWacCDxqzty","trackType":"spotify","seek":0,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:32 volumio volumio[879]: info: CoreCommandRouter::servicePushState Mar 02 14:02:32 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:32 volumio volumio[879]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Noc jak owoc","artist":"Tadeusz Nalepa, Grażyna Dramowicz, Dzem","album":"Numero Uno","albumart":"https://i.scdn.co/image/ab67616d00001e029f8f5c468c897c771877f857","uri":"spotify:track:4mjolWWkINqUWacCDxqzty","trackType":"spotify","seek":0,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:32 volumio volumio[879]: verbose: CURRENT POSITION 2 Mar 02 14:02:32 volumio volumio[879]: info: CoreStateMachine::syncState stateService play Mar 02 14:02:32 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus stop Mar 02 14:02:32 volumio volumio[879]: info: CoreCommandRouter::volumioPlay Mar 02 14:02:32 volumio volumio[879]: info: CoreStateMachine::play index undefined Mar 02 14:02:32 volumio volumio[879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 14:02:32 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:33 volumio volumio[879]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 14:02:33 volumio volumio[879]: SPOTIFY: {"status":"play","service":"spop","title":"Noc jak owoc","artist":"Tadeusz Nalepa, Grażyna Dramowicz, Dzem","album":"Numero Uno","albumart":"https://i.scdn.co/image/ab67616d00001e029f8f5c468c897c771877f857","uri":"spotify:track:4mjolWWkINqUWacCDxqzty","trackType":"spotify","seek":0,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:33 volumio go-librespot[1281]: time="2025-03-02T14:02:33+01:00" level=debug msg="fetched chunk 2/31, size: 524288" Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::servicePushState Mar 02 14:02:33 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:33 volumio volumio[879]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Noc jak owoc","artist":"Tadeusz Nalepa, Grażyna Dramowicz, Dzem","album":"Numero Uno","albumart":"https://i.scdn.co/image/ab67616d00001e029f8f5c468c897c771877f857","uri":"spotify:track:4mjolWWkINqUWacCDxqzty","trackType":"spotify","seek":0,"duration":373,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 14:02:33 volumio volumio[879]: verbose: CURRENT POSITION 2 Mar 02 14:02:33 volumio volumio[879]: info: CoreStateMachine::syncState stateService play Mar 02 14:02:33 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus play Mar 02 14:02:33 volumio volumio[879]: info: Received an update from plugin. extracting info from payload Mar 02 14:02:33 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:33 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:33 volumio volumio[879]: info: CoreStateMachine::pushState Mar 02 14:02:33 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Mar 02 14:02:33 volumio volumio[879]: SPOTIFY: RECEIVED VOLUMIO VOLUME 67 Mar 02 14:02:33 volumio go-librespot[1281]: time="2025-03-02T14:02:33+01:00" level=debug msg="fetched chunk 3/31, size: 524288" Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 02 14:02:33 volumio volumio[879]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 02 14:02:33 volumio volumio[879]: info: Received Get System Version Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 02 14:02:33 volumio volumio[879]: info: Received Get System Info Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 02 14:02:33 volumio volumio[879]: info: Discovery: Getting this device information Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Mar 02 14:02:33 volumio volumio[879]: info: CorePlayQueue::getTrack 2 Mar 02 14:02:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 02 14:02:39 volumio kernel: hwmon hwmon1: Voltage normalised Mar 02 14:02:42 volumio go-librespot[1281]: time="2025-03-02T14:02:42+01:00" level=debug msg="fetched chunk 4/31, size: 524288" Mar 02 14:02:44 volumio volumio[879]: info: ___________ PLUGINS: Run Shutdown Tasks ___________ Mar 02 14:02:44 volumio volumio[879]: info: PLUGIN onShutdown : networkfs Mar 02 14:02:44 volumio volumio[879]: info: PLUGIN onShutdown : audiophonicsonoff Mar 02 14:02:44 volumio volumio[879]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 02 14:02:44 volumio volumio[879]: TypeError: Cannot read property 'writeSync' of undefined Mar 02 14:02:44 volumio volumio[879]: at ControllerAudiophonicsOnOff.onVolumioShutdown (/data/plugins/system_controller/audiophonicsonoff/index.js:43:25) Mar 02 14:02:44 volumio volumio[879]: at PluginManager.onVolumioShutdownPlugin (/volumio/app/pluginmanager.js:638:30) Mar 02 14:02:44 volumio volumio[879]: at HashMap. (/volumio/app/pluginmanager.js:621:31) Mar 02 14:02:44 volumio volumio[879]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 02 14:02:44 volumio volumio[879]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 02 14:02:44 volumio volumio[879]: at PluginManager.onVolumioShutdown (/volumio/app/pluginmanager.js:619:20) Mar 02 14:02:44 volumio volumio[879]: at CoreCommandRouter.shutdown (/volumio/app/index.js:1332:24) Mar 02 14:02:44 volumio volumio[879]: at ControllerAudiophonicsOnOff.hardShutdownRequest (/data/plugins/system_hardware/audiophonicsonoff/index.js:209:21) Mar 02 14:02:44 volumio volumio[879]: at /data/plugins/system_hardware/audiophonicsonoff/node_modules/onoff/onoff.js:135:9 Mar 02 14:02:44 volumio volumio[879]: at Array.forEach () Mar 02 14:02:44 volumio volumio[879]: at pollerEventHandler (/data/plugins/system_hardware/audiophonicsonoff/node_modules/onoff/onoff.js:134:32) Mar 02 14:02:44 volumio volumio[879]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 02 14:02:45 volumio sudo[3721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-02 14:01 Mar 02 14:02:45 volumio sudo[3721]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"