-- 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"