-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Sat 2024-03-30 19:52:53 EDT. -- Mar 30 19:51:00 volumio volumio[805]: info: Get:17 http://mirror.umd.edu/raspbian/raspbian buster/main armhf make armhf 4.2.1-1.2 [321 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:18 http://mirror.umd.edu/raspbian/raspbian buster/main armhf patch armhf 2.7.6-3+deb10u1 [115 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:19 http://mirror.umd.edu/raspbian/raspbian buster/main armhf dpkg-dev all 1.19.8 [1776 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:20 http://mirror.umd.edu/raspbian/raspbian buster/main armhf build-essential armhf 12.6 [7568 B] Mar 30 19:51:00 volumio volumio[805]: info: Get:21 http://mirror.umd.edu/raspbian/raspbian buster/main armhf dh-python all 3.20190308 [99.3 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:22 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libfakeroot armhf 1.23-1 [43.3 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:23 http://mirror.umd.edu/raspbian/raspbian buster/main armhf fakeroot armhf 1.23-1 [85.2 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:24 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libalgorithm-diff-perl all 1.19.03-2 [47.9 kB] Mar 30 19:51:00 volumio volumio[805]: info: Get:25 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libalgorithm-diff-xs-perl armhf 0.04-5+b1 [11.4 kB] Mar 30 19:51:01 volumio volumio[805]: info: Get:26 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libalgorithm-merge-perl all 0.08-3 [12.7 kB] Mar 30 19:51:01 volumio volumio[805]: info: Get:27 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libexpat1-dev armhf 2.2.6-2+deb10u6 [134 kB] Mar 30 19:51:02 volumio volumio[805]: info: Get:28 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libpython3.7 armhf 3.7.3-2+deb10u7 [1252 kB] Mar 30 19:51:02 volumio volumio[805]: info: Get:29 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libpython3.7-dev armhf 3.7.3-2+deb10u7 [47.2 MB] Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: metavolumio , setInfinityPlayback Mar 30 19:51:14 volumio volumio[805]: info: METAVOLUMIO: Enabling Infinity Playback Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:14 volumio volumio[805]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::volumioRandom Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::writePlayerControls Mar 30 19:51:14 volumio volumio[805]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:14 volumio volumio[805]: info: CoreStateMachine::setRepeat false single false Mar 30 19:51:14 volumio volumio[805]: info: CoreStateMachine::pushState Mar 30 19:51:14 volumio volumio[805]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:51:14 volumio volumio[805]: info: CoreCommandRouter::volumioPushState Mar 30 19:51:14 volumio volumio[805]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:51:14 volumio volumio[805]: info: MRS: Pushing multiroomSync output Mar 30 19:51:14 volumio volumio[805]: info: Get:30 http://mirror.umd.edu/raspbian/raspbian buster/main armhf libpython3-dev armhf 3.7.3-1 [20.1 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:31 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-multidict armhf 4.5.2-1 [52.9 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:32 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-yarl armhf 1.3.0-1 [44.0 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:33 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-async-timeout all 3.0.1-1 [6292 B] Mar 30 19:51:14 volumio volumio[805]: info: Get:34 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-attr all 18.2.0-1 [37.3 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:35 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-aiohttp armhf 3.5.1-1+deb10u1 [241 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:36 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-asn1crypto all 0.24.0-1 [78.2 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:37 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-cffi-backend armhf 1.12.2-1 [70.1 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:38 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-crypto armhf 2.6.1-9+b1 [251 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:39 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-cryptography armhf 2.6.1-3+deb10u4 [184 kB] Mar 30 19:51:14 volumio volumio[805]: info: Get:40 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-dbus armhf 1.2.8-3 [95.9 kB] Mar 30 19:51:15 volumio volumio[805]: info: Get:41 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3.7-dev armhf 3.7.3-2+deb10u7 [527 kB] Mar 30 19:51:15 volumio volumio[805]: info: Get:42 http://raspbian.raspberrypi.org/raspbian buster/main armhf python3-dev armhf 3.7.3-1 [1264 B] Mar 30 19:51:15 volumio volumio[805]: info: Get:43 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-entrypoints all 0.3-1 [5508 B] Mar 30 19:51:16 volumio volumio[805]: info: Get:44 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-gi armhf 3.30.4-1 [161 kB] Mar 30 19:51:16 volumio volumio[805]: info: Get:45 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-secretstorage all 2.3.1-2 [14.2 kB] Mar 30 19:51:16 volumio volumio[805]: info: Get:46 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-keyring all 17.1.1-1 [43.1 kB] Mar 30 19:51:17 volumio volumio[805]: info: Get:47 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-keyrings.alt all 3.1.1-1 [18.2 kB] Mar 30 19:51:17 volumio volumio[805]: info: Get:48 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-setuptools all 40.8.0-1 [306 kB] Mar 30 19:51:17 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: metavolumio , setInfinityPlayback Mar 30 19:51:17 volumio volumio[805]: info: METAVOLUMIO: Disabling Infinity Playback Mar 30 19:51:17 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 30 19:51:17 volumio volumio[805]: info: CoreCommandRouter::volumioRandom Mar 30 19:51:17 volumio volumio[805]: info: CoreCommandRouter::writePlayerControls Mar 30 19:51:17 volumio volumio[805]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:17 volumio volumio[805]: info: CoreStateMachine::setRepeat false single false Mar 30 19:51:17 volumio volumio[805]: info: CoreStateMachine::pushState Mar 30 19:51:17 volumio volumio[805]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:17 volumio volumio[805]: info: CoreCommandRouter::volumioPushState Mar 30 19:51:17 volumio volumio[805]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:51:17 volumio volumio[805]: info: MRS: Pushing multiroomSync output Mar 30 19:51:18 volumio volumio[805]: info: Get:50 http://mirror.umd.edu/raspbian/raspbian buster/main armhf python3-xdg all 0.25-5 [35.9 kB] Mar 30 19:51:18 volumio volumio[805]: info: Get:49 http://mirrors.ocf.berkeley.edu/raspbian/raspbian buster/main armhf python3-wheel all 0.32.3-2 [19.4 kB] Mar 30 19:51:19 volumio volumio[805]: info: Fetched 76.2 MB in 33s (2328 kB/s) Mar 30 19:51:19 volumio volumio[805]: [620B blob data] Mar 30 19:51:19 volumio volumio[805]: info: Preparing to unpack .../00-python3.7_3.7.3-2+deb10u7_armhf.deb ... Mar 30 19:51:19 volumio volumio[805]: info: Unpacking python3.7 (3.7.3-2+deb10u7) over (3.7.3-2+deb10u6) ... Mar 30 19:51:19 volumio volumio[805]: info: Preparing to unpack .../01-libpython3.7-stdlib_3.7.3-2+deb10u7_armhf.deb ... Mar 30 19:51:20 volumio volumio[805]: info: Unpacking libpython3.7-stdlib:armhf (3.7.3-2+deb10u7) over (3.7.3-2+deb10u6) ... Mar 30 19:51:21 volumio volumio[805]: info: CoreCommandRouter::volumioGetQueue Mar 30 19:51:21 volumio volumio[805]: info: CoreStateMachine::getQueue Mar 30 19:51:21 volumio volumio[805]: info: CorePlayQueue::getQueue Mar 30 19:51:24 volumio volumio[805]: info: Preparing to unpack .../02-python3.7-minimal_3.7.3-2+deb10u7_armhf.deb ... Mar 30 19:51:24 volumio volumio[805]: info: Unpacking python3.7-minimal (3.7.3-2+deb10u7) over (3.7.3-2+deb10u6) ... Mar 30 19:51:25 volumio volumio[805]: info: Preparing to unpack .../03-libpython3.7-minimal_3.7.3-2+deb10u7_armhf.deb ... Mar 30 19:51:25 volumio volumio[805]: info: Unpacking libpython3.7-minimal:armhf (3.7.3-2+deb10u7) over (3.7.3-2+deb10u6) ... Mar 30 19:51:27 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:27 volumio volumio[805]: info: Preload queue cleared Mar 30 19:51:28 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:28 volumio volumio[805]: info: Preload queue cleared Mar 30 19:51:29 volumio volumio[805]: info: Selecting previously unselected package bzip2. Mar 30 19:51:29 volumio volumio[805]: info: Preparing to unpack .../04-bzip2_1.0.6-9.2~deb10u2_armhf.deb ... Mar 30 19:51:29 volumio volumio[805]: info: Unpacking bzip2 (1.0.6-9.2~deb10u2) ... Mar 30 19:51:29 volumio volumio[805]: info: Selecting previously unselected package libcc1-0:armhf. Mar 30 19:51:29 volumio volumio[805]: info: Preparing to unpack .../05-libcc1-0_8.3.0-6+rpi1_armhf.deb ... Mar 30 19:51:29 volumio volumio[805]: info: Unpacking libcc1-0:armhf (8.3.0-6+rpi1) ... Mar 30 19:51:29 volumio volumio[805]: info: Selecting previously unselected package libasan5:armhf. Mar 30 19:51:29 volumio volumio[805]: info: Preparing to unpack .../06-libasan5_8.3.0-6+rpi1_armhf.deb ... Mar 30 19:51:29 volumio volumio[805]: info: Unpacking libasan5:armhf (8.3.0-6+rpi1) ... Mar 30 19:51:29 volumio volumio[805]: info: Selecting previously unselected package libubsan1:armhf. Mar 30 19:51:29 volumio volumio[805]: info: Preparing to unpack .../07-libubsan1_8.3.0-6+rpi1_armhf.deb ... Mar 30 19:51:29 volumio volumio[805]: info: Unpacking libubsan1:armhf (8.3.0-6+rpi1) ... Mar 30 19:51:29 volumio volumio[805]: info: Selecting previously unselected package libgcc-8-dev:armhf. Mar 30 19:51:29 volumio volumio[805]: info: Preparing to unpack .../08-libgcc-8-dev_8.3.0-6+rpi1_armhf.deb ... Mar 30 19:51:29 volumio volumio[805]: info: Unpacking libgcc-8-dev:armhf (8.3.0-6+rpi1) ... Mar 30 19:51:30 volumio volumio[805]: info: Selecting previously unselected package gcc-8. Mar 30 19:51:30 volumio volumio[805]: info: Preparing to unpack .../09-gcc-8_8.3.0-6+rpi1_armhf.deb ... Mar 30 19:51:30 volumio volumio[805]: info: Unpacking gcc-8 (8.3.0-6+rpi1) ... Mar 30 19:51:30 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:31 volumio volumio[805]: info: Preload queue cleared Mar 30 19:51:33 volumio volumio[805]: info: Selecting previously unselected package gcc. Mar 30 19:51:33 volumio volumio[805]: info: Preparing to unpack .../10-gcc_4%3a8.3.0-1+rpi2_armhf.deb ... Mar 30 19:51:33 volumio volumio[805]: info: Unpacking gcc (4:8.3.0-1+rpi2) ... Mar 30 19:51:33 volumio volumio[805]: info: Selecting previously unselected package libstdc++-8-dev:armhf. Mar 30 19:51:33 volumio volumio[805]: info: Preparing to unpack .../11-libstdc++-8-dev_8.3.0-6+rpi1_armhf.deb ... Mar 30 19:51:33 volumio volumio[805]: info: Unpacking libstdc++-8-dev:armhf (8.3.0-6+rpi1) ... Mar 30 19:51:33 volumio volumio[805]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:33 volumio volumio[805]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 30 19:51:33 volumio volumio[805]: TypeError: Cannot read property 'length' of undefined Mar 30 19:51:33 volumio volumio[805]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Mar 30 19:51:33 volumio volumio[805]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Mar 30 19:51:33 volumio volumio[805]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Mar 30 19:51:33 volumio volumio[805]: at Parser.emit (events.js:315:20) Mar 30 19:51:33 volumio volumio[805]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Mar 30 19:51:33 volumio volumio[805]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Mar 30 19:51:33 volumio volumio[805]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Mar 30 19:51:33 volumio volumio[805]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Mar 30 19:51:33 volumio volumio[805]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Mar 30 19:51:33 volumio volumio[805]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Mar 30 19:51:33 volumio volumio[805]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Mar 30 19:51:33 volumio volumio[805]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Mar 30 19:51:33 volumio volumio[805]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Mar 30 19:51:33 volumio volumio[805]: at IncomingMessage.emit (events.js:327:22) Mar 30 19:51:33 volumio volumio[805]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 30 19:51:33 volumio volumio[805]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 30 19:51:33 volumio volumio[805]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 30 19:51:33 volumio sudo[7736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-30 19:50 Mar 30 19:51:33 volumio sudo[7736]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:34 volumio sudo[7736]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:34 volumio vtcs[2209]: [2024-03-30 19:51:34.720] [tisoc] [error] [SpkconServer.cpp:377] recv error. socket disconnected Mar 30 19:51:34 volumio volumio-remote-updater[1416]: [2024-03-30 19:51:34] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 30 19:51:34 volumio volumio-remote-updater[1416]: [2024-03-30 19:51:34] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 30 19:51:34 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 30 19:51:34 volumio systemd[1]: upmpdcli.service: Succeeded. Mar 30 19:51:34 volumio sudo[7254]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:34 volumio sudo[7536]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:34 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 30 19:51:34 volumio systemd[1]: Started dynamicswap service. Mar 30 19:51:34 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 30 19:51:34 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 30 19:51:34 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Mar 30 19:51:35 volumio systemd[1]: Started dynamicswap service. Mar 30 19:51:35 volumio systemd[1]: Stopped Volumio Backend Module. Mar 30 19:51:35 volumio systemd[1]: Started Volumio Backend Module. Mar 30 19:51:35 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 30 19:51:36 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:51:36 volumio volumio[7752]: info: ----- Volumio3 ---- Mar 30 19:51:36 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:51:36 volumio volumio[7752]: info: ----- System startup ---- Mar 30 19:51:36 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:51:36 volumio volumio[7752]: info: MYVOLUMIO Environment detected Mar 30 19:51:36 volumio volumio[7752]: info: Plugin folders cleanup Mar 30 19:51:36 volumio volumio[7752]: info: Scanning into folder /volumio/app/plugins/ Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category audio_interface Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category miscellanea Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category music_service Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category plugins.json Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category system_controller Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category user_interface Mar 30 19:51:36 volumio volumio[7752]: info: Scanning into folder /data/plugins/ Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category audio_interface Mar 30 19:51:36 volumio volumio[7752]: info: Scanning category user_interface Mar 30 19:51:36 volumio volumio[7752]: info: Plugin folders cleanup completed Mar 30 19:51:36 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:51:36 volumio volumio[7752]: info: ----- Core plugins startup ---- Mar 30 19:51:36 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:51:36 volumio volumio[7752]: info: Loading plugins from folder /volumio/app/plugins/ Mar 30 19:51:36 volumio volumio[7752]: info: Adding plugin upnp to MyMusic Plugins Mar 30 19:51:36 volumio volumio[7752]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 30 19:51:36 volumio volumio[7752]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 30 19:51:36 volumio volumio[7752]: info: Loading plugins from folder /data/plugins/ Mar 30 19:51:36 volumio volumio[7752]: info: Loading plugin "system"... Mar 30 19:51:36 volumio volumio[7752]: info: Loading plugin "appearance"... Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "network"... Mar 30 19:51:37 volumio volumio[7752]: info: Refreshing Cached IP Addresses Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "services"... Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "alsa_controller"... Mar 30 19:51:37 volumio sudo[7779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 30 19:51:37 volumio sudo[7779]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:37 volumio sudo[7779]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:37 volumio sudo[7782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 30 19:51:37 volumio sudo[7782]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:37 volumio sudo[7781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 30 19:51:37 volumio sudo[7781]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:37 volumio sudo[7781]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:37 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "wizard"... Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "networkfs"... Mar 30 19:51:37 volumio volumio[7752]: info: Starting Udev Watcher for removable devices Mar 30 19:51:37 volumio volumio[7752]: info: Ignoring mount for partition: boot Mar 30 19:51:37 volumio volumio[7752]: info: Ignoring mount for partition: volumio Mar 30 19:51:37 volumio volumio[7752]: info: Ignoring mount for partition: volumio_data Mar 30 19:51:37 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "volumio_command_line_client"... Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "upnp"... Mar 30 19:51:37 volumio volumio[7752]: info: [1711842697919] Starting Upmpd Daemon Mar 30 19:51:37 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "my_music"... Mar 30 19:51:37 volumio volumio[7752]: info: Loading plugin "mpd"... Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "upnp_browser"... Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "alarm-clock"... Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "airplay_emulation"... Mar 30 19:51:38 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "last_100"... Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "webradio"... Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "i2s_dacs"... Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "volumiodiscovery"... Mar 30 19:51:38 volumio volumio[7752]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 30 19:51:38 volumio volumio[7752]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 30 19:51:38 volumio node[7752]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 30 19:51:38 volumio volumio[7752]: *** WARNING *** For more information see Mar 30 19:51:38 volumio volumio[7752]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 30 19:51:38 volumio volumio[7752]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 30 19:51:38 volumio volumio[7752]: *** WARNING *** For more information see Mar 30 19:51:38 volumio node[7752]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 30 19:51:38 volumio node[7752]: *** WARNING *** For more information see Mar 30 19:51:38 volumio node[7752]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 30 19:51:38 volumio node[7752]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 30 19:51:38 volumio node[7752]: *** WARNING *** For more information see Mar 30 19:51:38 volumio volumio[7752]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 30 19:51:38 volumio volumio[7752]: info: Discovery: Started advertising with name: Volumio Mar 30 19:51:38 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 30 19:51:38 volumio volumio[7752]: info: Loading plugin "now_playing"... Mar 30 19:51:39 volumio volumio-remote-updater[1416]: [2024-03-30 19:51:39] [connect] Successful connection Mar 30 19:51:39 volumio volumio[7752]: info: Loading plugin "outputs"... Mar 30 19:51:39 volumio volumio[7752]: info: Loading plugin "albumart"... Mar 30 19:51:39 volumio volumio[7752]: info: Plugin example_plugin is not enabled Mar 30 19:51:39 volumio volumio[7752]: info: Loading plugin "inputs"... Mar 30 19:51:39 volumio volumio[7752]: info: Loading plugin "updater_comm"... Mar 30 19:51:39 volumio volumio[7752]: info: Plugin mpdemulation is not enabled Mar 30 19:51:39 volumio volumio[7752]: info: Loading plugin "rest_api"... Mar 30 19:51:40 volumio volumio[7752]: info: Loading plugin "websocket"... Mar 30 19:51:40 volumio volumio[7752]: info: Plugin fusiondsp is not enabled Mar 30 19:51:40 volumio volumio[7752]: info: Loading plugin "randomizer"... Mar 30 19:51:40 volumio volumio[7752]: Forking 3 albumart workers Mar 30 19:51:40 volumio volumio[7752]: info: Applying required configuration parameters for plugin randomizer Mar 30 19:51:40 volumio volumio[7752]: info: Loading plugin "touch_display"... Mar 30 19:51:41 volumio volumio[7752]: Starting albumart workers Mar 30 19:51:41 volumio volumio[7752]: info: Applying required configuration parameters for plugin touch_display Mar 30 19:51:41 volumio volumio[7752]: info: Loading i18n strings for locale en Mar 30 19:51:41 volumio volumio[7752]: Starting albumart workers Mar 30 19:51:41 volumio volumio[7752]: Updating browse sources language Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:51:41 volumio volumio[7752]: Starting albumart workers Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::initPlayerControls Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 30 19:51:41 volumio volumio[7752]: Express server listening on port 3000 Mar 30 19:51:41 volumio volumio[7752]: [Metrics] WebUI: 5s 844.39ms Mar 30 19:51:41 volumio volumio[7752]: info: CoreStateMachine::resetVolumioState Mar 30 19:51:41 volumio volumio[7752]: info: CoreStateMachine::getcurrentVolume Mar 30 19:51:41 volumio volumio[7752]: info: CoreCommandRouter::volumioRetrievevolume Mar 30 19:51:41 volumio sudo[7782]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:41 volumio volumio[7752]: info: Cannot read play queue from file Mar 30 19:51:42 volumio volumio[7752]: verbose: New Socket.io Connection to 192.168.1.238 from 192.168.1.144 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.2.1 Safari/605.1.15 Total Clients: 1 Mar 30 19:51:42 volumio volumio[7752]: 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: 2 Mar 30 19:51:42 volumio volumio-remote-updater[1416]: [2024-03-30 19:51:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1711842699 101 Mar 30 19:51:42 volumio volumio[7752]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3 Mar 30 19:51:42 volumio volumio[7752]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::setRepeat false single undefined Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:51:42 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::setRandom null Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:51:42 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:51:42 volumio volumio[7752]: info: Setting Device type: Raspberry PI Mar 30 19:51:42 volumio volumio[7752]: info: VolumeController:: Volume=100 Mute =false Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:51:42 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::updateTrackBlock Mar 30 19:51:42 volumio volumio[7752]: info: CorePlayQueue::getTrackBlock Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::volumioRetrievevolume Mar 30 19:51:42 volumio volumio[7752]: info: Discovery: adding 51e6139a-ad5d-48b6-a4d8-f4b417a04cc6 Mar 30 19:51:42 volumio volumio[7752]: info: Discovery: Found device Volumio Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:42 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:42 volumio volumio[7752]: info: VolumeController:: Volume=100 Mute =false Mar 30 19:51:42 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:51:42 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:42 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:51:43 volumio volumio[7752]: verbose: New Socket.io Connection to 192.168.1.238 from 192.168.1.144 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.2.1 Safari/605.1.15 Total Clients: 5 Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::volumioGetVisibleSources Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:43 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:43 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 30 19:51:43 volumio volumio[7752]: info: Received Get System Info Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 30 19:51:43 volumio volumio[7752]: info: Discovery: Getting this device information Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:43 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 30 19:51:43 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:43 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:43 volumio volumio[7752]: info: Listing playlists Mar 30 19:51:44 volumio volumio[7752]: 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: 6 Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::volumioGetVisibleSources Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:44 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 30 19:51:44 volumio volumio[7752]: info: Received Get System Info Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 30 19:51:44 volumio volumio[7752]: info: Discovery: Getting this device information Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:44 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:51:44 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:51:44 volumio volumio[7752]: info: Listing playlists Mar 30 19:51:44 volumio volumio[7752]: info: CoreCommandRouter::volumioGetQueue Mar 30 19:51:44 volumio volumio[7752]: info: CoreStateMachine::getQueue Mar 30 19:51:44 volumio volumio[7752]: info: CorePlayQueue::getQueue Mar 30 19:51:47 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:47 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:51:47 volumio sudo[7918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 30 19:51:47 volumio sudo[7918]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:47 volumio sudo[7919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 30 19:51:48 volumio sudo[7918]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:48 volumio sudo[7919]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:48 volumio sudo[7919]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:48 volumio sudo[7923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 30 19:51:48 volumio sudo[7923]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:51:48 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Mar 30 19:51:48 volumio sudo[7923]: pam_unix(sudo:session): session closed for user root Mar 30 19:51:48 volumio volumio[7752]: info: Upmpdcli Daemon Started Mar 30 19:51:48 volumio volumio[7925]: writing RSA key Mar 30 19:51:49 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:53 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:51:58 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:51:58 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:51:59 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 30 19:52:00 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@e4721217515c2e8d3cd9 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@fdd88bddc3a995292f96 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@beede61b2bbeb2152fb1 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@56e5dca1479debb05fd5 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@9f9acf02e3974d74a934 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@23404e01f0dfe8f0cb10 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@18e54a9bb974a6f70fc0 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@0bf3450a6e7474411fd7 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@f7da6cf95e0adc202ff6 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@ba45c50617e30b2f82fa Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@b3e453435dc44a304a8a Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@3a7f6d7432c5f6cc7f02 Mar 30 19:52:00 volumio volumio[7752]: info: Preloading song: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@156c6343dd4aad2c857f Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@e4721217515c2e8d3cd9 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@fdd88bddc3a995292f96 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@beede61b2bbeb2152fb1 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@56e5dca1479debb05fd5 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@9f9acf02e3974d74a934 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: No valid Plugin REST Endpoint Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@23404e01f0dfe8f0cb10 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@18e54a9bb974a6f70fc0 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@0bf3450a6e7474411fd7 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@f7da6cf95e0adc202ff6 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@ba45c50617e30b2f82fa in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@b3e453435dc44a304a8a in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@3a7f6d7432c5f6cc7f02 in service upnp_browser Mar 30 19:52:00 volumio volumio[7752]: info: Exploding uri upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@156c6343dd4aad2c857f in service upnp_browser Mar 30 19:52:05 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:05 volumio volumio[7752]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::ClearQueue Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::stop Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::clearPlayQueue Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::saveQueue Mar 30 19:52:05 volumio volumio[7752]: info: CoreCommandRouter::volumioPushQueue Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::addQueueItems Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::addQueueItems Mar 30 19:52:05 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:05 volumio volumio[7752]: info: Adding Item to queue: upnp/folder/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@77601710a9e7825c9127 Mar 30 19:52:05 volumio volumio[7752]: info: Exploding uri upnp/folder/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@77601710a9e7825c9127 in service upnp_browser Mar 30 19:52:05 volumio volumio[7752]: info: CoreCommandRouter::volumioPushQueue Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::saveQueue Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::updateTrackBlock Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::getTrackBlock Mar 30 19:52:05 volumio volumio[7752]: info: CoreCommandRouter::volumioPlay Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::play index 0 Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::stop Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::play index undefined Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:05 volumio volumio[7752]: info: CoreStateMachine::startPlaybackTimer Mar 30 19:52:05 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:05 volumio volumio[7752]: info: [1711842725148] ControllerUPNPBrowser::clearAddPlayTrack Mar 30 19:52:08 volumio volumio[7752]: info: Listing playlists Mar 30 19:52:11 volumio volumio[7752]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion Mar 30 19:52:11 volumio volumio[7752]: info: Preparing to generate the ALSA configuration file Mar 30 19:52:11 volumio volumio[7752]: info: Asound.conf file unchanged, so no further update is needed Mar 30 19:52:11 volumio volumio[7752]: info: Output device has changed, restarting MPD Mar 30 19:52:11 volumio sudo[7969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 30 19:52:11 volumio sudo[7969]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio sudo[7969]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:11 volumio volumio[7752]: info: Output device has changed, restarting Shairport Sync Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:11 volumio sudo[7973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 30 19:52:11 volumio sudo[7973]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio systemd[1]: Stopping Music Player Daemon... Mar 30 19:52:11 volumio systemd[1]: mpd.service: Succeeded. Mar 30 19:52:11 volumio volumio[7752]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 30 19:52:11 volumio systemd[1]: Stopped Music Player Daemon. Mar 30 19:52:11 volumio volumio[7752]: info: ___________ START PLUGINS ___________ Mar 30 19:52:11 volumio volumio[7752]: info: ControllerMpd::onStart: Initializing MPD Mar 30 19:52:11 volumio volumio[7752]: info: Creating MPD Configuration file Mar 30 19:52:11 volumio sudo[7980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 30 19:52:11 volumio sudo[7980]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 30 19:52:11 volumio sudo[7980]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:11 volumio volumio[7752]: info: [1711842731472] CoreMusicLibrary::Adding element Media Servers Mar 30 19:52:11 volumio systemd[1]: Starting Music Player Daemon... Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:52:11 volumio sudo[7983]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 30 19:52:11 volumio sudo[7983]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:11 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 30 19:52:11 volumio systemd[1]: mpd.service: Succeeded. Mar 30 19:52:11 volumio systemd[1]: Stopped Music Player Daemon. Mar 30 19:52:11 volumio systemd[1]: Starting Music Player Daemon... Mar 30 19:52:11 volumio volumio[7752]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 30 19:52:11 volumio volumio[7752]: info: [1711842731583] CoreMusicLibrary::Adding element Last_100 Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 30 19:52:11 volumio volumio[7752]: info: [1711842731585] CoreMusicLibrary::Adding element Webradio Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 30 19:52:11 volumio volumio[7752]: info: [now-playing] ConfigUpdater: config is up to date. Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 30 19:52:11 volumio volumio[7752]: info: [1711842731628] CoreMusicLibrary::Adding element Randomizer Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 30 19:52:11 volumio volumio[7752]: Cannot find translation for source Randomizer Mar 30 19:52:11 volumio volumio[7752]: info: Loading i18n strings for locale en Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 30 19:52:11 volumio volumio[7752]: info: Volumio Calling Home Mar 30 19:52:11 volumio sudo[7996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 30 19:52:11 volumio sudo[7996]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio sudo[7999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 30 19:52:11 volumio sudo[7999]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio sudo[8002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 30 19:52:11 volumio sudo[8002]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:11 volumio systemd[1]: Reloading. Mar 30 19:52:11 volumio volumio[7752]: info: [now-playing] Fetching API key... Mar 30 19:52:11 volumio volumio[7752]: info: [now-playing] App is listening on port 4004. Mar 30 19:52:11 volumio volumio[7752]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Mar 30 19:52:11 volumio volumio[7752]: error: touch_display: Error detecting backlight interface: Error: ENOENT: no such file or directory, scandir '/sys/class/backlight/' Mar 30 19:52:11 volumio volumio[7752]: info: MPD Permissions set Mar 30 19:52:11 volumio volumio[7752]: info: MPD Permissions set Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:11 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:12 volumio volumio[7752]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Mar 30 19:52:12 volumio sudo[8026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 30 19:52:12 volumio sudo[8026]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:12 volumio sudo[8026]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:12 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:52:12 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:52:12 volumio sudo[8029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 30 19:52:12 volumio sudo[8029]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:12 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:52:12 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Mar 30 19:52:12 volumio volumio[7752]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 30 19:52:12 volumio volumio[7752]: info: Volumio called home Mar 30 19:52:12 volumio sudo[8033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 30 19:52:12 volumio sudo[8033]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:12 volumio sudo[8034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 30 19:52:12 volumio sudo[8034]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:12 volumio mpd[7988]: Mar 30 19:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 30 19:52:12 volumio systemd[1]: Started Music Player Daemon. Mar 30 19:52:12 volumio sudo[7983]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:12 volumio sudo[7999]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:12 volumio sudo[7973]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:12 volumio volumio[7752]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 30 19:52:12 volumio systemd[1]: Reloading. Mar 30 19:52:12 volumio volumio[7752]: error: MPD error: The expression evaluated to a falsy value: Mar 30 19:52:12 volumio volumio[7752]: assert.ok(self.idling) Mar 30 19:52:12 volumio volumio[7752]: error: The expression evaluated to a falsy value: Mar 30 19:52:12 volumio volumio[7752]: assert.ok(self.idling) Mar 30 19:52:12 volumio volumio[7752]: info: MPD running with PID7988 Mar 30 19:52:12 volumio volumio[7752]: ,establishing connection Mar 30 19:52:12 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:12 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:12 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Mar 30 19:52:13 volumio volumio[7752]: info: Listing playlists Mar 30 19:52:13 volumio sudo[8002]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: systemctl daemon-reload succeeded. Mar 30 19:52:13 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 30 19:52:13 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 30 19:52:13 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:13 volumio sudo[7996]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 30 19:52:13 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:13 volumio sudo[8029]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:13 volumio sudo[8034]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:13 volumio volumio[7752]: info: Shairport-Sync Started Mar 30 19:52:13 volumio sudo[8033]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:13 volumio volumio[7752]: Error adding Membership: Error: addMembership EINVAL Mar 30 19:52:13 volumio volumio[7752]: info: Shairport-Sync Started Mar 30 19:52:13 volumio volumio[7752]: info: Shairport-Sync Started Mar 30 19:52:13 volumio sudo[8056]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 30 19:52:13 volumio sudo[8056]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:13 volumio sudo[8056]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: Volumio Kiosk started. Mar 30 19:52:13 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:52:13 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:13 volumio volumio[7752]: info: Completed starting Core Plugins Mar 30 19:52:13 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:52:13 volumio volumio[7752]: info: ----- MyVolumio plugins startup ---- Mar 30 19:52:13 volumio volumio[7752]: info: ------------------------------------------- Mar 30 19:52:13 volumio volumio[7752]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 30 19:52:13 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:52:13 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: X display number found: 0 Mar 30 19:52:13 volumio volumio[7752]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 30 19:52:13 volumio volumio[7752]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: X display number found: 0 Mar 30 19:52:13 volumio volumio[7752]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 30 19:52:14 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:52:14 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:17 volumio volumio[7752]: info: [now-playing] OpenWeatherMap API key obtained. Mar 30 19:52:17 volumio volumio[7752]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 30 19:52:18 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 30 19:52:18 volumio volumio[7752]: info: Discovery: Getting this device information Mar 30 19:52:18 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:52:18 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:18 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 30 19:52:19 volumio volumio[7752]: info: Listing playlists Mar 30 19:52:23 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::ClearQueue Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::stop Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::clearPlayQueue Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::saveQueue Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushQueue Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::addQueueItems Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::addQueueItems Mar 30 19:52:23 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:23 volumio volumio[7752]: info: Adding Item to queue: upnp/folder/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@77601710a9e7825c9127 Mar 30 19:52:23 volumio volumio[7752]: info: Using cached record of: upnp/folder/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@77601710a9e7825c9127 Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushQueue Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::saveQueue Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::updateTrackBlock Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrackBlock Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPlay Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::play index 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::stop Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::play index undefined Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::startPlaybackTimer Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: info: [1711842743256] ControllerUPNPBrowser::clearAddPlayTrack Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand stop Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand stop took 11 milliseconds Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand clear Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:23 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand clear took 5 milliseconds Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3" Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:23 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:23 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:23 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 10ms Mar 30 19:52:23 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:23 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3" Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 46ms Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 45ms Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:23 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand add "http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3" took 3 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand play Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:23 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:23 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 6ms Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand play took 4 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 5ms Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 3ms Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand status took 25 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand status took 27 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand status took 26 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand status took 5 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand status took 3 milliseconds Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":90,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3","trackType":"mp3"} Mar 30 19:52:23 volumio volumio[7752]: verbose: CURRENT POSITION 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus stop Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 45ms Mar 30 19:52:23 volumio volumio[7752]: info: Mar 30 19:52:23 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 15 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 14 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 14 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand status took 3 milliseconds Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":251,"duration":90,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3","trackType":"mp3"} Mar 30 19:52:23 volumio volumio[7752]: verbose: CURRENT POSITION 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:23 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":320,"duration":90,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3","trackType":"mp3"} Mar 30 19:52:23 volumio volumio[7752]: verbose: CURRENT POSITION 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:23 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":90,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3","trackType":"mp3"} Mar 30 19:52:23 volumio volumio[7752]: verbose: CURRENT POSITION 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:23 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":90,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3","trackType":"mp3"} Mar 30 19:52:23 volumio volumio[7752]: verbose: CURRENT POSITION 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:23 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 150ms Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 148ms Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 130ms Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 126ms Mar 30 19:52:23 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 102 milliseconds Mar 30 19:52:23 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:23 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:23 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:23 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":90,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/e4721217515c2e8d3cd9/file.mp3","trackType":"mp3"} Mar 30 19:52:23 volumio volumio[7752]: verbose: CURRENT POSITION 0 Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:23 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:23 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:23 volumio volumio[7752]: info: ------------------------------ 147ms Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 30 19:52:25 volumio volumio[7752]: info: Adding plugin bluetooth to MyMusic Plugins Mar 30 19:52:25 volumio volumio[7752]: info: Adding plugin multiroom to MyMusic Plugins Mar 30 19:52:25 volumio volumio[7752]: info: Adding plugin metavolumio to MyMusic Plugins Mar 30 19:52:25 volumio volumio[7752]: info: Adding plugin cd_controller to MyMusic Plugins Mar 30 19:52:25 volumio volumio[7752]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 30 19:52:25 volumio volumio[7752]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 30 19:52:25 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:25 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:25 volumio volumio[7752]: info: Starting MyVolumio Remote Streaming Endpoints Mar 30 19:52:25 volumio volumio[7752]: info: MyVolumio login type: Token Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 30 19:52:25 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 30 19:52:26 volumio volumio[7752]: info: Starting Streaming Service Transparent Proxy Mar 30 19:52:26 volumio volumio[7752]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 30 19:52:26 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 30 19:52:26 volumio volumio[7752]: info: Streaming services startup Mar 30 19:52:26 volumio volumio[7752]: info: Starting Streaming Daemon Mar 30 19:52:26 volumio sudo[8084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 30 19:52:26 volumio sudo[8084]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:26 volumio sudo[8084]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:26 volumio volumio[7752]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 30 19:52:26 volumio volumio[7752]: error: Cannot start Volumio Streaming Daemon Mar 30 19:52:26 volumio volumio[7752]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 30 19:52:26 volumio volumio[7752]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 30 19:52:27 volumio volumio[7752]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 30 19:52:27 volumio volumio[7752]: STREAMING PROXY: Starting server on port 3245 Mar 30 19:52:27 volumio volumio[7752]: Node JS runtime: 14 Mar 30 19:52:28 volumio volumio[7752]: info: MyVolumio token set successfully Mar 30 19:52:28 volumio volumio[7752]: info: MYVOLUMIO: Adding device Mar 30 19:52:28 volumio volumio[7752]: info: MYVOLUMIO: Evaluating Server Mar 30 19:52:28 volumio volumio[7752]: info: MyVolumio Plan changed: premium Mar 30 19:52:28 volumio volumio[7752]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 30 19:52:28 volumio volumio[7752]: info: Removing browser output: myVolumio user plan is not superstar Mar 30 19:52:28 volumio volumio[7752]: info: Removing audio output: Mar 30 19:52:28 volumio volumio[7752]: info: MYVOLUMIO: Adding device Mar 30 19:52:28 volumio volumio[7752]: info: MYVOLUMIO: Evaluating Server Mar 30 19:52:28 volumio volumio[7752]: info: Remote config written successfully Mar 30 19:52:28 volumio volumio[7752]: info: Starting Tunnel 1 Mar 30 19:52:28 volumio volumio[7752]: info: Starting Tunnel Connection Checker Mar 30 19:52:28 volumio volumio[7752]: info: Completed starting MyVolumio Plugin Mar 30 19:52:28 volumio volumio[7752]: info: MYVolumio Device enabled Mar 30 19:52:28 volumio volumio[7752]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 30 19:52:28 volumio volumio[7752]: info: MyVolumio status changed Mar 30 19:52:28 volumio volumio[7752]: info: Streaming services startup Mar 30 19:52:28 volumio volumio[7752]: info: Starting Streaming Daemon Mar 30 19:52:29 volumio sudo[8124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 30 19:52:29 volumio sudo[8124]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:29 volumio sudo[8124]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:29 volumio volumio[7752]: error: Cannot start Volumio Streaming Daemon Mar 30 19:52:29 volumio volumio[7752]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 30 19:52:29 volumio volumio[7752]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 30 19:52:29 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 30 19:52:29 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 30 19:52:29 volumio volumio[7752]: info: [1711842749141] Starting BluetoothController Mar 30 19:52:29 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 30 19:52:29 volumio volumio[7752]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 30 19:52:30 volumio sudo[8127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 30 19:52:30 volumio sudo[8127]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio sudo[8127]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio volumio[7752]: /bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 30 19:52:30 volumio volumio[7752]: info: MRS: MultiRoom plugin initialized Mar 30 19:52:30 volumio volumio[7752]: info: MRS: STOPPING SNAPCLIENT Mar 30 19:52:30 volumio volumio[7752]: info: MRS: Snap server stop Mar 30 19:52:30 volumio sudo[8143]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 30 19:52:30 volumio sudo[8143]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio volumio[7752]: info: MRS: STOPPING volumioStreaming Mar 30 19:52:30 volumio sudo[8146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 30 19:52:30 volumio sudo[8146]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio sudo[8143]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio sudo[8149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 30 19:52:30 volumio sudo[8146]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio sudo[8149]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 30 19:52:30 volumio sudo[8152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 30 19:52:30 volumio sudo[8152]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio sudo[8152]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio sudo[8149]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 30 19:52:30 volumio volumio[7752]: info: Preparing to generate the ALSA configuration file Mar 30 19:52:30 volumio volumio[7752]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 30 19:52:30 volumio volumio[7752]: info: Reading ALSA contributions from plugins. Mar 30 19:52:30 volumio volumio[7752]: info: Setting Geolocation for MyVolumio to us1 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:30 volumio volumio[7752]: info: MRS: Removed streaming files Mar 30 19:52:30 volumio volumio[7752]: info: MRS: volumioStreaming STOPPED Mar 30 19:52:30 volumio volumio[7752]: info: MRS: SNAPSERVER STOPPED Mar 30 19:52:30 volumio volumio[7752]: info: MRS: SNAPCLIENT STOPPED Mar 30 19:52:30 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::ClearQueue Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::stop Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::stPlaybackTimer Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::updateTrackBlock Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrackBlock Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::serviceStop Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 0 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::serviceStop Mar 30 19:52:30 volumio volumio[7752]: info: [1711842750446] ControllerUPNPBrowser::stop Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand stop Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::clearPlayQueue Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::saveQueue Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushQueue Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::addQueueItems Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::addQueueItems Mar 30 19:52:30 volumio volumio[7752]: info: Preload queue cleared Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@e4721217515c2e8d3cd9 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@e4721217515c2e8d3cd9 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@fdd88bddc3a995292f96 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@fdd88bddc3a995292f96 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@beede61b2bbeb2152fb1 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@beede61b2bbeb2152fb1 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@56e5dca1479debb05fd5 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@56e5dca1479debb05fd5 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@9f9acf02e3974d74a934 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@9f9acf02e3974d74a934 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@23404e01f0dfe8f0cb10 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@23404e01f0dfe8f0cb10 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@18e54a9bb974a6f70fc0 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@18e54a9bb974a6f70fc0 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@0bf3450a6e7474411fd7 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@0bf3450a6e7474411fd7 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@f7da6cf95e0adc202ff6 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@f7da6cf95e0adc202ff6 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@ba45c50617e30b2f82fa Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@ba45c50617e30b2f82fa Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@b3e453435dc44a304a8a Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@b3e453435dc44a304a8a Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@3a7f6d7432c5f6cc7f02 Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@3a7f6d7432c5f6cc7f02 Mar 30 19:52:30 volumio volumio[7752]: info: Adding Item to queue: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@156c6343dd4aad2c857f Mar 30 19:52:30 volumio volumio[7752]: info: Using cached record of: upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@156c6343dd4aad2c857f Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushQueue Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::saveQueue Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::updateTrackBlock Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrackBlock Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPlay Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::play index 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::stop Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::play index undefined Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::startPlaybackTimer Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: [1711842750476] ControllerUPNPBrowser::clearAddPlayTrack Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand stop Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand stop took 49 milliseconds Mar 30 19:52:30 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand stop took 30 milliseconds Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand clear Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:30 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:30 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:30 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand status took 37 milliseconds Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand clear took 36 milliseconds Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand status took 34 milliseconds Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand status took 33 milliseconds Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3" Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:30 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 30 19:52:30 volumio volumio[7752]: verbose: CURRENT POSITION 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::syncState stateService stop Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus stop Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: No code Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 30 19:52:30 volumio volumio[7752]: verbose: CURRENT POSITION 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::syncState stateService stop Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus stop Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: No code Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:30 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 90ms Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 89ms Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:30 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:30 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:30 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:30 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:30 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 67ms Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 64 milliseconds Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3" Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 9ms Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 9ms Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:30 volumio volumio[7752]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 116ms Mar 30 19:52:30 volumio volumio[7752]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:30 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand add "http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3" took 36 milliseconds Mar 30 19:52:30 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 30 19:52:30 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand play Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:30 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:30 volumio volumio[7752]: info: Mar 30 19:52:30 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:30 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 9ms Mar 30 19:52:30 volumio volumio[7752]: info: sendMpdCommand play took 8 milliseconds Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 8ms Mar 30 19:52:30 volumio volumio[7752]: info: ------------------------------ 6ms Mar 30 19:52:30 volumio volumio[7752]: info: Asound.conf file written Mar 30 19:52:30 volumio sudo[8159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 30 19:52:30 volumio sudo[8159]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio sudo[8159]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio volumio[7752]: No state is present for card b1 Mar 30 19:52:30 volumio volumio[7752]: /usr/share/alsa/init/bcm2835:14: control element not found Mar 30 19:52:30 volumio volumio[7752]: No state is present for card b1 Mar 30 19:52:30 volumio volumio[7752]: No state is present for card Headphones Mar 30 19:52:30 volumio volumio[7752]: /usr/share/alsa/init/bcm2835:20: control element not found Mar 30 19:52:30 volumio volumio[7752]: No state is present for card Headphones Mar 30 19:52:30 volumio volumio[7752]: No state is present for card BossDAC Mar 30 19:52:30 volumio volumio[7752]: Found hardware: "BossDAC" "" "" "" "" Mar 30 19:52:30 volumio volumio[7752]: Hardware is initialized using a generic method Mar 30 19:52:30 volumio volumio[7752]: No state is present for card BossDAC Mar 30 19:52:30 volumio volumio[7752]: info: Output device has changed, restarting MPD Mar 30 19:52:30 volumio sudo[8164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 30 19:52:30 volumio sudo[8164]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio sudo[8164]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio volumio[7752]: info: Output device has changed, restarting Shairport Sync Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:30 volumio sudo[8167]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 30 19:52:30 volumio sudo[8167]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio systemd[1]: Stopping Music Player Daemon... Mar 30 19:52:30 volumio volumio[7752]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 30 19:52:30 volumio systemd[1]: mpd.service: Succeeded. Mar 30 19:52:30 volumio systemd[1]: Stopped Music Player Daemon. Mar 30 19:52:30 volumio volumio[7752]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 30 19:52:30 volumio volumio[7752]: info: MRS: Pushing multiroomSync output for this device Mar 30 19:52:30 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:30 volumio systemd[1]: Starting Music Player Daemon... Mar 30 19:52:30 volumio volumio[7752]: info: Adding audio output: Mar 30 19:52:30 volumio volumio[7752]: info: Adding audio output: Mar 30 19:52:30 volumio sudo[8176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Mar 30 19:52:30 volumio sudo[8176]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:30 volumio sudo[8176]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:30 volumio volumio[7752]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 30 19:52:30 volumio volumio[7752]: info: Adding METAVOLUMIO REST API Endpoints Mar 30 19:52:30 volumio volumio[7752]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 30 19:52:30 volumio volumio[7752]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 30 19:52:30 volumio volumio[7752]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 30 19:52:30 volumio volumio[7752]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 30 19:52:30 volumio volumio[7752]: info: Adding Manifest REST API Endpoints Mar 30 19:52:30 volumio volumio[7752]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Mar 30 19:52:30 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 30 19:52:30 volumio volumio[7752]: info: Preparing CD Folders Mar 30 19:52:30 volumio volumio[7752]: info: Adding CD REST API Endpoints Mar 30 19:52:30 volumio volumio[7752]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 30 19:52:30 volumio volumio[7752]: info: Starting UDEV Watcher for CD Mar 30 19:52:30 volumio volumio[7752]: info: Detecting CD presence with UDEV Mar 30 19:52:30 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 30 19:52:31 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 30 19:52:31 volumio volumio[7752]: info: Adding inputs REST Endpoints Mar 30 19:52:31 volumio volumio[7752]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 30 19:52:31 volumio volumio[7752]: info: Scanning Audio Inputs Mar 30 19:52:31 volumio volumio[7752]: info: Checking against Known Cards name Mar 30 19:52:31 volumio volumio[7752]: info: Adding Server instance for streaming Mar 30 19:52:31 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 30 19:52:31 volumio volumio[7752]: error: Hi Res Audio Failed Login: Missing Login Data Mar 30 19:52:31 volumio volumio[7752]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 30 19:52:31 volumio volumio[7752]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 30 19:52:31 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 30 19:52:31 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 30 19:52:31 volumio volumio[7752]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 30 19:52:31 volumio volumio[7752]: info: Stopping AccessToken refresher cron Mar 30 19:52:31 volumio sudo[8184]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 30 19:52:31 volumio sudo[8184]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:31 volumio systemd[1]: Stopping Volumio Tidal Connect Service... Mar 30 19:52:31 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Mar 30 19:52:31 volumio systemd[1]: vtcs.service: Succeeded. Mar 30 19:52:31 volumio systemd[1]: Stopped Volumio Tidal Connect Service. Mar 30 19:52:31 volumio volumio[7752]: info: AccessToken refresher cron started Mar 30 19:52:31 volumio volumio[7752]: info: Stopping AccessToken refresher cron for QOBUZ Mar 30 19:52:31 volumio sudo[8184]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:31 volumio volumio[7752]: info: AccessToken refresher cron started for QOBUZ Mar 30 19:52:31 volumio volumio[7752]: info: Adding TIDAL REST API Endpoints Mar 30 19:52:31 volumio volumio[7752]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Mar 30 19:52:31 volumio volumio[7752]: info: Adding QOBUZ REST API Endpoints Mar 30 19:52:31 volumio volumio[7752]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Mar 30 19:52:31 volumio volumio[7752]: info: Mar 30 19:52:31 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:31 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:31 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:31 volumio volumio[7752]: error: MPD error: Error: write EPIPE Mar 30 19:52:31 volumio volumio[7752]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Mar 30 19:52:31 volumio volumio[7752]: info: Mar 30 19:52:31 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:31 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:31 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:31 volumio volumio[7752]: error: MPD error: Error: write EPIPE Mar 30 19:52:31 volumio volumio[7752]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Mar 30 19:52:31 volumio volumio[7752]: info: Mar 30 19:52:31 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:31 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:31 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:31 volumio volumio[7752]: error: MPD error: Error: write EPIPE Mar 30 19:52:31 volumio volumio[7752]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Mar 30 19:52:31 volumio volumio[7752]: info: Bluetooth name changed to Volumio Mar 30 19:52:31 volumio volumio[7752]: info: MPD Permissions set Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:52:31 volumio sudo[8192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 30 19:52:31 volumio sudo[8192]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:31 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 30 19:52:31 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 30 19:52:31 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:31 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:31 volumio sudo[8192]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:31 volumio volumio[7752]: info: Updating MyVolumio device info Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:31 volumio volumio[7752]: info: Shairport-Sync Started Mar 30 19:52:31 volumio mpd[8172]: Mar 30 19:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 30 19:52:31 volumio systemd[1]: Started Music Player Daemon. Mar 30 19:52:31 volumio volumio[7752]: info: Successfully Added MyVolumio device Mar 30 19:52:31 volumio sudo[8167]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:31 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:31 volumio volumio[7752]: info: Successfully Updated MyVolumio device Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::volumioPlay Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::play index undefined Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 30 19:52:33 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::startPlaybackTimer Mar 30 19:52:33 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:33 volumio volumio[7752]: info: [1711842753006] ControllerUPNPBrowser::clearAddPlayTrack Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand stop Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand stop took 1 milliseconds Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand clear Mar 30 19:52:33 volumio volumio[7752]: info: Mar 30 19:52:33 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:33 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand clear took 1 milliseconds Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3" Mar 30 19:52:33 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:33 volumio volumio[7752]: info: ------------------------------ 2ms Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3" Mar 30 19:52:33 volumio volumio[7752]: info: Mar 30 19:52:33 volumio volumio[7752]: ---------------------------- MPD announces system playlist update Mar 30 19:52:33 volumio volumio[7752]: info: Ignoring MPD Status Update Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand add "http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3" took 1 milliseconds Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand play Mar 30 19:52:33 volumio volumio[7752]: info: ------------------------------ 2ms Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand play took 1 milliseconds Mar 30 19:52:33 volumio volumio[7752]: info: Mar 30 19:52:33 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:33 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:33 volumio volumio[7752]: info: Mar 30 19:52:33 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand status took 47 milliseconds Mar 30 19:52:33 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand status took 2 milliseconds Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:33 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:33 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:33 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":254,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3","trackType":"mp3"} Mar 30 19:52:33 volumio volumio[7752]: verbose: CURRENT POSITION 3 Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus stop Mar 30 19:52:33 volumio volumio[7752]: info: ------------------------------ 52ms Mar 30 19:52:33 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 30 19:52:33 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:33 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:33 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:33 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":254,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3","trackType":"mp3"} Mar 30 19:52:33 volumio volumio[7752]: verbose: CURRENT POSITION 3 Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:33 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:33 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:33 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:33 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:33 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:33 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:33 volumio volumio[7752]: info: ------------------------------ 33ms Mar 30 19:52:33 volumio volumio[7752]: info: Setting Geolocation for MyVolumio to us1 Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:33 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:33 volumio sudo[8210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 30 19:52:33 volumio sudo[8210]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:33 volumio autossh[7557]: received signal to exit (15) Mar 30 19:52:33 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Mar 30 19:52:33 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Mar 30 19:52:33 volumio systemd[1]: sshtunnel.service: Succeeded. Mar 30 19:52:33 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Mar 30 19:52:33 volumio systemd[1]: Started MyVolumio SSH Tunnel. Mar 30 19:52:33 volumio sudo[8210]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:33 volumio volumio[7752]: info: Remote SSH Started Mar 30 19:52:33 volumio autossh[8214]: port set to 0, monitoring disabled Mar 30 19:52:33 volumio autossh[8214]: starting ssh (count 1) Mar 30 19:52:33 volumio autossh[8214]: ssh child pid is 8217 Mar 30 19:52:33 volumio sudo[8219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 30 19:52:33 volumio sudo[8219]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:34 volumio sudo[8219]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:34 volumio volumio[7752]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 19:52:34 volumio volumio[7752]: info: Volumio BT Module successfully started Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:52:34 volumio volumio[7752]: info: TidalConnect service stoped! Mar 30 19:52:34 volumio volumio[7752]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 30 19:52:34 volumio volumio[7752]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 30 19:52:34 volumio sudo[8230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 30 19:52:34 volumio sudo[8230]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:34 volumio systemd[1]: Started Volumio Tidal Connect Service. Mar 30 19:52:34 volumio sudo[8230]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:34 volumio volumio[7752]: info: Executing endpoint tc_getconfig Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 30 19:52:34 volumio vtcs[8232]: STARTING TidalConnect services, version: 1.3.0.19 Mar 30 19:52:34 volumio vtcs[8232]: STARTED TidalConnect services. Mar 30 19:52:34 volumio volumio[7752]: info: Updating MyVolumio device info Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:34 volumio volumio[7752]: info: Executing endpoint tc_connect Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 30 19:52:34 volumio volumio[7752]: info: Connecting to TidalConnect Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:34 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:34 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:34 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:34 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:34 volumio volumio[7752]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:34 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:34 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:34 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:34 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:34 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:34 volumio volumio[7752]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Mar 30 19:52:35 volumio volumio[7752]: info: MRS: Getting audio outputs on start Mar 30 19:52:35 volumio volumio[7752]: info: MRS: Requesting all other devices output Mar 30 19:52:36 volumio volumio[7752]: info: Successfully Added MyVolumio device Mar 30 19:52:36 volumio volumiossh-tunnel[8212]: Warning: Permanently added '[us1.myvolumio.org]:2222,[162.243.167.188]:2222' (RSA) to the list of known hosts. Mar 30 19:52:36 volumio volumio[7752]: info: Successfully Updated MyVolumio device Mar 30 19:52:37 volumio volumio[7752]: info: TidalConnect service started! Mar 30 19:52:37 volumio volumio[7752]: info: BOOT COMPLETED Mar 30 19:52:37 volumio volumio[7752]: [Metrics] CommandRouter: 61s 119.89ms Mar 30 19:52:37 volumio volumio[7752]: info: CoreCommandRouter::volumiosetStartupVolume Mar 30 19:52:37 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:37 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:37 volumio volumio[7752]: info: CoreCommandRouter::Close All Modals sent Mar 30 19:52:37 volumio volumio[7752]: info: CoreCommandRouter::Close All Modals sent Mar 30 19:52:37 volumio volumio[7752]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Mar 30 19:52:37 volumio volumio[7752]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Mar 30 19:52:37 volumio volumio[7752]: aplay: main:828: audio open error: Device or resource busy Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::volumioSeek Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::seek Mar 30 19:52:38 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:38 volumio volumio[7752]: info: TRACKBLOCK {"service":"upnp_browser","uri":"http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3","realUri":"upnp/http://192.168.1.102:32469/ContentDirectory/41a7b23f-1561-8cdc-8522-8a9bf0f37cfa/control.xml@56e5dca1479debb05fd5","type":"song","albumart":"http://192.168.1.102:32469/proxy/b9aeb44c0b06431ef8e9/albumart.jpg","artist":"Aaliyah","album":"Age Ain’t Nothing but a Number","name":"Age Ain’t Nothing but a Number","title":"Age Ain’t Nothing but a Number","duration":254} Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::startPlaybackTimer Mar 30 19:52:38 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:38 volumio volumio[7752]: info: [1711842758823] ControllerUPNPBrowser::seek Mar 30 19:52:38 volumio volumio[7752]: info: ControllerMpd::seek Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:38 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:38 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:38 volumio volumio[7752]: error: null Mar 30 19:52:38 volumio volumio[7752]: info: Mar 30 19:52:38 volumio volumio[7752]: ---------------------------- MPD announces state update: player Mar 30 19:52:38 volumio volumio[7752]: info: ControllerMpd::getState Mar 30 19:52:38 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand status Mar 30 19:52:38 volumio volumio[7752]: info: sendMpdCommand status took 18 milliseconds Mar 30 19:52:38 volumio volumio[7752]: verbose: ControllerMpd::parseState Mar 30 19:52:38 volumio volumio[7752]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 30 19:52:38 volumio volumio[7752]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 30 19:52:38 volumio volumio[7752]: verbose: ControllerMpd::parseTrackInfo Mar 30 19:52:38 volumio volumio[7752]: info: ControllerMpd::pushState Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::servicePushState Mar 30 19:52:38 volumio volumio[7752]: info: CorePlayQueue::getTrack 3 Mar 30 19:52:38 volumio volumio[7752]: verbose: STATE SERVICE {"status":"play","position":0,"seek":127108,"duration":254,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.1.102:32469/object/56e5dca1479debb05fd5/file.mp3","trackType":"mp3"} Mar 30 19:52:38 volumio volumio[7752]: verbose: CURRENT POSITION 3 Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::syncState stateService play Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::syncState currentStatus play Mar 30 19:52:38 volumio volumio[7752]: info: Received an update from plugin. extracting info from payload Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:38 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:38 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:38 volumio volumio[7752]: info: CoreStateMachine::pushState Mar 30 19:52:38 volumio volumio[7752]: info: CoreCommandRouter::volumioPushState Mar 30 19:52:38 volumio volumio[7752]: info: MRS: Pushing multiroomSync output update for this device Mar 30 19:52:38 volumio volumio[7752]: info: MRS: Pushing multiroomSync output Mar 30 19:52:38 volumio volumio[7752]: info: ------------------------------ 47ms Mar 30 19:52:40 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 30 19:52:40 volumio volumio[7752]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Mar 30 19:52:40 volumio volumio[7752]: info: CoreCommandRouter::volumioGetState Mar 30 19:52:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 30 19:52:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 30 19:52:41 volumio volumio-remote-updater[1416]: No test mode Mar 30 19:52:41 volumio volumio-remote-updater[1416]: No alpha test mode Mar 30 19:52:41 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 30 19:52:42 volumio volumio[7752]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 30 19:52:42 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::volumioGetBrowseSources Mar 30 19:52:45 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 30 19:52:51 volumio volumio[7752]: info: Enabling plugin fusiondsp Mar 30 19:52:51 volumio volumio[7752]: info: Loading plugin "fusiondsp"... Mar 30 19:52:51 volumio volumio[7752]: info: Preparing to generate the ALSA configuration file Mar 30 19:52:51 volumio volumio[7752]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 30 19:52:51 volumio volumio[7752]: info: Reading ALSA contributions from plugins. Mar 30 19:52:51 volumio volumio[7752]: info: Asound.conf file unchanged, so no further update is needed Mar 30 19:52:51 volumio volumio[7752]: info: Output device has changed, restarting MPD Mar 30 19:52:51 volumio sudo[8318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 30 19:52:51 volumio sudo[8318]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio sudo[8318]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:51 volumio volumio[7752]: info: Output device has changed, restarting Shairport Sync Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:51 volumio sudo[8321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 30 19:52:51 volumio sudo[8321]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio systemd[1]: Stopping Music Player Daemon... Mar 30 19:52:51 volumio volumio[7752]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 30 19:52:51 volumio volumio[7752]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio systemd[1]: mpd.service: Succeeded. Mar 30 19:52:51 volumio systemd[1]: Stopped Music Player Daemon. Mar 30 19:52:51 volumio vtcs[8232]: [2024-03-30 19:52:51.422] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Mar 30 19:52:51 volumio vtcs[8232]: [2024-03-30 19:52:51.423] [tisoc] [error] [SpkconServer.cpp:382] recv error. client fd=8 errorno=104 error=Connection reset by peer Mar 30 19:52:51 volumio vtcs[8232]: [2024-03-30 19:52:51.423] [tisoc] [error] [SpkconServer.cpp:377] recv error. socket disconnected Mar 30 19:52:51 volumio volumio[7752]: info: PLUGIN START: fusiondsp Mar 30 19:52:51 volumio systemd[1]: Starting Music Player Daemon... Mar 30 19:52:51 volumio volumio[7752]: info: Loading i18n strings for locale en Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: FusionDsp - mixtype--------------------- Hardware Mar 30 19:52:51 volumio sudo[8330]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 30 19:52:51 volumio volumio[7752]: info: Preparing to generate the ALSA configuration file Mar 30 19:52:51 volumio sudo[8330]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio systemd[1]: Stopping Volumio Tidal Connect Service... Mar 30 19:52:51 volumio volumio[7752]: info: Done. Mar 30 19:52:51 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Mar 30 19:52:51 volumio systemd[1]: vtcs.service: Succeeded. Mar 30 19:52:51 volumio systemd[1]: Stopped Volumio Tidal Connect Service. Mar 30 19:52:51 volumio sudo[8330]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:51 volumio volumio[7752]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 30 19:52:51 volumio volumio[7752]: info: Reading ALSA contributions from plugins. Mar 30 19:52:51 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:51 volumio sudo[8334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 30 19:52:51 volumio sudo[8334]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 30 19:52:51 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:51 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 30 19:52:51 volumio sudo[8334]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:51 volumio volumio[7752]: info: MPD Permissions set Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:52:51 volumio volumio[7752]: info: Asound.conf file unchanged, so no further update is needed Mar 30 19:52:51 volumio volumio[7752]: info: Output device has changed, restarting MPD Mar 30 19:52:51 volumio sudo[8342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 30 19:52:51 volumio sudo[8342]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 30 19:52:51 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 30 19:52:51 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:51 volumio sudo[8346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 30 19:52:51 volumio sudo[8346]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:51 volumio volumio[7752]: info: Output device has changed, restarting Shairport Sync Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:51 volumio sudo[8346]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:51 volumio sudo[8350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 30 19:52:51 volumio sudo[8350]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:51 volumio sudo[8342]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:51 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 30 19:52:51 volumio systemd[1]: mpd.service: Succeeded. Mar 30 19:52:51 volumio systemd[1]: Stopped Music Player Daemon. Mar 30 19:52:51 volumio systemd[1]: Starting Music Player Daemon... Mar 30 19:52:51 volumio volumio[7752]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 30 19:52:51 volumio volumio[7752]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 30 19:52:51 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio sudo[8362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 30 19:52:52 volumio sudo[8362]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:52 volumio sudo[8362]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 30 19:52:52 volumio sudo[8365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 30 19:52:52 volumio sudo[8365]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:52 volumio sudo[8365]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:52 volumio volumio[7752]: info: MPD Permissions set Mar 30 19:52:52 volumio volumio[7752]: info: Shairport-Sync Started Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:52 volumio volumio[7752]: info: Starting Shairport Sync Mar 30 19:52:52 volumio sudo[8374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 30 19:52:52 volumio sudo[8374]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:52 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 30 19:52:52 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 30 19:52:52 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 30 19:52:52 volumio volumio[7752]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 30 19:52:52 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 30 19:52:52 volumio sudo[8374]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:52 volumio volumio[7752]: info: Shairport-Sync Started Mar 30 19:52:52 volumio mpd[8356]: Mar 30 19:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 30 19:52:52 volumio systemd[1]: Started Music Player Daemon. Mar 30 19:52:52 volumio sudo[8350]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:52 volumio sudo[8321]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:52 volumio volumio[7752]: error: MPD error: The expression evaluated to a falsy value: Mar 30 19:52:52 volumio volumio[7752]: assert.ok(self.idling) Mar 30 19:52:52 volumio volumio[7752]: error: The expression evaluated to a falsy value: Mar 30 19:52:52 volumio volumio[7752]: assert.ok(self.idling) Mar 30 19:52:52 volumio volumio[7752]: error: updateQueue error: null Mar 30 19:52:53 volumio volumio[7752]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Mar 30 19:52:53 volumio volumio[7752]: info: camilladsp service started and running in background, instance 1 Mar 30 19:52:53 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 30 19:52:53 volumio volumio[7752]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Mar 30 19:52:53 volumio volumio[7752]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Mar 30 19:52:53 volumio volumio[7752]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Mar 30 19:52:53 volumio volumio[7752]: info: FusionDsp loaded Mar 30 19:52:53 volumio volumio[7752]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 30 19:52:53 volumio sudo[8391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Mar 30 19:52:53 volumio sudo[8391]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 19:52:53 volumio volumio[7752]: info: FusionDsp - Reporting Fusion DSP Enabled Mar 30 19:52:53 volumio volumio[7752]: info: Adding Signal Path Element [object Object] Mar 30 19:52:53 volumio volumio[7752]: info: Adding fusiondspeq DSP Signal Path Element Mar 30 19:52:53 volumio volumio[7752]: info: FusionDsp - ---- installed callbackRead Mar 30 19:52:53 volumio volumio[7752]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 30 19:52:53 volumio volumio[7752]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Mar 30 19:52:53 volumio volumio[7752]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Mar 30 19:52:53 volumio volumio[7752]: at onErrorNT (internal/child_process.js:465:16) Mar 30 19:52:53 volumio volumio[7752]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { Mar 30 19:52:53 volumio volumio[7752]: errno: -2, Mar 30 19:52:53 volumio volumio[7752]: code: 'ENOENT', Mar 30 19:52:53 volumio volumio[7752]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Mar 30 19:52:53 volumio volumio[7752]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Mar 30 19:52:53 volumio volumio[7752]: spawnargs: [ Mar 30 19:52:53 volumio volumio[7752]: '-p', Mar 30 19:52:53 volumio volumio[7752]: 9876, Mar 30 19:52:53 volumio volumio[7752]: '-o', Mar 30 19:52:53 volumio volumio[7752]: '/tmp/camilladsp.log', Mar 30 19:52:53 volumio volumio[7752]: '-l', Mar 30 19:52:53 volumio volumio[7752]: 'warn', Mar 30 19:52:53 volumio volumio[7752]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Mar 30 19:52:53 volumio volumio[7752]: ] Mar 30 19:52:53 volumio volumio[7752]: } Mar 30 19:52:53 volumio volumio[7752]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 30 19:52:53 volumio sudo[8391]: pam_unix(sudo:session): session closed for user root Mar 30 19:52:53 volumio sudo[8402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-30 19:51 Mar 30 19:52:53 volumio sudo[8402]: 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"