-- Logs begin at Thu 2019-02-14 18:11:59 +08, end at Wed 2024-05-01 18:34:26 +08. -- May 01 18:33:02 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:02+08:00" level=debug msg="fetched chunk 9/18, size: 524288" May 01 18:33:16 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:16+08:00" level=debug msg="fetched chunk 10/18, size: 524288" May 01 18:33:19 volumiorpi3 volumio[864]: info: Preload queue cleared May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioReplaceandPlayItems May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::ClearQueue May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::stop May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::setConsumeUpdateService undefined May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::stPlaybackTimer May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::updateTrackBlock May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrackBlock May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 0 May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::serviceStop May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 0 May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::serviceStop May 01 18:33:19 volumiorpi3 volumio[864]: info: Spotify Stop May 01 18:33:19 volumiorpi3 volumio[864]: SPOTIFY: SPOTIFY STOP May 01 18:33:19 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","position":0,"title":"One Last Breath","artist":"Creed","album":"Weathered","albumart":"https://i.scdn.co/image/ab67616d0000b273a32f2ae4dade83e0d7a294f4","uri":"spotify:track:42T2QQv3xgBlpQxaSP7lnK","trackType":"spotify","codec":"ogg","seek":1,"duration":238,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":true,"repeatSingle":false,"consume":false,"volume":85,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} May 01 18:33:19 volumiorpi3 volumio[864]: info: Sending Spotify command to local API: /player/pause May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::clearPlayQueue May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::saveQueue May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushQueue May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::addQueueItems May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::addQueueItems May 01 18:33:19 volumiorpi3 volumio[864]: info: Preload queue cleared May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:6ouq07JR52uMIDnHhFbrQ2 May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:6ouq07JR52uMIDnHhFbrQ2 May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:3IrNhMvzard7nCKgfe18IW May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:3IrNhMvzard7nCKgfe18IW May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:3ySLzrN7950dpf1ncttONO May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:3ySLzrN7950dpf1ncttONO May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:6WK9dVrRABMkUXFLNlgWFh May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:6WK9dVrRABMkUXFLNlgWFh May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:40riOy7x9W7GXjyGp4pjAv May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:40riOy7x9W7GXjyGp4pjAv May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:0COqiPhxzoWICwFCS4eZcp May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:0COqiPhxzoWICwFCS4eZcp May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:3HNTLCpAGnizbyJmk7466r May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:3HNTLCpAGnizbyJmk7466r May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:19LnUKbcwoy6pHm0PshRwT May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:19LnUKbcwoy6pHm0PshRwT May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:4Vnbh54MMkRf2uZXcON3Av May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:4Vnbh54MMkRf2uZXcON3Av May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:7pa5oEfyt0tCeMHjHuQrCA May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:7pa5oEfyt0tCeMHjHuQrCA May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:17i5jLpzndlQhbS4SrTd0B May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:17i5jLpzndlQhbS4SrTd0B May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:0zhzkkSXFj60Y5fzb2j9hU May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:0zhzkkSXFj60Y5fzb2j9hU May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:6DLK0gTnZnWa1eh1oiFQri May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:6DLK0gTnZnWa1eh1oiFQri May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:67Hna13dNDkZvBpTXRIaOJ May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:67Hna13dNDkZvBpTXRIaOJ May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:1ItJjahltmjQNjit9sdksw May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:1ItJjahltmjQNjit9sdksw May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:6QgjcU0zLnzq5OrUoSZ3OK May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:6QgjcU0zLnzq5OrUoSZ3OK May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:5oE6INocVL9viDow5y8QNM May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:5oE6INocVL9viDow5y8QNM May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:71yXwcl1PNMmEBWYK6JMDV May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:71yXwcl1PNMmEBWYK6JMDV May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:5eAZSmWJjKNnMposeGbcCh May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:5eAZSmWJjKNnMposeGbcCh May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:5P6ZBMWS66FVo6deJaDdHy May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:5P6ZBMWS66FVo6deJaDdHy May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:3dPQuX8Gs42Y7b454ybpMR May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:3dPQuX8Gs42Y7b454ybpMR May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:4Pn0JlCUusD2QHjADuOzuV May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:4Pn0JlCUusD2QHjADuOzuV May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:4DsbdOinvRPoD2ax4DhxMU May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:4DsbdOinvRPoD2ax4DhxMU May 01 18:33:19 volumiorpi3 volumio[864]: info: Adding Item to queue: spotify:track:4bJdiWb6zsQmMnFIk2DBin May 01 18:33:19 volumiorpi3 volumio[864]: info: Using cached record of: spotify:track:4bJdiWb6zsQmMnFIk2DBin May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushQueue May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::saveQueue May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::updateTrackBlock May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrackBlock May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPlay May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::play index 10 May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::setConsumeUpdateService undefined May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::stop May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::setConsumeUpdateService undefined May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::play index undefined May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::setConsumeUpdateService undefined May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:19 volumiorpi3 volumio[864]: info: CoreStateMachine::startPlaybackTimer May 01 18:33:19 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:19 volumiorpi3 volumio[864]: info: [1714559599357] ControllerSpotify::clearAddPlayTrack May 01 18:33:19 volumiorpi3 volumio[864]: info: Sending Spotify command with payload to local API: /player/play May 01 18:33:19 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:19 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:19+08:00" level=debug msg="pause track at 90766ms" May 01 18:33:19 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:19+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="loading track spotify:track:17i5jLpzndlQhbS4SrTd0B (paused: false, position: 0ms)" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=trace msg="emitting websocket event: will_play" May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:17i5jLpzndlQhbS4SrTd0B" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="requested aes key for file a12cd87b410d159a898b90f59ab70444f3d61105, gid: 17i5jLpzndlQhbS4SrTd0B" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="fetched first chunk of 11, total size is 5356708 bytes" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" May 01 18:33:20 volumiorpi3 kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=info msg="loaded track \"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude\" (uri: spotify:track:17i5jLpzndlQhbS4SrTd0B, paused: false, position: 0ms, duration: 152280ms)" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=trace msg="emitting websocket event: metadata" May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","name":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist_names":["Johann Sebastian Bach","Yo-Yo Ma"],"album_name":"Bach: Cello Suites Nos. 1, 5 \u0026 6","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","position":0,"duration":152280,"release_date":"year:1983","track_number":1,"disc_number":1}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","name":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist_names":["Johann Sebastian Bach","Yo-Yo Ma"],"album_name":"Bach: Cello Suites Nos. 1, 5 \u0026 6","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","position":0,"duration":152280,"release_date":"year:1983","track_number":1,"disc_number":1}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","name":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist_names":["Johann Sebastian Bach","Yo-Yo Ma"],"album_name":"Bach: Cello Suites Nos. 1, 5 \u0026 6","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","position":0,"duration":152280,"release_date":"year:1983","track_number":1,"disc_number":1}} May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="fetched chunk 2/10, size: 524288" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=trace msg="emitting websocket event: paused" May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: {"status":"pause","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:20 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:20 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:20 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService pause May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus stop May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:20 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: {"status":"pause","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:20 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:20 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:20 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService pause May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus stop May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:20 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:20 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:20+08:00" level=debug msg="fetched chunk 3/10, size: 524288" May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: {"status":"pause","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:20 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:20 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:20 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService pause May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus stop May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:20 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:20 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:20 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:21+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 01 18:33:21 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:21+08:00" level=trace msg="emitting websocket event: playing" May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService play May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus stop May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService play May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus play May 01 18:33:21 volumiorpi3 volumio[864]: info: Received an update from plugin. extracting info from payload May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","play_origin":"go-librespot"}} May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService play May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus play May 01 18:33:21 volumiorpi3 volumio[864]: info: Received an update from plugin. extracting info from payload May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService play May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus play May 01 18:33:21 volumiorpi3 volumio[864]: info: Received an update from plugin. extracting info from payload May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:21+08:00" level=debug msg="fetched chunk 1/10, size: 524288" May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService play May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus play May 01 18:33:21 volumiorpi3 volumio[864]: info: Received an update from plugin. extracting info from payload May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: PUSH STATE SPOTIFY May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::servicePushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Cello Suite No. 1 in G Major, BWV 1007: I. Prélude","artist":"Johann Sebastian Bach, Yo-Yo Ma","album":"Bach: Cello Suites Nos. 1, 5 & 6","albumart":"https://i.scdn.co/image/ab67616d00001e02cbb64bd416bb225456100bbc","uri":"spotify:track:17i5jLpzndlQhbS4SrTd0B","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 01 18:33:21 volumiorpi3 volumio[864]: verbose: CURRENT POSITION 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState stateService play May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::syncState currentStatus play May 01 18:33:21 volumiorpi3 volumio[864]: info: Received an update from plugin. extracting info from payload May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:21 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:21 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:21 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 May 01 18:33:27 volumiorpi3 volumio[864]: info: VolumeController::SetAlsaVolume84 May 01 18:33:27 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:27 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:27 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:27 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: SPOTIFY VOLUME 85 May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: VOLUMIO VOLUME 84 May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: false May 01 18:33:27 volumiorpi3 volumio[864]: info: VolumeController::SetAlsaVolume90 May 01 18:33:27 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:27 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:27 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:27 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: SPOTIFY VOLUME 85 May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: VOLUMIO VOLUME 90 May 01 18:33:27 volumiorpi3 volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: true May 01 18:33:27 volumiorpi3 volumio[864]: info: Setting Spotify Volume from Volumio: 90 May 01 18:33:28 volumiorpi3 volumio[864]: info: VolumeController::SetAlsaVolume95 May 01 18:33:28 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:28 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:28 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:28 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: SPOTIFY VOLUME 90 May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: VOLUMIO VOLUME 95 May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: true May 01 18:33:28 volumiorpi3 volumio[864]: info: Setting Spotify Volume from Volumio: 95 May 01 18:33:28 volumiorpi3 volumio[864]: info: VolumeController::SetAlsaVolume97 May 01 18:33:28 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:33:28 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:33:28 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:33:28 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: SPOTIFY VOLUME 95 May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: VOLUMIO VOLUME 97 May 01 18:33:28 volumiorpi3 volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: true May 01 18:33:28 volumiorpi3 volumio[864]: info: Setting Spotify Volume from Volumio: 97 May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: SETTING SPOTIFY VOLUME 97 May 01 18:33:29 volumiorpi3 volumio[864]: info: Sending Spotify command with payload to local API: /player/volume May 01 18:33:29 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:29+08:00" level=debug msg="update volume to 63568/65535" May 01 18:33:29 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:29+08:00" level=debug msg="put connect state because VOLUME_CHANGED" May 01 18:33:29 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:29+08:00" level=trace msg="emitting websocket event: volume" May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"volume","data":{"value":97,"max":100}} May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED SPOTIFY VOLUME 97 May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"volume","data":{"value":97,"max":100}} May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED SPOTIFY VOLUME 97 May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: received: {"type":"volume","data":{"value":97,"max":100}} May 01 18:33:29 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED SPOTIFY VOLUME 97 May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 01 18:33:35 volumiorpi3 volumio[864]: info: Getting Alsa Cards List without I2S DAC May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 01 18:33:35 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 01 18:33:36 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:36+08:00" level=debug msg="fetched chunk 4/10, size: 524288" May 01 18:33:49 volumiorpi3 ntpd[687]: Soliciting pool server 47.254.196.78 May 01 18:33:51 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:33:51+08:00" level=debug msg="fetched chunk 5/10, size: 524288" May 01 18:33:54 volumiorpi3 ntpd[687]: Soliciting pool server 47.254.196.78 May 01 18:34:01 volumiorpi3 volumio[864]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioGetState May 01 18:34:01 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:34:01 volumiorpi3 volumio[864]: info: Restoring Previous Volume level: 97 false false May 01 18:34:01 volumiorpi3 volumio[864]: info: Volume configurations have been set May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 01 18:34:01 volumiorpi3 volumio[864]: info: Updating Volume Controller Parameters: Device: 2 Name: IQaudIO Pi-DigiAMP+ Mixer: Digital Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10 May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 01 18:34:01 volumiorpi3 volumio[864]: info: Disabling external Volume Control May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 01 18:34:01 volumiorpi3 volumio[864]: info: Getting Alsa Cards List without I2S DAC May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 01 18:34:01 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 01 18:34:02 volumiorpi3 volumio[864]: info: VolumeController:: Volume=96 Mute =false May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:34:02 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:34:02 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:34:02 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 May 01 18:34:02 volumiorpi3 volumio[864]: SPOTIFY: SPOTIFY VOLUME 97 May 01 18:34:02 volumiorpi3 volumio[864]: SPOTIFY: VOLUMIO VOLUME 96 May 01 18:34:02 volumiorpi3 volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: false May 01 18:34:06 volumiorpi3 volumio[864]: info: VolumeController::SetAlsaVolume97 May 01 18:34:06 volumiorpi3 volumio[864]: info: CoreStateMachine::pushState May 01 18:34:06 volumiorpi3 volumio[864]: info: CorePlayQueue::getTrack 10 May 01 18:34:06 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 01 18:34:06 volumiorpi3 volumio[864]: info: CoreCommandRouter::volumioPushState May 01 18:34:06 volumiorpi3 volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 May 01 18:34:06 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:34:06+08:00" level=debug msg="fetched chunk 6/10, size: 524288" May 01 18:34:11 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 01 18:34:11 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 01 18:34:19 volumiorpi3 go-librespot[2065]: time="2024-05-01T18:34:19+08:00" level=debug msg="fetched chunk 7/10, size: 524288" May 01 18:34:23 volumiorpi3 volumio[864]: info: Enabling plugin fusiondsp May 01 18:34:23 volumiorpi3 volumio[864]: info: Loading plugin "fusiondsp"... May 01 18:34:23 volumiorpi3 volumio[864]: error: Could not copy default configuration to /data/configuration/audio_interface/fusiondsp/config.json May 01 18:34:23 volumiorpi3 volumio[864]: info: Preparing to generate the ALSA configuration file May 01 18:34:23 volumiorpi3 volumio[864]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 01 18:34:23 volumiorpi3 volumio[864]: info: Reading ALSA contributions from plugins. May 01 18:34:23 volumiorpi3 volumio[864]: info: Asound.conf file written May 01 18:34:23 volumiorpi3 sudo[2500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 01 18:34:23 volumiorpi3 sudo[2500]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:23 volumiorpi3 sudo[2500]: pam_unix(sudo:session): session closed for user root May 01 18:34:23 volumiorpi3 volumio[864]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy May 01 18:34:23 volumiorpi3 volumio[864]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy May 01 18:34:23 volumiorpi3 volumio[864]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy May 01 18:34:23 volumiorpi3 volumio[864]: info: Output device has changed, restarting MPD May 01 18:34:23 volumiorpi3 sudo[2505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 18:34:23 volumiorpi3 volumio[864]: info: Output device has changed, restarting Shairport Sync May 01 18:34:23 volumiorpi3 sudo[2505]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:23 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:23 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:34:23 volumiorpi3 sudo[2505]: pam_unix(sudo:session): session closed for user root May 01 18:34:23 volumiorpi3 sudo[2507]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 18:34:23 volumiorpi3 sudo[2507]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:24 volumiorpi3 systemd[1]: Stopping Music Player Daemon... May 01 18:34:24 volumiorpi3 volumio[864]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 01 18:34:24 volumiorpi3 volumio[864]: info: PLUGIN START: fusiondsp May 01 18:34:24 volumiorpi3 volumio[864]: info: Loading i18n strings for locale en May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: FusionDsp - mixtype--------------------- Hardware May 01 18:34:24 volumiorpi3 volumio[864]: info: Preparing to generate the ALSA configuration file May 01 18:34:24 volumiorpi3 volumio[864]: info: Done. May 01 18:34:24 volumiorpi3 volumio[864]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 01 18:34:24 volumiorpi3 volumio[864]: info: Reading ALSA contributions from plugins. May 01 18:34:24 volumiorpi3 volumio[864]: info: MPD Permissions set May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: Starting Shairport Sync May 01 18:34:24 volumiorpi3 systemd[1]: mpd.service: Succeeded. May 01 18:34:24 volumiorpi3 systemd[1]: Stopped Music Player Daemon. May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin May 01 18:34:24 volumiorpi3 volumio[864]: info: Asound.conf file unchanged, so no further update is needed May 01 18:34:24 volumiorpi3 volumio[864]: info: Output device has changed, restarting MPD May 01 18:34:24 volumiorpi3 sudo[2520]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 18:34:24 volumiorpi3 sudo[2520]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:24 volumiorpi3 volumio[864]: info: Output device has changed, restarting Shairport Sync May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:34:24 volumiorpi3 systemd[1]: Starting Music Player Daemon... May 01 18:34:24 volumiorpi3 sudo[2526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 01 18:34:24 volumiorpi3 sudo[2523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 01 18:34:24 volumiorpi3 sudo[2523]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:24 volumiorpi3 sudo[2526]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:24 volumiorpi3 sudo[2523]: pam_unix(sudo:session): session closed for user root May 01 18:34:24 volumiorpi3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 18:34:24 volumiorpi3 systemd[1]: shairport-sync.service: Succeeded. May 01 18:34:24 volumiorpi3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 18:34:24 volumiorpi3 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 01 18:34:24 volumiorpi3 systemd[1]: mpd.service: Succeeded. May 01 18:34:24 volumiorpi3 systemd[1]: Stopped Music Player Daemon. May 01 18:34:24 volumiorpi3 volumio[864]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 01 18:34:24 volumiorpi3 systemd[1]: Starting Music Player Daemon... May 01 18:34:24 volumiorpi3 volumio[864]: info: MPD Permissions set May 01 18:34:24 volumiorpi3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 18:34:24 volumiorpi3 sudo[2520]: pam_unix(sudo:session): session closed for user root May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:24 volumiorpi3 volumio[864]: info: Shairport-Sync Started May 01 18:34:24 volumiorpi3 volumio[864]: info: Starting Shairport Sync May 01 18:34:24 volumiorpi3 sudo[2541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 01 18:34:24 volumiorpi3 sudo[2541]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:24 volumiorpi3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 01 18:34:24 volumiorpi3 systemd[1]: shairport-sync.service: Succeeded. May 01 18:34:24 volumiorpi3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 01 18:34:24 volumiorpi3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 01 18:34:24 volumiorpi3 sudo[2541]: pam_unix(sudo:session): session closed for user root May 01 18:34:24 volumiorpi3 volumio[864]: info: Shairport-Sync Started May 01 18:34:25 volumiorpi3 volumio[864]: Configuration write error: Error: ENOENT: no such file or directory, open '/data/configuration/audio_interface/fusiondsp/config.json' May 01 18:34:25 volumiorpi3 volumio[864]: info: CoreCommandRouter::getUIConfigOnPlugin May 01 18:34:25 volumiorpi3 mpd[2532]: May 01 18:34 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 01 18:34:25 volumiorpi3 systemd[1]: Started Music Player Daemon. May 01 18:34:25 volumiorpi3 sudo[2526]: pam_unix(sudo:session): session closed for user root May 01 18:34:25 volumiorpi3 sudo[2507]: pam_unix(sudo:session): session closed for user root May 01 18:34:25 volumiorpi3 volumio[864]: error: MPD error: The expression evaluated to a falsy value: May 01 18:34:25 volumiorpi3 volumio[864]: assert.ok(self.idling) May 01 18:34:25 volumiorpi3 volumio[864]: error: The expression evaluated to a falsy value: May 01 18:34:25 volumiorpi3 volumio[864]: assert.ok(self.idling) May 01 18:34:25 volumiorpi3 volumio[864]: error: updateQueue error: null May 01 18:34:26 volumiorpi3 volumio[864]: info: camilladsp spawned new process with pid undefined, instance 1, run: true May 01 18:34:26 volumiorpi3 volumio[864]: info: camilladsp service started and running in background, instance 1 May 01 18:34:26 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 01 18:34:26 volumiorpi3 volumio[864]: /bin/sh: 1: cannot create /data/configuration/audio_interface/fusiondsp/hwinfo.json: Directory nonexistent May 01 18:34:26 volumiorpi3 volumio[864]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 01 18:34:26 volumiorpi3 volumio[864]: /bin/sh: 1: cannot create /data/configuration/audio_interface/fusiondsp/hwinfo.json: Directory nonexistent May 01 18:34:26 volumiorpi3 volumio[864]: info: FusionDsp loaded May 01 18:34:26 volumiorpi3 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 01 18:34:26 volumiorpi3 sudo[2558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 01 18:34:26 volumiorpi3 sudo[2558]: pam_unix(sudo:session): session opened for user root by (uid=0) May 01 18:34:26 volumiorpi3 volumio[864]: info: FusionDsp - Reporting Fusion DSP Enabled May 01 18:34:26 volumiorpi3 volumio[864]: info: Adding Signal Path Element [object Object] May 01 18:34:26 volumiorpi3 volumio[864]: info: Adding fusiondspeq DSP Signal Path Element May 01 18:34:26 volumiorpi3 volumio[864]: info: FusionDsp - ---- installed callbackRead May 01 18:34:26 volumiorpi3 volumio[864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 01 18:34:26 volumiorpi3 volumio[864]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp EACCES May 01 18:34:26 volumiorpi3 volumio[864]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) May 01 18:34:26 volumiorpi3 volumio[864]: at onErrorNT (internal/child_process.js:465:16) May 01 18:34:26 volumiorpi3 volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { May 01 18:34:26 volumiorpi3 volumio[864]: errno: -13, May 01 18:34:26 volumiorpi3 volumio[864]: code: 'EACCES', May 01 18:34:26 volumiorpi3 volumio[864]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', May 01 18:34:26 volumiorpi3 volumio[864]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', May 01 18:34:26 volumiorpi3 volumio[864]: spawnargs: [ May 01 18:34:26 volumiorpi3 volumio[864]: '-p', May 01 18:34:26 volumiorpi3 volumio[864]: 9876, May 01 18:34:26 volumiorpi3 volumio[864]: '-o', May 01 18:34:26 volumiorpi3 volumio[864]: '/tmp/camilladsp.log', May 01 18:34:26 volumiorpi3 volumio[864]: '-l', May 01 18:34:26 volumiorpi3 volumio[864]: 'warn', May 01 18:34:26 volumiorpi3 volumio[864]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' May 01 18:34:26 volumiorpi3 volumio[864]: ] May 01 18:34:26 volumiorpi3 volumio[864]: } May 01 18:34:26 volumiorpi3 volumio[864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 01 18:34:26 volumiorpi3 systemd[1]: Started FusionDsp Daemon. May 01 18:34:26 volumiorpi3 sudo[2558]: pam_unix(sudo:session): session closed for user root May 01 18:34:26 volumiorpi3 volumio[2560]: /usr/bin/python3: can't open file '/data/plugins/audio_interface/fusiondsp/cgui/main.py': [Errno 2] No such file or directory May 01 18:34:26 volumiorpi3 systemd[1]: fusiondsp.service: Main process exited, code=exited, status=2/INVALIDARGUMENT May 01 18:34:26 volumiorpi3 systemd[1]: fusiondsp.service: Failed with result 'exit-code'. May 01 18:34:26 volumiorpi3 sudo[2570]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-01 18:33 May 01 18:34:26 volumiorpi3 sudo[2570]: 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"