-- Logs begin at Sat 2024-10-12 14:01:13 EEST, end at Sat 2024-10-12 14:10:50 EEST. -- Oct 12 14:09:10 volumio volumio[1188]: info: CoreCommandRouter::volumioPlay Oct 12 14:09:10 volumio volumio[1188]: info: CoreStateMachine::play index undefined Oct 12 14:09:10 volumio volumio[1188]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 14:09:10 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:28 volumio volumio[1188]: info: CoreCommandRouter::volumioPlay Oct 12 14:09:28 volumio volumio[1188]: info: CoreStateMachine::play index undefined Oct 12 14:09:28 volumio volumio[1188]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 14:09:28 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: Preload queue cleared Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::ClearQueue Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::stop Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::stPlaybackTimer Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::updateTrackBlock Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrackBlock Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::serviceStop Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::serviceStop Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::stop Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::clearPlayQueue Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::saveQueue Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushQueue Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::addQueueItems Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::addQueueItems Oct 12 14:09:32 volumio volumio[1188]: info: Preload queue cleared Oct 12 14:09:32 volumio volumio[1188]: info: Adding Item to queue: webnineties/2 Oct 12 14:09:32 volumio volumio[1188]: info: Using cached record of: webnineties/2 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushQueue Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::saveQueue Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::updateTrackBlock Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrackBlock Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPlay Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::play index 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::stop Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::play index undefined Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::startPlaybackTimer Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: [1728731372370] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/eurodance/mp3-192/volumio Oct 12 14:09:32 volumio volumio[1188]: info: [1728731372370] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=188&count=2 Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio volumio[1188]: info: Oct 12 14:09:32 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand stop took 77 milliseconds Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio sudo[3295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3295]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music112/v4/49/66/4f/49664f08-07eb-1d5d-914c-c647522b5568/cover.jpg/600x600bb.jpg","name":"Loft - Summer Summer 2022","title":"Summer Summer 2022","artist":"90s90s Dance","album":"","streaming":true,"disableUiControls":true,"duration":"239","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 12 14:09:32 volumio volumio[1188]: verbose: CURRENT POSITION 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::syncState stateService stop Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::syncState currentStatus stop Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio volumio[1188]: info: No code Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio sudo[3295]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:32 volumio volumio[1188]: info: Oct 12 14:09:32 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:32 volumio volumio[1188]: info: Oct 12 14:09:32 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:32 volumio volumio[1188]: info: Oct 12 14:09:32 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio sudo[3298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3298]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio sudo[3301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3301]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio sudo[3298]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:32 volumio sudo[3301]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand status took 250 milliseconds Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand status took 180 milliseconds Oct 12 14:09:32 volumio sudo[3304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3304]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand status took 181 milliseconds Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand status took 181 milliseconds Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:32 volumio volumio[1188]: error: [now-playing] No images found in My Backgrounds Oct 12 14:09:32 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 12 14:09:32 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 14 milliseconds Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:32 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:32 volumio sudo[3304]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:32 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:32 volumio volumio[1188]: info: CoreStateMachine::pushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::volumioPushState Oct 12 14:09:32 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:32 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:32 volumio volumio[1188]: info: ------------------------------ 340ms Oct 12 14:09:32 volumio volumio[1188]: info: ------------------------------ 268ms Oct 12 14:09:32 volumio volumio[1188]: info: ------------------------------ 267ms Oct 12 14:09:32 volumio volumio[1188]: info: ------------------------------ 267ms Oct 12 14:09:32 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:32 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:32 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 14:09:32 volumio volumio[1188]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Loft - Summer Summer 2022","artist":"90s90s Dance","album":"","duration":"239","uri":"http://streams.90s90s.de/eurodance/mp3-192/volumio","service":""} Oct 12 14:09:32 volumio volumio[1188]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:32 volumio volumio[1188]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:176:15) Oct 12 14:09:32 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:32 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:32 volumio volumio[1188]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Oct 12 14:09:32 volumio volumio[1188]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 12 14:09:32 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:32 volumio volumio[1188]: at DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:68:19) Oct 12 14:09:32 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:32 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:32 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 36) Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio sudo[3309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3309]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio sudo[3309]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:32 volumio sudo[3312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3312]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio volumio[1188]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 12 14:09:32 volumio sudo[3312]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:32 volumio sudo[3315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:32 volumio sudo[3315]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:32 volumio sudo[3315]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:33 volumio sudo[3318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 12 14:09:33 volumio sudo[3318]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 14:09:33 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:33 volumio volumio[1188]: info: [1728731373045] [80s80s] received new event containing 2 songs. Oct 12 14:09:33 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 14:09:33 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:33 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:33 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:33 volumio volumio[1188]: info: sendMpdCommand stop took 4 milliseconds Oct 12 14:09:33 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: info: sendMpdCommand clear took 6 milliseconds Oct 12 14:09:33 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio sudo[3318]: pam_unix(sudo:session): session closed for user root Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: error: updateQueue error: null Oct 12 14:09:33 volumio volumio[1188]: error: updateQueue error: null Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 11ms Oct 12 14:09:33 volumio volumio[1188]: info: sendMpdCommand consume 1 took 10 milliseconds Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 8ms Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 7ms Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 4ms Oct 12 14:09:33 volumio volumio[1188]: info: [1728731373069] [80s80s] adding url: http://streams.90s90s.de/eurodance/mp3-192/volumio Oct 12 14:09:33 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/eurodance/mp3-192/volumio" Oct 12 14:09:33 volumio volumio[1188]: info: peppymeterbasic Daemon Stop Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: info: sendMpdCommand add "http://streams.90s90s.de/eurodance/mp3-192/volumio" took 2 milliseconds Oct 12 14:09:33 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand play Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: info: Oct 12 14:09:33 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:33 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 17ms Oct 12 14:09:33 volumio volumio[1188]: info: sendMpdCommand play took 7 milliseconds Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 5ms Oct 12 14:09:33 volumio volumio[1188]: info: ------------------------------ 4ms Oct 12 14:09:33 volumio volumio[1188]: info: [1728731373088] [80s80s] Pushing the next song state: Loft - Summer Summer 2022 Oct 12 14:09:33 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:33 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:33 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:33 volumio volumio[1188]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music112/v4/49/66/4f/49664f08-07eb-1d5d-914c-c647522b5568/cover.jpg/600x600bb.jpg","name":"Loft - Summer Summer 2022","title":"Summer Summer 2022","artist":"90s90s Dance","album":"","streaming":true,"disableUiControls":true,"duration":"239","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 12 14:09:33 volumio volumio[1188]: verbose: CURRENT POSITION 0 Oct 12 14:09:33 volumio volumio[1188]: info: CoreStateMachine::syncState stateService play Oct 12 14:09:33 volumio volumio[1188]: info: CoreStateMachine::syncState currentStatus stop Oct 12 14:09:33 volumio volumio[1188]: info: [1728731373090] [80s80s] PlayNextTrack API delay: 5 Oct 12 14:09:33 volumio volumio[1188]: info: [1728731373094] [80s80s] Setting timer to: 239000 milliseconds. Oct 12 14:09:33 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 14:09:33 volumio volumio[1188]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"90s90s Dance","artist":"","duration":"1000","uri":"http://streams.90s90s.de/eurodance/mp3-192/volumio","service":""} Oct 12 14:09:33 volumio volumio[1188]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:176:15) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Oct 12 14:09:33 volumio volumio[1188]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:68:19) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 38) Oct 12 14:09:33 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 14:09:33 volumio volumio[1188]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"90s90s Dance","duration":"1000","uri":"http://streams.90s90s.de/eurodance/mp3-192/volumio","service":""} Oct 12 14:09:33 volumio volumio[1188]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:176:15) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Oct 12 14:09:33 volumio volumio[1188]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:68:19) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 40) Oct 12 14:09:33 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 14:09:33 volumio volumio[1188]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"90s90s Dance","artist":"","duration":"1000","uri":"http://streams.90s90s.de/eurodance/mp3-192/volumio","service":""} Oct 12 14:09:33 volumio volumio[1188]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:176:15) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Oct 12 14:09:33 volumio volumio[1188]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:68:19) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 42) Oct 12 14:09:33 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 14:09:33 volumio volumio[1188]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"90s90s Dance","duration":"1000","uri":"http://streams.90s90s.de/eurodance/mp3-192/volumio","service":""} Oct 12 14:09:33 volumio volumio[1188]: error: [now-playing] API endpoint metadata/fetchInfo returned error: Error: Could not fetch info: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at MetadataAPI._MetadataAPI_doFetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:176:15) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: at async MetadataAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:52:36) Oct 12 14:09:33 volumio volumio[1188]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Oct 12 14:09:33 volumio volumio[1188]: at DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:68:19) Oct 12 14:09:33 volumio volumio[1188]: at runMicrotasks () Oct 12 14:09:33 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 12 14:09:33 volumio volumio[1188]: (node:1188) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 44) Oct 12 14:09:33 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:33 volumio volumio[1188]: info: CorePlayQueue::getTrack 1 Oct 12 14:09:33 volumio volumio[1188]: error: [now-playing] No images found in My Backgrounds Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 18 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 17 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 16 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 18 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 3 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 28ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 27ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 26ms Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 4 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 3 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 1 milliseconds Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 33ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 18ms Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:34 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:34 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:34 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:34 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:34 volumio volumio[1188]: info: Oct 12 14:09:34 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 17 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 8ms Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 5 milliseconds Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 26ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 25ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 24ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 8ms Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 8 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 8ms Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 7 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 6ms Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand status took 5 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 16ms Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 12 14:09:34 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 12 14:09:34 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:34 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:34 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:34 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 19ms Oct 12 14:09:34 volumio volumio[1188]: info: ------------------------------ 17ms Oct 12 14:09:34 volumio volumio[1188]: error: error Oct 12 14:09:34 volumio volumio[1188]: error: error Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:36 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:36 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:36 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces system playlist update Oct 12 14:09:36 volumio volumio[1188]: info: Ignoring MPD Status Update Oct 12 14:09:36 volumio volumio[1188]: info: Oct 12 14:09:36 volumio volumio[1188]: ---------------------------- MPD announces state update: player Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::getState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 8ms Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand status took 7 milliseconds Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 8ms Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand status took 5 milliseconds Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 4ms Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand status took 3 milliseconds Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 2ms Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand status took 2 milliseconds Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::parseState Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 14:09:36 volumio volumio[1188]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 14:09:36 volumio volumio[1188]: verbose: ControllerMpd::parseTrackInfo Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:36 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:36 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:36 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:36 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:36 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:36 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:36 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:36 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:36 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:36 volumio volumio[1188]: info: ControllerMpd::pushState Oct 12 14:09:36 volumio volumio[1188]: info: CoreCommandRouter::servicePushState Oct 12 14:09:36 volumio volumio[1188]: info: CorePlayQueue::getTrack 0 Oct 12 14:09:36 volumio volumio[1188]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 16ms Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 12ms Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 10ms Oct 12 14:09:36 volumio volumio[1188]: info: ------------------------------ 9ms Oct 12 14:09:57 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 14:09:57 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 14:10:21 volumio volumio[1188]: error: error Oct 12 14:10:21 volumio volumio[1188]: error: error Oct 12 14:10:39 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 12 14:10:39 volumio volumio[1188]: info: Preload queue cleared Oct 12 14:10:42 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 12 14:10:43 volumio volumio[1188]: info: Preload queue cleared Oct 12 14:10:45 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 12 14:10:45 volumio volumio[1188]: info: Preload queue cleared Oct 12 14:10:48 volumio volumio[1188]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 12 14:10:50 volumio volumio[1188]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 14:10:50 volumio volumio[1188]: TypeError: Cannot read property 'length' of undefined Oct 12 14:10:50 volumio volumio[1188]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 12 14:10:50 volumio volumio[1188]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 12 14:10:50 volumio volumio[1188]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 12 14:10:50 volumio volumio[1188]: at Parser.emit (events.js:400:28) Oct 12 14:10:50 volumio volumio[1188]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 12 14:10:50 volumio volumio[1188]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 12 14:10:50 volumio volumio[1188]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 12 14:10:50 volumio volumio[1188]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 12 14:10:50 volumio volumio[1188]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 12 14:10:50 volumio volumio[1188]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 12 14:10:50 volumio volumio[1188]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 12 14:10:50 volumio volumio[1188]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 12 14:10:50 volumio volumio[1188]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 12 14:10:50 volumio volumio[1188]: at IncomingMessage.emit (events.js:412:35) Oct 12 14:10:50 volumio volumio[1188]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 12 14:10:50 volumio volumio[1188]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 12 14:10:50 volumio volumio[1188]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 14:10:50 volumio sudo[3564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-12 14:09 Oct 12 14:10:50 volumio sudo[3564]: 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"