-- Logs begin at Mon 2024-11-25 21:51:35 CET, end at Mon 2024-11-25 22:15:32 CET. -- Nov 25 22:14:06 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:06 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:06 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:06 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:07 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:07 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:07 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:07 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:07 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:07 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:07 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:07 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:08 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:08 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:08 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:08 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:11 volumio volumio[1110]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Nov 25 22:14:11 volumio sudo[6505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 25 22:14:11 volumio sudo[6505]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 22:14:11 volumio sudo[6505]: pam_unix(sudo:session): session closed for user root Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio sudo[6508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 25 22:14:11 volumio sudo[6508]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 22:14:11 volumio systemd[1]: Stopping Music Player Daemon... Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 25 22:14:11 volumio systemd[1]: mpd.service: Succeeded. Nov 25 22:14:11 volumio systemd[1]: Stopped Music Player Daemon. Nov 25 22:14:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 25 22:14:11 volumio volumio[1110]: info: MPD Permissions set Nov 25 22:14:11 volumio systemd[1]: Starting Music Player Daemon... Nov 25 22:14:11 volumio sudo[6516]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 25 22:14:11 volumio sudo[6516]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 22:14:11 volumio sudo[6516]: pam_unix(sudo:session): session closed for user root Nov 25 22:14:11 volumio mpd[6518]: Nov 25 22:14 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 25 22:14:11 volumio systemd[1]: Started Music Player Daemon. Nov 25 22:14:11 volumio sudo[6508]: pam_unix(sudo:session): session closed for user root Nov 25 22:14:11 volumio volumio[1110]: error: updateQueue error: null Nov 25 22:14:11 volumio volumio[1110]: error: Upnp client error: Error: This socket has been ended by the other party Nov 25 22:14:17 volumio volumio[1110]: info: Selecting previously unselected package build-essential. Nov 25 22:14:17 volumio volumio[1110]: info: Preparing to unpack .../22-build-essential_12.6_amd64.deb ... Nov 25 22:14:17 volumio volumio[1110]: info: Unpacking build-essential (12.6) ... Nov 25 22:14:17 volumio volumio[1110]: info: Selecting previously unselected package dh-python. Nov 25 22:14:17 volumio volumio[1110]: info: Preparing to unpack .../23-dh-python_3.20190308_all.deb ... Nov 25 22:14:17 volumio volumio[1110]: info: Unpacking dh-python (3.20190308) ... Nov 25 22:14:18 volumio volumio[1110]: info: Selecting previously unselected package libfakeroot:amd64. Nov 25 22:14:18 volumio volumio[1110]: info: Preparing to unpack .../24-libfakeroot_1.23-1_amd64.deb ... Nov 25 22:14:18 volumio volumio[1110]: info: Unpacking libfakeroot:amd64 (1.23-1) ... Nov 25 22:14:18 volumio volumio[1110]: info: Selecting previously unselected package fakeroot. Nov 25 22:14:18 volumio volumio[1110]: info: Preparing to unpack .../25-fakeroot_1.23-1_amd64.deb ... Nov 25 22:14:18 volumio volumio[1110]: info: Unpacking fakeroot (1.23-1) ... Nov 25 22:14:18 volumio volumio[1110]: info: Selecting previously unselected package libalgorithm-diff-perl. Nov 25 22:14:18 volumio volumio[1110]: info: Preparing to unpack .../26-libalgorithm-diff-perl_1.19.03-2_all.deb ... Nov 25 22:14:18 volumio volumio[1110]: info: Unpacking libalgorithm-diff-perl (1.19.03-2) ... Nov 25 22:14:18 volumio volumio[1110]: info: CoreCommandRouter::volumioGetState Nov 25 22:14:18 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:19 volumio volumio[1110]: info: Selecting previously unselected package libalgorithm-diff-xs-perl. Nov 25 22:14:19 volumio volumio[1110]: info: Preparing to unpack .../27-libalgorithm-diff-xs-perl_0.04-5+b1_amd64.deb ... Nov 25 22:14:19 volumio volumio[1110]: info: Unpacking libalgorithm-diff-xs-perl (0.04-5+b1) ... Nov 25 22:14:19 volumio volumio[1110]: info: Selecting previously unselected package libalgorithm-merge-perl. Nov 25 22:14:19 volumio volumio[1110]: info: Preparing to unpack .../28-libalgorithm-merge-perl_0.08-3_all.deb ... Nov 25 22:14:19 volumio volumio[1110]: info: Unpacking libalgorithm-merge-perl (0.08-3) ... Nov 25 22:14:22 volumio volumio[1110]: info: CoreCommandRouter::volumioPause Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::pause Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::stPlaybackTimer Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::servicePause Nov 25 22:14:22 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:22 volumio volumio[1110]: info: CoreCommandRouter::servicePause Nov 25 22:14:22 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand pause Nov 25 22:14:22 volumio volumio[1110]: info: sendMpdCommand pause took 0 milliseconds Nov 25 22:14:22 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:22 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:22 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:22 volumio volumio[1110]: verbose: STATE SERVICE {"status":"pause","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music124/v4/8d/b1/c3/8db1c336-a299-f8af-a7e2-34f30f58bd0d/source/600x600bb.jpg","name":"Love Message - Love Message","title":"Love Message","artist":"90s90s Dance","album":"","streaming":true,"disableUiControls":true,"duration":"225","seek":112442,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Nov 25 22:14:22 volumio volumio[1110]: verbose: CURRENT POSITION 0 Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::syncState stateService pause Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::syncState currentStatus pause Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:22 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:22 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 22:14:22 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:22 volumio volumio[1110]: info: CoreStateMachine::stPlaybackTimer Nov 25 22:14:22 volumio volumio[1110]: info: Selecting previously unselected package libexpat1-dev:amd64. Nov 25 22:14:22 volumio volumio[1110]: info: Preparing to unpack .../29-libexpat1-dev_2.2.6-2+deb10u4_amd64.deb ... Nov 25 22:14:22 volumio volumio[1110]: info: Unpacking libexpat1-dev:amd64 (2.2.6-2+deb10u4) ... Nov 25 22:14:23 volumio volumio[1110]: info: CoreCommandRouter::volumioPlay Nov 25 22:14:23 volumio volumio[1110]: info: CoreStateMachine::play index undefined Nov 25 22:14:23 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:23 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:23 volumio volumio[1110]: info: CoreStateMachine::startPlaybackTimer Nov 25 22:14:23 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:23 volumio volumio[1110]: verbose: MPD COMMAND [object Object] Nov 25 22:14:23 volumio volumio[1110]: verbose: MPD COMMAND [object Object] Nov 25 22:14:25 volumio volumio[1110]: info: Selecting previously unselected package libpython3.7:amd64. Nov 25 22:14:25 volumio volumio[1110]: info: Preparing to unpack .../30-libpython3.7_3.7.3-2+deb10u3_amd64.deb ... Nov 25 22:14:25 volumio volumio[1110]: info: Unpacking libpython3.7:amd64 (3.7.3-2+deb10u3) ... Nov 25 22:14:26 volumio volumio[1110]: info: Selecting previously unselected package libpython3.7-dev:amd64. Nov 25 22:14:26 volumio volumio[1110]: info: Preparing to unpack .../31-libpython3.7-dev_3.7.3-2+deb10u3_amd64.deb ... Nov 25 22:14:26 volumio volumio[1110]: info: Unpacking libpython3.7-dev:amd64 (3.7.3-2+deb10u3) ... Nov 25 22:14:30 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Nov 25 22:14:30 volumio volumio[1110]: info: [1732569270880] [80s80s] handleBrowseUri curUri: 80s80s Nov 25 22:14:30 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:32 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Nov 25 22:14:32 volumio volumio[1110]: info: [1732569272578] [80s80s] handleBrowseUri curUri: 80s80s/eighties Nov 25 22:14:32 volumio volumio[1110]: info: [1732569272578] [80s80s] getRadioContent url: eighties Nov 25 22:14:32 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:35 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::ClearQueue Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::stop Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::updateTrackBlock Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrackBlock Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::stPlaybackTimer Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::serviceStop Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::serviceStop Nov 25 22:14:35 volumio volumio[1110]: info: ControllerMpd::stop Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand stop Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::clearPlayQueue Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::saveQueue Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushQueue Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::addQueueItems Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::addQueueItems Nov 25 22:14:35 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:35 volumio volumio[1110]: info: Adding Item to queue: webeighties/0 Nov 25 22:14:35 volumio volumio[1110]: info: Exploding uri webeighties/0 in service 80s80s Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275572] [80s80s] explodeUri: webeighties/0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushQueue Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::saveQueue Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::updateTrackBlock Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrackBlock Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPlay Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::play index 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::stop Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::play index undefined Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::startPlaybackTimer Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275582] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/web/mp3-192/volumio Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275582] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=62&count=2 Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand stop took 14 milliseconds Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music124/v4/8d/b1/c3/8db1c336-a299-f8af-a7e2-34f30f58bd0d/source/600x600bb.jpg","name":"Love Message - Love Message","title":"Love Message","artist":"90s90s Dance","album":"","streaming":true,"disableUiControls":true,"duration":"225","seek":112442,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Nov 25 22:14:35 volumio volumio[1110]: verbose: CURRENT POSITION 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::syncState stateService stop Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::syncState currentStatus stop Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:35 volumio volumio[1110]: info: No code Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275906] [80s80s] received new event containing 2 songs. Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand stop Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand stop took 0 milliseconds Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand clear Nov 25 22:14:35 volumio volumio[1110]: info: Nov 25 22:14:35 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:35 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand clear took 0 milliseconds Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand consume 1 Nov 25 22:14:35 volumio volumio[1110]: error: updateQueue error: null Nov 25 22:14:35 volumio volumio[1110]: info: Nov 25 22:14:35 volumio volumio[1110]: ---------------------------- MPD announces state update: options Nov 25 22:14:35 volumio volumio[1110]: info: ------------------------------ 0ms Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand consume 1 took 1 milliseconds Nov 25 22:14:35 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275909] [80s80s] adding url: http://streams.80s80s.de/web/mp3-192/volumio Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" Nov 25 22:14:35 volumio volumio[1110]: info: Nov 25 22:14:35 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:35 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand status took 0 milliseconds Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" took 0 milliseconds Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:35 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand play Nov 25 22:14:35 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:35 volumio volumio[1110]: info: ------------------------------ 8ms Nov 25 22:14:35 volumio volumio[1110]: info: ------------------------------ 7ms Nov 25 22:14:35 volumio volumio[1110]: info: sendMpdCommand play took 7 milliseconds Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275918] [80s80s] Pushing the next song state: Nik Kershaw - The Riddle Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:35 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:35 volumio volumio[1110]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is5-ssl.mzstatic.com/image/thumb/Music118/v4/d8/87/7b/d8877b89-28fd-26cc-fcbe-aa194a136b30/source/600x600bb.jpg","name":"Nik Kershaw - The Riddle","title":"The Riddle","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"219","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Nov 25 22:14:35 volumio volumio[1110]: verbose: CURRENT POSITION 0 Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::syncState stateService play Nov 25 22:14:35 volumio volumio[1110]: info: CoreStateMachine::syncState currentStatus stop Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275919] [80s80s] PlayNextTrack API delay: 30 Nov 25 22:14:35 volumio volumio[1110]: info: [1732569275920] [80s80s] Setting timer to: 219000 milliseconds. Nov 25 22:14:36 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:36 volumio volumio[1110]: info: CorePlayQueue::getTrack 1 Nov 25 22:14:36 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:36 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:36 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:36 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:38 volumio volumio[1110]: info: Nov 25 22:14:38 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:38 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:38 volumio volumio[1110]: info: Nov 25 22:14:38 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:38 volumio volumio[1110]: info: sendMpdCommand status took 11 milliseconds Nov 25 22:14:38 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:38 volumio volumio[1110]: info: sendMpdCommand status took 1 milliseconds Nov 25 22:14:38 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:38 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:38 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:38 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:38 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:38 volumio volumio[1110]: info: ------------------------------ 14ms Nov 25 22:14:38 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:38 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:38 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:38 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:38 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:38 volumio volumio[1110]: info: ------------------------------ 2ms Nov 25 22:14:38 volumio volumio[1110]: info: Nov 25 22:14:38 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:38 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:38 volumio volumio[1110]: info: Nov 25 22:14:38 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:38 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:38 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:38 volumio volumio[1110]: info: sendMpdCommand status took 1 milliseconds Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:38 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 25 22:14:38 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:38 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:38 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:38 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:38 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:38 volumio volumio[1110]: info: ------------------------------ 2ms Nov 25 22:14:39 volumio volumio[1110]: info: Nov 25 22:14:39 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:39 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:39 volumio volumio[1110]: info: Nov 25 22:14:39 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:39 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:39 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:39 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:39 volumio volumio[1110]: info: sendMpdCommand status took 0 milliseconds Nov 25 22:14:39 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:39 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:39 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 25 22:14:39 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:39 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:39 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:39 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:39 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:39 volumio volumio[1110]: info: ------------------------------ 2ms Nov 25 22:14:42 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Nov 25 22:14:42 volumio volumio[1110]: info: [1732569282946] [80s80s] handleBrowseUri curUri: 80s80s/nineties Nov 25 22:14:42 volumio volumio[1110]: info: [1732569282946] [80s80s] getRadioContent url: nineties Nov 25 22:14:42 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:43 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:43 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:43 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:43 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:46 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:46 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:46 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:46 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:14:47 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::ClearQueue Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::stop Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::stPlaybackTimer Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::updateTrackBlock Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrackBlock Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::serviceStop Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::serviceStop Nov 25 22:14:47 volumio volumio[1110]: info: ControllerMpd::stop Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand stop Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::clearPlayQueue Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::saveQueue Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushQueue Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::addQueueItems Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::addQueueItems Nov 25 22:14:47 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:14:47 volumio volumio[1110]: info: Adding Item to queue: webnineties/2 Nov 25 22:14:47 volumio volumio[1110]: info: Using cached record of: webnineties/2 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushQueue Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::saveQueue Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::updateTrackBlock Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrackBlock Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPlay Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::play index 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::stop Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::play index undefined Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::startPlaybackTimer Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287418] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/eurodance/mp3-192/volumio Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287418] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=188&count=2 Nov 25 22:14:47 volumio volumio[1110]: info: Nov 25 22:14:47 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand stop took 6 milliseconds Nov 25 22:14:47 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is5-ssl.mzstatic.com/image/thumb/Music118/v4/d8/87/7b/d8877b89-28fd-26cc-fcbe-aa194a136b30/source/600x600bb.jpg","name":"Nik Kershaw - The Riddle","title":"The Riddle","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"219","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Nov 25 22:14:47 volumio volumio[1110]: verbose: CURRENT POSITION 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::syncState stateService stop Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::syncState currentStatus stop Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:47 volumio volumio[1110]: info: No code Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand status took 9 milliseconds Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:47 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::pushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::volumioPushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:47 volumio volumio[1110]: info: ------------------------------ 13ms Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287650] [80s80s] received new event containing 2 songs. Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand stop Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand stop took 0 milliseconds Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand clear Nov 25 22:14:47 volumio volumio[1110]: info: Nov 25 22:14:47 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:47 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand clear took 1 milliseconds Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand consume 1 Nov 25 22:14:47 volumio volumio[1110]: error: updateQueue error: null Nov 25 22:14:47 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand consume 1 took 0 milliseconds Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287652] [80s80s] adding url: http://streams.90s90s.de/eurodance/mp3-192/volumio Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/eurodance/mp3-192/volumio" Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand add "http://streams.90s90s.de/eurodance/mp3-192/volumio" took 1 milliseconds Nov 25 22:14:47 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand play Nov 25 22:14:47 volumio volumio[1110]: info: Nov 25 22:14:47 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:47 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:47 volumio volumio[1110]: info: sendMpdCommand play took 1 milliseconds Nov 25 22:14:47 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287655] [80s80s] Pushing the next song state: Love Message - Love Message Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music124/v4/8d/b1/c3/8db1c336-a299-f8af-a7e2-34f30f58bd0d/source/600x600bb.jpg","name":"Love Message - Love Message","title":"Love Message","artist":"90s90s Dance","album":"","streaming":true,"disableUiControls":true,"duration":"225","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Nov 25 22:14:47 volumio volumio[1110]: verbose: CURRENT POSITION 0 Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::syncState stateService play Nov 25 22:14:47 volumio volumio[1110]: info: CoreStateMachine::syncState currentStatus stop Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287656] [80s80s] PlayNextTrack API delay: 30 Nov 25 22:14:47 volumio volumio[1110]: info: [1732569287656] [80s80s] Setting timer to: 225000 milliseconds. Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:47 volumio volumio[1110]: info: CorePlayQueue::getTrack 1 Nov 25 22:14:49 volumio volumio[1110]: info: Nov 25 22:14:49 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:49 volumio volumio[1110]: info: Nov 25 22:14:49 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand status took 1 milliseconds Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand status took 1 milliseconds Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:49 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:49 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:49 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:49 volumio volumio[1110]: info: ------------------------------ 2ms Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:49 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:49 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:49 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:49 volumio volumio[1110]: info: ------------------------------ 2ms Nov 25 22:14:49 volumio volumio[1110]: info: Nov 25 22:14:49 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:49 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:49 volumio volumio[1110]: info: Nov 25 22:14:49 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:49 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand status took 1 milliseconds Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:49 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:49 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:49 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:49 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:49 volumio volumio[1110]: info: Nov 25 22:14:49 volumio volumio[1110]: ---------------------------- MPD announces system playlist update Nov 25 22:14:49 volumio volumio[1110]: info: Ignoring MPD Status Update Nov 25 22:14:49 volumio volumio[1110]: info: Nov 25 22:14:49 volumio volumio[1110]: ---------------------------- MPD announces state update: player Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::getState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand status Nov 25 22:14:49 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand status took 1 milliseconds Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseState Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 25 22:14:49 volumio volumio[1110]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 25 22:14:49 volumio volumio[1110]: verbose: ControllerMpd::parseTrackInfo Nov 25 22:14:49 volumio volumio[1110]: info: ControllerMpd::pushState Nov 25 22:14:49 volumio volumio[1110]: info: CoreCommandRouter::servicePushState Nov 25 22:14:49 volumio volumio[1110]: info: CorePlayQueue::getTrack 0 Nov 25 22:14:49 volumio volumio[1110]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Nov 25 22:14:49 volumio volumio[1110]: info: ------------------------------ 1ms Nov 25 22:14:59 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:14:59 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:14:59 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:14:59 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:15:05 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 25 22:15:05 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:15:10 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 25 22:15:10 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:15:10 volumio kernel: pcieport 0000:00:1c.3: AER: Corrected error message received from 0000:02:00.0 Nov 25 22:15:10 volumio kernel: ath9k 0000:02:00.0: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID) Nov 25 22:15:10 volumio kernel: ath9k 0000:02:00.0: device [168c:0032] error status/mask=00000001/00002000 Nov 25 22:15:10 volumio kernel: ath9k 0000:02:00.0: [ 0] RxErr (First) Nov 25 22:15:11 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 25 22:15:11 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:15:15 volumio volumio[1110]: info: Selecting previously unselected package libpython3-dev:amd64. Nov 25 22:15:15 volumio volumio[1110]: info: Preparing to unpack .../32-libpython3-dev_3.7.3-1_amd64.deb ... Nov 25 22:15:15 volumio volumio[1110]: info: Unpacking libpython3-dev:amd64 (3.7.3-1) ... Nov 25 22:15:15 volumio volumio[1110]: info: Selecting previously unselected package python-pip-whl. Nov 25 22:15:15 volumio volumio[1110]: info: Preparing to unpack .../33-python-pip-whl_18.1-5_all.deb ... Nov 25 22:15:15 volumio volumio[1110]: info: Unpacking python-pip-whl (18.1-5) ... Nov 25 22:15:17 volumio volumio[1110]: info: Selecting previously unselected package python3-multidict. Nov 25 22:15:17 volumio volumio[1110]: info: Preparing to unpack .../34-python3-multidict_4.5.2-1_amd64.deb ... Nov 25 22:15:17 volumio volumio[1110]: info: Unpacking python3-multidict (4.5.2-1) ... Nov 25 22:15:18 volumio volumio[1110]: info: Selecting previously unselected package python3-yarl. Nov 25 22:15:18 volumio volumio[1110]: info: Preparing to unpack .../35-python3-yarl_1.3.0-1_amd64.deb ... Nov 25 22:15:18 volumio volumio[1110]: info: Unpacking python3-yarl (1.3.0-1) ... Nov 25 22:15:18 volumio volumio[1110]: info: Selecting previously unselected package python3-async-timeout. Nov 25 22:15:18 volumio volumio[1110]: info: Preparing to unpack .../36-python3-async-timeout_3.0.1-1_all.deb ... Nov 25 22:15:18 volumio volumio[1110]: info: Unpacking python3-async-timeout (3.0.1-1) ... Nov 25 22:15:19 volumio volumio[1110]: info: Selecting previously unselected package python3-attr. Nov 25 22:15:19 volumio volumio[1110]: info: Preparing to unpack .../37-python3-attr_18.2.0-1_all.deb ... Nov 25 22:15:19 volumio volumio[1110]: info: Unpacking python3-attr (18.2.0-1) ... Nov 25 22:15:20 volumio volumio[1110]: info: Selecting previously unselected package python3-aiohttp. Nov 25 22:15:20 volumio volumio[1110]: info: Preparing to unpack .../38-python3-aiohttp_3.5.1-1+deb10u1_amd64.deb ... Nov 25 22:15:20 volumio volumio[1110]: info: Unpacking python3-aiohttp (3.5.1-1+deb10u1) ... Nov 25 22:15:23 volumio volumio[1110]: info: Selecting previously unselected package python3-asn1crypto. Nov 25 22:15:23 volumio volumio[1110]: info: Preparing to unpack .../39-python3-asn1crypto_0.24.0-1_all.deb ... Nov 25 22:15:23 volumio volumio[1110]: info: Unpacking python3-asn1crypto (0.24.0-1) ... Nov 25 22:15:23 volumio volumio[1110]: info: Selecting previously unselected package python3-cffi-backend. Nov 25 22:15:23 volumio volumio[1110]: info: Preparing to unpack .../40-python3-cffi-backend_1.12.2-1_amd64.deb ... Nov 25 22:15:23 volumio volumio[1110]: info: Unpacking python3-cffi-backend (1.12.2-1) ... Nov 25 22:15:24 volumio volumio[1110]: info: Selecting previously unselected package python3-crypto. Nov 25 22:15:24 volumio volumio[1110]: info: Preparing to unpack .../41-python3-crypto_2.6.1-9+b1_amd64.deb ... Nov 25 22:15:24 volumio volumio[1110]: info: Unpacking python3-crypto (2.6.1-9+b1) ... Nov 25 22:15:26 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 25 22:15:26 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:15:28 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 25 22:15:29 volumio volumio[1110]: info: Preload queue cleared Nov 25 22:15:32 volumio volumio[1110]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 25 22:15:32 volumio volumio[1110]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 22:15:32 volumio volumio[1110]: TypeError: Cannot read property 'length' of undefined Nov 25 22:15:32 volumio volumio[1110]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 25 22:15:32 volumio volumio[1110]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 25 22:15:32 volumio volumio[1110]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 25 22:15:32 volumio volumio[1110]: at Parser.emit (events.js:400:28) Nov 25 22:15:32 volumio volumio[1110]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 25 22:15:32 volumio volumio[1110]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 25 22:15:32 volumio volumio[1110]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 25 22:15:32 volumio volumio[1110]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 25 22:15:32 volumio volumio[1110]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 25 22:15:32 volumio volumio[1110]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 25 22:15:32 volumio volumio[1110]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 25 22:15:32 volumio volumio[1110]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 25 22:15:32 volumio volumio[1110]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 25 22:15:32 volumio volumio[1110]: at IncomingMessage.emit (events.js:412:35) Nov 25 22:15:32 volumio volumio[1110]: at endReadableNT (internal/streams/readable.js:1333:12) Nov 25 22:15:32 volumio volumio[1110]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Nov 25 22:15:32 volumio volumio[1110]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 22:15:32 volumio sudo[7069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-25 22:14 Nov 25 22:15:32 volumio sudo[7069]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"