Feb 09 20:22:00 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:22:00 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:22:02 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:22:02 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 9) (YouTube Music) Incoming message: 'noop' Feb 09 20:22:02 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 9) (YouTube Music) Not handled: 'noop' Feb 09 20:22:10 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:22:10 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:22:10 volumio volumio[16058]: info: Listing playlists Feb 09 20:22:10 volumio volumio[16058]: info: Listing playlists Feb 09 20:22:17 volumio go-librespot[16251]: time="2026-02-09T20:22:17+01:00" level=trace msg="sent dealer ping" Feb 09 20:22:17 volumio go-librespot[16251]: time="2026-02-09T20:22:17+01:00" level=trace msg="received dealer pong" Feb 09 20:22:20 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:22:20 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:22:22 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:22:22 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 10) (YouTube) Incoming message: 'noop' Feb 09 20:22:22 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 10) (YouTube) Not handled: 'noop' Feb 09 20:22:26 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:22:26 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 10) (YouTube Music) Incoming message: 'noop' Feb 09 20:22:26 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 10) (YouTube Music) Not handled: 'noop' Feb 09 20:22:30 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:22:30 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:22:30 volumio volumio[16058]: info: Listing playlists Feb 09 20:22:30 volumio volumio[16058]: info: Listing playlists Feb 09 20:22:33 volumio nmbd[1093]: [2026/02/09 20:22:33.871548, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 09 20:22:33 volumio nmbd[1093]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.167 for name WORKGROUP<1d>. Feb 09 20:22:33 volumio nmbd[1093]: This response was from IP 192.168.1.184, reporting an IP address of 192.168.1.184. Feb 09 20:22:40 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:22:40 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:22:47 volumio go-librespot[16251]: time="2026-02-09T20:22:47+01:00" level=trace msg="sent dealer ping" Feb 09 20:22:47 volumio go-librespot[16251]: time="2026-02-09T20:22:47+01:00" level=trace msg="received dealer pong" Feb 09 20:22:48 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:22:48 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 11) (YouTube) Incoming message: 'noop' Feb 09 20:22:48 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 11) (YouTube) Not handled: 'noop' Feb 09 20:22:50 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:22:50 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:22:50 volumio volumio[16058]: info: Listing playlists Feb 09 20:22:50 volumio volumio[16058]: info: Listing playlists Feb 09 20:22:56 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:22:56 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 11) (YouTube Music) Incoming message: 'noop' Feb 09 20:22:56 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 11) (YouTube Music) Not handled: 'noop' Feb 09 20:23:00 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:00 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:23:10 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:10 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:23:10 volumio volumio[16058]: info: Listing playlists Feb 09 20:23:10 volumio volumio[16058]: info: Listing playlists Feb 09 20:23:15 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:23:15 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 12) (YouTube) Incoming message: 'noop' Feb 09 20:23:15 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 12) (YouTube) Not handled: 'noop' Feb 09 20:23:17 volumio go-librespot[16251]: time="2026-02-09T20:23:17+01:00" level=trace msg="sent dealer ping" Feb 09 20:23:17 volumio go-librespot[16251]: time="2026-02-09T20:23:17+01:00" level=trace msg="received dealer pong" Feb 09 20:23:20 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:20 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:23:23 volumio volumio[16058]: verbose: ----------------------------------- Feb 09 20:23:23 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 12) (YouTube Music) Incoming message: 'noop' Feb 09 20:23:23 volumio volumio[16058]: verbose: [yt-cast-receiver] (AID: 12) (YouTube Music) Not handled: 'noop' Feb 09 20:23:30 volumio volumio[16058]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:30 volumio volumio[16058]: info: CorePlayQueue::getTrack 3 Feb 09 20:23:30 volumio volumio[16058]: info: Listing playlists Feb 09 20:23:30 volumio volumio[16058]: info: Listing playlists Feb 09 20:23:35 volumio sudo[16864]: volumio : TTY=pts/3 ; PWD=/data/plugins/music_service/monochrome ; USER=root ; COMMAND=/bin/systemctl restart volumio Feb 09 20:23:35 volumio sudo[16864]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Feb 09 20:23:35 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 09 20:23:35 volumio systemd[1]: Stopping volumio.service - Volumio Backend Module... Feb 09 20:23:35 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 09 20:23:35 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:35.722+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Feb 09 20:23:35 volumio go-librespot[16251]: time="2026-02-09T20:23:35+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Feb 09 20:23:35 volumio systemd[1]: volumio.service: Deactivated successfully. Feb 09 20:23:35 volumio volumio-remote-updater[714]: [2026-02-09 20:23:35] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 09 20:23:35 volumio volumio-remote-updater[714]: [2026-02-09 20:23:35] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 09 20:23:35 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 09 20:23:35 volumio systemd[1]: volumio.service: Consumed 25.399s CPU time. Feb 09 20:23:35 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:35.729+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Feb 09 20:23:35 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 09 20:23:35 volumio sudo[16864]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:36 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:36 volumio volumio[16889]: info: ----- Volumio3 ---- Feb 09 20:23:36 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:36 volumio volumio[16889]: info: ----- System startup ---- Feb 09 20:23:36 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:37 volumio volumio[16889]: info: MYVOLUMIO Environment detected Feb 09 20:23:37 volumio volumio[16889]: info: Plugin folders cleanup Feb 09 20:23:37 volumio volumio[16889]: info: Scanning into folder /volumio/app/plugins/ Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category audio_interface Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category miscellanea Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category music_service Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category plugins.json Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category system_controller Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category user_interface Feb 09 20:23:37 volumio volumio[16889]: info: Scanning into folder /data/plugins/ Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category music_service Feb 09 20:23:37 volumio volumio[16889]: info: Scanning category user_interface Feb 09 20:23:37 volumio volumio[16889]: info: Plugin folders cleanup completed Feb 09 20:23:37 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:37 volumio volumio[16889]: info: ----- Core plugins startup ---- Feb 09 20:23:37 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugins from folder /volumio/app/plugins/ Feb 09 20:23:37 volumio volumio[16889]: info: Adding plugin upnp to MyMusic Plugins Feb 09 20:23:37 volumio volumio[16889]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 09 20:23:37 volumio volumio[16889]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugins from folder /data/plugins/ Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "system"... Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "appearance"... Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "network"... Feb 09 20:23:37 volumio volumio[16889]: info: Refreshing Cached IP Addresses Feb 09 20:23:37 volumio sudo[16914]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 20:23:37 volumio sudo[16914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:37 volumio sudo[16916]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 20:23:37 volumio sudo[16916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:37 volumio sudo[16914]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:37 volumio sudo[16916]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "services"... Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "volumio5onboarding"... Feb 09 20:23:37 volumio sudo[16923]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 09 20:23:37 volumio sudo[16923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "alsa_controller"... Feb 09 20:23:37 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "wizard"... Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "networkfs"... Feb 09 20:23:37 volumio volumio[16889]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Feb 09 20:23:37 volumio volumio[16889]: info: Starting Udev Watcher for removable devices Feb 09 20:23:37 volumio volumio[16889]: info: Ignoring mount for partition: boot Feb 09 20:23:37 volumio volumio[16889]: info: Ignoring mount for partition: volumio Feb 09 20:23:37 volumio volumio[16889]: info: Ignoring mount for partition: volumio_data Feb 09 20:23:37 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "volumio_command_line_client"... Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "upnp"... Feb 09 20:23:37 volumio volumio[16889]: info: [1770665017977] Starting Upmpd Daemon Feb 09 20:23:37 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "my_music"... Feb 09 20:23:37 volumio volumio[16889]: info: Loading plugin "mpd"... Feb 09 20:23:38 volumio volumio[16889]: info: Loading plugin "upnp_browser"... Feb 09 20:23:38 volumio volumio[16889]: info: Starting UPNP Browser Feb 09 20:23:38 volumio volumio[16889]: info: Loading plugin "alarm-clock"... Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "airplay_emulation"... Feb 09 20:23:39 volumio volumio[16889]: info: Starting Shairport Sync Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "last_100"... Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "webradio"... Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "i2s_dacs"... Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "volumiodiscovery"... Feb 09 20:23:39 volumio volumio[16889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 20:23:39 volumio volumio[16889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 20:23:39 volumio volumio[16889]: *** WARNING *** For more information see Feb 09 20:23:39 volumio volumio[16889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 20:23:39 volumio volumio[16889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 20:23:39 volumio node[16889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 09 20:23:39 volumio volumio[16889]: *** WARNING *** For more information see Feb 09 20:23:39 volumio node[16889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 20:23:39 volumio node[16889]: *** WARNING *** For more information see Feb 09 20:23:39 volumio node[16889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 09 20:23:39 volumio node[16889]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 09 20:23:39 volumio node[16889]: *** WARNING *** For more information see Feb 09 20:23:39 volumio volumio[16889]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 09 20:23:39 volumio volumio[16889]: info: Discovery: Started advertising with name: Volumio Feb 09 20:23:39 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "calmradio"... Feb 09 20:23:39 volumio volumio[16889]: info: Loading plugin "spop"... Feb 09 20:23:40 volumio volumio[16889]: info: Loading plugin "ytcr"... Feb 09 20:23:40 volumio volumio-remote-updater[714]: [2026-02-09 20:23:40] [connect] Successful connection Feb 09 20:23:40 volumio volumio[16889]: info: Loading plugin "ytmusic"... Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "outputs"... Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "albumart"... Feb 09 20:23:41 volumio volumio[16889]: info: Plugin example_plugin is not enabled Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "inputs"... Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "updater_comm"... Feb 09 20:23:41 volumio volumio[16889]: info: Plugin mpdemulation is not enabled Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "rest_api"... Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "websocket"... Feb 09 20:23:41 volumio volumio[16889]: info: Starting Socket.io Server version 1.7.4 Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "80s80s"... Feb 09 20:23:41 volumio volumio[16889]: info: Applying required configuration parameters for plugin 80s80s Feb 09 20:23:41 volumio volumio[16889]: info: [1770665021488] [80s80s] API delay: 30 Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "monochrome"... Feb 09 20:23:41 volumio volumio[16948]: Forking 3 albumart workers Feb 09 20:23:41 volumio sudo[16923]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:41 volumio volumio[16889]: info: Monochrome plugin constructor called Feb 09 20:23:41 volumio volumio[16889]: info: Monochrome onVolumioStart called Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "motherearthradio"... Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "rad357pl"... Feb 09 20:23:41 volumio volumio[16889]: info: Applying required configuration parameters for plugin rad357pl Feb 09 20:23:41 volumio volumio[16889]: info: [1770665021774] [rad357pl] API delay: 5 Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "radio_paradise"... Feb 09 20:23:41 volumio volumio[16889]: info: Applying required configuration parameters for plugin radio_paradise Feb 09 20:23:41 volumio volumio[16889]: info: [1770665021933] [RadioParadise] API delay: 5 Feb 09 20:23:41 volumio volumio[16889]: info: Loading plugin "Systeminfo"... Feb 09 20:23:42 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:42.035+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.243:39856 @ 0x1fe85a0" available=true connected=true macAddress=dc:a6:32:35:56:e2 ip4Address=192.168.1.167/24 ip6Address= ssid="OpenWrt 5G" Feb 09 20:23:42 volumio volumio[16889]: info: Loading i18n strings for locale pl Feb 09 20:23:42 volumio volumio[16889]: Updating browse sources language Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::initPlayerControls Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: Express server listening on port 3000 Feb 09 20:23:42 volumio volumio[16889]: [Metrics] WebUI: 5s 815.10ms Feb 09 20:23:42 volumio volumio[16960]: Starting albumart workers Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::resetVolumioState Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::getcurrentVolume Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::pushState Feb 09 20:23:42 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::volumioPushState Feb 09 20:23:42 volumio volumio[16889]: info: Volumio Network Manager: Network status updated: 2 Feb 09 20:23:42 volumio volumio[16959]: Starting albumart workers Feb 09 20:23:42 volumio volumio[16958]: Starting albumart workers Feb 09 20:23:42 volumio volumio[16889]: verbose: New Socket.io Connection to 192.168.1.167 from 192.168.1.157 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 09 20:23:42 volumio volumio[16889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: Reloading queue from file Feb 09 20:23:42 volumio volumio[16889]: verbose: New Socket.io Connection to 192.168.1.167 from 192.168.1.157 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 2 Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::setRepeat false single undefined Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::pushState Feb 09 20:23:42 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::volumioPushState Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::setRandom false Feb 09 20:23:42 volumio volumio[16889]: info: CoreStateMachine::pushState Feb 09 20:23:42 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::volumioPushState Feb 09 20:23:42 volumio volumio[16889]: info: Setting Device type: Raspberry PI Feb 09 20:23:42 volumio volumio[16889]: verbose: New Socket.io Connection to 192.168.1.167 from 192.168.1.157 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 09 20:23:42 volumio volumio[16889]: info: Completed loading Core Plugins Feb 09 20:23:42 volumio volumio[16889]: info: Preparing to generate the ALSA configuration file Feb 09 20:23:42 volumio volumio[16889]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 09 20:23:42 volumio volumio[16889]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03111 Feb 09 20:23:42 volumio volumio[16889]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:42 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:42 volumio volumio-remote-updater[714]: [2026-02-09 20:23:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770665020 101 Feb 09 20:23:42 volumio volumio[16889]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Feb 09 20:23:42 volumio volumio[16889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 09 20:23:42 volumio volumio[16889]: info: Asound.conf file unchanged, so no further update is needed Feb 09 20:23:42 volumio volumio[16889]: info: Output device has changed, restarting MPD Feb 09 20:23:42 volumio volumio[16889]: info: Output device has changed, restarting Shairport Sync Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:42 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:42 volumio sudo[17006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 20:23:42 volumio sudo[17006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:42 volumio sudo[17006]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:42 volumio sudo[17008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 20:23:42 volumio sudo[17008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:42 volumio volumio[16889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 20:23:42 volumio volumio[16889]: info: ___________ START PLUGINS ___________ Feb 09 20:23:43 volumio volumio[16889]: info: ControllerMpd::onStart: Initializing MPD Feb 09 20:23:43 volumio volumio[16889]: info: Creating MPD Configuration file Feb 09 20:23:43 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 09 20:23:43 volumio sudo[17019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 09 20:23:43 volumio sudo[17019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:43 volumio sudo[17027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 09 20:23:43 volumio sudo[17027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:43 volumio sudo[17027]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023055] CoreMusicLibrary::Adding element Serwery Mediów Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 20:23:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 20:23:43 volumio systemd[1]: mpd.service: Consumed 1.908s CPU time. Feb 09 20:23:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 20:23:43 volumio sudo[17032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 09 20:23:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 20:23:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 20:23:43 volumio sudo[17032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:43 volumio volumio[16889]: info: UPNP Browser: Client initialized successfully Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023125] CoreMusicLibrary::Adding element Last_100 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023128] CoreMusicLibrary::Adding element Webradio Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 20:23:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 20:23:43 volumio volumio[16889]: info: Initializing BBC Radios Feb 09 20:23:43 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 09 20:23:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 09 20:23:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 09 20:23:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 09 20:23:43 volumio sudo[17019]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 09 20:23:43 volumio volumio[16889]: info: Adding Calm Radio to Browse Sources Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023186] CoreMusicLibrary::Adding element Calm Radio Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 09 20:23:43 volumio volumio[16889]: info: Creating Spotify config file Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio sudo[17060]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 09 20:23:43 volumio sudo[17060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 09 20:23:43 volumio sudo[17060]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023369] CoreMusicLibrary::Adding element YouTube Music Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023374] CoreMusicLibrary::Adding element 80s80s Radio Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source 80s80s Radio Feb 09 20:23:43 volumio volumio[16889]: info: Monochrome onStart called Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023429] CoreMusicLibrary::Adding element Monochrome Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source 80s80s Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Monochrome Feb 09 20:23:43 volumio volumio[16889]: info: Added Monochrome to browse sources Feb 09 20:23:43 volumio volumio[16889]: error: [Monochrome] Error finding MPD plugin: pluginManager.getPlugins is not a function Feb 09 20:23:43 volumio volumio[16889]: info: Monochrome plugin started successfully Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023433] CoreMusicLibrary::Adding element Mother Earth Radio Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source 80s80s Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Monochrome Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Mother Earth Radio Feb 09 20:23:43 volumio volumio[16889]: info: [MER] Plugin started (SSE mode) Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023438] CoreMusicLibrary::Adding element RADIO 357 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source 80s80s Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Monochrome Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Mother Earth Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source RADIO 357 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:43 volumio volumio[16889]: info: [1770665023442] CoreMusicLibrary::Adding element Radio Paradise Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source 80s80s Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Monochrome Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Mother Earth Radio Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source RADIO 357 Feb 09 20:23:43 volumio volumio[16889]: Cannot find translation for source Radio Paradise Feb 09 20:23:43 volumio volumio[16889]: info: Volumio Calling Home Feb 09 20:23:43 volumio volumio[16889]: verbose: [yt-cast-receiver] Setting app pid to stored value: 2809e844-55a2-4a96-ae3c-2048f0cabddd Feb 09 20:23:43 volumio volumio[16889]: verbose: [yt-cast-receiver] Starting YouTubeApp... Feb 09 20:23:43 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube) Configuring session with stored MDX context: Feb 09 20:23:43 volumio volumio[16889]: { Feb 09 20:23:43 volumio volumio[16889]: deviceId: 'a58f512f-6e78-4df2-b44b-3169552fec2c', Feb 09 20:23:43 volumio volumio[16889]: screenId: 'p3581il0mm6inksjf9o2vmldv6' Feb 09 20:23:43 volumio volumio[16889]: } Feb 09 20:23:43 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube Music) Configuring session with stored MDX context: Feb 09 20:23:43 volumio volumio[16889]: { Feb 09 20:23:43 volumio volumio[16889]: deviceId: '6f2cf9b8-85c1-47a5-ba32-6c9c61a3e396', Feb 09 20:23:43 volumio volumio[16889]: screenId: 'hpv8pke8toeuvtvlb6gg6hlc65' Feb 09 20:23:43 volumio volumio[16889]: } Feb 09 20:23:43 volumio volumio[16889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 09 20:23:43 volumio volumio[16889]: info: Received Get System Info Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 09 20:23:43 volumio volumio[16889]: info: Discovery: Getting this device information Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:43 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 09 20:23:43 volumio volumio[16889]: info: Discovery: adding 6c7a6f07-44c6-4605-ac41-e0f763f26d43 Feb 09 20:23:43 volumio volumio[16889]: info: Discovery: Found device Volumio Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:43 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:43 volumio volumio[16889]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 09 20:23:43 volumio volumio[16889]: info: MPD Permissions set Feb 09 20:23:43 volumio volumio[16889]: info: MPD Permissions set Feb 09 20:23:43 volumio volumio[16889]: info: Volumio called home Feb 09 20:23:43 volumio volumio[16889]: info: Spotify config file written Feb 09 20:23:43 volumio volumio[16889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio sudo[17067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 09 20:23:43 volumio sudo[17067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 09 20:23:43 volumio systemd[1]: go-librespot-daemon.service: Killing process 16619 (go-librespot) with signal SIGKILL. Feb 09 20:23:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 09 20:23:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 09 20:23:43 volumio volumio[16889]: info: No need to fix Spotify hosts Feb 09 20:23:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 09 20:23:43 volumio sudo[17067]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:43 volumio go-librespot[17079]: go-librespot daemon starting... Feb 09 20:23:43 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:43 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:43 volumio volumio[16889]: info: Starting Shairport Sync Feb 09 20:23:43 volumio go-librespot[17081]: time="2026-02-09T20:23:43+01:00" level=info msg="running go-librespot 0.6.2" Feb 09 20:23:43 volumio go-librespot[17081]: time="2026-02-09T20:23:43+01:00" level=debug msg="app state loaded" Feb 09 20:23:43 volumio volumio[16889]: info: Starting Shairport Sync Feb 09 20:23:43 volumio volumio[16889]: info: Starting Shairport Sync Feb 09 20:23:43 volumio go-librespot[17081]: time="2026-02-09T20:23:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 09 20:23:43 volumio sudo[17089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 20:23:43 volumio sudo[17089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:43 volumio sudo[17092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 20:23:43 volumio sudo[17092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:43 volumio sudo[17094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 09 20:23:43 volumio sudo[17094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:44 volumio volumio[16889]: info: New Spotify access tokenBQBsZmjRiU... Feb 09 20:23:44 volumio volumio[16889]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 09 20:23:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 09 20:23:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 09 20:23:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 20:23:44 volumio systemd[1]: shairport-sync.service: Consumed 2.127s CPU time. Feb 09 20:23:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 09 20:23:44 volumio sudo[17094]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:44 volumio sudo[17089]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:44 volumio sudo[17092]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:44 volumio volumio[16889]: info: Shairport-Sync Started Feb 09 20:23:44 volumio volumio[16889]: Error adding Membership: Error: addMembership EINVAL Feb 09 20:23:44 volumio volumio[16889]: info: Shairport-Sync Started Feb 09 20:23:44 volumio volumio[16889]: info: Shairport-Sync Started Feb 09 20:23:44 volumio mpd[17062]: 2026-02-09T20:23:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 09 20:23:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 09 20:23:44 volumio sudo[17008]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:44 volumio sudo[17032]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:44 volumio volumio[16889]: error: MPD error: The expression evaluated to a falsy value: Feb 09 20:23:44 volumio volumio[16889]: assert.ok(self.idling) Feb 09 20:23:44 volumio volumio[16889]: error: The expression evaluated to a falsy value: Feb 09 20:23:44 volumio volumio[16889]: assert.ok(self.idling) Feb 09 20:23:44 volumio volumio[16889]: info: CoreCommandRouter::volumioGetQueue Feb 09 20:23:44 volumio volumio[16889]: info: CoreStateMachine::getQueue Feb 09 20:23:44 volumio volumio[16889]: info: CorePlayQueue::getQueue Feb 09 20:23:44 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Feb 09 20:23:44 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getUpdaterChannel Feb 09 20:23:44 volumio volumio[16889]: info: CALLMETHOD: music_service inputs serialMonitorAction [object Object] Feb 09 20:23:44 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: inputs , serialMonitorAction Feb 09 20:23:44 volumio volumio[16889]: info: Error : CoreCommandRouter::executeOnPlugin: No method [serialMonitorAction] in plugin inputs Feb 09 20:23:44 volumio volumio[16889]: info: CALLMETHOD: system_controller motivocontrol displaySelection [object Object] Feb 09 20:23:44 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: motivocontrol , displaySelection Feb 09 20:23:44 volumio volumio[16889]: info: MPD running with PID17062 Feb 09 20:23:44 volumio volumio[16889]: ,establishing connection Feb 09 20:23:44 volumio volumio[16889]: error: updateQueue error: null Feb 09 20:23:44 volumio volumio[16889]: error: updateQueue error: null Feb 09 20:23:45 volumio go-librespot[17081]: time="2026-02-09T20:23:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 09 20:23:45 volumio go-librespot[17081]: time="2026-02-09T20:23:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 09 20:23:45 volumio go-librespot[17081]: time="2026-02-09T20:23:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 09 20:23:45 volumio go-librespot[17081]: time="2026-02-09T20:23:45+01:00" level=info msg="zeroconf server listening on port 36963" Feb 09 20:23:45 volumio volumio[16889]: verbose: New Socket.io Connection to 192.168.1.167 from 192.168.1.157 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::volumioGetVisibleSources Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:45 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:45 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 09 20:23:45 volumio volumio[16889]: info: Received Get System Info Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 09 20:23:45 volumio volumio[16889]: info: Discovery: Getting this device information Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:45 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:45 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:45 volumio volumio[16889]: info: Listing playlists Feb 09 20:23:45 volumio volumio[16889]: info: CoreCommandRouter::volumioGetQueue Feb 09 20:23:45 volumio volumio[16889]: info: CoreStateMachine::getQueue Feb 09 20:23:45 volumio volumio[16889]: info: CorePlayQueue::getQueue Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="obtained new client token: AACJ7EPMKIS5HkQbZpyuWZdqn/Kq6xSlyEMxlR2C0480OIoqKyFJb+/sJXHbktnZwyW2cwxE4JITIKDU3POq+pQqTzL19FmcYlhNUnPkPeOLFK4iwvpHGT9U39xw4BQg1Iwm8GTWCqSF2p3/6Cg5XbeBo4LPMNfcWEpPLemsCSvGmud3zhVg89Ag/Vw21W0JKYoGlKrWCn4/uiW2gfbdIjpccxfD3A9cuM6tEyN9uDDRcdHv1IFRkO38bg==" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="completed keyexchange" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="completed challenge" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=info msg="authenticated AP" username="31************************lm" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=info msg="authenticated Login5" username="31************************lm" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="initializing zeroconf session" username="31************************lm" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="dealer connection opened" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=trace msg="starting accesspoint recv loop" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=trace msg="starting dealer recv loop" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=trace msg="received accesspoint ping" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="received connection id: YjczNGNkOGMtZDAx...NDEyQUJERDdFRQ==" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=trace msg="received accesspoint pong ack" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="update volume requested to 65535/65535" Feb 09 20:23:46 volumio volumio[16889]: info: go-librespot daemon successfully initialized Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 09 20:23:46 volumio go-librespot[17081]: time="2026-02-09T20:23:46+01:00" level=trace msg="emitting websocket event: volume" Feb 09 20:23:48 volumio sudo[17150]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 09 20:23:48 volumio sudo[17150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:48 volumio sudo[17150]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:48 volumio sudo[17152]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 09 20:23:48 volumio sudo[17152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:48 volumio sudo[17152]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:48 volumio sudo[17156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 09 20:23:48 volumio sudo[17156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 09 20:23:48 volumio sudo[17156]: pam_unix(sudo:session): session closed for user root Feb 09 20:23:48 volumio volumio[16889]: info: Upmpdcli Daemon Started Feb 09 20:23:48 volumio volumio[16889]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Feb 09 20:23:48 volumio volumio[16889]: info: Discovery: this is already registered, 6c7a6f07-44c6-4605-ac41-e0f763f26d43 Feb 09 20:23:48 volumio volumio[16889]: info: Discovery: Found device Volumio Feb 09 20:23:48 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:48 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:48 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:48.664+01:00 level=INFO msg="enabling BLE discovery" Feb 09 20:23:48 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:48 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:48 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube) Obtained lounge token: Feb 09 20:23:48 volumio volumio[16889]: { Feb 09 20:23:48 volumio volumio[16889]: screenId: 'p3581il0mm6inksjf9o2vmldv6', Feb 09 20:23:48 volumio volumio[16889]: refreshIntervalInMillis: 1123200000, Feb 09 20:23:48 volumio volumio[16889]: remoteRefreshIntervalMs: 79200000, Feb 09 20:23:48 volumio volumio[16889]: refreshIntervalMs: 1123200000, Feb 09 20:23:48 volumio volumio[16889]: loungeTokenLifespanMs: 1209600000, Feb 09 20:23:48 volumio volumio[16889]: loungeToken: 'AGdO5p-TXL9QWqT7pWIMXNf1UudXBetyC9aMNtfDQkRtOtHOpyV5usYUp921EulptOgtSp9ndM604ptBl3c7c4QJPY9umWfTMGAbIQVfKsNLz-XjWpm4hw0', Feb 09 20:23:48 volumio volumio[16889]: remoteRefreshIntervalInMillis: 79200000, Feb 09 20:23:48 volumio volumio[16889]: expiration: 1771788228750 Feb 09 20:23:48 volumio volumio[16889]: } Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube) Received messages for establishing session: Feb 09 20:23:49 volumio volumio[16889]: [ Feb 09 20:23:49 volumio volumio[16889]: Message { AID: 0, name: 'c', payload: [ 'CE8AC3ABA3BC1F08', '', 8 ] }, Feb 09 20:23:49 volumio volumio[16889]: Message { Feb 09 20:23:49 volumio volumio[16889]: AID: 1, Feb 09 20:23:49 volumio volumio[16889]: name: 'S', Feb 09 20:23:49 volumio volumio[16889]: payload: 'IC9fwEQL_5Sqqp7u7pQsSAA2iLm2U9ot' Feb 09 20:23:49 volumio volumio[16889]: }, Feb 09 20:23:49 volumio volumio[16889]: Message { Feb 09 20:23:49 volumio volumio[16889]: AID: 2, Feb 09 20:23:49 volumio volumio[16889]: name: 'loungeStatus', Feb 09 20:23:49 volumio volumio[16889]: payload: { Feb 09 20:23:49 volumio volumio[16889]: queueId: 'RQpuhDLoixpMiHlvQHL6V3OjYdWZM', Feb 09 20:23:49 volumio volumio[16889]: devices: '[{"app":"ytcr","capabilities":"dsp,mic,dpa,ntb,que,mus","clientName":"unknown","experiments":"","name":"YouTube on Volumio","theme":"cl","id":"a58f512f-6e78-4df2-b44b-3169552fec2c","type":"LOUNGE_SCREEN","hasCc":"true","deviceInfo":"{\\"year\\":0,\\"os\\":\\"Windows\\",\\"osVersion\\":\\"10.0\\",\\"chipset\\":\\"\\",\\"clientName\\":\\"TVHTML5\\",\\"dialAdditionalDataSupportLevel\\":\\"unsupported\\",\\"mdxDialServerType\\":\\"MDX_DIAL_SERVER_TYPE_UNKNOWN\\",\\"brand\\":\\"Generic\\",\\"model\\":\\"SmartTV\\"}","receiverIdentityMatchStatus":"IS_RECEIVER"}]', Feb 09 20:23:49 volumio volumio[16889]: connectionEventDetails: '{"deviceId":"a58f512f-6e78-4df2-b44b-3169552fec2c"}' Feb 09 20:23:49 volumio volumio[16889]: } Feb 09 20:23:49 volumio volumio[16889]: }, Feb 09 20:23:49 volumio volumio[16889]: Message { AID: 3, name: 'getNowPlaying', payload: {} }, Feb 09 20:23:49 volumio volumio[16889]: Message { AID: 4, name: 'getDiscoveryDeviceId', payload: {} } Feb 09 20:23:49 volumio volumio[16889]: ] Feb 09 20:23:49 volumio volumio[16889]: verbose: ----------------------------------- Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] (AID: 2) (YouTube) Incoming message: 'loungeStatus' Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=3&CI=0&RID=rpc&SID=CE8AC3ABA3BC1F08&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=IC9fwEQL_5Sqqp7u7pQsSAA2iLm2U9ot&id=a58f512f-6e78-4df2-b44b-3169552fec2c&loungeIdToken=AGdO5p-TXL9QWqT7pWIMXNf1UudXBetyC9aMNtfDQkRtOtHOpyV5usYUp921EulptOgtSp9ndM604ptBl3c7c4QJPY9umWfTMGAbIQVfKsNLz-XjWpm4hw0&mdxVersion=2&name=YouTube%20on%20Volumio&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=83e6dc56f1f0 Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] RPC connection established. Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube) Session established. Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube) Saving MDX context to data store: Feb 09 20:23:49 volumio volumio[16889]: { Feb 09 20:23:49 volumio volumio[16889]: deviceId: 'a58f512f-6e78-4df2-b44b-3169552fec2c', Feb 09 20:23:49 volumio volumio[16889]: screenId: 'p3581il0mm6inksjf9o2vmldv6' Feb 09 20:23:49 volumio volumio[16889]: } Feb 09 20:23:49 volumio volumio[16889]: verbose: ----------------------------------- Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] (AID: 4) (YouTube) Incoming message: 'getDiscoveryDeviceId' Feb 09 20:23:49 volumio volumio[16889]: verbose: [yt-cast-receiver] (AID: 4) (YouTube) Not handled: 'getDiscoveryDeviceId' Feb 09 20:23:49 volumio volumio[16889]: SPOTIFY: User informations: {"country":"PL","display_name":"Blackscreener","email":"blackscreener@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31y6xmrpyo7ug3lj2udb4q7b6wlm"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31y6xmrpyo7ug3lj2udb4q7b6wlm","id":"31y6xmrpyo7ug3lj2udb4q7b6wlm","images":[],"product":"premium","type":"user","uri":"spotify:user:31y6xmrpyo7ug3lj2udb4q7b6wlm"} Feb 09 20:23:49 volumio volumio[16889]: info: Spotify Successfully logged in Feb 09 20:23:49 volumio volumio[16889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 09 20:23:49 volumio volumio[16889]: info: [1770665029850] CoreMusicLibrary::Adding element Spotify Feb 09 20:23:49 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source Calm Radio Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source YouTube Music Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source 80s80s Radio Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source Monochrome Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source Mother Earth Radio Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source RADIO 357 Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source Radio Paradise Feb 09 20:23:49 volumio volumio[16889]: Cannot find translation for source Spotify Feb 09 20:23:49 volumio volumio[16889]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 09 20:23:49 volumio volumio[16889]: info: Initializing connection to go-librespot Websocket Feb 09 20:23:50 volumio go-librespot[17081]: time="2026-02-09T20:23:50+01:00" level=debug msg="new websocket client" Feb 09 20:23:50 volumio volumio[16889]: info: Connection to go-librespot Websocket established Feb 09 20:23:50 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:50 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:50 volumio volumio[16889]: info: Listing playlists Feb 09 20:23:50 volumio volumio[16889]: info: Listing playlists Feb 09 20:23:51 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube Music) Obtained lounge token: Feb 09 20:23:51 volumio volumio[16889]: { Feb 09 20:23:51 volumio volumio[16889]: screenId: 'hpv8pke8toeuvtvlb6gg6hlc65', Feb 09 20:23:51 volumio volumio[16889]: refreshIntervalInMillis: 1123200000, Feb 09 20:23:51 volumio volumio[16889]: remoteRefreshIntervalMs: 79200000, Feb 09 20:23:51 volumio volumio[16889]: refreshIntervalMs: 1123200000, Feb 09 20:23:51 volumio volumio[16889]: loungeTokenLifespanMs: 1209600000, Feb 09 20:23:51 volumio volumio[16889]: loungeToken: 'AGdO5p_rX7OL59Ha5uu7kL1YtCksGSkfha_n8oBPNZbf1XhTzbzLTiXyCfilrDbqjoZL-iNz7q_Xjw2hgmVxYiQVijzJdVezvctrYbnAbh3ocYXZg5v573U', Feb 09 20:23:51 volumio volumio[16889]: remoteRefreshIntervalInMillis: 79200000, Feb 09 20:23:51 volumio volumio[16889]: expiration: 1771788231700 Feb 09 20:23:51 volumio volumio[16889]: } Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube Music) Received messages for establishing session: Feb 09 20:23:52 volumio volumio[16889]: [ Feb 09 20:23:52 volumio volumio[16889]: Message { AID: 0, name: 'c', payload: [ 'DAF29AA3AFC8061A', '', 8 ] }, Feb 09 20:23:52 volumio volumio[16889]: Message { Feb 09 20:23:52 volumio volumio[16889]: AID: 1, Feb 09 20:23:52 volumio volumio[16889]: name: 'S', Feb 09 20:23:52 volumio volumio[16889]: payload: 'eAzYMrgKmNHZaeDHjkAUXzr_wUgVbPeX' Feb 09 20:23:52 volumio volumio[16889]: }, Feb 09 20:23:52 volumio volumio[16889]: Message { Feb 09 20:23:52 volumio volumio[16889]: AID: 2, Feb 09 20:23:52 volumio volumio[16889]: name: 'loungeStatus', Feb 09 20:23:52 volumio volumio[16889]: payload: { Feb 09 20:23:52 volumio volumio[16889]: queueId: 'RQzhDRK047B1W-dTec7gNzfK2YzdY', Feb 09 20:23:52 volumio volumio[16889]: devices: '[{"app":"ytcr","capabilities":"dsp,mic,dpa,ntb","clientName":"unknown","experiments":"","name":"YouTube on Volumio","theme":"m","id":"6f2cf9b8-85c1-47a5-ba32-6c9c61a3e396","type":"LOUNGE_SCREEN","hasCc":"true","deviceInfo":"{\\"year\\":0,\\"os\\":\\"Windows\\",\\"osVersion\\":\\"10.0\\",\\"chipset\\":\\"\\",\\"clientName\\":\\"TVHTML5\\",\\"dialAdditionalDataSupportLevel\\":\\"unsupported\\",\\"mdxDialServerType\\":\\"MDX_DIAL_SERVER_TYPE_UNKNOWN\\",\\"brand\\":\\"Generic\\",\\"model\\":\\"SmartTV\\"}","receiverIdentityMatchStatus":"IS_RECEIVER"}]', Feb 09 20:23:52 volumio volumio[16889]: connectionEventDetails: '{"deviceId":"6f2cf9b8-85c1-47a5-ba32-6c9c61a3e396"}' Feb 09 20:23:52 volumio volumio[16889]: } Feb 09 20:23:52 volumio volumio[16889]: }, Feb 09 20:23:52 volumio volumio[16889]: Message { AID: 3, name: 'getNowPlaying', payload: {} }, Feb 09 20:23:52 volumio volumio[16889]: Message { AID: 4, name: 'getDiscoveryDeviceId', payload: {} } Feb 09 20:23:52 volumio volumio[16889]: ] Feb 09 20:23:52 volumio volumio[16889]: verbose: ----------------------------------- Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] (AID: 2) (YouTube Music) Incoming message: 'loungeStatus' Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=3&CI=0&RID=rpc&SID=DAF29AA3AFC8061A&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=eAzYMrgKmNHZaeDHjkAUXzr_wUgVbPeX&id=6f2cf9b8-85c1-47a5-ba32-6c9c61a3e396&loungeIdToken=AGdO5p_rX7OL59Ha5uu7kL1YtCksGSkfha_n8oBPNZbf1XhTzbzLTiXyCfilrDbqjoZL-iNz7q_Xjw2hgmVxYiQVijzJdVezvctrYbnAbh3ocYXZg5v573U&mdxVersion=2&name=YouTube%20on%20Volumio&obfuscatedGaiaId=&t=1&theme=m&v=2&zx=2d08b8ebfbc1 Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] RPC connection established. Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube Music) Session established. Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] (YouTube Music) Saving MDX context to data store: Feb 09 20:23:52 volumio volumio[16889]: { Feb 09 20:23:52 volumio volumio[16889]: deviceId: '6f2cf9b8-85c1-47a5-ba32-6c9c61a3e396', Feb 09 20:23:52 volumio volumio[16889]: screenId: 'hpv8pke8toeuvtvlb6gg6hlc65' Feb 09 20:23:52 volumio volumio[16889]: } Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] Starting DIAL server... Feb 09 20:23:52 volumio volumio[16889]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 09 20:23:52 volumio volumio[16889]: info: CoreCommandRouter::volumioRetrievevolume Feb 09 20:23:52 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:52 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:52 volumio volumio[16889]: info: CoreStateMachine::pushState Feb 09 20:23:52 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:52 volumio volumio[16889]: info: CoreCommandRouter::volumioPushState Feb 09 20:23:52 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:52.063+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.243:39856 @ 0x1fe85a0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 09 20:23:52 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:52.063+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.243:39856 @ 0x1fe85a0" id=monochrome://track/107747318 title=Tusz Feb 09 20:23:52 volumio volumio[16889]: error: [ytcr] VolumeControl failed to obtain volume from Volumio: Feb 09 20:23:52 volumio volumio[16889]: (TypeError) Cannot read properties of undefined (reading 'vol') Feb 09 20:23:52 volumio volumio[16889]: TypeError: Cannot read properties of undefined (reading 'vol') Feb 09 20:23:52 volumio volumio[16889]: at VolumeControl.getVolume (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:56:42) Feb 09 20:23:52 volumio volumio[16889]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 09 20:23:52 volumio volumio[16889]: at async VolumeControl.init (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:28:68) Feb 09 20:23:52 volumio volumio[16889]: at async /data/plugins/music_service/ytcr/dist/index.js:346:13 Feb 09 20:23:52 volumio volumio[16889]: verbose: [ytcr] VolumeControl initialized with current volume: Feb 09 20:23:52 volumio volumio[16889]: { level: 0, muted: false } Feb 09 20:23:52 volumio volumio[16889]: verbose: ----------------------------------- Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] (AID: 4) (YouTube Music) Incoming message: 'getDiscoveryDeviceId' Feb 09 20:23:52 volumio volumio[16889]: verbose: [yt-cast-receiver] (AID: 4) (YouTube Music) Not handled: 'getDiscoveryDeviceId' Feb 09 20:23:52 volumio volumio[16889]: verbose: [ytcr] MPD connected Feb 09 20:23:52 volumio volumio[16889]: verbose: [ytcr] MPDSubsystemEventEmitter enabled. Feb 09 20:23:52 volumio volumio[16889]: verbose: [ytcr] Receiver started with options: Feb 09 20:23:52 volumio volumio[16889]: { Feb 09 20:23:52 volumio volumio[16889]: dial: { port: 8098, bindToInterfaces: undefined }, Feb 09 20:23:52 volumio volumio[16889]: app: { Feb 09 20:23:52 volumio volumio[16889]: enableAutoplayOnConnect: true, Feb 09 20:23:52 volumio volumio[16889]: resetPlayerOnDisconnectPolicy: 'allDisconnected' Feb 09 20:23:52 volumio volumio[16889]: }, Feb 09 20:23:52 volumio volumio[16889]: dataStore: ReceiverDataStore {}, Feb 09 20:23:52 volumio volumio[16889]: logger: Logger { level: 'debug', color: true }, Feb 09 20:23:52 volumio volumio[16889]: logLevel: 'debug', Feb 09 20:23:52 volumio volumio[16889]: device: { name: 'Volumio' } Feb 09 20:23:52 volumio volumio[16889]: } Feb 09 20:23:52 volumio volumio[16889]: info: Completed starting Core Plugins Feb 09 20:23:52 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:52 volumio volumio[16889]: info: ----- MyVolumio plugins startup ---- Feb 09 20:23:52 volumio volumio[16889]: info: ------------------------------------------- Feb 09 20:23:52 volumio volumio[16889]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 09 20:23:53 volumio volumio[16889]: info: Getting Spotify volume Feb 09 20:23:53 volumio volumio[16889]: info: Spotify volume: 100 Feb 09 20:23:53 volumio volumio[16889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 09 20:23:53 volumio volumio[16889]: info: CoreCommandRouter::volumioGetState Feb 09 20:23:53 volumio volumio[16889]: info: CorePlayQueue::getTrack 0 Feb 09 20:23:53 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: monochrome , handleBrowseUri Feb 09 20:23:53 volumio volumio[16889]: info: Browse URI: monochrome Feb 09 20:23:53 volumio volumio[16889]: info: Preload queue cleared Feb 09 20:23:53 volumio volumio[16889]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Feb 09 20:23:55 volumio volumio[16889]: Searching plugin music_service/monochrome Feb 09 20:23:55 volumio volumio[16889]: info: CoreCommandRouter::executeOnPlugin: monochrome , search Feb 09 20:23:55 volumio volumio[16889]: info: Memory: RSS=136MB, Heap=62/70MB Feb 09 20:23:55 volumio volumio[16889]: info: Memory before search: 62MB Feb 09 20:23:55 volumio volumio[16889]: info: Monochrome: Starting search for: tymek Feb 09 20:23:55 volumio volumio[16889]: info: Memory: RSS=136MB, Heap=62/70MB Feb 09 20:23:55 volumio volumio[16889]: info: Using search limit: 5 Feb 09 20:23:55 volumio volumio[16889]: info: [Monochrome] Searching tracks: "tymek" with limit: 5 Feb 09 20:23:55 volumio volumio[16889]: [Monochrome API] Searching tracks for: "tymek" Feb 09 20:23:55 volumio volumio[16889]: [Monochrome API] Trying 3 instances for: /search/?s=tymek Feb 09 20:23:55 volumio volumio[16889]: [Monochrome API] Attempt 1/3: https://api.monochrome.tf Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] ? Success from: https://api.monochrome.tf Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Search response received Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Using data.items, count: 25 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 107747318 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '107747318', title: 'Tusz', artist: 'Smolasty', duration: 161 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 489871557 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '489871557', Feb 09 20:23:56 volumio volumio[16889]: title: 'chciałem być kimś (Król dopala', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 229 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 114467228 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '114467228', Feb 09 20:23:56 volumio volumio[16889]: title: 'Będzie Lepiej', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Miyo', Feb 09 20:23:56 volumio volumio[16889]: duration: 185 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 188904502 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '188904502', Feb 09 20:23:56 volumio volumio[16889]: title: "Ostatni (Rojst '97 | Netflix)", Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 220 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 327325145 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '327325145', Feb 09 20:23:56 volumio volumio[16889]: title: 'Sophia Loren', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 170 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 170152340 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '170152340', Feb 09 20:23:56 volumio volumio[16889]: title: 'Język ciała', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 201 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 154098974 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '154098974', title: "80's", artist: 'Tymek', duration: 139 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 162574652 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '162574652', Feb 09 20:23:56 volumio volumio[16889]: title: 'Oczko w głowie', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 176 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 170152344 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '170152344', Feb 09 20:23:56 volumio volumio[16889]: title: 'Poza kontrolą', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 164 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 107370095 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '107370095', title: 'Slow Mo', artist: 'Wiatr', duration: 164 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 404583764 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '404583764', Feb 09 20:23:56 volumio volumio[16889]: title: 'Sophia Loren 3AM', Feb 09 20:23:56 volumio volumio[16889]: artist: 'DJ Remo', Feb 09 20:23:56 volumio volumio[16889]: duration: 171 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 434433999 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '434433999', Feb 09 20:23:56 volumio volumio[16889]: title: 'Anioły i Demony', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 211 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 434433989 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '434433989', title: 'Rainman', artist: 'Tymek', duration: 226 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 82070379 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '82070379', title: 'Ona', artist: 'Tymek', duration: 172 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 154098984 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '154098984', Feb 09 20:23:56 volumio volumio[16889]: title: 'Klubowa Suka', Feb 09 20:23:56 volumio volumio[16889]: artist: 'C0PIK', Feb 09 20:23:56 volumio volumio[16889]: duration: 122 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 146256202 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '146256202', Feb 09 20:23:56 volumio volumio[16889]: title: 'TRANQUILLO', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 162 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 199030898 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '199030898', Feb 09 20:23:56 volumio volumio[16889]: title: 'Anastazja', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Szczyl', Feb 09 20:23:56 volumio volumio[16889]: duration: 183 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 492296529 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '492296529', Feb 09 20:23:56 volumio volumio[16889]: title: 'Lovers of Ursa Major', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 398 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 267707714 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '267707714', Feb 09 20:23:56 volumio volumio[16889]: title: 'Dementor', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Filipek', Feb 09 20:23:56 volumio volumio[16889]: duration: 240 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 154098993 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '154098993', Feb 09 20:23:56 volumio volumio[16889]: title: 'Poza kontrolą', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 164 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 149627565 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '149627565', title: 'Kultowe', artist: 'Tymek', duration: 202 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 122881642 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:56 volumio volumio[16889]: id: '122881642', Feb 09 20:23:56 volumio volumio[16889]: title: 'Bravi Ragazzi', Feb 09 20:23:56 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:56 volumio volumio[16889]: duration: 159 Feb 09 20:23:56 volumio volumio[16889]: } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 148119796 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '148119796', title: 'Mimosa', artist: 'Tymek', duration: 218 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 124438229 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '124438229', title: 'Hollow', artist: 'Tymek', duration: 201 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Preparing track ID: 151365067 Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] Prepared track: { id: '151365067', title: 'Beautiful', artist: 'Tymek', duration: 172 } Feb 09 20:23:56 volumio volumio[16889]: [Monochrome API] ? Search successful, returning 25 tracks Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] API returned 25 tracks, limiting to 5 Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] Processing track 0: id=107747318, title="Tusz" Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Using track.cover: 7a8b5cd7-9be3-4d8f-9099-77d4855abd45... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Generated cover URL: https://resources.tidal.com/images/7a8b5cd7/9be3/4d8f/9099/7... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Cached metadata for track 107747318 Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Prepared track: "Tusz" - Smolasty Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] Processing track 1: id=489871557, title="chciałem być kimś (Król dopalaczy)" Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Using track.cover: c6986c8f-86c9-4383-90c1-82b50c67a7e5... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Generated cover URL: https://resources.tidal.com/images/c6986c8f/86c9/4383/90c1/8... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Cached metadata for track 489871557 Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Prepared track: "chciałem być kimś (Król dopala" - Tymek Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] Processing track 2: id=114467228, title="Będzie Lepiej" Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Using track.cover: 93b74260-835f-4166-9356-fb39bea02df8... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Generated cover URL: https://resources.tidal.com/images/93b74260/835f/4166/9356/f... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Cached metadata for track 114467228 Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Prepared track: "Będzie Lepiej" - Miyo Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] Processing track 3: id=188904502, title="Ostatni (Rojst '97 | Netflix)" Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Using track.cover: 5de0bfd9-eb1c-436f-9ab6-18235b598a8a... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Generated cover URL: https://resources.tidal.com/images/5de0bfd9/eb1c/436f/9ab6/1... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Cached metadata for track 188904502 Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Prepared track: "Ostatni (Rojst '97 | Netflix)" - Tymek Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] Processing track 4: id=327325145, title="Sophia Loren" Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Using track.cover: 20248850-b12f-40c7-9188-b6b1f3fa3bac... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Generated cover URL: https://resources.tidal.com/images/20248850/b12f/40c7/9188/b... Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Cached metadata for track 327325145 Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] ? Prepared track: "Sophia Loren" - Tymek Feb 09 20:23:56 volumio volumio[16889]: info: [Monochrome] Successfully prepared 5 tracks Feb 09 20:23:56 volumio volumio[16889]: info: Creating list with 5 tracks Feb 09 20:23:56 volumio volumio[16889]: info: Search completed: 5 tracks Feb 09 20:23:56 volumio volumio[16889]: info: Returning 1 search sections to Volumio Feb 09 20:23:56 volumio volumio[16889]: info: All search sources collected, pushing search results Feb 09 20:23:56 volumio volumio[16889]: info: Memory: RSS=136MB, Heap=60/70MB Feb 09 20:23:56 volumio volumio[16889]: info: Memory after search: 60MB (delta: -2MB) Feb 09 20:23:57 volumio volumio[16889]: info: Memory: RSS=136MB, Heap=60/70MB Feb 09 20:23:57 volumio volumio[16889]: info: Preload queue cleared Feb 09 20:23:57 volumio volumio[16889]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 09 20:23:57 volumio volumio[16889]: info: CoreStateMachine::ClearQueue Feb 09 20:23:57 volumio volumio[16889]: info: CoreStateMachine::stop Feb 09 20:23:57 volumio volumio[16889]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 20:23:57 volumio volumio[16889]: info: CorePlayQueue::clearPlayQueue Feb 09 20:23:57 volumio volumio[16889]: info: CorePlayQueue::saveQueue Feb 09 20:23:57 volumio volumio[16889]: info: CoreCommandRouter::volumioPushQueue Feb 09 20:23:57 volumio volumio[16889]: info: CoreStateMachine::addQueueItems Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::addQueueItems Feb 09 20:23:58 volumio volumio[16889]: info: Preload queue cleared Feb 09 20:23:58 volumio volumio[16889]: info: Adding Item to queue: monochrome://track/107747318 Feb 09 20:23:58 volumio volumio[16889]: info: Exploding uri monochrome://track/107747318 in service monochrome Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] explodeUri for: monochrome://track/107747318 Feb 09 20:23:58 volumio volumio[16889]: info: Using cached metadata for 107747318 (age: 2s) Feb 09 20:23:58 volumio volumio[16889]: info: Adding Item to queue: monochrome://track/489871557 Feb 09 20:23:58 volumio volumio[16889]: info: Exploding uri monochrome://track/489871557 in service monochrome Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] explodeUri for: monochrome://track/489871557 Feb 09 20:23:58 volumio volumio[16889]: info: Using cached metadata for 489871557 (age: 2s) Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioPushQueue Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::saveQueue Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::updateTrackBlock Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::getTrackBlock Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioPlay Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::play index 1 Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::addQueueItems Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::addQueueItems Feb 09 20:23:58 volumio volumio[16889]: info: Preload queue cleared Feb 09 20:23:58 volumio volumio[16889]: info: Adding Item to queue: monochrome://track/114467228 Feb 09 20:23:58 volumio volumio[16889]: info: Exploding uri monochrome://track/114467228 in service monochrome Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] explodeUri for: monochrome://track/114467228 Feb 09 20:23:58 volumio volumio[16889]: info: Using cached metadata for 114467228 (age: 2s) Feb 09 20:23:58 volumio volumio[16889]: info: Adding Item to queue: monochrome://track/188904502 Feb 09 20:23:58 volumio volumio[16889]: info: Exploding uri monochrome://track/188904502 in service monochrome Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] explodeUri for: monochrome://track/188904502 Feb 09 20:23:58 volumio volumio[16889]: info: Using cached metadata for 188904502 (age: 2s) Feb 09 20:23:58 volumio volumio[16889]: info: Adding Item to queue: monochrome://track/327325145 Feb 09 20:23:58 volumio volumio[16889]: info: Exploding uri monochrome://track/327325145 in service monochrome Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] explodeUri for: monochrome://track/327325145 Feb 09 20:23:58 volumio volumio[16889]: info: Using cached metadata for 327325145 (age: 2s) Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::stop Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::play index undefined Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::getTrack 1 Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::startPlaybackTimer Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::getTrack 1 Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] clearAddPlayTrack calling playTrackDirect Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] playTrackDirect for: 489871557 Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Cache hit for track metadata: 489871557 Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Getting metadata for track: 489871557 Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioPushQueue Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::saveQueue Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::updateTrackBlock Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::getTrackBlock Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Trying 3 instances for: /info/?id=489871557 Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Attempt 1/3: https://api.monochrome.tf Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] ? Success from: https://api.monochrome.tf Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Preparing track ID: 489871557 Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Prepared track: { Feb 09 20:23:58 volumio volumio[16889]: id: '489871557', Feb 09 20:23:58 volumio volumio[16889]: title: 'chciałem być kimś (Król dopala', Feb 09 20:23:58 volumio volumio[16889]: artist: 'Tymek', Feb 09 20:23:58 volumio volumio[16889]: duration: 229 Feb 09 20:23:58 volumio volumio[16889]: } Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Metadata retrieved for: 489871557 Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Getting FRESH stream URL for track: 489871557 (quality: LOSSLESS) Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Trying endpoint: /track/?id=489871557&quality=LOSSLESS Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Trying 3 instances for: /track/?id=489871557&quality=LOSSLESS Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Attempt 1/3: https://api.monochrome.tf Feb 09 20:23:58 volumio volumio[16889]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] ? Success from: https://api.monochrome.tf Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Manifest MIME type: application/vnd.tidal.bts Feb 09 20:23:58 volumio volumio[16889]: [Monochrome API] Fresh stream URL for 489871557: https://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiRiNzIxZjVlNjI0NThjZmNjNzk4NzliZTYyNmQyZjdkNS5tcDQ/... Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] Got stream URL for: 489871557 Feb 09 20:23:58 volumio volumio[16889]: info: [Monochrome] Using simple Volumio methods Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioStop Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::stop Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioClearQueue Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::ClearQueue Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::stop Feb 09 20:23:58 volumio volumio[16889]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::clearPlayQueue Feb 09 20:23:58 volumio volumio[16889]: info: CorePlayQueue::saveQueue Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioPushState Feb 09 20:23:58 volumio volumio[16889]: info: CoreCommandRouter::volumioPushQueue Feb 09 20:23:58 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:58.724+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.243:39856 @ 0x1fe85a0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 09 20:23:58 volumio volumio5-onboarding[1628]: time=2026-02-09T20:23:58.724+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.243:39856 @ 0x1fe85a0" id= title= Feb 09 20:23:58 volumio volumio[16889]: MONOCHROME - UNCAUGHT EXCEPTION (non-critical): self.commandRouter.volumioAddToQueue is not a function Feb 09 20:23:58 volumio volumio[16889]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 20:23:58 volumio volumio[16889]: TypeError: self.commandRouter.volumioAddToQueue is not a function Feb 09 20:23:58 volumio volumio[16889]: at Timeout._onTimeout (/data/plugins/music_service/monochrome/index.js:2237:36) Feb 09 20:23:58 volumio volumio[16889]: at listOnTimeout (node:internal/timers:573:17) Feb 09 20:23:58 volumio volumio[16889]: at process.processTimers (node:internal/timers:514:7) Feb 09 20:23:58 volumio volumio[16889]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 20:23:59 volumio sudo[17208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-09 20:22' Feb 09 20:23:59 volumio sudo[17208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"