Jan 26 13:42:00 volumiopc volumio[15316]: info: New Spotify access tokenBQA6GlG26h... Jan 26 13:42:00 volumiopc volumio[15316]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 13:42:04 volumiopc go-librespot[15531]: time="2026-01-26T13:42:04Z" level=debug msg="new websocket client" Jan 26 13:42:04 volumiopc volumio[15316]: info: Connection to go-librespot Websocket established Jan 26 13:42:04 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:42:04 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:42:05 volumiopc volumio[15316]: SPOTIFY: User informations: {"country":"GB","display_name":"briandupling","email":"ian@theburberrys.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/briandupling"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/briandupling","id":"briandupling","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85fff01b84009dae594b3dfb5b","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82fff01b84009dae594b3dfb5b","width":64}],"product":"premium","type":"user","uri":"spotify:user:briandupling"} Jan 26 13:42:05 volumiopc volumio[15316]: info: Spotify Successfully logged in Jan 26 13:42:05 volumiopc volumio[15316]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:42:05 volumiopc volumio[15316]: info: [1769434925661] CoreMusicLibrary::Adding element Spotify Jan 26 13:42:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:42:05 volumiopc volumio[15316]: Cannot find translation for source Spotify Jan 26 13:42:06 volumiopc volumio[15316]: info: Volumio called home Jan 26 13:42:06 volumiopc mpd[15614]: 2026-01-26T13:42:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 13:42:06 volumiopc systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 13:42:06 volumiopc mpd_monitor.sh[18116]: MPD Monitor Service: MPD restarted due to no mpc output. Jan 26 13:42:06 volumiopc sudo[15467]: pam_unix(sudo:session): session closed for user root Jan 26 13:42:06 volumiopc sudo[15476]: pam_unix(sudo:session): session closed for user root Jan 26 13:42:06 volumiopc volumio[15316]: info: Completed starting Core Plugins Jan 26 13:42:06 volumiopc volumio[15316]: info: ------------------------------------------- Jan 26 13:42:06 volumiopc volumio[15316]: info: ----- MyVolumio plugins startup ---- Jan 26 13:42:06 volumiopc volumio[15316]: info: ------------------------------------------- Jan 26 13:42:06 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 13:42:07 volumiopc volumio[15316]: error: MPD error: The expression evaluated to a falsy value: Jan 26 13:42:07 volumiopc volumio[15316]: assert.ok(self.idling) Jan 26 13:42:07 volumiopc volumio[15316]: error: The expression evaluated to a falsy value: Jan 26 13:42:07 volumiopc volumio[15316]: assert.ok(self.idling) Jan 26 13:42:07 volumiopc volumio[15316]: error: updateQueue error: null Jan 26 13:42:07 volumiopc volumio[15316]: info: MPD running with PID15614 Jan 26 13:42:07 volumiopc volumio[15316]: ,establishing connection Jan 26 13:42:07 volumiopc volumio[15316]: error: updateQueue error: null Jan 26 13:42:07 volumiopc volumio[15316]: info: Getting Spotify volume Jan 26 13:42:07 volumiopc volumio[15316]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 13:42:07 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:42:07 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:42:07 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:42:07 volumiopc volumio[15316]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 13:42:07 volumiopc volumio[15316]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 13:42:07 volumiopc volumio[15316]: info: Aligning Spotify Volume to Volumio Volume Jan 26 13:42:07 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:42:07 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:42:07 volumiopc volumio[15316]: info: Setting Spotify Volume from Volumio: 100 Jan 26 13:42:09 volumiopc volumio[15316]: info: Discovery: this is already registered, 3ece5b8c-ec32-4dfc-b1e5-6457ee402474 Jan 26 13:42:09 volumiopc volumio[15316]: info: Discovery: Found device VolumioPC Jan 26 13:42:09 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:42:09 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:42:09 volumiopc volumio[15316]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jan 26 13:42:09 volumiopc volumio[15316]: info: Sending Spotify command with payload to local API: /player/volume Jan 26 13:42:09 volumiopc sudo[15644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 26 13:42:09 volumiopc sudo[15642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 26 13:42:09 volumiopc sudo[15644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:42:09 volumiopc sudo[15642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:42:09 volumiopc systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 26 13:42:09 volumiopc systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 26 13:42:09 volumiopc systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 26 13:42:09 volumiopc systemd[1]: mpd_monitor.service: Consumed 4min 16.755s CPU time. Jan 26 13:42:09 volumiopc systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 26 13:42:09 volumiopc sudo[15644]: pam_unix(sudo:session): session closed for user root Jan 26 13:42:09 volumiopc sudo[15642]: pam_unix(sudo:session): session closed for user root Jan 26 13:42:09 volumiopc volumio[15316]: info: Successfully started MPD Monitor Jan 26 13:42:09 volumiopc volumio[15316]: info: Successfully started MPD Monitor Jan 26 13:42:09 volumiopc mpd_monitor.sh[15647]: MPD Monitor Service: Starting MPD Monitor Service Jan 26 13:42:09 volumiopc go-librespot[15531]: time="2026-01-26T13:42:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 26 13:42:09 volumiopc go-librespot[15531]: time="2026-01-26T13:42:09Z" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.2.195:40640->104.199.65.9:4070: read: connection reset by peer" Jan 26 13:42:11 volumiopc volumio[15316]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 13:42:20 volumiopc volumio[15316]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jan 26 13:42:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:42:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:42:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:42:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 13:42:26 volumiopc volumio[15316]: error: MyVolumio Plugin failed to start in a timely fashion Jan 26 13:42:26 volumiopc volumio[15316]: [Metrics] CommandRouter: 48s 912.81ms Jan 26 13:42:26 volumiopc volumio[15316]: info: CoreCommandRouter::volumiosetStartupVolume Jan 26 13:42:26 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:42:26 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:42:26 volumiopc volumio[15316]: info: CoreCommandRouter::Close All Modals sent Jan 26 13:42:26 volumiopc volumio[15316]: info: CoreCommandRouter::Close All Modals sent Jan 26 13:42:27 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 26 13:42:27 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 26 13:42:27 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 26 13:42:33 volumiopc volumio[15316]: info: BOOT COMPLETED Jan 26 13:42:40 volumiopc go-librespot[15531]: time="2026-01-26T13:42:40Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: i/o timeout" Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 13:42:42 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 13:42:45 volumiopc volumio[15316]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 13:42:45 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 13:42:45 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:42:45 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:42:45 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:42:45 volumiopc volumio[15316]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 13:42:45 volumiopc volumio[15316]: info: MyVolumio login type: Token Jan 26 13:42:45 volumiopc volumio[15316]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 13:42:45 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 13:42:47 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 13:42:47 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 13:42:47 volumiopc volumio[15316]: info: Streaming services startup Jan 26 13:42:47 volumiopc volumio[15316]: info: Starting Streaming Daemon Jan 26 13:42:47 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 13:42:47 volumiopc sudo[15723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 13:42:47 volumiopc sudo[15723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:42:48 volumiopc sudo[15723]: pam_unix(sudo:session): session closed for user root Jan 26 13:42:48 volumiopc volumio[15316]: error: Cannot start Volumio Streaming Daemon Jan 26 13:42:48 volumiopc volumio[15316]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 13:42:48 volumiopc volumio[15316]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 13:43:00 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 26 13:43:02 volumiopc volumio[15316]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 26 13:43:02 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:02 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:43:02 volumiopc volumio[15316]: error: MyVolumio Custom Token format not valid, refreshing it Jan 26 13:43:04 volumiopc go-librespot[15531]: time="2026-01-26T13:43:04Z" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 26 13:43:04 volumiopc volumio[15316]: info: MyVolumio login type: Token Jan 26 13:43:04 volumiopc go-librespot[15531]: time="2026-01-26T13:43:04Z" level=debug msg="completed keyexchange" Jan 26 13:43:04 volumiopc go-librespot[15531]: time="2026-01-26T13:43:04Z" level=debug msg="completed challenge" Jan 26 13:43:04 volumiopc go-librespot[15531]: time="2026-01-26T13:43:04Z" level=info msg="authenticated AP" username="br********ng" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=info msg="authenticated Login5" username="br********ng" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="initializing zeroconf session" username="br********ng" Jan 26 13:43:05 volumiopc volumio[15316]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="dealer connection opened" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=trace msg="starting accesspoint recv loop" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=trace msg="starting dealer recv loop" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=trace msg="received accesspoint ping" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="update volume requested to 65535/65535" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 26 13:43:05 volumiopc volumio[15316]: info: Spotify volume: 100 Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="received connection id: NmY4NDJjNjctMTU0...RjE3NjNEMDRGMA==" Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetBrowseSources Jan 26 13:43:05 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:43:05 volumiopc go-librespot[15531]: time="2026-01-26T13:43:05Z" level=debug msg="put connect state because NEW_DEVICE" Jan 26 13:43:06 volumiopc volumio[15316]: info: MyVolumio token set successfully Jan 26 13:43:06 volumiopc volumio[15316]: info: MYVOLUMIO: Adding device Jan 26 13:43:06 volumiopc volumio[15316]: info: MYVOLUMIO: Evaluating Server Jan 26 13:43:06 volumiopc go-librespot[15531]: time="2026-01-26T13:43:06Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 26 13:43:06 volumiopc go-librespot[15531]: time="2026-01-26T13:43:06Z" level=trace msg="emitting websocket event: volume" Jan 26 13:43:06 volumiopc go-librespot[15531]: time="2026-01-26T13:43:06Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 26 13:43:06 volumiopc go-librespot[15531]: time="2026-01-26T13:43:06Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 26 13:43:06 volumiopc go-librespot[15531]: time="2026-01-26T13:43:06Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 26 13:43:06 volumiopc go-librespot[15531]: time="2026-01-26T13:43:06Z" level=trace msg="received accesspoint pong ack" Jan 26 13:43:06 volumiopc volumio[15316]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Jan 26 13:43:06 volumiopc volumio[15316]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Jan 26 13:43:06 volumiopc volumio[15316]: info: MyVolumio Plan changed: premium Jan 26 13:43:06 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Jan 26 13:43:06 volumiopc volumio[15316]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 13:43:06 volumiopc volumio[15316]: info: Removing audio output: Jan 26 13:43:06 volumiopc volumio[15316]: info: MYVOLUMIO: Adding device Jan 26 13:43:06 volumiopc volumio[15316]: info: MYVOLUMIO: Evaluating Server Jan 26 13:43:06 volumiopc volumio[15316]: info: Remote config written successfully Jan 26 13:43:06 volumiopc volumio[15316]: info: Starting Tunnel 1 Jan 26 13:43:06 volumiopc volumio[15316]: info: Starting Tunnel Connection Checker Jan 26 13:43:06 volumiopc volumio[15316]: info: MYVolumio Device enabled Jan 26 13:43:06 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jan 26 13:43:06 volumiopc volumio[15316]: info: MyVolumio status changed Jan 26 13:43:06 volumiopc volumio[15316]: info: Streaming services startup Jan 26 13:43:06 volumiopc volumio[15316]: info: Starting Streaming Daemon Jan 26 13:43:06 volumiopc sudo[15808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 13:43:06 volumiopc sudo[15808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:06 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jan 26 13:43:06 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:43:06 volumiopc sudo[15808]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:06 volumiopc volumio[15316]: error: [MyVolumio PluginManager] Cache data is invalid! Jan 26 13:43:06 volumiopc volumio[15316]: error: Cannot start Volumio Streaming Daemon Jan 26 13:43:06 volumiopc volumio[15316]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 13:43:06 volumiopc volumio[15316]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 13:43:08 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Jan 26 13:43:09 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Jan 26 13:43:09 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Jan 26 13:43:11 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Jan 26 13:43:11 volumiopc sudo[15816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Jan 26 13:43:11 volumiopc sudo[15816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:11 volumiopc sudo[15816]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:11 volumiopc volumio[15316]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Jan 26 13:43:11 volumiopc volumio[15316]: info: MRS: MultiRoom plugin initialized Jan 26 13:43:11 volumiopc volumio[15316]: info: MRS: STOPPING SNAPCLIENT Jan 26 13:43:11 volumiopc volumio[15316]: info: MRS: Snap server stop Jan 26 13:43:12 volumiopc volumio[15316]: info: MRS: STOPPING volumioStreaming Jan 26 13:43:12 volumiopc sudo[15847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Jan 26 13:43:12 volumiopc sudo[15847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:12 volumiopc sudo[15849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Jan 26 13:43:12 volumiopc sudo[15849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Jan 26 13:43:12 volumiopc sudo[15851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Jan 26 13:43:12 volumiopc sudo[15851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:12 volumiopc sudo[15854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jan 26 13:43:12 volumiopc sudo[15854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:12 volumiopc sudo[15854]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Jan 26 13:43:12 volumiopc sudo[15849]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Jan 26 13:43:12 volumiopc sudo[15851]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:12 volumiopc sudo[15847]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Jan 26 13:43:12 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Jan 26 13:43:12 volumiopc volumio[15316]: info: Preparing to generate the ALSA configuration file Jan 26 13:43:12 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jan 26 13:43:12 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:43:12 volumiopc volumio[15316]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 26 13:43:12 volumiopc volumio[15316]: info: Reading ALSA contributions from plugins. Jan 26 13:43:12 volumiopc volumio[15316]: info: MRS: Removed streaming files Jan 26 13:43:12 volumiopc volumio[15316]: info: MRS: volumioStreaming STOPPED Jan 26 13:43:12 volumiopc volumio[15316]: info: MRS: SNAPSERVER STOPPED Jan 26 13:43:12 volumiopc volumio[15316]: info: MRS: SNAPCLIENT STOPPED Jan 26 13:43:12 volumiopc volumio[15316]: info: Asound.conf file written Jan 26 13:43:12 volumiopc sudo[15866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 26 13:43:12 volumiopc sudo[15866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:12 volumiopc sudo[15869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 26 13:43:12 volumiopc sudo[15869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:13 volumiopc systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Jan 26 13:43:13 volumiopc sudo[15869]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:13 volumiopc autossh[2805]: received signal to exit (15) Jan 26 13:43:13 volumiopc volumio[15316]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Jan 26 13:43:13 volumiopc volumio[15316]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Jan 26 13:43:13 volumiopc volumio[15316]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Jan 26 13:43:13 volumiopc volumio[15316]: No state is present for card IQaudIODAC Jan 26 13:43:13 volumiopc volumio[15316]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Jan 26 13:43:13 volumiopc volumio[15316]: Found hardware: "IQaudIODAC" "" "" "" "" Jan 26 13:43:13 volumiopc volumio[15316]: Hardware is initialized using a generic method Jan 26 13:43:13 volumiopc volumio[15316]: No state is present for card IQaudIODAC Jan 26 13:43:13 volumiopc volumio[15316]: info: Output device has changed, restarting MPD Jan 26 13:43:13 volumiopc systemd[1]: sshtunnel.service: Deactivated successfully. Jan 26 13:43:13 volumiopc systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Jan 26 13:43:13 volumiopc systemd[1]: sshtunnel.service: Consumed 2.247s CPU time. Jan 26 13:43:13 volumiopc volumio[15316]: info: Output device has changed, restarting Shairport Sync Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:43:13 volumiopc systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Jan 26 13:43:13 volumiopc sudo[15866]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:13 volumiopc volumio[15316]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:43:13 volumiopc volumio[15316]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:13 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Jan 26 13:43:13 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: [FUNC] onStart Jan 26 13:43:13 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Jan 26 13:43:13 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Jan 26 13:43:13 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Jan 26 13:43:13 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Jan 26 13:43:13 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output for this device Jan 26 13:43:13 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding audio output: Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding audio output: Jan 26 13:43:13 volumiopc sudo[15879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 13:43:13 volumiopc sudo[15879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:13 volumiopc sudo[15878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 13:43:13 volumiopc sudo[15878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:13 volumiopc sudo[15878]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:13 volumiopc volumio[15316]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:13 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding METAVOLUMIO REST API Endpoints Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Jan 26 13:43:13 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Jan 26 13:43:13 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Jan 26 13:43:13 volumiopc volumio[15316]: info: Preparing CD Folders Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding CD REST API Endpoints Jan 26 13:43:13 volumiopc volumio[15316]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jan 26 13:43:13 volumiopc volumio[15316]: info: Starting UDEV Watcher for CD Jan 26 13:43:13 volumiopc autossh[15889]: port set to 0, monitoring disabled Jan 26 13:43:13 volumiopc autossh[15889]: starting ssh (count 1) Jan 26 13:43:13 volumiopc autossh[15889]: ssh child pid is 15896 Jan 26 13:43:13 volumiopc volumio[15316]: info: Detecting CD presence with UDEV Jan 26 13:43:13 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Jan 26 13:43:13 volumiopc systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 13:43:13 volumiopc bluetoothd[790]: Path / reserved for Adv Monitor app :1.370 Jan 26 13:43:13 volumiopc bluetoothd[790]: Adv Monitor app :1.370 disconnected from D-Bus Jan 26 13:43:16 volumiopc systemd[1]: mpd.service: Deactivated successfully. Jan 26 13:43:16 volumiopc systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 13:43:16 volumiopc systemd[1]: mpd.service: Consumed 7.095s CPU time. Jan 26 13:43:16 volumiopc systemd[1]: mpd.socket: Deactivated successfully. Jan 26 13:43:16 volumiopc systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 13:43:16 volumiopc systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 13:43:16 volumiopc systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 13:43:16 volumiopc systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 13:43:17 volumiopc sudo[15903]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 13:43:17 volumiopc sudo[15903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 13:43:17 volumiopc sudo[15903]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:18 volumiopc volumio[15316]: warn: [cd-plugin] cdspeedctl: device or media not ready Jan 26 13:43:18 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Jan 26 13:43:18 volumiopc volumio[15316]: info: Adding inputs REST Endpoints Jan 26 13:43:18 volumiopc volumio[15316]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jan 26 13:43:18 volumiopc volumio[15316]: info: Scanning Audio Inputs Jan 26 13:43:19 volumiopc volumio[15316]: info: Checking against Known Cards name Jan 26 13:43:19 volumiopc volumio[15316]: info: Adding Server instance for streaming Jan 26 13:43:19 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Jan 26 13:43:19 volumiopc volumio[15316]: error: Hi Res Audio Failed Login: Missing Login Data Jan 26 13:43:19 volumiopc volumio[15316]: info: Adding HIGHRESAUDIO REST API Endpoints Jan 26 13:43:19 volumiopc volumio[15316]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Jan 26 13:43:19 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Jan 26 13:43:19 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Jan 26 13:43:19 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Jan 26 13:43:19 volumiopc volumio[15316]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Jan 26 13:43:19 volumiopc volumio[15316]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Jan 26 13:43:19 volumiopc volumio[15316]: info: QobuzConnect: Starting Qobuz Connect socket and service Jan 26 13:43:19 volumiopc sudo[15910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 26 13:43:19 volumiopc sudo[15910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:19 volumiopc sudo[15917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 26 13:43:19 volumiopc sudo[15917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:19 volumiopc volumio[15316]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Jan 26 13:43:19 volumiopc volumio[15316]: info: Adding TIDAL REST API Endpoints Jan 26 13:43:19 volumiopc volumio[15316]: info: Stopping AccessToken refresher cron for QOBUZ Jan 26 13:43:19 volumiopc systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Jan 26 13:43:19 volumiopc systemd[1]: vtcs.service: Deactivated successfully. Jan 26 13:43:19 volumiopc systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Jan 26 13:43:19 volumiopc systemd[1]: vtcs.service: Consumed 2min 27.992s CPU time. Jan 26 13:43:19 volumiopc sudo[15917]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:19 volumiopc sudo[15910]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:19 volumiopc sudo[15919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 26 13:43:19 volumiopc sudo[15919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:19 volumiopc volumio[15316]: info: AccessToken refresher cron started for QOBUZ Jan 26 13:43:19 volumiopc volumio[15316]: info: Adding QOBUZ REST API Endpoints Jan 26 13:43:19 volumiopc volumio[15316]: info: MRS: Getting audio outputs on start Jan 26 13:43:19 volumiopc volumio[15316]: info: MRS: Requesting all other devices output Jan 26 13:43:19 volumiopc systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Jan 26 13:43:19 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Jan 26 13:43:19 volumiopc volumio[15316]: info: MPD Permissions set Jan 26 13:43:19 volumiopc volumio[15316]: info: Remote SSH Started Jan 26 13:43:19 volumiopc sudo[15923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jan 26 13:43:19 volumiopc sudo[15923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:20 volumiopc qobuz-connect[18060]: 20260126 13:43:20.020 [18060.18060] INFO SampleApp: Stopping Local configuration server Jan 26 13:43:20 volumiopc sudo[15923]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:20 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::volumioStop Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreStateMachine::stop Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 13:43:20 volumiopc volumio[15316]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:43:20 volumiopc volumio[15316]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 26 13:43:20 volumiopc volumio[15316]: info: Starting Shairport Sync Jan 26 13:43:20 volumiopc sudo[15935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:43:20 volumiopc sudo[15935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:20 volumiopc systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 13:43:20 volumiopc systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 13:43:20 volumiopc systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:43:20 volumiopc systemd[1]: shairport-sync.service: Consumed 2.397s CPU time. Jan 26 13:43:20 volumiopc systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:43:20 volumiopc sudo[15935]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:20 volumiopc volumio[15316]: info: Shairport-Sync Started Jan 26 13:43:21 volumiopc systemd[1]: qobuz-connect.service: Deactivated successfully. Jan 26 13:43:21 volumiopc systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Jan 26 13:43:21 volumiopc systemd[1]: qobuz-connect.service: Consumed 5.653s CPU time. Jan 26 13:43:21 volumiopc systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Jan 26 13:43:21 volumiopc sudo[15919]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:21 volumiopc volumio[15316]: info: Executing endpoint qc_getconfig Jan 26 13:43:21 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.812 [15952.15952] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jan 26 13:43:21 volumiopc volumio[15316]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jan 26 13:43:21 volumiopc volumio[15316]: info: QobuzConnect: QOBUZ Connect daemon connected Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.833 [15952.15952] INFO VolumeManager: [0x10115c8]: Setting new playback volume: 75 Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.833 [15952.15952] INFO VolumeManager: [0x10115c8]: Setting new mute state: 0 Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.833 [15952.15952] INFO QobuzConnect: [0x1011f98]: Client initialized! Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.833 [15952.15952] INFO SampleApp: Starting Avahi advertising, name: VolumioPC, service name: _qobuz-connect._tcp Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.858 [15952.15952] INFO LocalConfigManager: [0x1010ea8]: Starting Local Configuration server Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.858 [15952.15952] INFO SampleApp: Starting Local configuration server Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.859 [15952.15952] INFO SampleApp: Connected to UNIX socket client 0xffb818 Jan 26 13:43:21 volumiopc qobuz-connect[15952]: 20260126 13:43:21.962 [15952.15952] INFO SampleApp: Playback volume changed: 75 Jan 26 13:43:21 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:22 volumiopc volumiossh-tunnel[15896]: Warning: Permanently added '[eu1.myvolumio.org]:2222' (RSA) to the list of known hosts. Jan 26 13:43:22 volumiopc volumio[15316]: info: TidalConnect service stoped! Jan 26 13:43:22 volumiopc volumio[15316]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jan 26 13:43:22 volumiopc volumio[15316]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Jan 26 13:43:22 volumiopc sudo[15983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jan 26 13:43:22 volumiopc sudo[15983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:23 volumiopc systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Jan 26 13:43:23 volumiopc sudo[15983]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:23 volumiopc volumio[15316]: info: Executing endpoint tc_getconfig Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Jan 26 13:43:23 volumiopc vtcs[15986]: STARTING TidalConnect services, version: 1.5.2.56 Jan 26 13:43:23 volumiopc vtcs[15986]: [2026-01-26 13:43:23.668] [tisoc] [critical] [DeviceInfo.cpp:52] ioctl error. ret=-1, errno="No such device" Jan 26 13:43:23 volumiopc vtcs[15986]: [2026-01-26 13:43:23.668] [tisoc] [critical] [DeviceInfo.cpp:53] [ASSERT] generateDeviceId(0) Jan 26 13:43:23 volumiopc vtcs[15986]: STARTED TidalConnect services. Jan 26 13:43:23 volumiopc volumio[15316]: info: Executing endpoint tc_connect Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Jan 26 13:43:23 volumiopc volumio[15316]: info: Connecting to TidalConnect Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::servicePushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::pushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioPushState Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output update for this device Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:23 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:43:23 volumiopc volumio[15316]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Jan 26 13:43:23 volumiopc volumio[15316]: verbose: CURRENT POSITION 0 Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::syncState stateService stop Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::syncState currentStatus stop Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::pushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioPushState Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output update for this device Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:23 volumiopc volumio[15316]: info: No code Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::pushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioPushState Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output update for this device Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::servicePushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::pushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioPushState Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output update for this device Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:23 volumiopc volumio[15316]: info: CorePlayQueue::getTrack 0 Jan 26 13:43:23 volumiopc volumio[15316]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Jan 26 13:43:23 volumiopc volumio[15316]: verbose: CURRENT POSITION 0 Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::syncState stateService stop Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::syncState currentStatus stop Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::pushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioPushState Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output update for this device Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:23 volumiopc volumio[15316]: info: No code Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreStateMachine::pushState Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioPushState Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output update for this device Jan 26 13:43:23 volumiopc volumio[15316]: info: MRS: Pushing multiroomSync output Jan 26 13:43:23 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:23 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:43:23 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:43:23 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:43:23 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:43:23 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:43:23 volumiopc volumio[15316]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:43:24 volumiopc volumio[15316]: info: Discovery: Disconnected from remote: 192.168.2.194 Jan 26 13:43:25 volumiopc mpd[15905]: 2026-01-26T13:43:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 13:43:25 volumiopc systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 13:43:25 volumiopc sudo[15879]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:25 volumiopc volumio[15316]: error: updateQueue error: null Jan 26 13:43:26 volumiopc volumio[15316]: info: TidalConnect service started! Jan 26 13:43:28 volumiopc sudo[16006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 26 13:43:28 volumiopc sudo[16006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:43:28 volumiopc systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 26 13:43:28 volumiopc systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 26 13:43:28 volumiopc systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 26 13:43:28 volumiopc systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 26 13:43:28 volumiopc sudo[16006]: pam_unix(sudo:session): session closed for user root Jan 26 13:43:28 volumiopc volumio[15316]: info: Successfully started MPD Monitor Jan 26 13:43:28 volumiopc mpd_monitor.sh[16008]: MPD Monitor Service: Starting MPD Monitor Service Jan 26 13:43:30 volumiopc volumio[15316]: info: Discovery: Remote connection error: 192.168.2.194 Jan 26 13:43:30 volumiopc volumio[15316]: info: Discovery: Remote connection timeout: 192.168.2.194 Jan 26 13:43:35 volumiopc volumio[15316]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.UdM2rX4S5iZjLwariXExpyYvAtG3.48794988aab0b5bb2fb782c009cbba9a.state.status' Jan 26 13:43:35 volumiopc volumio[15316]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.UdM2rX4S5iZjLwariXExpyYvAtG3.48794988aab0b5bb2fb782c009cbba9a.state.status' Jan 26 13:43:35 volumiopc volumio[15316]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.UdM2rX4S5iZjLwariXExpyYvAtG3.48794988aab0b5bb2fb782c009cbba9a.state.status' Jan 26 13:43:35 volumiopc volumio[15316]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.UdM2rX4S5iZjLwariXExpyYvAtG3.48794988aab0b5bb2fb782c009cbba9a.state.status' Jan 26 13:43:35 volumiopc volumio[15316]: info: CoreCommandRouter::volumioGetState Jan 26 13:43:35 volumiopc volumio[15316]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.UdM2rX4S5iZjLwariXExpyYvAtG3.48794988aab0b5bb2fb782c009cbba9a.state.status' Jan 26 13:43:35 volumiopc go-librespot[15531]: time="2026-01-26T13:43:35Z" level=trace msg="sent dealer ping" Jan 26 13:43:36 volumiopc volumio[15316]: info: Discovery: Remote connection error: 192.168.2.194 Jan 26 13:43:36 volumiopc volumio[15316]: info: Discovery: Remote connection timeout: 192.168.2.194 Jan 26 13:43:39 volumiopc volumio[15316]: error: Failed to ping endpoint eu2.myvolumio.org : unknown error Jan 26 13:43:39 volumiopc volumio[15316]: error: Failed to ping endpoint eu2.myvolumio.org : unknown error Jan 26 13:43:39 volumiopc volumio[15316]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 13:43:39 volumiopc volumio[15316]: Error: Unable to resolve or reject the same promise twice Jan 26 13:43:39 volumiopc volumio[15316]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jan 26 13:43:39 volumiopc volumio[15316]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32371) Jan 26 13:43:39 volumiopc volumio[15316]: at Socket.emit (node:events:514:28) Jan 26 13:43:39 volumiopc volumio[15316]: at addChunk (node:internal/streams/readable:343:12) Jan 26 13:43:39 volumiopc volumio[15316]: at readableAddChunk (node:internal/streams/readable:316:9) Jan 26 13:43:39 volumiopc volumio[15316]: at Readable.push (node:internal/streams/readable:253:10) Jan 26 13:43:39 volumiopc volumio[15316]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Jan 26 13:43:39 volumiopc volumio[15316]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 13:43:42 volumiopc sudo[16057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 13:42' Jan 26 13:43:42 volumiopc sudo[16057]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"