-- Logs begin at Tue 2024-05-14 10:04:04 JST, end at Tue 2024-05-14 15:05:31 JST. -- May 14 15:04:03 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:04:03 volumio volumio[935]: info: CorePlayQueue::getTrack 0 May 14 15:04:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 14 15:04:27 volumio volumio[935]: info: CURURI: music-library/NAS/DS216J/Jazz/The Bill Evans Trio - Sunday At The Village Vanguard (SACD) May 14 15:04:27 volumio volumio[935]: info: Preload queue cleared May 14 15:04:31 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 14 15:04:31 volumio volumio[935]: info: CURURI: music-library/NAS/DS216J/Jazz/The Bill Evans Trio - Sunday At The Village Vanguard (SACD)/The Bill Evans Trio - Sunday At The Village Vanguard (flac) May 14 15:04:31 volumio volumio[935]: info: Preload queue cleared May 14 15:04:48 volumio volumio[935]: info: Preload queue cleared May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: [1715666688691] ---------------------------- Client requests add and Play Volumio CUE entry May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue May 14 15:04:48 volumio volumio[935]: info: Adding CUE individual entry: 0 NAS/DS216J/Jazz/The Bill Evans Trio - Sunday At The Village Vanguard (SACD)/The Bill Evans Trio - Sunday At The Village Vanguard (flac)/The Bill Evans Trio - Sunday At The Village Vanguard (SACD).cue May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioAddQueueItems May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::addQueueItems May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::addQueueItems May 14 15:04:48 volumio volumio[935]: info: Preload queue cleared May 14 15:04:48 volumio volumio[935]: info: Adding Item to queue: cue://NAS/DS216J/Jazz/The Bill Evans Trio - Sunday At The Village Vanguard (SACD)/The Bill Evans Trio - Sunday At The Village Vanguard (flac)/The Bill Evans Trio - Sunday At The Village Vanguard (SACD).cue@0 May 14 15:04:48 volumio volumio[935]: info: Exploding uri cue://NAS/DS216J/Jazz/The Bill Evans Trio - Sunday At The Village Vanguard (SACD)/The Bill Evans Trio - Sunday At The Village Vanguard (flac)/The Bill Evans Trio - Sunday At The Village Vanguard (SACD).cue@0 in service mpd May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioPlay May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::play index 10 May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::stop May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::stPlaybackTimer May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::updateTrackBlock May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrackBlock May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::pushState May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 0 May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioPushState May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::serviceStop May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 0 May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::serviceStop May 14 15:04:48 volumio volumio[935]: info: ControllerMpd::stop May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand stop May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioPushQueue May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::saveQueue May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::updateTrackBlock May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrackBlock May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: ---------------------------- MPD announces state update: player May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand stop took 27 milliseconds May 14 15:04:48 volumio volumio[935]: info: ControllerMpd::getState May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand status May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::play index undefined May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::setConsumeUpdateService undefined May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::startPlaybackTimer May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand stop May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: ---------------------------- MPD announces state update: player May 14 15:04:48 volumio volumio[935]: info: ControllerMpd::getState May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand status May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: ---------------------------- MPD announces state update: player May 14 15:04:48 volumio volumio[935]: info: ControllerMpd::getState May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand status May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand status took 10 milliseconds May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand stop took 7 milliseconds May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand status took 5 milliseconds May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand status took 4 milliseconds May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::parseState May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand clear May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::parseState May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::parseState May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: ---------------------------- MPD announces system playlist update May 14 15:04:48 volumio volumio[935]: info: Ignoring MPD Status Update May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand playlistinfo took 8 milliseconds May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand clear took 8 milliseconds May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand playlistinfo took 8 milliseconds May 14 15:04:48 volumio volumio[935]: info: sendMpdCommand playlistinfo took 8 milliseconds May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::parseTrackInfo May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::sendMpdCommand load "NAS/DS216J/Jazz/The Bill Evans Trio - Sunday At The Village Vanguard (SACD)/The Bill Evans Trio - Sunday At The Village Vanguard (flac)/The Bill Evans Trio - Sunday At The Village Vanguard (SACD).cue" May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::parseTrackInfo May 14 15:04:48 volumio volumio[935]: verbose: ControllerMpd::parseTrackInfo May 14 15:04:48 volumio volumio[935]: info: ControllerMpd::pushState May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::servicePushState May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::pushState May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioPushState May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:04:48 volumio volumio[935]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"My Foolish Heart","artist":"The Bill Evans Trio","album":"Waltz For Debby","uri":"NAS/DS216J/Jazz/Bill Evans Trio - Waltz For Debby (2011) [24-192 HD FLAC]/1-My Foolish Heart.flac","trackType":"flac"} May 14 15:04:48 volumio volumio[935]: verbose: CURRENT POSITION 10 May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::syncState stateService stop May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::syncState currentStatus stop May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::pushState May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioPushState May 14 15:04:48 volumio volumio[935]: info: No code May 14 15:04:48 volumio volumio[935]: info: CoreStateMachine::pushState May 14 15:04:48 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:04:48 volumio volumio[935]: info: CoreCommandRouter::volumioPushState May 14 15:04:48 volumio volumio[935]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 14 15:04:48 volumio volumio[935]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 14 15:04:48 volumio volumio[935]: info: ------------------------------ 67ms May 14 15:04:48 volumio volumio[935]: info: ------------------------------ 62ms May 14 15:04:48 volumio volumio[935]: info: ------------------------------ 60ms May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: ---------------------------- MPD announces system playlist update May 14 15:04:48 volumio volumio[935]: info: Ignoring MPD Status Update May 14 15:04:48 volumio volumio[935]: info: May 14 15:04:48 volumio volumio[935]: ---------------------------- MPD announces system playlist update May 14 15:04:48 volumio volumio[935]: info: Ignoring MPD Status Update May 14 15:04:48 volumio volumio[935]: error: updateQueue error: null May 14 15:04:48 volumio volumio[935]: info: ------------------------------ 71ms May 14 15:04:48 volumio volumio[935]: error: updateQueue error: null May 14 15:04:48 volumio volumio[935]: error: updateQueue error: null May 14 15:04:48 volumio volumio[935]: info: ------------------------------ 25ms May 14 15:04:48 volumio volumio[935]: info: ------------------------------ 17ms May 14 15:04:59 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:04:59 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:06 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:06 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:07 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 14 15:05:07 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 14 15:05:11 volumio sudo[1756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 14 15:05:11 volumio sudo[1756]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 15:05:11 volumio sudo[1756]: pam_unix(sudo:session): session closed for user root May 14 15:05:11 volumio sudo[1759]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 14 15:05:11 volumio sudo[1759]: pam_unix(sudo:session): session opened for user root by (uid=0) May 14 15:05:11 volumio sudo[1759]: pam_unix(sudo:session): session closed for user root May 14 15:05:12 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.3.100 from 192.168.3.12 UA: okhttp/4.9.2 Total Clients: 6 May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::volumioGetVisibleSources May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:12 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 14 15:05:12 volumio volumio[935]: info: Received Get System Info May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 14 15:05:12 volumio volumio[935]: info: Discovery: Getting this device information May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:12 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:12 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:12 volumio volumio[935]: info: Listing playlists May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 14 15:05:12 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 14 15:05:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:13 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 14 15:05:13 volumio volumio[935]: info: Received Get System Info May 14 15:05:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 14 15:05:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 14 15:05:13 volumio volumio[935]: info: Discovery: Getting this device information May 14 15:05:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:13 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 15:05:15 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 14 15:05:15 volumio volumio[935]: info: Received Get System Info May 14 15:05:15 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 14 15:05:15 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 14 15:05:15 volumio volumio[935]: info: Discovery: Getting this device information May 14 15:05:15 volumio volumio[935]: info: CoreCommandRouter::volumioGetState May 14 15:05:15 volumio volumio[935]: info: CorePlayQueue::getTrack 10 May 14 15:05:15 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 14 15:05:15 volumio volumio[935]: info: CoreCommandRouter::volumioGetQueue May 14 15:05:15 volumio volumio[935]: info: CoreStateMachine::getQueue May 14 15:05:15 volumio volumio[935]: info: CorePlayQueue::getQueue May 14 15:05:24 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 14 15:05:24 volumio volumio[935]: info: CURURI: music-library/NAS/DS216J/Jazz/The Bill Evans Trio - Waltz For Debby (SACD) May 14 15:05:24 volumio volumio[935]: info: Preload queue cleared May 14 15:05:30 volumio volumio[935]: info: CoreCommandRouter::volumioAddQueueItems May 14 15:05:30 volumio volumio[935]: info: CoreStateMachine::addQueueItems May 14 15:05:30 volumio volumio[935]: info: CorePlayQueue::addQueueItems May 14 15:05:30 volumio volumio[935]: info: Preload queue cleared May 14 15:05:30 volumio volumio[935]: info: Adding Item to queue: music-library/NAS/DS216J/Jazz/The Bill Evans Trio - Waltz For Debby (SACD)/The Bill Evans Trio - Waltz For Debby (wav) May 14 15:05:30 volumio volumio[935]: info: Exploding uri music-library/NAS/DS216J/Jazz/The Bill Evans Trio - Waltz For Debby (SACD)/The Bill Evans Trio - Waltz For Debby (wav) in service mpd May 14 15:05:30 volumio volumio[935]: info: ALBUMART /albumart?cacheid=629&web=The%20Bill%20Evans%20Trio/Waltz%20For%20Debby%20(SACD)/extralarge&path=%2Fmnt%2FNAS%2FDS216J%2FJazz%2FThe%20Bill%20Evans%20Trio%20-%20Waltz%20For%20Debby%20(SACD)%2FThe%20Bill%20Evans%20Trio%20-%20Waltz%20For%20Debby%20(wav)%2FThe%20Bill%20Evans%20Trio%20-%20Waltz%20For%20Debby%20(SACD).cue&metadata=false May 14 15:05:30 volumio volumio[935]: info: URI /mnt/NAS/DS216J/Jazz/The Bill Evans Trio - Waltz For Debby (SACD)/The Bill Evans Trio - Waltz For Debby (wav)/The Bill Evans Trio - Waltz For Debby (SACD).cue May 14 15:05:30 volumio volumio[935]: info: ALBUMART /albumart?cacheid=629&web=The%20Bill%20Evans%20Trio/Waltz%20For%20Debby%20(SACD)/extralarge&path=%2Fmnt%2FNAS%2FDS216J%2FJazz%2FThe%20Bill%20Evans%20Trio%20-%20Waltz%20For%20Debby%20(SACD)%2FThe%20Bill%20Evans%20Trio%20-%20Waltz%20For%20Debby%20(wav)%2FThe%20Bill%20Evans%20Trio%20-%20Waltz%20For%20Debby%20(SACD).cue&metadata=false May 14 15:05:30 volumio volumio[935]: info: URI /mnt/NAS/DS216J/Jazz/The Bill Evans Trio - Waltz For Debby (SACD)/The Bill Evans Trio - Waltz For Debby (wav)/The Bill Evans Trio - Waltz For Debby (SACD).cue May 14 15:05:30 volumio volumio[935]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 14 15:05:30 volumio volumio[935]: Error: Unable to resolve or reject the same promise twice May 14 15:05:30 volumio volumio[935]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 14 15:05:30 volumio volumio[935]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 May 14 15:05:30 volumio volumio[935]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 14 15:05:30 volumio volumio[935]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 14 15:05:30 volumio volumio[935]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 14 15:05:30 volumio volumio[935]: at Socket.emit (events.js:315:20) May 14 15:05:30 volumio volumio[935]: at addChunk (internal/streams/readable.js:309:12) May 14 15:05:30 volumio volumio[935]: at readableAddChunk (internal/streams/readable.js:280:11) May 14 15:05:30 volumio volumio[935]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 14 15:05:30 volumio volumio[935]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 14 15:05:30 volumio volumio[935]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 14 15:05:31 volumio sudo[1813]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-14 15:04 May 14 15:05:31 volumio sudo[1813]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"