Dec 18 16:48:13 volumio volumio[1210]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 18 16:48:14 volumio volumio[1210]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 18 16:48:14 volumio volumio[1210]: info: Streaming services startup Dec 18 16:48:14 volumio volumio[1210]: info: Starting Streaming Daemon Dec 18 16:48:14 volumio volumio[1210]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 18 16:48:14 volumio sudo[1673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 18 16:48:14 volumio sudo[1673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 16:48:14 volumio sudo[1673]: pam_unix(sudo:session): session closed for user root Dec 18 16:48:15 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 16:48:15 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:15 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 18 16:48:15 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 18 16:48:15 volumio volumio[1210]: error: Cannot start Volumio Streaming Daemon Dec 18 16:48:15 volumio volumio[1210]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 18 16:48:15 volumio volumio[1210]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 18 16:48:16 volumio volumio[1210]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Dec 18 16:48:18 volumio volumio-remote-updater[718]: Test mode disabled Dec 18 16:48:18 volumio volumio-remote-updater[718]: Alpha mode disabled Dec 18 16:48:18 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Dec 18 16:48:18 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::volumioGetBrowseSources Dec 18 16:48:19 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 18 16:48:20 volumio volumio[1210]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 18 16:48:20 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 18 16:48:21 volumio volumio[1210]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 18 16:48:21 volumio volumio[1210]: info: CoreCommandRouter::volumioGetState Dec 18 16:48:21 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:48:23 volumio volumio[1210]: info: MyVolumio token set successfully Dec 18 16:48:23 volumio volumio[1210]: info: MYVOLUMIO: Adding device Dec 18 16:48:23 volumio volumio[1210]: info: MYVOLUMIO: Evaluating Server Dec 18 16:48:25 volumio volumio[1210]: info: MyVolumio status changed Dec 18 16:48:25 volumio volumio[1210]: info: Streaming services startup Dec 18 16:48:25 volumio volumio[1210]: info: Starting Streaming Daemon Dec 18 16:48:25 volumio volumio[1210]: info: Removing browser output: myVolumio user plan is not superstar Dec 18 16:48:25 volumio volumio[1210]: info: Removing audio output: Dec 18 16:48:25 volumio volumio[1210]: info: Stoppping Tunnel 1 Dec 18 16:48:26 volumio sudo[1721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 18 16:48:26 volumio sudo[1721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 16:48:26 volumio volumio[1210]: info: Setting Geolocation for MyVolumio to as1 Dec 18 16:48:26 volumio sudo[1721]: pam_unix(sudo:session): session closed for user root Dec 18 16:48:26 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:26 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:26 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:26 volumio volumio[1210]: error: Cannot start Volumio Streaming Daemon Dec 18 16:48:26 volumio sudo[1723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 18 16:48:26 volumio volumio[1210]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 18 16:48:26 volumio volumio[1210]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 18 16:48:26 volumio sudo[1723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 18 16:48:26 volumio sudo[1723]: pam_unix(sudo:session): session closed for user root Dec 18 16:48:26 volumio volumio[1210]: info: Remote SSH Stopped Dec 18 16:48:27 volumio volumio[1210]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 18 16:48:27 volumio volumio[1210]: info: Updating MyVolumio device info Dec 18 16:48:27 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:27 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:27 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:27 volumio volumio[1210]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 18 16:48:31 volumio volumio[1210]: info: MYVOLUMIO: Adding device Dec 18 16:48:31 volumio volumio[1210]: info: MYVOLUMIO: Evaluating Server Dec 18 16:48:33 volumio volumio[1210]: info: Setting Geolocation for MyVolumio to as1 Dec 18 16:48:33 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:33 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:33 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:33 volumio volumio[1210]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 18 16:48:34 volumio volumio[1210]: info: Updating MyVolumio device info Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:34 volumio volumio[1210]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 18 16:48:34 volumio volumio[1210]: info: Completed starting MyVolumio Plugin Dec 18 16:48:34 volumio volumio[1210]: [Metrics] CommandRouter: 95s 174.74ms Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::volumiosetStartupVolume Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 18 16:48:34 volumio volumio[1210]: info: VolumeController:: Setting startup Volume 100 Dec 18 16:48:34 volumio volumio[1210]: info: VolumeController::SetAlsaVolume100 Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::Close All Modals sent Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::Close All Modals sent Dec 18 16:48:34 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:48:34 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 16:48:34 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:48:35 volumio volumio[1210]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 18 16:48:35 volumio volumio[1210]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Dec 18 16:48:35 volumio volumio[1210]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for sndrpihifiberry Dec 18 16:48:35 volumio volumio[1210]: aplay: main:831: audio open error: No such device Dec 18 16:48:35 volumio volumio[1210]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '2'. Dec 18 16:48:35 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 18 16:48:35 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 18 16:48:35 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 18 16:48:41 volumio volumio[1210]: info: BOOT COMPLETED Dec 18 16:49:12 volumio volumio[1210]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.94 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 18 16:49:13 volumio volumio[1210]: info: CoreCommandRouter::volumioGetState Dec 18 16:49:13 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:13 volumio volumio[1210]: info: CoreCommandRouter::volumioGetVisibleSources Dec 18 16:49:13 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 18 16:49:13 volumio volumio[1210]: info: CoreCommandRouter::volumioGetQueue Dec 18 16:49:13 volumio volumio[1210]: info: CoreStateMachine::getQueue Dec 18 16:49:13 volumio volumio[1210]: info: CorePlayQueue::getQueue Dec 18 16:49:13 volumio volumio[1210]: info: Listing playlists Dec 18 16:49:13 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 18 16:49:21 volumio volumio[1210]: info: CoreCommandRouter::volumioPlay Dec 18 16:49:21 volumio volumio[1210]: info: CoreStateMachine::play index undefined Dec 18 16:49:21 volumio volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 18 16:49:21 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:21 volumio volumio[1210]: info: CoreStateMachine::startPlaybackTimer Dec 18 16:49:21 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:21 volumio volumio[1210]: verbose: ControllerMpd::clearAddPlayTracks USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff Dec 18 16:49:21 volumio volumio[1210]: info: Setting Volume to 100 automatically for DSD Dec 18 16:49:21 volumio volumio[1210]: info: VolumeController::SetAlsaVolume100 Dec 18 16:49:21 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand stop Dec 18 16:49:21 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:21 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:21 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:22 volumio volumio[1210]: info: sendMpdCommand stop took 307 milliseconds Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand clear Dec 18 16:49:22 volumio volumio[1210]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '2'. Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces system playlist update Dec 18 16:49:22 volumio volumio[1210]: info: Ignoring MPD Status Update Dec 18 16:49:22 volumio volumio[1210]: info: sendMpdCommand clear took 109 milliseconds Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand add "USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff" Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces system playlist update Dec 18 16:49:22 volumio volumio[1210]: info: Ignoring MPD Status Update Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces system playlist update Dec 18 16:49:22 volumio volumio[1210]: info: Ignoring MPD Status Update Dec 18 16:49:22 volumio volumio[1210]: error: updateQueue error: null Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces system playlist update Dec 18 16:49:22 volumio volumio[1210]: info: Ignoring MPD Status Update Dec 18 16:49:22 volumio volumio[1210]: info: ------------------------------ 198ms Dec 18 16:49:22 volumio volumio[1210]: info: sendMpdCommand add "USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff" took 94 milliseconds Dec 18 16:49:22 volumio volumio[1210]: info: ------------------------------ 92ms Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand play Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces system playlist update Dec 18 16:49:22 volumio volumio[1210]: info: Ignoring MPD Status Update Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces system playlist update Dec 18 16:49:22 volumio volumio[1210]: info: Ignoring MPD Status Update Dec 18 16:49:22 volumio volumio[1210]: info: ------------------------------ 169ms Dec 18 16:49:22 volumio volumio[1210]: info: ------------------------------ 82ms Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces state update: player Dec 18 16:49:22 volumio volumio[1210]: info: sendMpdCommand play took 245 milliseconds Dec 18 16:49:22 volumio volumio[1210]: info: ------------------------------ 248ms Dec 18 16:49:22 volumio volumio[1210]: info: ------------------------------ 261ms Dec 18 16:49:22 volumio volumio[1210]: info: ControllerMpd::getState Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand status Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces state update: player Dec 18 16:49:22 volumio volumio[1210]: info: ControllerMpd::getState Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand status Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces state update: player Dec 18 16:49:22 volumio volumio[1210]: info: ControllerMpd::getState Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand status Dec 18 16:49:22 volumio volumio[1210]: info: Dec 18 16:49:22 volumio volumio[1210]: ---------------------------- MPD announces state update: player Dec 18 16:49:22 volumio volumio[1210]: info: ControllerMpd::getState Dec 18 16:49:22 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand status Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand clearerror Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand status took 334 milliseconds Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 16:49:23 volumio volumio[1210]: info: Dec 18 16:49:23 volumio volumio[1210]: ---------------------------- MPD announces state update: player Dec 18 16:49:23 volumio volumio[1210]: info: ControllerMpd::getState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand status Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand clearerror Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand status took 480 milliseconds Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand clearerror Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand status took 503 milliseconds Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand clearerror Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand status took 369 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand clearerror took 227 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand playlistinfo took 174 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand status took 140 milliseconds Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseTrackInfo Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 16:49:23 volumio volumio[1210]: info: ControllerMpd::pushState Dec 18 16:49:23 volumio volumio[1210]: info: CoreCommandRouter::servicePushState Dec 18 16:49:23 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:23 volumio volumio[1210]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":518,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","artist":null,"album":null,"uri":"USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","trackType":"dff"} Dec 18 16:49:23 volumio volumio[1210]: verbose: CURRENT POSITION 0 Dec 18 16:49:23 volumio volumio[1210]: info: CoreStateMachine::syncState stateService pause Dec 18 16:49:23 volumio volumio[1210]: info: CoreStateMachine::syncState currentStatus stop Dec 18 16:49:23 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:23 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:23 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 16:49:23 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:23 volumio volumio[1210]: info: ------------------------------ 1173ms Dec 18 16:49:23 volumio volumio[1210]: info: Dec 18 16:49:23 volumio volumio[1210]: ---------------------------- MPD announces state update: player Dec 18 16:49:23 volumio volumio[1210]: info: ControllerMpd::getState Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand status Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand clearerror took 669 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand clearerror took 645 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand clearerror took 638 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand playlistinfo took 519 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand playlistinfo took 517 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand playlistinfo took 494 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand playlistinfo took 491 milliseconds Dec 18 16:49:23 volumio volumio[1210]: info: sendMpdCommand status took 198 milliseconds Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseTrackInfo Dec 18 16:49:23 volumio volumio[1210]: verbose: ControllerMpd::parseTrackInfo Dec 18 16:49:24 volumio volumio[1210]: verbose: ControllerMpd::parseTrackInfo Dec 18 16:49:24 volumio volumio[1210]: verbose: ControllerMpd::parseTrackInfo Dec 18 16:49:24 volumio volumio[1210]: verbose: ControllerMpd::parseState Dec 18 16:49:24 volumio volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 18 16:49:24 volumio volumio[1210]: info: ControllerMpd::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::servicePushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":518,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","artist":null,"album":null,"uri":"USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","trackType":"dff"} Dec 18 16:49:24 volumio volumio[1210]: verbose: CURRENT POSITION 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState stateService pause Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState currentStatus stop Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:24 volumio volumio[1210]: info: ControllerMpd::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::servicePushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":518,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","artist":null,"album":null,"uri":"USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","trackType":"dff"} Dec 18 16:49:24 volumio volumio[1210]: verbose: CURRENT POSITION 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState stateService pause Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState currentStatus stop Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:24 volumio volumio[1210]: info: ControllerMpd::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::servicePushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":518,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","artist":null,"album":null,"uri":"USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","trackType":"dff"} Dec 18 16:49:24 volumio volumio[1210]: verbose: CURRENT POSITION 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState stateService pause Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState currentStatus stop Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:24 volumio volumio[1210]: info: ControllerMpd::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::servicePushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":518,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","artist":null,"album":null,"uri":"USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","trackType":"dff"} Dec 18 16:49:24 volumio volumio[1210]: verbose: CURRENT POSITION 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState stateService pause Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState currentStatus stop Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:24 volumio volumio[1210]: info: ------------------------------ 1995ms Dec 18 16:49:24 volumio volumio[1210]: info: ------------------------------ 1949ms Dec 18 16:49:24 volumio volumio[1210]: info: ------------------------------ 1860ms Dec 18 16:49:24 volumio volumio[1210]: info: ------------------------------ 1702ms Dec 18 16:49:24 volumio volumio[1210]: info: sendMpdCommand playlistinfo took 788 milliseconds Dec 18 16:49:24 volumio volumio[1210]: verbose: ControllerMpd::parseTrackInfo Dec 18 16:49:24 volumio volumio[1210]: info: ControllerMpd::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::servicePushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":518,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","artist":null,"album":null,"uri":"USB/SILVER/Anne-Sophie Mutter - Carmen-Fantasie/01 - Violin Anne-Sophie Mutter Wiener Philharmoniker Conduc - Sarasate Zigeunerweisen.dff","trackType":"dff"} Dec 18 16:49:24 volumio volumio[1210]: verbose: CURRENT POSITION 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState stateService pause Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::syncState currentStatus stop Dec 18 16:49:24 volumio volumio[1210]: info: CoreStateMachine::pushState Dec 18 16:49:24 volumio volumio[1210]: info: CorePlayQueue::getTrack 0 Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 18 16:49:24 volumio volumio[1210]: info: CoreCommandRouter::volumioPushState Dec 18 16:49:25 volumio volumio[1210]: info: ------------------------------ 1295ms Dec 18 16:49:34 volumio upmpdcli[1866]: writing RSA key Dec 18 16:49:38 volumio volumio[1210]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 18 16:49:38 volumio volumio[1210]: info: CoreStateMachine::ClearQueue Dec 18 16:49:38 volumio volumio[1210]: info: CoreStateMachine::stop Dec 18 16:49:38 volumio volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 18 16:49:38 volumio volumio[1210]: info: CorePlayQueue::clearPlayQueue Dec 18 16:49:38 volumio volumio[1210]: info: CorePlayQueue::saveQueue Dec 18 16:49:38 volumio volumio[1210]: info: CoreCommandRouter::volumioPushQueue Dec 18 16:49:38 volumio volumio[1210]: info: CoreStateMachine::addQueueItems Dec 18 16:49:38 volumio volumio[1210]: info: CorePlayQueue::addQueueItems Dec 18 16:49:38 volumio volumio[1210]: info: Preload queue cleared Dec 18 16:49:38 volumio volumio[1210]: info: Adding Item to queue: music-library/USB/SILVER/Kenny G - Breathless Dec 18 16:49:38 volumio volumio[1210]: info: Exploding uri music-library/USB/SILVER/Kenny G - Breathless in service mpd Dec 18 16:49:38 volumio volumio[1210]: info: ALBUMART /albumart?cacheid=740&web=//extralarge&path=%2Fmnt%2FUSB%2FSILVER%2FKenny%20G%20-%20Breathless%2FKenny%20G%20-%20Breathless.ape&metadata=false Dec 18 16:49:38 volumio volumio[1210]: info: URI /mnt/USB/SILVER/Kenny G - Breathless/Kenny G - Breathless.ape Dec 18 16:49:38 volumio volumio[1210]: info: ALBUMART /albumart?cacheid=740&web=Kenny%20G/Breathless/extralarge&path=%2Fmnt%2FUSB%2FSILVER%2FKenny%20G%20-%20Breathless%2FKenny%20G%20-%20Breathless.cue&metadata=false Dec 18 16:49:38 volumio volumio[1210]: info: URI /mnt/USB/SILVER/Kenny G - Breathless/Kenny G - Breathless.cue Dec 18 16:49:38 volumio volumio[1210]: info: ALBUMART /albumart?cacheid=740&web=Kenny%20G/Breathless/extralarge&path=%2Fmnt%2FUSB%2FSILVER%2FKenny%20G%20-%20Breathless%2FKenny%20G%20-%20Breathless.cue&metadata=false Dec 18 16:49:38 volumio volumio[1210]: info: URI /mnt/USB/SILVER/Kenny G - Breathless/Kenny G - Breathless.cue Dec 18 16:49:38 volumio volumio[1210]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 16:49:38 volumio volumio[1210]: Error: Unable to resolve or reject the same promise twice Dec 18 16:49:38 volumio volumio[1210]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Dec 18 16:49:38 volumio volumio[1210]: at /volumio/app/plugins/music_service/mpd/index.js:2587:21 Dec 18 16:49:38 volumio volumio[1210]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Dec 18 16:49:38 volumio volumio[1210]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Dec 18 16:49:38 volumio volumio[1210]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Dec 18 16:49:38 volumio volumio[1210]: at Socket.emit (node:events:514:28) Dec 18 16:49:38 volumio volumio[1210]: at addChunk (node:internal/streams/readable:343:12) Dec 18 16:49:38 volumio volumio[1210]: at readableAddChunk (node:internal/streams/readable:312:11) Dec 18 16:49:38 volumio volumio[1210]: at Readable.push (node:internal/streams/readable:253:10) Dec 18 16:49:38 volumio volumio[1210]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Dec 18 16:49:38 volumio volumio[1210]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 18 16:49:49 volumio sudo[1907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-18 16:48' Dec 18 16:49:49 volumio sudo[1907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"