-- Logs begin at Thu 2019-02-14 10:12:00 GMT, end at Sat 2024-11-02 16:16:05 GMT. -- Nov 02 16:15:21 volumio ntpd[670]: receive: Unexpected origin timestamp 0xead0c557.923cfd1a does not match aorg 0000000000.00000000 from server@44.31.52.36 xmt 0xead0ce99.cf877ff6 Nov 02 16:15:21 volumio ntpd[670]: receive: Unexpected origin timestamp 0xead0c557.924aed73 does not match aorg 0000000000.00000000 from server@131.111.8.63 xmt 0xead0ce99.d00b250f Nov 02 16:15:22 volumio volumio[915]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Nov 02 16:15:22 volumio sudo[1655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 02 16:15:22 volumio sudo[1655]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 02 16:15:22 volumio sudo[1655]: pam_unix(sudo:session): session closed for user root Nov 02 16:15:22 volumio volumio[915]: info: MPD Permissions set Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio sudo[1658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 02 16:15:22 volumio sudo[1658]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 16:15:22 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:22 volumio systemd[1]: Stopping Music Player Daemon... Nov 02 16:15:22 volumio systemd[1]: mpd.service: Succeeded. Nov 02 16:15:22 volumio systemd[1]: Stopped Music Player Daemon. Nov 02 16:15:22 volumio systemd[1]: Starting Music Player Daemon... Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 02 16:15:24 volumio volumio[915]: info: Adding plugin bluetooth to MyMusic Plugins Nov 02 16:15:24 volumio volumio[915]: info: Adding plugin multiroom to MyMusic Plugins Nov 02 16:15:24 volumio volumio[915]: info: Adding plugin metavolumio to MyMusic Plugins Nov 02 16:15:24 volumio volumio[915]: info: Adding plugin cd_controller to MyMusic Plugins Nov 02 16:15:24 volumio volumio[915]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 02 16:15:24 volumio volumio[915]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 02 16:15:24 volumio volumio[915]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 02 16:15:24 volumio dhcpcd[789]: eth0: using IPv4LL address 169.254.209.39 Nov 02 16:15:24 volumio dhcpcd[789]: eth0: adding route to 169.254.0.0/16 Nov 02 16:15:24 volumio dhcpcd[789]: eth0: adding default route Nov 02 16:15:24 volumio avahi-daemon[517]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.209.39. Nov 02 16:15:24 volumio avahi-daemon[517]: New relevant interface eth0.IPv4 for mDNS. Nov 02 16:15:24 volumio avahi-daemon[517]: Registering new address record for 169.254.209.39 on eth0.IPv4. Nov 02 16:15:24 volumio dhcpcd[838]: eth0: using IPv4LL address 169.254.46.101 Nov 02 16:15:24 volumio dhcpcd[838]: eth0: adding route to 169.254.0.0/16 Nov 02 16:15:24 volumio avahi-daemon[517]: Registering new address record for 169.254.46.101 on eth0.IPv4. Nov 02 16:15:25 volumio mpd[1664]: Nov 02 16:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 02 16:15:25 volumio systemd[1]: Started Music Player Daemon. Nov 02 16:15:25 volumio sudo[1658]: pam_unix(sudo:session): session closed for user root Nov 02 16:15:25 volumio ntpd[670]: Listen normally on 7 eth0 169.254.209.39:123 Nov 02 16:15:25 volumio ntpd[670]: Listen normally on 8 eth0 169.254.46.101:123 Nov 02 16:15:25 volumio ntpd[670]: 44.31.52.36 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 85.199.214.98 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 95.215.175.2 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 131.111.8.63 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 185.103.119.60 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 85.199.214.102 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 178.215.228.24 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 131.111.8.60 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: 193.57.144.50 local addr 192.168.1.123 -> 169.254.209.39 Nov 02 16:15:25 volumio ntpd[670]: new interface(s) found: waking up resolver Nov 02 16:15:27 volumio volumio[915]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 02 16:15:27 volumio volumio[915]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 02 16:15:27 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 16:15:27 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 16:15:27 volumio volumio[915]: info: Starting MyVolumio Remote Streaming Endpoints Nov 02 16:15:27 volumio volumio[915]: info: MyVolumio login type: Token Nov 02 16:15:27 volumio volumio[915]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 02 16:15:27 volumio volumio[915]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 02 16:15:31 volumio volumio[915]: info: Starting Streaming Service Transparent Proxy Nov 02 16:15:31 volumio volumio[915]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 02 16:15:31 volumio volumio[915]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 02 16:15:31 volumio volumio[915]: info: Streaming services startup Nov 02 16:15:31 volumio volumio[915]: info: Starting Streaming Daemon Nov 02 16:15:31 volumio volumio[915]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 02 16:15:31 volumio sudo[1808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 02 16:15:31 volumio sudo[1808]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 02 16:15:31 volumio sudo[1808]: pam_unix(sudo:session): session closed for user root Nov 02 16:15:31 volumio volumio[915]: error: Cannot start Volumio Streaming Daemon Nov 02 16:15:31 volumio volumio[915]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 02 16:15:31 volumio volumio[915]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 02 16:15:31 volumio volumio[915]: info: CoreCommandRouter::volumioPlay Nov 02 16:15:31 volumio volumio[915]: info: CoreStateMachine::play index undefined Nov 02 16:15:31 volumio volumio[915]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 16:15:31 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:31 volumio volumio[915]: info: CoreStateMachine::startPlaybackTimer Nov 02 16:15:31 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::clearAddPlayTracks USB/Sandisk/2003 林志美 SACD/01. 感情的段落.dsf Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 16:15:31 volumio volumio[915]: error: updateQueue error: null Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand stop took 13 milliseconds Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand clear Nov 02 16:15:31 volumio volumio[915]: info: Nov 02 16:15:31 volumio volumio[915]: ---------------------------- MPD announces system playlist update Nov 02 16:15:31 volumio volumio[915]: info: Ignoring MPD Status Update Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand clear took 15 milliseconds Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand add "USB/Sandisk/2003 林志美 SACD/01. 感情的段落.dsf" Nov 02 16:15:31 volumio volumio[915]: error: updateQueue error: null Nov 02 16:15:31 volumio volumio[915]: info: Nov 02 16:15:31 volumio volumio[915]: ---------------------------- MPD announces system playlist update Nov 02 16:15:31 volumio volumio[915]: info: Ignoring MPD Status Update Nov 02 16:15:31 volumio volumio[915]: info: ------------------------------ 25ms Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand add "USB/Sandisk/2003 林志美 SACD/01. 感情的段落.dsf" took 15 milliseconds Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand play Nov 02 16:15:31 volumio volumio[915]: info: ------------------------------ 48ms Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand play took 37 milliseconds Nov 02 16:15:31 volumio volumio[915]: info: Discovery: adding 271f537b-5f11-47ba-9192-c680fb8f158d Nov 02 16:15:31 volumio volumio[915]: info: Discovery: Found device Volumio Nov 02 16:15:31 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:31 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:31 volumio volumio[915]: info: Nov 02 16:15:31 volumio volumio[915]: ---------------------------- MPD announces state update: player Nov 02 16:15:31 volumio volumio[915]: info: ControllerMpd::getState Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand status Nov 02 16:15:31 volumio volumio[915]: info: FusionDsp - ---- read samplerate, raw: 176400,S32_LE,2,32 Nov 02 16:15:31 volumio volumio[915]: info: FusionDsp - ---- read samplerate from file: 176400 Nov 02 16:15:31 volumio volumio[915]: info: camilladsp stopping service pid 1278... Nov 02 16:15:31 volumio volumio[915]: info: camilladsp service terminated, instance 1 Nov 02 16:15:31 volumio volumio[915]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 02 16:15:31 volumio volumio[915]: info: camilladsp service started and running in background, instance 1 Nov 02 16:15:31 volumio volumio[915]: info: FusionDsp - ---- read samplerate, raw: 176400,S32_LE,2,32 Nov 02 16:15:31 volumio volumio[915]: info: FusionDsp - ---- read samplerate from file: 176400 Nov 02 16:15:31 volumio volumio[915]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 02 16:15:31 volumio volumio[915]: info: Nov 02 16:15:31 volumio volumio[915]: ---------------------------- MPD announces state update: player Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand status took 148 milliseconds Nov 02 16:15:31 volumio volumio[915]: info: ControllerMpd::getState Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand status Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::parseState Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand status took 23 milliseconds Nov 02 16:15:31 volumio volumio[915]: info: sendMpdCommand playlistinfo took 19 milliseconds Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::parseState Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 16:15:31 volumio volumio[915]: verbose: ControllerMpd::parseTrackInfo Nov 02 16:15:31 volumio volumio[915]: info: ControllerMpd::pushState Nov 02 16:15:31 volumio volumio[915]: info: CoreCommandRouter::servicePushState Nov 02 16:15:31 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:31 volumio volumio[915]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":242,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"01. 感情的段落.dsf","artist":null,"album":null,"uri":"USB/Sandisk/2003 林志美 SACD/01. 感情的段落.dsf","trackType":"dsf"} Nov 02 16:15:31 volumio volumio[915]: verbose: CURRENT POSITION 0 Nov 02 16:15:31 volumio volumio[915]: info: CoreStateMachine::syncState stateService play Nov 02 16:15:31 volumio volumio[915]: info: CoreStateMachine::syncState currentStatus stop Nov 02 16:15:31 volumio volumio[915]: info: ------------------------------ 206ms Nov 02 16:15:31 volumio volumio[915]: error: FusionDsp - WebSocket error: [object Object] Nov 02 16:15:32 volumio volumio[915]: info: camilladsp spawned new process with pid 1828, instance 1, run: true Nov 02 16:15:32 volumio volumio[915]: info: sendMpdCommand playlistinfo took 87 milliseconds Nov 02 16:15:32 volumio volumio[915]: verbose: ControllerMpd::parseTrackInfo Nov 02 16:15:32 volumio volumio[915]: info: ControllerMpd::pushState Nov 02 16:15:32 volumio volumio[915]: info: CoreCommandRouter::servicePushState Nov 02 16:15:32 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:32 volumio volumio[915]: verbose: STATE SERVICE {"status":"play","position":0,"seek":732,"duration":242,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"01. 感情的段落.dsf","artist":null,"album":null,"uri":"USB/Sandisk/2003 林志美 SACD/01. 感情的段落.dsf","trackType":"dsf"} Nov 02 16:15:32 volumio volumio[915]: verbose: CURRENT POSITION 0 Nov 02 16:15:32 volumio volumio[915]: info: CoreStateMachine::syncState stateService play Nov 02 16:15:32 volumio volumio[915]: info: CoreStateMachine::syncState currentStatus play Nov 02 16:15:32 volumio volumio[915]: info: Received an update from plugin. extracting info from payload Nov 02 16:15:32 volumio volumio[915]: info: CoreStateMachine::pushState Nov 02 16:15:32 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:32 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 16:15:32 volumio volumio[915]: info: CoreCommandRouter::volumioPushState Nov 02 16:15:32 volumio volumio[915]: info: CoreStateMachine::pushState Nov 02 16:15:32 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:32 volumio volumio[915]: info: CoreCommandRouter::volumioPushState Nov 02 16:15:32 volumio volumio[915]: info: ------------------------------ 309ms Nov 02 16:15:32 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:32 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:32 volumio volumio[915]: info: CoreCommandRouter::volumioGetQueue Nov 02 16:15:32 volumio volumio[915]: info: CoreStateMachine::getQueue Nov 02 16:15:32 volumio volumio[915]: info: CorePlayQueue::getQueue Nov 02 16:15:33 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:33 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:33 volumio volumio[915]: info: CoreCommandRouter::volumioGetQueue Nov 02 16:15:33 volumio volumio[915]: info: CoreStateMachine::getQueue Nov 02 16:15:33 volumio volumio[915]: info: CorePlayQueue::getQueue Nov 02 16:15:34 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:34 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:34 volumio volumio[915]: info: CoreCommandRouter::volumioGetQueue Nov 02 16:15:34 volumio volumio[915]: info: CoreStateMachine::getQueue Nov 02 16:15:34 volumio volumio[915]: info: CorePlayQueue::getQueue Nov 02 16:15:34 volumio volumio[915]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Nov 02 16:15:34 volumio volumio[915]: info: Retrying Login Due to Network Error Nov 02 16:15:34 volumio volumio[915]: STREAMING PROXY: Starting server on port 3245 Nov 02 16:15:34 volumio volumio[915]: Node JS runtime: 14 Nov 02 16:15:35 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:35 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:35 volumio volumio[915]: info: CoreCommandRouter::volumioGetQueue Nov 02 16:15:35 volumio volumio[915]: info: CoreStateMachine::getQueue Nov 02 16:15:35 volumio volumio[915]: info: CorePlayQueue::getQueue Nov 02 16:15:36 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 16:15:36 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 16:15:36 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 02 16:15:36 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:36 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:36 volumio volumio[915]: info: CoreCommandRouter::volumioGetQueue Nov 02 16:15:36 volumio volumio[915]: info: CoreStateMachine::getQueue Nov 02 16:15:36 volumio volumio[915]: info: CorePlayQueue::getQueue Nov 02 16:15:37 volumio volumio[915]: info: CoreCommandRouter::volumioPause Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::pause Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::stPlaybackTimer Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::servicePause Nov 02 16:15:37 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:37 volumio volumio[915]: info: CoreCommandRouter::servicePause Nov 02 16:15:37 volumio volumio[915]: info: ControllerMpd::pause Nov 02 16:15:37 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand pause Nov 02 16:15:37 volumio volumio[915]: info: Nov 02 16:15:37 volumio volumio[915]: ---------------------------- MPD announces state update: player Nov 02 16:15:37 volumio volumio[915]: info: sendMpdCommand pause took 20 milliseconds Nov 02 16:15:37 volumio volumio[915]: info: ControllerMpd::getState Nov 02 16:15:37 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand status Nov 02 16:15:37 volumio volumio[915]: info: sendMpdCommand status took 3 milliseconds Nov 02 16:15:37 volumio volumio[915]: verbose: ControllerMpd::parseState Nov 02 16:15:37 volumio volumio[915]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 16:15:37 volumio volumio[915]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 02 16:15:37 volumio volumio[915]: verbose: ControllerMpd::parseTrackInfo Nov 02 16:15:37 volumio volumio[915]: info: ControllerMpd::pushState Nov 02 16:15:37 volumio volumio[915]: info: CoreCommandRouter::servicePushState Nov 02 16:15:37 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:37 volumio volumio[915]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5748,"duration":242,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"01. 感情的段落.dsf","artist":null,"album":null,"uri":"USB/Sandisk/2003 林志美 SACD/01. 感情的段落.dsf","trackType":"dsf"} Nov 02 16:15:37 volumio volumio[915]: verbose: CURRENT POSITION 0 Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::syncState stateService pause Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::syncState currentStatus pause Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::pushState Nov 02 16:15:37 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:37 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 16:15:37 volumio volumio[915]: info: CoreCommandRouter::volumioPushState Nov 02 16:15:37 volumio volumio[915]: info: CoreStateMachine::stPlaybackTimer Nov 02 16:15:37 volumio volumio[915]: info: ------------------------------ 74ms Nov 02 16:15:37 volumio volumio[915]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 02 16:15:37 volumio volumio[915]: info: camilladsp spawned new process with pid 1840, instance 1, run: true Nov 02 16:15:38 volumio volumio[915]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 46 Nov 02 16:15:42 volumio volumio[915]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Total Clients: 47 Nov 02 16:15:42 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 02 16:15:42 volumio volumio[915]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 48 Nov 02 16:15:42 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:42 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:44 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 02 16:15:44 volumio volumio[915]: info: MyVolumio login type: Token Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::volumioGetVisibleSources Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:45 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 02 16:15:45 volumio volumio[915]: info: Received Get System Info Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 02 16:15:45 volumio volumio[915]: info: Discovery: Getting this device information Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:45 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:45 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:45 volumio volumio[915]: info: Listing playlists Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 02 16:15:45 volumio volumio[915]: info: Received Get System Info Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 02 16:15:45 volumio volumio[915]: info: Discovery: Getting this device information Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:45 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:45 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 02 16:15:46 volumio volumio[915]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 02 16:15:46 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:15:46 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:15:47 volumio volumio[915]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Nov 02 16:15:47 volumio volumio[915]: info: Retrying Login Due to Network Error Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::volumioGetBrowseSources Nov 02 16:15:47 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 16:15:50 volumio volumio[1047]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 02 16:15:50 volumio volumio[915]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 02 16:15:50 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 02 16:15:50 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 02 16:15:50 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 02 16:15:51 volumio volumio[915]: info: Received Get System Version Nov 02 16:15:51 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 16:15:51 volumio volumio[915]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 02 16:15:51 volumio volumio[915]: info: Completed starting MyVolumio Plugin Nov 02 16:15:51 volumio volumio[915]: info: BOOT COMPLETED Nov 02 16:15:51 volumio volumio[915]: [Metrics] CommandRouter: 89s 419.89ms Nov 02 16:15:51 volumio volumio[915]: info: CoreCommandRouter::volumiosetStartupVolume Nov 02 16:15:51 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 16:15:51 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 16:15:51 volumio volumio[915]: info: CoreCommandRouter::Close All Modals sent Nov 02 16:15:51 volumio volumio[915]: info: CoreCommandRouter::Close All Modals sent Nov 02 16:15:51 volumio volumio[915]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 02 16:15:51 volumio volumio[915]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 02 16:15:51 volumio volumio[915]: info: camilladsp stopping service pid 1840... Nov 02 16:15:51 volumio volumio[915]: info: camilladsp service terminated, instance 1 Nov 02 16:15:51 volumio volumio[915]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 02 16:15:51 volumio volumio[915]: info: camilladsp service started and running in background, instance 1 Nov 02 16:15:51 volumio volumio[915]: info: camilladsp spawned new process with pid 1936, instance 1, run: true Nov 02 16:15:52 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 02 16:15:52 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 02 16:15:52 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 02 16:15:52 volumio volumio[1047]: .....++++ Nov 02 16:15:56 volumio volumio[1047]: .............++++ Nov 02 16:15:56 volumio volumio[1047]: e is 65537 (0x010001) Nov 02 16:15:56 volumio volumio[1047]: writing RSA key Nov 02 16:15:56 volumio dhcpcd[838]: wlan0: hardware address 00:17:13:36:f8:19 claims 192.168.1.123 Nov 02 16:15:56 volumio dhcpcd[838]: wlan0: hardware address 00:17:13:36:f8:19 claims 192.168.1.123 Nov 02 16:15:56 volumio dhcpcd[838]: wlan0: 10 second defence failed for 192.168.1.123 Nov 02 16:15:56 volumio avahi-daemon[517]: Withdrawing address record for 192.168.1.123 on wlan0. Nov 02 16:15:56 volumio avahi-daemon[517]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.123. Nov 02 16:15:56 volumio dhcpcd[838]: eth0: adding default route Nov 02 16:15:56 volumio dhcpcd[838]: wlan0: deleting route to 192.168.1.0/24 Nov 02 16:15:56 volumio dhcpcd[838]: wlan0: deleting default route via 192.168.1.254 Nov 02 16:15:56 volumio avahi-daemon[517]: Interface wlan0.IPv4 no longer relevant for mDNS. Nov 02 16:15:56 volumio volumio[915]: info: Discovery: A device disappeared from network Nov 02 16:15:56 volumio volumio[915]: info: Discovery: Device volumio disappeared from network Nov 02 16:15:57 volumio volumio[915]: info: MyVolumio login type: Token Nov 02 16:15:57 volumio dhcpcd[838]: wlan0: rebinding lease of 192.168.1.123 Nov 02 16:15:57 volumio volumio[915]: info: camilladsp spawned new process with pid 2141, instance 1, run: true Nov 02 16:15:57 volumio dhcpcd[838]: wlan0: probing address 192.168.1.123/24 Nov 02 16:15:58 volumio ntpd[670]: Deleting interface #4 wlan0, 192.168.1.123#123, interface stats: received=19, sent=65, dropped=0, active_time=100 secs Nov 02 16:15:58 volumio ntpd[670]: 217.114.59.66 local addr 192.168.1.123 -> Nov 02 16:15:58 volumio ntpd[670]: 185.53.45.4 local addr 192.168.1.123 -> Nov 02 16:15:58 volumio ntpd[670]: 88.80.189.24 local addr 192.168.1.123 -> Nov 02 16:15:58 volumio ntpd[670]: 213.5.132.231 local addr 192.168.1.123 -> Nov 02 16:15:58 volumio ntpd[670]: 162.159.200.1 local addr 192.168.1.123 -> Nov 02 16:15:58 volumio ntpd[670]: 85.199.214.101 local addr 192.168.1.123 -> Nov 02 16:16:02 volumio dhcpcd[838]: wlan0: leased 192.168.1.123 for 86400 seconds Nov 02 16:16:02 volumio avahi-daemon[517]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.123. Nov 02 16:16:02 volumio avahi-daemon[517]: New relevant interface wlan0.IPv4 for mDNS. Nov 02 16:16:02 volumio dhcpcd[838]: wlan0: adding route to 192.168.1.0/24 Nov 02 16:16:02 volumio avahi-daemon[517]: Registering new address record for 192.168.1.123 on wlan0.IPv4. Nov 02 16:16:02 volumio dhcpcd[838]: wlan0: adding default route via 192.168.1.254 Nov 02 16:16:02 volumio dhcpcd[838]: eth0: deleting default route Nov 02 16:16:02 volumio dhcpcd[789]: eth0: pid 838 deleted default route Nov 02 16:16:03 volumio ntpd[670]: Listen normally on 9 wlan0 192.168.1.123:123 Nov 02 16:16:03 volumio ntpd[670]: 44.31.52.36 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 85.199.214.98 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 85.199.214.101 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 95.215.175.2 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 131.111.8.63 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 185.103.119.60 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 85.199.214.102 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 162.159.200.1 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 213.5.132.231 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 88.80.189.24 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 178.215.228.24 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 185.53.45.4 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 131.111.8.60 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 217.114.59.66 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: 193.57.144.50 local addr 169.254.209.39 -> 192.168.1.123 Nov 02 16:16:03 volumio ntpd[670]: new interface(s) found: waking up resolver Nov 02 16:16:04 volumio volumio[915]: info: Command Delete User Data Received Nov 02 16:16:04 volumio volumio[915]: info: CoreCommandRouter::executeOnPlugin: system , deleteUserData Nov 02 16:16:04 volumio volumio[915]: info: Discovery: adding 271f537b-5f11-47ba-9192-c680fb8f158d Nov 02 16:16:04 volumio volumio[915]: info: Discovery: Found device Volumio Nov 02 16:16:04 volumio volumio[915]: info: CoreCommandRouter::volumioGetState Nov 02 16:16:04 volumio volumio[915]: info: CorePlayQueue::getTrack 0 Nov 02 16:16:04 volumio volumio[915]: info: Created User Data delete file, rebooting Nov 02 16:16:04 volumio volumio[915]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Nov 02 16:16:04 volumio volumio[915]: info: PLUGIN onReboot : networkfs Nov 02 16:16:04 volumio volumio[915]: info: PLUGIN onReboot : audiophonicsonoff Nov 02 16:16:04 volumio volumio[915]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 16:16:04 volumio volumio[915]: TypeError: Cannot read property 'writeSync' of undefined Nov 02 16:16:04 volumio volumio[915]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Nov 02 16:16:04 volumio volumio[915]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Nov 02 16:16:04 volumio volumio[915]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Nov 02 16:16:04 volumio volumio[915]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 02 16:16:04 volumio volumio[915]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 02 16:16:04 volumio volumio[915]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Nov 02 16:16:04 volumio volumio[915]: at CoreCommandRouter.reboot (/volumio/app/index.js:1325:22) Nov 02 16:16:04 volumio volumio[915]: at /volumio/app/plugins/system_controller/system/index.js:710:26 Nov 02 16:16:04 volumio volumio[915]: at /volumio/node_modules/graceful-fs/graceful-fs.js:144:16 Nov 02 16:16:04 volumio volumio[915]: at /data/plugins/system_hardware/gpio-buttons/node_modules/graceful-fs/graceful-fs.js:43:10 Nov 02 16:16:04 volumio volumio[915]: at /volumio/node_modules/graceful-fs/graceful-fs.js:61:14 Nov 02 16:16:04 volumio volumio[915]: at FSReqCallback.oncomplete (fs.js:171:23) Nov 02 16:16:04 volumio volumio[915]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 16:16:05 volumio sudo[2194]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-02 16:15 Nov 02 16:16:05 volumio sudo[2194]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"