-- Logs begin at Sat 2025-11-01 15:11:16 CET, end at Sat 2025-11-01 19:39:13 CET. -- Nov 01 19:38:00 volumio volumio[26244]: info: Starting Streaming Service Transparent Proxy Nov 01 19:38:00 volumio volumio[26244]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 01 19:38:00 volumio volumio[26244]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 01 19:38:00 volumio volumio[26244]: info: Streaming services startup Nov 01 19:38:00 volumio volumio[26244]: info: Starting Streaming Daemon Nov 01 19:38:00 volumio sudo[26653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 19:38:00 volumio sudo[26653]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 19:38:00 volumio sudo[26653]: pam_unix(sudo:session): session closed for user root Nov 01 19:38:00 volumio volumio[26244]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 01 19:38:00 volumio volumio[26244]: error: Cannot start Volumio Streaming Daemon Nov 01 19:38:00 volumio volumio[26244]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 19:38:00 volumio volumio[26244]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 19:38:01 volumio volumio[26244]: STREAMING PROXY: Starting server on port 3245 Nov 01 19:38:01 volumio volumio[26244]: Node JS runtime: 14 Nov 01 19:38:03 volumio volumio[26244]: error: MyVolumio Custom Token format not valid, refreshing it Nov 01 19:38:03 volumio volumio[26244]: info: MyVolumio login type: Token Nov 01 19:38:04 volumio volumio[26244]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 01 19:38:05 volumio volumio[26244]: info: MyVolumio token set successfully Nov 01 19:38:05 volumio volumio[26244]: info: MYVOLUMIO: Adding device Nov 01 19:38:05 volumio volumio[26244]: info: MYVOLUMIO: Evaluating Server Nov 01 19:38:05 volumio volumio[26244]: info: MyVolumio status changed Nov 01 19:38:05 volumio volumio[26244]: info: Streaming services startup Nov 01 19:38:05 volumio volumio[26244]: info: Starting Streaming Daemon Nov 01 19:38:05 volumio volumio[26244]: info: Removing browser output: myVolumio user plan is not superstar Nov 01 19:38:05 volumio volumio[26244]: info: Removing audio output: Nov 01 19:38:05 volumio volumio[26244]: info: Stoppping Tunnel 1 Nov 01 19:38:05 volumio sudo[26692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 19:38:05 volumio sudo[26692]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 19:38:05 volumio sudo[26692]: pam_unix(sudo:session): session closed for user root Nov 01 19:38:05 volumio volumio[26244]: error: Cannot start Volumio Streaming Daemon Nov 01 19:38:05 volumio volumio[26244]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 19:38:05 volumio volumio[26244]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 19:38:05 volumio sudo[26695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 01 19:38:05 volumio sudo[26695]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 19:38:06 volumio sudo[26695]: pam_unix(sudo:session): session closed for user root Nov 01 19:38:06 volumio volumio[26244]: info: Remote SSH Stopped Nov 01 19:38:06 volumio volumio[26244]: info: Starting Uninstall of plugin system_controller - ampswitch Nov 01 19:38:06 volumio volumio[26244]: info: Uninstalling plugin ampswitch Nov 01 19:38:06 volumio volumio[26244]: info: [ASDebug] Port: 24 Nov 01 19:38:06 volumio volumio[26244]: info: [ASDebug] Inverted: false Nov 01 19:38:06 volumio volumio[26244]: info: [ASDebug] Delay: 720 Nov 01 19:38:06 volumio volumio[26244]: info: Setting Geolocation for MyVolumio to eu2 Nov 01 19:38:06 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:06 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:06 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:06 volumio volumio[26244]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 01 19:38:07 volumio volumio[26244]: info: Updating MyVolumio device info Nov 01 19:38:07 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:07 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:07 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:07 volumio volumio[26244]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 01 19:38:10 volumio volumio[26244]: info: MYVOLUMIO: Adding device Nov 01 19:38:10 volumio volumio[26244]: info: MYVOLUMIO: Evaluating Server Nov 01 19:38:11 volumio volumio[26244]: info: Setting Geolocation for MyVolumio to eu8 Nov 01 19:38:11 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:11 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:11 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:11 volumio volumio[26244]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 01 19:38:12 volumio volumio[26244]: info: Updating MyVolumio device info Nov 01 19:38:12 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:12 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:12 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:12 volumio volumio[26244]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 01 19:38:14 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 19:38:14 volumio volumio[26244]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Nov 01 19:38:14 volumio volumio[26244]: info: CoreCommandRouter::volumioGetState Nov 01 19:38:14 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:38:16 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 19:38:16 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:16 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 19:38:17 volumio volumio-remote-updater[571]: Test mode enabled Nov 01 19:38:17 volumio volumio-remote-updater[571]: No alpha test mode Nov 01 19:38:17 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 01 19:38:17 volumio volumio[26244]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 01 19:38:17 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::volumioGetBrowseSources Nov 01 19:38:19 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 19:38:20 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$1 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$2 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$3 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$4 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$5 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$6 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$7 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$8 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$9 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$10 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$11 Nov 01 19:38:20 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$12 Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$1 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$2 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$3 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$4 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$5 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$6 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$7 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$8 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$9 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$10 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$11 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$46$12 in service upnp_browser Nov 01 19:38:20 volumio volumio[26244]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 01 19:38:20 volumio volumio[26244]: info: Completed starting MyVolumio Plugin Nov 01 19:38:20 volumio volumio[26244]: [Metrics] CommandRouter: 40s 822.21ms Nov 01 19:38:20 volumio volumio[26244]: info: CoreCommandRouter::volumiosetStartupVolume Nov 01 19:38:20 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 19:38:20 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 19:38:20 volumio volumio[26244]: info: CoreCommandRouter::Close All Modals sent Nov 01 19:38:20 volumio volumio[26244]: info: CoreCommandRouter::Close All Modals sent Nov 01 19:38:21 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 01 19:38:21 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 01 19:38:21 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 01 19:38:24 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 19:38:24 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 19:38:24 volumio volumio[26244]: info: Discovery: Getting this device information Nov 01 19:38:24 volumio volumio[26244]: info: CoreCommandRouter::volumioGetState Nov 01 19:38:24 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:38:24 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 19:38:27 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 19:38:27 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$1 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$2 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$3 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$4 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$5 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$6 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$7 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$8 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$9 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$10 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$11 Nov 01 19:38:27 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$12 Nov 01 19:38:27 volumio volumio[26244]: info: BOOT COMPLETED Nov 01 19:38:27 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$1 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$2 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$3 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$4 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$5 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$6 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$7 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$8 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$9 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$10 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$11 in service upnp_browser Nov 01 19:38:28 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$45$12 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 19:38:45 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$1 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$2 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$3 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$4 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$5 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$6 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$7 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$8 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$9 Nov 01 19:38:45 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$10 Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$1 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$2 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$3 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$4 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$5 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$6 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$7 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$8 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$9 in service upnp_browser Nov 01 19:38:45 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$43$10 in service upnp_browser Nov 01 19:38:54 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 19:38:54 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 19:38:54 volumio volumio[26244]: info: Discovery: Getting this device information Nov 01 19:38:54 volumio volumio[26244]: info: CoreCommandRouter::volumioGetState Nov 01 19:38:54 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:38:54 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 19:38:55 volumio nmbd[692]: [2025/11/01 19:38:55.279949, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Nov 01 19:38:55 volumio nmbd[692]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.51.166 for name WORKGROUP<1d>. Nov 01 19:38:55 volumio nmbd[692]: This response was from IP 192.168.51.147, reporting an IP address of 192.168.51.147. Nov 01 19:38:55 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 19:38:55 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$1 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$2 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$3 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$4 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$5 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$6 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$7 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$8 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$9 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$10 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$11 Nov 01 19:38:55 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$12 Nov 01 19:38:55 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$1 in service upnp_browser Nov 01 19:38:55 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$2 in service upnp_browser Nov 01 19:38:55 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$3 in service upnp_browser Nov 01 19:38:55 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$4 in service upnp_browser Nov 01 19:38:55 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$5 in service upnp_browser Nov 01 19:38:55 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$6 in service upnp_browser Nov 01 19:38:56 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$7 in service upnp_browser Nov 01 19:38:56 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$8 in service upnp_browser Nov 01 19:38:56 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$9 in service upnp_browser Nov 01 19:38:56 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$10 in service upnp_browser Nov 01 19:38:56 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$11 in service upnp_browser Nov 01 19:38:56 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$44$12 in service upnp_browser Nov 01 19:39:10 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 01 19:39:10 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:39:10 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$2 Nov 01 19:39:10 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$4 Nov 01 19:39:10 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$5 Nov 01 19:39:10 volumio volumio[26244]: info: Preloading song: upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$8 Nov 01 19:39:10 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$2 in service upnp_browser Nov 01 19:39:10 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$4 in service upnp_browser Nov 01 19:39:10 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$5 in service upnp_browser Nov 01 19:39:11 volumio volumio[26244]: info: Exploding uri upnp/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A$8 in service upnp_browser Nov 01 19:39:11 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:39:11 volumio volumio[26244]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::ClearQueue Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::stop Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::clearPlayQueue Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::saveQueue Nov 01 19:39:11 volumio volumio[26244]: info: CoreCommandRouter::volumioPushQueue Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::addQueueItems Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::addQueueItems Nov 01 19:39:11 volumio volumio[26244]: info: Preload queue cleared Nov 01 19:39:11 volumio volumio[26244]: info: Adding Item to queue: upnp/folder/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A Nov 01 19:39:11 volumio volumio[26244]: info: Exploding uri upnp/folder/http://192.168.51.197:8200/ctl/ContentDir@1$F$5A in service upnp_browser Nov 01 19:39:11 volumio volumio[26244]: info: CoreCommandRouter::volumioPushQueue Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::saveQueue Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::updateTrackBlock Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::getTrackBlock Nov 01 19:39:11 volumio volumio[26244]: info: CoreCommandRouter::volumioPlay Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::play index 0 Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::stop Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::play index undefined Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:11 volumio volumio[26244]: info: CoreStateMachine::startPlaybackTimer Nov 01 19:39:11 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:11 volumio volumio[26244]: info: [1762022351974] ControllerUPNPBrowser::clearAddPlayTrack Nov 01 19:39:11 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 19:39:11 volumio volumio[26244]: info: sendMpdCommand stop took 13 milliseconds Nov 01 19:39:11 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand clear Nov 01 19:39:11 volumio volumio[26244]: info: Nov 01 19:39:11 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:11 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:11 volumio volumio[26244]: info: sendMpdCommand clear took 4 milliseconds Nov 01 19:39:11 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.51.197:8200/MediaItems/9942.flac" Nov 01 19:39:11 volumio volumio[26244]: info: Nov 01 19:39:11 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:11 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:11 volumio volumio[26244]: info: Nov 01 19:39:11 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:11 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:12 volumio volumio[26244]: error: updateQueue error: null Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 10ms Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.51.197:8200/MediaItems/9942.flac" Nov 01 19:39:12 volumio volumio[26244]: error: updateQueue error: null Nov 01 19:39:12 volumio volumio[26244]: error: updateQueue error: null Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:12 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 30ms Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand add "http://192.168.51.197:8200/MediaItems/9942.flac" took 4 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand play Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:12 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:12 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 9ms Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand play took 6 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 6ms Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 4ms Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand status took 17 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand status took 7 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand status took 6 milliseconds Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand status took 15 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand playlistinfo took 12 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand playlistinfo took 11 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand status took 7 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand status took 5 milliseconds Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseTrackInfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseTrackInfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseTrackInfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::servicePushState Nov 01 19:39:12 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:12 volumio volumio[26244]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":514,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9942.flac","artist":null,"album":null,"uri":"http://192.168.51.197:8200/MediaItems/9942.flac","trackType":"flac"} Nov 01 19:39:12 volumio volumio[26244]: verbose: CURRENT POSITION 0 Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState stateService play Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState currentStatus stop Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::servicePushState Nov 01 19:39:12 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:12 volumio volumio[26244]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":514,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9942.flac","artist":null,"album":null,"uri":"http://192.168.51.197:8200/MediaItems/9942.flac","trackType":"flac"} Nov 01 19:39:12 volumio volumio[26244]: verbose: CURRENT POSITION 0 Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState stateService play Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState currentStatus play Nov 01 19:39:12 volumio volumio[26244]: info: Received an update from plugin. extracting info from payload Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::servicePushState Nov 01 19:39:12 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:12 volumio volumio[26244]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":514,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9942.flac","artist":null,"album":null,"uri":"http://192.168.51.197:8200/MediaItems/9942.flac","trackType":"flac"} Nov 01 19:39:12 volumio volumio[26244]: verbose: CURRENT POSITION 0 Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState stateService play Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState currentStatus play Nov 01 19:39:12 volumio volumio[26244]: info: Received an update from plugin. extracting info from payload Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 82ms Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 115ms Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 104ms Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces system playlist update Nov 01 19:39:12 volumio volumio[26244]: info: Ignoring MPD Status Update Nov 01 19:39:12 volumio volumio[26244]: info: Nov 01 19:39:12 volumio volumio[26244]: ---------------------------- MPD announces state update: player Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand playlistinfo took 83 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand playlistinfo took 80 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: sendMpdCommand playlistinfo took 80 milliseconds Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::getState Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::sendMpdCommand status Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseTrackInfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseTrackInfo Nov 01 19:39:12 volumio volumio[26244]: verbose: ControllerMpd::parseTrackInfo Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::servicePushState Nov 01 19:39:12 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:12 volumio volumio[26244]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":514,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9942.flac","artist":null,"album":null,"uri":"http://192.168.51.197:8200/MediaItems/9942.flac","trackType":"flac"} Nov 01 19:39:12 volumio volumio[26244]: verbose: CURRENT POSITION 0 Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState stateService play Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState currentStatus play Nov 01 19:39:12 volumio volumio[26244]: info: Received an update from plugin. extracting info from payload Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::servicePushState Nov 01 19:39:12 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:12 volumio volumio[26244]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":514,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9942.flac","artist":null,"album":null,"uri":"http://192.168.51.197:8200/MediaItems/9942.flac","trackType":"flac"} Nov 01 19:39:12 volumio volumio[26244]: verbose: CURRENT POSITION 0 Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState stateService play Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState currentStatus play Nov 01 19:39:12 volumio volumio[26244]: info: Received an update from plugin. extracting info from payload Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: ControllerMpd::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::servicePushState Nov 01 19:39:12 volumio volumio[26244]: info: CorePlayQueue::getTrack 0 Nov 01 19:39:12 volumio volumio[26244]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":514,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"9942.flac","artist":null,"album":null,"uri":"http://192.168.51.197:8200/MediaItems/9942.flac","trackType":"flac"} Nov 01 19:39:12 volumio volumio[26244]: verbose: CURRENT POSITION 0 Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState stateService play Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::syncState currentStatus play Nov 01 19:39:12 volumio volumio[26244]: info: Received an update from plugin. extracting info from payload Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreStateMachine::pushState Nov 01 19:39:12 volumio volumio[26244]: info: CoreCommandRouter::volumioPushState Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 241ms Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 230ms Nov 01 19:39:12 volumio volumio[26244]: info: ------------------------------ 229ms Nov 01 19:39:12 volumio volumio[26244]: info: [ASDebug] CurState: play PrevState: stop Nov 01 19:39:12 volumio volumio[26244]: info: [ASDebug] Togle GPIO: ON Nov 01 19:39:12 volumio volumio[26244]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 19:39:12 volumio volumio[26244]: Error: ESPIPE: invalid seek, write Nov 01 19:39:12 volumio volumio[26244]: at Object.writeSync (fs.js:711:3) Nov 01 19:39:12 volumio volumio[26244]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Nov 01 19:39:12 volumio volumio[26244]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) Nov 01 19:39:12 volumio volumio[26244]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) Nov 01 19:39:12 volumio volumio[26244]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Nov 01 19:39:12 volumio volumio[26244]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) Nov 01 19:39:12 volumio volumio[26244]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) Nov 01 19:39:12 volumio volumio[26244]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Nov 01 19:39:12 volumio volumio[26244]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Nov 01 19:39:12 volumio volumio[26244]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) Nov 01 19:39:12 volumio volumio[26244]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Nov 01 19:39:12 volumio volumio[26244]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Nov 01 19:39:12 volumio volumio[26244]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) Nov 01 19:39:12 volumio volumio[26244]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) Nov 01 19:39:12 volumio volumio[26244]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Nov 01 19:39:12 volumio volumio[26244]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) { Nov 01 19:39:12 volumio volumio[26244]: errno: -29, Nov 01 19:39:12 volumio volumio[26244]: syscall: 'write', Nov 01 19:39:12 volumio volumio[26244]: code: 'ESPIPE' Nov 01 19:39:12 volumio volumio[26244]: } Nov 01 19:39:12 volumio volumio[26244]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 19:39:13 volumio sudo[26885]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 19:38 Nov 01 19:39:13 volumio sudo[26885]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5d50cd80bebce60dddccd7f5e813d656e28ca4cd" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="7840f283c310c38bfe939a4c485727a6ff6a0ce1" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 21 Oct 2025 03:46:47 PM CEST" VOLUMIO_VERSION="3.866" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e2f3a8aca3147ba51b5da8167dd6ff8"