Jan 09 13:28:04 volumio go-librespot[6526]: time="2026-01-09T13:28:04Z" level=debug msg="fetched chunk 52/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:28:14 volumio go-librespot[6526]: time="2026-01-09T13:28:14Z" level=trace msg="sent dealer ping" Jan 09 13:28:14 volumio go-librespot[6526]: time="2026-01-09T13:28:14Z" level=trace msg="received dealer pong" Jan 09 13:28:18 volumio go-librespot[6526]: time="2026-01-09T13:28:18Z" level=debug msg="fetched chunk 53/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:28:33 volumio go-librespot[6526]: time="2026-01-09T13:28:33Z" level=debug msg="fetched chunk 54/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:28:44 volumio go-librespot[6526]: time="2026-01-09T13:28:44Z" level=trace msg="sent dealer ping" Jan 09 13:28:44 volumio go-librespot[6526]: time="2026-01-09T13:28:44Z" level=trace msg="received dealer pong" Jan 09 13:28:46 volumio go-librespot[6526]: time="2026-01-09T13:28:46Z" level=debug msg="fetched chunk 55/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:28:47 volumio go-librespot[6526]: time="2026-01-09T13:28:47Z" level=trace msg="received accesspoint ping" Jan 09 13:28:47 volumio go-librespot[6526]: time="2026-01-09T13:28:47Z" level=trace msg="received accesspoint pong ack" Jan 09 13:28:55 volumio volumio[1104]: info: MPD Database updated - AlbumList cache refreshed Jan 09 13:28:55 volumio volumio[1104]: info: Jan 09 13:28:55 volumio volumio[1104]: ---------------------------- MPD announces state update: database Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Jan 09 13:28:55 volumio volumio[1104]: info: Jan 09 13:28:55 volumio volumio[1104]: ---------------------------- MPD announces state update: update Jan 09 13:28:55 volumio volumio[1104]: info: ControllerMpd::getState Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Jan 09 13:28:55 volumio volumio[1104]: info: ControllerMpd::getState Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Jan 09 13:28:55 volumio volumio[1104]: info: sendMpdCommand status took 428 milliseconds Jan 09 13:28:55 volumio volumio[1104]: info: sendMpdCommand status took 428 milliseconds Jan 09 13:28:55 volumio volumio[1104]: info: sendMpdCommand status took 428 milliseconds Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::parseState Jan 09 13:28:55 volumio volumio[1104]: info: Command Router : Notfying DB Updatetrue Jan 09 13:28:55 volumio volumio[1104]: info: CoreCommandRouter::Close All Modals sent Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::parseState Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::parseState Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 09 13:28:55 volumio volumio[1104]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 09 13:28:55 volumio volumio[1104]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::parseTrackInfo Jan 09 13:28:55 volumio volumio[1104]: verbose: ControllerMpd::parseTrackInfo Jan 09 13:28:55 volumio volumio[1104]: info: ControllerMpd::pushState Jan 09 13:28:55 volumio volumio[1104]: info: CoreCommandRouter::servicePushState Jan 09 13:28:55 volumio volumio[1104]: info: CoreStateMachine::pushState Jan 09 13:28:55 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:28:55 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:28:55 volumio volumio[1104]: info: CoreCommandRouter::volumioPushState Jan 09 13:28:55 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:28:55 volumio volumio[1104]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jan 09 13:28:55 volumio volumio[1104]: info: ControllerMpd::pushState Jan 09 13:28:55 volumio volumio[1104]: info: CoreCommandRouter::servicePushState Jan 09 13:28:55 volumio volumio[1104]: info: CoreStateMachine::pushState Jan 09 13:28:55 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:28:55 volumio volumio[1104]: info: CoreCommandRouter::volumioPushState Jan 09 13:28:55 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:28:55 volumio volumio[1104]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jan 09 13:28:55 volumio volumio[1104]: info: ------------------------------ 501ms Jan 09 13:28:55 volumio volumio[1104]: info: ------------------------------ 503ms Jan 09 13:29:00 volumio volumio[1104]: info: CoreCommandRouter::volumioGetState Jan 09 13:29:00 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:29:00 volumio go-librespot[6526]: time="2026-01-09T13:29:00Z" level=debug msg="fetched chunk 56/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:29:03 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 09 13:29:03 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 09 13:29:06 volumio volumio[1104]: info: MPD Database updated - AlbumList cache refreshed Jan 09 13:29:06 volumio volumio[1104]: info: Jan 09 13:29:06 volumio volumio[1104]: ---------------------------- MPD announces state update: database Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Jan 09 13:29:06 volumio volumio[1104]: info: Jan 09 13:29:06 volumio volumio[1104]: ---------------------------- MPD announces state update: update Jan 09 13:29:06 volumio volumio[1104]: info: ControllerMpd::getState Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Jan 09 13:29:06 volumio volumio[1104]: info: ControllerMpd::getState Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand status Jan 09 13:29:06 volumio volumio[1104]: info: sendMpdCommand status took 325 milliseconds Jan 09 13:29:06 volumio volumio[1104]: info: sendMpdCommand status took 325 milliseconds Jan 09 13:29:06 volumio volumio[1104]: info: sendMpdCommand status took 325 milliseconds Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::parseState Jan 09 13:29:06 volumio volumio[1104]: info: Command Router : Notfying DB Updatefalse Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::Close All Modals sent Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::parseState Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::parseState Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 09 13:29:06 volumio volumio[1104]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::parseTrackInfo Jan 09 13:29:06 volumio volumio[1104]: info: ControllerMpd::pushState Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::servicePushState Jan 09 13:29:06 volumio volumio[1104]: info: CoreStateMachine::pushState Jan 09 13:29:06 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::volumioPushState Jan 09 13:29:06 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:29:06 volumio volumio[1104]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jan 09 13:29:06 volumio volumio[1104]: info: ------------------------------ 425ms Jan 09 13:29:06 volumio volumio[1104]: info: sendMpdCommand playlistinfo took 7 milliseconds Jan 09 13:29:06 volumio volumio[1104]: verbose: ControllerMpd::parseTrackInfo Jan 09 13:29:06 volumio volumio[1104]: info: ControllerMpd::pushState Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::servicePushState Jan 09 13:29:06 volumio volumio[1104]: info: CoreStateMachine::pushState Jan 09 13:29:06 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 09 13:29:06 volumio volumio[1104]: info: CoreCommandRouter::volumioPushState Jan 09 13:29:06 volumio volumio[1104]: info: CorePlayQueue::getTrack 1 Jan 09 13:29:06 volumio volumio[1104]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jan 09 13:29:06 volumio volumio[1104]: info: ------------------------------ 431ms Jan 09 13:29:14 volumio go-librespot[6526]: time="2026-01-09T13:29:14Z" level=debug msg="fetched chunk 57/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:29:14 volumio go-librespot[6526]: time="2026-01-09T13:29:14Z" level=trace msg="sent dealer ping" Jan 09 13:29:14 volumio go-librespot[6526]: time="2026-01-09T13:29:14Z" level=trace msg="received dealer pong" Jan 09 13:29:22 volumio volumio[1104]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/ferrum_streaming_control_technology/volumio/bookworm/amd64 Jan 09 13:29:23 volumio volumio[1104]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/ferrum_streaming_control_technology/volumio/bookworm/amd64 Jan 09 13:29:23 volumio volumio[1104]: info: Folder /tmp/plugins removed Jan 09 13:29:23 volumio volumio[1104]: info: Check plugin dependencies Jan 09 13:29:23 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 09 13:29:23 volumio volumio[1104]: info: Checking if plugin already exists Jan 09 13:29:23 volumio volumio[1104]: info: Rename folder Jan 09 13:29:23 volumio volumio[1104]: info: Folder /tmp/downloaded_plugin.zip removed Jan 09 13:29:23 volumio volumio[1104]: info: Move to category Jan 09 13:29:24 volumio volumio[1104]: info: Checking if install.sh is present Jan 09 13:29:24 volumio volumio[1104]: info: Executing install.sh Jan 09 13:29:24 volumio sudo[141932]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/ferrum_streaming_control_technology/install.sh Jan 09 13:29:24 volumio sudo[141932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 09 13:29:24 volumio sudo[141932]: pam_unix(sudo:session): session closed for user root Jan 09 13:29:24 volumio volumio[1104]: info: Installing ferrum streaming control technology Dependencies Jan 09 13:29:24 volumio volumio[1104]: Plugin install end detected on script Jan 09 13:29:24 volumio volumio[1104]: info: Install script completed Jan 09 13:29:24 volumio volumio[1104]: info: Adding reference to registry Jan 09 13:29:24 volumio volumio[1104]: info: Done installing plugin. Jan 09 13:29:24 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 09 13:29:24 volumio volumio[1104]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 09 13:29:24 volumio volumio[1104]: info: Folder /tmp/plugins removed Jan 09 13:29:24 volumio volumio[1104]: info: Folder /tmp/downloaded_plugin.zip removed Jan 09 13:29:24 volumio volumio[1104]: info: Folder /data/temp removed Jan 09 13:29:27 volumio go-librespot[6526]: time="2026-01-09T13:29:27Z" level=debug msg="fetched chunk 58/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:29:28 volumio volumio[1104]: info: Enabling plugin ferrum_streaming_control_technology Jan 09 13:29:28 volumio volumio[1104]: info: Loading plugin "ferrum_streaming_control_technology"... Jan 09 13:29:28 volumio volumio[1104]: error: !!!! WARNING !!!! Jan 09 13:29:28 volumio volumio[1104]: error: The plugin user_interface/ferrum_streaming_control_technology failed to load, setting it to stopped. Error: Error: Cannot find module '@hemspzoo/fsct-lib-linux-x64-gnu' Jan 09 13:29:28 volumio volumio[1104]: Require stack: Jan 09 13:29:28 volumio volumio[1104]: - /data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js Jan 09 13:29:28 volumio volumio[1104]: - /data/plugins/user_interface/ferrum_streaming_control_technology/index.js Jan 09 13:29:28 volumio volumio[1104]: - /volumio/app/pluginmanager.js Jan 09 13:29:28 volumio volumio[1104]: - /volumio/app/index.js Jan 09 13:29:28 volumio volumio[1104]: - /volumio/index.js Jan 09 13:29:28 volumio volumio[1104]: error: Stack trace: Error: Cannot find module '@hemspzoo/fsct-lib-linux-x64-gnu' Jan 09 13:29:28 volumio volumio[1104]: Require stack: Jan 09 13:29:28 volumio volumio[1104]: - /data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js Jan 09 13:29:28 volumio volumio[1104]: - /data/plugins/user_interface/ferrum_streaming_control_technology/index.js Jan 09 13:29:28 volumio volumio[1104]: - /volumio/app/pluginmanager.js Jan 09 13:29:28 volumio volumio[1104]: - /volumio/app/index.js Jan 09 13:29:28 volumio volumio[1104]: - /volumio/index.js Jan 09 13:29:28 volumio volumio[1104]: at Module._resolveFilename (node:internal/modules/cjs/loader:1048:15) Jan 09 13:29:28 volumio volumio[1104]: at Module._load (node:internal/modules/cjs/loader:901:27) Jan 09 13:29:28 volumio volumio[1104]: at Module.require (node:internal/modules/cjs/loader:1115:19) Jan 09 13:29:28 volumio volumio[1104]: at require (node:internal/modules/helpers:130:18) Jan 09 13:29:28 volumio volumio[1104]: at Object. (/data/plugins/user_interface/ferrum_streaming_control_technology/node_modules/@hemspzoo/fsct-lib/index.js:190:31) Jan 09 13:29:28 volumio volumio[1104]: at Module._compile (node:internal/modules/cjs/loader:1233:14) Jan 09 13:29:28 volumio volumio[1104]: at Module._extensions..js (node:internal/modules/cjs/loader:1287:10) Jan 09 13:29:28 volumio volumio[1104]: at Module.load (node:internal/modules/cjs/loader:1091:32) Jan 09 13:29:28 volumio volumio[1104]: at Module._load (node:internal/modules/cjs/loader:938:12) Jan 09 13:29:28 volumio volumio[1104]: at Module.require (node:internal/modules/cjs/loader:1115:19) Jan 09 13:29:28 volumio volumio[1104]: at require (node:internal/modules/helpers:130:18) Jan 09 13:29:28 volumio volumio[1104]: at Object. (/data/plugins/user_interface/ferrum_streaming_control_technology/index.js:25:118) Jan 09 13:29:28 volumio volumio[1104]: at Module._compile (node:internal/modules/cjs/loader:1233:14) Jan 09 13:29:28 volumio volumio[1104]: at Module._extensions..js (node:internal/modules/cjs/loader:1287:10) Jan 09 13:29:28 volumio volumio[1104]: at Module.load (node:internal/modules/cjs/loader:1091:32) Jan 09 13:29:28 volumio volumio[1104]: at Module._load (node:internal/modules/cjs/loader:938:12) Jan 09 13:29:28 volumio volumio[1104]: error: !!!! WARNING !!!! Jan 09 13:29:28 volumio volumio[1104]: info: Done. Jan 09 13:29:41 volumio go-librespot[6526]: time="2026-01-09T13:29:41Z" level=debug msg="fetched chunk 59/89, size: 524288" uri="spotify:track:1Kpg4PeNEOD8LZYKzj5wYT" Jan 09 13:29:42 volumio volumio[1104]: info: Starting Uninstall of plugin user_interface - ferrum_streaming_control_technology Jan 09 13:29:42 volumio volumio[1104]: info: Uninstalling plugin ferrum_streaming_control_technology Jan 09 13:29:44 volumio go-librespot[6526]: time="2026-01-09T13:29:44Z" level=trace msg="sent dealer ping" Jan 09 13:29:44 volumio go-librespot[6526]: time="2026-01-09T13:29:44Z" level=trace msg="received dealer pong" Jan 09 13:29:53 volumio volumio[1104]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/now_playing/volumio/bookworm/amd64 Jan 09 13:29:53 volumio volumio[1104]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 13:29:53 volumio volumio[1104]: TypeError: Cannot read properties of null (reading 'broadcastMessage') Jan 09 13:29:53 volumio volumio[1104]: at /volumio/app/index.js:1534:32 Jan 09 13:29:53 volumio volumio[1104]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Jan 09 13:29:53 volumio volumio[1104]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Jan 09 13:29:53 volumio volumio[1104]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Jan 09 13:29:53 volumio volumio[1104]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Jan 09 13:29:53 volumio volumio[1104]: at PluginManager.installPlugin (/volumio/app/pluginmanager.js:776:8) Jan 09 13:29:53 volumio volumio[1104]: at CoreCommandRouter.installPlugin (/volumio/app/index.js:1453:22) Jan 09 13:29:53 volumio volumio[1104]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1220:47) Jan 09 13:29:53 volumio volumio[1104]: at Socket.emit (node:events:514:28) Jan 09 13:29:53 volumio volumio[1104]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Jan 09 13:29:53 volumio volumio[1104]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jan 09 13:29:53 volumio volumio[1104]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 09 13:29:53 volumio sudo[142027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-09 13:28' Jan 09 13:29:53 volumio sudo[142027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 21:07:15 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4b5c74f40f473b90a542bf010b97924b"