Jan 10 22:36:03 volumiorpi5 volumio[1505]: verbose: New Socket.io Connection to 192.168.79.211 from 192.168.79.130 UA: Mozilla/5.0 (Linux; Android 15; ASUS_AI2302 Build/AQ3A.240812.002; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.146 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 14 Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetVisibleSources Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetState Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: Received Get System Info Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: Discovery: Getting this device information Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetState Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetState Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: Listing playlists Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 10 22:36:03 volumiorpi5 volumio[1505]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 10 22:36:04 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 10 22:36:08 volumiorpi5 volumio[1505]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/allo_relay_attenuator/volumio/bookworm/armhf Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/allo_relay_attenuator/volumio/bookworm/armhf Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Folder /tmp/plugins removed Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Check plugin dependencies Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Checking if plugin already exists Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Rename folder Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Folder /tmp/downloaded_plugin.zip removed Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Move to category Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Checking if install.sh is present Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Executing install.sh Jan 10 22:36:09 volumiorpi5 sudo[13790]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/system_hardware/allo_relay_attenuator/install.sh Jan 10 22:36:09 volumiorpi5 sudo[13790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Installing Allo Relay Attenuator plugin Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Detected architecture: arm Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Using packages from: /data/plugins/system_hardware/allo_relay_attenuator/packages/arm Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Jan 10 22:36:09 volumiorpi5 volumio[1505]: info: Cleaning up previous installation... Jan 10 22:36:10 volumiorpi5 volumio[1505]: info: Cleanup complete Jan 10 22:36:10 volumiorpi5 volumio[1505]: info: Jan 10 22:36:10 volumiorpi5 volumio[1505]: info: Installing dependencies... Jan 10 22:36:10 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:10+01:00" level=debug msg="fetched chunk 22/23, size: 524288" uri="spotify:track:499KI8AMbwmtiNfREkP1SB" Jan 10 22:36:10 volumiorpi5 volumio[1505]: info: Hit:1 https://deb.nodesource.com/node_20.x nodistro InRelease Jan 10 22:36:10 volumiorpi5 volumio[1505]: info: Hit:2 http://archive.raspberrypi.com/debian bookworm InRelease Jan 10 22:36:10 volumiorpi5 volumio[1505]: info: Hit:3 http://raspbian.raspberrypi.com/raspbian bookworm InRelease Jan 10 22:36:12 volumiorpi5 volumio[1505]: info: Reading package lists... Jan 10 22:36:12 volumiorpi5 volumio[1505]: info: Installing LIRC client library... Jan 10 22:36:13 volumiorpi5 volumio[1505]: info: Reading package lists... Jan 10 22:36:13 volumiorpi5 volumio[1505]: info: Building dependency tree... Jan 10 22:36:13 volumiorpi5 volumio[1505]: info: Reading state information... Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: liblirc-client0 is already the newest version (0.10.1-7.2). Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: liblirc-client0 set to manually installed. Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: The following NEW packages will be installed: Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: liblircclient0 Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: 0 upgraded, 1 newly installed, 0 to remove and 14 not upgraded. Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: Need to get 30.8 kB of archives. Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: After this operation, 44.0 kB of additional disk space will be used. Jan 10 22:36:14 volumiorpi5 volumio[1505]: info: Get:1 http://ftp.icm.edu.pl/pub/Linux/distributions/raspbian/raspbian bookworm/main armhf liblircclient0 armhf 0.10.1-7.2 [30.8 kB] Jan 10 22:36:15 volumiorpi5 volumio[1505]: info: Fetched 30.8 kB in 0s (71.8 kB/s) Jan 10 22:36:15 volumiorpi5 volumio[1505]: info: Selecting previously unselected package liblircclient0. Jan 10 22:36:16 volumiorpi5 volumio[1505]: [620B blob data] Jan 10 22:36:16 volumiorpi5 volumio[1505]: info: Preparing to unpack .../liblircclient0_0.10.1-7.2_armhf.deb ... Jan 10 22:36:16 volumiorpi5 volumio[1505]: info: Unpacking liblircclient0 (0.10.1-7.2) ... Jan 10 22:36:16 volumiorpi5 volumio[1505]: info: Setting up liblircclient0 (0.10.1-7.2) ... Jan 10 22:36:16 volumiorpi5 volumio[1505]: info: Installing LIRC daemon... Jan 10 22:36:16 volumiorpi5 volumio[1505]: info: Reading package lists... Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: Building dependency tree... Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: Reading state information... Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: lirc is already the newest version (0.10.1-7.2). Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: 0 upgraded, 0 newly installed, 0 to remove and 14 not upgraded. Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: Installing bundled packages... Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: Installing libfn-lgpio0... Jan 10 22:36:17 volumiorpi5 volumio[1505]: info: Selecting previously unselected package libfn-lgpio0. Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: (Reading database ... 52897 files and directories currently installed.) Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Preparing to unpack .../libfn-lgpio0_0.2.2-1_arm.deb ... Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Unpacking libfn-lgpio0 (0.2.2-1) ... Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Setting up libfn-lgpio0 (0.2.2-1) ... Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Installing foonerd-rattenu... Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Selecting previously unselected package foonerd-rattenu. Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: (Reading database ... 52900 files and directories currently installed.) Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Preparing to unpack .../foonerd-rattenu_2.0.1-1_arm.deb ... Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Unpacking foonerd-rattenu (2.0.1-1) ... Jan 10 22:36:18 volumiorpi5 volumio[1505]: info: Setting up foonerd-rattenu (2.0.1-1) ... Jan 10 22:36:19 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:19+01:00" level=trace msg="received accesspoint ping" Jan 10 22:36:19 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:19+01:00" level=trace msg="received accesspoint pong ack" Jan 10 22:36:19 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:19+01:00" level=trace msg="sent dealer ping" Jan 10 22:36:19 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:19+01:00" level=trace msg="received dealer pong" Jan 10 22:36:19 volumiorpi5 volumio[1505]: info: Reading package lists... Jan 10 22:36:20 volumiorpi5 volumio[1505]: info: Building dependency tree... Jan 10 22:36:20 volumiorpi5 volumio[1505]: info: Reading state information... Jan 10 22:36:20 volumiorpi5 volumio[1505]: info: 0 upgraded, 0 newly installed, 0 to remove and 14 not upgraded. Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Packages installed successfully Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Installing service files... Jan 10 22:36:21 volumiorpi5 systemd[1]: Reloading. Jan 10 22:36:21 volumiorpi5 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 10 22:36:21 volumiorpi5 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Service installed Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Installing LIRC configuration... Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Original lirc_options.conf backed up Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: lirc_options.conf installed (driver=default for GPIO IR) Jan 10 22:36:21 volumiorpi5 systemd[1]: Starting apt-daily.service - Daily apt download activities... Jan 10 22:36:21 volumiorpi5 systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Jan 10 22:36:21 volumiorpi5 lircd-setup[14097]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Jan 10 22:36:21 volumiorpi5 lircd-setup[14097]: parser = configparser.SafeConfigParser() Jan 10 22:36:21 volumiorpi5 systemd[1]: lircd-setup.service: Deactivated successfully. Jan 10 22:36:21 volumiorpi5 systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Jan 10 22:36:21 volumiorpi5 systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Info: lircd: Opening log, level: Info Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Version: lircd 0.10.1 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: System info: Linux volumiorpi5 6.12.47-v8+ #1904 SMP PREEMPT Mon Sep 15 13:10:52 BST 2025 aarch64 GNU/Linux Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Info: Initial device: /dev/lirc0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: 'lirc' written to protocols file /sys/class/rc/rc2/protocols Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Info: Initial device: /dev/lirc0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Info: [lirc] protocol is enabled Jan 10 22:36:21 volumiorpi5 lircd[14103]: lircd-0.10.1[14103]: Info: lircd: Opening log, level: Info Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: driver: default Jan 10 22:36:21 volumiorpi5 lircd[14103]: lircd-0.10.1[14103]: Notice: Using systemd fd Jan 10 22:36:21 volumiorpi5 lircd[14103]: lircd-0.10.1[14103]: Warning: Running as root Jan 10 22:36:21 volumiorpi5 lircd[14103]: lircd-0.10.1[14103]: Info: Using remote: allo_relay_attenuator. Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: output: /var/run/lirc/lircd Jan 10 22:36:21 volumiorpi5 lircd[14103]: lircd-0.10.1[14103]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: nodaemon: 1 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Jan 10 22:36:21 volumiorpi5 systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: logfile: syslog Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: immediate-init: 0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: permission: 666 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: driver-options: Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: listen: 0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: connect: (null) Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: userelease: 0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: effective_user: (null) Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: release_suffix: _EVUP Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: allow_simulate: 0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: repeat_max: 600 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: configfile: /etc/lirc/lircd.conf Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Options: dynamic_codes: (null) Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Current driver: default Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Driver API version: 3 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Driver version: 0.10.0 Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Info: lircd: Opening log, level: Info Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: Using systemd fd Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Warning: Running as root Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Info: Using remote: allo_relay_attenuator. Jan 10 22:36:21 volumiorpi5 lircd-0.10.1[14103]: Notice: lircd(default) ready, using /var/run/lirc/lircd Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: LIRC configuration installed Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Setting up volume control scripts... Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Volume scripts configured Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Configuring sudoers... Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: /etc/sudoers.d/volumio-user-allo_relay_attenuator: parsed OK Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Sudoers configured Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Configuring I2C... Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: I2C is available Jan 10 22:36:21 volumiorpi5 sudo[13790]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Install script completed Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Adding reference to registry Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Done installing plugin. Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Folder /tmp/plugins removed Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Folder /tmp/downloaded_plugin.zip removed Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Folder /data/temp removed Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: I2C configured Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: ========================================== Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator installation complete Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: ========================================== Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Version: 4.0.2 Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Architecture: arm Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Installed packages: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: - libfn-lgpio0 (GPIO library) Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: - foonerd-rattenu (daemon and client) Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: - liblirc-client0 (IR support) Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Installed binaries: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: - /usr/bin/fn-rattenu (daemon) Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: - /usr/bin/fn-rattenuc (client) Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Service: fn-rattenu.service Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: NOTE: A reboot may be required for I2C changes Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: ========================================== Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: Jan 10 22:36:21 volumiorpi5 volumio[1505]: Plugin install end detected on script Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 10 22:36:21 volumiorpi5 volumio[1505]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 10 22:36:22 volumiorpi5 systemd[1]: apt-daily.service: Deactivated successfully. Jan 10 22:36:22 volumiorpi5 systemd[1]: Finished apt-daily.service - Daily apt download activities. Jan 10 22:36:23 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:23+01:00" level=debug msg="fetched chunk 23/23, size: 203688" uri="spotify:track:499KI8AMbwmtiNfREkP1SB" Jan 10 22:36:26 volumiorpi5 volumio[1505]: info: Enabling plugin allo_relay_attenuator Jan 10 22:36:26 volumiorpi5 volumio[1505]: info: Loading plugin "allo_relay_attenuator"... Jan 10 22:36:26 volumiorpi5 volumio[1505]: info: PLUGIN START: allo_relay_attenuator Jan 10 22:36:26 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Starting plugin Jan 10 22:36:26 volumiorpi5 sudo[14183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp /tmp/fn-rattenu.service /lib/systemd/system/fn-rattenu.service Jan 10 22:36:26 volumiorpi5 sudo[14183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:26 volumiorpi5 sudo[14183]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:26 volumiorpi5 sudo[14186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 10 22:36:26 volumiorpi5 sudo[14186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:26 volumiorpi5 systemd[1]: Reloading. Jan 10 22:36:26 volumiorpi5 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 10 22:36:26 volumiorpi5 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 10 22:36:26 volumiorpi5 sudo[14186]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Service file updated, IR disabled Jan 10 22:36:27 volumiorpi5 sudo[14209]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fn-rattenu.service Jan 10 22:36:27 volumiorpi5 sudo[14209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:27 volumiorpi5 systemd[1]: Started fn-rattenu.service - Allo Relay Attenuator Daemon. Jan 10 22:36:27 volumiorpi5 sudo[14209]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:27 volumiorpi5 fn-rattenu[14211]: Error: Writing to I2C Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Daemon started Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Registering volume override for card 5 Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Setting Device Volume Override Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Applying Volume Override Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Updating Volume Controller Parameters: Device: 5 Name: DX5 II Mixer: DX5 II Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Enabling external Volume Control Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , updateVolumeSettings Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: updateVolumeSettings called Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , retrievevolume Jan 10 22:36:27 volumiorpi5 sudo[14218]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c GET_VOLUME Jan 10 22:36:27 volumiorpi5 sudo[14218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:27 volumiorpi5 sudo[14218]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:27 volumiorpi5 sudo[14224]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c GET_MUTE Jan 10 22:36:27 volumiorpi5 sudo[14224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:27 volumiorpi5 sudo[14224]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: retrievevolume - hardware=31, ui=31, muted=false Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Volume override registered successfully Jan 10 22:36:27 volumiorpi5 volumio[1505]: info: Done. Jan 10 22:36:29 volumiorpi5 sudo[14227]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=31 Jan 10 22:36:29 volumiorpi5 sudo[14227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:36:29 volumiorpi5 fn-rattenu[14211]: Error: Writing to I2C Jan 10 22:36:29 volumiorpi5 sudo[14227]: pam_unix(sudo:session): session closed for user root Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Startup volume set to 31 Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetState Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: CoreStateMachine::pushState Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioPushState Jan 10 22:36:29 volumiorpi5 volumio[1505]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 10 22:36:29 volumiorpi5 volumio[1505]: SPOTIFY: SPOTIFY VOLUME 100 Jan 10 22:36:29 volumiorpi5 volumio[1505]: SPOTIFY: VOLUMIO VOLUME 31 Jan 10 22:36:29 volumiorpi5 volumio[1505]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: Setting Spotify Volume from Volumio: 31 Jan 10 22:36:29 volumiorpi5 volumio[1505]: info: FusionDsp - Volumio is playing Jan 10 22:36:30 volumiorpi5 volumio[1505]: SPOTIFY: SETTING SPOTIFY VOLUME 31 Jan 10 22:36:30 volumiorpi5 volumio[1505]: info: Sending Spotify command with payload to local API: /player/volume Jan 10 22:36:30 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:30+01:00" level=debug msg="update volume requested to 20315/65535" Jan 10 22:36:30 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:30+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 10 22:36:30 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:30+01:00" level=trace msg="emitting websocket event: volume" Jan 10 22:36:30 volumiorpi5 volumio[1505]: SPOTIFY: received: {"type":"volume","data":{"value":31,"max":100}} Jan 10 22:36:30 volumiorpi5 volumio[1505]: SPOTIFY: RECEIVED SPOTIFY VOLUME 31 Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="prefetching next track" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="selected format OGG_VORBIS_320 (c7995db284255998c8b20146996efedfd2ce0817)" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="requested aes key for file c7995db284255998c8b20146996efedfd2ce0817, gid: 0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="fetched first chunk of 22, total size is 11325608 bytes" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=info msg="prefetched track \"Mirrors\" (duration: 350785ms)" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:37 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:37+01:00" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:36:49 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:49+01:00" level=trace msg="sent dealer ping" Jan 10 22:36:49 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:36:49+01:00" level=trace msg="received dealer pong" Jan 10 22:36:53 volumiorpi5 volumio[1505]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 10 22:36:59 volumiorpi5 volumio[1505]: verbose: New Socket.io Connection to 192.168.79.211:3000 from 192.168.79.130 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 14 Jan 10 22:36:59 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 22:36:59 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 22:36:59 volumiorpi5 volumio[1505]: info: Discovery: Getting this device information Jan 10 22:36:59 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetState Jan 10 22:36:59 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=trace msg="emitting websocket event: not_playing" Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:album:405nunSZfNrvDPjkwMvA0U","uri":"spotify:track:499KI8AMbwmtiNfREkP1SB","play_origin":"album"}} Jan 10 22:37:04 volumiorpi5 volumio[1505]: error: Failed to decode event: not_playing Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=trace msg="emitting websocket event: will_play" Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:405nunSZfNrvDPjkwMvA0U","uri":"spotify:track:0WF6Cke3fk1sXGOzNCQlrY","play_origin":"album"}} Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=info msg="loaded track \"Mirrors\" (paused: false, position: 0ms, duration: 350785ms, prefetched: true)" uri="spotify:track:0WF6Cke3fk1sXGOzNCQlrY" Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=trace msg="scheduling prefetch in 321s" Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=trace msg="emitting websocket event: metadata" Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0WF6Cke3fk1sXGOzNCQlrY","name":"Mirrors","artist_names":["Kangurul"],"album_name":"Raspberry","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02aa543b425e9268f28480b224","position":0,"duration":350785,"release_date":"year:2021 month:11 day:24","track_number":3,"disc_number":1}} Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 22:37:04 volumiorpi5 go-librespot[1834]: time="2026-01-10T22:37:04+01:00" level=trace msg="emitting websocket event: playing" Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:405nunSZfNrvDPjkwMvA0U","uri":"spotify:track:0WF6Cke3fk1sXGOzNCQlrY","resume":false,"play_origin":"album"}} Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: {"status":"play","service":"spop","title":"Mirrors","artist":"Kangurul","album":"Raspberry","albumart":"https://i.scdn.co/image/ab67616d00001e02aa543b425e9268f28480b224","uri":"spotify:track:0WF6Cke3fk1sXGOzNCQlrY","trackType":"spotify","seek":1000,"duration":350,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreCommandRouter::servicePushState Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreStateMachine::pushState Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioPushState Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: FusionDsp - Volumio is playing Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: {"status":"play","service":"spop","title":"Mirrors","artist":"Kangurul","album":"Raspberry","albumart":"https://i.scdn.co/image/ab67616d00001e02aa543b425e9268f28480b224","uri":"spotify:track:0WF6Cke3fk1sXGOzNCQlrY","trackType":"spotify","seek":1000,"duration":350,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreCommandRouter::servicePushState Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreStateMachine::pushState Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioPushState Jan 10 22:37:04 volumiorpi5 volumio[1505]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Jan 10 22:37:04 volumiorpi5 volumio[1505]: info: FusionDsp - Volumio is playing Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: allo_relay_attenuator , alsavolume Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: alsavolume called with 45 Jan 10 22:37:09 volumiorpi5 sudo[14295]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/fn-rattenuc -c SET_VOLUME=45 Jan 10 22:37:09 volumiorpi5 sudo[14295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 22:37:09 volumiorpi5 fn-rattenu[14211]: Error: Writing to I2C Jan 10 22:37:09 volumiorpi5 sudo[14295]: pam_unix(sudo:session): session closed for user root Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: Allo Relay Attenuator: Hardware volume set to 45 Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioGetState Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: CoreStateMachine::pushState Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:37:09 volumiorpi5 volumio[1505]: info: CoreCommandRouter::volumioPushState Jan 10 22:37:09 volumiorpi5 volumio[1505]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 22:37:09 volumiorpi5 volumio[1505]: TypeError: Cannot read properties of undefined (reading 'vol') Jan 10 22:37:09 volumiorpi5 volumio[1505]: at /data/plugins/music_service/ytcr/dist/index.js:300:35 Jan 10 22:37:09 volumiorpi5 volumio[1505]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) Jan 10 22:37:09 volumiorpi5 volumio[1505]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) Jan 10 22:37:09 volumiorpi5 volumio[1505]: at Promise._successFn (/volumio/app/index.js:137:16) Jan 10 22:37:09 volumiorpi5 volumio[1505]: at nextTickCallback (/data/plugins/system_hardware/allo_relay_attenuator/node_modules/kew/kew.js:47:28) Jan 10 22:37:09 volumiorpi5 volumio[1505]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jan 10 22:37:09 volumiorpi5 volumio[1505]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 22:37:10 volumiorpi5 sudo[14311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-10 22:36' Jan 10 22:37:10 volumiorpi5 sudo[14311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"