-- 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"