-- Logs begin at Wed 2024-07-03 18:49:57 CEST, end at Fri 2024-07-05 10:13:53 CEST. -- Jul 05 10:12:21 alessiochet kernel: usb 1-1.4: new high-speed USB device number 4 using dwc_otg Jul 05 10:12:22 alessiochet kernel: usb 1-1.4: device descriptor read/64, error -71 Jul 05 10:12:22 alessiochet kernel: usb 1-1.4: New USB device found, idVendor=1058, idProduct=07a8, bcdDevice=10.33 Jul 05 10:12:22 alessiochet kernel: usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Jul 05 10:12:22 alessiochet kernel: usb 1-1.4: Product: My Passport 07A8 Jul 05 10:12:22 alessiochet kernel: usb 1-1.4: Manufacturer: Western Digital Jul 05 10:12:22 alessiochet kernel: usb 1-1.4: SerialNumber: 5758513145383246544C4432 Jul 05 10:12:22 alessiochet kernel: usb-storage 1-1.4:1.0: USB Mass Storage device detected Jul 05 10:12:22 alessiochet kernel: scsi host0: usb-storage 1-1.4:1.0 Jul 05 10:12:23 alessiochet kernel: scsi 0:0:0:0: Direct-Access WD My Passport 07A8 1033 PQ: 0 ANSI: 6 Jul 05 10:12:23 alessiochet kernel: scsi 0:0:0:1: Enclosure WD SES Device 1033 PQ: 0 ANSI: 6 Jul 05 10:12:23 alessiochet kernel: sd 0:0:0:0: [sda] Spinning up disk... Jul 05 10:12:23 alessiochet kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Jul 05 10:12:23 alessiochet kernel: scsi 0:0:0:1: Attached scsi generic sg1 type 13 Jul 05 10:12:24 alessiochet kernel: .ready Jul 05 10:12:24 alessiochet kernel: sd 0:0:0:0: [sda] 1953458176 512-byte logical blocks: (1.00 TB/931 GiB) Jul 05 10:12:24 alessiochet kernel: sd 0:0:0:0: [sda] Write Protect is off Jul 05 10:12:24 alessiochet kernel: sd 0:0:0:0: [sda] Mode Sense: 53 00 10 08 Jul 05 10:12:24 alessiochet kernel: sd 0:0:0:0: [sda] No Caching mode page found Jul 05 10:12:24 alessiochet kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through Jul 05 10:12:24 alessiochet kernel: sda: sda1 Jul 05 10:12:24 alessiochet kernel: sd 0:0:0:0: [sda] Attached SCSI disk Jul 05 10:12:25 alessiochet volumio[28883]: info: Mounting Device Volume Jul 05 10:12:25 alessiochet sudo[900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Volume -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jul 05 10:12:25 alessiochet sudo[900]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 10:12:26 alessiochet ntfs-3g[903]: Version 2017.3.23AR.3 integrated FUSE 28 Jul 05 10:12:26 alessiochet ntfs-3g[903]: Mounted /dev/sda1 (Read-Write, label "Volume", NTFS 3.1) Jul 05 10:12:26 alessiochet ntfs-3g[903]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Jul 05 10:12:26 alessiochet ntfs-3g[903]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Jul 05 10:12:26 alessiochet ntfs-3g[903]: Global ownership and permissions enforced, configuration type 7 Jul 05 10:12:26 alessiochet sudo[900]: pam_unix(sudo:session): session closed for user root Jul 05 10:12:26 alessiochet volumio[28883]: info: Scanning new location : "USB/Volume" Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand status Jul 05 10:12:26 alessiochet volumio[28883]: info: Jul 05 10:12:26 alessiochet volumio[28883]: ---------------------------- MPD announces state update: update Jul 05 10:12:26 alessiochet volumio[28883]: info: ControllerMpd::getState Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand status Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand status Jul 05 10:12:26 alessiochet volumio[28883]: info: Jul 05 10:12:26 alessiochet volumio[28883]: ---------------------------- MPD announces state update: update Jul 05 10:12:26 alessiochet volumio[28883]: info: ControllerMpd::getState Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand status Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand status Jul 05 10:12:26 alessiochet volumio[28883]: info: Jul 05 10:12:26 alessiochet volumio[28883]: ---------------------------- MPD announces state update: update Jul 05 10:12:26 alessiochet volumio[28883]: info: ControllerMpd::getState Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand status Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand status took 14 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand status took 11 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand status took 11 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand status took 8 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand status took 6 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand status took 4 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseState Jul 05 10:12:26 alessiochet volumio[28883]: info: Command Router : Notfying DB Updatetrue Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseState Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseState Jul 05 10:12:26 alessiochet volumio[28883]: info: Command Router : Notfying DB Updatetrue Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::Close All Modals sent Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseState Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseState Jul 05 10:12:26 alessiochet volumio[28883]: info: Command Router : Notfying DB Updatetrue Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::Close All Modals sent Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseState Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand playlistinfo took 167 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand playlistinfo took 129 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: info: sendMpdCommand playlistinfo took 66 milliseconds Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseTrackInfo Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseTrackInfo Jul 05 10:12:26 alessiochet volumio[28883]: verbose: ControllerMpd::parseTrackInfo Jul 05 10:12:26 alessiochet volumio[28883]: info: ControllerMpd::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::servicePushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CorePlayQueue::getTrack 0 Jul 05 10:12:26 alessiochet volumio[28883]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1477734,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio Kiss Kiss Italia","artist":"Radio Kiss Kiss Italia","album":null,"uri":"https://kisskiss.fluidstream.eu/KKItalia.mp3?FLID=3","trackType":"mp3"} Jul 05 10:12:26 alessiochet volumio[28883]: verbose: CURRENT POSITION 0 Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::syncState stateService play Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::syncState currentStatus play Jul 05 10:12:26 alessiochet volumio[28883]: info: Received an update from plugin. extracting info from payload Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::volumioPushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::volumioPushState Jul 05 10:12:26 alessiochet volumio[28883]: info: ControllerMpd::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::servicePushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CorePlayQueue::getTrack 0 Jul 05 10:12:26 alessiochet volumio[28883]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1477860,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio Kiss Kiss Italia","artist":"Radio Kiss Kiss Italia","album":null,"uri":"https://kisskiss.fluidstream.eu/KKItalia.mp3?FLID=3","trackType":"mp3"} Jul 05 10:12:26 alessiochet volumio[28883]: verbose: CURRENT POSITION 0 Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::syncState stateService play Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::syncState currentStatus play Jul 05 10:12:26 alessiochet volumio[28883]: info: Received an update from plugin. extracting info from payload Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::volumioPushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::volumioPushState Jul 05 10:12:26 alessiochet volumio[28883]: info: ControllerMpd::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::servicePushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CorePlayQueue::getTrack 0 Jul 05 10:12:26 alessiochet volumio[28883]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1477860,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Radio Kiss Kiss Italia","artist":"Radio Kiss Kiss Italia","album":null,"uri":"https://kisskiss.fluidstream.eu/KKItalia.mp3?FLID=3","trackType":"mp3"} Jul 05 10:12:26 alessiochet volumio[28883]: verbose: CURRENT POSITION 0 Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::syncState stateService play Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::syncState currentStatus play Jul 05 10:12:26 alessiochet volumio[28883]: info: Received an update from plugin. extracting info from payload Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::volumioPushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreStateMachine::pushState Jul 05 10:12:26 alessiochet volumio[28883]: info: CoreCommandRouter::volumioPushState Jul 05 10:12:26 alessiochet volumio[28883]: info: ------------------------------ 596ms Jul 05 10:12:26 alessiochet volumio[28883]: info: ------------------------------ 593ms Jul 05 10:12:26 alessiochet volumio[28883]: info: ------------------------------ 589ms Jul 05 10:12:26 alessiochet volumio[28883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Jul 05 10:12:26 alessiochet volumio[28883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Jul 05 10:12:26 alessiochet volumio[28883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Jul 05 10:12:26 alessiochet volumio[28883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Jul 05 10:12:26 alessiochet volumio[28883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Jul 05 10:12:26 alessiochet volumio[28883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Jul 05 10:13:20 alessiochet volumio[28883]: info: CoreCommandRouter::volumioGetState Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 10:13:23 alessiochet volumio[28883]: info: Retrieving Cloud Streaming UI Jul 05 10:13:23 alessiochet volumio[28883]: info: Getting Tidal Cloud Configuration Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 10:13:23 alessiochet volumio[28883]: info: Getting Qobuz Cloud Configuration Jul 05 10:13:23 alessiochet volumio[28883]: info: Asking plugin for UI Config Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 10:13:23 alessiochet volumio[28883]: info: Getting Spotify Cloud Configuration Jul 05 10:13:23 alessiochet volumio[28883]: info: Asking plugin for UI Config Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 10:13:23 alessiochet volumio[28883]: info: Saving Spotify Acccount Jul 05 10:13:23 alessiochet volumio[28883]: info: Got Tidal Cloud Configuration Jul 05 10:13:23 alessiochet volumio[28883]: info: Got it Jul 05 10:13:23 alessiochet volumio[28883]: info: Got it Jul 05 10:13:23 alessiochet volumio[28883]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 10:13:23 alessiochet volumio[28883]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 10:13:23 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 05 10:13:27 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 10:13:31 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 10:13:35 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 10:13:37 alessiochet volumio[28883]: info: CoreCommandRouter::volumioGetState Jul 05 10:13:41 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 10:13:41 alessiochet volumio[28883]: info: Preload queue cleared Jul 05 10:13:44 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 10:13:44 alessiochet volumio[28883]: info: Preload queue cleared Jul 05 10:13:46 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 10:13:46 alessiochet volumio[28883]: info: Preload queue cleared Jul 05 10:13:49 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 10:13:49 alessiochet volumio[28883]: info: Preload queue cleared Jul 05 10:13:51 alessiochet volumio[28883]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 05 10:13:51 alessiochet volumio[28883]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 10:13:51 alessiochet volumio[28883]: TypeError: Cannot read property 'length' of undefined Jul 05 10:13:51 alessiochet volumio[28883]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 05 10:13:51 alessiochet volumio[28883]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 05 10:13:51 alessiochet volumio[28883]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 05 10:13:51 alessiochet volumio[28883]: at Parser.emit (events.js:315:20) Jul 05 10:13:51 alessiochet volumio[28883]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 05 10:13:51 alessiochet volumio[28883]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 05 10:13:51 alessiochet volumio[28883]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 05 10:13:51 alessiochet volumio[28883]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 05 10:13:51 alessiochet volumio[28883]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 05 10:13:51 alessiochet volumio[28883]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 05 10:13:51 alessiochet volumio[28883]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 05 10:13:51 alessiochet volumio[28883]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 05 10:13:51 alessiochet volumio[28883]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 05 10:13:51 alessiochet volumio[28883]: at IncomingMessage.emit (events.js:327:22) Jul 05 10:13:51 alessiochet volumio[28883]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 05 10:13:51 alessiochet volumio[28883]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 05 10:13:51 alessiochet volumio[28883]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 10:13:53 alessiochet sudo[1076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-05 10:12 Jul 05 10:13:53 alessiochet sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"