-- Logs begin at Wed 2024-07-17 02:00:04 BST, end at Thu 2024-07-18 00:01:42 BST. -- Jul 18 00:00:01 volumiopi3 CRON[22304]: pam_unix(cron:session): session opened for user root by (uid=0) Jul 18 00:00:01 volumiopi3 CRON[22304]: (root) CMD ([22305] cat /dev/null > /etc/mpd.log) Jul 18 00:00:01 volumiopi3 CRON[22304]: (root) END ([22305] cat /dev/null > /etc/mpd.log) Jul 18 00:00:01 volumiopi3 CRON[22304]: pam_unix(cron:session): session closed for user root Jul 18 00:00:03 volumiopi3 nmbd[763]: [2024/07/18 00:00:03.433816, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jul 18 00:00:03 volumiopi3 nmbd[763]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.103 for name WORKGROUP<1d>. Jul 18 00:00:03 volumiopi3 nmbd[763]: This response was from IP 192.168.1.104, reporting an IP address of 192.168.1.104. Jul 18 00:00:08 volumiopi3 systemd[1]: Starting Daily man-db regeneration... Jul 18 00:00:08 volumiopi3 systemd[1]: man-db.service: Succeeded. Jul 18 00:00:08 volumiopi3 systemd[1]: Started Daily man-db regeneration. Jul 18 00:00:17 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 11 Jul 18 00:00:17 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Prefetching next song Jul 18 00:00:17 volumiopi3 volumio[1231]: info: DOING PREFETCH IN MPD Jul 18 00:00:17 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand add "NAS/NAS/SD Card/Pacific 707.mp3" Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Jul 18 00:00:17 volumiopi3 volumio[1231]: ---------------------------- MPD announces system playlist update Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Ignoring MPD Status Update Jul 18 00:00:17 volumiopi3 volumio[1231]: info: sendMpdCommand add "NAS/NAS/SD Card/Pacific 707.mp3" took 3 milliseconds Jul 18 00:00:17 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand consume 1 Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Jul 18 00:00:17 volumiopi3 volumio[1231]: ---------------------------- MPD announces system playlist update Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Ignoring MPD Status Update Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Jul 18 00:00:17 volumiopi3 volumio[1231]: ---------------------------- MPD announces system playlist update Jul 18 00:00:17 volumiopi3 volumio[1231]: info: Ignoring MPD Status Update Jul 18 00:00:17 volumiopi3 volumio[1231]: info: ------------------------------ 11ms Jul 18 00:00:17 volumiopi3 volumio[1231]: info: sendMpdCommand consume 1 took 9 milliseconds Jul 18 00:00:17 volumiopi3 volumio[1231]: info: ------------------------------ 9ms Jul 18 00:00:17 volumiopi3 volumio[1231]: info: ------------------------------ 8ms Jul 18 00:00:21 volumiopi3 volumio[1231]: info: CoreStateMachine::startPlaybackTimer Jul 18 00:00:21 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Jul 18 00:00:22 volumiopi3 volumio[1231]: ---------------------------- MPD announces system playlist update Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Ignoring MPD Status Update Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Jul 18 00:00:22 volumiopi3 volumio[1231]: ---------------------------- MPD announces state update: player Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ControllerMpd::getState Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand status Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Jul 18 00:00:22 volumiopi3 volumio[1231]: ---------------------------- MPD announces system playlist update Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Ignoring MPD Status Update Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Jul 18 00:00:22 volumiopi3 volumio[1231]: ---------------------------- MPD announces state update: player Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ControllerMpd::getState Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand status Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Jul 18 00:00:22 volumiopi3 volumio[1231]: ---------------------------- MPD announces system playlist update Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Ignoring MPD Status Update Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Jul 18 00:00:22 volumiopi3 volumio[1231]: ---------------------------- MPD announces state update: player Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ControllerMpd::getState Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand status Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ------------------------------ 20ms Jul 18 00:00:22 volumiopi3 volumio[1231]: info: sendMpdCommand status took 19 milliseconds Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ------------------------------ 19ms Jul 18 00:00:22 volumiopi3 volumio[1231]: info: sendMpdCommand status took 14 milliseconds Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ------------------------------ 14ms Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::parseState Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::parseState Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 00:00:22 volumiopi3 volumio[1231]: info: sendMpdCommand status took 14 milliseconds Jul 18 00:00:22 volumiopi3 volumio[1231]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 18 00:00:22 volumiopi3 volumio[1231]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::parseState Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::parseTrackInfo Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::parseTrackInfo Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ControllerMpd::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::servicePushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":229,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Pacific 707","artist":"808 State","album":"Q - essential dance","uri":"NAS/NAS/SD Card/Pacific 707.mp3","trackType":"mp3"} Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: CURRENT POSITION 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::syncState stateService play Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::syncState currentStatus play Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Received an update from plugin. extracting info from payload Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ControllerMpd::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::servicePushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":229,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Pacific 707","artist":"808 State","album":"Q - essential dance","uri":"NAS/NAS/SD Card/Pacific 707.mp3","trackType":"mp3"} Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: CURRENT POSITION 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::syncState stateService play Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::syncState currentStatus play Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Received an update from plugin. extracting info from payload Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ------------------------------ 103ms Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ------------------------------ 101ms Jul 18 00:00:22 volumiopi3 volumio[1231]: info: sendMpdCommand playlistinfo took 77 milliseconds Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: ControllerMpd::parseTrackInfo Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ControllerMpd::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::servicePushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":229,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Pacific 707","artist":"808 State","album":"Q - essential dance","uri":"NAS/NAS/SD Card/Pacific 707.mp3","trackType":"mp3"} Jul 18 00:00:22 volumiopi3 volumio[1231]: verbose: CURRENT POSITION 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::syncState stateService play Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::syncState currentStatus play Jul 18 00:00:22 volumiopi3 volumio[1231]: info: Received an update from plugin. extracting info from payload Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreStateMachine::pushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:22 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioPushState Jul 18 00:00:22 volumiopi3 volumio[1231]: info: ------------------------------ 138ms Jul 18 00:00:36 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 18 00:00:36 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 18 00:00:36 volumiopi3 volumio[1231]: info: Discovery: Getting this device information Jul 18 00:00:36 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioGetState Jul 18 00:00:36 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:36 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 00:00:45 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 18 00:00:45 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 18 00:00:45 volumiopi3 volumio[1231]: info: Discovery: Getting this device information Jul 18 00:00:45 volumiopi3 volumio[1231]: info: CoreCommandRouter::volumioGetState Jul 18 00:00:45 volumiopi3 volumio[1231]: info: CorePlayQueue::getTrack 12 Jul 18 00:00:45 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 00:00:52 volumiopi3 volumio[1231]: Searching plugin music_service/mpd Jul 18 00:00:52 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jul 18 00:00:54 volumiopi3 volumio[1231]: info: All search sources collected, pushing search results Jul 18 00:00:58 volumiopi3 volumio[1231]: Searching plugin music_service/mpd Jul 18 00:00:58 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jul 18 00:01:00 volumiopi3 volumio[1231]: Searching plugin music_service/mpd Jul 18 00:01:00 volumiopi3 volumio[1231]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jul 18 00:01:03 volumiopi3 volumio[1231]: Upnp client error: Error: This socket has been ended by the other party Jul 18 00:01:03 volumiopi3 volumio[1231]: Upnp client error: Error: This socket has been ended by the other party Jul 18 00:01:11 volumiopi3 volumio[1231]: Cannot compose Albumart path Jul 18 00:01:12 volumiopi3 volumio[1231]: Upnp client error: Error: This socket has been ended by the other party Jul 18 00:01:19 volumiopi3 volumio[1231]: Cannot compose Albumart path Jul 18 00:01:20 volumiopi3 volumio[1231]: info: All search sources collected, pushing search results Jul 18 00:01:22 volumiopi3 volumio[1231]: <--- Last few GCs ---> Jul 18 00:01:22 volumiopi3 volumio[1231]: [1231:0x3c2c788] 79233416 ms: Scavenge (reduce) 194.0 (211.2) -> 194.0 (211.2) MB, 22.4 / 0.0 ms (average mu = 0.881, current mu = 0.942) allocation failure Jul 18 00:01:22 volumiopi3 volumio[1231]: [1231:0x3c2c788] 79233517 ms: Scavenge (reduce) 197.8 (212.9) -> 197.7 (212.9) MB, 16.5 / 0.0 ms (average mu = 0.881, current mu = 0.942) allocation failure Jul 18 00:01:22 volumiopi3 volumio[1231]: [1231:0x3c2c788] 79233571 ms: Scavenge (reduce) 201.6 (216.8) -> 201.5 (216.8) MB, 2.2 / 0.0 ms (average mu = 0.881, current mu = 0.942) allocation failure Jul 18 00:01:22 volumiopi3 volumio[1231]: <--- JS stacktrace ---> Jul 18 00:01:22 volumiopi3 volumio[1231]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory Jul 18 00:01:22 volumiopi3 volumio-remote-updater[613]: [2024-07-18 00:01:22] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 18 00:01:22 volumiopi3 systemd[1]: volumio.service: Main process exited, code=killed, status=6/ABRT Jul 18 00:01:22 volumiopi3 systemd[1]: volumio.service: Failed with result 'signal'. Jul 18 00:01:22 volumiopi3 volumio-remote-updater[613]: [2024-07-18 00:01:22] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 18 00:01:23 volumiopi3 systemd[1]: Started dynamicswap service. Jul 18 00:01:23 volumiopi3 systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jul 18 00:01:23 volumiopi3 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Jul 18 00:01:23 volumiopi3 systemd[1]: Stopped Volumio Backend Module. Jul 18 00:01:23 volumiopi3 systemd[1]: Started Volumio Backend Module. Jul 18 00:01:23 volumiopi3 systemd[1]: dynamicswap.service: Succeeded. Jul 18 00:01:27 volumiopi3 volumio[22502]: info: ------------------------------------------- Jul 18 00:01:27 volumiopi3 volumio[22502]: info: ----- Volumio3 ---- Jul 18 00:01:27 volumiopi3 volumio[22502]: info: ------------------------------------------- Jul 18 00:01:27 volumiopi3 volumio[22502]: info: ----- System startup ---- Jul 18 00:01:27 volumiopi3 volumio[22502]: info: ------------------------------------------- Jul 18 00:01:27 volumiopi3 volumio-remote-updater[613]: [2024-07-18 00:01:27] [connect] Successful connection Jul 18 00:01:28 volumiopi3 volumio[22502]: info: MYVOLUMIO Environment detected Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Plugin folders cleanup Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning into folder /volumio/app/plugins/ Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category audio_interface Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category miscellanea Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category music_service Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category plugins.json Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category system_controller Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category user_interface Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning into folder /data/plugins/ Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category music_service Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category system_controller Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Scanning category user_interface Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Plugin folders cleanup completed Jul 18 00:01:29 volumiopi3 volumio[22502]: info: ------------------------------------------- Jul 18 00:01:29 volumiopi3 volumio[22502]: info: ----- Core plugins startup ---- Jul 18 00:01:29 volumiopi3 volumio[22502]: info: ------------------------------------------- Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Loading plugins from folder /volumio/app/plugins/ Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Adding plugin upnp to MyMusic Plugins Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Loading plugins from folder /data/plugins/ Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Loading plugin "system"... Jul 18 00:01:29 volumiopi3 volumio[22502]: info: Loading plugin "appearance"... Jul 18 00:01:30 volumiopi3 volumio[22502]: info: Loading plugin "network"... Jul 18 00:01:30 volumiopi3 volumio[22502]: info: Refreshing Cached IP Addresses Jul 18 00:01:30 volumiopi3 volumio[22502]: info: Loading plugin "services"... Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "alsa_controller"... Jul 18 00:01:31 volumiopi3 sudo[22526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 00:01:31 volumiopi3 sudo[22528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 00:01:31 volumiopi3 sudo[22530]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 18 00:01:31 volumiopi3 sudo[22528]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:31 volumiopi3 sudo[22530]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:31 volumiopi3 sudo[22526]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:31 volumiopi3 sudo[22528]: pam_unix(sudo:session): session closed for user root Jul 18 00:01:31 volumiopi3 sudo[22526]: pam_unix(sudo:session): session closed for user root Jul 18 00:01:31 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "wizard"... Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "networkfs"... Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Starting Udev Watcher for removable devices Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Ignoring mount for partition: boot Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Ignoring mount for partition: volumio Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Ignoring mount for partition: volumio_data Jul 18 00:01:31 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "volumio_command_line_client"... Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "upnp"... Jul 18 00:01:31 volumiopi3 volumio[22502]: info: [1721257291444] Starting Upmpd Daemon Jul 18 00:01:31 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "my_music"... Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "mpd"... Jul 18 00:01:31 volumiopi3 sudo[22530]: pam_unix(sudo:session): session closed for user root Jul 18 00:01:31 volumiopi3 volumio[22502]: info: Loading plugin "upnp_browser"... Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Loading plugin "alarm-clock"... Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Loading plugin "airplay_emulation"... Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Starting Shairport Sync Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Loading plugin "last_100"... Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Loading plugin "webradio"... Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Loading plugin "i2s_dacs"... Jul 18 00:01:32 volumiopi3 volumio[22502]: info: I2S DAC not set, start Auto-detection Jul 18 00:01:32 volumiopi3 volumio[22502]: info: Loading plugin "volumiodiscovery"... Jul 18 00:01:33 volumiopi3 volumio[22502]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 00:01:33 volumiopi3 volumio[22502]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 00:01:33 volumiopi3 volumio[22502]: *** WARNING *** For more information see Jul 18 00:01:33 volumiopi3 volumio[22502]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 00:01:33 volumiopi3 volumio[22502]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 00:01:33 volumiopi3 node[22502]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 00:01:33 volumiopi3 volumio[22502]: *** WARNING *** For more information see Jul 18 00:01:33 volumiopi3 node[22502]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 00:01:33 volumiopi3 node[22502]: *** WARNING *** For more information see Jul 18 00:01:33 volumiopi3 node[22502]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 00:01:33 volumiopi3 node[22502]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 00:01:33 volumiopi3 node[22502]: *** WARNING *** For more information see Jul 18 00:01:33 volumiopi3 volumio[22502]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 18 00:01:33 volumiopi3 volumio[22502]: info: Discovery: Started advertising with name: VolumioPi3 Jul 18 00:01:33 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 00:01:33 volumiopi3 volumio[22502]: info: Plugin ytmusic is not enabled Jul 18 00:01:33 volumiopi3 volumio[22502]: info: Loading plugin "autostart"... Jul 18 00:01:33 volumiopi3 volumio[22502]: info: Applying required configuration parameters for plugin autostart Jul 18 00:01:33 volumiopi3 volumio[22502]: info: AutoStart - onVolumioStart - read config.json Jul 18 00:01:33 volumiopi3 volumio[22502]: info: Loading plugin "now_playing"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "outputs"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "albumart"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Plugin example_plugin is not enabled Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "inputs"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "updater_comm"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Plugin mpdemulation is not enabled Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "rest_api"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "websocket"... Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Starting Socket.io Server version 2.3.0 Jul 18 00:01:35 volumiopi3 volumio[22502]: info: Loading plugin "podcast"... Jul 18 00:01:35 volumiopi3 volumio[22502]: Forking 3 albumart workers Jul 18 00:01:36 volumiopi3 volumio[22502]: info: ControllerPodcast::constructor Jul 18 00:01:36 volumiopi3 volumio[22502]: info: Loading plugin "backup_restore"... Jul 18 00:01:36 volumiopi3 volumio[22502]: info: Applying required configuration parameters for plugin backup_restore Jul 18 00:01:36 volumiopi3 volumio[22502]: info: Loading plugin "Systeminfo"... Jul 18 00:01:37 volumiopi3 volumio[22502]: Starting albumart workers Jul 18 00:01:37 volumiopi3 volumio[22502]: Starting albumart workers Jul 18 00:01:37 volumiopi3 volumio[22502]: Starting albumart workers Jul 18 00:01:37 volumiopi3 volumio[22502]: info: Loading plugin "touch_display"... Jul 18 00:01:38 volumiopi3 volumio[22502]: info: Applying required configuration parameters for plugin touch_display Jul 18 00:01:38 volumiopi3 volumio[22502]: info: Loading i18n strings for locale en Jul 18 00:01:38 volumiopi3 volumio[22502]: Updating browse sources language Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::initPlayerControls Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 00:01:38 volumiopi3 volumio[22502]: Express server listening on port 3000 Jul 18 00:01:38 volumiopi3 volumio[22502]: [Metrics] WebUI: 12s 318.71ms Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreStateMachine::resetVolumioState Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreStateMachine::getcurrentVolume Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 00:01:38 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Jul 18 00:01:39 volumiopi3 volumio[22502]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'Headphone',0 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 1 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 2 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 3 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 4 Jul 18 00:01:39 volumiopi3 volumio[22502]: 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 Engine version: 3 Transport: polling Total Clients: 5 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: polling Total Clients: 6 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 7 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 8 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 9 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 10 Jul 18 00:01:39 volumiopi3 volumio[22502]: 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 Engine version: 3 Transport: polling Total Clients: 11 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 12 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 13 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: polling Total Clients: 14 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 15 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 16 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 17 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 18 Jul 18 00:01:39 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: VolumeController:: Volume=undefined Mute =false Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::pushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioPushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::updateTrackBlock Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrackBlock Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::setRepeat null single undefined Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::pushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioPushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::setRandom null Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::pushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioPushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Setting Device type: Raspberry PI Jul 18 00:01:39 volumiopi3 volumio[22502]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'Headphone',0 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: VolumeController:: Volume=undefined Mute =false Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreStateMachine::pushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioPushState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Discovery: adding fb7ba525-c46e-4e9e-bdc0-794eb0667df1 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Discovery: Found device VolumioPi3 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioGetState Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Completed loading Core Plugins Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Preparing to generate the ALSA configuration file Jul 18 00:01:39 volumiopi3 volumio[22502]: 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 Engine version: 3 Transport: polling Total Clients: 20 Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Asound.conf file unchanged, so no further update is needed Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Output device has changed, restarting MPD Jul 18 00:01:39 volumiopi3 sudo[22606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 00:01:39 volumiopi3 volumio[22502]: info: Output device has changed, restarting Shairport Sync Jul 18 00:01:39 volumiopi3 sudo[22606]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:39 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:39 volumiopi3 sudo[22606]: pam_unix(sudo:session): session closed for user root Jul 18 00:01:39 volumiopi3 sudo[22608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 00:01:39 volumiopi3 sudo[22608]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 00:01:40 volumiopi3 volumio[22502]: info: ___________ START PLUGINS ___________ Jul 18 00:01:40 volumiopi3 volumio[22502]: info: ControllerMpd::onStart: Initializing MPD Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Creating MPD Configuration file Jul 18 00:01:40 volumiopi3 systemd[1]: Stopping Music Player Daemon... Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 00:01:40 volumiopi3 sudo[22616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 00:01:40 volumiopi3 sudo[22616]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 00:01:40 volumiopi3 volumio[22502]: info: [1721257300126] CoreMusicLibrary::Adding element Media Servers Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 00:01:40 volumiopi3 sudo[22616]: pam_unix(sudo:session): session closed for user root Jul 18 00:01:40 volumiopi3 sudo[22618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 00:01:40 volumiopi3 sudo[22618]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 00:01:40 volumiopi3 volumio[22502]: info: [1721257300328] CoreMusicLibrary::Adding element Last_100 Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 00:01:40 volumiopi3 volumio[22502]: info: [1721257300332] CoreMusicLibrary::Adding element Webradio Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Initializing BBC Radios Jul 18 00:01:40 volumiopi3 volumio-remote-updater[613]: [2024-07-18 00:01:40] [connect] Successful connection Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:40 volumiopi3 volumio[22502]: info: AutoStart - onStart Jul 18 00:01:40 volumiopi3 volumio[22502]: info: [now-playing-config] Config is up to date. Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Discovery: Getting this device information Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioGetState Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 00:01:40 volumiopi3 volumio[22502]: info: [1721257300546] CoreMusicLibrary::Adding element Podcast Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 00:01:40 volumiopi3 volumio[22502]: Cannot find translation for source Podcast Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Loading i18n strings for locale en Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 00:01:40 volumiopi3 volumio[22502]: info: Volumio Calling Home Jul 18 00:01:40 volumiopi3 volumio[22502]: info: [now-playing-app] App is listening on port 4004. Jul 18 00:01:40 volumiopi3 sudo[22640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jul 18 00:01:40 volumiopi3 sudo[22640]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 00:01:40 volumiopi3 systemd[1]: Reloading. Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 18 00:01:40 volumiopi3 volumio[22502]: info: MPD Permissions set Jul 18 00:01:40 volumiopi3 volumio[22502]: info: MPD Permissions set Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioGetVisibleSources Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioGetState Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:40 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 18 00:01:41 volumiopi3 volumio[22502]: info: Received Get System Info Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 18 00:01:41 volumiopi3 volumio[22502]: info: Discovery: Getting this device information Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioGetState Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::volumioGetState Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CorePlayQueue::getTrack 0 Jul 18 00:01:41 volumiopi3 volumio[22502]: info: Listing playlists Jul 18 00:01:41 volumiopi3 volumio-remote-updater[613]: [2024-07-18 00:01:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1721257300 101 Jul 18 00:01:41 volumiopi3 volumio[22502]: 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: 21 Jul 18 00:01:41 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 22 Jul 18 00:01:41 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to 192.168.1.103 from 192.168.1.100 UA: okhttp/4.9.2 Engine version: 3 Transport: polling Total Clients: 23 Jul 18 00:01:41 volumiopi3 volumio[22502]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 00:01:41 volumiopi3 volumio[22502]: Searching plugin music_service/mpd Jul 18 00:01:41 volumiopi3 volumio[22502]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jul 18 00:01:41 volumiopi3 volumio[22502]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 00:01:41 volumiopi3 volumio[22502]: TypeError: Cannot read property 'then' of undefined Jul 18 00:01:41 volumiopi3 volumio[22502]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1582:17) Jul 18 00:01:41 volumiopi3 volumio[22502]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1083:32) Jul 18 00:01:41 volumiopi3 volumio[22502]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:477:37) Jul 18 00:01:41 volumiopi3 volumio[22502]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:478:44) Jul 18 00:01:41 volumiopi3 volumio[22502]: at Socket.emit (events.js:315:20) Jul 18 00:01:41 volumiopi3 volumio[22502]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 18 00:01:41 volumiopi3 volumio[22502]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jul 18 00:01:41 volumiopi3 volumio[22502]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 00:01:42 volumiopi3 sudo[22674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-18 00:00 Jul 18 00:01:42 volumiopi3 sudo[22674]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"