Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:00 volumio volumio[1379]: info: Starting MyVolumio Remote Streaming Endpoints Nov 04 15:31:00 volumio volumio[1379]: info: MyVolumio not started Nov 04 15:31:00 volumio volumio[1379]: info: Initializing device activation check Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.728Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08eb8e97ce055a0e0819120018d999c0f2a433208827 type=REQUEST_TYPE_PING id=1506133867 Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.728Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.729Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.729Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1506133867 status=STATUS_OK Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 04 15:31:00 volumio volumio[1379]: info: Streaming services startup Nov 04 15:31:00 volumio volumio[1379]: info: Starting Streaming Daemon Nov 04 15:31:00 volumio sudo[2267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 04 15:31:00 volumio sudo[2267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:00 volumio volumio[1379]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 04 15:31:00 volumio sudo[2267]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Nov 04 15:31:00 volumio volumio[1379]: info: Loading i18n strings for locale en Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.788Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.791Z level=DEBUG msg="received event" component=volumio/socket event=pushUiSettings Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.792Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_LANGUAGE_CHANGED Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.792Z level=DEBUG msg="writing packet" component=conn/multi size=134 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.792Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_LANGUAGE_CHANGED Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.792Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.792Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=840031843 status=STATUS_OK Nov 04 15:31:00 volumio volumio[1379]: error: Cannot start Volumio Streaming Daemon Nov 04 15:31:00 volumio volumio[1379]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 04 15:31:00 volumio volumio[1379]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.800Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=089289a2d3055a1c0805120e0a0c417369612f4b6f6c6b61746118ac9ac0f2a43320904e type=REQUEST_TYPE_SET_DEVICE_TIMEZONE id=1516799122 Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.800Z level=INFO msg="received request" component=server type=REQUEST_TYPE_SET_DEVICE_TIMEZONE peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.800Z level=INFO msg="set device timezone" component=server type=REQUEST_TYPE_SET_DEVICE_TIMEZONE peer="192.168.1.187:38212 @ 0x3125170" latency=340.554973ms timeout=10s timezone=Asia/Kolkata Nov 04 15:31:00 volumio volumio[1379]: Updating browse sources language Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.807Z level=DEBUG msg="received event" component=volumio/socket event=pushMenuItems Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.809Z level=DEBUG msg="received event" component=volumio/socket event=pushBrowseSources Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.812Z level=DEBUG msg="received event" component=volumio/socket event=pushAvailableTimezones Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Nov 04 15:31:00 volumio volumio[1379]: info: Setting timezone to Asia/Kolkata Nov 04 15:31:00 volumio sudo[2277]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Nov 04 15:31:00 volumio sudo[2277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:00 volumio sudo[2277]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:00 volumio sudo[2281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Kolkata /etc/localtime Nov 04 15:31:00 volumio sudo[2281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:00 volumio sudo[2281]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:00 volumio sudo[2285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Nov 04 15:31:00 volumio sudo[2285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:00 volumio sudo[2285]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:00 volumio sudo[2289]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Kolkata Nov 04 15:31:00 volumio sudo[2289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:00 volumio sudo[2289]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.884Z level=DEBUG msg="received event" component=volumio/socket event=pushCurrentTimezone Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.885Z level=DEBUG msg="received event" component=volumio/socket event=pushCurrentTimezone Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.885Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_TIMEZONE_CHANGED Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.885Z level=DEBUG msg="writing packet" component=conn/multi size=33 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.885Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_TIMEZONE_CHANGED Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.885Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.885Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1516799122 status=STATUS_OK Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.897Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08bcedc8bd015a10080112020803188c9bc0f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=397555388 Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.898Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.898Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=342.066806ms timeout=10s from=APP_PAGE_SETUP_V1_INTRO Nov 04 15:31:00 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:00 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:00 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:00 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.902Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.902Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_NAME_CHANGED Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.902Z level=DEBUG msg="writing packet" component=conn/multi size=28 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.902Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_NAME_CHANGED Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.902Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:00.902Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=397555388 status=STATUS_OK Nov 04 15:31:01 volumio volumio[1379]: info: Fetching Streaming Services browse cache Nov 04 15:31:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:01.780Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=088599bd86065a0e0819120018fea1c0f2a433208827 type=REQUEST_TYPE_PING id=1624198277 Nov 04 15:31:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:01.781Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:01.781Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:01.781Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1624198277 status=STATUS_OK Nov 04 15:31:02 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 04 15:31:03 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Nov 04 15:31:03 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Nov 04 15:31:03 volumio volumio[1379]: info: Refreshing Cached IP Addresses Nov 04 15:31:03 volumio sudo[2292]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Nov 04 15:31:03 volumio sudo[2292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:03 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:03.361Z level=DEBUG msg="received event" component=volumio/socket event=pushInfoNetworkReload Nov 04 15:31:03 volumio sudo[2294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 04 15:31:03 volumio sudo[2294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:03 volumio sudo[2294]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:03 volumio sudo[2296]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:03 volumio sudo[2296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:03 volumio sudo[2296]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:03 volumio sudo[2292]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:03 volumio volumio[1379]: error: Cannot kill upmpdcli Error: Command failed: /usr/bin/sudo /usr/bin/killall upmpdcli Nov 04 15:31:03 volumio volumio[1379]: upmpdcli: no process found Nov 04 15:31:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:05.750Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08d6c189075a0e0819120018f6c0c0f2a433208827 type=REQUEST_TYPE_PING id=14835926 Nov 04 15:31:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:05.750Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:05.751Z level=DEBUG msg="writing packet" component=conn/multi size=18 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:05.751Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=14835926 status=STATUS_OK Nov 04 15:31:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:06.792Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08e1d6d8e1015a0e081912001891c9c0f2a433208827 type=REQUEST_TYPE_PING id=473312097 Nov 04 15:31:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:06.792Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:06.792Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:06.792Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=473312097 status=STATUS_OK Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.435Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08a6afe1b7025a17080312090a07566f6c756d696f188bcec0f2a43320904e type=REQUEST_TYPE_SET_DEVICE_NAME id=653809574 Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.435Z level=INFO msg="received request" component=server type=REQUEST_TYPE_SET_DEVICE_NAME peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.436Z level=INFO msg="set device name" component=server type=REQUEST_TYPE_SET_DEVICE_NAME peer="192.168.1.187:38212 @ 0x3125170" latency=352.914932ms timeout=10s name=Volumio Nov 04 15:31:07 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.438Z level=DEBUG msg="received event" component=volumio/socket event=pushDeviceName Nov 04 15:31:07 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:07 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:07 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:07 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:07 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:07 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:07 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.440Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.440Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_NAME_CHANGED Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.440Z level=DEBUG msg="writing packet" component=conn/multi size=28 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.440Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_DEVICE_NAME_CHANGED Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.440Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.440Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=653809574 status=STATUS_OK Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.448Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08d2ccb21a5a1008011202080418a5cec0f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=55354962 Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.448Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.448Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=339.516191ms timeout=10s from=APP_PAGE_SETUP_V1_NAME Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_ETHERNET_INFO_CHANGED Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="writing packet" component=conn/multi size=75 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_ETHERNET_INFO_CHANGED Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="writing packet" component=conn/multi size=17 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="writing packet" component=conn/multi size=22 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.449Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=55354962 status=STATUS_OK Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.471Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08afb0cc325a0f0806120018bccec0f2a43320e0d403 type=REQUEST_TYPE_RUN_WIFI_SCAN id=106108975 Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.471Z level=INFO msg="received request" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:07.471Z level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="192.168.1.187:38212 @ 0x3125170" latency=339.841821ms timeout=1m0s Nov 04 15:31:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:09 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:09 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:09 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:09 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:09.973Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_SCAN Nov 04 15:31:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:09.973Z level=DEBUG msg="writing packet" component=conn/multi size=539 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:09.973Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_SCAN Nov 04 15:31:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:09.973Z level=DEBUG msg="writing packet" component=conn/multi size=18 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:09.973Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=106108975 status=STATUS_OK Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Nov 04 15:31:10 volumio volumio[1379]: info: MyVolumio login type: Token Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.307Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioToken Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.320Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.320Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_USER_CHANGED Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.320Z level=DEBUG msg="writing packet" component=conn/multi size=17 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.320Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_USER_CHANGED Nov 04 15:31:10 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:10 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:10 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.325Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.475Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 04 15:31:10 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:10 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:10 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.477Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.479Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.479Z level=DEBUG msg="writing packet" component=conn/multi size=17 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.479Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.479Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.480Z level=INFO msg="BLE descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.481Z level=INFO msg="mDNS descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.762Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08a5abc799015a0e081912001892e8c0f2a433208827 type=REQUEST_TYPE_PING id=322033061 Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.764Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.764Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:10.764Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=322033061 status=STATUS_OK Nov 04 15:31:10 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:10 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:11 volumio volumio[1379]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 04 15:31:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:11.805Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f6f3f9b3065a0e0819120018a4f0c0f2a433208827 type=REQUEST_TYPE_PING id=1719564790 Nov 04 15:31:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:11.805Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:11.805Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:11.805Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1719564790 status=STATUS_OK Nov 04 15:31:12 volumio volumio[1379]: info: MyVolumio token set successfully Nov 04 15:31:12 volumio volumio[1379]: info: MYVOLUMIO: Adding device Nov 04 15:31:12 volumio volumio[1379]: info: MYVOLUMIO: Evaluating Server Nov 04 15:31:12 volumio volumio[1379]: info: MyVolumio status changed Nov 04 15:31:12 volumio volumio[1379]: info: Streaming services startup Nov 04 15:31:12 volumio volumio[1379]: info: Starting Streaming Daemon Nov 04 15:31:12 volumio volumio[1379]: info: Removing browser output: myVolumio user plan is not superstar Nov 04 15:31:12 volumio volumio[1379]: info: Removing audio output: Nov 04 15:31:12 volumio volumio[1379]: info: Stoppping Tunnel 1 Nov 04 15:31:12 volumio sudo[2338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 04 15:31:12 volumio sudo[2338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:12 volumio sudo[2340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 04 15:31:12 volumio sudo[2340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:12 volumio sudo[2338]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio volumio[1379]: error: Cannot start Volumio Streaming Daemon Nov 04 15:31:12 volumio volumio[1379]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 04 15:31:12 volumio volumio[1379]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 15:31:12 volumio sudo[2340]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:12 volumio volumio[1379]: info: Remote SSH Stopped Nov 04 15:31:12 volumio volumio[1379]: info: Setting Geolocation for MyVolumio to as2 Nov 04 15:31:12 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:12 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:12 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:13 volumio volumio[1379]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 04 15:31:13 volumio sudo[2344]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 04 15:31:13 volumio sudo[2346]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:13 volumio sudo[2346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:13 volumio sudo[2344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:13 volumio sudo[2346]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:13 volumio sudo[2344]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:13 volumio sudo[2350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 04 15:31:13 volumio sudo[2350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:13 volumio (upmpdcli)[2352]: upmpdcli.service: Failed to locate executable /usr/bin/upmpdcli: No such file or directory Nov 04 15:31:13 volumio (upmpdcli)[2352]: upmpdcli.service: Failed at step EXEC spawning /usr/bin/upmpdcli: No such file or directory Nov 04 15:31:13 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Nov 04 15:31:13 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=203/EXEC Nov 04 15:31:13 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 04 15:31:13 volumio sudo[2350]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:13 volumio volumio[1379]: info: Upmpdcli Daemon Started Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:13 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:13 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:13 volumio volumio[1379]: info: Updating MyVolumio device info Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:13 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:14 volumio volumio[1379]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 04 15:31:15 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 04 15:31:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:15.209Z level=DEBUG msg="received event" component=volumio/socket event=pushBackendEventsStatus Nov 04 15:31:15 volumio volumio[1379]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 04 15:31:15 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:15 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:15.771Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08b9e48d98025a0e0819120018a68fc1f2a433208827 type=REQUEST_TYPE_PING id=587428409 Nov 04 15:31:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:15.771Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:15.772Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:15.772Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=587428409 status=STATUS_OK Nov 04 15:31:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:16.814Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08b0d3e0be025a0e0819120018b797c1f2a433208827 type=REQUEST_TYPE_PING id=668477872 Nov 04 15:31:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:16.814Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:16.814Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:16.814Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=668477872 status=STATUS_OK Nov 04 15:31:17 volumio volumio[1379]: info: MYVOLUMIO: Adding device Nov 04 15:31:17 volumio volumio[1379]: info: MYVOLUMIO: Evaluating Server Nov 04 15:31:17 volumio volumio[1379]: info: Setting Geolocation for MyVolumio to as2 Nov 04 15:31:17 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:17 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:17 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:18 volumio volumio[1379]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 04 15:31:18 volumio volumio[1379]: info: Updating MyVolumio device info Nov 04 15:31:18 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:18 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:18 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.372Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08c4b1ecad025a2d0807121e0a0b43656461725f536d6f6b65120f6275726e696e67776f6f643231313218adabc1f2a43320e0d403 type=REQUEST_TYPE_CONNECT_TO_WIFI id=633018564 Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.372Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONNECT_TO_WIFI peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.372Z level=INFO msg="connect to WiFi" component=server type=REQUEST_TYPE_CONNECT_TO_WIFI peer="192.168.1.187:38212 @ 0x3125170" latency=351.494832ms timeout=1m0s ssid=Cedar_Smoke Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.373Z level=INFO msg="wpa_supplicant control socket not functional, starting temporary daemon" component=volumio reason="dial unixgram /tmp/wpa_supplicant2528557394->/var/run/wpa_supplicant/wlan0: connect: no such file or directory" Nov 04 15:31:19 volumio wpa_supplicant[2386]: Successfully initialized wpa_supplicant Nov 04 15:31:19 volumio volumio[1379]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 04 15:31:19 volumio wpa_supplicant[2386]: nl80211: kernel reports: Registration to specific type not supported Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.886Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.886Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.886Z level=DEBUG msg="writing packet" component=conn/multi size=17 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.887Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:19 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:19 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:19 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:19 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:19 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:19 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:19 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.888Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:19 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 04 15:31:19 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.889Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.894Z level=INFO msg="BLE descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:19 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:19.895Z level=INFO msg="mDNS descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::volumioGetBrowseSources Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 15:31:20 volumio volumio[1379]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 04 15:31:20 volumio volumio[1379]: info: Completed starting MyVolumio Plugin Nov 04 15:31:20 volumio volumio[1379]: [Metrics] CommandRouter: 46s 527.17ms Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::volumiosetStartupVolume Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::Close All Modals sent Nov 04 15:31:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:20.775Z level=DEBUG msg="received event" component=volumio/socket event=closeAllModals Nov 04 15:31:20 volumio volumio[1379]: info: CoreCommandRouter::Close All Modals sent Nov 04 15:31:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:20.776Z level=DEBUG msg="received event" component=volumio/socket event=closeAllModals Nov 04 15:31:20 volumio volumio[1379]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Nov 04 15:31:20 volumio volumio[1379]: aplay: main:831: audio open error: Unknown error 524 Nov 04 15:31:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:20.794Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08c9b6bdf0025a0e0819120018b9b6c1f2a433208827 type=REQUEST_TYPE_PING id=772758345 Nov 04 15:31:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:20.794Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:20.794Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:20.794Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=772758345 status=STATUS_OK Nov 04 15:31:21 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 04 15:31:21 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:31:21 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 04 15:31:21 volumio volumio[1379]: info: Version has changed, forcing UI Reload Nov 04 15:31:21 volumio volumio[1379]: info: CoreCommandRouter::Reload Ui Nov 04 15:31:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:21.791Z level=DEBUG msg="received event" component=volumio/socket event=reloadUi Nov 04 15:31:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:21.823Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=089282ff8f055a0e0819120018cabec1f2a433208827 type=REQUEST_TYPE_PING id=1375715602 Nov 04 15:31:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:21.823Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:21.823Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:21.823Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1375715602 status=STATUS_OK Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: Trying to associate with 84:d8:1b:27:2c:40 (SSID='Cedar_Smoke' freq=5200 MHz) Nov 04 15:31:22 volumio sudo[2395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 04 15:31:22 volumio sudo[2395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:22 volumio sudo[2395]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:22 volumio sudo[2397]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:22 volumio sudo[2397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:22 volumio sudo[2397]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:22 volumio volumio[1379]: verbose: New Socket.io Connection to 192.168.1.74 from 192.168.1.156 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: Associated with 84:d8:1b:27:2c:40 Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: WPA: Key negotiation completed with 84:d8:1b:27:2c:40 [PTK=CCMP GTK=CCMP] Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: CTRL-EVENT-CONNECTED - Connection to 84:d8:1b:27:2c:40 completed [id=0 id_str=] Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.153Z level=INFO msg="connected temporarily to WiFi network" component=volumio ssid=Cedar_Smoke Nov 04 15:31:22 volumio dhcpcd[1020]: wlan0: carrier acquired Nov 04 15:31:22 volumio dhcpcd[1020]: wlan0: connected to Access Point: Cedar_Smoke Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: CTRL-EVENT-DISCONNECTED bssid=84:d8:1b:27:2c:40 reason=3 locally_generated=1 Nov 04 15:31:22 volumio dhcpcd[1020]: wlan0: IAID dd:b6:c4:55 Nov 04 15:31:22 volumio dhcpcd[1020]: wlan0: adding address fe80::693f:a2b7:6fd1:f22e Nov 04 15:31:22 volumio dhcpcd[1020]: ipv6_addaddr1: Permission denied Nov 04 15:31:22 volumio dhcpcd[1020]: wlan0: carrier lost - roaming Nov 04 15:31:22 volumio wpa_supplicant[2386]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::volumioGetVisibleSources Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Nov 04 15:31:22 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:22 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:22 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.209Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:22 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:22 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:22 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 15:31:22 volumio volumio[1379]: info: Retrieving Cloud Streaming UI Nov 04 15:31:22 volumio volumio[1379]: info: Getting Tidal Cloud Configuration Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 15:31:22 volumio volumio[1379]: info: Getting Qobuz Cloud Configuration Nov 04 15:31:22 volumio volumio[1379]: info: Asking plugin for UI Config Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 15:31:22 volumio volumio[1379]: info: Getting Spotify Cloud Configuration Nov 04 15:31:22 volumio volumio[1379]: info: Asking plugin for UI Config Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 15:31:22 volumio volumio[1379]: info: Saving Spotify Acccount Nov 04 15:31:22 volumio volumio[1379]: info: Got Tidal Cloud Configuration Nov 04 15:31:22 volumio volumio[1379]: info: Got it Nov 04 15:31:22 volumio volumio[1379]: info: Got it Nov 04 15:31:22 volumio volumio[1379]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 15:31:22 volumio volumio[1379]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Nov 04 15:31:22 volumio volumio[1379]: info: Saving new wireless network Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.247Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 15:31:22 volumio sudo[2421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Nov 04 15:31:22 volumio sudo[2421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:22 volumio dhcpcd[1020]: wlan0: soliciting an IPv6 router Nov 04 15:31:22 volumio sudo[2421]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Nov 04 15:31:22 volumio volumio[1379]: info: Discovery: Restarting Advertising due to device name change Nov 04 15:31:22 volumio sudo[2428]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Nov 04 15:31:22 volumio sudo[2428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:22 volumio systemd[1]: Stopping wireless.service - Wireless Services... Nov 04 15:31:22 volumio systemd[1]: wireless.service: Deactivated successfully. Nov 04 15:31:22 volumio systemd[1]: Stopped wireless.service - Wireless Services. Nov 04 15:31:22 volumio systemd[1]: Starting wireless.service - Wireless Services... Nov 04 15:31:22 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.626Z level=DEBUG msg="received event" component=volumio/socket event=updateReady Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.664Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.665Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.665Z level=DEBUG msg="writing packet" component=conn/multi size=16 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.665Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:22 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:22 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:22 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.668Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 04 15:31:22 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.670Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.672Z level=INFO msg="BLE descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:22 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:22.672Z level=INFO msg="mDNS descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:22 volumio wireless.js[2430]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Nov 04 15:31:22 volumio wireless.js[2430]: WIRELESS.JS: Wired network status changed to: ---connected--- Nov 04 15:31:22 volumio wireless.js[2430]: WIRELESS.JS: Wireless.js initializing wireless flow Nov 04 15:31:22 volumio wireless.js[2430]: WIRELESS.JS: Cleaning previous... Nov 04 15:31:22 volumio sudo[2448]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Nov 04 15:31:22 volumio sudo[2448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 04 15:31:22 volumio sudo[2448]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:22 volumio sudo[2450]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Nov 04 15:31:22 volumio sudo[2450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 04 15:31:23 volumio dhcpcd[1020]: wlan0: carrier lost Nov 04 15:31:23 volumio sudo[2450]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 15:31:23 volumio wireless.js[2430]: WIRELESS.JS: Stopped aP Nov 04 15:31:23 volumio sudo[2472]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 04 15:31:23 volumio sudo[2472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2472]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 04 15:31:23 volumio sudo[2474]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Nov 04 15:31:23 volumio sudo[2474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2474]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio sudo[2482]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 04 15:31:23 volumio sudo[2482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2482]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio sudo[2484]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Nov 04 15:31:23 volumio sudo[2484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio volumio[1379]: info: Discovery: A device disappeared from network Nov 04 15:31:23 volumio volumio[1379]: info: Discovery: Device volumio disappeared from network Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.478Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:31:23 volumio volumio[1379]: info: Discovery: A device disappeared from network Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.480Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:31:23 volumio sudo[2489]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:23 volumio sudo[2489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2489]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.489Z level=DEBUG msg="received event" component=volumio/socket event=pushSaveWirelessNetworkSettings Nov 04 15:31:23 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:23 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:23 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.603Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Nov 04 15:31:23 volumio volumio[1379]: info: Loading i18n strings for locale en Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Nov 04 15:31:23 volumio volumio[1379]: info: Setting timezone to Asia/Calcutta Nov 04 15:31:23 volumio sudo[2494]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Nov 04 15:31:23 volumio sudo[2494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2494]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio sudo[2498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Calcutta /etc/localtime Nov 04 15:31:23 volumio sudo[2498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2498]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio sudo[2502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Nov 04 15:31:23 volumio sudo[2502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio sudo[2502]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio sudo[2506]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Calcutta Nov 04 15:31:23 volumio sudo[2506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:23 volumio systemd-timedated[2164]: Changed time zone to 'Asia/Calcutta' (IST). Nov 04 15:31:23 volumio sudo[2506]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.851Z level=DEBUG msg="received event" component=volumio/socket event=pushMenuItems Nov 04 15:31:23 volumio volumio[1379]: Updating browse sources language Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.854Z level=DEBUG msg="received event" component=volumio/socket event=pushBrowseSources Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.889Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.891Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.891Z level=DEBUG msg="writing packet" component=conn/multi size=17 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.891Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:23 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:23 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:23 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.892Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.893Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.894Z level=INFO msg="BLE descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:23 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:23.895Z level=INFO msg="mDNS descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:23 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:23 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:24 volumio volumio[1379]: info: Fetching Streaming Services browse cache Nov 04 15:31:24 volumio sudo[2509]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:24 volumio sudo[2509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:24 volumio sudo[2509]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:24 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:25 volumio sudo[2512]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:25 volumio sudo[2512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:25 volumio sudo[2512]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:25 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:25.808Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=0887fbbaca045a0e0819120018daddc1f2a433208827 type=REQUEST_TYPE_PING id=1229897095 Nov 04 15:31:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:25.808Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:25.809Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:25.809Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1229897095 status=STATUS_OK Nov 04 15:31:25 volumio sudo[2484]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:25 volumio wireless.js[2430]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: IN Nov 04 15:31:25 volumio sudo[2530]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Nov 04 15:31:25 volumio sudo[2530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:25 volumio sudo[2530]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:25 volumio sudo[2532]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set IN Nov 04 15:31:25 volumio sudo[2532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:25 volumio sudo[2532]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:25 volumio wireless.js[2430]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: IN Nov 04 15:31:25 volumio wireless.js[2430]: WIRELESS.JS: Single Network Mode: Wired network active, not starting wireless flow Nov 04 15:31:26 volumio wireless.js[2430]: WIRELESS.JS: Notified systemd about wireless ready Nov 04 15:31:26 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Nov 04 15:31:26 volumio systemd[1]: Started wireless.service - Wireless Services. Nov 04 15:31:26 volumio sudo[2428]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.040Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.449Z level=DEBUG msg="network info updated" component=volumio/wifi ssid= ip4= ip6= Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.449Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.449Z level=DEBUG msg="writing packet" component=conn/multi size=16 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.450Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_WIFI_INFO_CHANGED Nov 04 15:31:26 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:26 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:26 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:26 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.451Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 04 15:31:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.452Z level=DEBUG msg="received event" component=volumio/socket event=pushWizard Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.454Z level=INFO msg="BLE descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.455Z level=INFO msg="mDNS descriptor updated" deviceId=8f9dfa18578a9839b5fbaca45be66780 deviceName=Volumio deviceModel= Nov 04 15:31:26 volumio sudo[2540]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:26 volumio sudo[2540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:26 volumio sudo[2540]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.833Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08acf6cdc5065a0e0819120018d9e5c1f2a433208827 type=REQUEST_TYPE_PING id=1756592940 Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.833Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.833Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:26.833Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1756592940 status=STATUS_OK Nov 04 15:31:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Nov 04 15:31:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 15:31:27 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:27 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:27 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:27.469Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:27 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 15:31:27 volumio volumio[1379]: info: Discovery: Started advertising with name: Volumio Nov 04 15:31:27 volumio sudo[2545]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:27 volumio sudo[2545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:27 volumio sudo[2545]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:27 volumio volumio[1379]: info: BOOT COMPLETED Nov 04 15:31:28 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:28 volumio volumio[1379]: info: Discovery: adding 8b0808a2-af60-46aa-b55d-930de7250212 Nov 04 15:31:28 volumio volumio[1379]: info: Discovery: Found device Volumio Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:28 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:28 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:28.376Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:31:28 volumio volumio[1379]: info: Discovery: this is already registered, 8b0808a2-af60-46aa-b55d-930de7250212 Nov 04 15:31:28 volumio volumio[1379]: info: Discovery: Found device Volumio Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:28 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:28 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:28.378Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:28 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:28 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:28 volumio volumio[1379]: verbose: New Socket.io Connection to 192.168.1.74:3000 from 192.168.1.187 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 04 15:31:28 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 04 15:31:28 volumio sudo[2550]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:28 volumio sudo[2550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:28 volumio sudo[2550]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:29 volumio sudo[2553]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:29 volumio sudo[2553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:29 volumio sudo[2553]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.054Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=089d879f88055a0e0809120018f2fec1f2a43320904e type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY id=1359463325 Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.054Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.054Z level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.375Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=http://pushupdates.volumio.org duration=319.10687ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.392Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=337.805741ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.420Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://www.googleapis.com duration=364.720426ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.476Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=420.711351ms Nov 04 15:31:30 volumio sudo[2564]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:30 volumio sudo[2564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:30 volumio sudo[2564]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.577Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://securetoken.googleapis.com duration=521.017166ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.615Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://functions.volumio.cloud duration=559.52687ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.620Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://database.volumio.cloud duration=564.058685ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.626Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=570.909573ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.740Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=684.006962ms Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.830Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f7d2ecac075a0e0819120018ec84c2f2a433208827 type=REQUEST_TYPE_PING id=1973102967 Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.830Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.830Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.830Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1973102967 status=STATUS_OK Nov 04 15:31:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:30.876Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://functions.volumio.cloud duration=820.492259ms Nov 04 15:31:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Nov 04 15:31:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Nov 04 15:31:31 volumio sudo[2567]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:31 volumio sudo[2567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:31 volumio sudo[2567]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.058Z level=DEBUG msg="received event" component=volumio/socket event=pushWizardWirelessConnResults Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.086Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=https://google.com duration=1.030662055s Nov 04 15:31:31 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:31 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:31 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.148Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.362Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=http://plugins.volumio.org duration=1.306284943s Nov 04 15:31:31 volumio sudo[2571]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:31 volumio sudo[2571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:31 volumio sudo[2571]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:31 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.579Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.187:38212 @ 0x3125170" latency=340.137308ms timeout=10s endpoint=http://cddb.volumio.org duration=1.523056462s Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.579Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.579Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1359463325 status=STATUS_OK Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.591Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08cc87abc5055a1008011202080518f18ac2f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=1487586252 Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.591Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.591Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=342.11601ms timeout=10s from=APP_PAGE_SETUP_V1_INTERNET Nov 04 15:31:31 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:31 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:31 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.593Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.594Z level=DEBUG msg="received event" component=volumio/socket event=updateWaitMsg Nov 04 15:31:31 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:31 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:31 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.596Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.849Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08fa80fca9035a0e0819120018f38cc2f2a433208827 type=REQUEST_TYPE_PING id=893321338 Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.849Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.850Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.850Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=893321338 status=STATUS_OK Nov 04 15:31:31 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:31 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.942Z level=DEBUG msg="received event" component=volumio/socket event=updateReady Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_SOFTWARE_INFO_CHANGED Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="writing packet" component=conn/multi size=32 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_SOFTWARE_INFO_CHANGED Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_SOFTWARE_UPDATE_PROGRESS Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="writing packet" component=conn/multi size=21 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_SOFTWARE_UPDATE_PROGRESS Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:31 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:31.943Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1487586252 status=STATUS_OK Nov 04 15:31:32 volumio sudo[2575]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:32 volumio sudo[2575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:32 volumio sudo[2575]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:33 volumio sudo[2578]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:33 volumio sudo[2578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:33 volumio sudo[2578]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:34 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:34.360Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08afecdedb025a1008011202080618c3a0c2f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=729265711 Nov 04 15:31:34 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:34.360Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:34 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:34.360Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=341.682231ms timeout=10s from=APP_PAGE_SETUP_V1_UPDATE Nov 04 15:31:34 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:34 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:34.362Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:31:34 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 04 15:31:34 volumio sudo[2581]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:34 volumio sudo[2581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:34 volumio sudo[2581]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:34 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:34.856Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioToken Nov 04 15:31:35 volumio sudo[2585]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:35 volumio sudo[2585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:35 volumio sudo[2585]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:35 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:35.518Z level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=t2zQiHHbqNQEpiREdOfVjBbhHPt1 tokenExpiry=2025-11-04T11:01:35.518Z Nov 04 15:31:35 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:35.850Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f68cc0c4065a0e08191200188aacc2f2a433208827 type=REQUEST_TYPE_PING id=1754269302 Nov 04 15:31:35 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:35.850Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:35 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:35.850Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:35 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:35.851Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1754269302 status=STATUS_OK Nov 04 15:31:36 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Nov 04 15:31:36 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Nov 04 15:31:36 volumio volumio[1379]: info: Refreshing Cached IP Addresses Nov 04 15:31:36 volumio sudo[2602]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Nov 04 15:31:36 volumio sudo[2602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:36 volumio sudo[2604]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 04 15:31:36 volumio sudo[2604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:36 volumio sudo[2604]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.059Z level=DEBUG msg="received event" component=volumio/socket event=pushInfoNetworkReload Nov 04 15:31:36 volumio sudo[2607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:36 volumio sudo[2607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:36 volumio sudo[2607]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:36 volumio sudo[2602]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:36 volumio volumio[1379]: error: Cannot kill upmpdcli Error: Command failed: /usr/bin/sudo /usr/bin/killall upmpdcli Nov 04 15:31:36 volumio volumio[1379]: upmpdcli: no process found Nov 04 15:31:36 volumio sudo[2611]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:36 volumio sudo[2611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:36 volumio sudo[2611]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.614Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_USER_CHANGED Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.614Z level=DEBUG msg="writing packet" component=conn/multi size=821 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.614Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_USER_CHANGED Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.614Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.614Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=729265711 status=STATUS_OK Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.862Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08b297d2c8065a0e081912001886b4c2f2a433208827 type=REQUEST_TYPE_PING id=1762954162 Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.863Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.863Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:36 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:36.863Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1762954162 status=STATUS_OK Nov 04 15:31:37 volumio sudo[2614]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:37 volumio sudo[2614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:37 volumio sudo[2614]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:38 volumio sudo[2620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:38 volumio sudo[2620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:38 volumio sudo[2620]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:39 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:39.474Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=088af3f1e4025aed05080a12dd050ada0565794a68624763694f694a53557a49314e694973496e523563434936496b705856434a392e65794a68645751694f694a6f64485277637a6f764c326c6b5a5735306158523564473976624774706443356e6232396e6247566863476c7a4c6d4e766253396e6232396e624755756157526c626e527064486b756157526c626e527064486c306232397361326c304c6e59784c6b6c6b5a57353061585235564739766247747064434973496d6c68644349364d5463324d6a49314d4451354e5377695a586877496a6f784e7a59794d6a55304d446b314c434a7063334d694f694a7465585a76624856746157394159584277633342766443356e63325679646d6c6a5a57466a59323931626e5175593239744969776963335669496a6f6962586c326232783162576c765147467763484e77623351755a334e6c636e5a705932566859324e76645735304c6d4e7662534973496e56705a434936496e5179656c4670534568696355355252584270556b566b54325a57616b4a69614568516444456966512e415641587372754e436967336f45727067515045736736344e6d69724d6a6a6976747a584c61537659495379574256544d733879396772474d50595232674c3469574d34646c6d5735397230715f714968317652746d533252543461587671554c67587246684a5566544d64777634557573543443363343385a41795f684261545f677864494d3345706847427756634665586f4c515f707043517a6c6f6151564d456e4f56616831646834664b6e3371417241414d474353554b6f4458505848626664645a6e69764768394a4a362d385145326f3061704c5a6f385761485068395746345864794a31386e696e454f467a34494e5f7541523233436e35304d685f31384f314c7a58426a3649637259643878426c335f5a38726a6550586835764a49755a684956463152577972537a44503270556e6e41326d774972635f423445455679356a72786855696d46533154576f31706718afc8c2f2a43320e0d403 type=REQUEST_TYPE_LOGIN_USER id=748452234 Nov 04 15:31:39 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:39.474Z level=INFO msg="received request" component=server type=REQUEST_TYPE_LOGIN_USER peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:39 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:39.474Z level=INFO msg="login user" component=server type=REQUEST_TYPE_LOGIN_USER peer="192.168.1.187:38212 @ 0x3125170" latency=355.160561ms timeout=1m0s token=eyJhbGciOiJSUzI1****jrxhUimFS1TWo1pg Nov 04 15:31:39 volumio sudo[2623]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:39 volumio sudo[2623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:39 volumio sudo[2623]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.026Z level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=t2zQiHHbqNQEpiREdOfVjBbhHPt1 tokenExpiry=2025-11-04T11:01:40.026Z Nov 04 15:31:40 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Nov 04 15:31:40 volumio volumio[1379]: info: MyVolumio login type: Token Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.029Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioToken Nov 04 15:31:40 volumio sudo[2626]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:40 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:40 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:40 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.735Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.735Z level=DEBUG msg="writing packet" component=conn/multi size=825 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.736Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=748452234 status=STATUS_OK Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.749Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08bbf5cfb2015a1008011202080718b7d2c2f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=374602427 Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.749Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.750Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=342.93869ms timeout=10s from=APP_PAGE_SETUP_V1_LOGIN_OPTIONS Nov 04 15:31:40 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Nov 04 15:31:40 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 15:31:40 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:31:40 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:31:40 volumio volumio[1379]: amixer -c 0 info | grep "vc4-hdmi-0" Nov 04 15:31:40 volumio volumio[1379]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Nov 04 15:31:40 volumio volumio[1379]: amixer -c 0 info | grep "vc4-hdmi-0" Nov 04 15:31:40 volumio volumio[1379]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Nov 04 15:31:40 volumio volumio[1379]: amixer -c 1 info | grep "vc4-hdmi-1" Nov 04 15:31:40 volumio volumio[1379]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Nov 04 15:31:40 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Nov 04 15:31:40 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:31:40 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:31:40 volumio volumio[1379]: amixer -c 2 info | grep "Cayin RU6" Nov 04 15:31:40 volumio volumio[1379]: Card sysdefault:2 'RU6'/'Cayin Cayin RU6 at usb-xhci-hcd.1-2, high speed' Nov 04 15:31:40 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Nov 04 15:31:40 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:31:40 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:31:40 volumio volumio[1379]: amixer -c 5 info | grep "M3i Integrated 24/96" Nov 04 15:31:40 volumio volumio[1379]: Card sysdefault:5 'M2496'/'Musical Fidelity M3i Integrated 24/96 at usb-xhci-hcd.1-1, full speed' Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.823Z level=DEBUG msg="received event" component=volumio/socket event=pushExtendedOutputDevices Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.823Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_AUDIO_OUTPUTS_CHANGED Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.823Z level=DEBUG msg="writing packet" component=conn/multi size=95 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.823Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_AUDIO_OUTPUTS_CHANGED Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.823Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.824Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=374602427 status=STATUS_OK Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.857Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=0888bedad9025a0e0819120018a6d3c2f2a433208827 type=REQUEST_TYPE_PING id=724999944 Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.857Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.858Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:40 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:40.858Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=724999944 status=STATUS_OK Nov 04 15:31:41 volumio sudo[2656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:41 volumio sudo[2656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:41 volumio sudo[2656]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 04 15:31:41 volumio volumio[1379]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 04 15:31:41 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:41.752Z level=DEBUG msg="received event" component=volumio/socket event=pushBackendEventsStatus Nov 04 15:31:41 volumio volumio[1379]: info: Received Get System Version Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 15:31:41 volumio volumio[1379]: info: Received Get System Info Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:31:41 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:31:41 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:31:41 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:31:41 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:41.885Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08fb92acd3055a0e08191200189adbc2f2a433208827 type=REQUEST_TYPE_PING id=1516964219 Nov 04 15:31:41 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:41.885Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:41 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:41.885Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:41 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:41.885Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1516964219 status=STATUS_OK Nov 04 15:31:42 volumio sudo[2659]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:42 volumio sudo[2659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:42 volumio sudo[2659]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:42 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:31:43 volumio sudo[2662]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:43 volumio sudo[2662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:43 volumio sudo[2662]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:44 volumio sudo[2665]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:44 volumio sudo[2665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:44 volumio sudo[2665]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:45 volumio sudo[2668]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:45 volumio sudo[2668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:45 volumio sudo[2668]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:45 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:45.869Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f9b6f3525a0e0819120018b6fac2f2a433208827 type=REQUEST_TYPE_PING id=173857657 Nov 04 15:31:45 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:45.869Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:45 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:45.869Z level=DEBUG msg="writing packet" component=conn/multi size=18 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:45 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:45.869Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=173857657 status=STATUS_OK Nov 04 15:31:46 volumio sudo[2685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 04 15:31:46 volumio sudo[2685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:46 volumio sudo[2685]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:46 volumio sudo[2687]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:46 volumio sudo[2687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:46 volumio sudo[2687]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:46 volumio sudo[2691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 04 15:31:46 volumio sudo[2691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:46 volumio (upmpdcli)[2693]: upmpdcli.service: Failed to locate executable /usr/bin/upmpdcli: No such file or directory Nov 04 15:31:46 volumio (upmpdcli)[2693]: upmpdcli.service: Failed at step EXEC spawning /usr/bin/upmpdcli: No such file or directory Nov 04 15:31:46 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Nov 04 15:31:46 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=203/EXEC Nov 04 15:31:46 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Nov 04 15:31:46 volumio sudo[2691]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:46 volumio volumio[1379]: info: Upmpdcli Daemon Started Nov 04 15:31:46 volumio sudo[2695]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:46 volumio sudo[2695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:46 volumio sudo[2695]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:46 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:46.899Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08bbb898f8075a0e0819120018b982c3f2a433208827 type=REQUEST_TYPE_PING id=2131106875 Nov 04 15:31:46 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:46.899Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:46 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:46.899Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:46 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:46.899Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=2131106875 status=STATUS_OK Nov 04 15:31:47 volumio sudo[2698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:47 volumio sudo[2698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:47 volumio sudo[2698]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:48 volumio sudo[2701]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:48 volumio sudo[2701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:48 volumio sudo[2701]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:49 volumio avahi-daemon[983]: Record [_Volumio._tcp.local IN PTR volumio._Volumio._tcp.local ; ttl=4500] not fitting in legacy unicast packet, dropping. Nov 04 15:31:49 volumio avahi-daemon[983]: Record [volumio._Volumio._tcp.local IN TXT "volumioName=Volumio" "UUID=8b0808a2-af60-46aa-b55d-930de7250212" ; ttl=4500] not fitting in legacy unicast packet, dropping. Nov 04 15:31:49 volumio avahi-daemon[983]: Record [volumio._Volumio._tcp.local IN SRV 0 0 3000 volumio.local ; ttl=120] not fitting in legacy unicast packet, dropping. Nov 04 15:31:49 volumio sudo[2704]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:49 volumio sudo[2704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:49 volumio sudo[2704]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:50 volumio sudo[2707]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:50 volumio sudo[2707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:50 volumio sudo[2707]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.876Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08ffeef29b045a0e0819120018c8a1c3f2a433208827 type=REQUEST_TYPE_PING id=1132246911 Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.876Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.876Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.876Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1132246911 status=STATUS_OK Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.908Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08afedaa705a11080b12030a013218e9a1c3f2a43320904e type=REQUEST_TYPE_TEST_AUDIO_OUTPUT id=235583151 Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.909Z level=INFO msg="received request" component=server type=REQUEST_TYPE_TEST_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:50 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:50.909Z level=INFO msg="test audio output" component=server type=REQUEST_TYPE_TEST_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" latency=339.946406ms timeout=10s id=2 Nov 04 15:31:51 volumio sudo[2711]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:51 volumio sudo[2711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:51 volumio sudo[2711]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:51 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:51.907Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=0894b2b7f3075a0e0819120018cea9c3f2a433208827 type=REQUEST_TYPE_PING id=2121128212 Nov 04 15:31:51 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:51.907Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:51 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:51.907Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:51 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:51.907Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=2121128212 status=STATUS_OK Nov 04 15:31:52 volumio sudo[2714]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 15:31:52 volumio sudo[2714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:31:52 volumio sudo[2714]: pam_unix(sudo:session): session closed for user root Nov 04 15:31:52 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:52.507Z level=DEBUG msg="received event" component=volumio/socket event=pushSaveWirelessNetworkSettings Nov 04 15:31:52 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:52.507Z level=ERROR msg="failed to save WiFi network settings" component=server type=REQUEST_TYPE_CONNECT_TO_WIFI peer="192.168.1.187:38212 @ 0x3125170" latency=351.494832ms timeout=1m0s ssid=Cedar_Smoke error="could not save Wi-Fi network \"Cedar_Smoke\": failed to connect to WiFi network \"Cedar_Smoke\"" Nov 04 15:31:52 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:52.507Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:52 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:52.507Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=633018564 status=STATUS_UNKNOWN Nov 04 15:31:53 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Nov 04 15:31:53 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 15:31:53 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Nov 04 15:31:54 volumio volumio-remote-updater[991]: Test mode disabled Nov 04 15:31:54 volumio volumio-remote-updater[991]: Alpha mode disabled Nov 04 15:31:54 volumio volumio-remote-updater[991]: Alpha legacy test mode disabled Nov 04 15:31:54 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:54.097Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 15:31:54 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 15:31:54 volumio volumio[1379]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 15:31:54 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 15:31:55 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:55.880Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08b3fac3bb025a0e0819120018d5c8c3f2a433208827 type=REQUEST_TYPE_PING id=661716275 Nov 04 15:31:55 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:55.881Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:55 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:55.881Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:55 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:55.881Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=661716275 status=STATUS_OK Nov 04 15:31:56 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:56.197Z level=DEBUG msg="writing packet" component=conn/multi size=18 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:56 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:56.197Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=235583151 status=STATUS_OK Nov 04 15:31:56 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:56.913Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08d2c9a0d5025a0e0819120018ded0c3f2a433208827 type=REQUEST_TYPE_PING id=715662546 Nov 04 15:31:56 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:56.914Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:56 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:56.914Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:31:56 volumio volumio5-onboarding[1952]: time=2025-11-04T10:01:56.914Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=715662546 status=STATUS_OK Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.286Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08aad8bedd055a11080b12030a0132188bebc3f2a43320904e type=REQUEST_TYPE_TEST_AUDIO_OUTPUT id=1538239530 Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.287Z level=INFO msg="received request" component=server type=REQUEST_TYPE_TEST_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.287Z level=INFO msg="test audio output" component=server type=REQUEST_TYPE_TEST_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" latency=340.01929ms timeout=10s id=2 Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.898Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f7bca8a5055a0e0819120018e2efc3f2a433208827 type=REQUEST_TYPE_PING id=1420435063 Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.898Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.898Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:00 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:00.899Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1420435063 status=STATUS_OK Nov 04 15:32:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:01.920Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f8d9fdfc025a0e0819120018eaf7c3f2a433208827 type=REQUEST_TYPE_PING id=798977272 Nov 04 15:32:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:01.920Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:01.920Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:01 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:01.920Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=798977272 status=STATUS_OK Nov 04 15:32:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:05.552Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:05.553Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1538239530 status=STATUS_OK Nov 04 15:32:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:05.918Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08fe9796af035a0e0819120018fc96c4f2a433208827 type=REQUEST_TYPE_PING id=904236030 Nov 04 15:32:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:05.919Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:05.919Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:05 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:05.919Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=904236030 status=STATUS_OK Nov 04 15:32:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:06.929Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08e7d4c6465a0e0819120018fd9ec4f2a433208827 type=REQUEST_TYPE_PING id=147958375 Nov 04 15:32:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:06.929Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:06.929Z level=DEBUG msg="writing packet" component=conn/multi size=18 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:06 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:06.929Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=147958375 status=STATUS_OK Nov 04 15:32:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:07.523Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=089a96aff0065a11080b12030a013518c2a3c4f2a43320904e type=REQUEST_TYPE_TEST_AUDIO_OUTPUT id=1846266650 Nov 04 15:32:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:07.523Z level=INFO msg="received request" component=server type=REQUEST_TYPE_TEST_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:07 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:07.524Z level=INFO msg="test audio output" component=server type=REQUEST_TYPE_TEST_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" latency=353.925248ms timeout=10s id=5 Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.495Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08f5838fd9075a11080c12030a01321883b3c4f2a43320904e type=REQUEST_TYPE_SET_AUDIO_OUTPUT id=2065940981 Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.495Z level=INFO msg="received request" component=server type=REQUEST_TYPE_SET_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.495Z level=INFO msg="set audio output" component=server type=REQUEST_TYPE_SET_AUDIO_OUTPUT peer="192.168.1.187:38212 @ 0x3125170" latency=340.766136ms timeout=10s id=2 Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.507Z level=DEBUG msg="received event" component=volumio/socket event=pushOutputDevices Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Nov 04 15:32:09 volumio volumio[1379]: info: Preparing to save Alsa Options, stopping services first Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:32:09 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::volumioPause Nov 04 15:32:09 volumio volumio[1379]: info: CoreStateMachine::pause Nov 04 15:32:09 volumio volumio[1379]: info: Saving Audio Output to: {"i2s":false,"i2sid":{"value":"","label":""},"output_device":{"value":"2","label":"Cayin RU6"},"disallowPush":true} Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:32:09 volumio volumio[1379]: info: Setting mixer PCM for card Cayin RU6 Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 04 15:32:09 volumio volumio[1379]: info: Updating Volume Controller Parameters: Device: 2 Name: Cayin RU6 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 04 15:32:09 volumio volumio[1379]: info: Disabling external Volume Control Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 15:32:09 volumio volumio[1379]: info: Preparing to generate the ALSA configuration file Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:32:09 volumio volumio[1379]: amixer -c 0 info | grep "vc4-hdmi-0" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Nov 04 15:32:09 volumio volumio[1379]: amixer -c 1 info | grep "vc4-hdmi-1" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Nov 04 15:32:09 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Nov 04 15:32:09 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:32:09 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:32:09 volumio volumio[1379]: amixer -c 5 info | grep "M3i Integrated 24/96" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:5 'M2496'/'Musical Fidelity M3i Integrated 24/96 at usb-xhci-hcd.1-1, full speed' Nov 04 15:32:09 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Nov 04 15:32:09 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:32:09 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:32:09 volumio volumio[1379]: amixer -c 2 info | grep "Cayin RU6" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:2 'RU6'/'Cayin Cayin RU6 at usb-xhci-hcd.1-2, high speed' Nov 04 15:32:09 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Nov 04 15:32:09 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:32:09 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:32:09 volumio volumio[1379]: amixer -c 2 info | grep "Cayin RU6" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:2 'RU6'/'Cayin Cayin RU6 at usb-xhci-hcd.1-2, high speed' Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.641Z level=DEBUG msg="received event" component=volumio/socket event=pushExtendedOutputDevices Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:32:09 volumio volumio[1379]: amixer -c 0 info | grep "vc4-hdmi-0" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Nov 04 15:32:09 volumio volumio[1379]: amixer -c 1 info | grep "vc4-hdmi-1" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 04 15:32:09 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Nov 04 15:32:09 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:32:09 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:32:09 volumio volumio[1379]: amixer -c 5 info | grep "M3i Integrated 24/96" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:5 'M2496'/'Musical Fidelity M3i Integrated 24/96 at usb-xhci-hcd.1-1, full speed' Nov 04 15:32:09 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Nov 04 15:32:09 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:32:09 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:32:09 volumio volumio[1379]: amixer -c 2 info | grep "Cayin RU6" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:2 'RU6'/'Cayin Cayin RU6 at usb-xhci-hcd.1-2, high speed' Nov 04 15:32:09 volumio volumio[1379]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Nov 04 15:32:09 volumio volumio[1379]: /bin/sh: 1: /usr/local/bin/alsacap: not found Nov 04 15:32:09 volumio volumio[1379]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Nov 04 15:32:09 volumio volumio[1379]: amixer -c 2 info | grep "Cayin RU6" Nov 04 15:32:09 volumio volumio[1379]: Card sysdefault:2 'RU6'/'Cayin Cayin RU6 at usb-xhci-hcd.1-2, high speed' Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.769Z level=DEBUG msg="received event" component=volumio/socket event=pushExtendedOutputDevices Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.770Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_AUDIO_OUTPUTS_CHANGED Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.770Z level=DEBUG msg="writing packet" component=conn/multi size=96 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:09 volumio volumio[1379]: info: VolumeController:: Volume=41 Mute =false Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.770Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_AUDIO_OUTPUTS_CHANGED Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.770Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:09 volumio volumio[1379]: info: CoreStateMachine::pushState Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.771Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=2065940981 status=STATUS_OK Nov 04 15:32:09 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.773Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.777Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.777Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.777Z level=DEBUG msg="writing packet" component=conn/multi size=27 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.777Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.778Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.778Z level=DEBUG msg="writing packet" component=conn/multi size=34 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.778Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED Nov 04 15:32:09 volumio volumio[1379]: info: Asound.conf file written Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.784Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08c2b5b7be045a1008011202080818a3b5c4f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=1204673218 Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.785Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.785Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=341.817062ms timeout=10s from=APP_PAGE_SETUP_V1_AUDIO_OUTPUTS Nov 04 15:32:09 volumio sudo[2838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 04 15:32:09 volumio sudo[2838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio sudo[2838]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:09 volumio volumio[1379]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Nov 04 15:32:09 volumio volumio[1379]: No state is present for card vc4hdmi0 Nov 04 15:32:09 volumio volumio[1379]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Nov 04 15:32:09 volumio volumio[1379]: Found hardware: "vc4-hdmi" "" "" "" "" Nov 04 15:32:09 volumio volumio[1379]: Hardware is initialized using a generic method Nov 04 15:32:09 volumio volumio[1379]: No state is present for card vc4hdmi0 Nov 04 15:32:09 volumio volumio[1379]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Nov 04 15:32:09 volumio volumio[1379]: No state is present for card vc4hdmi1 Nov 04 15:32:09 volumio volumio[1379]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Nov 04 15:32:09 volumio volumio[1379]: Found hardware: "vc4-hdmi" "" "" "" "" Nov 04 15:32:09 volumio volumio[1379]: Hardware is initialized using a generic method Nov 04 15:32:09 volumio volumio[1379]: No state is present for card vc4hdmi1 Nov 04 15:32:09 volumio volumio[1379]: No state is present for card RU6 Nov 04 15:32:09 volumio volumio[1379]: Found hardware: "USB-Audio" "USB Mixer" "USB2d87:c001" "" "" Nov 04 15:32:09 volumio volumio[1379]: Hardware is initialized using a generic method Nov 04 15:32:09 volumio volumio[1379]: No state is present for card RU6 Nov 04 15:32:09 volumio volumio[1379]: No state is present for card M2496 Nov 04 15:32:09 volumio volumio[1379]: Found hardware: "USB-Audio" "USB Mixer" "USB25b0:0015" "" "" Nov 04 15:32:09 volumio volumio[1379]: Hardware is initialized using a generic method Nov 04 15:32:09 volumio volumio[1379]: No state is present for card M2496 Nov 04 15:32:09 volumio volumio[1379]: info: Output device has changed, restarting MPD Nov 04 15:32:09 volumio volumio[1379]: info: Output device has changed, restarting Shairport Sync Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio sudo[2844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 04 15:32:09 volumio sudo[2844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio sudo[2844]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:09 volumio volumio[1379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 04 15:32:09 volumio volumio[1379]: info: Output device has changed, restarting MPD Nov 04 15:32:09 volumio sudo[2847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 04 15:32:09 volumio sudo[2847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio sudo[2854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 04 15:32:09 volumio sudo[2856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 04 15:32:09 volumio volumio[1379]: info: Output device has changed, restarting Shairport Sync Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio sudo[2856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio sudo[2854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio sudo[2854]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 04 15:32:09 volumio volumio[1379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:09 volumio volumio[1379]: info: MPD Permissions set Nov 04 15:32:09 volumio volumio[1379]: info: MPD Permissions set Nov 04 15:32:09 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:09.878Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:09 volumio volumio[1379]: info: Starting Shairport Sync Nov 04 15:32:09 volumio volumio[1379]: info: Starting Shairport Sync Nov 04 15:32:09 volumio sudo[2875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 04 15:32:09 volumio sudo[2875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio sudo[2877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 04 15:32:09 volumio sudo[2877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 04 15:32:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 04 15:32:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 04 15:32:09 volumio systemd[1]: shairport-sync.service: Consumed 1.643s CPU time. Nov 04 15:32:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 04 15:32:09 volumio sudo[2875]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:09 volumio sudo[2877]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:09 volumio volumio[1379]: info: Shairport-Sync Started Nov 04 15:32:09 volumio volumio[1379]: info: Shairport-Sync Started Nov 04 15:32:10 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 04 15:32:10 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 04 15:32:10 volumio systemd[1]: mpd.service: Consumed 1min 4.411s CPU time. Nov 04 15:32:10 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 04 15:32:10 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 04 15:32:10 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 04 15:32:10 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 04 15:32:10 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 04 15:32:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:10.937Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=088fe9aa8d025a0e081912001899bec4f2a433208827 type=REQUEST_TYPE_PING id=564835471 Nov 04 15:32:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:10.937Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:10.937Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:10 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:10.937Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=564835471 status=STATUS_OK Nov 04 15:32:10 volumio sudo[2896]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 04 15:32:10 volumio sudo[2896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 04 15:32:10 volumio sudo[2896]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.566Z level=DEBUG msg="received event" component=volumio/socket event=pushAvailablePlugins Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.571Z level=DEBUG msg="received event" component=volumio/socket event=pushInstalledPlugins Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.571Z level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.571Z level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.571Z level=WARN msg="could not read username/password data for music provider" component=volumio provider=highresaudio error="could not open plugin config file for \"highresaudio\": open /data/configuration/music_service/highresaudio/config.json: no such file or directory" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.571Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_MUSIC_PROVIDERS_CHANGED Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.571Z level=DEBUG msg="writing packet" component=conn/multi size=905 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.572Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_MUSIC_PROVIDERS_CHANGED Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.572Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.572Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1204673218 status=STATUS_OK Nov 04 15:32:11 volumio mpd[2898]: 2025-11-04T15:32:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 04 15:32:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 04 15:32:11 volumio sudo[2847]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:11 volumio sudo[2856]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.626Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.629Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 15:32:11 volumio volumio[1379]: error: MPD error: The expression evaluated to a falsy value: Nov 04 15:32:11 volumio volumio[1379]: assert.ok(self.idling) Nov 04 15:32:11 volumio volumio[1379]: error: The expression evaluated to a falsy value: Nov 04 15:32:11 volumio volumio[1379]: assert.ok(self.idling) Nov 04 15:32:11 volumio volumio[1379]: error: updateQueue error: null Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.935Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08e480bc95035a0e08191200188bc6c4f2a433208827 type=REQUEST_TYPE_PING id=850329700 Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.935Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.935Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:11 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:11.935Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=850329700 status=STATUS_OK Nov 04 15:32:12 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:12.799Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:12 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:12.799Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1846266650 status=STATUS_OK Nov 04 15:32:13 volumio volumio[1379]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 04 15:32:13 volumio volumio[1379]: info: CoreStateMachine::getcurrentVolume Nov 04 15:32:13 volumio volumio[1379]: info: CoreCommandRouter::volumioRetrievevolume Nov 04 15:32:13 volumio volumio[1379]: info: VolumeController:: Volume=41 Mute =false Nov 04 15:32:13 volumio volumio[1379]: info: CoreStateMachine::pushState Nov 04 15:32:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:32:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.577Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:32:13 volumio volumio[1379]: info: CoreStateMachine::updateTrackBlock Nov 04 15:32:13 volumio volumio[1379]: info: CorePlayQueue::getTrackBlock Nov 04 15:32:13 volumio volumio[1379]: info: CoreCommandRouter::volumioRetrievevolume Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.583Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.583Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.583Z level=DEBUG msg="writing packet" component=conn/multi size=27 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.584Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.584Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.584Z level=DEBUG msg="writing packet" component=conn/multi size=34 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.585Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED Nov 04 15:32:13 volumio volumio[1379]: info: VolumeController:: Volume=41 Mute =false Nov 04 15:32:13 volumio volumio[1379]: info: CoreStateMachine::pushState Nov 04 15:32:13 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:32:13 volumio volumio[1379]: info: CoreCommandRouter::volumioPushState Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.598Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.599Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.600Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.600Z level=DEBUG msg="writing packet" component=conn/multi size=27 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.600Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_STATE_CHANGED Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.600Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.600Z level=DEBUG msg="writing packet" component=conn/multi size=34 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:13 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:13.600Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_PLAYER_METADATA_CHANGED Nov 04 15:32:14 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 15:32:14 volumio sudo[2906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 04 15:32:14 volumio sudo[2906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:14 volumio sudo[2908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 04 15:32:14 volumio sudo[2908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 15:32:14 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 04 15:32:14 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 04 15:32:14 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 04 15:32:14 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 04 15:32:14 volumio sudo[2906]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:14 volumio volumio[1379]: info: Successfully started MPD Monitor Nov 04 15:32:14 volumio mpd_monitor.sh[2911]: MPD Monitor Service: Starting MPD Monitor Service Nov 04 15:32:14 volumio sudo[2908]: pam_unix(sudo:session): session closed for user root Nov 04 15:32:14 volumio volumio[1379]: info: Successfully started MPD Monitor Nov 04 15:32:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:15.947Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08b1d5abdf055a0e0819120018b5e5c4f2a433208827 type=REQUEST_TYPE_PING id=1542122161 Nov 04 15:32:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:15.947Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:15.947Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:15 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:15.947Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1542122161 status=STATUS_OK Nov 04 15:32:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:16.949Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=0882c0eebe025a0e08191200189eedc4f2a433208827 type=REQUEST_TYPE_PING id=668704770 Nov 04 15:32:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:16.949Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:16.949Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:16 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:16.949Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=668704770 status=STATUS_OK Nov 04 15:32:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:20.966Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08a1be88e3055a0e0819120018c68cc5f2a433208827 type=REQUEST_TYPE_PING id=1549934369 Nov 04 15:32:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:20.967Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:20.967Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:20 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:20.967Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1549934369 status=STATUS_OK Nov 04 15:32:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:21.972Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08d8d9a9c3015a0e0819120018b394c5f2a433208827 type=REQUEST_TYPE_PING id=409627864 Nov 04 15:32:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:21.973Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:21.973Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:21 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:21.973Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=409627864 status=STATUS_OK Nov 04 15:32:24 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:24.694Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=0896d9b484055a1a080d120c0a0a736f756e64636c6f756418e2a9c5f2a43320904e type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER id=1351429270 Nov 04 15:32:24 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:24.694Z level=INFO msg="received request" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:24 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:24.695Z level=INFO msg="enable music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.1.187:38212 @ 0x3125170" latency=340.955701ms timeout=10s provider=soundcloud Nov 04 15:32:24 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:24 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:24.696Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:24 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:24 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 04 15:32:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:25.974Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08c8eea7ca025a0e0819120018e2b3c5f2a433208827 type=REQUEST_TYPE_PING id=692713288 Nov 04 15:32:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:25.975Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:25.975Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:25 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:25.975Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=692713288 status=STATUS_OK Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.166Z level=DEBUG msg="received event" component=volumio/socket event=pushAvailablePlugins Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.170Z level=DEBUG msg="received event" component=volumio/socket event=pushInstalledPlugins Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.170Z level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.170Z level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.170Z level=WARN msg="could not read username/password data for music provider" component=volumio provider=highresaudio error="could not open plugin config file for \"highresaudio\": open /data/configuration/music_service/highresaudio/config.json: no such file or directory" Nov 04 15:32:26 volumio volumio[1379]: info: Received Get System Info Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 04 15:32:26 volumio volumio[1379]: info: Discovery: Getting this device information Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::volumioGetState Nov 04 15:32:26 volumio volumio[1379]: info: CorePlayQueue::getTrack 0 Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.172Z level=DEBUG msg="received event" component=volumio/socket event=pushSystemInfo Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.430Z level=INFO msg="installing required plugin for music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.1.187:38212 @ 0x3125170" latency=340.955701ms timeout=10s provider=soundcloud plugin=soundcloud Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.431Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:26 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.985Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=08b8a0fcd6075a0e0819120018d5bbc5f2a433208827 type=REQUEST_TYPE_PING id=2061439032 Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.985Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.985Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:26 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:26.985Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=2061439032 status=STATUS_OK Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.706Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=089fe79adb015a10080112020809189bc1c5f2a43320904e type=REQUEST_TYPE_CONTINUE_NAVIGATION id=459715487 Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.706Z level=INFO msg="received request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.706Z level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.187:38212 @ 0x3125170" latency=351.70181ms timeout=10s from=APP_PAGE_SETUP_V1_MUSIC_PROVIDERS Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.706Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.706Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=459715487 status=STATUS_OK Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.786Z level=DEBUG msg="received event" component=volumio/socket event=pushAvailablePlugins Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.790Z level=DEBUG msg="received event" component=volumio/socket event=pushInstalledPlugins Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.791Z level=DEBUG msg="received event" component=volumio/socket event=closeModals Nov 04 15:32:27 volumio volumio[1379]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/bookworm/armhf Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="received event" component=volumio/socket event=openInstallerModal Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="received event" component=volumio/socket event=installPluginStatus Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="sending event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_MUSIC_PROVIDER_CHANGED Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="writing packet" component=conn/multi size=125 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="sent event" component=server dst="192.168.1.187:38212 @ 0x3125170" event=SERVER_EVENT_TYPE_MUSIC_PROVIDER_CHANGED Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="writing packet" component=conn/multi size=23 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:27 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:27.797Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=1351429270 status=STATUS_OK Nov 04 15:32:30 volumio volumio[1379]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/bookworm/armhf Nov 04 15:32:30 volumio volumio[1379]: info: Folder /tmp/plugins removed Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.711Z level=DEBUG msg="received event" component=volumio/socket event=installPluginStatus Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.719Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.789Z level=DEBUG msg="received event" component=volumio/socket event=installPluginStatus Nov 04 15:32:30 volumio volumio[1379]: info: Check plugin dependencies Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.810Z level=DEBUG msg="received event" component=volumio/socket event=installPluginStatus Nov 04 15:32:30 volumio volumio[1379]: info: Checking if plugin already exists Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.812Z level=DEBUG msg="received event" component=volumio/socket event=installPluginStatus Nov 04 15:32:30 volumio volumio[1379]: info: Rename folder Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:30 volumio volumio[1379]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.821Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.821Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.821Z level=DEBUG msg="received event" component=volumio/socket event=pushMyVolumioStatus Nov 04 15:32:30 volumio volumio[1379]: info: Folder /tmp/downloaded_plugin.zip removed Nov 04 15:32:30 volumio volumio[1379]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 15:32:30 volumio volumio[1379]: TypeError: Cannot read properties of undefined (reading 'plugin_type') Nov 04 15:32:30 volumio volumio[1379]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1644:56) Nov 04 15:32:30 volumio volumio[1379]: at PluginManager.getAvailablePlugins (/volumio/app/pluginmanager.js:1691:24) Nov 04 15:32:30 volumio volumio[1379]: at CoreCommandRouter.getAvailablePlugins (/volumio/app/index.js:1544:29) Nov 04 15:32:30 volumio volumio[1379]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1354:45) Nov 04 15:32:30 volumio volumio[1379]: at Socket.emit (node:events:514:28) Nov 04 15:32:30 volumio volumio[1379]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Nov 04 15:32:30 volumio volumio[1379]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Nov 04 15:32:30 volumio volumio[1379]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.985Z level=DEBUG msg="received request" component=server src="192.168.1.187:38212 @ 0x3125170" packet=0899c1fdf0015a0e0819120018f2dac5f2a433208827 type=REQUEST_TYPE_PING id=505372825 Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.985Z level=INFO msg="received request" component=server type=REQUEST_TYPE_PING peer="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.985Z level=DEBUG msg="writing packet" component=conn/multi size=19 addr="192.168.1.187:38212 @ 0x3125170" Nov 04 15:32:30 volumio volumio5-onboarding[1952]: time=2025-11-04T10:02:30.985Z level=DEBUG msg="sent response" component=server dst="192.168.1.187:38212 @ 0x3125170" id=505372825 status=STATUS_OK Nov 04 15:32:31 volumio sudo[2967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-04 15:31' Nov 04 15:32:31 volumio sudo[2967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="1bb44897f7ce359a55b9194fdfa5cb35d97fb06e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Nov 3 09:07:40 UTC 2025" VOLUMIO_VERSION="4.064" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="55f2684742b79a5937291394763da14b"