-- Logs begin at Tue 2024-10-22 14:55:55 +07, end at Tue 2024-10-22 15:04:59 +07. -- Oct 22 15:03:00 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:03:00 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:03:03 volumio volumio[1219]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 22 15:03:03 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 22 15:03:03 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 22 15:03:03 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 22 15:03:03 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 22 15:03:03 volumio volumio[1219]: info: Received Get System Version Oct 22 15:03:03 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 22 15:03:26 volumio volumio[1219]: info: CALLMETHOD: system_controller system setLanguageTimezone [object Object] Oct 22 15:03:26 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , setLanguageTimezone Oct 22 15:03:26 volumio volumio[1219]: info: Setting timezone to Asia/Saigon Oct 22 15:03:26 volumio sudo[2773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Oct 22 15:03:26 volumio sudo[2773]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:03:26 volumio sudo[2773]: pam_unix(sudo:session): session closed for user root Oct 22 15:03:26 volumio sudo[2776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Saigon /etc/localtime Oct 22 15:03:26 volumio sudo[2776]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:03:26 volumio sudo[2776]: pam_unix(sudo:session): session closed for user root Oct 22 15:03:26 volumio sudo[2779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Oct 22 15:03:26 volumio sudo[2779]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:03:26 volumio sudo[2779]: pam_unix(sudo:session): session closed for user root Oct 22 15:03:26 volumio sudo[2782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Saigon Oct 22 15:03:26 volumio sudo[2782]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:03:26 volumio dbus-daemon[809]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.31' (uid=0 pid=2783 comm="/usr/bin/timedatectl set-timezone Asia/Saigon ") Oct 22 15:03:26 volumio systemd[1]: Starting Time & Date Service... Oct 22 15:03:26 volumio dbus-daemon[809]: [system] Successfully activated service 'org.freedesktop.timedate1' Oct 22 15:03:26 volumio systemd[1]: Started Time & Date Service. Oct 22 15:03:26 volumio sudo[2782]: pam_unix(sudo:session): session closed for user root Oct 22 15:03:26 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Oct 22 15:03:26 volumio volumio[1219]: info: Loading i18n strings for locale vi Oct 22 15:03:26 volumio volumio[1219]: Updating browse sources language Oct 22 15:03:26 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 22 15:03:26 volumio volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Oct 22 15:03:26 volumio volumio[1219]: info: Fetching Streaming Services browse cache Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::volumioGetVisibleSources Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:03:29 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 22 15:03:29 volumio volumio[1219]: info: Received Get System Info Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 22 15:03:29 volumio volumio[1219]: info: Discovery: Getting this device information Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:03:29 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:03:29 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:03:29 volumio volumio[1219]: info: Listing playlists Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 22 15:03:29 volumio volumio[1219]: info: Received Get System Info Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 22 15:03:29 volumio volumio[1219]: info: Discovery: Getting this device information Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:03:29 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 22 15:03:29 volumio volumio[1219]: info: Received Get System Version Oct 22 15:03:29 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 22 15:03:30 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 22 15:03:30 volumio volumio[1219]: info: Received Get System Info Oct 22 15:03:30 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 22 15:03:30 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 22 15:03:30 volumio volumio[1219]: info: Discovery: Getting this device information Oct 22 15:03:30 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:03:30 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:03:30 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 22 15:03:30 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 22 15:03:30 volumio kernel: usb 1-1.1: USB disconnect, device number 14 Oct 22 15:03:30 volumio kernel: device offline error, dev sdc, sector 64 op 0x1:(WRITE) flags 0x100000 phys_seg 1 prio class 2 Oct 22 15:03:30 volumio kernel: Buffer I/O error on dev sdc1, logical block 1, lost async page write Oct 22 15:03:30 volumio volumio[1219]: info: Partition removed: {"syspath":"/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.1/1-1.1:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc2","ACTION":"remove","DEVLINKS":"/dev/disk/by-path/pci-0000:00:1d.0-usb-0:1.1:1.0-scsi-0:0:0:0-part2 /dev/disk/by-id/usb-SSK_SHE088_0123456789AF169-0:0-part2 /dev/disk/by-partuuid/3c7d34b8-02 /dev/disk/by-uuid/0BE413040BE41304 /dev/disk/by-label/HDD-DATA","DEVNAME":"/dev/sdc2","DEVPATH":"/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.1/1-1.1:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc2","DEVTYPE":"partition","DISKSEQ":"18","ID_BUS":"usb","ID_FS_LABEL":"HDD-DATA","ID_FS_LABEL_ENC":"HDD-DATA","ID_FS_TYPE":"ntfs","ID_FS_USAGE":"filesystem","ID_FS_UUID":"0BE413040BE41304","ID_FS_UUID_ENC":"0BE413040BE41304","ID_INSTANCE":"0:0","ID_MODEL":"SHE088","ID_MODEL_ENC":"SHE088\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"1066","ID_PART_ENTRY_DISK":"8:32","ID_PART_ENTRY_NUMBER":"2","ID_PART_ENTRY_OFFSET":"19458048","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"214992896","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"3c7d34b8-02","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"3c7d34b8","ID_PATH":"pci-0000:00:1d.0-usb-0:1.1:1.0-scsi-0:0:0:0","ID_PATH_TAG":"pci-0000_00_1d_0-usb-0_1_1_1_0-scsi-0_0_0_0","ID_REVISION":"2.45","ID_SERIAL":"SSK_SHE088_0123456789AF169-0:0","ID_SERIAL_SHORT":"0123456789AF169","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"SSK","ID_VENDOR_ENC":"SSK\\x20\\x20\\x20\\x20\\x20","ID_VENDOR_ID":"2537","MAJOR":"8","MINOR":"34","PARTN":"2","SEQNUM":"3632","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"323485230"} Oct 22 15:03:30 volumio sudo[2800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sdc2 Oct 22 15:03:30 volumio sudo[2800]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:03:30 volumio ntfs-3g[2571]: Unmounting /dev/sdc2 (HDD-DATA) Oct 22 15:03:30 volumio sudo[2800]: pam_unix(sudo:session): session closed for user root Oct 22 15:03:30 volumio systemd[1]: media-HDD\x2dDATA.mount: Succeeded. Oct 22 15:03:30 volumio volumio[1219]: info: Partition removed: {"syspath":"/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.1/1-1.1:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc1","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/usb-SSK_SHE088_0123456789AF169-0:0-part1 /dev/disk/by-partuuid/3c7d34b8-01 /dev/disk/by-uuid/0BE2-0E1F /dev/disk/by-label/HDD-BOOT /dev/disk/by-path/pci-0000:00:1d.0-usb-0:1.1:1.0-scsi-0:0:0:0-part1","DEVNAME":"/dev/sdc1","DEVPATH":"/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.1/1-1.1:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc1","DEVTYPE":"partition","DISKSEQ":"18","ID_BUS":"usb","ID_FS_LABEL":"HDD-BOOT","ID_FS_LABEL_ENC":"HDD-BOOT","ID_FS_TYPE":"vfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"0BE2-0E1F","ID_FS_UUID_ENC":"0BE2-0E1F","ID_FS_VERSION":"FAT32","ID_INSTANCE":"0:0","ID_MODEL":"SHE088","ID_MODEL_ENC":"SHE088\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"1066","ID_PART_ENTRY_DISK":"8:32","ID_PART_ENTRY_FLAGS":"0x80","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"63","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"19457985","ID_PART_ENTRY_TYPE":"0x1b","ID_PART_ENTRY_UUID":"3c7d34b8-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"3c7d34b8","ID_PATH":"pci-0000:00:1d.0-usb-0:1.1:1.0-scsi-0:0:0:0","ID_PATH_TAG":"pci-0000_00_1d_0-usb-0_1_1_1_0-scsi-0_0_0_0","ID_REVISION":"2.45","ID_SERIAL":"SSK_SHE088_0123456789AF169-0:0","ID_SERIAL_SHORT":"0123456789AF169","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_VENDOR":"SSK","ID_VENDOR_ENC":"SSK\\x20\\x20\\x20\\x20\\x20","ID_VENDOR_ID":"2537","MAJOR":"8","MINOR":"33","PARTN":"1","SEQNUM":"3631","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"323493324"} Oct 22 15:03:30 volumio sudo[2803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sdc1 Oct 22 15:03:30 volumio sudo[2803]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:03:30 volumio sudo[2803]: pam_unix(sudo:session): session closed for user root Oct 22 15:03:30 volumio systemd[1]: media-HDD\x2dBOOT.mount: Succeeded. Oct 22 15:03:31 volumio kernel: usb 1-1.1: new high-speed USB device number 15 using ehci-pci Oct 22 15:03:31 volumio kernel: usb 1-1.1: New USB device found, idVendor=2537, idProduct=1066, bcdDevice= 1.00 Oct 22 15:03:31 volumio kernel: usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Oct 22 15:03:31 volumio kernel: usb 1-1.1: Product: SHE088(NS1066 2.45) Oct 22 15:03:31 volumio kernel: usb 1-1.1: Manufacturer: SSK Oct 22 15:03:31 volumio kernel: usb 1-1.1: SerialNumber: 0123456789AF169 Oct 22 15:03:31 volumio kernel: usb-storage 1-1.1:1.0: USB Mass Storage device detected Oct 22 15:03:31 volumio kernel: scsi host7: usb-storage 1-1.1:1.0 Oct 22 15:03:31 volumio kernel: usb 1-1.1: USB disconnect, device number 15 Oct 22 15:03:31 volumio kernel: usb 1-1.1: new high-speed USB device number 16 using ehci-pci Oct 22 15:03:31 volumio kernel: usb 1-1.1: New USB device found, idVendor=2537, idProduct=1066, bcdDevice= 1.00 Oct 22 15:03:31 volumio kernel: usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Oct 22 15:03:31 volumio kernel: usb 1-1.1: Product: SHE088(NS1066 2.45) Oct 22 15:03:31 volumio kernel: usb 1-1.1: Manufacturer: SSK Oct 22 15:03:31 volumio kernel: usb 1-1.1: SerialNumber: 0123456789AF169 Oct 22 15:03:31 volumio kernel: usb-storage 1-1.1:1.0: USB Mass Storage device detected Oct 22 15:03:31 volumio kernel: scsi host7: usb-storage 1-1.1:1.0 Oct 22 15:03:32 volumio kernel: usb 1-1.1: USB disconnect, device number 16 Oct 22 15:03:32 volumio kernel: usb 1-1.1: new high-speed USB device number 17 using ehci-pci Oct 22 15:03:33 volumio kernel: usb 1-1.1: device descriptor read/64, error -71 Oct 22 15:03:33 volumio kernel: usb 1-1.1: New USB device found, idVendor=2537, idProduct=1066, bcdDevice= 1.00 Oct 22 15:03:33 volumio kernel: usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Oct 22 15:03:33 volumio kernel: usb 1-1.1: Product: SHE088(NS1066 2.45) Oct 22 15:03:33 volumio kernel: usb 1-1.1: Manufacturer: SSK Oct 22 15:03:33 volumio kernel: usb 1-1.1: SerialNumber: 0123456789AF169 Oct 22 15:03:33 volumio kernel: usb-storage 1-1.1:1.0: USB Mass Storage device detected Oct 22 15:03:33 volumio kernel: scsi host7: usb-storage 1-1.1:1.0 Oct 22 15:03:34 volumio volumio[1219]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/HDD-DATA Oct 22 15:03:34 volumio volumio[1219]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/HDD-BOOT Oct 22 15:03:35 volumio volumio[1219]: info: Scanning removed location : "USB/HDD-BOOT" Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: info: Oct 22 15:03:35 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:03:35 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: info: Oct 22 15:03:35 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:03:35 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: info: Oct 22 15:03:35 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:03:35 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: info: Oct 22 15:03:35 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:03:35 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:03:35 volumio volumio[1219]: info: sendMpdCommand status took 5 milliseconds Oct 22 15:03:35 volumio volumio[1219]: info: sendMpdCommand status took 4 milliseconds Oct 22 15:03:35 volumio volumio[1219]: info: sendMpdCommand status took 4 milliseconds Oct 22 15:03:35 volumio volumio[1219]: info: sendMpdCommand status took 3 milliseconds Oct 22 15:03:35 volumio volumio[1219]: info: sendMpdCommand status took 3 milliseconds Oct 22 15:03:35 volumio volumio[1219]: info: sendMpdCommand status took 3 milliseconds Oct 22 15:03:35 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:03:36 volumio kernel: scsi 7:0:0:0: Direct-Access SSK SHE088 2.45 PQ: 0 ANSI: 6 Oct 22 15:03:36 volumio kernel: sd 7:0:0:0: Attached scsi generic sg3 type 0 Oct 22 15:03:36 volumio kernel: sd 7:0:0:0: [sdc] 234455040 512-byte logical blocks: (120 GB/112 GiB) Oct 22 15:03:36 volumio kernel: sd 7:0:0:0: [sdc] Write Protect is off Oct 22 15:03:36 volumio kernel: sd 7:0:0:0: [sdc] Mode Sense: 43 00 00 00 Oct 22 15:03:36 volumio kernel: sd 7:0:0:0: [sdc] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA Oct 22 15:03:36 volumio kernel: sdc: sdc1 sdc2 Oct 22 15:03:36 volumio kernel: sd 7:0:0:0: [sdc] Attached SCSI disk Oct 22 15:03:43 volumio volumio-remote-updater[819]: [2024-10-22 15:03:43] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Oct 22 15:03:48 volumio volumio-remote-updater[819]: [2024-10-22 15:03:48] [connect] Successful connection Oct 22 15:03:50 volumio ntpd[1518]: Soliciting pool server 115.165.161.155 Oct 22 15:03:53 volumio ntpd[1518]: Soliciting pool server 103.184.124.23 Oct 22 15:03:56 volumio systemd[1]: systemd-timedated.service: Succeeded. Oct 22 15:03:57 volumio ntpd[1518]: Soliciting pool server 2404:fbc0:0:2046::c Oct 22 15:03:59 volumio ntpd[1518]: Soliciting pool server 103.184.124.23 Oct 22 15:04:01 volumio volumio-remote-updater[819]: [2024-10-22 15:04:01] [connect] Successful connection Oct 22 15:04:05 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:05 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:05 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:05 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:11 volumio volumio[1219]: info: ------------------------------ 35891ms Oct 22 15:04:11 volumio volumio[1219]: info: ------------------------------ 35890ms Oct 22 15:04:11 volumio volumio[1219]: info: ------------------------------ 35889ms Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:11 volumio volumio[1219]: info: Oct 22 15:04:11 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:11 volumio volumio[1219]: info: Oct 22 15:04:11 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 22 15:04:11 volumio volumio[1219]: info: sendMpdCommand status took 35898 milliseconds Oct 22 15:04:11 volumio volumio[1219]: info: sendMpdCommand status took 35898 milliseconds Oct 22 15:04:11 volumio volumio[1219]: info: sendMpdCommand status took 10 milliseconds Oct 22 15:04:11 volumio volumio[1219]: info: sendMpdCommand status took 9 milliseconds Oct 22 15:04:11 volumio volumio[1219]: info: sendMpdCommand status took 9 milliseconds Oct 22 15:04:11 volumio volumio[1219]: info: sendMpdCommand status took 8 milliseconds Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:11 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:11 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:11 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:11 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:11 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:11 volumio volumio[1219]: info: ------------------------------ 35950ms Oct 22 15:04:11 volumio volumio[1219]: info: ------------------------------ 62ms Oct 22 15:04:11 volumio volumio[1219]: info: ------------------------------ 61ms Oct 22 15:04:11 volumio volumio[1219]: info: Mounting Device HDD-DATA Oct 22 15:04:11 volumio sudo[2887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdc2 /mnt/USB/HDD-DATA -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 22 15:04:11 volumio sudo[2887]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:04:12 volumio ntfs-3g[2890]: Version 2017.3.23AR.3 integrated FUSE 28 Oct 22 15:04:12 volumio ntfs-3g[2890]: Mounted /dev/sdc2 (Read-Write, label "HDD-DATA", NTFS 3.1) Oct 22 15:04:12 volumio ntfs-3g[2890]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 22 15:04:12 volumio ntfs-3g[2890]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sdc2,blkdev,blksize=4096 Oct 22 15:04:12 volumio ntfs-3g[2890]: Global ownership and permissions enforced, configuration type 7 Oct 22 15:04:12 volumio sudo[2887]: pam_unix(sudo:session): session closed for user root Oct 22 15:04:12 volumio volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 22 15:04:12 volumio volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 22 15:04:12 volumio volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Oct 22 15:04:12 volumio volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Oct 22 15:04:12 volumio volumio[1219]: info: Mounting Device HDD-BOOT Oct 22 15:04:12 volumio sudo[2896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdc1 /mnt/USB/HDD-BOOT -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 22 15:04:12 volumio sudo[2896]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 22 15:04:12 volumio kernel: FAT-fs (sdc1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Oct 22 15:04:12 volumio sudo[2896]: pam_unix(sudo:session): session closed for user root Oct 22 15:04:12 volumio kernel: FAT-fs (sdc1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioGetVisibleSources Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 22 15:04:12 volumio volumio[1219]: info: Received Get System Info Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 22 15:04:12 volumio volumio[1219]: info: Discovery: Getting this device information Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Listing playlists Oct 22 15:04:12 volumio volumio[1219]: info: Scanning new location : "USB/HDD-DATA" Oct 22 15:04:12 volumio volumio[1219]: info: Scanning new location : "USB/HDD-BOOT" Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 6 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 5 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 5 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 4 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 5 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 4 milliseconds Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatetrue Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatetrue Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatetrue Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 220ms Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 219ms Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 221ms Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 15 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 15 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 14 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 13 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 12 milliseconds Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatetrue Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatetrue Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatetrue Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 127ms Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 125ms Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 123ms Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: Oct 22 15:04:12 volumio volumio[1219]: ---------------------------- MPD announces state update: update Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::getState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::sendMpdCommand status Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 3 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 2 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 2 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 3 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 2 milliseconds Oct 22 15:04:12 volumio volumio[1219]: info: sendMpdCommand status took 1 milliseconds Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: Command Router : Notfying DB Updatefalse Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Oct 22 15:04:12 volumio volumio[1219]: verbose: ControllerMpd::parseState Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ControllerMpd::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::servicePushState Oct 22 15:04:12 volumio volumio[1219]: info: CoreStateMachine::pushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Oct 22 15:04:12 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:12 volumio volumio[1219]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 45ms Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 45ms Oct 22 15:04:12 volumio volumio[1219]: info: ------------------------------ 44ms Oct 22 15:04:13 volumio volumio[1219]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 22 15:04:13 volumio volumio[1219]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 22 15:04:13 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:04:13 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:16 volumio volumio-remote-updater[819]: [2024-10-22 15:04:16] [connect] Successful connection Oct 22 15:04:16 volumio volumio-remote-updater[819]: [2024-10-22 15:04:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729584256 101 Oct 22 15:04:16 volumio volumio[1219]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 7 Oct 22 15:04:23 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Oct 22 15:04:23 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Oct 22 15:04:26 volumio volumio[1219]: info: CoreCommandRouter::volumioGetQueue Oct 22 15:04:26 volumio volumio[1219]: info: CoreStateMachine::getQueue Oct 22 15:04:26 volumio volumio[1219]: info: CorePlayQueue::getQueue Oct 22 15:04:31 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 22 15:04:31 volumio volumio[1219]: info: Preload queue cleared Oct 22 15:04:37 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 22 15:04:37 volumio volumio[1219]: info: Preload queue cleared Oct 22 15:04:39 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 22 15:04:39 volumio volumio[1219]: info: Preload queue cleared Oct 22 15:04:44 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 22 15:04:44 volumio volumio[1219]: info: Preload queue cleared Oct 22 15:04:54 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 22 15:04:54 volumio volumio[1219]: info: Preload queue cleared Oct 22 15:04:56 volumio ntpd[1518]: Soliciting pool server 103.184.124.23 Oct 22 15:04:58 volumio ntpd[1518]: Soliciting pool server 103.184.124.23 Oct 22 15:04:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 22 15:04:59 volumio volumio[1219]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 22 15:04:59 volumio volumio[1219]: TypeError: Cannot read property 'length' of undefined Oct 22 15:04:59 volumio volumio[1219]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 22 15:04:59 volumio volumio[1219]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 22 15:04:59 volumio volumio[1219]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 22 15:04:59 volumio volumio[1219]: at Parser.emit (events.js:400:28) Oct 22 15:04:59 volumio volumio[1219]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 22 15:04:59 volumio volumio[1219]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 22 15:04:59 volumio volumio[1219]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 22 15:04:59 volumio volumio[1219]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 22 15:04:59 volumio volumio[1219]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 22 15:04:59 volumio volumio[1219]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 22 15:04:59 volumio volumio[1219]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 22 15:04:59 volumio volumio[1219]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 22 15:04:59 volumio volumio[1219]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 22 15:04:59 volumio volumio[1219]: at IncomingMessage.emit (events.js:412:35) Oct 22 15:04:59 volumio volumio[1219]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 22 15:04:59 volumio volumio[1219]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 22 15:04:59 volumio volumio[1219]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 22 15:04:59 volumio sudo[2934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-22 15:03 Oct 22 15:04:59 volumio sudo[2934]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"