-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-05-22 17:28:46 CEST. --
May 22 17:27:04 volumiodramper fake-hwclock[315]: Thu May 22 15:27:04 UTC 2025
May 22 17:27:04 volumiodramper systemd[1]: Mounted RPC Pipe File System.
May 22 17:27:04 volumiodramper systemd[1]: Started Remount Root and Kernel File Systems.
May 22 17:27:04 volumiodramper systemd[1]: Started Restore / save the current clock.
May 22 17:27:04 volumiodramper systemd[1]: Started Load Kernel Modules.
May 22 17:27:04 volumiodramper systemd[1]: Mounting FUSE Control File System...
May 22 17:27:04 volumiodramper systemd[1]: Mounting Kernel Configuration File System...
May 22 17:27:04 volumiodramper systemd[1]: Starting Apply Kernel Variables...
May 22 17:27:04 volumiodramper systemd[1]: Starting Create System Users...
May 22 17:27:04 volumiodramper systemd[1]: Starting Load/Save Random Seed...
May 22 17:27:04 volumiodramper systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
May 22 17:27:04 volumiodramper systemd[1]: Mounted FUSE Control File System.
May 22 17:27:04 volumiodramper systemd[1]: Mounted Kernel Configuration File System.
May 22 17:27:04 volumiodramper systemd[1]: Started Load/Save Random Seed.
May 22 17:27:04 volumiodramper systemd[1]: Started Apply Kernel Variables.
May 22 17:27:04 volumiodramper systemd[1]: dynamicswap.service: Succeeded.
May 22 17:27:04 volumiodramper systemd[1]: Started udev Coldplug all Devices.
May 22 17:27:04 volumiodramper systemd[1]: Started Create System Users.
May 22 17:27:04 volumiodramper systemd[1]: Starting Create Static Device Nodes in /dev...
May 22 17:27:04 volumiodramper systemd[1]: Starting Helper to synchronize boot up for ifupdown...
May 22 17:27:04 volumiodramper systemd[1]: Started Create Static Device Nodes in /dev.
May 22 17:27:04 volumiodramper systemd[1]: Reached target Local File Systems (Pre).
May 22 17:27:04 volumiodramper systemd[1]: Mounting /var/spool/cups...
May 22 17:27:04 volumiodramper systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway.
May 22 17:27:04 volumiodramper systemd[1]: Mounting /tmp...
May 22 17:27:04 volumiodramper systemd[1]: var-log.mount: Directory /var/log to mount over is not empty, mounting anyway.
May 22 17:27:04 volumiodramper systemd[1]: Mounting /var/log...
May 22 17:27:04 volumiodramper systemd[1]: Starting udev Kernel Device Manager...
May 22 17:27:04 volumiodramper systemd[1]: Mounted /var/spool/cups.
May 22 17:27:04 volumiodramper systemd[1]: Mounted /tmp.
May 22 17:27:04 volumiodramper systemd[1]: Mounted /var/log.
May 22 17:27:04 volumiodramper systemd[1]: Starting Flush Journal to Persistent Storage...
May 22 17:27:04 volumiodramper systemd[1]: Mounting /var/spool/cups/tmp...
May 22 17:27:04 volumiodramper systemd[1]: Mounted /var/spool/cups/tmp.
May 22 17:27:04 volumiodramper systemd-udevd[354]: Network interface NamePolicy= disabled on kernel command line, ignoring.
May 22 17:27:04 volumiodramper systemd-journald[323]: Runtime journal (/run/log/journal/812f34afd0ce27b2b3638d4b67eac851) is 7.5M, max 30.0M, 22.5M free.
May 22 17:27:04 volumiodramper systemd[1]: Started Flush Journal to Persistent Storage.
May 22 17:27:04 volumiodramper systemd[1]: Started udev Kernel Device Manager.
May 22 17:27:04 volumiodramper systemd[1]: Starting Show Plymouth Boot Screen...
May 22 17:27:04 volumiodramper systemd[1]: plymouth-start.service: Succeeded.
May 22 17:27:04 volumiodramper systemd[1]: Started Show Plymouth Boot Screen.
May 22 17:27:04 volumiodramper systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.
May 22 17:27:04 volumiodramper systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
May 22 17:27:04 volumiodramper systemd[1]: Reached target Local Encrypted Volumes.
May 22 17:27:04 volumiodramper systemd[1]: Reached target Paths.
May 22 17:27:04 volumiodramper kernel: Registered IR keymap rc-rc6-mce
May 22 17:27:04 volumiodramper kernel: IR RC6 protocol handler initialized
May 22 17:27:04 volumiodramper kernel: rpi-gpiomem fe200000.gpiomem: window base 0xfe200000 size 0x00001000
May 22 17:27:04 volumiodramper kernel: rpi-gpiomem fe200000.gpiomem: initialised 1 regions as /dev/gpiomem
May 22 17:27:04 volumiodramper kernel: mc: Linux media interface: v0.10
May 22 17:27:04 volumiodramper systemd-udevd[392]: Using default interface naming scheme 'v240'.
May 22 17:27:04 volumiodramper kernel: rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@4/rc/rc0
May 22 17:27:04 volumiodramper kernel: rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter
May 22 17:27:04 volumiodramper kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@4/rc/rc0/input0
May 22 17:27:04 volumiodramper systemd-udevd[392]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
May 22 17:27:04 volumiodramper kernel: vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: bcm2835_vc_sm_cma_probe: Videocore shared memory driver
May 22 17:27:04 volumiodramper kernel: [vc_sm_connected_init]: start
May 22 17:27:04 volumiodramper kernel: [vc_sm_connected_init]: installed successfully
May 22 17:27:04 volumiodramper kernel: videodev: Linux video capture interface: v2.00
May 22 17:27:04 volumiodramper kernel: bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: snd_bcm2835: unknown parameter 'enable_compat_alsa' ignored
May 22 17:27:04 volumiodramper kernel: bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: bcm2835_audio bcm2835_audio: card created with 4 channels
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video10
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 decode
May 22 17:27:04 volumiodramper kernel: rpivid feb10000.codec: Device registered as /dev/video19
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video11
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835_audio bcm2835_audio: card created with 4 channels
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video12
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 isp
May 22 17:27:04 volumiodramper kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video18
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx
May 22 17:27:04 volumiodramper kernel: cfg80211: Loading compiled-in X.509 certificates for regulatory database
May 22 17:27:04 volumiodramper systemd-udevd[368]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
May 22 17:27:04 volumiodramper kernel: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf'
May 22 17:27:04 volumiodramper kernel: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328'
May 22 17:27:04 volumiodramper kernel: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
May 22 17:27:04 volumiodramper kernel: Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Device registered as /dev/video31
May 22 17:27:04 volumiodramper kernel: bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register output node 0 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
May 22 17:27:04 volumiodramper kernel: bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
May 22 17:27:05 volumiodramper kernel: pcm512x 1-004d: Failed to reset device: -5
May 22 17:27:05 volumiodramper kernel: Bluetooth: Core ver 2.22
May 22 17:27:05 volumiodramper kernel: NET: Registered PF_BLUETOOTH protocol family
May 22 17:27:05 volumiodramper kernel: Bluetooth: HCI device and connection manager initialized
May 22 17:27:05 volumiodramper kernel: Bluetooth: HCI socket layer initialized
May 22 17:27:05 volumiodramper kernel: Bluetooth: L2CAP socket layer initialized
May 22 17:27:05 volumiodramper kernel: Bluetooth: SCO socket layer initialized
May 22 17:27:05 volumiodramper kernel: pcm512x: probe of 1-004d failed with error -5
May 22 17:27:05 volumiodramper kernel: Bluetooth: HCI UART driver ver 2.3
May 22 17:27:05 volumiodramper kernel: Bluetooth: HCI UART protocol H4 registered
May 22 17:27:05 volumiodramper kernel: brcmfmac: F1 signature read @0x18000000=0x15264345
May 22 17:27:05 volumiodramper kernel: Bluetooth: HCI UART protocol Three-wire (H5) registered
May 22 17:27:05 volumiodramper kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
May 22 17:27:05 volumiodramper kernel: Bluetooth: HCI UART protocol Broadcom registered
May 22 17:27:05 volumiodramper kernel: hci_uart_bcm serial0-0: supply vbat not found, using dummy regulator
May 22 17:27:05 volumiodramper kernel: hci_uart_bcm serial0-0: supply vddio not found, using dummy regulator
May 22 17:27:05 volumiodramper kernel: usbcore: registered new interface driver brcmfmac
May 22 17:27:05 volumiodramper kernel: uart-pl011 fe201000.serial: no DMA platform data
May 22 17:27:05 volumiodramper kernel: alsactl[550]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
May 22 17:27:05 volumiodramper systemd[1]: Found device /dev/disk/by-uuid/8E61-2966.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in /sys/subsystem/net/devices/eth0 being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Starting Show Plymouth Boot Screen...
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Huge Pages File System being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
May 22 17:27:05 volumiodramper systemd[1]: Starting File System Check on /dev/disk/by-uuid/8E61-2966...
May 22 17:27:05 volumiodramper kernel: brcmfmac: brcmf_c_process_txcap_blob: no txcap_blob available (err=-2)
May 22 17:27:05 volumiodramper kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov  1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
May 22 17:27:05 volumiodramper systemd-udevd[365]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
May 22 17:27:05 volumiodramper systemd-udevd[365]: Using default interface naming scheme 'v240'.
May 22 17:27:05 volumiodramper systemd-udevd[365]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
May 22 17:27:05 volumiodramper systemd[1]: Started File System Check Daemon to report status.
May 22 17:27:05 volumiodramper systemd[1]: Created slice system-bthelper.slice.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Huge Pages File System being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Starting Load/Save RF Kill Switch Status...
May 22 17:27:05 volumiodramper kernel: Bluetooth: hci0: BCM: chip id 107
May 22 17:27:05 volumiodramper kernel: Bluetooth: hci0: BCM: features 0x2f
May 22 17:27:05 volumiodramper kernel: Bluetooth: hci0: BCM4345C0
May 22 17:27:05 volumiodramper kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0000
May 22 17:27:05 volumiodramper systemd[1]: plymouth-start.service: Succeeded.
May 22 17:27:05 volumiodramper systemd[1]: Started Show Plymouth Boot Screen.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
May 22 17:27:05 volumiodramper kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.hcd' Patch
May 22 17:27:05 volumiodramper systemd[1]: Started Load/Save RF Kill Switch Status.
May 22 17:27:05 volumiodramper systemd[1]: Found device /sys/subsystem/net/devices/wlan0.
May 22 17:27:05 volumiodramper systemd-fsck[560]: fsck.fat 4.1 (2017-01-24)
May 22 17:27:05 volumiodramper systemd-fsck[560]: /dev/mmcblk0p1: 405 files, 166320/184582 clusters
May 22 17:27:05 volumiodramper systemd[1]: Started File System Check on /dev/disk/by-uuid/8E61-2966.
May 22 17:27:05 volumiodramper systemd[1]: Mounting /boot...
May 22 17:27:05 volumiodramper systemd[1]: Mounted /boot.
May 22 17:27:05 volumiodramper systemd[1]: Reached target Local File Systems.
May 22 17:27:05 volumiodramper systemd[1]: Starting Tell Plymouth To Write Out Runtime Data...
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Starting Create Volatile Files and Directories...
May 22 17:27:05 volumiodramper systemd[1]: Starting Preprocess NFS configuration...
May 22 17:27:05 volumiodramper systemd[1]: Started ifup for wlan0.
May 22 17:27:05 volumiodramper systemd[1]: Started ifup for eth0.
May 22 17:27:05 volumiodramper systemd[1]: plymouth-read-write.service: Succeeded.
May 22 17:27:05 volumiodramper systemd[1]: Started Tell Plymouth To Write Out Runtime Data.
May 22 17:27:05 volumiodramper systemd[1]: Received SIGRTMIN+20 from PID 213 (plymouthd).
May 22 17:27:05 volumiodramper systemd[1]: nfs-config.service: Succeeded.
May 22 17:27:05 volumiodramper systemd[1]: Started Preprocess NFS configuration.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Reached target NFS client services.
May 22 17:27:05 volumiodramper systemd[1]: Started Create Volatile Files and Directories.
May 22 17:27:05 volumiodramper kernel: warning: `iwconfig' uses wireless extensions which will stop working for Wi-Fi 7 hardware; use nl80211
May 22 17:27:05 volumiodramper systemd[1]: Starting RPC bind portmap service...
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Network Time Synchronization being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Starting Update UTMP about System Boot/Shutdown...
May 22 17:27:05 volumiodramper systemd[1]: Started Entropy daemon using the HAVEGE algorithm.
May 22 17:27:05 volumiodramper systemd[1]: Started Update UTMP about System Boot/Shutdown.
May 22 17:27:05 volumiodramper systemd[1]: Reached target System Initialization.
May 22 17:27:05 volumiodramper systemd[1]: Listening on triggerhappy.socket.
May 22 17:27:05 volumiodramper systemd[1]: Started Daily Cleanup of Temporary Directories.
May 22 17:27:05 volumiodramper systemd[1]: Listening on lircd.socket.
May 22 17:27:05 volumiodramper systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
May 22 17:27:05 volumiodramper systemd[1]: Listening on D-Bus System Message Bus Socket.
May 22 17:27:05 volumiodramper systemd[1]: Reached target Sockets.
May 22 17:27:05 volumiodramper systemd[1]: Reached target Basic System.
May 22 17:27:05 volumiodramper systemd[1]: Started Volumio Log Rotation Service.
May 22 17:27:05 volumiodramper systemd[1]: Started MPD Monitor Service.
May 22 17:27:05 volumiodramper systemd[1]: Starting Configure Bluetooth Modems connected by UART...
May 22 17:27:05 volumiodramper systemd[1]: Starting Volumio Time Update Utility...
May 22 17:27:05 volumiodramper systemd[1]: Started Manage Sound Card State (restore and store).
May 22 17:27:05 volumiodramper kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
May 22 17:27:05 volumiodramper alsactl[627]: alsactl 1.1.8 daemon started
May 22 17:27:05 volumiodramper systemd[1]: Starting triggerhappy global hotkey daemon...
May 22 17:27:05 volumiodramper kernel: bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
May 22 17:27:05 volumiodramper kernel: bcmgenet fd580000.ethernet eth0: Link is Down
May 22 17:27:05 volumiodramper systemd[1]: Started volumio-remote-updater.service.
May 22 17:27:05 volumiodramper systemd[1]: Starting Save/Restore Sound Card State...
May 22 17:27:05 volumiodramper systemd[1]: Started UPnP Renderer front-end to MPD.
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
May 22 17:27:05 volumiodramper systemd[1]: Starting Wireless Services...
May 22 17:27:05 volumiodramper mpd_monitor.sh[623]: MPD Monitor Service: Starting MPD Monitor Service
May 22 17:27:05 volumiodramper systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
May 22 17:27:05 volumiodramper volumio-time-update[626]: volumio-time-update-util: Fetching time from Volumio...
May 22 17:27:05 volumiodramper systemd[1]: Started Volumio Iptables Module.
May 22 17:27:05 volumiodramper systemd[1]: Starting dhcpcd on all interfaces...
May 22 17:27:05 volumiodramper systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
May 22 17:27:05 volumiodramper systemd[1]: Starting Login Service...
May 22 17:27:05 volumiodramper systemd[1]: Started D-Bus System Message Bus.
May 22 17:27:05 volumiodramper systemd[1]: Starting WPA supplicant...
May 22 17:27:05 volumiodramper systemd[1]: Started Daily apt download activities.
May 22 17:27:05 volumiodramper systemd[1]: Started Daily apt upgrade and clean activities.
May 22 17:27:05 volumiodramper systemd[1]: Reached target Timers.
May 22 17:27:05 volumiodramper systemd[1]: Starting Volumio SSH enabler...
May 22 17:27:05 volumiodramper thd[629]: Unable to parse trigger line:
May 22 17:27:05 volumiodramper thd[629]: Unable to parse trigger line: KEY_MIN_INTERESTING 1 /usr/local/bin/volumio volume toggle
May 22 17:27:05 volumiodramper thd[629]: Unable to parse trigger line:
May 22 17:27:05 volumiodramper thd[629]: Unable to parse trigger line:
May 22 17:27:05 volumiodramper thd[629]: Found socket passed from systemd
May 22 17:27:06 volumiodramper systemd[1]: Started triggerhappy global hotkey daemon.
May 22 17:27:06 volumiodramper systemd[1]: Started Save/Restore Sound Card State.
May 22 17:27:06 volumiodramper volumiossh[660]: SSH file found, enabling SSH
May 22 17:27:06 volumiodramper systemd[1]: Reached target Sound Card.
May 22 17:27:06 volumiodramper volumiossh[661]: Synchronizing state of ssh.service with SysV service script with /lib/systemd/systemd-sysv-install.
May 22 17:27:06 volumiodramper volumiossh[661]: Executing: /lib/systemd/systemd-sysv-install enable ssh
May 22 17:27:06 volumiodramper systemd-logind[646]: Watching system buttons on /dev/input/event0 (gpio_ir_recv)
May 22 17:27:06 volumiodramper systemd-logind[646]: New seat seat0.
May 22 17:27:06 volumiodramper mpd_monitor.sh[623]: MPD error: Connection refused
May 22 17:27:06 volumiodramper mpd_monitor.sh[623]: MPD Monitor Service: MPD Appears to be inactive, restarting
May 22 17:27:06 volumiodramper kernel: Bluetooth: hci0: BCM: features 0x2f
May 22 17:27:06 volumiodramper kernel: Bluetooth: hci0: BCM43455 37.4MHz Raspberry Pi 3+
May 22 17:27:06 volumiodramper kernel: Bluetooth: hci0: BCM4345C0 (003.001.025) build 0342
May 22 17:27:06 volumiodramper avahi-daemon[644]: Found user 'avahi' (UID 110) and group 'avahi' (GID 113).
May 22 17:27:06 volumiodramper avahi-daemon[644]: Successfully dropped root privileges.
May 22 17:27:06 volumiodramper avahi-daemon[644]: avahi-daemon 0.7 starting up.
May 22 17:27:06 volumiodramper mpd_monitor.sh[623]: mpd: no process found
May 22 17:27:06 volumiodramper dhcpcd[643]: dev: loaded udev
May 22 17:27:06 volumiodramper dhcpcd[643]: forked to background, child pid 711
May 22 17:27:06 volumiodramper kernel: 8021q: 802.1Q VLAN Support v1.8
May 22 17:27:06 volumiodramper volumio-remote-updater[632]: Error: No active session
May 22 17:27:06 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:06] [info] asio async_connect error: system:111 (Connection refused)
May 22 17:27:06 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:06] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected)
May 22 17:27:06 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:06] [error] handle_connect error: Underlying Transport Error
May 22 17:27:06 volumiodramper volumio[635]: Could not open config: /tmp/upmpdcli.conf
May 22 17:27:06 volumiodramper avahi-daemon[644]: Successfully called chroot().
May 22 17:27:06 volumiodramper avahi-daemon[644]: Successfully dropped remaining capabilities.
May 22 17:27:06 volumiodramper dbus-daemon[647]: [system] Successfully activated service 'org.freedesktop.systemd1'
May 22 17:27:06 volumiodramper wpa_supplicant[650]: Successfully initialized wpa_supplicant
May 22 17:27:06 volumiodramper systemd[1]: Started WPA supplicant.
May 22 17:27:06 volumiodramper systemd[1]: Started Avahi mDNS/DNS-SD Stack.
May 22 17:27:06 volumiodramper systemd[1]: Started Login Service.
May 22 17:27:06 volumiodramper systemd[1]: Started RPC bind portmap service.
May 22 17:27:06 volumiodramper avahi-daemon[644]: Loading service file /services/volumio.service.
May 22 17:27:06 volumiodramper systemd[1]: Started Helper to synchronize boot up for ifupdown.
May 22 17:27:06 volumiodramper avahi-daemon[644]: Network interface enumeration completed.
May 22 17:27:06 volumiodramper systemd[1]: hciuart.service: Succeeded.
May 22 17:27:06 volumiodramper avahi-daemon[644]: Server startup complete. Host name is volumiodramper.local. Local service cookie is 3801773682.
May 22 17:27:06 volumiodramper systemd[1]: Started Configure Bluetooth Modems connected by UART.
May 22 17:27:06 volumiodramper avahi-daemon[644]: Service "Volumio_DR_AMPER" (/services/volumio.service) successfully established.
May 22 17:27:06 volumiodramper systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
May 22 17:27:06 volumiodramper systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
May 22 17:27:06 volumiodramper systemd[1]: Started dhcpcd on all interfaces.
May 22 17:27:06 volumiodramper sh[583]: eth0=eth0
May 22 17:27:06 volumiodramper volumio-time-update[626]: volumio-time-update-util: Date not found in response
May 22 17:27:06 volumiodramper volumio-time-update[626]: volumio-time-update-util: Retrying in 5 seconds...
May 22 17:27:06 volumiodramper sh[582]: wlan0=wlan0
May 22 17:27:06 volumiodramper dhcpcd-run-hooks[748]: wlan0: starting wpa_supplicant
May 22 17:27:07 volumiodramper systemd[1]: Listening on mpd.socket.
May 22 17:27:07 volumiodramper systemd[1]: Starting Raspberry Pi bluetooth helper...
May 22 17:27:07 volumiodramper systemd[1]: Starting Raise network interfaces...
May 22 17:27:07 volumiodramper systemd[1]: Reached target Remote File Systems (Pre).
May 22 17:27:07 volumiodramper systemd[1]: Reached target Remote File Systems.
May 22 17:27:07 volumiodramper systemd[1]: Starting LSB: Load kernel modules needed to enable cpufreq scaling...
May 22 17:27:07 volumiodramper systemd[1]: Reached target RPC Port Mapper.
May 22 17:27:07 volumiodramper systemd[1]: iptables.service: Succeeded.
May 22 17:27:07 volumiodramper bthelper[751]: Raspberry Pi BDADDR already set
May 22 17:27:07 volumiodramper systemd[1]: Started Raspberry Pi bluetooth helper.
May 22 17:27:07 volumiodramper systemd[1]: Starting Bluetooth service...
May 22 17:27:07 volumiodramper systemd[1]: Reloading.
May 22 17:27:07 volumiodramper haveged[621]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K
May 22 17:27:07 volumiodramper haveged[621]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488
May 22 17:27:07 volumiodramper haveged[621]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B):  last entropy estimate 8.00043
May 22 17:27:07 volumiodramper haveged[621]: haveged: fills: 0, generated: 0
May 22 17:27:07 volumiodramper dhcpcd[711]: wlan0: connected to Access Point `'
May 22 17:27:07 volumiodramper loadcpufreq[756]: Loading cpufreq kernel modules...done (none).
May 22 17:27:07 volumiodramper dhcpcd[711]: eth0: waiting for carrier
May 22 17:27:07 volumiodramper dhcpcd[711]: wlan0: waiting for carrier
May 22 17:27:07 volumiodramper bluetoothd[798]: Bluetooth daemon 5.50
May 22 17:27:07 volumiodramper bluetoothd[798]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf
May 22 17:27:07 volumiodramper bluetoothd[798]: Starting SDP server
May 22 17:27:07 volumiodramper bluetoothd[798]: Excluding (cli) sap
May 22 17:27:07 volumiodramper bluetoothd[798]: Bluetooth management interface 1.22 initialized
May 22 17:27:07 volumiodramper dbus-daemon[647]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.4' (uid=0 pid=798 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ")
May 22 17:27:07 volumiodramper kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
May 22 17:27:07 volumiodramper kernel: Bluetooth: BNEP filters: protocol multicast
May 22 17:27:07 volumiodramper kernel: Bluetooth: BNEP socket layer initialized
May 22 17:27:07 volumiodramper kernel: Bluetooth: MGMT ver 1.22
May 22 17:27:07 volumiodramper systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
May 22 17:27:07 volumiodramper bluetoothd[798]: Failed to set privacy: Rejected (0x0b)
May 22 17:27:07 volumiodramper systemd[1]: volumiossh.service: Current command vanished from the unit file, execution of the command list won't be resumed.
May 22 17:27:07 volumiodramper systemd[1]: Started LSB: Load kernel modules needed to enable cpufreq scaling.
May 22 17:27:07 volumiodramper systemd[1]: Starting Hostname Service...
May 22 17:27:07 volumiodramper systemd[1]: Starting LSB: set CPUFreq kernel parameters...
May 22 17:27:07 volumiodramper systemd[1]: Started Raise network interfaces.
May 22 17:27:07 volumiodramper systemd[1]: Reached target Network.
May 22 17:27:07 volumiodramper systemd[1]: Starting OpenBSD Secure Shell server...
May 22 17:27:07 volumiodramper wireless.js[636]: Cleaning previous...
May 22 17:27:07 volumiodramper systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
May 22 17:27:07 volumiodramper systemd[1]: Starting Permit User Sessions...
May 22 17:27:07 volumiodramper systemd[1]: Starting Music Player Daemon...
May 22 17:27:07 volumiodramper systemd[1]: Starting Network Time Service...
May 22 17:27:07 volumiodramper systemd[1]: Reached target Network is Online.
May 22 17:27:07 volumiodramper systemd[1]: Starting /etc/rc.local Compatibility...
May 22 17:27:07 volumiodramper systemd[1]: Starting Samba NMB Daemon...
May 22 17:27:07 volumiodramper systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
May 22 17:27:07 volumiodramper systemd[1]: Starting LSB: Brings up/down network automatically...
May 22 17:27:07 volumiodramper systemd[1]: Started /etc/rc.local Compatibility.
May 22 17:27:08 volumiodramper dbus-daemon[647]: [system] Successfully activated service 'org.freedesktop.hostname1'
May 22 17:27:08 volumiodramper systemd[1]: Started Permit User Sessions.
May 22 17:27:08 volumiodramper systemd[1]: Started Hostname Service.
May 22 17:27:08 volumiodramper sshd[910]: Server listening on 0.0.0.0 port 22.
May 22 17:27:08 volumiodramper sshd[910]: Server listening on :: port 22.
May 22 17:27:08 volumiodramper cpufrequtils[885]: CPUFreq Utilities: Setting ondemand CPUFreq governor...CPU0...CPU1...CPU2...CPU3...done.
May 22 17:27:08 volumiodramper ntpd[897]: ntpd 4.2.8p12@1.3728-o (1): Starting
May 22 17:27:08 volumiodramper ntpd[897]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 103:103
May 22 17:27:08 volumiodramper ntpd[923]: proto: precision = 0.797 usec (-20)
May 22 17:27:08 volumiodramper sudo[894]:     root : unable to resolve host volumiodramper
May 22 17:27:08 volumiodramper sudo[894]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:08 volumiodramper sudo[894]:     root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:08 volumiodramper ntpd[923]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature
May 22 17:27:08 volumiodramper ntpd[923]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2024-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37
May 22 17:27:08 volumiodramper ntpd[923]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 146 days ago
May 22 17:27:08 volumiodramper ntpd[923]: Listen and drop on 0 v6wildcard [::]:123
May 22 17:27:08 volumiodramper ntpd[923]: Listen and drop on 1 v4wildcard 0.0.0.0:123
May 22 17:27:08 volumiodramper ntpd[923]: Listen normally on 2 lo 127.0.0.1:123
May 22 17:27:08 volumiodramper ntpd[923]: Listening on routing socket on fd #19 for interface updates
May 22 17:27:08 volumiodramper ntpd[923]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
May 22 17:27:08 volumiodramper ntpd[923]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
May 22 17:27:08 volumiodramper systemd[1]: Started OpenBSD Secure Shell server.
May 22 17:27:08 volumiodramper systemd[1]: Started LSB: set CPUFreq kernel parameters.
May 22 17:27:08 volumiodramper systemd[1]: Started Network Time Service.
May 22 17:27:08 volumiodramper systemd[1]: Reloading.
May 22 17:27:08 volumiodramper sudo[894]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 22 17:27:08 volumiodramper sudo[894]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:08 volumiodramper sudo[894]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
May 22 17:27:08 volumiodramper sudo[894]: pam_unix(sudo:session): session closed for user root
May 22 17:27:08 volumiodramper systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
May 22 17:27:08 volumiodramper nmbd[903]: [2025/05/22 17:27:08.536559,  0] ../source3/nmbd/asyncdns.c:158(start_async_dns)
May 22 17:27:08 volumiodramper nmbd[903]:   started asyncdns process 941
May 22 17:27:08 volumiodramper nmbd[903]: [2025/05/22 17:27:08.538187,  0] ../lib/util/become_daemon.c:149(daemon_status)
May 22 17:27:08 volumiodramper nmbd[903]:   daemon_status: STATUS=daemon 'nmbd' : No local IPv4 non-loopback interfaces available, waiting for interface ...
May 22 17:27:08 volumiodramper nmbd[903]: [2025/05/22 17:27:08.538296,  0] ../source3/nmbd/nmbd_subnetdb.c:254(create_subnets)
May 22 17:27:08 volumiodramper nmbd[903]:   NOTE: NetBIOS name resolution is not supported for Internet Protocol Version 6 (IPv6).
May 22 17:27:08 volumiodramper systemd[1]: Starting Hold until boot process finishes up...
May 22 17:27:08 volumiodramper systemd[1]: Starting Terminate Plymouth Boot Screen...
May 22 17:27:08 volumiodramper systemd[1]: Reloading.
May 22 17:27:08 volumiodramper ifplugd(eth0)[954]: ifplugd 0.28 initializing.
May 22 17:27:08 volumiodramper ifplugd(eth0)[954]: Using interface eth0/2C:CF:67:07:E6:30 with driver  (version: 6.6.62-v7l+)
May 22 17:27:08 volumiodramper ifplugd(eth0)[954]: Using detection mode: SIOCETHTOOL
May 22 17:27:08 volumiodramper ifplugd(eth0)[954]: Initialization complete, link beat not detected.
May 22 17:27:08 volumiodramper ifplugd[901]: Network Interface Plugging Daemon...start eth0...done.
May 22 17:27:09 volumiodramper systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
May 22 17:27:09 volumiodramper ntpd[923]: error resolving pool 0.debian.pool.ntp.org: System error (-11)
May 22 17:27:09 volumiodramper systemd[1]: Started LSB: Brings up/down network automatically.
May 22 17:27:09 volumiodramper systemd[1]: plymouth-quit-wait.service: Succeeded.
May 22 17:27:09 volumiodramper systemd[1]: Started Hold until boot process finishes up.
May 22 17:27:09 volumiodramper systemd[1]: plymouth-quit.service: Succeeded.
May 22 17:27:09 volumiodramper systemd[1]: Started Terminate Plymouth Boot Screen.
May 22 17:27:09 volumiodramper systemd[1]: Received SIGRTMIN+21 from PID 213 (n/a).
May 22 17:27:09 volumiodramper systemd[1]: Received SIGRTMIN+21 from PID 213 (n/a).
May 22 17:27:09 volumiodramper systemd[1]: Started Getty on tty1.
May 22 17:27:09 volumiodramper systemd[1]: Reached target Login Prompts.
May 22 17:27:09 volumiodramper sudo[969]:     root : unable to resolve host volumiodramper
May 22 17:27:09 volumiodramper sudo[969]:     root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:09 volumiodramper systemd[1]: Started Bluetooth service.
May 22 17:27:09 volumiodramper systemd[1]: volumiossh.service: Succeeded.
May 22 17:27:09 volumiodramper systemd[1]: Started Volumio SSH enabler.
May 22 17:27:09 volumiodramper sudo[969]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
May 22 17:27:09 volumiodramper sudo[969]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:09 volumiodramper systemd[1]: Reached target Bluetooth.
May 22 17:27:09 volumiodramper sudo[969]: pam_unix(sudo:session): session closed for user root
May 22 17:27:09 volumiodramper sudo[972]:     root : unable to resolve host volumiodramper
May 22 17:27:09 volumiodramper sudo[972]:     root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:09 volumiodramper sudo[972]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down
May 22 17:27:09 volumiodramper sudo[972]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:10 volumiodramper sudo[972]: pam_unix(sudo:session): session closed for user root
May 22 17:27:10 volumiodramper wireless.js[636]: Stopped aP
May 22 17:27:10 volumiodramper sudo[979]:  volumio : unable to resolve host volumiodramper
May 22 17:27:10 volumiodramper sudo[979]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:10 volumiodramper sudo[979]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
May 22 17:27:10 volumiodramper sudo[979]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:10 volumiodramper ntpd[923]: error resolving pool 1.debian.pool.ntp.org: System error (-11)
May 22 17:27:10 volumiodramper sudo[979]: pam_unix(sudo:session): session closed for user root
May 22 17:27:10 volumiodramper kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
May 22 17:27:10 volumiodramper kernel: brcmfmac: brcmf_dump_obss: dump_obss error (-110)
May 22 17:27:10 volumiodramper kernel: ieee80211 phy0: brcmf_set_mpc: fail to set mpc
May 22 17:27:10 volumiodramper kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
May 22 17:27:10 volumiodramper sudo[981]:  volumio : unable to resolve host volumiodramper
May 22 17:27:10 volumiodramper sudo[981]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:10 volumiodramper sudo[981]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get
May 22 17:27:10 volumiodramper sudo[981]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:10 volumiodramper sudo[981]: pam_unix(sudo:session): session closed for user root
May 22 17:27:10 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:10 volumiodramper sudo[988]:  volumio : unable to resolve host volumiodramper
May 22 17:27:10 volumiodramper sudo[988]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:10 volumiodramper sudo[988]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
May 22 17:27:10 volumiodramper sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:10 volumiodramper sudo[988]: pam_unix(sudo:session): session closed for user root
May 22 17:27:10 volumiodramper sudo[990]:  volumio : unable to resolve host volumiodramper
May 22 17:27:10 volumiodramper sudo[990]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:10 volumiodramper sudo[990]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan
May 22 17:27:10 volumiodramper sudo[990]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:10 volumiodramper mpd[942]: May 22 17:27 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 22 17:27:10 volumiodramper systemd[1]: Started Music Player Daemon.
May 22 17:27:10 volumiodramper mpd_monitor.sh[623]: MPD Monitor Service: MPD restarted due to no mpc output.
May 22 17:27:10 volumiodramper systemd[1]: systemd-rfkill.service: Succeeded.
May 22 17:27:11 volumiodramper ntpd[923]: error resolving pool 2.debian.pool.ntp.org: System error (-11)
May 22 17:27:11 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:11] [info] asio async_connect error: system:111 (Connection refused)
May 22 17:27:11 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected)
May 22 17:27:11 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:11] [error] handle_connect error: Underlying Transport Error
May 22 17:27:11 volumiodramper volumio-time-update[626]: volumio-time-update-util: Fetching time from Volumio...
May 22 17:27:11 volumiodramper volumio-time-update[626]: volumio-time-update-util: Date not found in response
May 22 17:27:11 volumiodramper volumio-time-update[626]: volumio-time-update-util: Retrying in 5 seconds...
May 22 17:27:12 volumiodramper bthelper[751]: Changing power off succeeded
May 22 17:27:12 volumiodramper ntpd[923]: error resolving pool 3.debian.pool.ntp.org: System error (-11)
May 22 17:27:12 volumiodramper bthelper[751]: [CHG] Controller 2C:CF:67:07:E6:32 Class: 0x0000041c
May 22 17:27:12 volumiodramper bthelper[751]: Changing power on succeeded
May 22 17:27:12 volumiodramper sudo[990]: pam_unix(sudo:session): session closed for user root
May 22 17:27:12 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:12 volumiodramper wireless.js[636]: SETTING APPROPRIATE REG DOMAIN: PL
May 22 17:27:12 volumiodramper sudo[1011]:  volumio : unable to resolve host volumiodramper
May 22 17:27:12 volumiodramper sudo[1011]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:12 volumiodramper sudo[1011]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
May 22 17:27:12 volumiodramper sudo[1011]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:12 volumiodramper sudo[1011]: pam_unix(sudo:session): session closed for user root
May 22 17:27:12 volumiodramper sudo[1013]:  volumio : unable to resolve host volumiodramper
May 22 17:27:12 volumiodramper sudo[1013]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:12 volumiodramper sudo[1013]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set PL
May 22 17:27:12 volumiodramper sudo[1013]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:12 volumiodramper sudo[1013]: pam_unix(sudo:session): session closed for user root
May 22 17:27:12 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:12 volumiodramper wireless.js[636]: SUCCESSFULLY SET NEW REGDOMAIN: PL
May 22 17:27:12 volumiodramper wireless.js[636]: Start wireless flow
May 22 17:27:12 volumiodramper wireless.js[636]: Stopped hotspot (if there)..
May 22 17:27:12 volumiodramper sudo[1018]:     root : unable to resolve host volumiodramper
May 22 17:27:12 volumiodramper sudo[1018]:     root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:12 volumiodramper sudo[1018]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
May 22 17:27:12 volumiodramper sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:12 volumiodramper sudo[1018]: pam_unix(sudo:session): session closed for user root
May 22 17:27:12 volumiodramper sudo[1020]:     root : unable to resolve host volumiodramper
May 22 17:27:12 volumiodramper sudo[1020]:     root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:12 volumiodramper sudo[1020]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down
May 22 17:27:12 volumiodramper sudo[1020]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:13 volumiodramper sudo[1020]: pam_unix(sudo:session): session closed for user root
May 22 17:27:13 volumiodramper wireless.js[636]: DHCP IP
May 22 17:27:13 volumiodramper wireless.js[636]: Start ap
May 22 17:27:13 volumiodramper wpa_supplicant[1022]: Successfully initialized wpa_supplicant
May 22 17:27:13 volumiodramper sudo[1023]:     root : unable to resolve host volumiodramper
May 22 17:27:13 volumiodramper sudo[1023]:     root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:13 volumiodramper sudo[1023]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd
May 22 17:27:13 volumiodramper sudo[1023]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:13 volumiodramper kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
May 22 17:27:13 volumiodramper dhcpcd[1024]: sending commands to master dhcpcd process
May 22 17:27:13 volumiodramper dhcpcd[711]: control command: /sbin/dhcpcd
May 22 17:27:13 volumiodramper sudo[1023]: pam_unix(sudo:session): session closed for user root
May 22 17:27:13 volumiodramper dhcpcd[711]: lo: carrier acquired
May 22 17:27:13 volumiodramper dhcpcd[711]: DUID 00:01:00:01:2f:7d:86:a4:2c:cf:67:07:e6:30
May 22 17:27:13 volumiodramper dhcpcd[711]: lo: IAID 6c:6f:00:00
May 22 17:27:13 volumiodramper dhcpcd[711]: lo: ipv6_start: Operation not supported
May 22 17:27:13 volumiodramper dhcpcd[711]: lo: using static address 127.0.0.1/8
May 22 17:27:13 volumiodramper dhcpcd[711]: lo: adding route to 127.0.0.0/8
May 22 17:27:13 volumiodramper dhcpcd[711]: arp_announce: Invalid argument
May 22 17:27:14 volumiodramper wireless.js[636]: trying...
May 22 17:27:14 volumiodramper sudo[1054]:  volumio : unable to resolve host volumiodramper
May 22 17:27:14 volumiodramper sudo[1054]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:14 volumiodramper sudo[1054]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:14 volumiodramper sudo[1054]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:14 volumiodramper sudo[1054]: pam_unix(sudo:session): session closed for user root
May 22 17:27:14 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:15 volumiodramper wireless.js[636]: trying...
May 22 17:27:15 volumiodramper sudo[1057]:  volumio : unable to resolve host volumiodramper
May 22 17:27:15 volumiodramper sudo[1057]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:15 volumiodramper sudo[1057]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:15 volumiodramper sudo[1057]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:15 volumiodramper sudo[1057]: pam_unix(sudo:session): session closed for user root
May 22 17:27:15 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:16 volumiodramper wireless.js[636]: trying...
May 22 17:27:16 volumiodramper sudo[1060]:  volumio : unable to resolve host volumiodramper
May 22 17:27:16 volumiodramper sudo[1060]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:16 volumiodramper sudo[1060]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:16 volumiodramper sudo[1060]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:16 volumiodramper sudo[1060]: pam_unix(sudo:session): session closed for user root
May 22 17:27:16 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:16 volumiodramper volumio-time-update[626]: volumio-time-update-util: Fetching time from Volumio...
May 22 17:27:16 volumiodramper volumio-time-update[626]: volumio-time-update-util: Date not found in response
May 22 17:27:16 volumiodramper volumio-time-update[626]: volumio-time-update-util: Retrying in 5 seconds...
May 22 17:27:17 volumiodramper wireless.js[636]: trying...
May 22 17:27:17 volumiodramper sudo[1068]:  volumio : unable to resolve host volumiodramper
May 22 17:27:17 volumiodramper sudo[1068]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:17 volumiodramper sudo[1068]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:17 volumiodramper sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:17 volumiodramper sudo[1068]: pam_unix(sudo:session): session closed for user root
May 22 17:27:17 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:18 volumiodramper wireless.js[636]: trying...
May 22 17:27:18 volumiodramper sudo[1071]:  volumio : unable to resolve host volumiodramper
May 22 17:27:18 volumiodramper sudo[1071]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:18 volumiodramper sudo[1071]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:18 volumiodramper sudo[1071]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:18 volumiodramper sudo[1071]: pam_unix(sudo:session): session closed for user root
May 22 17:27:18 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:19 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:19] [info] asio async_connect error: system:111 (Connection refused)
May 22 17:27:19 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:19] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected)
May 22 17:27:19 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:19] [error] handle_connect error: Underlying Transport Error
May 22 17:27:19 volumiodramper wireless.js[636]: trying...
May 22 17:27:19 volumiodramper sudo[1074]:  volumio : unable to resolve host volumiodramper
May 22 17:27:19 volumiodramper sudo[1074]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:19 volumiodramper sudo[1074]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:19 volumiodramper sudo[1074]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:19 volumiodramper sudo[1074]: pam_unix(sudo:session): session closed for user root
May 22 17:27:19 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:19 volumiodramper wpa_supplicant[1040]: wlan0: Trying to associate with SSID 'Orange_Swiatlowod_B980'
May 22 17:27:20 volumiodramper wireless.js[636]: trying...
May 22 17:27:20 volumiodramper sudo[1077]:  volumio : unable to resolve host volumiodramper
May 22 17:27:20 volumiodramper sudo[1077]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:20 volumiodramper sudo[1077]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:20 volumiodramper sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:20 volumiodramper sudo[1077]: pam_unix(sudo:session): session closed for user root
May 22 17:27:20 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:20 volumiodramper wpa_supplicant[1040]: wlan0: Associated with c0:3c:04:4a:b9:80
May 22 17:27:20 volumiodramper wpa_supplicant[1040]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:3c:04:4a:b9:80 completed [id=0 id_str=]
May 22 17:27:20 volumiodramper dhcpcd[711]: wlan0: carrier acquired
May 22 17:27:20 volumiodramper wpa_supplicant[1040]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
May 22 17:27:20 volumiodramper dhcpcd[711]: wlan0: connected to Access Point `Orange_Swiatlowod_B980'
May 22 17:27:20 volumiodramper wpa_supplicant[1040]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=PL
May 22 17:27:20 volumiodramper dhcpcd[711]: wlan0: IAID 67:07:e6:31
May 22 17:27:20 volumiodramper dhcpcd[711]: wlan0: adding address fe80::2ecf:67ff:fe07:e631
May 22 17:27:20 volumiodramper dhcpcd[711]: ipv6_addaddr1: Permission denied
May 22 17:27:20 volumiodramper dhcpcd[711]: wlan0: probing address 192.168.1.123/24
May 22 17:27:21 volumiodramper dhcpcd[711]: wlan0: soliciting an IPv6 router
May 22 17:27:21 volumiodramper wireless.js[636]: trying...
May 22 17:27:21 volumiodramper sudo[1082]:  volumio : unable to resolve host volumiodramper
May 22 17:27:21 volumiodramper sudo[1082]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:21 volumiodramper sudo[1082]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:21 volumiodramper sudo[1082]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:21 volumiodramper sudo[1082]: pam_unix(sudo:session): session closed for user root
May 22 17:27:21 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:21 volumiodramper volumio-time-update[626]: volumio-time-update-util: Fetching time from Volumio...
May 22 17:27:21 volumiodramper volumio-time-update[626]: volumio-time-update-util: Date not found in response
May 22 17:27:21 volumiodramper volumio-time-update[626]: volumio-time-update-util: Retrying in 5 seconds...
May 22 17:27:22 volumiodramper wireless.js[636]: trying...
May 22 17:27:22 volumiodramper sudo[1090]:  volumio : unable to resolve host volumiodramper
May 22 17:27:22 volumiodramper sudo[1090]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:22 volumiodramper sudo[1090]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:22 volumiodramper sudo[1090]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:22 volumiodramper sudo[1090]: pam_unix(sudo:session): session closed for user root
May 22 17:27:22 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:22 volumiodramper dhcpcd[711]: wlan0: carrier lost
May 22 17:27:22 volumiodramper wpa_supplicant[1040]: wlan0: Associated with c0:3c:04:4a:b9:85
May 22 17:27:22 volumiodramper wpa_supplicant[1040]: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:3c:04:4a:b9:85 completed [id=0 id_str=]
May 22 17:27:22 volumiodramper wpa_supplicant[1040]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
May 22 17:27:22 volumiodramper dhcpcd[711]: wlan0: carrier acquired
May 22 17:27:22 volumiodramper dhcpcd[711]: wlan0: IAID 67:07:e6:31
May 22 17:27:22 volumiodramper dhcpcd[711]: wlan0: probing address 192.168.1.123/24
May 22 17:27:23 volumiodramper dhcpcd[711]: wlan0: soliciting an IPv6 router
May 22 17:27:23 volumiodramper wireless.js[636]: trying...
May 22 17:27:23 volumiodramper sudo[1113]:  volumio : unable to resolve host volumiodramper
May 22 17:27:23 volumiodramper sudo[1113]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:23 volumiodramper sudo[1113]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:23 volumiodramper sudo[1113]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:23 volumiodramper sudo[1113]: pam_unix(sudo:session): session closed for user root
May 22 17:27:23 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:24 volumiodramper wireless.js[636]: trying...
May 22 17:27:24 volumiodramper sudo[1116]:  volumio : unable to resolve host volumiodramper
May 22 17:27:24 volumiodramper sudo[1116]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:24 volumiodramper sudo[1116]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:24 volumiodramper sudo[1116]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:24 volumiodramper sudo[1116]: pam_unix(sudo:session): session closed for user root
May 22 17:27:24 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:25 volumiodramper wireless.js[636]: trying...
May 22 17:27:25 volumiodramper sudo[1119]:  volumio : unable to resolve host volumiodramper
May 22 17:27:25 volumiodramper sudo[1119]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:25 volumiodramper sudo[1119]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:25 volumiodramper sudo[1119]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:25 volumiodramper sudo[1119]: pam_unix(sudo:session): session closed for user root
May 22 17:27:25 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:26 volumiodramper wireless.js[636]: trying...
May 22 17:27:26 volumiodramper sudo[1122]:  volumio : unable to resolve host volumiodramper
May 22 17:27:26 volumiodramper sudo[1122]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:26 volumiodramper sudo[1122]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:26 volumiodramper sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:26 volumiodramper sudo[1122]: pam_unix(sudo:session): session closed for user root
May 22 17:27:26 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:26 volumiodramper volumio-time-update[626]: volumio-time-update-util: Fetching time from Volumio...
May 22 17:27:26 volumiodramper volumio-time-update[626]: volumio-time-update-util: Date not found in response
May 22 17:27:26 volumiodramper volumio-time-update[626]: volumio-time-update-util: Retrying in 5 seconds...
May 22 17:27:27 volumiodramper wireless.js[636]: trying...
May 22 17:27:27 volumiodramper sudo[1130]:  volumio : unable to resolve host volumiodramper
May 22 17:27:27 volumiodramper sudo[1130]:  volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
May 22 17:27:27 volumiodramper sudo[1130]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:27 volumiodramper sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:27 volumiodramper sudo[1130]: pam_unix(sudo:session): session closed for user root
May 22 17:27:27 volumiodramper wireless.js[636]: sudo: unable to resolve host volumiodramper: System error
May 22 17:27:27 volumiodramper dhcpcd[711]: wlan0: using static address 192.168.1.123/24
May 22 17:27:27 volumiodramper avahi-daemon[644]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.123.
May 22 17:27:27 volumiodramper avahi-daemon[644]: New relevant interface wlan0.IPv4 for mDNS.
May 22 17:27:27 volumiodramper avahi-daemon[644]: Registering new address record for 192.168.1.123 on wlan0.IPv4.
May 22 17:27:27 volumiodramper dhcpcd[711]: wlan0: adding route to 192.168.1.0/24
May 22 17:27:27 volumiodramper dhcpcd[711]: wlan0: adding default route via 192.168.1.1
May 22 17:27:28 volumiodramper wireless.js[636]: trying...
May 22 17:27:28 volumiodramper sudo[1154]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
May 22 17:27:28 volumiodramper sudo[1154]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:28 volumiodramper sudo[1154]: pam_unix(sudo:session): session closed for user root
May 22 17:27:28 volumiodramper wireless.js[636]: Connected to: ----Orange_Swiatlowod_B980
May 22 17:27:28 volumiodramper wireless.js[636]: ----
May 22 17:27:28 volumiodramper sudo[1157]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 22 17:27:28 volumiodramper sudo[1157]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:28 volumiodramper sudo[1157]: pam_unix(sudo:session): session closed for user root
May 22 17:27:28 volumiodramper wireless.js[636]: ... joined AP, wlan0 IPv4 is 192.168.1.123, ipV6 is undefined
May 22 17:27:28 volumiodramper wireless.js[636]: It's done! AP
May 22 17:27:28 volumiodramper nmbd[903]: [2025/05/22 17:27:28.543703,  0] ../lib/util/become_daemon.c:138(daemon_ready)
May 22 17:27:28 volumiodramper nmbd[903]:   daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections
May 22 17:27:28 volumiodramper systemd[1]: Started Samba NMB Daemon.
May 22 17:27:28 volumiodramper systemd[1]: Starting Samba Winbind Daemon...
May 22 17:27:28 volumiodramper systemd[1]: Started Wireless Services.
May 22 17:27:28 volumiodramper kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
May 22 17:27:28 volumiodramper systemd[1]: Started Volumio Backend Module.
May 22 17:27:28 volumiodramper systemd[1]: Started Volumio Cpu Tweaker.
May 22 17:27:28 volumiodramper volumio-cpu-tweak[1165]: Setting RT Priority for mpd
May 22 17:27:28 volumiodramper volumio-cpu-tweak[1165]: Setting MPD Affinity
May 22 17:27:28 volumiodramper volumio-cpu-tweak[1165]: pid 942's current affinity mask: f
May 22 17:27:28 volumiodramper volumio-cpu-tweak[1165]: pid 942's new affinity mask: 3
May 22 17:27:28 volumiodramper volumio-cpu-tweak[1165]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input
May 22 17:27:28 volumiodramper volumio-cpu-tweak[1165]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance
May 22 17:27:28 volumiodramper systemd[1]: volumio_cpu_tweak.service: Succeeded.
May 22 17:27:28 volumiodramper winbindd[1162]: [2025/05/22 17:27:28.791963,  0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache)
May 22 17:27:28 volumiodramper winbindd[1162]:   initialize_winbindd_cache: clearing cache and re-creating with version number 2
May 22 17:27:28 volumiodramper winbindd[1162]: [2025/05/22 17:27:28.809408,  0] ../lib/util/become_daemon.c:138(daemon_ready)
May 22 17:27:28 volumiodramper systemd[1]: Started Samba Winbind Daemon.
May 22 17:27:28 volumiodramper winbindd[1162]:   daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections
May 22 17:27:28 volumiodramper systemd[1]: Starting Samba SMB Daemon...
May 22 17:27:29 volumiodramper ntpd[923]: Listen normally on 3 wlan0 192.168.1.123:123
May 22 17:27:29 volumiodramper ntpd[923]: new interface(s) found: waking up resolver
May 22 17:27:29 volumiodramper smbd[1184]: [2025/05/22 17:27:29.220351,  0] ../lib/util/become_daemon.c:138(daemon_ready)
May 22 17:27:29 volumiodramper systemd[1]: Started Samba SMB Daemon.
May 22 17:27:29 volumiodramper smbd[1184]:   daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
May 22 17:27:29 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:29] [info] asio async_connect error: system:111 (Connection refused)
May 22 17:27:29 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:29] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected)
May 22 17:27:29 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:27:29] [error] handle_connect error: Underlying Transport Error
May 22 17:27:30 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:27:30 volumiodramper volumio[1164]: info: -----            Volumio3              ----
May 22 17:27:30 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:27:30 volumiodramper volumio[1164]: info: -----          System startup          ----
May 22 17:27:30 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:27:30 volumiodramper volumio[1164]: info: MYVOLUMIO Environment detected
May 22 17:27:30 volumiodramper volumio[1164]: info: Plugin folders cleanup
May 22 17:27:30 volumiodramper volumio[1164]: info: Scanning into folder /volumio/app/plugins/
May 22 17:27:30 volumiodramper volumio[1164]: info: Scanning category audio_interface
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category miscellanea
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category music_service
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category plugins.json
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category system_controller
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category user_interface
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning into folder /data/plugins/
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category audio_interface
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category music_service
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category system_controller
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category system_hardware
May 22 17:27:31 volumiodramper volumio[1164]: info: Scanning category user_interface
May 22 17:27:31 volumiodramper volumio[1164]: info: Plugin folders cleanup completed
May 22 17:27:31 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:27:31 volumiodramper volumio[1164]: info: -----      Core plugins startup        ----
May 22 17:27:31 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:27:31 volumiodramper volumio[1164]: info: Loading plugins from folder /volumio/app/plugins/
May 22 17:27:31 volumiodramper volumio[1164]: info: Adding plugin upnp to MyMusic Plugins
May 22 17:27:31 volumiodramper volumio[1164]: info: Adding plugin airplay_emulation to MyMusic Plugins
May 22 17:27:31 volumiodramper volumio[1164]: info: Adding plugin upnp_browser to MyMusic Plugins
May 22 17:27:31 volumiodramper volumio[1164]: info: Loading plugins from folder /data/plugins/
May 22 17:27:31 volumiodramper volumio[1164]: info: Loading plugin "system"...
May 22 17:27:31 volumiodramper volumio[1164]: info: Loading plugin "appearance"...
May 22 17:27:31 volumiodramper volumio[1164]: info: Loading plugin "network"...
May 22 17:27:31 volumiodramper volumio[1164]: info: Refreshing Cached IP Addresses
May 22 17:27:31 volumiodramper sudo[1209]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 22 17:27:31 volumiodramper sudo[1209]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:32 volumiodramper volumio-time-update[626]: volumio-time-update-util: Fetching time from Volumio...
May 22 17:27:32 volumiodramper sudo[1211]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 22 17:27:32 volumiodramper sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:32 volumiodramper sudo[1209]: pam_unix(sudo:session): session closed for user root
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "services"...
May 22 17:27:32 volumiodramper sudo[1211]: pam_unix(sudo:session): session closed for user root
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "alsa_controller"...
May 22 17:27:32 volumiodramper sudo[1224]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
May 22 17:27:32 volumiodramper sudo[1224]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:32 volumiodramper volumio[1164]: warn: Unable to locate the audio output device HiFiBerry Amp2. Please configure a valid output device.
May 22 17:27:32 volumiodramper volumio[1164]: Invalid card number.
May 22 17:27:32 volumiodramper volumio[1164]: info: Hardware Mixer selected but no Hardware mixer available, detecting default mixer
May 22 17:27:32 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
May 22 17:27:32 volumiodramper volumio[1164]: Invalid card number.
May 22 17:27:32 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioUpdateVolumeSettings
May 22 17:27:32 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "wizard"...
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "networkfs"...
May 22 17:27:32 volumiodramper volumio[1164]: info: Starting Udev Watcher for removable devices
May 22 17:27:32 volumiodramper volumio[1164]: info: Ignoring mount for partition: boot
May 22 17:27:32 volumiodramper volumio[1164]: info: Ignoring mount for partition: volumio
May 22 17:27:32 volumiodramper volumio[1164]: info: Ignoring mount for partition: volumio_data
May 22 17:27:32 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "volumio_command_line_client"...
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "upnp"...
May 22 17:27:32 volumiodramper volumio[1164]: info: [1747927652232] Starting Upmpd Daemon
May 22 17:27:32 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "my_music"...
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "mpd"...
May 22 17:27:32 volumiodramper volumio-time-update[626]: volumio-time-update-util: Setting system time to: 2025-05-22 17:28:00
May 22 17:27:32 volumiodramper sudo[1247]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-05-22 17:28:00
May 22 17:27:32 volumiodramper sudo[1247]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:27:32 volumiodramper dbus-daemon[647]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.10' (uid=0 pid=1248 comm="timedatectl set-time 2025-05-22 17:28:00 ")
May 22 17:27:32 volumiodramper systemd[1]: Starting Time & Date Service...
May 22 17:27:32 volumiodramper dbus-daemon[647]: [system] Successfully activated service 'org.freedesktop.timedate1'
May 22 17:27:32 volumiodramper systemd[1]: Started Time & Date Service.
May 22 17:27:32 volumiodramper volumio[1164]: info: Loading plugin "upnp_browser"...
May 22 17:28:00 volumiodramper systemd-timedated[1249]: Changed local time to Thu May 22 17:28:00 2025
May 22 17:28:00 volumiodramper sudo[1247]: pam_unix(sudo:session): session closed for user root
May 22 17:28:00 volumiodramper volumio-time-update[626]: volumio-time-update-util: System time updated successfully.
May 22 17:28:00 volumiodramper systemd[1]: Started Volumio Time Update Utility.
May 22 17:28:00 volumiodramper systemd[1]: Reached target Multi-User System.
May 22 17:28:00 volumiodramper systemd[1]: Reached target Graphical Interface.
May 22 17:28:00 volumiodramper systemd[1]: Starting Update UTMP about System Runlevel Changes...
May 22 17:28:00 volumiodramper systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
May 22 17:28:00 volumiodramper systemd[1]: Started Update UTMP about System Runlevel Changes.
May 22 17:28:00 volumiodramper systemd[1]: Startup finished in 11.961s (kernel) + 29.433s (userspace) = 41.395s.
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "alarm-clock"...
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "airplay_emulation"...
May 22 17:28:00 volumiodramper volumio[1164]: info: Starting Shairport Sync
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "last_100"...
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "webradio"...
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "i2s_dacs"...
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "volumiodiscovery"...
May 22 17:28:00 volumiodramper volumio[1164]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
May 22 17:28:00 volumiodramper volumio[1164]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 22 17:28:00 volumiodramper node[1164]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
May 22 17:28:00 volumiodramper volumio[1164]: *** WARNING *** For more information see 
May 22 17:28:00 volumiodramper volumio[1164]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
May 22 17:28:00 volumiodramper volumio[1164]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 22 17:28:00 volumiodramper volumio[1164]: *** WARNING *** For more information see 
May 22 17:28:00 volumiodramper node[1164]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 22 17:28:00 volumiodramper node[1164]: *** WARNING *** For more information see 
May 22 17:28:00 volumiodramper node[1164]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
May 22 17:28:00 volumiodramper node[1164]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 22 17:28:00 volumiodramper node[1164]: *** WARNING *** For more information see 
May 22 17:28:00 volumiodramper volumio[1164]: info: Applying required configuration parameters for plugin volumiodiscovery
May 22 17:28:00 volumiodramper volumio[1164]: info: Discovery: Started advertising with name: Volumio_DR_AMPER
May 22 17:28:00 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 22 17:28:00 volumiodramper volumio[1164]: info: Loading plugin "spop"...
May 22 17:28:01 volumiodramper volumio[1164]: info: Loading plugin "now_playing"...
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "outputs"...
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "albumart"...
May 22 17:28:02 volumiodramper volumio[1164]: info: Plugin example_plugin is not enabled
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "inputs"...
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "updater_comm"...
May 22 17:28:02 volumiodramper volumio[1164]: info: Plugin mpdemulation is not enabled
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "rest_api"...
May 22 17:28:02 volumiodramper sudo[1224]: pam_unix(sudo:session): session closed for user root
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "websocket"...
May 22 17:28:02 volumiodramper volumio[1164]: info: Starting Socket.io Server version 2.3.0
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "mpdoutput"...
May 22 17:28:02 volumiodramper volumio[1164]: Forking 3 albumart workers
May 22 17:28:02 volumiodramper volumio[1164]: info: Plugin backup_restore is not enabled
May 22 17:28:02 volumiodramper volumio[1164]: info: Plugin audiophonics_evo_sabre is not enabled
May 22 17:28:02 volumiodramper volumio[1164]: info: Loading plugin "audiophonicsonoff"...
May 22 17:28:03 volumiodramper systemd[1]: systemd-fsckd.service: Succeeded.
May 22 17:28:03 volumiodramper volumio[1164]: info: Applying required configuration parameters for plugin audiophonicsonoff
May 22 17:28:03 volumiodramper volumio[1164]: info: Audiophonics on/off initiated
May 22 17:28:03 volumiodramper volumio[1164]: info: Plugin gpio_control is not enabled
May 22 17:28:03 volumiodramper volumio[1164]: info: Plugin ir_controller is not enabled
May 22 17:28:03 volumiodramper volumio[1164]: info: Plugin mpd_oled is not enabled
May 22 17:28:03 volumiodramper volumio[1164]: info: Plugin onkyo_control is not enabled
May 22 17:28:03 volumiodramper volumio[1164]: info: Loading i18n strings for locale pl
May 22 17:28:03 volumiodramper volumio[1164]: Updating browse sources language
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:03 volumiodramper volumio[1164]: Starting albumart workers
May 22 17:28:03 volumiodramper volumio[1164]: Starting albumart workers
May 22 17:28:03 volumiodramper volumio[1164]: Starting albumart workers
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::initPlayerControls
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: Express server listening on port 3000
May 22 17:28:03 volumiodramper volumio[1164]:  [Metrics]  WebUI:  6s 453.35ms 
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::resetVolumioState
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::getcurrentVolume
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioRetrievevolume
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioRetrieveVolumeLevels
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::getcurrentVolume
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioRetrievevolume
May 22 17:28:03 volumiodramper volumio[1164]: info: Volumio Network Manager: Network status updated: 2
May 22 17:28:03 volumiodramper volumio[1164]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number.
May 22 17:28:03 volumiodramper volumio[1164]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number.
May 22 17:28:03 volumiodramper volumio[1164]: verbose: New Socket.io Connection to 192.168.1.123 from 192.168.1.40 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1
May 22 17:28:03 volumiodramper volumio[1164]: info: VolumeController:: Volume=undefined Mute =false
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::updateTrackBlock
May 22 17:28:03 volumiodramper volumio[1164]: info: CorePlayQueue::getTrackBlock
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioRetrievevolume
May 22 17:28:03 volumiodramper volumio[1164]: info: VolumeController:: Volume=undefined Mute =false
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::updateTrackBlock
May 22 17:28:03 volumiodramper volumio[1164]: info: CorePlayQueue::getTrackBlock
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioRetrievevolume
May 22 17:28:03 volumiodramper volumio[1164]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number.
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:03 volumiodramper volumio[1164]: info: Reloading queue from file
May 22 17:28:03 volumiodramper volumio[1164]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number.
May 22 17:28:03 volumiodramper volumio[1164]: info: Setting Device type: Raspberry PI
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::setRepeat null single undefined
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::setRandom null
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:03 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:03 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:03 volumiodramper volumio[1164]: info: Completed loading Core Plugins
May 22 17:28:03 volumiodramper volumio[1164]: info: Preparing to generate the ALSA configuration file
May 22 17:28:04 volumiodramper volumio[1164]: info: VolumeController:: Volume=undefined Mute =false
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:04 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:04 volumiodramper volumio[1164]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
May 22 17:28:04 volumiodramper volumio[1164]: info: USB Boot Capable - System SBC Revision found in cpuinfo:  d03115
May 22 17:28:04 volumiodramper volumio[1164]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
May 22 17:28:04 volumiodramper volumio[1164]: info: VolumeController:: Volume=undefined Mute =false
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:04 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:04 volumiodramper volumio[1164]: info: Asound.conf file unchanged, so no further update is needed
May 22 17:28:04 volumiodramper volumio[1164]: info: Output device has changed, restarting MPD
May 22 17:28:04 volumiodramper volumio[1164]: info: Output device has changed, restarting Shairport Sync
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:04 volumiodramper sudo[1323]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 22 17:28:04 volumiodramper sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper sudo[1325]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 22 17:28:04 volumiodramper sudo[1325]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper sudo[1323]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper systemd[1]: Stopping Music Player Daemon...
May 22 17:28:04 volumiodramper volumio[1164]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 22 17:28:04 volumiodramper volumio[1164]: info: ___________ START PLUGINS ___________
May 22 17:28:04 volumiodramper volumio[1164]: info: ControllerMpd::onStart: Initializing MPD
May 22 17:28:04 volumiodramper volumio[1164]: info: Creating MPD Configuration file
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 22 17:28:04 volumiodramper volumio[1164]: info: [1747927684122] CoreMusicLibrary::Adding element Serwery Mediów
May 22 17:28:04 volumiodramper sudo[1332]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:04 volumiodramper sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper sudo[1332]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper sudo[1334]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:04 volumiodramper sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper systemd[1]: mpd.service: Succeeded.
May 22 17:28:04 volumiodramper systemd[1]: Stopped Music Player Daemon.
May 22 17:28:04 volumiodramper volumio[1164]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 22 17:28:04 volumiodramper volumio[1164]: info: [1747927684213] CoreMusicLibrary::Adding element Last_100
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:04 volumiodramper systemd[1]: Starting Music Player Daemon...
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 22 17:28:04 volumiodramper volumio[1164]: info: [1747927684216] CoreMusicLibrary::Adding element Webradio
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 22 17:28:04 volumiodramper volumio[1164]: info: Initializing BBC Radios
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:04 volumiodramper sudo[1340]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 22 17:28:04 volumiodramper sudo[1340]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper volumio[1164]: info: Creating Spotify config file
May 22 17:28:04 volumiodramper sudo[1340]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: [now-playing] ConfigUpdater: config is up to date.
May 22 17:28:04 volumiodramper volumio[1164]: info: Configuring GPIO pins
May 22 17:28:04 volumiodramper volumio[1164]: error: Plugin audiophonicsonoff failed to start! Error: EBUSY: resource busy or locked, write
May 22 17:28:04 volumiodramper volumio[1164]: info: Volumio Calling Home
May 22 17:28:04 volumiodramper volumio[1164]: info: [now-playing] App is listening on port 4004.
May 22 17:28:04 volumiodramper volumio[1164]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds
May 22 17:28:04 volumiodramper volumio[1164]: info: Discovery: adding 39a459a7-d564-4623-9073-c46a7598e7d2
May 22 17:28:04 volumiodramper volumio[1164]: info: Discovery: Found device Volumio_DR_AMPER
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:04 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:04 volumiodramper volumio[1164]: info: MPD Permissions set
May 22 17:28:04 volumiodramper volumio[1164]: info: MPD Permissions set
May 22 17:28:04 volumiodramper volumio[1164]: info: Spotify config file written
May 22 17:28:04 volumiodramper volumio[1164]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper sudo[1365]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
May 22 17:28:04 volumiodramper sudo[1365]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: No need to fix Spotify hosts
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:04 volumiodramper systemd[1]: Started go-librespot Daemon.
May 22 17:28:04 volumiodramper go-librespot[1371]: go-librespot daemon starting...
May 22 17:28:04 volumiodramper sudo[1365]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper volumio[1164]: info: Volumio called home
May 22 17:28:04 volumiodramper volumio[1164]: info: Starting Shairport Sync
May 22 17:28:04 volumiodramper volumio[1164]: info: Starting Shairport Sync
May 22 17:28:04 volumiodramper volumio[1164]: info: Starting Shairport Sync
May 22 17:28:04 volumiodramper sudo[1378]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 22 17:28:04 volumiodramper sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper sudo[1384]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 22 17:28:04 volumiodramper sudo[1384]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper sudo[1388]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 22 17:28:04 volumiodramper sudo[1388]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:04 volumiodramper systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
May 22 17:28:04 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:04 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:04 volumiodramper systemd[1]: shairport-sync.service: Succeeded.
May 22 17:28:04 volumiodramper systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
May 22 17:28:04 volumiodramper systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
May 22 17:28:04 volumiodramper sudo[1378]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper sudo[1384]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
May 22 17:28:04 volumiodramper systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM
May 22 17:28:04 volumiodramper systemd[1]: shairport-sync.service: Succeeded.
May 22 17:28:04 volumiodramper systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
May 22 17:28:04 volumiodramper systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
May 22 17:28:04 volumiodramper sudo[1388]: pam_unix(sudo:session): session closed for user root
May 22 17:28:04 volumiodramper volumio[1164]: info: Shairport-Sync Started
May 22 17:28:04 volumiodramper volumio[1164]: Error adding Membership: Error: addMembership EINVAL
May 22 17:28:04 volumiodramper volumio[1164]: info: Shairport-Sync Started
May 22 17:28:04 volumiodramper volumio[1164]: info: Shairport-Sync Started
May 22 17:28:04 volumiodramper volumio[1164]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
May 22 17:28:04 volumiodramper volumio[1164]: SPOTIFY: BQA3j3pbFTr3Kz8GvPET7fohDk5sYtVrj4JQ4zhD6ibEFph5MYVD-dIYSab_ECe8p9O1m7PQ0gWZdfoIb4NPani6c_Ja9pnsYj0-zRGUuhAFUE7z5NwuPkm_ATWaagE-n0L6Os5HgxheocifxlaKT01-veM87vZEOminGV6VsHLLlm2L3hVKyVstCmGpvqxiCf5talHk8_pBpa2plVWoX6THzDegfffZKblZcIL6jCwNdPPvqVCGNg5utcyXGqO9SgbfYAgothMKW-jSz9piPnpOccLEvCeRQA
May 22 17:28:04 volumiodramper volumio[1164]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
May 22 17:28:04 volumiodramper volumio[1164]: info: New Spotify access token = BQA3j3pbFTr3Kz8GvPET7fohDk5sYtVrj4JQ4zhD6ibEFph5MYVD-dIYSab_ECe8p9O1m7PQ0gWZdfoIb4NPani6c_Ja9pnsYj0-zRGUuhAFUE7z5NwuPkm_ATWaagE-n0L6Os5HgxheocifxlaKT01-veM87vZEOminGV6VsHLLlm2L3hVKyVstCmGpvqxiCf5talHk8_pBpa2plVWoX6THzDegfffZKblZcIL6jCwNdPPvqVCGNg5utcyXGqO9SgbfYAgothMKW-jSz9piPnpOccLEvCeRQA
May 22 17:28:04 volumiodramper volumio[1164]: info: Spotify credentials grant success - running version from March 24, 2019
May 22 17:28:04 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:04+02:00" level=info msg="running go-librespot 0.2.0"
May 22 17:28:04 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:04+02:00" level=debug msg="app state loaded"
May 22 17:28:04 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:04+02:00" level=info msg="api server listening on 127.0.0.1:9879"
May 22 17:28:05 volumiodramper mpd[1355]: May 22 17:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 22 17:28:05 volumiodramper systemd[1]: Started Music Player Daemon.
May 22 17:28:05 volumiodramper sudo[1325]: pam_unix(sudo:session): session closed for user root
May 22 17:28:05 volumiodramper sudo[1334]: pam_unix(sudo:session): session closed for user root
May 22 17:28:05 volumiodramper volumio[1164]: info: Completed starting Core Plugins
May 22 17:28:05 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:28:05 volumiodramper volumio[1164]: info: -----    MyVolumio plugins startup     ----
May 22 17:28:05 volumiodramper volumio[1164]: info: -------------------------------------------
May 22 17:28:05 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Fetching plans data....
May 22 17:28:05 volumiodramper volumio[1164]: error: updateQueue error: null
May 22 17:28:05 volumiodramper volumio[1164]: info: MPD running with PID1355
May 22 17:28:05 volumiodramper volumio[1164]:  ,establishing connection
May 22 17:28:05 volumiodramper volumio[1164]: error: MPD error: The expression evaluated to a falsy value:
May 22 17:28:05 volumiodramper volumio[1164]:   assert.ok(self.idling)
May 22 17:28:05 volumiodramper volumio[1164]: error: The expression evaluated to a falsy value:
May 22 17:28:05 volumiodramper volumio[1164]:   assert.ok(self.idling)
May 22 17:28:05 volumiodramper volumio[1164]: error: updateQueue error: null
May 22 17:28:05 volumiodramper volumio[1164]: SPOTIFY: User informations: {"country":"PL","display_name":"m4teuszglowacki","email":"m4teuszglowacki@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/m4teuszglowacki"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/m4teuszglowacki","id":"m4teuszglowacki","images":[],"product":"premium","type":"user","uri":"spotify:user:m4teuszglowacki"}
May 22 17:28:05 volumiodramper volumio[1164]: info: Spotify Successfully logged in
May 22 17:28:05 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 22 17:28:05 volumiodramper volumio[1164]: info: [1747927685232] CoreMusicLibrary::Adding element Spotify
May 22 17:28:05 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:05 volumiodramper volumio[1164]: Cannot find translation for source Spotify
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=info msg="zeroconf server listening on port 38669"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="obtained new client token: AACs6/Gg8qZJ4g4BX0VMYHo3FfXQwrQSHkdYxw/fTUzYtGJ5OS3VwVJXxo7jO20EDpEoWMSASH0fN0ONKzoc566kJ0JJfyT0zioObeJCRMhy+mO1FYnjxNnNk68r7xDmrn5S55Ot0V79LHW5tqJOI837loVh8vq9Ka+ZrslHf/bSzviAsoIvEtjW8QB3HurmJaJ+OlBpH1BVdeabsHJA3W0Y2Aur5fPqOjajj9PsQh2TWqskvDXh2dI="
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
May 22 17:28:05 volumiodramper systemd[1]: systemd-hostnamed.service: Succeeded.
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="completed keyexchange"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="completed challenge"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=info msg="authenticated AP as m4teuszglowacki"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=info msg="authenticated Login5 as m4teuszglowacki"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="initializing zeroconf session, username: m4teuszglowacki"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="dealer connection opened"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=trace msg="starting accesspoint recv loop"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=trace msg="starting dealer recv loop"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=trace msg="received accesspoint ping"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=debug msg="received connection id: YmEwYWMzNjAtM2Q2Yi00MTIyLWEwMGUtZDJlZjBkMjIzMTQxK2RlYWxlcit0Y3A6Ly8wYWNhNTgwOS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNjhFOEFGNkY4RDg0RTQ1REFCRTZDODM3MjdGOERGNkIyMTBCOUI0REMwQUM1OTI0RTM3OTVCMjE1MkQyRjI2OA=="
May 22 17:28:05 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:05+02:00" level=trace msg="received accesspoint pong ack"
May 22 17:28:06 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:06+02:00" level=debug msg="put connect state because NEW_DEVICE"
May 22 17:28:06 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:28:06] [connect] Successful connection
May 22 17:28:06 volumiodramper volumio-remote-updater[632]: [2025-05-22 17:28:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747927686 101
May 22 17:28:06 volumiodramper volumio[1164]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3
May 22 17:28:07 volumiodramper volumio[1164]: info: go-librespot daemon successfully initialized
May 22 17:28:09 volumiodramper sudo[1420]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 22 17:28:09 volumiodramper sudo[1420]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:09 volumiodramper sudo[1420]: pam_unix(sudo:session): session closed for user root
May 22 17:28:09 volumiodramper sudo[1422]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 22 17:28:09 volumiodramper sudo[1422]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:09 volumiodramper sudo[1422]: pam_unix(sudo:session): session closed for user root
May 22 17:28:09 volumiodramper sudo[1426]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
May 22 17:28:09 volumiodramper sudo[1426]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:09 volumiodramper volumio[1164]: verbose: New Socket.io Connection to 192.168.1.123 from 192.168.1.40 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4
May 22 17:28:09 volumiodramper systemd[1]: Started UPnP Renderer front-end to MPD.
May 22 17:28:09 volumiodramper sudo[1426]: pam_unix(sudo:session): session closed for user root
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 22 17:28:09 volumiodramper volumio[1164]: info: Upmpdcli Daemon Started
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetVisibleSources
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:09 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:09 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 22 17:28:09 volumiodramper volumio[1164]: info: Received Get System Info
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 22 17:28:09 volumiodramper volumio[1164]: info: Discovery: Getting this device information
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:09 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 22 17:28:09 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:09 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:09 volumiodramper volumio[1164]: info: Listing playlists
May 22 17:28:09 volumiodramper volumio[1428]: Generating RSA private key, 4096 bit long modulus (2 primes)
May 22 17:28:10 volumiodramper volumio[1164]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
May 22 17:28:10 volumiodramper volumio[1164]: info: Initializing connection to go-librespot Websocket
May 22 17:28:10 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:10+02:00" level=debug msg="new websocket client"
May 22 17:28:10 volumiodramper volumio[1164]: info: Connection to go-librespot Websocket established
May 22 17:28:11 volumiodramper volumio[1164]: info: VolumeController::SetAlsaVolume0
May 22 17:28:11 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:11 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:11 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 22 17:28:11 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:11 volumiodramper volumio[1164]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number.
May 22 17:28:12 volumiodramper volumio[1428]: ...........................++++
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
May 22 17:28:13 volumiodramper volumio[1164]: info: Adding plugin bluetooth to MyMusic Plugins
May 22 17:28:13 volumiodramper volumio[1164]: info: Adding plugin multiroom to MyMusic Plugins
May 22 17:28:13 volumiodramper volumio[1164]: info: Adding plugin metavolumio to MyMusic Plugins
May 22 17:28:13 volumiodramper volumio[1164]: info: Adding plugin cd_controller to MyMusic Plugins
May 22 17:28:13 volumiodramper volumio[1164]: info: Adding plugin smart_inputs to MyMusic Plugins
May 22 17:28:13 volumiodramper volumio[1164]: info: Adding plugin tidalconnect to MyMusic Plugins
May 22 17:28:13 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
May 22 17:28:14 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
May 22 17:28:14 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
May 22 17:28:14 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:14 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:14 volumiodramper volumio[1164]: info: Starting MyVolumio Remote Streaming Endpoints
May 22 17:28:14 volumiodramper volumio[1164]: info: MyVolumio login type: Token
May 22 17:28:14 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
May 22 17:28:14 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
May 22 17:28:15 volumiodramper volumio[1164]: info: Starting Streaming Service Transparent Proxy
May 22 17:28:15 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
May 22 17:28:15 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
May 22 17:28:15 volumiodramper volumio[1164]: info: Streaming services startup
May 22 17:28:15 volumiodramper volumio[1164]: info: Starting Streaming Daemon
May 22 17:28:15 volumiodramper sudo[1452]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 22 17:28:15 volumiodramper sudo[1452]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:15 volumiodramper volumio[1164]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
May 22 17:28:15 volumiodramper sudo[1452]: pam_unix(sudo:session): session closed for user root
May 22 17:28:15 volumiodramper volumio[1164]: info: Getting Spotify volume
May 22 17:28:15 volumiodramper volumio[1164]: error: Cannot start Volumio Streaming Daemon
May 22 17:28:15 volumiodramper volumio[1164]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 22 17:28:15 volumiodramper volumio[1164]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 22 17:28:15 volumiodramper volumio[1164]: info: Spotify volume: 100
May 22 17:28:15 volumiodramper volumio[1164]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
May 22 17:28:15 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:15 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:15 volumiodramper volumio[1164]: STREAMING PROXY: Starting server on port 3245
May 22 17:28:15 volumiodramper volumio[1164]: Node JS runtime: 14
May 22 17:28:15 volumiodramper volumio[1164]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
May 22 17:28:16 volumiodramper volumio[1164]: info: MyVolumio token set successfully
May 22 17:28:16 volumiodramper volumio[1164]: info: MYVOLUMIO: Adding device
May 22 17:28:16 volumiodramper volumio[1164]: info: MYVOLUMIO: Evaluating Server
May 22 17:28:16 volumiodramper volumio[1164]: info: MyVolumio status changed
May 22 17:28:16 volumiodramper volumio[1164]: info: Streaming services startup
May 22 17:28:16 volumiodramper volumio[1164]: info: Starting Streaming Daemon
May 22 17:28:16 volumiodramper volumio[1164]: info: Removing browser output: myVolumio user plan is not superstar
May 22 17:28:16 volumiodramper volumio[1164]: info: Removing audio output:
May 22 17:28:16 volumiodramper volumio[1164]: info: Stoppping Tunnel 1
May 22 17:28:16 volumiodramper sudo[1477]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 22 17:28:16 volumiodramper sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:16 volumiodramper sudo[1479]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
May 22 17:28:16 volumiodramper sudo[1479]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:16 volumiodramper sudo[1477]: pam_unix(sudo:session): session closed for user root
May 22 17:28:16 volumiodramper volumio[1164]: error: Cannot start Volumio Streaming Daemon
May 22 17:28:16 volumiodramper volumio[1164]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 22 17:28:16 volumiodramper volumio[1164]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 22 17:28:16 volumiodramper sudo[1479]: pam_unix(sudo:session): session closed for user root
May 22 17:28:16 volumiodramper volumio[1164]: info: Remote SSH Stopped
May 22 17:28:17 volumiodramper volumio[1164]: info: Setting Geolocation for MyVolumio to eu4
May 22 17:28:17 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:17 volumiodramper volumio[1164]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
May 22 17:28:18 volumiodramper volumio[1164]: info: Updating MyVolumio device info
May 22 17:28:18 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:18 volumiodramper volumio[1164]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
May 22 17:28:21 volumiodramper volumio[1164]: info: MYVOLUMIO: Adding device
May 22 17:28:21 volumiodramper volumio[1164]: info: MYVOLUMIO: Evaluating Server
May 22 17:28:22 volumiodramper volumio[1164]: info: Setting Geolocation for MyVolumio to eu4
May 22 17:28:22 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:22 volumiodramper volumio[1164]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
May 22 17:28:23 volumiodramper volumio[1164]: info: Updating MyVolumio device info
May 22 17:28:23 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:24 volumiodramper volumio[1164]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
May 22 17:28:29 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 22 17:28:29 volumiodramper volumio[1164]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6
May 22 17:28:29 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:29 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:30 volumiodramper systemd[1]: systemd-timedated.service: Succeeded.
May 22 17:28:31 volumiodramper volumio[1428]: ..................................................................................................................................................................................................................++++
May 22 17:28:31 volumiodramper volumio[1428]: e is 65537 (0x010001)
May 22 17:28:31 volumiodramper volumio[1428]: writing RSA key
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetBrowseSources
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 22 17:28:34 volumiodramper volumio-remote-updater[632]: No test mode
May 22 17:28:34 volumiodramper volumio-remote-updater[632]: No alpha test mode
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
May 22 17:28:34 volumiodramper volumio[1164]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nVarious Fixes for QOBUZ Connect
\n
\nNEW ADDITIONS
\n\nQobuz Connect Ready
\n\n","title":"Update v3.812","updateavailable":true}
May 22 17:28:34 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 22 17:28:35 volumiodramper volumio[1164]: error: MyVolumio Plugin failed to authenticate in a timely fashion
May 22 17:28:35 volumiodramper volumio[1164]: info: Completed starting MyVolumio Plugin
May 22 17:28:35 volumiodramper volumio[1164]:  [Metrics]  CommandRouter:  37s 528.45ms 
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::volumiosetStartupVolume
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 22 17:28:35 volumiodramper volumio[1164]: info: VolumeController:: Setting startup Volume 10
May 22 17:28:35 volumiodramper volumio[1164]: info: VolumeController::SetAlsaVolume10
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::Close All Modals sent
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::Close All Modals sent
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreStateMachine::pushState
May 22 17:28:35 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPushState
May 22 17:28:35 volumiodramper volumio[1164]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10
May 22 17:28:35 volumiodramper volumio[1164]: SPOTIFY: SPOTIFY VOLUME 100
May 22 17:28:35 volumiodramper volumio[1164]: SPOTIFY: VOLUMIO VOLUME 10
May 22 17:28:35 volumiodramper volumio[1164]: SPOTIFY: DELTA VOLUME ENOUGH: true
May 22 17:28:35 volumiodramper volumio[1164]: info: Setting Spotify Volume from Volumio: 10
May 22 17:28:35 volumiodramper volumio[1164]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number.
May 22 17:28:35 volumiodramper volumio[1164]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav
May 22 17:28:35 volumiodramper volumio[1164]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card
May 22 17:28:35 volumiodramper volumio[1164]: aplay: main:828: audio open error: No such device
May 22 17:28:35 volumiodramper sudo[1590]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 22 17:28:35 volumiodramper sudo[1590]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:35 volumiodramper sudo[1590]: pam_unix(sudo:session): session closed for user root
May 22 17:28:35 volumiodramper sudo[1592]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 22 17:28:35 volumiodramper sudo[1592]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:35 volumiodramper sudo[1592]: pam_unix(sudo:session): session closed for user root
May 22 17:28:35 volumiodramper volumio[1164]: verbose: New Socket.io Connection to 192.168.1.123 from 192.168.1.40 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetVisibleSources
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:35 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 22 17:28:35 volumiodramper volumio[1164]: info: Received Get System Info
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 22 17:28:35 volumiodramper volumio[1164]: info: Discovery: Getting this device information
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:35 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:35 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:35 volumiodramper volumio[1164]: info: Listing playlists
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 22 17:28:35 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
May 22 17:28:35 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:35+02:00" level=trace msg="sent dealer ping"
May 22 17:28:35 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:35+02:00" level=trace msg="received dealer pong"
May 22 17:28:36 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
May 22 17:28:36 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
May 22 17:28:36 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
May 22 17:28:36 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:36 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:36 volumiodramper volumio[1164]: SPOTIFY: SETTING SPOTIFY VOLUME 10
May 22 17:28:36 volumiodramper volumio[1164]: info: Sending Spotify command with payload to local API: /player/volume
May 22 17:28:36 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:36+02:00" level=debug msg="update volume to 6553/65535"
May 22 17:28:36 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 22 17:28:37 volumiodramper volumio[1164]: info: Received Get System Info
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 22 17:28:37 volumiodramper volumio[1164]: info: Discovery: Getting this device information
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:37 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPlay
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreStateMachine::play index undefined
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreStateMachine::setConsumeUpdateService undefined
May 22 17:28:37 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:37 volumiodramper volumio[1164]: info: CoreStateMachine::startPlaybackTimer
May 22 17:28:37 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:37 volumiodramper volumio[1164]: info: [1747927717553] ControllerSpotify::clearAddPlayTrack
May 22 17:28:37 volumiodramper volumio[1164]: info: Sending Spotify command with payload to local API: /player/play
May 22 17:28:37 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:37+02:00" level=debug msg="resolved context of track" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:37 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:37+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:37 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:37+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:37 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
May 22 17:28:37 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:37+02:00" level=trace msg="emitting websocket event: will_play"
May 22 17:28:37 volumiodramper volumio[1164]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3AJwUDP919kvQ9QcozQPxg","play_origin":"go-librespot"}}
May 22 17:28:38 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 22 17:28:38 volumiodramper volumio[1164]: info: Received Get System Info
May 22 17:28:38 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 22 17:28:38 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 22 17:28:38 volumiodramper volumio[1164]: info: Discovery: Getting this device information
May 22 17:28:38 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:38 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:38 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=debug msg="selected format OGG_VORBIS_320 (99002cfce1a4ad53f18186b77245deed99b08911)" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=debug msg="requested aes key for file 99002cfce1a4ad53f18186b77245deed99b08911, gid: 3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=debug msg="fetched first chunk of 20, total size is 10385336 bytes" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=debug msg="created new output device"
May 22 17:28:38 volumiodramper go-librespot[1371]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:3AJwUDP919kvQ9QcozQPxg: ALSA error at snd_pcm_open: No such device"
May 22 17:28:38 volumiodramper volumio[1164]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
May 22 17:28:38 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:38+02:00" level=trace msg="emitting websocket event: volume"
May 22 17:28:38 volumiodramper volumio[1164]: SPOTIFY: received: {"type":"volume","data":{"value":10,"max":100}}
May 22 17:28:38 volumiodramper volumio[1164]: SPOTIFY: RECEIVED SPOTIFY VOLUME 10
May 22 17:28:39 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:39+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:39 volumiodramper go-librespot[1371]: time="2025-05-22T17:28:39+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:3AJwUDP919kvQ9QcozQPxg"
May 22 17:28:40 volumiodramper ntpd[923]: Soliciting pool server 193.25.222.136
May 22 17:28:41 volumiodramper ntpd[923]: Soliciting pool server 188.165.17.91
May 22 17:28:42 volumiodramper volumio[1164]: info: BOOT COMPLETED
May 22 17:28:42 volumiodramper ntpd[923]: Soliciting pool server 54.37.233.160
May 22 17:28:42 volumiodramper volumio[1164]: info: mpdhttpout ---Boot completed detected! Patching mpd now!
May 22 17:28:42 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioGetState
May 22 17:28:42 volumiodramper volumio[1164]: info: CorePlayQueue::getTrack 0
May 22 17:28:42 volumiodramper volumio[1164]: info: CoreCommandRouter::volumioPause
May 22 17:28:42 volumiodramper volumio[1164]: info: CoreStateMachine::pause
May 22 17:28:42 volumiodramper volumio[1164]: info: mpdhttpout --- Volumio set on pause
May 22 17:28:42 volumiodramper volumio[1164]: info: mpdhttpout ---Configuration successfully added to mpd.conf.
May 22 17:28:42 volumiodramper ntpd[923]: Soliciting pool server 193.59.134.156
May 22 17:28:43 volumiodramper ntpd[923]: Soliciting pool server 193.70.94.182
May 22 17:28:43 volumiodramper ntpd[923]: Soliciting pool server 91.210.128.220
May 22 17:28:44 volumiodramper ntpd[923]: Soliciting pool server 51.68.141.5
May 22 17:28:44 volumiodramper ntpd[923]: Soliciting pool server 194.146.251.101
May 22 17:28:44 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd
May 22 17:28:44 volumiodramper sudo[1613]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 22 17:28:44 volumiodramper sudo[1613]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:44 volumiodramper systemd[1]: Stopping Music Player Daemon...
May 22 17:28:44 volumiodramper systemd[1]: mpd.service: Succeeded.
May 22 17:28:44 volumiodramper systemd[1]: Stopped Music Player Daemon.
May 22 17:28:44 volumiodramper systemd[1]: Starting Music Player Daemon...
May 22 17:28:44 volumiodramper sudo[1615]:     root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 22 17:28:44 volumiodramper sudo[1615]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 22 17:28:44 volumiodramper sudo[1615]: pam_unix(sudo:session): session closed for user root
May 22 17:28:45 volumiodramper volumio[1164]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
May 22 17:28:45 volumiodramper mpd[1617]: May 22 17:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 22 17:28:45 volumiodramper systemd[1]: Started Music Player Daemon.
May 22 17:28:45 volumiodramper sudo[1613]: pam_unix(sudo:session): session closed for user root
May 22 17:28:45 volumiodramper volumio[1164]: error: updateQueue error: null
May 22 17:28:45 volumiodramper ntpd[923]: Soliciting pool server 212.127.78.21
May 22 17:28:45 volumiodramper ntpd[923]: Soliciting pool server 89.161.47.136
May 22 17:28:45 volumiodramper ntpd[923]: Soliciting pool server 195.46.37.22
May 22 17:28:46 volumiodramper volumio[1164]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________
May 22 17:28:46 volumiodramper volumio[1164]: info: PLUGIN onReboot : networkfs
May 22 17:28:46 volumiodramper volumio[1164]: info: PLUGIN onReboot : audiophonicsonoff
May 22 17:28:46 volumiodramper volumio[1164]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 22 17:28:46 volumiodramper volumio[1164]: TypeError: Cannot read property 'writeSync' of undefined
May 22 17:28:46 volumiodramper volumio[1164]:     at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25)
May 22 17:28:46 volumiodramper volumio[1164]:     at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30)
May 22 17:28:46 volumiodramper volumio[1164]:     at HashMap. (/volumio/app/pluginmanager.js:668:31)
May 22 17:28:46 volumiodramper volumio[1164]:     at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
May 22 17:28:46 volumiodramper volumio[1164]:     at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
May 22 17:28:46 volumiodramper volumio[1164]:     at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20)
May 22 17:28:46 volumiodramper volumio[1164]:     at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22)
May 22 17:28:46 volumiodramper volumio[1164]:     at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:870:33)
May 22 17:28:46 volumiodramper volumio[1164]:     at Socket.emit (events.js:315:20)
May 22 17:28:46 volumiodramper volumio[1164]:     at /volumio/node_modules/socket.io/lib/socket.js:528:12
May 22 17:28:46 volumiodramper volumio[1164]:     at processTicksAndRejections (internal/process/task_queues.js:75:11)
May 22 17:28:46 volumiodramper volumio[1164]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 22 17:28:46 volumiodramper ntpd[923]: Soliciting pool server 162.159.200.1
May 22 17:28:46 volumiodramper ntpd[923]: Soliciting pool server 178.215.228.24
May 22 17:28:46 volumiodramper sudo[1629]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-22 17:27
May 22 17:28:46 volumiodramper sudo[1629]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST"
VOLUMIO_VERSION="3.804"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"