-- Logs begin at Thu 2019-02-14 03:11:58 MST, end at Fri 2025-02-28 12:50:06 MST. -- Feb 28 12:49:00 musicbox systemd[1]: Starting Cleanup of Temporary Directories... Feb 28 12:49:00 musicbox volumio[1238]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 28 12:49:00 musicbox systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Feb 28 12:49:00 musicbox systemd[1]: Started Cleanup of Temporary Directories. Feb 28 12:49:17 musicbox volumio[1238]: info: VolumeController::SetAlsaVolume- Feb 28 12:49:17 musicbox volumio[1238]: info: CoreStateMachine::pushState Feb 28 12:49:17 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 12:49:17 musicbox volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 28 12:49:17 musicbox volumio[1238]: info: MRS: Pushing multiroomSync output update for this device Feb 28 12:49:17 musicbox volumio[1238]: info: MRS: Pushing multiroomSync output Feb 28 12:49:17 musicbox volumio[1238]: info: [ASDebug] CurState: play PrevState: play Feb 28 12:49:17 musicbox volumio[1238]: info: [GPIO_Control] Status changed: play Feb 28 12:49:28 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 28 12:49:28 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 28 12:49:28 musicbox volumio[1238]: info: Discovery: Getting this device information Feb 28 12:49:28 musicbox volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 28 12:49:28 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 28 12:49:58 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 28 12:49:58 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 28 12:49:58 musicbox volumio[1238]: info: Discovery: Getting this device information Feb 28 12:49:58 musicbox volumio[1238]: info: CoreCommandRouter::volumioGetState Feb 28 12:49:58 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 28 12:50:01 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 28 12:50:01 musicbox volumio[1238]: info: browseTIDALUri took 410 milliseconds Feb 28 12:50:01 musicbox volumio[1238]: info: Preload queue cleared Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866264 Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866266 Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866267 Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866268 Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866269 Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866271 Feb 28 12:50:01 musicbox volumio[1238]: info: Preloading song: tidal://song/200866272 Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866264 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866266 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: Executing endpoint metavolumio Feb 28 12:50:01 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 28 12:50:01 musicbox volumio[1238]: info: Executing endpoint metavolumio Feb 28 12:50:01 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866267 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866268 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866269 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866271 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: Exploding uri tidal://song/200866272 in service tidal Feb 28 12:50:01 musicbox volumio[1238]: info: explodeTIDALUri took 328 milliseconds Feb 28 12:50:01 musicbox volumio[1238]: info: explodeTIDALUri took 350 milliseconds Feb 28 12:50:01 musicbox volumio[1238]: info: explodeTIDALUri took 324 milliseconds Feb 28 12:50:02 musicbox volumio[1238]: info: explodeTIDALUri took 285 milliseconds Feb 28 12:50:02 musicbox volumio[1238]: info: explodeTIDALUri took 339 milliseconds Feb 28 12:50:02 musicbox volumio[1238]: info: explodeTIDALUri took 343 milliseconds Feb 28 12:50:02 musicbox volumio[1238]: info: explodeTIDALUri took 332 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: info: Preload queue cleared Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::ClearQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::stop Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::stPlaybackTimer Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::updateTrackBlock Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrackBlock Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::pushState Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrack 9 Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::volumioPushState Feb 28 12:50:05 musicbox volumio[1238]: info: MRS: Pushing multiroomSync output update for this device Feb 28 12:50:05 musicbox volumio[1238]: info: MRS: Pushing multiroomSync output Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::serviceStop Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrack 9 Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::serviceStop Feb 28 12:50:05 musicbox volumio[1238]: info: [1740772205623] ControllerTidal::stop Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 28 12:50:05 musicbox volumio[1238]: info: ControllerMpd::stop Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::clearPlayQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::saveQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::volumioPushQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::addQueueItems Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::addQueueItems Feb 28 12:50:05 musicbox volumio[1238]: info: Preload queue cleared Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866264 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866264 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866265 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866265 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866266 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866266 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866267 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866267 Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::volumioPushQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::saveQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::updateTrackBlock Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrackBlock Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::volumioPlay Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::play index 3 Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::addQueueItems Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::addQueueItems Feb 28 12:50:05 musicbox volumio[1238]: info: Preload queue cleared Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866268 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866268 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866269 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866269 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866270 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866270 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866271 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866271 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866272 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866272 Feb 28 12:50:05 musicbox volumio[1238]: info: Adding Item to queue: tidal://song/200866273 Feb 28 12:50:05 musicbox volumio[1238]: info: Using cached record of: tidal://song/200866273 Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::stop Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::volumioPushQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::saveQueue Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::play index undefined Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::updateTrackBlock Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrackBlock Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrack 3 Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::startPlaybackTimer Feb 28 12:50:05 musicbox volumio[1238]: info: CorePlayQueue::getTrack 3 Feb 28 12:50:05 musicbox volumio[1238]: info: [1740772205697] ControllerTidal::clearAddPlayTrack Feb 28 12:50:05 musicbox volumio[1238]: info: Getting stream with soundQuality LOSSLESS Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand stop Feb 28 12:50:05 musicbox volumio[1238]: info: [ASDebug] CurState: stop PrevState: play Feb 28 12:50:05 musicbox volumio[1238]: info: [ASDebug] InitTimeout - Amp off in: 200 ms Feb 28 12:50:05 musicbox volumio[1238]: info: [GPIO_Control] Status changed: stop Feb 28 12:50:05 musicbox volumio[1238]: info: [GPIO_Control] Handling event: musicStop Feb 28 12:50:05 musicbox volumio[1238]: info: Feb 28 12:50:05 musicbox volumio[1238]: ---------------------------- MPD announces state update: player Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand stop took 95 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: info: ControllerMpd::getState Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand status Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand stop took 23 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand clear Feb 28 12:50:05 musicbox volumio[1238]: info: Feb 28 12:50:05 musicbox volumio[1238]: ---------------------------- MPD announces system playlist update Feb 28 12:50:05 musicbox volumio[1238]: info: Ignoring MPD Status Update Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand status took 2 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand clear took 2 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::parseState Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/200866267&soundQuality=LOSSLESS" Feb 28 12:50:05 musicbox volumio[1238]: error: updateQueue error: null Feb 28 12:50:05 musicbox volumio[1238]: info: Feb 28 12:50:05 musicbox volumio[1238]: ---------------------------- MPD announces system playlist update Feb 28 12:50:05 musicbox volumio[1238]: info: Ignoring MPD Status Update Feb 28 12:50:05 musicbox volumio[1238]: info: ------------------------------ 26ms Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand playlistinfo took 25 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/200866267&soundQuality=LOSSLESS" took 25 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::parseTrackInfo Feb 28 12:50:05 musicbox volumio[1238]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 28 12:50:05 musicbox volumio[1238]: verbose: ControllerMpd::sendMpdCommand play Feb 28 12:50:05 musicbox volumio[1238]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 28 12:50:05 musicbox volumio[1238]: info: ------------------------------ 32ms Feb 28 12:50:05 musicbox volumio[1238]: STREAMING PROXY: Handling url /?data=tidal://song/200866267&soundQuality=LOSSLESS Feb 28 12:50:05 musicbox volumio[1238]: info: ------------------------------ 7ms Feb 28 12:50:05 musicbox volumio[1238]: info: sendMpdCommand play took 4 milliseconds Feb 28 12:50:05 musicbox volumio[1238]: info: touch_display: Setting screensaver timeout to 60 seconds. Feb 28 12:50:05 musicbox volumio[1238]: info: Executing endpoint getStreamUrltidal Feb 28 12:50:05 musicbox volumio[1238]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 28 12:50:05 musicbox volumio[1238]: info: [ASDebug] Togle GPIO: OFF Feb 28 12:50:05 musicbox volumio[1238]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 28 12:50:05 musicbox volumio[1238]: Error: ESPIPE: invalid seek, write Feb 28 12:50:05 musicbox volumio[1238]: at Object.writeSync (fs.js:711:3) Feb 28 12:50:05 musicbox volumio[1238]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Feb 28 12:50:05 musicbox volumio[1238]: at AmpSwitchController.off (/data/plugins/system_controller/ampswitch/index.js:223:23) Feb 28 12:50:05 musicbox volumio[1238]: at Timeout._onTimeout (/data/plugins/system_controller/ampswitch/index.js:195:88) Feb 28 12:50:05 musicbox volumio[1238]: at listOnTimeout (internal/timers.js:554:17) Feb 28 12:50:05 musicbox volumio[1238]: at processTimers (internal/timers.js:497:7) { Feb 28 12:50:05 musicbox volumio[1238]: errno: -29, Feb 28 12:50:05 musicbox volumio[1238]: syscall: 'write', Feb 28 12:50:05 musicbox volumio[1238]: code: 'ESPIPE' Feb 28 12:50:05 musicbox volumio[1238]: } Feb 28 12:50:05 musicbox volumio[1238]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 28 12:50:06 musicbox sudo[4618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-28 12:49 Feb 28 12:50:06 musicbox sudo[4618]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"