-- Logs begin at Thu 2019-02-14 02:11:59 PST, end at Fri 2024-11-22 17:22:05 PST. -- Nov 22 17:21:08 volumio volumio[1006]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] Nov 22 17:21:08 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions Nov 22 17:21:08 volumio volumio[1006]: info: [ASDebug] Saving Settings: Port: 11 Nov 22 17:21:08 volumio volumio[1006]: info: [ASDebug] Saving Settings: Inverted: false Nov 22 17:21:08 volumio volumio[1006]: info: [ASDebug] Saving Settings: Delay: 60000 Nov 22 17:21:08 volumio volumio[1006]: info: [ASDebug] Saving Settings: Latched: false Nov 22 17:21:08 volumio volumio[1006]: info: [ASDebug] Saving Settings: On Pulse width: 500 Nov 22 17:21:08 volumio volumio[1006]: info: [ASDebug] Saving Settings: Off Pulse width: 500 Nov 22 17:21:09 volumio go-librespot[1203]: time="2024-11-22T17:21:09-08:00" level=debug msg="fetched chunk 12/19, size: 524288" uri="spotify:track:5dcUUklOiH01fVEH5pmWRs" Nov 22 17:21:11 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 22 17:21:11 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 22 17:21:13 volumio go-librespot[1203]: time="2024-11-22T17:21:13-08:00" level=debug msg="handling pause player command from 7ca019106350edd20088fd196402ec05e938d792" Nov 22 17:21:13 volumio go-librespot[1203]: time="2024-11-22T17:21:13-08:00" level=debug msg="pause track at 116397ms" Nov 22 17:21:13 volumio go-librespot[1203]: time="2024-11-22T17:21:13-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:13 volumio go-librespot[1203]: time="2024-11-22T17:21:13-08:00" level=debug msg="sending successful reply for dealer request" Nov 22 17:21:14 volumio go-librespot[1203]: time="2024-11-22T17:21:14-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:14 volumio go-librespot[1203]: time="2024-11-22T17:21:14-08:00" level=trace msg="emitting websocket event: paused" Nov 22 17:21:14 volumio volumio[1006]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","play_origin":"artist"}} Nov 22 17:21:14 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:14 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":115000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:14 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:14 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:14 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 17:21:14 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:14 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:14 volumio volumio[1006]: info: [ASDebug] CurState: pause PrevState: play Nov 22 17:21:14 volumio volumio[1006]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=debug msg="handling resume player command from 7ca019106350edd20088fd196402ec05e938d792" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=trace msg="seek to 116397ms (diff: 161ms, samples: 5133107, bytes: 4874223)" uri="spotify:track:5dcUUklOiH01fVEH5pmWRs" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=debug msg="resume track at 116236ms" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=trace msg="scheduling prefetch in 91s" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=debug msg="sending successful reply for dealer request" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:15 volumio go-librespot[1203]: time="2024-11-22T17:21:15-08:00" level=trace msg="emitting websocket event: playing" Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","play_origin":"artist"}} Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":115000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:15 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:15 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:15 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 17:21:15 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:15 volumio volumio[1006]: info: [ASDebug] CurState: play PrevState: play Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":115000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:15 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:15 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:15 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:15 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:15 volumio volumio[1006]: info: [ASDebug] CurState: play PrevState: play Nov 22 17:21:16 volumio go-librespot[1203]: time="2024-11-22T17:21:16-08:00" level=debug msg="handling pause player command from 7ca019106350edd20088fd196402ec05e938d792" Nov 22 17:21:16 volumio go-librespot[1203]: time="2024-11-22T17:21:16-08:00" level=debug msg="pause track at 117715ms" Nov 22 17:21:17 volumio go-librespot[1203]: time="2024-11-22T17:21:17-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:17 volumio go-librespot[1203]: time="2024-11-22T17:21:17-08:00" level=debug msg="sending successful reply for dealer request" Nov 22 17:21:17 volumio go-librespot[1203]: time="2024-11-22T17:21:17-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:17 volumio go-librespot[1203]: time="2024-11-22T17:21:17-08:00" level=trace msg="emitting websocket event: paused" Nov 22 17:21:17 volumio volumio[1006]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","play_origin":"artist"}} Nov 22 17:21:17 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:17 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":116000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:17 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:17 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:17 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 17:21:17 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:17 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:17 volumio volumio[1006]: info: [ASDebug] CurState: pause PrevState: play Nov 22 17:21:17 volumio volumio[1006]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Nov 22 17:21:20 volumio volumio[1006]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 17:21:20 volumio volumio[1006]: info: [ASDebug] Setting UI defaults Nov 22 17:21:20 volumio volumio[1006]: info: [ASDebug] Port: 11 Nov 22 17:21:20 volumio volumio[1006]: info: [ASDebug] Inverted: false Nov 22 17:21:20 volumio volumio[1006]: info: [ASDebug] Latched: false Nov 22 17:21:20 volumio volumio[1006]: info: [ASDebug] On pulse width: 500 Nov 22 17:21:20 volumio volumio[1006]: info: [ASDebug] Off pulse width: 500 Nov 22 17:21:25 volumio volumio[1006]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] Nov 22 17:21:25 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions Nov 22 17:21:25 volumio volumio[1006]: info: [ASDebug] Saving Settings: Port: 11 Nov 22 17:21:25 volumio volumio[1006]: info: [ASDebug] Saving Settings: Inverted: false Nov 22 17:21:25 volumio volumio[1006]: info: [ASDebug] Saving Settings: Delay: 720 Nov 22 17:21:25 volumio volumio[1006]: info: [ASDebug] Saving Settings: Latched: false Nov 22 17:21:25 volumio volumio[1006]: info: [ASDebug] Saving Settings: On Pulse width: 500 Nov 22 17:21:25 volumio volumio[1006]: info: [ASDebug] Saving Settings: Off Pulse width: 500 Nov 22 17:21:27 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 22 17:21:27 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=debug msg="handling resume player command from 7ca019106350edd20088fd196402ec05e938d792" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=trace msg="seek to 117715ms (diff: 79ms, samples: 5191231, bytes: 4929006)" uri="spotify:track:5dcUUklOiH01fVEH5pmWRs" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=debug msg="resume track at 117565ms" Nov 22 17:21:30 volumio kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=trace msg="scheduling prefetch in 90s" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=debug msg="sending successful reply for dealer request" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:30 volumio go-librespot[1203]: time="2024-11-22T17:21:30-08:00" level=trace msg="emitting websocket event: playing" Nov 22 17:21:30 volumio volumio[1006]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","play_origin":"artist"}} Nov 22 17:21:30 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:30 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":116000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:30 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:30 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:30 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 17:21:30 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:30 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:30 volumio volumio[1006]: info: [ASDebug] CurState: play PrevState: play Nov 22 17:21:30 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:30 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":116000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:30 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:30 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:30 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:31 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:31 volumio volumio[1006]: info: [ASDebug] CurState: play PrevState: play Nov 22 17:21:34 volumio go-librespot[1203]: time="2024-11-22T17:21:34-08:00" level=debug msg="handling pause player command from 7ca019106350edd20088fd196402ec05e938d792" Nov 22 17:21:34 volumio go-librespot[1203]: time="2024-11-22T17:21:34-08:00" level=debug msg="pause track at 121433ms" Nov 22 17:21:34 volumio go-librespot[1203]: time="2024-11-22T17:21:34-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:34 volumio go-librespot[1203]: time="2024-11-22T17:21:34-08:00" level=debug msg="sending successful reply for dealer request" Nov 22 17:21:34 volumio go-librespot[1203]: time="2024-11-22T17:21:34-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:21:34 volumio go-librespot[1203]: time="2024-11-22T17:21:34-08:00" level=trace msg="emitting websocket event: paused" Nov 22 17:21:34 volumio volumio[1006]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","play_origin":"artist"}} Nov 22 17:21:34 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:21:34 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":119000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:21:34 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:21:34 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:21:34 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 17:21:34 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:21:34 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:21:34 volumio volumio[1006]: info: [ASDebug] CurState: pause PrevState: play Nov 22 17:21:34 volumio volumio[1006]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Nov 22 17:21:35 volumio volumio[1006]: info: [ASDebug] Togle GPIO: OFF Nov 22 17:21:37 volumio volumio[1006]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 22 17:21:37 volumio volumio[1006]: info: [ASDebug] Setting UI defaults Nov 22 17:21:37 volumio volumio[1006]: info: [ASDebug] Port: 11 Nov 22 17:21:37 volumio volumio[1006]: info: [ASDebug] Inverted: false Nov 22 17:21:37 volumio volumio[1006]: info: [ASDebug] Latched: false Nov 22 17:21:37 volumio volumio[1006]: info: [ASDebug] On pulse width: 500 Nov 22 17:21:37 volumio volumio[1006]: info: [ASDebug] Off pulse width: 500 Nov 22 17:21:46 volumio volumio[1006]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] Nov 22 17:21:46 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions Nov 22 17:21:46 volumio volumio[1006]: info: [ASDebug] Saving Settings: Port: 11 Nov 22 17:21:46 volumio volumio[1006]: info: [ASDebug] Saving Settings: Inverted: false Nov 22 17:21:46 volumio volumio[1006]: info: [ASDebug] Saving Settings: Delay: 720 Nov 22 17:21:46 volumio volumio[1006]: info: [ASDebug] Saving Settings: Latched: false Nov 22 17:21:46 volumio volumio[1006]: info: [ASDebug] Saving Settings: On Pulse width: 500 Nov 22 17:21:46 volumio volumio[1006]: info: [ASDebug] Saving Settings: Off Pulse width: 500 Nov 22 17:21:48 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 22 17:21:49 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 22 17:21:51 volumio volumio[1006]: info: [ASDebug] Port: 11 Nov 22 17:21:51 volumio volumio[1006]: info: [ASDebug] Inverted: false Nov 22 17:21:51 volumio volumio[1006]: info: [ASDebug] Delay: 720 Nov 22 17:21:53 volumio volumio[1006]: info: Enabling plugin gpio_control Nov 22 17:21:53 volumio volumio[1006]: info: Loading plugin "gpio_control"... Nov 22 17:21:53 volumio volumio[1006]: info: Applying required configuration parameters for plugin gpio_control Nov 22 17:21:53 volumio volumio[1006]: info: PLUGIN START: gpio_control Nov 22 17:21:53 volumio volumio[1006]: info: Error: Error: EINVAL: invalid argument, write Nov 22 17:21:53 volumio kernel: export_store: invalid GPIO 11 Nov 22 17:21:53 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Nov 22 17:21:57 volumio volumio[1006]: info: Starting Uninstall of plugin system_hardware - gpio_control Nov 22 17:21:57 volumio volumio[1006]: info: Uninstalling plugin gpio_control Nov 22 17:21:57 volumio volumio[1006]: info: Disabling plugin gpio_control Nov 22 17:21:57 volumio volumio[1006]: info: Checking if uninstall.sh is present Nov 22 17:21:57 volumio volumio[1006]: info: Executing uninstall.sh Nov 22 17:21:57 volumio sudo[2447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/system_hardware/gpio_control/uninstall.sh Nov 22 17:21:57 volumio sudo[2447]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 22 17:21:57 volumio sudo[2447]: pam_unix(sudo:session): session closed for user root Nov 22 17:21:57 volumio volumio[1006]: info: Uninstall script completed Nov 22 17:21:57 volumio volumio[1006]: info: Removing plugin gpio_control from configuration Nov 22 17:21:58 volumio volumio[1006]: info: Successfully removed gpio_control configuration files Nov 22 17:21:58 volumio volumio[1006]: info: Plugin folders cleanup Nov 22 17:21:58 volumio volumio[1006]: info: Scanning into folder /volumio/app/plugins/ Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category audio_interface Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category miscellanea Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category music_service Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category plugins.json Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category system_controller Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category user_interface Nov 22 17:21:58 volumio volumio[1006]: info: Scanning into folder /data/plugins/ Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category music_service Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category system_controller Nov 22 17:21:58 volumio volumio[1006]: info: Scanning category system_hardware Nov 22 17:21:58 volumio volumio[1006]: info: Cleaning folder for gpio_control Nov 22 17:21:58 volumio volumio[1006]: info: Plugin folders cleanup completed Nov 22 17:21:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 22 17:21:58 volumio volumio[1006]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.0","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Amplifier Switch","name":"ampswitch","category":"system_controller","version":"0.2.1","icon":"fa-power-off","isManuallyInstalled":false,"enabled":true,"active":false}] Nov 22 17:21:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=debug msg="handling resume player command from 7ca019106350edd20088fd196402ec05e938d792" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=trace msg="seek to 121433ms (diff: 148ms, samples: 5355195, bytes: 5081324)" uri="spotify:track:5dcUUklOiH01fVEH5pmWRs" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=debug msg="resume track at 121214ms" Nov 22 17:22:04 volumio kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=trace msg="scheduling prefetch in 86s" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=debug msg="sending successful reply for dealer request" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 17:22:04 volumio go-librespot[1203]: time="2024-11-22T17:22:04-08:00" level=trace msg="emitting websocket event: playing" Nov 22 17:22:04 volumio volumio[1006]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","play_origin":"artist"}} Nov 22 17:22:04 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Nov 22 17:22:04 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Extreme Ways","artist":"Moby","album":"18 & 18 B-Sides","albumart":"https://i.scdn.co/image/ab67616d00001e021fefc78cc3add698ee8a34ae","uri":"spotify:track:5dcUUklOiH01fVEH5pmWRs","trackType":"spotify","seek":119000,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 22 17:22:04 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Nov 22 17:22:04 volumio volumio[1006]: info: CoreStateMachine::pushState Nov 22 17:22:04 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 22 17:22:04 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Nov 22 17:22:04 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Nov 22 17:22:04 volumio volumio[1006]: info: [ASDebug] CurState: play PrevState: pause Nov 22 17:22:04 volumio volumio[1006]: info: [ASDebug] Togle GPIO: ON Nov 22 17:22:04 volumio volumio[1006]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 22 17:22:04 volumio volumio[1006]: Error: EBADF: bad file descriptor, write Nov 22 17:22:04 volumio volumio[1006]: at Object.writeSync (fs.js:711:3) Nov 22 17:22:04 volumio volumio[1006]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Nov 22 17:22:04 volumio volumio[1006]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) Nov 22 17:22:04 volumio volumio[1006]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) Nov 22 17:22:04 volumio volumio[1006]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Nov 22 17:22:04 volumio volumio[1006]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) Nov 22 17:22:04 volumio volumio[1006]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) Nov 22 17:22:04 volumio volumio[1006]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Nov 22 17:22:04 volumio volumio[1006]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Nov 22 17:22:04 volumio volumio[1006]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) Nov 22 17:22:04 volumio volumio[1006]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Nov 22 17:22:04 volumio volumio[1006]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Nov 22 17:22:04 volumio volumio[1006]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) Nov 22 17:22:04 volumio volumio[1006]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) Nov 22 17:22:04 volumio volumio[1006]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Nov 22 17:22:04 volumio volumio[1006]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) { Nov 22 17:22:04 volumio volumio[1006]: errno: -9, Nov 22 17:22:04 volumio volumio[1006]: syscall: 'write', Nov 22 17:22:04 volumio volumio[1006]: code: 'EBADF' Nov 22 17:22:04 volumio volumio[1006]: } Nov 22 17:22:04 volumio volumio[1006]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 22 17:22:05 volumio sudo[2518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-22 17:21 Nov 22 17:22:05 volumio sudo[2518]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"