-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2024-11-23 09:23:19 CET. -- Nov 23 09:22:01 sonata go-librespot[1474]: time="2024-11-23T09:22:01+01:00" level=debug msg="fetched chunk 6/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:22:12 sonata go-librespot[1474]: time="2024-11-23T09:22:12+01:00" level=debug msg="fetched chunk 7/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:22:23 sonata go-librespot[1474]: time="2024-11-23T09:22:23+01:00" level=debug msg="fetched chunk 8/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:22:31 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:31 sonata volumio[925]: info: Spotify previous Nov 23 09:22:31 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:32 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:32 sonata volumio[925]: info: Spotify previous Nov 23 09:22:32 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:33 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:33 sonata volumio[925]: info: Spotify previous Nov 23 09:22:33 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:33 sonata volumio[925]: info: CoreCommandRouter::volumioSeek Nov 23 09:22:33 sonata volumio[925]: info: CoreStateMachine::seek Nov 23 09:22:33 sonata volumio[925]: info: Spotify seek to: 67000 Nov 23 09:22:33 sonata volumio[925]: info: Sending Spotify command with payload to local API: /player/seek Nov 23 09:22:33 sonata volumio[925]: info: CoreStateMachine::startPlaybackTimer Nov 23 09:22:33 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:22:33 sonata volumio[925]: info: CoreStateMachine::pushState Nov 23 09:22:33 sonata volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 09:22:33 sonata volumio[925]: info: CoreCommandRouter::volumioPushState Nov 23 09:22:33 sonata volumio[925]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Nov 23 09:22:34 sonata volumio[925]: info: CoreCommandRouter::volumioSeek Nov 23 09:22:34 sonata volumio[925]: info: CoreStateMachine::seek Nov 23 09:22:34 sonata volumio[925]: info: Spotify seek to: 68000 Nov 23 09:22:34 sonata volumio[925]: info: Sending Spotify command with payload to local API: /player/seek Nov 23 09:22:34 sonata volumio[925]: info: CoreStateMachine::startPlaybackTimer Nov 23 09:22:34 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:22:34 sonata volumio[925]: info: CoreStateMachine::pushState Nov 23 09:22:34 sonata volumio[925]: info: CoreCommandRouter::volumioPushState Nov 23 09:22:34 sonata volumio[925]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Nov 23 09:22:34 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:34 sonata volumio[925]: info: Spotify previous Nov 23 09:22:34 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:34 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:34 sonata volumio[925]: info: Spotify previous Nov 23 09:22:34 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:34 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:34 sonata volumio[925]: info: Spotify previous Nov 23 09:22:34 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:34 sonata go-librespot[1474]: time="2024-11-23T09:22:34+01:00" level=debug msg="fetched chunk 9/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:22:34 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:34 sonata volumio[925]: info: Spotify previous Nov 23 09:22:34 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:35 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:22:35 sonata volumio[925]: info: Spotify previous Nov 23 09:22:35 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:22:37 sonata volumio[925]: info: CoreCommandRouter::volumioGetQueue Nov 23 09:22:37 sonata volumio[925]: info: CoreStateMachine::getQueue Nov 23 09:22:37 sonata volumio[925]: info: CorePlayQueue::getQueue Nov 23 09:22:41 sonata volumio[925]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 23 09:22:41 sonata volumio[925]: info: CURURI: music-library Nov 23 09:22:41 sonata volumio[925]: info: Preload queue cleared Nov 23 09:22:47 sonata go-librespot[1474]: time="2024-11-23T09:22:47+01:00" level=debug msg="fetched chunk 10/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:22:59 sonata volumio[925]: info: CoreCommandRouter::volumioNext Nov 23 09:22:59 sonata volumio[925]: info: CoreStateMachine::next Nov 23 09:22:59 sonata volumio[925]: info: Spotify next Nov 23 09:22:59 sonata volumio[925]: info: Sending Spotify command to local API: /player/next Nov 23 09:22:59 sonata go-librespot[1474]: time="2024-11-23T09:22:59+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7pu70H0Wjs5HdqLJjUUYXP" Nov 23 09:22:59 sonata go-librespot[1474]: time="2024-11-23T09:22:59+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 23 09:22:59 sonata go-librespot[1474]: time="2024-11-23T09:22:59+01:00" level=trace msg="emitting websocket event: will_play" Nov 23 09:22:59 sonata volumio[925]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7pu70H0Wjs5HdqLJjUUYXP","play_origin":"playlist"}} Nov 23 09:22:59 sonata go-librespot[1474]: time="2024-11-23T09:22:59+01:00" level=debug msg="selected format OGG_VORBIS_320 (b4b8442986a3da38c4da2a09273c1dfd72ea0c91)" uri="spotify:track:7pu70H0Wjs5HdqLJjUUYXP" Nov 23 09:22:59 sonata go-librespot[1474]: time="2024-11-23T09:22:59+01:00" level=debug msg="requested aes key for file b4b8442986a3da38c4da2a09273c1dfd72ea0c91, gid: 7pu70H0Wjs5HdqLJjUUYXP" Nov 23 09:23:00 sonata go-librespot[1474]: time="2024-11-23T09:23:00+01:00" level=debug msg="fetched chunk 11/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:23:00 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:23:00 sonata volumio[925]: info: Spotify previous Nov 23 09:23:00 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:23:01 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:23:01 sonata volumio[925]: info: Spotify previous Nov 23 09:23:01 sonata volumio[925]: info: Sending Spotify command to local API: /player/prev Nov 23 09:23:04 sonata volumio[925]: info: CoreCommandRouter::volumioSeek Nov 23 09:23:04 sonata volumio[925]: info: CoreStateMachine::seek Nov 23 09:23:04 sonata volumio[925]: info: Spotify seek to: 5000 Nov 23 09:23:04 sonata volumio[925]: info: Sending Spotify command with payload to local API: /player/seek Nov 23 09:23:04 sonata volumio[925]: info: CoreStateMachine::startPlaybackTimer Nov 23 09:23:04 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:04 sonata volumio[925]: info: CoreStateMachine::pushState Nov 23 09:23:04 sonata volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 09:23:04 sonata volumio[925]: info: CoreCommandRouter::volumioPushState Nov 23 09:23:04 sonata volumio[925]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Nov 23 09:23:10 sonata volumio[925]: info: CoreCommandRouter::volumioClearQueue Nov 23 09:23:10 sonata volumio[925]: info: CoreStateMachine::ClearQueue Nov 23 09:23:10 sonata volumio[925]: info: CoreStateMachine::stop Nov 23 09:23:10 sonata volumio[925]: info: CoreStateMachine::serviceStop Nov 23 09:23:10 sonata volumio[925]: info: CoreCommandRouter::serviceStop Nov 23 09:23:10 sonata volumio[925]: info: Spotify Stop Nov 23 09:23:10 sonata volumio[925]: SPOTIFY: SPOTIFY STOP Nov 23 09:23:10 sonata volumio[925]: SPOTIFY: {"status":"play","title":"BFF","artist":"bryska","album":"BFF","albumart":"https://i.scdn.co/image/ab67616d00001e0243ae729bd51a9c41bb001b92","uri":"spotify:track:1EvGBqeeM1xUwwurZeru5Q","trackType":"spotify","codec":"ogg","seek":100000,"duration":156,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":true,"repeat":true,"repeatSingle":true,"consume":false,"volume":49,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Nov 23 09:23:10 sonata volumio[925]: info: Sending Spotify command to local API: /player/pause Nov 23 09:23:10 sonata volumio[925]: info: CorePlayQueue::clearPlayQueue Nov 23 09:23:10 sonata volumio[925]: info: CorePlayQueue::saveQueue Nov 23 09:23:10 sonata volumio[925]: info: CoreCommandRouter::volumioPushState Nov 23 09:23:10 sonata volumio[925]: info: CoreCommandRouter::volumioPushQueue Nov 23 09:23:10 sonata volumio[925]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Nov 23 09:23:10 sonata volumio[925]: info: touch_display: Setting screensaver timeout to 0 seconds. Nov 23 09:23:11 sonata go-librespot[1474]: time="2024-11-23T09:23:11+01:00" level=debug msg="fetched chunk 12/13, size: 524288" uri="spotify:track:1EvGBqeeM1xUwwurZeru5Q" Nov 23 09:23:15 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:15 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:15 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:15 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:17 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:17 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:17 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:17 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:17 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:17 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:17 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:17 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:17 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:17 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:17 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:17 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:18 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:18 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:18 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:18 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:18 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:18 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:18 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:18 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:18 sonata volumio[925]: info: CoreCommandRouter::volumioPlay Nov 23 09:23:18 sonata volumio[925]: info: CoreStateMachine::play index undefined Nov 23 09:23:18 sonata volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 09:23:18 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:19 sonata volumio[925]: info: CoreCommandRouter::volumioPrevious Nov 23 09:23:19 sonata volumio[925]: info: CoreStateMachine::previous Nov 23 09:23:19 sonata volumio[925]: info: CorePlayQueue::getTrack 0 Nov 23 09:23:19 sonata volumio[925]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 09:23:19 sonata volumio[925]: TypeError: Cannot read property 'service' of undefined Nov 23 09:23:19 sonata volumio[925]: at CoreStateMachine.previous (/volumio/app/statemachine.js:1325:97) Nov 23 09:23:19 sonata volumio[925]: at CoreCommandRouter.volumioPrevious (/volumio/app/index.js:97:28) Nov 23 09:23:19 sonata volumio[925]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:270:33) Nov 23 09:23:19 sonata volumio[925]: at Socket.emit (events.js:315:20) Nov 23 09:23:19 sonata volumio[925]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 23 09:23:19 sonata volumio[925]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 23 09:23:19 sonata volumio[925]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 09:23:19 sonata sudo[7102]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-23 09:22 Nov 23 09:23:19 sonata sudo[7102]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"