-- Logs begin at Thu 2019-02-14 17:11:59 +07, end at Fri 2024-07-26 22:05:55 +07. -- Jul 26 22:04:05 volumio go-librespot[1294]: time="2024-07-26T22:04:05+07:00" level=debug msg="fetched chunk 16/19, size: 524288" Jul 26 22:04:17 volumio go-librespot[1294]: time="2024-07-26T22:04:17+07:00" level=debug msg="fetched chunk 17/19, size: 524288" Jul 26 22:04:31 volumio go-librespot[1294]: time="2024-07-26T22:04:31+07:00" level=debug msg="fetched chunk 18/19, size: 524288" Jul 26 22:04:44 volumio go-librespot[1294]: time="2024-07-26T22:04:44+07:00" level=debug msg="fetched chunk 19/19, size: 206397" Jul 26 22:05:29 volumio go-librespot[1294]: time="2024-07-26T22:05:29+07:00" level=trace msg="emitting websocket event: not_playing" Jul 26 22:05:29 volumio go-librespot[1294]: time="2024-07-26T22:05:29+07:00" level=debug msg="loading track spotify:track:3yNXmA1gOWkefrcTfCoISK (paused: true, position: 0ms)" Jul 26 22:05:29 volumio volumio[971]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","play_origin":"playlist"}} Jul 26 22:05:29 volumio volumio[971]: error: Failed to decode event: not_playing Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=trace msg="emitting websocket event: will_play" Jul 26 22:05:30 volumio volumio[971]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","play_origin":"playlist"}} Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:3yNXmA1gOWkefrcTfCoISK" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=debug msg="requested aes key for file fec00f6ef1e17a8559728dfae38c9906a5c8c4ae, gid: 3yNXmA1gOWkefrcTfCoISK" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=debug msg="fetched first chunk of 20, total size is 10167869 bytes" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=info msg="loaded track \"Small Day Tomorrow - Radio Edit\" (uri: spotify:track:3yNXmA1gOWkefrcTfCoISK, paused: true, position: 0ms, duration: 246315ms)" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=debug msg="fetched chunk 2/19, size: 524288" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=trace msg="emitting websocket event: metadata" Jul 26 22:05:30 volumio go-librespot[1294]: time="2024-07-26T22:05:30+07:00" level=trace msg="emitting websocket event: stopped" Jul 26 22:05:30 volumio volumio[971]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","name":"Small Day Tomorrow - Radio Edit","artist_names":["Olaf Olsen"],"album_name":"Sentimental Journey","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ba971f914c1ba994243b8180","position":0,"duration":246315}} Jul 26 22:05:31 volumio volumio[971]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"playlist"}} Jul 26 22:05:31 volumio volumio[971]: SPOTIFY: PUSH STATE SPOTIFY Jul 26 22:05:31 volumio volumio[971]: SPOTIFY: {"status":"stop","service":"spop","title":"Small Day Tomorrow - Radio Edit","artist":"Olaf Olsen","album":"Sentimental Journey","albumart":"https://i.scdn.co/image/ab67616d00001e02ba971f914c1ba994243b8180","uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","trackType":"spotify","seek":0,"duration":246,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 26 22:05:31 volumio volumio[971]: info: CoreCommandRouter::servicePushState Jul 26 22:05:31 volumio volumio[971]: info: CoreStateMachine::pushState Jul 26 22:05:31 volumio volumio[971]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 26 22:05:31 volumio volumio[971]: info: CoreCommandRouter::volumioPushState Jul 26 22:05:31 volumio volumio[971]: info: CorePlayQueue::getTrack 5 Jul 26 22:05:31 volumio volumio[971]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received spop Jul 26 22:05:31 volumio go-librespot[1294]: time="2024-07-26T22:05:31+07:00" level=debug msg="fetched chunk 1/19, size: 524288" Jul 26 22:05:31 volumio go-librespot[1294]: time="2024-07-26T22:05:31+07:00" level=debug msg="fetched chunk 3/19, size: 524288" Jul 26 22:05:31 volumio go-librespot[1294]: time="2024-07-26T22:05:31+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 26 22:05:31 volumio go-librespot[1294]: time="2024-07-26T22:05:31+07:00" level=trace msg="emitting websocket event: paused" Jul 26 22:05:31 volumio volumio[971]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","play_origin":"playlist"}} Jul 26 22:05:31 volumio volumio[971]: SPOTIFY: PUSH STATE SPOTIFY Jul 26 22:05:31 volumio volumio[971]: SPOTIFY: {"status":"pause","service":"spop","title":"Small Day Tomorrow - Radio Edit","artist":"Olaf Olsen","album":"Sentimental Journey","albumart":"https://i.scdn.co/image/ab67616d00001e02ba971f914c1ba994243b8180","uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","trackType":"spotify","seek":0,"duration":246,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 26 22:05:31 volumio volumio[971]: info: CoreCommandRouter::servicePushState Jul 26 22:05:31 volumio volumio[971]: info: CoreStateMachine::pushState Jul 26 22:05:31 volumio volumio[971]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 26 22:05:31 volumio volumio[971]: info: CoreCommandRouter::volumioPushState Jul 26 22:05:53 volumio volumio[971]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 26 22:05:53 volumio volumio[971]: info: CoreStateMachine::ClearQueue Jul 26 22:05:53 volumio volumio[971]: info: CoreStateMachine::stop Jul 26 22:05:53 volumio volumio[971]: info: CoreStateMachine::serviceStop Jul 26 22:05:53 volumio volumio[971]: info: CoreCommandRouter::serviceStop Jul 26 22:05:53 volumio volumio[971]: info: Spotify Stop Jul 26 22:05:53 volumio volumio[971]: SPOTIFY: SPOTIFY STOP Jul 26 22:05:53 volumio volumio[971]: SPOTIFY: {"status":"pause","title":"Small Day Tomorrow - Radio Edit","artist":"Olaf Olsen","album":"Sentimental Journey","albumart":"https://i.scdn.co/image/ab67616d00001e02ba971f914c1ba994243b8180","uri":"spotify:track:3yNXmA1gOWkefrcTfCoISK","trackType":"spotify","codec":"ogg","seek":0,"duration":246,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":true,"volatile":true,"service":"spop"} Jul 26 22:05:53 volumio volumio[971]: info: Sending Spotify command to local API: /player/pause Jul 26 22:05:53 volumio volumio[971]: info: CorePlayQueue::clearPlayQueue Jul 26 22:05:53 volumio volumio[971]: info: CorePlayQueue::saveQueue Jul 26 22:05:53 volumio volumio[971]: info: CoreCommandRouter::volumioPushQueue Jul 26 22:05:53 volumio volumio[971]: info: CoreStateMachine::addQueueItems Jul 26 22:05:53 volumio volumio[971]: info: CorePlayQueue::addQueueItems Jul 26 22:05:53 volumio volumio[971]: info: Preload queue cleared Jul 26 22:05:53 volumio volumio[971]: info: Adding Item to queue: music-library/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD) Jul 26 22:05:53 volumio volumio[971]: info: Exploding uri music-library/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD) in service mpd Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F01%20-%20Hey%20There.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/01 - Hey There.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F02%20-%20My%20Foolish%20Heart.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/02 - My Foolish Heart.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F03%20-%20Little%20Girl%20Blue.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/03 - Little Girl Blue.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F04%20-%20Too%20Young.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/04 - Too Young.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F05%20-%20Misty.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/05 - Misty.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F06%20-%20Someone%20That%20I%20Used%20to%20Love.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/06 - Someone That I Used to Love.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F07%20-%20Bewitched.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/07 - Bewitched.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F08%20-%20Bridge%20over%20Troubled%20Water.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/08 - Bridge over Troubled Water.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F09%20-%20Just%20the%20Way%20You%20Are.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/09 - Just the Way You Are.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F10%20-%20Tears%20in%20Heaven.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/10 - Tears in Heaven.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F11%20-%20Georgia%20on%20My%20Mind.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/11 - Georgia on My Mind.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F12%20-%20When%20You%20Smile.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/12 - When You Smile.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2F13%20-%20Tea%20for%20Two.flac&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/13 - Tea for Two.flac Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2FA%20World%20of%20Love.cue&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/A World of Love.cue Jul 26 22:05:54 volumio volumio[971]: info: ALBUMART /albumart?cacheid=57&web=Ayako%20Hosokawa/A%20World%20of%20Love/extralarge&path=%2Fmnt%2FNAS%2F%D0%9D%D0%BE%D0%B2%D1%8B%D0%B9_%D1%82%D0%BE%D0%BC%2FAyako%20Hosokawa%20-%20A%20World%20of%20Love%20(1997%2C%20FIM-XRCD)%2FA%20World%20of%20Love.cue&metadata=false Jul 26 22:05:54 volumio volumio[971]: info: URI /mnt/NAS/Новый_том/Ayako Hosokawa - A World of Love (1997, FIM-XRCD)/A World of Love.cue Jul 26 22:05:54 volumio volumio[971]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 26 22:05:54 volumio volumio[971]: Error: Unable to resolve or reject the same promise twice Jul 26 22:05:54 volumio volumio[971]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jul 26 22:05:54 volumio volumio[971]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Jul 26 22:05:54 volumio volumio[971]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Jul 26 22:05:54 volumio volumio[971]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Jul 26 22:05:54 volumio volumio[971]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Jul 26 22:05:54 volumio volumio[971]: at Socket.emit (events.js:315:20) Jul 26 22:05:54 volumio volumio[971]: at addChunk (internal/streams/readable.js:309:12) Jul 26 22:05:54 volumio volumio[971]: at readableAddChunk (internal/streams/readable.js:280:11) Jul 26 22:05:54 volumio volumio[971]: at Socket.Readable.push (internal/streams/readable.js:223:10) Jul 26 22:05:54 volumio volumio[971]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Jul 26 22:05:54 volumio volumio[971]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 26 22:05:55 volumio sudo[18192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-26 22:04 Jul 26 22:05:55 volumio sudo[18192]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"