-- Logs begin at Wed 2025-04-16 02:29:24 +08, end at Wed 2025-04-16 02:37:01 +08. -- Apr 16 02:36:02 volumio volumio-remote-updater[858]: [2025-04-16 02:36:02] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Apr 16 02:36:07 volumio volumio-remote-updater[858]: [2025-04-16 02:36:07] [connect] Successful connection Apr 16 02:36:11 volumio go-librespot[1758]: time="2025-04-16T02:36:11+08:00" level=trace msg="received accesspoint ping" Apr 16 02:36:11 volumio go-librespot[1758]: time="2025-04-16T02:36:11+08:00" level=trace msg="received accesspoint pong ack" Apr 16 02:36:11 volumio go-librespot[1758]: time="2025-04-16T02:36:11+08:00" level=trace msg="sent dealer ping" Apr 16 02:36:11 volumio go-librespot[1758]: time="2025-04-16T02:36:11+08:00" level=trace msg="received dealer pong" Apr 16 02:36:18 volumio volumio[1209]: info: Checking if install.sh is present Apr 16 02:36:18 volumio volumio[1209]: info: Executing install.sh Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 192.168.60.130 from 192.168.60.148 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 4 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 192.168.60.130 from 192.168.60.148 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 6 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 192.168.60.130 from 192.168.60.148 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 8 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Apr 16 02:36:18 volumio volumio[1209]: verbose: New Socket.io Connection to 192.168.60.130 from 192.168.60.148 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 10 Apr 16 02:36:18 volumio sudo[3521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/user_interface/now_playing/install.sh Apr 16 02:36:18 volumio sudo[3521]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:18 volumio volumio[1209]: Upnp client error: Error: This socket has been ended by the other party Apr 16 02:36:19 volumio volumio[1209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::volumioGetState Apr 16 02:36:19 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:19 volumio volumio[1209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Apr 16 02:36:19 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::volumioGetState Apr 16 02:36:19 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:19 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::volumioGetState Apr 16 02:36:19 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:19 volumio volumio[1209]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 02:36:19 volumio volumio[1209]: info: Listing playlists Apr 16 02:36:19 volumio volumio[1209]: info: CoreCommandRouter::volumioGetQueue Apr 16 02:36:19 volumio volumio[1209]: info: CoreStateMachine::getQueue Apr 16 02:36:19 volumio volumio[1209]: info: CorePlayQueue::getQueue Apr 16 02:36:20 volumio volumio-remote-updater[858]: [2025-04-16 02:36:20] [connect] Successful connection Apr 16 02:36:20 volumio volumio-remote-updater[858]: [2025-04-16 02:36:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744742180 101 Apr 16 02:36:20 volumio volumio[1209]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 15 Apr 16 02:36:21 volumio volumio[1209]: verbose: New Socket.io Connection to 192.168.60.130 from 192.168.60.148 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 16 Apr 16 02:36:21 volumio volumio[1209]: info: CoreCommandRouter::volumioGetState Apr 16 02:36:21 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:21 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 16 02:36:21 volumio volumio[1209]: info: CoreCommandRouter::volumioGetVisibleSources Apr 16 02:36:21 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 16 02:36:21 volumio volumio[1209]: info: Listing playlists Apr 16 02:36:21 volumio volumio[1209]: info: CoreCommandRouter::volumioGetQueue Apr 16 02:36:21 volumio volumio[1209]: info: CoreStateMachine::getQueue Apr 16 02:36:21 volumio volumio[1209]: info: CorePlayQueue::getQueue Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::volumioPause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::stPlaybackTimer Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::servicePause Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::servicePause Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::pause Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand pause Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand pause took 2 milliseconds Apr 16 02:36:29 volumio volumio[1209]: info: Apr 16 02:36:29 volumio volumio[1209]: ---------------------------- MPD announces state update: player Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::getState Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Apr 16 02:36:29 volumio volumio[1209]: info: Apr 16 02:36:29 volumio volumio[1209]: ---------------------------- MPD announces state update: player Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::getState Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Apr 16 02:36:29 volumio volumio[1209]: info: Apr 16 02:36:29 volumio volumio[1209]: ---------------------------- MPD announces state update: player Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::getState Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand status took 6 milliseconds Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::parseState Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand status took 8 milliseconds Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand status took 5 milliseconds Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::parseState Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::parseState Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::parseTrackInfo Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::pushState Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::servicePushState Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":100331,"duration":506,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"554 Kbps","isStreaming":false,"title":"02 Money for Nothing","artist":"Dire Straits","album":"Brother in Arms","uri":"USB/8C94-7B62/SPEAKER TEST SONGS/02 02 Money for Nothing.flac","trackType":"flac"} Apr 16 02:36:29 volumio volumio[1209]: verbose: CURRENT POSITION 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::syncState stateService pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::syncState currentStatus pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::stPlaybackTimer Apr 16 02:36:29 volumio volumio[1209]: info: ------------------------------ 42ms Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand playlistinfo took 32 milliseconds Apr 16 02:36:29 volumio volumio[1209]: info: sendMpdCommand playlistinfo took 31 milliseconds Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::parseTrackInfo Apr 16 02:36:29 volumio volumio[1209]: verbose: ControllerMpd::parseTrackInfo Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::pushState Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::servicePushState Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":100331,"duration":506,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"554 Kbps","isStreaming":false,"title":"02 Money for Nothing","artist":"Dire Straits","album":"Brother in Arms","uri":"USB/8C94-7B62/SPEAKER TEST SONGS/02 02 Money for Nothing.flac","trackType":"flac"} Apr 16 02:36:29 volumio volumio[1209]: verbose: CURRENT POSITION 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::syncState stateService pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::syncState currentStatus pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::stPlaybackTimer Apr 16 02:36:29 volumio volumio[1209]: info: ControllerMpd::pushState Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::servicePushState Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":100331,"duration":506,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"554 Kbps","isStreaming":false,"title":"02 Money for Nothing","artist":"Dire Straits","album":"Brother in Arms","uri":"USB/8C94-7B62/SPEAKER TEST SONGS/02 02 Money for Nothing.flac","trackType":"flac"} Apr 16 02:36:29 volumio volumio[1209]: verbose: CURRENT POSITION 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::syncState stateService pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::syncState currentStatus pause Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:29 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:29 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:29 volumio volumio[1209]: info: CoreStateMachine::stPlaybackTimer Apr 16 02:36:29 volumio volumio[1209]: info: ------------------------------ 92ms Apr 16 02:36:29 volumio volumio[1209]: info: ------------------------------ 90ms Apr 16 02:36:29 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:29 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:29 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::volumioPlay Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::play index undefined Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::startPlaybackTimer Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::resume Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand play Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand play took 39 milliseconds Apr 16 02:36:30 volumio volumio[1209]: info: Apr 16 02:36:30 volumio volumio[1209]: ---------------------------- MPD announces state update: player Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::getState Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Apr 16 02:36:30 volumio volumio[1209]: info: Apr 16 02:36:30 volumio volumio[1209]: ---------------------------- MPD announces state update: player Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::getState Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Apr 16 02:36:30 volumio volumio[1209]: info: Apr 16 02:36:30 volumio volumio[1209]: ---------------------------- MPD announces state update: player Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::getState Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand status Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand status took 6 milliseconds Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand status took 5 milliseconds Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand status took 2 milliseconds Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::parseState Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::parseState Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::parseState Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 16 02:36:30 volumio volumio[1209]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::parseTrackInfo Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::parseTrackInfo Apr 16 02:36:30 volumio volumio[1209]: verbose: ControllerMpd::parseTrackInfo Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::servicePushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: verbose: STATE SERVICE {"status":"play","position":0,"seek":100946,"duration":506,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"647 Kbps","isStreaming":false,"title":"02 Money for Nothing","artist":"Dire Straits","album":"Brother in Arms","uri":"USB/8C94-7B62/SPEAKER TEST SONGS/02 02 Money for Nothing.flac","trackType":"flac"} Apr 16 02:36:30 volumio volumio[1209]: verbose: CURRENT POSITION 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::syncState stateService play Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::syncState currentStatus pause Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::servicePushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: verbose: STATE SERVICE {"status":"play","position":0,"seek":100946,"duration":506,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"647 Kbps","isStreaming":false,"title":"02 Money for Nothing","artist":"Dire Straits","album":"Brother in Arms","uri":"USB/8C94-7B62/SPEAKER TEST SONGS/02 02 Money for Nothing.flac","trackType":"flac"} Apr 16 02:36:30 volumio volumio[1209]: verbose: CURRENT POSITION 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::syncState stateService play Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::syncState currentStatus play Apr 16 02:36:30 volumio volumio[1209]: info: Received an update from plugin. extracting info from payload Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:30 volumio volumio[1209]: info: ControllerMpd::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::servicePushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: verbose: STATE SERVICE {"status":"play","position":0,"seek":100946,"duration":506,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"647 Kbps","isStreaming":false,"title":"02 Money for Nothing","artist":"Dire Straits","album":"Brother in Arms","uri":"USB/8C94-7B62/SPEAKER TEST SONGS/02 02 Money for Nothing.flac","trackType":"flac"} Apr 16 02:36:30 volumio volumio[1209]: verbose: CURRENT POSITION 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::syncState stateService play Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::syncState currentStatus play Apr 16 02:36:30 volumio volumio[1209]: info: Received an update from plugin. extracting info from payload Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:30 volumio volumio[1209]: info: CoreStateMachine::pushState Apr 16 02:36:30 volumio volumio[1209]: info: CorePlayQueue::getTrack 1 Apr 16 02:36:30 volumio volumio[1209]: info: CoreCommandRouter::volumioPushState Apr 16 02:36:30 volumio volumio[1209]: info: ------------------------------ 108ms Apr 16 02:36:30 volumio volumio[1209]: info: ------------------------------ 107ms Apr 16 02:36:30 volumio volumio[1209]: info: ------------------------------ 106ms Apr 16 02:36:30 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:30 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:30 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:30 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:30 volumio volumio[1209]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 16 02:36:41 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 16 02:36:41 volumio volumio[1209]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 16 02:36:41 volumio go-librespot[1758]: time="2025-04-16T02:36:41+08:00" level=trace msg="sent dealer ping" Apr 16 02:36:41 volumio go-librespot[1758]: time="2025-04-16T02:36:41+08:00" level=trace msg="received dealer pong" Apr 16 02:36:45 volumio volumio[1209]: info: Enabling plugin now_playing Apr 16 02:36:45 volumio volumio[1209]: info: Loading plugin "now_playing"... Apr 16 02:36:45 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:45 volumio volumio[1209]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Apr 16 02:36:45 volumio volumio[1209]: Require stack: Apr 16 02:36:45 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:45 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:45 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:45 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:45 volumio volumio[1209]: error: Stack trace: Error: Cannot find module 'geo-tz' Apr 16 02:36:45 volumio volumio[1209]: Require stack: Apr 16 02:36:45 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:45 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:45 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:45 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:45 volumio volumio[1209]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:931:15) Apr 16 02:36:45 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:774:27) Apr 16 02:36:45 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:45 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:45 volumio volumio[1209]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Apr 16 02:36:45 volumio volumio[1209]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Apr 16 02:36:45 volumio volumio[1209]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Apr 16 02:36:45 volumio volumio[1209]: at Module.load (internal/modules/cjs/loader.js:979:32) Apr 16 02:36:45 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Apr 16 02:36:45 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:45 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:45 volumio volumio[1209]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Apr 16 02:36:45 volumio volumio[1209]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 16 02:36:45 volumio volumio[1209]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 16 02:36:45 volumio volumio[1209]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Apr 16 02:36:45 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:45 volumio volumio[1209]: info: Done. Apr 16 02:36:48 volumio volumio[1209]: info: Enabling plugin now_playing Apr 16 02:36:48 volumio volumio[1209]: info: Loading plugin "now_playing"... Apr 16 02:36:48 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:48 volumio volumio[1209]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Apr 16 02:36:48 volumio volumio[1209]: Require stack: Apr 16 02:36:48 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:48 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:48 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:48 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:48 volumio volumio[1209]: error: Stack trace: Error: Cannot find module 'geo-tz' Apr 16 02:36:48 volumio volumio[1209]: Require stack: Apr 16 02:36:48 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:48 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:48 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:48 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:48 volumio volumio[1209]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:931:15) Apr 16 02:36:48 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:774:27) Apr 16 02:36:48 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:48 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:48 volumio volumio[1209]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Apr 16 02:36:48 volumio volumio[1209]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Apr 16 02:36:48 volumio volumio[1209]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Apr 16 02:36:48 volumio volumio[1209]: at Module.load (internal/modules/cjs/loader.js:979:32) Apr 16 02:36:48 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Apr 16 02:36:48 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:48 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:48 volumio volumio[1209]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Apr 16 02:36:48 volumio volumio[1209]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 16 02:36:48 volumio volumio[1209]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 16 02:36:48 volumio volumio[1209]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Apr 16 02:36:48 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:48 volumio volumio[1209]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Apr 16 02:36:49 volumio volumio[1209]: info: Enabling plugin now_playing Apr 16 02:36:49 volumio volumio[1209]: info: Loading plugin "now_playing"... Apr 16 02:36:49 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:49 volumio volumio[1209]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Apr 16 02:36:49 volumio volumio[1209]: Require stack: Apr 16 02:36:49 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:49 volumio volumio[1209]: error: Stack trace: Error: Cannot find module 'geo-tz' Apr 16 02:36:49 volumio volumio[1209]: Require stack: Apr 16 02:36:49 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:49 volumio volumio[1209]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:931:15) Apr 16 02:36:49 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:774:27) Apr 16 02:36:49 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:49 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:49 volumio volumio[1209]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Apr 16 02:36:49 volumio volumio[1209]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Apr 16 02:36:49 volumio volumio[1209]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Apr 16 02:36:49 volumio volumio[1209]: at Module.load (internal/modules/cjs/loader.js:979:32) Apr 16 02:36:49 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Apr 16 02:36:49 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:49 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:49 volumio volumio[1209]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Apr 16 02:36:49 volumio volumio[1209]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 16 02:36:49 volumio volumio[1209]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 16 02:36:49 volumio volumio[1209]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Apr 16 02:36:49 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:49 volumio volumio[1209]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Apr 16 02:36:49 volumio volumio[1209]: info: Enabling plugin now_playing Apr 16 02:36:49 volumio volumio[1209]: info: Loading plugin "now_playing"... Apr 16 02:36:49 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:49 volumio volumio[1209]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Apr 16 02:36:49 volumio volumio[1209]: Require stack: Apr 16 02:36:49 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:49 volumio volumio[1209]: error: Stack trace: Error: Cannot find module 'geo-tz' Apr 16 02:36:49 volumio volumio[1209]: Require stack: Apr 16 02:36:49 volumio volumio[1209]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/pluginmanager.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/app/index.js Apr 16 02:36:49 volumio volumio[1209]: - /volumio/index.js Apr 16 02:36:49 volumio volumio[1209]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:931:15) Apr 16 02:36:49 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:774:27) Apr 16 02:36:49 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:49 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:49 volumio volumio[1209]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Apr 16 02:36:49 volumio volumio[1209]: at Module._compile (internal/modules/cjs/loader.js:1114:14) Apr 16 02:36:49 volumio volumio[1209]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1143:10) Apr 16 02:36:49 volumio volumio[1209]: at Module.load (internal/modules/cjs/loader.js:979:32) Apr 16 02:36:49 volumio volumio[1209]: at Function.Module._load (internal/modules/cjs/loader.js:819:12) Apr 16 02:36:49 volumio volumio[1209]: at Module.require (internal/modules/cjs/loader.js:1003:19) Apr 16 02:36:49 volumio volumio[1209]: at require (internal/modules/cjs/helpers.js:107:18) Apr 16 02:36:49 volumio volumio[1209]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Apr 16 02:36:49 volumio volumio[1209]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 16 02:36:49 volumio volumio[1209]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 16 02:36:49 volumio volumio[1209]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Apr 16 02:36:49 volumio volumio[1209]: error: !!!! WARNING !!!! Apr 16 02:36:50 volumio volumio[1209]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Apr 16 02:36:52 volumio volumio[1209]: info: Starting Uninstall of plugin user_interface - now_playing Apr 16 02:36:52 volumio volumio[1209]: info: Uninstalling plugin now_playing Apr 16 02:36:59 volumio volumio[1209]: info: Starting Uninstall of plugin user_interface - now_playing Apr 16 02:36:59 volumio volumio[1209]: info: Uninstalling plugin now_playing Apr 16 02:37:01 volumio volumio[1209]: info: + geo-tz@8.1.4 Apr 16 02:37:01 volumio volumio[1209]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 16 02:37:01 volumio volumio[1209]: TypeError: Cannot read property 'broadcastMessage' of null Apr 16 02:37:01 volumio volumio[1209]: at /volumio/app/index.js:1534:32 Apr 16 02:37:01 volumio volumio[1209]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Apr 16 02:37:01 volumio volumio[1209]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Apr 16 02:37:01 volumio volumio[1209]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Apr 16 02:37:01 volumio volumio[1209]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Apr 16 02:37:01 volumio volumio[1209]: at Tail. (/volumio/app/pluginmanager.js:860:24) Apr 16 02:37:01 volumio volumio[1209]: at Tail.emit (events.js:400:28) Apr 16 02:37:01 volumio volumio[1209]: at ReadStream. (/volumio/node_modules/tail/lib/tail.js:51:33) Apr 16 02:37:01 volumio volumio[1209]: at ReadStream.emit (events.js:400:28) Apr 16 02:37:01 volumio volumio[1209]: at addChunk (internal/streams/readable.js:293:12) Apr 16 02:37:01 volumio volumio[1209]: at readableAddChunk (internal/streams/readable.js:263:11) Apr 16 02:37:01 volumio volumio[1209]: at ReadStream.Readable.push (internal/streams/readable.js:206:10) Apr 16 02:37:01 volumio volumio[1209]: at internal/fs/streams.js:190:14 Apr 16 02:37:01 volumio volumio[1209]: at FSReqCallback.wrapper [as oncomplete] (fs.js:563:5) Apr 16 02:37:01 volumio volumio[1209]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 16 02:37:01 volumio sudo[3756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-16 02:36 Apr 16 02:37:01 volumio sudo[3756]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:27:48 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4bc1ecb08f34ad14b420d6678a2aef1b"