-- Logs begin at Thu 2019-02-14 23:11:59 NZDT, end at Sat 2024-05-04 17:59:11 NZST. -- May 04 17:58:01 volumio go-librespot[1073]: time="2024-05-04T17:58:01+12:00" level=trace msg="emitting websocket event: not_playing" May 04 17:58:01 volumio go-librespot[1073]: time="2024-05-04T17:58:01+12:00" level=debug msg="loading track spotify:track:32X9ALMtpYkpTUINneRZSE (paused: false, position: 0ms)" May 04 17:58:01 volumio volumio[863]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:2MCFkkrdgKS6p7NEP8ypip","play_origin":"collection-songs"}} May 04 17:58:01 volumio volumio[863]: error: Failed to decode event: not_playing May 04 17:58:01 volumio go-librespot[1073]: time="2024-05-04T17:58:01+12:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 17:58:01 volumio go-librespot[1073]: time="2024-05-04T17:58:01+12:00" level=trace msg="emitting websocket event: will_play" May 04 17:58:01 volumio volumio[863]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:32X9ALMtpYkpTUINneRZSE","play_origin":"collection-songs"}} May 04 17:58:02 volumio go-librespot[1073]: time="2024-05-04T17:58:02+12:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:32X9ALMtpYkpTUINneRZSE" May 04 17:58:02 volumio go-librespot[1073]: time="2024-05-04T17:58:02+12:00" level=debug msg="requested aes key for file 0b83281a917a30a2a14b65a8de3c0faeff2efbca, gid: 32X9ALMtpYkpTUINneRZSE" May 04 17:58:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 04 17:58:02 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=debug msg="fetched first chunk of 17, total size is 8897560 bytes" May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" May 04 17:58:04 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=info msg="loaded track \"Compadre\" (uri: spotify:track:32X9ALMtpYkpTUINneRZSE, paused: false, position: 0ms, duration: 201446ms)" May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=debug msg="fetched chunk 1/16, size: 524288" May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=trace msg="emitting websocket event: metadata" May 04 17:58:04 volumio volumio[863]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:32X9ALMtpYkpTUINneRZSE","name":"Compadre","artist_names":["Status the Marlboro Man","Krookid Hooks","A-F-R-O"],"album_name":"Compadre","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f3d1dd610e9c6d8319b9fc66","position":0,"duration":201446,"release_date":"year:2023 month:2 day:25","track_number":1,"disc_number":1}} May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=debug msg="fetched chunk 2/16, size: 524288" May 04 17:58:04 volumio go-librespot[1073]: time="2024-05-04T17:58:04+12:00" level=debug msg="fetched chunk 3/16, size: 524288" May 04 17:58:05 volumio go-librespot[1073]: time="2024-05-04T17:58:05+12:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 17:58:05 volumio go-librespot[1073]: time="2024-05-04T17:58:05+12:00" level=trace msg="emitting websocket event: playing" May 04 17:58:05 volumio volumio[863]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:32X9ALMtpYkpTUINneRZSE","play_origin":"collection-songs"}} May 04 17:58:05 volumio volumio[863]: SPOTIFY: PUSH STATE SPOTIFY May 04 17:58:05 volumio volumio[863]: SPOTIFY: {"status":"play","service":"spop","title":"Compadre","artist":"Status the Marlboro Man, Krookid Hooks, A-F-R-O","album":"Compadre","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d1dd610e9c6d8319b9fc66","uri":"spotify:track:32X9ALMtpYkpTUINneRZSE","trackType":"spotify","seek":0,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 04 17:58:05 volumio volumio[863]: info: CoreCommandRouter::servicePushState May 04 17:58:05 volumio volumio[863]: info: CoreStateMachine::pushState May 04 17:58:05 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 17:58:05 volumio volumio[863]: info: CoreCommandRouter::volumioPushState May 04 17:58:05 volumio volumio[863]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 04 17:58:05 volumio volumio[863]: SPOTIFY: PUSH STATE SPOTIFY May 04 17:58:05 volumio volumio[863]: SPOTIFY: {"status":"play","service":"spop","title":"Compadre","artist":"Status the Marlboro Man, Krookid Hooks, A-F-R-O","album":"Compadre","albumart":"https://i.scdn.co/image/ab67616d00001e02f3d1dd610e9c6d8319b9fc66","uri":"spotify:track:32X9ALMtpYkpTUINneRZSE","trackType":"spotify","seek":1000,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 04 17:58:05 volumio volumio[863]: info: CoreCommandRouter::servicePushState May 04 17:58:05 volumio volumio[863]: info: CoreStateMachine::pushState May 04 17:58:05 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 17:58:05 volumio volumio[863]: info: CoreCommandRouter::volumioPushState May 04 17:58:05 volumio volumio[863]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 04 17:58:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 04 17:58:11 volumio volumio[863]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 04 17:58:11 volumio volumio[863]: info: Received Get System Version May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 17:58:11 volumio volumio[863]: info: Received Get System Info May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 17:58:11 volumio volumio[863]: info: Discovery: Getting this device information May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:11 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 17:58:12 volumio volumio[863]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/download/fusiondsp/1.0.53/volumio/buster/armhf May 04 17:58:15 volumio volumio[863]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/download/fusiondsp/1.0.53/volumio/buster/armhf May 04 17:58:15 volumio volumio[863]: info: Folder /tmp/plugins removed May 04 17:58:15 volumio volumio[863]: info: Check plugin dependencies May 04 17:58:15 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 17:58:15 volumio volumio[863]: info: Checking if plugin already exists May 04 17:58:15 volumio volumio[863]: info: Rename folder May 04 17:58:15 volumio volumio[863]: info: Folder /tmp/downloaded_plugin.zip removed May 04 17:58:15 volumio volumio[863]: info: Move to category May 04 17:58:15 volumio volumio[863]: info: Checking if install.sh is present May 04 17:58:15 volumio volumio[863]: info: Executing install.sh May 04 17:58:15 volumio sudo[1808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/install.sh May 04 17:58:15 volumio sudo[1808]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:58:15 volumio volumio[863]: info: creating filters folder and copying demo filters May 04 17:58:15 volumio volumio[863]: info: copying demo flters May 04 17:58:16 volumio volumio[863]: info: Installing/fusiondsp dependencies May 04 17:58:16 volumio sudo[1829]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/apt update May 04 17:58:16 volumio sudo[1829]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:58:16 volumio volumio[863]: info: Get:1 https://deb.nodesource.com/node_14.x buster InRelease [4584 B] May 04 17:58:16 volumio volumio[863]: info: Get:2 http://raspbian.raspberrypi.org/raspbian buster InRelease [15.0 kB] May 04 17:58:16 volumio volumio[863]: info: Get:3 http://archive.raspberrypi.org/debian buster InRelease [32.6 kB] May 04 17:58:17 volumio go-librespot[1073]: time="2024-05-04T17:58:17+12:00" level=debug msg="fetched chunk 4/16, size: 524288" May 04 17:58:17 volumio volumio[863]: info: Get:4 https://deb.nodesource.com/node_14.x buster/main armhf Packages [786 B] May 04 17:58:17 volumio volumio[863]: info: Get:5 http://raspbian.raspberrypi.org/raspbian buster/main armhf Packages [13.0 MB] May 04 17:58:17 volumio volumio[863]: info: Get:6 http://archive.raspberrypi.org/debian buster/main armhf Packages [400 kB] May 04 17:58:25 volumio volumio[863]: info: Get:7 http://raspbian.raspberrypi.org/raspbian buster/contrib armhf Packages [58.8 kB] May 04 17:58:26 volumio volumio[863]: info: Get:8 http://raspbian.raspberrypi.org/raspbian buster/non-free armhf Packages [110 kB] May 04 17:58:28 volumio volumio[863]: info: Get:9 http://raspbian.raspberrypi.org/raspbian buster/rpi armhf Packages [1360 B] May 04 17:58:28 volumio go-librespot[1073]: time="2024-05-04T17:58:28+12:00" level=debug msg="fetched chunk 5/16, size: 524288" May 04 17:58:30 volumio volumio[863]: info: Fetched 13.6 MB in 14s (958 kB/s) May 04 17:58:32 volumio ntpd[653]: 162.159.200.1 local addr 192.168.1.95 -> May 04 17:58:35 volumio go-librespot[1073]: time="2024-05-04T17:58:35+12:00" level=debug msg="handling play player command from 8ef53755377f938a443262f5162b8ac8ab1d3747" May 04 17:58:35 volumio go-librespot[1073]: time="2024-05-04T17:58:35+12:00" level=trace msg="fetched new page 0 with 12 items (list: 12)" May 04 17:58:35 volumio go-librespot[1073]: time="2024-05-04T17:58:35+12:00" level=debug msg="loading track spotify:track:5A9xSuOZGQJNdRGEWVNGeI (paused: false, position: 348ms)" May 04 17:58:35 volumio go-librespot[1073]: time="2024-05-04T17:58:35+12:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 17:58:35 volumio go-librespot[1073]: time="2024-05-04T17:58:35+12:00" level=trace msg="emitting websocket event: will_play" May 04 17:58:35 volumio volumio[863]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5A9xSuOZGQJNdRGEWVNGeI","play_origin":"playlist"}} May 04 17:58:36 volumio go-librespot[1073]: time="2024-05-04T17:58:36+12:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5A9xSuOZGQJNdRGEWVNGeI" May 04 17:58:36 volumio go-librespot[1073]: time="2024-05-04T17:58:36+12:00" level=debug msg="requested aes key for file 4522732a85d32d1ea03d40368604cb86e6a21cac, gid: 5A9xSuOZGQJNdRGEWVNGeI" May 04 17:58:36 volumio volumio[863]: info: Reading package lists... May 04 17:58:36 volumio volumio[863]: info: Building dependency tree... May 04 17:58:36 volumio go-librespot[1073]: time="2024-05-04T17:58:36+12:00" level=debug msg="fetched first chunk of 16, total size is 8310904 bytes" May 04 17:58:36 volumio go-librespot[1073]: time="2024-05-04T17:58:36+12:00" level=trace msg="seek to 348ms (diff: 158ms, samples: 15346, bytes: 8167)" May 04 17:58:36 volumio volumio[863]: info: Reading state information... May 04 17:58:36 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 May 04 17:58:36 volumio go-librespot[1073]: time="2024-05-04T17:58:36+12:00" level=info msg="loaded track \"Falling Down (with Nick Hexum of 311)\" (uri: spotify:track:5A9xSuOZGQJNdRGEWVNGeI, paused: false, position: 348ms, duration: 198282ms)" May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=debug msg="fetched chunk 1/15, size: 524288" May 04 17:58:37 volumio volumio[863]: info: 27 packages can be upgraded. Run 'apt list --upgradable' to see them. May 04 17:58:37 volumio sudo[1829]: pam_unix(sudo:session): session closed for user root May 04 17:58:37 volumio sudo[2034]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/apt -y install python3-aiohttp python3-pip May 04 17:58:37 volumio sudo[2034]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=debug msg="fetched chunk 3/15, size: 524288" May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=debug msg="fetched chunk 2/15, size: 524288" May 04 17:58:37 volumio volumio[863]: info: Reading package lists... May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=trace msg="emitting websocket event: metadata" May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=debug msg="sending successful reply for delaer request" May 04 17:58:37 volumio volumio[863]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5A9xSuOZGQJNdRGEWVNGeI","name":"Falling Down (with Nick Hexum of 311)","artist_names":["Tropidelic","311"],"album_name":"All The Colors","album_cover_url":"https://i.scdn.co/image/ab67616d00001e020b8b4c8f51979b4e2086896d","position":348,"duration":198282,"release_date":"year:2022 month:8 day:5","track_number":1,"disc_number":1}} May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 17:58:37 volumio go-librespot[1073]: time="2024-05-04T17:58:37+12:00" level=trace msg="emitting websocket event: playing" May 04 17:58:37 volumio volumio[863]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5A9xSuOZGQJNdRGEWVNGeI","play_origin":"playlist"}} May 04 17:58:37 volumio volumio[863]: SPOTIFY: PUSH STATE SPOTIFY May 04 17:58:37 volumio volumio[863]: SPOTIFY: {"status":"play","service":"spop","title":"Falling Down (with Nick Hexum of 311)","artist":"Tropidelic, 311","album":"All The Colors","albumart":"https://i.scdn.co/image/ab67616d00001e020b8b4c8f51979b4e2086896d","uri":"spotify:track:5A9xSuOZGQJNdRGEWVNGeI","trackType":"spotify","seek":348,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 04 17:58:37 volumio volumio[863]: info: CoreCommandRouter::servicePushState May 04 17:58:37 volumio volumio[863]: info: CoreStateMachine::pushState May 04 17:58:37 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 17:58:37 volumio volumio[863]: info: CoreCommandRouter::volumioPushState May 04 17:58:37 volumio volumio[863]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 04 17:58:37 volumio volumio[863]: info: Building dependency tree... May 04 17:58:37 volumio volumio[863]: info: Reading state information... May 04 17:58:37 volumio volumio[863]: SPOTIFY: PUSH STATE SPOTIFY May 04 17:58:37 volumio volumio[863]: SPOTIFY: {"status":"play","service":"spop","title":"Falling Down (with Nick Hexum of 311)","artist":"Tropidelic, 311","album":"All The Colors","albumart":"https://i.scdn.co/image/ab67616d00001e020b8b4c8f51979b4e2086896d","uri":"spotify:track:5A9xSuOZGQJNdRGEWVNGeI","trackType":"spotify","seek":348,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 04 17:58:37 volumio volumio[863]: info: CoreCommandRouter::servicePushState May 04 17:58:37 volumio volumio[863]: info: CoreStateMachine::pushState May 04 17:58:37 volumio volumio[863]: info: CoreCommandRouter::volumioPushState May 04 17:58:37 volumio volumio[863]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 04 17:58:38 volumio volumio[863]: info: VolumeController::SetAlsaVolume0 May 04 17:58:38 volumio volumio[863]: info: CoreStateMachine::pushState May 04 17:58:38 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 17:58:38 volumio volumio[863]: info: CoreCommandRouter::volumioPushState May 04 17:58:38 volumio volumio[863]: info: The following additional packages will be installed: May 04 17:58:38 volumio volumio[863]: info: build-essential bzip2 cpp cpp-8 dh-python dpkg-dev fakeroot g++ g++-8 gcc May 04 17:58:38 volumio volumio[863]: info: gcc-8 libalgorithm-diff-perl libalgorithm-diff-xs-perl May 04 17:58:38 volumio volumio[863]: info: libalgorithm-merge-perl libasan5 libcc1-0 libexpat1 libexpat1-dev May 04 17:58:38 volumio volumio[863]: info: libfakeroot libgcc-8-dev libisl19 libmpc3 libmpfr6 libpython3-dev May 04 17:58:38 volumio volumio[863]: info: libpython3.7 libpython3.7-dev libpython3.7-minimal libpython3.7-stdlib May 04 17:58:38 volumio volumio[863]: info: libstdc++-8-dev libubsan1 make patch python-pip-whl python3-asn1crypto May 04 17:58:38 volumio volumio[863]: info: python3-async-timeout python3-attr python3-cffi-backend python3-crypto May 04 17:58:38 volumio volumio[863]: info: python3-cryptography python3-dbus python3-dev python3-entrypoints python3-gi May 04 17:58:38 volumio volumio[863]: info: python3-keyring python3-keyrings.alt python3-multidict python3-secretstorage May 04 17:58:38 volumio volumio[863]: info: python3-setuptools python3-wheel python3-xdg python3-yarl python3.7 May 04 17:58:38 volumio volumio[863]: info: python3.7-dev python3.7-minimal May 04 17:58:38 volumio volumio[863]: info: Suggested packages: May 04 17:58:38 volumio volumio[863]: info: bzip2-doc cpp-doc gcc-8-locales debian-keyring gcc-8-doc libstdc++6-8-dbg May 04 17:58:38 volumio volumio[863]: info: gcc-multilib autoconf automake libtool flex bison gdb gcc-doc libgcc1-dbg May 04 17:58:38 volumio volumio[863]: info: libgomp1-dbg libitm1-dbg libatomic1-dbg libasan5-dbg liblsan0-dbg May 04 17:58:38 volumio volumio[863]: info: libtsan0-dbg libubsan1-dbg libmpx2-dbg libquadmath0-dbg libstdc++-8-doc May 04 17:58:38 volumio volumio[863]: info: make-doc ed diffutils-doc python-attr-doc python-crypto-doc May 04 17:58:38 volumio volumio[863]: info: python-cryptography-doc python3-cryptography-vectors python-dbus-doc May 04 17:58:38 volumio volumio[863]: info: python3-dbus-dbg gnome-keyring libkf5wallet-bin gir1.2-gnomekeyring-1.0 May 04 17:58:38 volumio volumio[863]: info: python-secretstorage-doc python-setuptools-doc python3.7-venv python3.7-doc May 04 17:58:38 volumio volumio[863]: info: binfmt-support May 04 17:58:38 volumio go-librespot[1073]: time="2024-05-04T17:58:38+12:00" level=debug msg="update volume to 65535/65535" May 04 17:58:38 volumio volumio[863]: info: The following NEW packages will be installed: May 04 17:58:38 volumio volumio[863]: info: build-essential bzip2 cpp cpp-8 dh-python dpkg-dev fakeroot g++ g++-8 gcc May 04 17:58:38 volumio volumio[863]: info: gcc-8 libalgorithm-diff-perl libalgorithm-diff-xs-perl May 04 17:58:38 volumio volumio[863]: info: libalgorithm-merge-perl libasan5 libcc1-0 libexpat1-dev libfakeroot May 04 17:58:38 volumio volumio[863]: info: libgcc-8-dev libisl19 libmpc3 libmpfr6 libpython3-dev libpython3.7 May 04 17:58:38 volumio volumio[863]: info: libpython3.7-dev libstdc++-8-dev libubsan1 make patch python-pip-whl May 04 17:58:38 volumio volumio[863]: info: python3-aiohttp python3-asn1crypto python3-async-timeout python3-attr May 04 17:58:38 volumio volumio[863]: info: python3-cffi-backend python3-crypto python3-cryptography python3-dbus May 04 17:58:38 volumio volumio[863]: info: python3-dev python3-entrypoints python3-gi python3-keyring May 04 17:58:38 volumio volumio[863]: info: python3-keyrings.alt python3-multidict python3-pip python3-secretstorage May 04 17:58:38 volumio volumio[863]: info: python3-setuptools python3-wheel python3-xdg python3-yarl python3.7-dev May 04 17:58:38 volumio volumio[863]: info: The following packages will be upgraded: May 04 17:58:38 volumio volumio[863]: info: libexpat1 libpython3.7-minimal libpython3.7-stdlib python3.7 May 04 17:58:38 volumio volumio[863]: info: python3.7-minimal May 04 17:58:38 volumio go-librespot[1073]: time="2024-05-04T17:58:38+12:00" level=debug msg="put connect state because VOLUME_CHANGED" May 04 17:58:38 volumio go-librespot[1073]: time="2024-05-04T17:58:38+12:00" level=trace msg="emitting websocket event: volume" May 04 17:58:38 volumio volumio[863]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} May 04 17:58:38 volumio volumio[863]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 May 04 17:58:38 volumio volumio[863]: info: Setting Volumio Volume from Spotify: 100 May 04 17:58:38 volumio volumio[863]: info: VolumeController::SetAlsaVolume100 May 04 17:58:38 volumio volumio[863]: info: CoreStateMachine::pushState May 04 17:58:38 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 17:58:38 volumio volumio[863]: info: CoreCommandRouter::volumioPushState May 04 17:58:38 volumio volumio[863]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 May 04 17:58:38 volumio volumio[863]: SPOTIFY: SPOTIFY VOLUME 100 May 04 17:58:38 volumio volumio[863]: SPOTIFY: VOLUMIO VOLUME 90 May 04 17:58:38 volumio volumio[863]: SPOTIFY: DELTA VOLUME ENOUGH: true May 04 17:58:38 volumio volumio[863]: info: Setting Spotify Volume from Volumio: 90 May 04 17:58:39 volumio volumio[863]: info: 5 upgraded, 51 newly installed, 0 to remove and 24 not upgraded. May 04 17:58:39 volumio volumio[863]: info: Need to get 84.3 MB of archives. May 04 17:58:39 volumio volumio[863]: info: After this operation, 180 MB of additional disk space will be used. May 04 17:58:39 volumio volumio[863]: info: Get:1 http://archive.raspberrypi.org/debian buster/main armhf python-pip-whl all 18.1-5+rpt1 [1591 kB] May 04 17:58:39 volumio volumio[863]: info: Get:2 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3.7 armhf 3.7.3-2+deb10u7 [331 kB] May 04 17:58:40 volumio volumio[863]: info: Get:3 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libpython3.7-stdlib armhf 3.7.3-2+deb10u7 [1665 kB] May 04 17:58:40 volumio volumio[863]: SPOTIFY: SETTING SPOTIFY VOLUME 90 May 04 17:58:40 volumio volumio[863]: info: Sending Spotify command with payload to local API: /player/volume May 04 17:58:40 volumio volumio[863]: error: Failed to send command to Spotify local API: /player/volume: Error: Internal Server Error May 04 17:58:40 volumio volumio[863]: info: Get:4 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3.7-minimal armhf 3.7.3-2+deb10u7 [1201 kB] May 04 17:58:41 volumio volumio[863]: info: Get:5 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libpython3.7-minimal armhf 3.7.3-2+deb10u7 [584 kB] May 04 17:58:41 volumio volumio[863]: info: Get:6 http://archive.raspberrypi.org/debian buster/main armhf python3-pip all 18.1-5+rpt1 [171 kB] May 04 17:58:42 volumio volumio[863]: info: Get:7 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libexpat1 armhf 2.2.6-2+deb10u7 [79.7 kB] May 04 17:58:42 volumio volumio[863]: info: Get:8 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf bzip2 armhf 1.0.6-9.2~deb10u2 [46.3 kB] May 04 17:58:43 volumio volumio[863]: info: Get:9 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libisl19 armhf 0.20-2 [439 kB] May 04 17:58:43 volumio volumio[863]: info: Get:10 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libmpfr6 armhf 4.0.2-1 [723 kB] May 04 17:58:44 volumio volumio[863]: info: Get:11 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libmpc3 armhf 1.1.0-1 [32.1 kB] May 04 17:58:45 volumio volumio[863]: info: Get:12 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf cpp-8 armhf 8.3.0-6+rpi1 [6787 kB] May 04 17:58:46 volumio volumio[863]: info: Get:13 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf cpp armhf 4:8.3.0-1+rpi2 [19.6 kB] May 04 17:58:46 volumio volumio[863]: info: Get:14 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libcc1-0 armhf 8.3.0-6+rpi1 [37.9 kB] May 04 17:58:47 volumio volumio[863]: info: Get:15 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libasan5 armhf 8.3.0-6+rpi1 [317 kB] May 04 17:58:47 volumio go-librespot[1073]: time="2024-05-04T17:58:47+12:00" level=debug msg="fetched chunk 4/15, size: 524288" May 04 17:58:47 volumio volumio[863]: info: Get:16 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libubsan1 armhf 8.3.0-6+rpi1 [103 kB] May 04 17:58:48 volumio volumio[863]: info: Get:17 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libgcc-8-dev armhf 8.3.0-6+rpi1 [595 kB] May 04 17:58:49 volumio volumio[863]: info: Get:18 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf gcc-8 armhf 8.3.0-6+rpi1 [7223 kB] May 04 17:58:49 volumio volumio[863]: info: Get:19 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf gcc armhf 4:8.3.0-1+rpi2 [5200 B] May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 17:58:50 volumio volumio[863]: info: Discovery: Getting this device information May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 17:58:50 volumio volumio[863]: verbose: New Socket.io Connection to 192.168.1.95 from 192.168.1.42 UA: okhttp/4.9.2 Total Clients: 5 May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 04 17:58:50 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 04 17:58:50 volumio volumio[863]: info: Get:20 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libstdc++-8-dev armhf 8.3.0-6+rpi1 [1545 kB] May 04 17:58:51 volumio volumio[863]: info: Get:21 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf g++-8 armhf 8.3.0-6+rpi1 [7464 kB] May 04 17:58:51 volumio volumio[863]: info: Get:22 http://raspbian.raspberrypi.org/raspbian buster/main armhf g++ armhf 4:8.3.0-1+rpi2 [1632 B] May 04 17:58:52 volumio volumio[863]: info: Get:23 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf make armhf 4.2.1-1.2 [321 kB] May 04 17:58:53 volumio volumio[863]: info: Get:24 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf patch armhf 2.7.6-3+deb10u1 [115 kB] May 04 17:58:53 volumio volumio[863]: info: Get:25 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf dpkg-dev all 1.19.8 [1776 kB] May 04 17:58:54 volumio sudo[2048]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 17:58:54 volumio sudo[2048]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:58:54 volumio sudo[2048]: pam_unix(sudo:session): session closed for user root May 04 17:58:54 volumio sudo[2050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 17:58:54 volumio sudo[2050]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:58:54 volumio sudo[2050]: pam_unix(sudo:session): session closed for user root May 04 17:58:54 volumio volumio[863]: verbose: New Socket.io Connection to 192.168.1.95 from 192.168.1.42 UA: okhttp/4.9.2 Total Clients: 6 May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::volumioGetVisibleSources May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 04 17:58:54 volumio volumio[863]: info: Received Get System Info May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 17:58:54 volumio volumio[863]: info: Discovery: Getting this device information May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:54 volumio volumio[863]: info: Listing playlists May 04 17:58:54 volumio volumio[863]: info: Get:26 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf build-essential armhf 12.6 [7568 B] May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 04 17:58:54 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 04 17:58:55 volumio volumio[863]: info: Get:27 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf dh-python all 3.20190308 [99.3 kB] May 04 17:58:55 volumio volumio[863]: info: Get:28 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libfakeroot armhf 1.23-1 [43.3 kB] May 04 17:58:56 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 04 17:58:56 volumio volumio[863]: info: Received Get System Info May 04 17:58:56 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 17:58:56 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 17:58:56 volumio volumio[863]: info: Discovery: Getting this device information May 04 17:58:56 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:56 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 17:58:56 volumio volumio[863]: info: Get:29 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf fakeroot armhf 1.23-1 [85.2 kB] May 04 17:58:56 volumio volumio[863]: info: Get:30 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libalgorithm-diff-perl all 1.19.03-2 [47.9 kB] May 04 17:58:57 volumio volumio[863]: info: Get:31 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libalgorithm-diff-xs-perl armhf 0.04-5+b1 [11.4 kB] May 04 17:58:57 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 04 17:58:57 volumio volumio[863]: info: Received Get System Info May 04 17:58:57 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 17:58:57 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 17:58:57 volumio volumio[863]: info: Discovery: Getting this device information May 04 17:58:57 volumio volumio[863]: info: CoreCommandRouter::volumioGetState May 04 17:58:57 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 17:58:58 volumio volumio[863]: info: Get:32 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libalgorithm-merge-perl all 0.08-3 [12.7 kB] May 04 17:58:58 volumio volumio[863]: info: Get:33 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libexpat1-dev armhf 2.2.6-2+deb10u7 [130 kB] May 04 17:58:59 volumio volumio[863]: info: Get:34 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf libpython3.7 armhf 3.7.3-2+deb10u7 [1252 kB] May 04 17:59:00 volumio volumio[863]: info: Get:35 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libpython3.7-dev armhf 3.7.3-2+deb10u7 [47.2 MB] May 04 17:59:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 04 17:59:00 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 04 17:59:00 volumio go-librespot[1073]: time="2024-05-04T17:59:00+12:00" level=debug msg="fetched chunk 5/15, size: 524288" May 04 17:59:02 volumio volumio[863]: info: Get:38 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-yarl armhf 1.3.0-1 [44.0 kB] May 04 17:59:04 volumio volumio[863]: info: Get:36 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf libpython3-dev armhf 3.7.3-1 [20.1 kB] May 04 17:59:06 volumio volumio[863]: info: Get:37 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-multidict armhf 4.5.2-1 [52.9 kB] May 04 17:59:06 volumio volumio[863]: info: Get:39 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-async-timeout all 3.0.1-1 [6292 B] May 04 17:59:06 volumio volumio[863]: info: Get:40 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-attr all 18.2.0-1 [37.3 kB] May 04 17:59:06 volumio volumio[863]: info: Get:41 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-aiohttp armhf 3.5.1-1+deb10u1 [241 kB] May 04 17:59:06 volumio volumio[863]: info: Get:42 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-asn1crypto all 0.24.0-1 [78.2 kB] May 04 17:59:06 volumio volumio[863]: info: Get:43 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-cffi-backend armhf 1.12.2-1 [70.1 kB] May 04 17:59:06 volumio volumio[863]: info: Get:44 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-crypto armhf 2.6.1-9+b1 [251 kB] May 04 17:59:07 volumio volumio[863]: info: Get:45 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-cryptography armhf 2.6.1-3+deb10u4 [184 kB] May 04 17:59:07 volumio volumio[863]: info: Get:46 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-dbus armhf 1.2.8-3 [95.9 kB] May 04 17:59:08 volumio volumio[863]: info: Enabling plugin fusiondsp May 04 17:59:08 volumio volumio[863]: info: Loading plugin "fusiondsp"... May 04 17:59:08 volumio volumio[863]: info: Preparing to generate the ALSA configuration file May 04 17:59:08 volumio volumio[863]: info: Asound.conf file unchanged, so no further update is needed May 04 17:59:08 volumio volumio[863]: info: Output device has changed, restarting MPD May 04 17:59:08 volumio sudo[2094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 17:59:08 volumio sudo[2094]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:08 volumio sudo[2094]: pam_unix(sudo:session): session closed for user root May 04 17:59:08 volumio volumio[863]: info: Output device has changed, restarting Shairport Sync May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 17:59:08 volumio sudo[2097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 17:59:08 volumio sudo[2097]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:08 volumio systemd[1]: Stopping Music Player Daemon... May 04 17:59:08 volumio volumio[863]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 17:59:08 volumio volumio[863]: info: PLUGIN START: fusiondsp May 04 17:59:08 volumio volumio[863]: info: Loading i18n strings for locale en May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: FusionDsp - mixtype--------------------- Hardware May 04 17:59:08 volumio volumio[863]: info: Preparing to generate the ALSA configuration file May 04 17:59:08 volumio volumio[863]: info: Done. May 04 17:59:08 volumio volumio[863]: info: MPD Permissions set May 04 17:59:08 volumio volumio[863]: info: Get:47 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf python3.7-dev armhf 3.7.3-2+deb10u7 [527 kB] May 04 17:59:08 volumio volumio[863]: info: Asound.conf file unchanged, so no further update is needed May 04 17:59:08 volumio volumio[863]: info: Output device has changed, restarting MPD May 04 17:59:08 volumio systemd[1]: mpd.service: Succeeded. May 04 17:59:08 volumio systemd[1]: Stopped Music Player Daemon. May 04 17:59:08 volumio sudo[2103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 17:59:08 volumio sudo[2103]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:08 volumio volumio[863]: info: Output device has changed, restarting Shairport Sync May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio sudo[2103]: pam_unix(sudo:session): session closed for user root May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 17:59:08 volumio sudo[2106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 17:59:08 volumio sudo[2106]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:08 volumio systemd[1]: Starting Music Player Daemon... May 04 17:59:08 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 04 17:59:08 volumio systemd[1]: mpd.service: Succeeded. May 04 17:59:08 volumio systemd[1]: Stopped Music Player Daemon. May 04 17:59:08 volumio volumio[863]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio systemd[1]: Starting Music Player Daemon... May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 17:59:08 volumio volumio[863]: info: MPD Permissions set May 04 17:59:08 volumio volumio[863]: info: Starting Shairport Sync May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio sudo[2119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 17:59:08 volumio sudo[2119]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 17:59:08 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:08 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 17:59:08 volumio systemd[1]: shairport-sync.service: Succeeded. May 04 17:59:08 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 17:59:08 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 17:59:08 volumio sudo[2119]: pam_unix(sudo:session): session closed for user root May 04 17:59:09 volumio volumio[863]: info: Shairport-Sync Started May 04 17:59:09 volumio volumio[863]: info: Starting Shairport Sync May 04 17:59:09 volumio volumio[863]: info: Get:48 http://raspbian.raspberrypi.org/raspbian buster/main armhf python3-dev armhf 3.7.3-1 [1264 B] May 04 17:59:09 volumio sudo[2129]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 17:59:09 volumio sudo[2129]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 17:59:09 volumio systemd[1]: shairport-sync.service: Succeeded. May 04 17:59:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 17:59:09 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 17:59:09 volumio sudo[2129]: pam_unix(sudo:session): session closed for user root May 04 17:59:09 volumio volumio[863]: info: Shairport-Sync Started May 04 17:59:09 volumio mpd[2113]: May 04 17:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 04 17:59:09 volumio systemd[1]: Started Music Player Daemon. May 04 17:59:09 volumio sudo[2106]: pam_unix(sudo:session): session closed for user root May 04 17:59:09 volumio sudo[2097]: pam_unix(sudo:session): session closed for user root May 04 17:59:09 volumio volumio[863]: error: MPD error: The expression evaluated to a falsy value: May 04 17:59:09 volumio volumio[863]: assert.ok(self.idling) May 04 17:59:09 volumio volumio[863]: error: The expression evaluated to a falsy value: May 04 17:59:09 volumio volumio[863]: assert.ok(self.idling) May 04 17:59:09 volumio volumio[863]: error: updateQueue error: null May 04 17:59:09 volumio volumio[863]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 17:59:09 volumio volumio[863]: info: Get:49 http://wlglam.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-entrypoints all 0.3-1 [5508 B] May 04 17:59:10 volumio volumio[863]: info: Get:50 http://hlzmel.fsmg.org.nz/raspbian/raspbian buster/main armhf python3-gi armhf 3.30.4-1 [161 kB] May 04 17:59:10 volumio volumio[863]: info: camilladsp spawned new process with pid undefined, instance 1, run: true May 04 17:59:10 volumio volumio[863]: info: camilladsp service started and running in background, instance 1 May 04 17:59:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 17:59:10 volumio volumio[863]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found May 04 17:59:10 volumio volumio[863]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 04 17:59:10 volumio volumio[863]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found May 04 17:59:10 volumio volumio[863]: info: FusionDsp loaded May 04 17:59:10 volumio volumio[863]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 17:59:10 volumio sudo[2147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 04 17:59:10 volumio sudo[2147]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 17:59:10 volumio volumio[863]: info: FusionDsp - Reporting Fusion DSP Enabled May 04 17:59:10 volumio volumio[863]: info: Adding Signal Path Element [object Object] May 04 17:59:10 volumio volumio[863]: info: Adding fusiondspeq DSP Signal Path Element May 04 17:59:10 volumio volumio[863]: info: FusionDsp - ---- installed callbackRead May 04 17:59:10 volumio volumio[863]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 17:59:10 volumio sudo[2147]: pam_unix(sudo:session): session closed for user root May 04 17:59:10 volumio volumio[863]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT May 04 17:59:10 volumio volumio[863]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) May 04 17:59:10 volumio volumio[863]: at onErrorNT (internal/child_process.js:465:16) May 04 17:59:10 volumio volumio[863]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { May 04 17:59:10 volumio volumio[863]: errno: -2, May 04 17:59:10 volumio volumio[863]: code: 'ENOENT', May 04 17:59:10 volumio volumio[863]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', May 04 17:59:10 volumio volumio[863]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', May 04 17:59:10 volumio volumio[863]: spawnargs: [ May 04 17:59:10 volumio volumio[863]: '-p', May 04 17:59:10 volumio volumio[863]: 9876, May 04 17:59:10 volumio volumio[863]: '-o', May 04 17:59:10 volumio volumio[863]: '/tmp/camilladsp.log', May 04 17:59:10 volumio volumio[863]: '-l', May 04 17:59:10 volumio volumio[863]: 'warn', May 04 17:59:10 volumio volumio[863]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' May 04 17:59:10 volumio volumio[863]: ] May 04 17:59:10 volumio volumio[863]: } May 04 17:59:10 volumio volumio[863]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 17:59:11 volumio sudo[2158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-04 17:58 May 04 17:59:11 volumio sudo[2158]: 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"