Apr 03 19:12:00 volumio volumio[1261]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Apr 03 19:12:00 volumio volumio[1261]: info: Discovery: Restarting Browsing Apr 03 19:12:00 volumio volumio[1261]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Apr 03 19:12:00 volumio volumio[1261]: info: Discovery: Restarting Browsing Apr 03 19:12:00 volumio volumio[1261]: info: Discovery: Restart already pending, ignoring duplicate call Apr 03 19:12:01 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:12:01 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 6. Apr 03 19:12:01 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:01 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:01 volumio upmpdcli[2295]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:12:01 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:12:01 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 03 19:12:02 volumio volumio[1261]: info: Getting Alsa Cards List without I2S DAC Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 03 19:12:02 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 03 19:12:04 volumio volumio[1261]: info: CoreCommandRouter::volumioPlay Apr 03 19:12:04 volumio volumio[1261]: info: CoreStateMachine::play index undefined Apr 03 19:12:04 volumio volumio[1261]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 19:12:04 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:05 volumio volumio[1261]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Apr 03 19:12:05 volumio volumio[1261]: info: Discovery: Restarting Browsing Apr 03 19:12:05 volumio volumio[1261]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Apr 03 19:12:05 volumio volumio[1261]: info: Discovery: Restarting Browsing Apr 03 19:12:05 volumio volumio[1261]: info: Discovery: Restart already pending, ignoring duplicate call Apr 03 19:12:05 volumio volumio[1261]: info: CoreCommandRouter::volumioGetQueue Apr 03 19:12:05 volumio volumio[1261]: info: CoreStateMachine::getQueue Apr 03 19:12:05 volumio volumio[1261]: info: CorePlayQueue::getQueue Apr 03 19:12:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 03 19:12:10 volumio volumio[1261]: info: Discovery: this is already registered, a69cf95d-fb8a-40d0-8e36-07523999d7a3 Apr 03 19:12:10 volumio volumio[1261]: info: Discovery: Found device Volumio Apr 03 19:12:10 volumio volumio[1261]: info: CoreCommandRouter::volumioGetState Apr 03 19:12:10 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:10 volumio volumio[1261]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Apr 03 19:12:10 volumio volumio[1261]: info: Discovery: Restarting Browsing Apr 03 19:12:10 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 03 19:12:10 volumio volumio[1261]: info: CURURI: playlists Apr 03 19:12:10 volumio volumio[1261]: info: Listing playlists Apr 03 19:12:11 volumio volumio[1261]: info: Preload queue cleared Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 03 19:12:14 volumio volumio[1261]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 03 19:12:14 volumio volumio[1261]: info: Received Get System Version Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 19:12:14 volumio volumio[1261]: info: Received Get System Info Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 03 19:12:14 volumio volumio[1261]: info: Discovery: Getting this device information Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::volumioGetState Apr 03 19:12:14 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 19:12:15 volumio volumio[1261]: info: Discovery: this is already registered, a69cf95d-fb8a-40d0-8e36-07523999d7a3 Apr 03 19:12:15 volumio volumio[1261]: info: Discovery: Found device Volumio Apr 03 19:12:15 volumio volumio[1261]: info: CoreCommandRouter::volumioGetState Apr 03 19:12:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:15 volumio volumio[1261]: info: Discovery: this is already registered, a69cf95d-fb8a-40d0-8e36-07523999d7a3 Apr 03 19:12:15 volumio volumio[1261]: info: Discovery: Found device Volumio Apr 03 19:12:15 volumio volumio[1261]: info: CoreCommandRouter::volumioGetState Apr 03 19:12:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:17 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 7. Apr 03 19:12:17 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:17 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:17 volumio upmpdcli[2347]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:12:17 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:12:17 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:12:22 volumio kernel: usb 1-1.3: USB disconnect, device number 3 Apr 03 19:12:22 volumio kernel: device offline error, dev sda, sector 0 op 0x1:(WRITE) flags 0x800 phys_seg 0 prio class 2 Apr 03 19:12:22 volumio kernel: EXT4-fs (sda1): shut down requested (2) Apr 03 19:12:22 volumio kernel: Aborting journal on device sda1-8. Apr 03 19:12:22 volumio kernel: device offline error, dev sda, sector 180266 op 0x1:(WRITE) flags 0x9800 phys_seg 1 prio class 2 Apr 03 19:12:22 volumio kernel: device offline error, dev sda, sector 180266 op 0x1:(WRITE) flags 0x9800 phys_seg 1 prio class 2 Apr 03 19:12:22 volumio kernel: Buffer I/O error on dev sda1, logical block 90113, lost sync page write Apr 03 19:12:22 volumio kernel: JBD2: I/O error when updating journal superblock for sda1-8. Apr 03 19:12:22 volumio kernel: device offline error, dev sda, sector 0 op 0x1:(WRITE) flags 0x800 phys_seg 0 prio class 2 Apr 03 19:12:22 volumio kernel: EXT4-fs (sda2): shut down requested (2) Apr 03 19:12:22 volumio kernel: Aborting journal on device sda2-8. Apr 03 19:12:22 volumio kernel: device offline error, dev sda, sector 3905570816 op 0x1:(WRITE) flags 0x9800 phys_seg 1 prio class 2 Apr 03 19:12:22 volumio kernel: device offline error, dev sda, sector 3905570816 op 0x1:(WRITE) flags 0x9800 phys_seg 1 prio class 2 Apr 03 19:12:22 volumio kernel: Buffer I/O error on dev sda2, logical block 488144896, lost sync page write Apr 03 19:12:22 volumio kernel: JBD2: I/O error when updating journal superblock for sda2-8. Apr 03 19:12:22 volumio kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache Apr 03 19:12:23 volumio kernel: sd 0:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK Apr 03 19:12:23 volumio volumio[1261]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda2","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-partuuid/ccc9f970-2119-4346-9b6c-73c8aabb7c27 /dev/disk/by-id/usb-Seagate_One_Touch_w_PW_00000000NAE55J2L-0:0-part2 /dev/disk/by-uuid/c82d83c3-0d29-43e3-aab8-76cbe7868723 /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0-scsi-0:0:0:0-part2","DEVNAME":"/dev/sda2","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda2","DEVTYPE":"partition","DISKSEQ":"26","ID_BUS":"usb","ID_FS_TYPE":"ext4","ID_FS_USAGE":"filesystem","ID_FS_UUID":"c82d83c3-0d29-43e3-aab8-76cbe7868723","ID_FS_UUID_ENC":"c82d83c3-0d29-43e3-aab8-76cbe7868723","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"One_Touch_w_PW","ID_MODEL_ENC":"One\\x20Touch\\x20w\\x2fPW\\x20\\x20","ID_MODEL_ID":"ab6f","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"2","ID_PART_ENTRY_OFFSET":"411648","ID_PART_ENTRY_SCHEME":"gpt","ID_PART_ENTRY_SIZE":"7813623808","ID_PART_ENTRY_TYPE":"ebd0a0a2-b9e5-4433-87c0-68b6b72699c7","ID_PART_ENTRY_UUID":"ccc9f970-2119-4346-9b6c-73c8aabb7c27","ID_PART_TABLE_TYPE":"gpt","ID_PART_TABLE_UUID":"907aee92-6e20-4f3f-8820-c255f51d7db6","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_3_1_0-scsi-0_0_0_0","ID_REVISION":"1708","ID_SERIAL":"Seagate_One_Touch_w_PW_00000000NAE55J2L-0:0","ID_SERIAL_SHORT":"00000000NAE55J2L","ID_TYPE":"disk","ID_USB_DRIVER":"uas","ID_USB_INSTANCE":"0:0","ID_USB_INTERFACES":":080650:080662:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"One_Touch_w_PW","ID_USB_MODEL_ENC":"One\\x20Touch\\x20w\\x2fPW\\x20\\x20","ID_USB_MODEL_ID":"ab6f","ID_USB_REVISION":"1708","ID_USB_SERIAL":"Seagate_One_Touch_w_PW_00000000NAE55J2L-0:0","ID_USB_SERIAL_SHORT":"00000000NAE55J2L","ID_USB_TYPE":"disk","ID_USB_VENDOR":"Seagate","ID_USB_VENDOR_ENC":"Seagate\\x20","ID_USB_VENDOR_ID":"0bc2","ID_VENDOR":"Seagate","ID_VENDOR_ENC":"Seagate\\x20","ID_VENDOR_ID":"0bc2","MAJOR":"8","MINOR":"2","PARTN":"2","SEQNUM":"2764","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"6556872"} Apr 03 19:12:23 volumio volumio[1261]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-partuuid/a8c85be8-26d4-4846-a90a-1579ddb6cbf9 /dev/disk/by-uuid/ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0-scsi-0:0:0:0-part1 /dev/disk/by-partlabel/EFI\\x20System\\x20Partition /dev/disk/by-id/usb-Seagate_One_Touch_w_PW_00000000NAE55J2L-0:0-part1","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"26","ID_BUS":"usb","ID_FS_TYPE":"ext4","ID_FS_USAGE":"filesystem","ID_FS_UUID":"ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc","ID_FS_UUID_ENC":"ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"One_Touch_w_PW","ID_MODEL_ENC":"One\\x20Touch\\x20w\\x2fPW\\x20\\x20","ID_MODEL_ID":"ab6f","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NAME":"EFI\\x20System\\x20Partition","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"40","ID_PART_ENTRY_SCHEME":"gpt","ID_PART_ENTRY_SIZE":"409600","ID_PART_ENTRY_TYPE":"c12a7328-f81f-11d2-ba4b-00a0c93ec93b","ID_PART_ENTRY_UUID":"a8c85be8-26d4-4846-a90a-1579ddb6cbf9","ID_PART_TABLE_TYPE":"gpt","ID_PART_TABLE_UUID":"907aee92-6e20-4f3f-8820-c255f51d7db6","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.3:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_3_1_0-scsi-0_0_0_0","ID_REVISION":"1708","ID_SERIAL":"Seagate_One_Touch_w_PW_00000000NAE55J2L-0:0","ID_SERIAL_SHORT":"00000000NAE55J2L","ID_TYPE":"disk","ID_USB_DRIVER":"uas","ID_USB_INSTANCE":"0:0","ID_USB_INTERFACES":":080650:080662:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"One_Touch_w_PW","ID_USB_MODEL_ENC":"One\\x20Touch\\x20w\\x2fPW\\x20\\x20","ID_USB_MODEL_ID":"ab6f","ID_USB_REVISION":"1708","ID_USB_SERIAL":"Seagate_One_Touch_w_PW_00000000NAE55J2L-0:0","ID_USB_SERIAL_SHORT":"00000000NAE55J2L","ID_USB_TYPE":"disk","ID_USB_VENDOR":"Seagate","ID_USB_VENDOR_ENC":"Seagate\\x20","ID_USB_VENDOR_ID":"0bc2","ID_VENDOR":"Seagate","ID_VENDOR_ENC":"Seagate\\x20","ID_VENDOR_ID":"0bc2","MAJOR":"8","MINOR":"1","PARTN":"1","PARTNAME":"EFI System Partition","SEQNUM":"2763","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"6554688"} Apr 03 19:12:25 volumio kernel: usb 1-1.3: new high-speed USB device number 4 using xhci_hcd Apr 03 19:12:25 volumio kernel: usb 1-1.3: New USB device found, idVendor=0bc2, idProduct=ab6f, bcdDevice=17.08 Apr 03 19:12:25 volumio kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 03 19:12:25 volumio kernel: usb 1-1.3: Product: One Touch w/PW Apr 03 19:12:25 volumio kernel: usb 1-1.3: Manufacturer: Seagate Apr 03 19:12:25 volumio kernel: usb 1-1.3: SerialNumber: 00000000NAE55J2L Apr 03 19:12:25 volumio kernel: scsi host1: uas Apr 03 19:12:25 volumio kernel: scsi 1:0:0:0: Direct-Access Seagate One Touch w/PW 1708 PQ: 0 ANSI: 6 Apr 03 19:12:25 volumio kernel: sd 1:0:0:0: Attached scsi generic sg0 type 0 Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] 7814037167 512-byte logical blocks: (4.00 TB/3.64 TiB) Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] 4096-byte physical blocks Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] Write Protect is off Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] Mode Sense: 03 00 00 00 Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] Preferred minimum I/O size 4096 bytes Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] Optimal transfer size 33553920 bytes not a multiple of preferred minimum block size (4096 bytes) Apr 03 19:12:31 volumio kernel: GPT:disk_guids don't match. Apr 03 19:12:31 volumio kernel: GPT:partition_entry_array_crc32 values don't match: 0xf12e5b52 != 0xbe4040c1 Apr 03 19:12:31 volumio kernel: GPT: Use GNU Parted to correct GPT errors. Apr 03 19:12:31 volumio kernel: sdb: sdb1 sdb2 Apr 03 19:12:31 volumio kernel: sd 1:0:0:0: [sdb] Attached SCSI disk Apr 03 19:12:32 volumio volumio[1261]: info: Mounting Device c82d83c3-0d29-43e3-aab8-76cbe7868723 Apr 03 19:12:32 volumio volumio[1261]: /bin/mkdir: cannot create directory ‘/mnt/USB/c82d83c3-0d29-43e3-aab8-76cbe7868723’: File exists Apr 03 19:12:32 volumio volumio[1261]: error: Failed to create folder Error: Command failed: /bin/mkdir -m 777 "/mnt/USB/c82d83c3-0d29-43e3-aab8-76cbe7868723" Apr 03 19:12:32 volumio volumio[1261]: /bin/mkdir: cannot create directory ‘/mnt/USB/c82d83c3-0d29-43e3-aab8-76cbe7868723’: File exists Apr 03 19:12:32 volumio sudo[2385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb2 /mnt/USB/c82d83c3-0d29-43e3-aab8-76cbe7868723 -o noatime Apr 03 19:12:32 volumio sudo[2385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 19:12:32 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 8. Apr 03 19:12:32 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:32 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:32 volumio upmpdcli[2387]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:12:32 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:12:32 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:12:33 volumio sudo[2385]: pam_unix(sudo:session): session closed for user root Apr 03 19:12:33 volumio kernel: EXT4-fs (sdb2): recovery complete Apr 03 19:12:33 volumio kernel: EXT4-fs (sdb2): mounted filesystem c82d83c3-0d29-43e3-aab8-76cbe7868723 r/w with ordered data mode. Quota mode: none. Apr 03 19:12:33 volumio volumio[1261]: info: Mounting Device ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc Apr 03 19:12:33 volumio volumio[1261]: /bin/mkdir: cannot create directory ‘/mnt/USB/ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc’: File exists Apr 03 19:12:33 volumio volumio[1261]: error: Failed to create folder Error: Command failed: /bin/mkdir -m 777 "/mnt/USB/ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc" Apr 03 19:12:33 volumio volumio[1261]: /bin/mkdir: cannot create directory ‘/mnt/USB/ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc’: File exists Apr 03 19:12:33 volumio sudo[2400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb1 /mnt/USB/ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc -o noatime Apr 03 19:12:33 volumio sudo[2400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 19:12:34 volumio sudo[2400]: pam_unix(sudo:session): session closed for user root Apr 03 19:12:34 volumio kernel: EXT4-fs (sdb1): recovery complete Apr 03 19:12:34 volumio kernel: EXT4-fs (sdb1): mounted filesystem ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc r/w with ordered data mode. Quota mode: none. Apr 03 19:12:34 volumio kernel: ext4 filesystem being mounted at /media/ed65bdb7-bbb7-464d-8e91-0ee1b98c88cc supports timestamps until 2038-01-19 (0x7fffffff) Apr 03 19:12:36 volumio volumio[1261]: info: CoreCommandRouter::volumioPlay Apr 03 19:12:36 volumio volumio[1261]: info: CoreStateMachine::play index undefined Apr 03 19:12:36 volumio volumio[1261]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 19:12:36 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:39 volumio volumio[1261]: info: CoreCommandRouter::volumioPlay Apr 03 19:12:39 volumio volumio[1261]: info: CoreStateMachine::play index undefined Apr 03 19:12:39 volumio volumio[1261]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 19:12:39 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:41 volumio volumio[1261]: info: CoreCommandRouter::volumioPlay Apr 03 19:12:41 volumio volumio[1261]: info: CoreStateMachine::play index undefined Apr 03 19:12:41 volumio volumio[1261]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 19:12:41 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:42 volumio volumio[1261]: info: CoreCommandRouter::volumioPlay Apr 03 19:12:42 volumio volumio[1261]: info: CoreStateMachine::play index undefined Apr 03 19:12:42 volumio volumio[1261]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 19:12:42 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:43 volumio volumio[1261]: info: CoreCommandRouter::volumioPlay Apr 03 19:12:43 volumio volumio[1261]: info: CoreStateMachine::play index undefined Apr 03 19:12:43 volumio volumio[1261]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 19:12:43 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:12:47 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 9. Apr 03 19:12:47 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:47 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:12:47 volumio upmpdcli[2433]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:12:47 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:12:47 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:12:48 volumio nmbd[1135]: [2026/04/03 19:12:48.847635, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Apr 03 19:12:48 volumio nmbd[1135]: Packet send failed to 192.168.219.255(138) ERRNO=Network is unreachable Apr 03 19:13:02 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 10. Apr 03 19:13:02 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:13:02 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:13:02 volumio upmpdcli[2448]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:13:02 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:13:02 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:13:05 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:13:05 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:13:05 volumio volumio[1261]: info: Retrieving Cloud Streaming UI Apr 03 19:13:05 volumio volumio[1261]: info: Getting Tidal Cloud Configuration Apr 03 19:13:05 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:13:05 volumio volumio[1261]: info: Getting Qobuz Cloud Configuration Apr 03 19:13:05 volumio volumio[1261]: info: Asking plugin for UI Config Apr 03 19:13:05 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:13:05 volumio volumio[1261]: info: Getting Spotify Cloud Configuration Apr 03 19:13:05 volumio volumio[1261]: info: Asking plugin for UI Config Apr 03 19:13:05 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:13:05 volumio volumio[1261]: info: Saving Spotify Acccount Apr 03 19:13:05 volumio volumio[1261]: info: Got Tidal Cloud Configuration Apr 03 19:13:05 volumio volumio[1261]: info: Got it Apr 03 19:13:05 volumio volumio[1261]: info: Got it Apr 03 19:13:05 volumio volumio[1261]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 03 19:13:05 volumio volumio[1261]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 19:13:05 volumio volumio[1261]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::volumioGetBrowseSources Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::volumioGetBrowseSources Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::volumioGetBrowseSources Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:06 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 03 19:13:09 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Apr 03 19:13:09 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Apr 03 19:13:10 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:14 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand update Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:14 volumio volumio[1261]: info: Apr 03 19:13:14 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand update took 28 milliseconds Apr 03 19:13:14 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:14 volumio volumio[1261]: info: Apr 03 19:13:14 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:14 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:14 volumio volumio[1261]: info: Apr 03 19:13:14 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:14 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand status took 70 milliseconds Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand status took 67 milliseconds Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand status took 67 milliseconds Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand status took 66 milliseconds Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand status took 65 milliseconds Apr 03 19:13:14 volumio volumio[1261]: info: sendMpdCommand status took 64 milliseconds Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:14 volumio volumio[1261]: info: Command Router : Notfying DB Updatetrue Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:14 volumio volumio[1261]: info: Command Router : Notfying DB Updatetrue Apr 03 19:13:14 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:14 volumio volumio[1261]: info: Command Router : Notfying DB Updatetrue Apr 03 19:13:14 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:14 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:15 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: No code Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:15 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: No code Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:15 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: No code Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.252+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.253+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.253+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.253+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.254+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.254+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.254+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.255+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.298+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.298+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.299+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.299+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.302+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.302+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.302+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.302+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.303+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.303+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.303+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.303+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.304+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.304+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.304+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.304+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.305+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.305+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.305+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.306+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.306+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.306+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.307+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:15 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:15.307+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:15 volumio volumio[1261]: info: ------------------------------ 914ms Apr 03 19:13:15 volumio volumio[1261]: info: ------------------------------ 911ms Apr 03 19:13:15 volumio volumio[1261]: info: ------------------------------ 910ms Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:15 volumio volumio[1261]: info: Apr 03 19:13:15 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:15 volumio volumio[1261]: info: Apr 03 19:13:15 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:15 volumio volumio[1261]: info: Apr 03 19:13:15 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:15 volumio volumio[1261]: info: sendMpdCommand status took 145 milliseconds Apr 03 19:13:15 volumio volumio[1261]: info: sendMpdCommand status took 145 milliseconds Apr 03 19:13:15 volumio volumio[1261]: info: sendMpdCommand status took 37 milliseconds Apr 03 19:13:15 volumio volumio[1261]: info: sendMpdCommand status took 3 milliseconds Apr 03 19:13:15 volumio volumio[1261]: info: sendMpdCommand status took 3 milliseconds Apr 03 19:13:15 volumio volumio[1261]: info: sendMpdCommand status took 2 milliseconds Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:15 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:15 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: No code Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:15 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: No code Apr 03 19:13:15 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:15 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:15 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:16 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:16 volumio volumio[1261]: info: No code Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.153+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.154+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.154+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.154+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.155+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.155+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.155+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.155+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.156+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.156+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.156+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.156+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.157+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.157+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.157+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.157+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.208+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.209+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.209+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.210+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.210+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.210+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.210+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.211+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.211+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.212+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.212+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.212+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.212+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.213+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.213+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.213+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.213+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.217+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.217+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.218+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio[1261]: info: ------------------------------ 904ms Apr 03 19:13:16 volumio volumio[1261]: info: ------------------------------ 813ms Apr 03 19:13:16 volumio volumio[1261]: info: ------------------------------ 779ms Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand rescan Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: info: Apr 03 19:13:16 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand rescan took 47 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: info: Apr 03 19:13:16 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:16 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 3 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 2 milliseconds Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:16 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:16 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:16 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:16 volumio volumio[1261]: info: No code Apr 03 19:13:16 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:16 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.738+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.739+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.739+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.739+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.739+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.740+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.740+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.740+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.741+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.741+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.741+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:16 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:16.741+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:16 volumio volumio[1261]: info: ------------------------------ 185ms Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: info: Apr 03 19:13:16 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:16 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: info: Apr 03 19:13:16 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:16 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 228 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 227 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 44 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 43 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 43 milliseconds Apr 03 19:13:16 volumio volumio[1261]: info: sendMpdCommand status took 42 milliseconds Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:16 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:16 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:16 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:16 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:17 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:17 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: No code Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:17 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: No code Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:17 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: No code Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.237+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.238+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.238+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.238+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.296+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.296+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.297+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.297+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.298+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.298+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.298+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.298+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.300+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.300+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.301+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.301+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.301+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.301+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.302+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.302+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.302+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.302+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.303+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.303+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.303+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.303+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.304+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.304+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.304+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.305+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.359+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.359+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.359+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:17 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:17.359+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:17 volumio volumio[1261]: info: ------------------------------ 857ms Apr 03 19:13:17 volumio volumio[1261]: info: ------------------------------ 674ms Apr 03 19:13:17 volumio volumio[1261]: info: ------------------------------ 673ms Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:17 volumio volumio[1261]: info: Apr 03 19:13:17 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:17 volumio volumio[1261]: info: Apr 03 19:13:17 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:17 volumio volumio[1261]: info: sendMpdCommand status took 167 milliseconds Apr 03 19:13:17 volumio volumio[1261]: info: sendMpdCommand status took 180 milliseconds Apr 03 19:13:17 volumio volumio[1261]: info: sendMpdCommand status took 183 milliseconds Apr 03 19:13:17 volumio volumio[1261]: info: sendMpdCommand status took 184 milliseconds Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:17 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:17 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:17 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:17 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: No code Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:17 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:17 volumio volumio[1261]: info: No code Apr 03 19:13:17 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:17 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:17 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.094+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.094+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.094+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.094+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:18 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11. Apr 03 19:13:18 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.106+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.106+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.106+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.106+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.114+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.114+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.114+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.115+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.126+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.126+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.126+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.127+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.131+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.131+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.131+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.131+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.137+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.137+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.137+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:18 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:18.137+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:18 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:13:18 volumio volumio[1261]: info: ------------------------------ 759ms Apr 03 19:13:18 volumio volumio[1261]: info: ------------------------------ 778ms Apr 03 19:13:18 volumio upmpdcli[2521]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:13:18 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:13:18 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:13:18 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:22 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:26 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:30 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:33 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 12. Apr 03 19:13:33 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:13:33 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 19:13:33 volumio upmpdcli[2537]: Could not open config: /tmp/upmpdcli.conf Apr 03 19:13:33 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 19:13:33 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 19:13:34 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand rescan Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: info: Apr 03 19:13:37 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand rescan took 3 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: info: Apr 03 19:13:37 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:37 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 3 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 2 milliseconds Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:37 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:37 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:37 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:37 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:37 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:37 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:37 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:37 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:37 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:37 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:37 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:37 volumio volumio[1261]: info: No code Apr 03 19:13:37 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:37 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.838+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.838+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.838+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.838+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.841+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.841+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.841+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.841+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.858+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.858+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.858+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:37 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:37.858+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:37 volumio volumio[1261]: info: ------------------------------ 251ms Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: info: Apr 03 19:13:37 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:37 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: info: Apr 03 19:13:37 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:37 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 296 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 296 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 46 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 21 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 20 milliseconds Apr 03 19:13:37 volumio volumio[1261]: info: sendMpdCommand status took 20 milliseconds Apr 03 19:13:37 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:37 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:37 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:38 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: No code Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:38 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: No code Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:38 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: No code Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.478+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.478+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.480+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.480+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.482+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.488+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.489+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.489+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.489+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.489+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.489+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.490+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.491+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.492+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:38 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:38.492+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:38 volumio volumio[1261]: info: ------------------------------ 900ms Apr 03 19:13:38 volumio volumio[1261]: info: ------------------------------ 676ms Apr 03 19:13:38 volumio volumio[1261]: info: ------------------------------ 649ms Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:38 volumio volumio[1261]: info: Apr 03 19:13:38 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:38 volumio volumio[1261]: info: Apr 03 19:13:38 volumio volumio[1261]: ---------------------------- MPD announces state update: update Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::getState Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::sendMpdCommand status Apr 03 19:13:38 volumio volumio[1261]: info: sendMpdCommand status took 94 milliseconds Apr 03 19:13:38 volumio volumio[1261]: info: sendMpdCommand status took 126 milliseconds Apr 03 19:13:38 volumio volumio[1261]: info: sendMpdCommand status took 126 milliseconds Apr 03 19:13:38 volumio volumio[1261]: info: sendMpdCommand status took 124 milliseconds Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: info: Command Router : Notfying DB Updatefalse Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::Close All Modals sent Apr 03 19:13:38 volumio volumio[1261]: verbose: ControllerMpd::parseState Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:38 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: No code Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: ControllerMpd::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::servicePushState Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 19:13:38 volumio volumio[1261]: verbose: CURRENT POSITION 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState stateService stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::syncState currentStatus stop Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:38 volumio volumio[1261]: info: No code Apr 03 19:13:38 volumio volumio[1261]: info: CoreStateMachine::pushState Apr 03 19:13:38 volumio volumio[1261]: info: CorePlayQueue::getTrack 0 Apr 03 19:13:38 volumio volumio[1261]: info: CoreCommandRouter::volumioPushState Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.008+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.008+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.008+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.008+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.011+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.011+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.011+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.011+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.018+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.018+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.018+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.018+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:39 volumio volumio[1261]: info: ------------------------------ 485ms Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.026+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.026+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player state changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.162:49622,00:00:00:00:00:00%01,122.40.182.39:58156 @ 0x2f107b0" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:39 volumio volumio5-onboarding[1907]: time=2026-04-03T19:13:39.027+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="122.40.182.39:58156 @ 0x2d50090" id= title= Apr 03 19:13:39 volumio volumio[1261]: info: ------------------------------ 525ms Apr 03 19:13:39 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 03 19:13:39 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Apr 03 19:13:39 volumio volumio[1261]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Apr 03 19:13:39 volumio volumio[1261]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 19:13:39 volumio volumio[1261]: Error: getaddrinfo -3007 Apr 03 19:13:39 volumio volumio[1261]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Apr 03 19:13:39 volumio volumio[1261]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Apr 03 19:13:39 volumio volumio[1261]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Apr 03 19:13:39 volumio volumio[1261]: code: -3007, Apr 03 19:13:39 volumio volumio[1261]: errno: -3007, Apr 03 19:13:39 volumio volumio[1261]: syscall: 'getaddrinfo' Apr 03 19:13:39 volumio volumio[1261]: } Apr 03 19:13:39 volumio volumio[1261]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 19:13:43 volumio sudo[2588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-03 19:12' Apr 03 19:13:43 volumio sudo[2588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"