Dec 25 23:54:05 netransportnew volumiossh-tunnel[8938]: Connection to eu10.myvolumio.org closed by remote host. Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:05 netransportnew autossh[8935]: starting ssh (count 2) Dec 25 23:54:05 netransportnew autossh[8935]: ssh child pid is 9445 Dec 25 23:54:05 netransportnew volumiossh-tunnel[9445]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:05 netransportnew autossh[8935]: starting ssh (count 3) Dec 25 23:54:05 netransportnew autossh[8935]: ssh child pid is 9446 Dec 25 23:54:05 netransportnew volumiossh-tunnel[9446]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:05 netransportnew autossh[8935]: starting ssh (count 4) Dec 25 23:54:05 netransportnew autossh[8935]: ssh child pid is 9447 Dec 25 23:54:05 netransportnew volumiossh-tunnel[9447]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:05 netransportnew autossh[8935]: starting ssh (count 5) Dec 25 23:54:05 netransportnew autossh[8935]: ssh child pid is 9448 Dec 25 23:54:05 netransportnew volumio[6393]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object] Dec 25 23:54:05 netransportnew volumio[6393]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter Dec 25 23:54:05 netransportnew volumiossh-tunnel[9448]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:05 netransportnew autossh[8935]: starting ssh (count 6) Dec 25 23:54:05 netransportnew autossh[8935]: ssh child pid is 9452 Dec 25 23:54:05 netransportnew volumiossh-tunnel[9452]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:05 netransportnew autossh[8935]: starting ssh (count 7) Dec 25 23:54:05 netransportnew autossh[8935]: ssh child pid is 9453 Dec 25 23:54:05 netransportnew volumiossh-tunnel[9453]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:05 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:07 netransportnew volumio[6393]: --2025-12-25 23:54:05-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/1280x400-Gelo5-BASIC_221.zip Dec 25 23:54:07 netransportnew volumio[6393]: Resolving github.com (github.com)... 140.82.121.4 Dec 25 23:54:07 netransportnew volumio[6393]: Connecting to github.com (github.com)|140.82.121.4|:443... connected. Dec 25 23:54:07 netransportnew volumio[6393]: HTTP request sent, awaiting response... 302 Found Dec 25 23:54:07 netransportnew volumio[6393]: Location: https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1280x400-Gelo5-BASIC_221.zip [following] Dec 25 23:54:07 netransportnew volumio[6393]: --2025-12-25 23:54:06-- https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/Zipped-folders/1280x400-Gelo5-BASIC_221.zip Dec 25 23:54:07 netransportnew volumio[6393]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.110.133, 185.199.109.133, 185.199.108.133, ... Dec 25 23:54:07 netransportnew volumio[6393]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.110.133|:443... connected. Dec 25 23:54:07 netransportnew volumio[6393]: HTTP request sent, awaiting response... 200 OK Dec 25 23:54:07 netransportnew volumio[6393]: Length: 12349515 (12M) [application/zip] Dec 25 23:54:07 netransportnew volumio[6393]: Saving to: ‘/tmp/1280x400-Gelo5-BASIC_221.zip’ Dec 25 23:54:07 netransportnew volumio[6393]: 0K .......... .......... .......... .......... .......... 0% 2.18M 5s Dec 25 23:54:07 netransportnew volumio[6393]: 50K .......... .......... .......... .......... .......... 0% 4.03M 4s Dec 25 23:54:07 netransportnew volumio[6393]: 100K .......... .......... .......... .......... .......... 1% 5.78M 3s Dec 25 23:54:07 netransportnew volumio[6393]: 150K .......... .......... .......... .......... .......... 1% 12.8M 3s Dec 25 23:54:07 netransportnew volumio[6393]: 200K .......... .......... .......... .......... .......... 2% 6.44M 3s Dec 25 23:54:07 netransportnew volumio[6393]: 250K .......... .......... .......... .......... .......... 2% 7.04M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 300K .......... .......... .......... .......... .......... 2% 19.3M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 350K .......... .......... .......... .......... .......... 3% 25.3M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 400K .......... .......... .......... .......... .......... 3% 15.2M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 450K .......... .......... .......... .......... .......... 4% 25.2M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 500K .......... .......... .......... .......... .......... 4% 5.69M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 550K .......... .......... .......... .......... .......... 4% 9.80M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 600K .......... .......... .......... .......... .......... 5% 20.5M 2s Dec 25 23:54:07 netransportnew volumio[6393]: 650K .......... .......... .......... .......... .......... 5% 27.1M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 700K .......... .......... .......... .......... .......... 6% 15.7M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 750K .......... .......... .......... .......... .......... 6% 25.1M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 800K .......... .......... .......... .......... .......... 7% 27.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 850K .......... .......... .......... .......... .......... 7% 33.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 900K .......... .......... .......... .......... .......... 7% 34.7M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 950K .......... .......... .......... .......... .......... 8% 27.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1000K .......... .......... .......... .......... .......... 8% 19.6M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1050K .......... .......... .......... .......... .......... 9% 22.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1100K .......... .......... .......... .......... .......... 9% 23.5M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1150K .......... .......... .......... .......... .......... 9% 18.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1200K .......... .......... .......... .......... .......... 10% 14.9M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1250K .......... .......... .......... .......... .......... 10% 16.5M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1300K .......... .......... .......... .......... .......... 11% 24.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1350K .......... .......... .......... .......... .......... 11% 21.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1400K .......... .......... .......... .......... .......... 12% 33.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1450K .......... .......... .......... .......... .......... 12% 22.6M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1500K .......... .......... .......... .......... .......... 12% 22.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1550K .......... .......... .......... .......... .......... 13% 16.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1600K .......... .......... .......... .......... .......... 13% 23.9M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1650K .......... .......... .......... .......... .......... 14% 23.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1700K .......... .......... .......... .......... .......... 14% 23.7M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1750K .......... .......... .......... .......... .......... 14% 31.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1800K .......... .......... .......... .......... .......... 15% 23.7M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1850K .......... .......... .......... .......... .......... 15% 30.1M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1900K .......... .......... .......... .......... .......... 16% 27.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 1950K .......... .......... .......... .......... .......... 16% 14.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2000K .......... .......... .......... .......... .......... 16% 11.6M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2050K .......... .......... .......... .......... .......... 17% 18.9M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2100K .......... .......... .......... .......... .......... 17% 21.8M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2150K .......... .......... .......... .......... .......... 18% 33.4M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2200K .......... .......... .......... .......... .......... 18% 26.5M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2250K .......... .......... .......... .......... .......... 19% 21.4M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2300K .......... .......... .......... .......... .......... 19% 25.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2350K .......... .......... .......... .......... .......... 19% 19.8M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2400K .......... .......... .......... .......... .......... 20% 28.4M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2450K .......... .......... .......... .......... .......... 20% 21.8M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2500K .......... .......... .......... .......... .......... 21% 21.1M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2550K .......... .......... .......... .......... .......... 21% 30.1M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2600K .......... .......... .......... .......... .......... 21% 22.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2650K .......... .......... .......... .......... .......... 22% 29.8M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2700K .......... .......... .......... .......... .......... 22% 12.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2750K .......... .......... .......... .......... .......... 23% 14.4M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2800K .......... .......... .......... .......... .......... 23% 28.6M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2850K .......... .......... .......... .......... .......... 24% 22.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2900K .......... .......... .......... .......... .......... 24% 32.2M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 2950K .......... .......... .......... .......... .......... 24% 20.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3000K .......... .......... .......... .......... .......... 25% 23.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3050K .......... .......... .......... .......... .......... 25% 25.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3100K .......... .......... .......... .......... .......... 26% 23.7M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3150K .......... .......... .......... .......... .......... 26% 18.6M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3200K .......... .......... .......... .......... .......... 26% 34.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3250K .......... .......... .......... .......... .......... 27% 34.6M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3300K .......... .......... .......... .......... .......... 27% 33.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3350K .......... .......... .......... .......... .......... 28% 20.5M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3400K .......... .......... .......... .......... .......... 28% 28.5M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3450K .......... .......... .......... .......... .......... 29% 13.9M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3500K .......... .......... .......... .......... .......... 29% 14.3M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3550K .......... .......... .......... .......... .......... 29% 19.8M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3600K .......... .......... .......... .......... .......... 30% 19.8M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3650K .......... .......... .......... .......... .......... 30% 24.0M 1s Dec 25 23:54:07 netransportnew volumio[6393]: 3700K .......... .......... .......... .......... .......... 31% 20.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 3750K .......... .......... .......... .......... .......... 31% 32.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 3800K .......... .......... .......... .......... .......... 31% 31.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 3850K .......... .......... .......... .......... .......... 32% 22.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 3900K .......... .......... .......... .......... .......... 32% 30.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 3950K .......... .......... .......... .......... .......... 33% 23.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4000K .......... .......... .......... .......... .......... 33% 32.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4050K .......... .......... .......... .......... .......... 33% 21.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4100K .......... .......... .......... .......... .......... 34% 26.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4150K .......... .......... .......... .......... .......... 34% 24.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4200K .......... .......... .......... .......... .......... 35% 19.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4250K .......... .......... .......... .......... .......... 35% 12.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4300K .......... .......... .......... .......... .......... 36% 20.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4350K .......... .......... .......... .......... .......... 36% 17.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4400K .......... .......... .......... .......... .......... 36% 25.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4450K .......... .......... .......... .......... .......... 37% 24.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4500K .......... .......... .......... .......... .......... 37% 32.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4550K .......... .......... .......... .......... .......... 38% 20.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4600K .......... .......... .......... .......... .......... 38% 28.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4650K .......... .......... .......... .......... .......... 38% 31.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4700K .......... .......... .......... .......... .......... 39% 33.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4750K .......... .......... .......... .......... .......... 39% 19.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4800K .......... .......... .......... .......... .......... 40% 25.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4850K .......... .......... .......... .......... .......... 40% 21.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4900K .......... .......... .......... .......... .......... 41% 32.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 4950K .......... .......... .......... .......... .......... 41% 22.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5000K .......... .......... .......... .......... .......... 41% 19.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5050K .......... .......... .......... .......... .......... 42% 14.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5100K .......... .......... .......... .......... .......... 42% 23.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5150K .......... .......... .......... .......... .......... 43% 23.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5200K .......... .......... .......... .......... .......... 43% 26.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5250K .......... .......... .......... .......... .......... 43% 20.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5300K .......... .......... .......... .......... .......... 44% 20.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5350K .......... .......... .......... .......... .......... 44% 23.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5400K .......... .......... .......... .......... .......... 45% 33.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5450K .......... .......... .......... .......... .......... 45% 33.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5500K .......... .......... .......... .......... .......... 46% 25.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5550K .......... .......... .......... .......... .......... 46% 16.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5600K .......... .......... .......... .......... .......... 46% 34.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5650K .......... .......... .......... .......... .......... 47% 30.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5700K .......... .......... .......... .......... .......... 47% 19.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5750K .......... .......... .......... .......... .......... 48% 15.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5800K .......... .......... .......... .......... .......... 48% 14.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5850K .......... .......... .......... .......... .......... 48% 31.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5900K .......... .......... .......... .......... .......... 49% 22.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 5950K .......... .......... .......... .......... .......... 49% 17.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6000K .......... .......... .......... .......... .......... 50% 33.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6050K .......... .......... .......... .......... .......... 50% 30.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6100K .......... .......... .......... .......... .......... 50% 22.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6150K .......... .......... .......... .......... .......... 51% 19.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6200K .......... .......... .......... .......... .......... 51% 30.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6250K .......... .......... .......... .......... .......... 52% 29.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6300K .......... .......... .......... .......... .......... 52% 24.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6350K .......... .......... .......... .......... .......... 53% 21.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6400K .......... .......... .......... .......... .......... 53% 24.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6450K .......... .......... .......... .......... .......... 53% 27.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6500K .......... .......... .......... .......... .......... 54% 30.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6550K .......... .......... .......... .......... .......... 54% 20.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6600K .......... .......... .......... .......... .......... 55% 11.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6650K .......... .......... .......... .......... .......... 55% 27.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6700K .......... .......... .......... .......... .......... 55% 29.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6750K .......... .......... .......... .......... .......... 56% 16.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6800K .......... .......... .......... .......... .......... 56% 27.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6850K .......... .......... .......... .......... .......... 57% 20.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6900K .......... .......... .......... .......... .......... 57% 27.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 6950K .......... .......... .......... .......... .......... 58% 32.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7000K .......... .......... .......... .......... .......... 58% 32.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7050K .......... .......... .......... .......... .......... 58% 24.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7100K .......... .......... .......... .......... .......... 59% 24.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7150K .......... .......... .......... .......... .......... 59% 27.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7200K .......... .......... .......... .......... .......... 60% 32.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7250K .......... .......... .......... .......... .......... 60% 25.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7300K .......... .......... .......... .......... .......... 60% 14.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7350K .......... .......... .......... .......... .......... 61% 14.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7400K .......... .......... .......... .......... .......... 61% 26.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7450K .......... .......... .......... .......... .......... 62% 28.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7500K .......... .......... .......... .......... .......... 62% 21.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7550K .......... .......... .......... .......... .......... 63% 16.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7600K .......... .......... .......... .......... .......... 63% 34.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7650K .......... .......... .......... .......... .......... 63% 26.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7700K .......... .......... .......... .......... .......... 64% 22.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7750K .......... .......... .......... .......... .......... 64% 18.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7800K .......... .......... .......... .......... .......... 65% 26.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7850K .......... .......... .......... .......... .......... 65% 34.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7900K .......... .......... .......... .......... .......... 65% 30.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 7950K .......... .......... .......... .......... .......... 66% 17.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8000K .......... .......... .......... .......... .......... 66% 22.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8050K .......... .......... .......... .......... .......... 67% 27.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8100K .......... .......... .......... .......... .......... 67% 12.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8150K .......... .......... .......... .......... .......... 67% 19.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8200K .......... .......... .......... .......... .......... 68% 24.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8250K .......... .......... .......... .......... .......... 68% 23.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8300K .......... .......... .......... .......... .......... 69% 30.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8350K .......... .......... .......... .......... .......... 69% 15.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8400K .......... .......... .......... .......... .......... 70% 25.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8450K .......... .......... .......... .......... .......... 70% 28.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8500K .......... .......... .......... .......... .......... 70% 33.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8550K .......... .......... .......... .......... .......... 71% 27.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8600K .......... .......... .......... .......... .......... 71% 25.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8650K .......... .......... .......... .......... .......... 72% 24.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8700K .......... .......... .......... .......... .......... 72% 27.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8750K .......... .......... .......... .......... .......... 72% 18.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8800K .......... .......... .......... .......... .......... 73% 27.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8850K .......... .......... .......... .......... .......... 73% 16.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8900K .......... .......... .......... .......... .......... 74% 15.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 8950K .......... .......... .......... .......... .......... 74% 25.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9000K .......... .......... .......... .......... .......... 75% 18.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9050K .......... .......... .......... .......... .......... 75% 22.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9100K .......... .......... .......... .......... .......... 75% 25.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9150K .......... .......... .......... .......... .......... 76% 23.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9200K .......... .......... .......... .......... .......... 76% 22.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9250K .......... .......... .......... .......... .......... 77% 21.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9300K .......... .......... .......... .......... .......... 77% 32.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9350K .......... .......... .......... .......... .......... 77% 27.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9400K .......... .......... .......... .......... .......... 78% 34.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9450K .......... .......... .......... .......... .......... 78% 33.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9500K .......... .......... .......... .......... .......... 79% 25.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9550K .......... .......... .......... .......... .......... 79% 17.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9600K .......... .......... .......... .......... .......... 80% 24.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9650K .......... .......... .......... .......... .......... 80% 18.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9700K .......... .......... .......... .......... .......... 80% 11.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9750K .......... .......... .......... .......... .......... 81% 24.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9800K .......... .......... .......... .......... .......... 81% 26.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9850K .......... .......... .......... .......... .......... 82% 20.8M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9900K .......... .......... .......... .......... .......... 82% 27.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 9950K .......... .......... .......... .......... .......... 82% 16.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10000K .......... .......... .......... .......... .......... 83% 26.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10050K .......... .......... .......... .......... .......... 83% 34.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10100K .......... .......... .......... .......... .......... 84% 25.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10150K .......... .......... .......... .......... .......... 84% 28.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10200K .......... .......... .......... .......... .......... 84% 23.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10250K .......... .......... .......... .......... .......... 85% 33.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10300K .......... .......... .......... .......... .......... 85% 27.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10350K .......... .......... .......... .......... .......... 86% 17.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10400K .......... .......... .......... .......... .......... 86% 14.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10450K .......... .......... .......... .......... .......... 87% 18.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10500K .......... .......... .......... .......... .......... 87% 33.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10550K .......... .......... .......... .......... .......... 87% 20.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10600K .......... .......... .......... .......... .......... 88% 24.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10650K .......... .......... .......... .......... .......... 88% 20.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10700K .......... .......... .......... .......... .......... 89% 29.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10750K .......... .......... .......... .......... .......... 89% 15.3M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10800K .......... .......... .......... .......... .......... 89% 27.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10850K .......... .......... .......... .......... .......... 90% 31.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10900K .......... .......... .......... .......... .......... 90% 27.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 10950K .......... .......... .......... .......... .......... 91% 31.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11000K .......... .......... .......... .......... .......... 91% 29.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11050K .......... .......... .......... .......... .......... 92% 18.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11100K .......... .......... .......... .......... .......... 92% 20.6M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11150K .......... .......... .......... .......... .......... 92% 16.4M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11200K .......... .......... .......... .......... .......... 93% 14.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11250K .......... .......... .......... .......... .......... 93% 19.5M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11300K .......... .......... .......... .......... .......... 94% 27.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11350K .......... .......... .......... .......... .......... 94% 28.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11400K .......... .......... .......... .......... .......... 94% 33.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11450K .......... .......... .......... .......... .......... 95% 34.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11500K .......... .......... .......... .......... .......... 95% 34.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11550K .......... .......... .......... .......... .......... 96% 26.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11600K .......... .......... .......... .......... .......... 96% 35.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11650K .......... .......... .......... .......... .......... 97% 34.1M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11700K .......... .......... .......... .......... .......... 97% 34.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11750K .......... .......... .......... .......... .......... 97% 33.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11800K .......... .......... .......... .......... .......... 98% 34.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11850K .......... .......... .......... .......... .......... 98% 34.0M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11900K .......... .......... .......... .......... .......... 99% 34.7M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 11950K .......... .......... .......... .......... .......... 99% 27.2M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 12000K .......... .......... .......... .......... .......... 99% 35.9M 0s Dec 25 23:54:07 netransportnew volumio[6393]: 12050K .......... 100% 133M=0.6s Dec 25 23:54:07 netransportnew volumio[6393]: 2025-12-25 23:54:07 (20.6 MB/s) - ‘/tmp/1280x400-Gelo5-BASIC_221.zip’ saved [12349515/12349515] Dec 25 23:54:07 netransportnew autossh[8935]: starting ssh (count 8) Dec 25 23:54:07 netransportnew autossh[8935]: ssh child pid is 9458 Dec 25 23:54:07 netransportnew volumiossh-tunnel[9458]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:07 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:15 netransportnew autossh[8935]: starting ssh (count 9) Dec 25 23:54:15 netransportnew autossh[8935]: ssh child pid is 9478 Dec 25 23:54:15 netransportnew volumiossh-tunnel[9478]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:15 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:21 netransportnew sudo[9479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /data/INTERNAL/PeppyMeterBasic/Templates/ Dec 25 23:54:21 netransportnew sudo[9479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:22 netransportnew sudo[9479]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:22 netransportnew volumio[6393]: info: PeppyMeterBasic ---message miniunzip -o /tmp/1280x400-Gelo5-BASIC_221.zip -d /data/INTERNAL/PeppyMeterBasic/Templates/ Dec 25 23:54:22 netransportnew volumio[6393]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 25 23:54:22 netransportnew volumio[6393]: info: CoreCommandRouter::Close All Modals sent Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=debug msg="handling play player command from c440b86926bbf484350ffd2778a1090c27242a99" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=debug msg="resolved context of track" uri="spotify:album:4OlAuurOASiGhOm0eueN9q" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=trace msg="fetched new page 0 with 14 items (list: 14)" uri="spotify:album:4OlAuurOASiGhOm0eueN9q" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=trace msg="emitting websocket event: will_play" Dec 25 23:54:24 netransportnew volumio[6393]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:4OlAuurOASiGhOm0eueN9q","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","play_origin":""}} Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=debug msg="selected format OGG_VORBIS_320 (170bd690c313e809ad766a3972728057a36ec4d5)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=debug msg="requested aes key for file 170bd690c313e809ad766a3972728057a36ec4d5, gid: 2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:24 netransportnew go-librespot[6754]: time="2025-12-25T23:54:24+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="fetched first chunk of 25, total size is 12701544 bytes" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=info msg="loaded track \"Playing With Madness (Instrumental) - Live in Hamburg\" (paused: false, position: 0ms, duration: 321960ms, prefetched: false)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=trace msg="scheduling prefetch in 292s" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=trace msg="emitting websocket event: metadata" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="sending successful reply for dealer request" Dec 25 23:54:25 netransportnew volumio[6393]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","name":"Playing With Madness (Instrumental) - Live in Hamburg","artist_names":["Schiller"],"album_name":"Atemlos Live","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027a886e1c6e8e149c71769b97","position":0,"duration":321960,"release_date":"year:2010 month:11 day:26","track_number":1,"disc_number":1}} Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=trace msg="emitting websocket event: playing" Dec 25 23:54:25 netransportnew volumio[6393]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:4OlAuurOASiGhOm0eueN9q","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","resume":false,"play_origin":""}} Dec 25 23:54:25 netransportnew volumio[6393]: SPOTIFY: PUSH STATE SPOTIFY Dec 25 23:54:25 netransportnew volumio[6393]: SPOTIFY: {"status":"play","service":"spop","title":"Playing With Madness (Instrumental) - Live in Hamburg","artist":"Schiller","album":"Atemlos Live","albumart":"https://i.scdn.co/image/ab67616d00001e027a886e1c6e8e149c71769b97","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","trackType":"spotify","seek":0,"duration":321,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::servicePushState Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreStateMachine::pushState Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::volumioPushState Dec 25 23:54:25 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output update for this device Dec 25 23:54:25 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::volumioGetState Dec 25 23:54:25 netransportnew go-librespot[6754]: time="2025-12-25T23:54:25+01:00" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:25 netransportnew volumio[6393]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 25 23:54:25 netransportnew sudo[9504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 25 23:54:25 netransportnew sudo[9504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:25 netransportnew volumio[6393]: info: touch_display: Setting screensaver timeout to 0 seconds. Dec 25 23:54:25 netransportnew sudo[9504]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:25 netransportnew volumio[6393]: info: peppymeterbasic Daemon Started Dec 25 23:54:25 netransportnew volumio[6393]: SPOTIFY: PUSH STATE SPOTIFY Dec 25 23:54:25 netransportnew volumio[6393]: SPOTIFY: {"status":"play","service":"spop","title":"Playing With Madness (Instrumental) - Live in Hamburg","artist":"Schiller","album":"Atemlos Live","albumart":"https://i.scdn.co/image/ab67616d00001e027a886e1c6e8e149c71769b97","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","trackType":"spotify","seek":0,"duration":321,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::servicePushState Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreStateMachine::pushState Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::volumioPushState Dec 25 23:54:25 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output update for this device Dec 25 23:54:25 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output Dec 25 23:54:25 netransportnew volumio[6393]: info: CoreCommandRouter::volumioGetState Dec 25 23:54:25 netransportnew volumio[6393]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 25 23:54:25 netransportnew sudo[9509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 25 23:54:25 netransportnew sudo[9509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:25 netransportnew sudo[9509]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:25 netransportnew volumio[6393]: info: peppymeterbasic Daemon Started Dec 25 23:54:28 netransportnew go-librespot[6754]: time="2025-12-25T23:54:28+01:00" level=trace msg="sent dealer ping" Dec 25 23:54:28 netransportnew go-librespot[6754]: time="2025-12-25T23:54:28+01:00" level=trace msg="received dealer pong" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="handling seek_to player command from c440b86926bbf484350ffd2778a1090c27242a99" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="seek track to 87970ms" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="fetched chunk 6/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=trace msg="seek to 87970ms (diff: 179ms, samples: 3879477, bytes: 3520807)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="fetched chunk 7/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="fetched chunk 8/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=trace msg="scheduling prefetch in 204s" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=trace msg="emitting websocket event: seek" Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="sending successful reply for dealer request" Dec 25 23:54:33 netransportnew volumio[6393]: SPOTIFY: received: {"type":"seek","data":{"context_uri":"spotify:album:4OlAuurOASiGhOm0eueN9q","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","position":87970,"duration":321960,"play_origin":""}} Dec 25 23:54:33 netransportnew volumio[6393]: SPOTIFY: PUSH STATE SPOTIFY Dec 25 23:54:33 netransportnew volumio[6393]: SPOTIFY: {"status":"play","service":"spop","title":"Playing With Madness (Instrumental) - Live in Hamburg","artist":"Schiller","album":"Atemlos Live","albumart":"https://i.scdn.co/image/ab67616d00001e027a886e1c6e8e149c71769b97","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","trackType":"spotify","seek":87970,"duration":321,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Dec 25 23:54:33 netransportnew volumio[6393]: info: CoreCommandRouter::servicePushState Dec 25 23:54:33 netransportnew volumio[6393]: info: CoreStateMachine::pushState Dec 25 23:54:33 netransportnew volumio[6393]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 23:54:33 netransportnew volumio[6393]: info: CoreCommandRouter::volumioPushState Dec 25 23:54:33 netransportnew go-librespot[6754]: time="2025-12-25T23:54:33+01:00" level=debug msg="fetched chunk 9/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:33 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output update for this device Dec 25 23:54:33 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output Dec 25 23:54:33 netransportnew volumio[6393]: info: CoreCommandRouter::volumioGetState Dec 25 23:54:33 netransportnew volumio[6393]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 25 23:54:33 netransportnew sudo[9531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 25 23:54:33 netransportnew sudo[9531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:33 netransportnew sudo[9531]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:33 netransportnew volumio[6393]: info: peppymeterbasic Daemon Started Dec 25 23:54:33 netransportnew autossh[8935]: starting ssh (count 10) Dec 25 23:54:33 netransportnew autossh[8935]: ssh child pid is 9533 Dec 25 23:54:34 netransportnew volumiossh-tunnel[9533]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 25 23:54:34 netransportnew autossh[8935]: ssh exited with error status 255; restarting ssh Dec 25 23:54:36 netransportnew go-librespot[6754]: time="2025-12-25T23:54:36+01:00" level=debug msg="fetched chunk 10/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:36 netransportnew go-librespot[6754]: time="2025-12-25T23:54:36+01:00" level=debug msg="update volume requested to 62914/65535" Dec 25 23:54:37 netransportnew go-librespot[6754]: time="2025-12-25T23:54:37+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 25 23:54:37 netransportnew go-librespot[6754]: time="2025-12-25T23:54:37+01:00" level=trace msg="emitting websocket event: volume" Dec 25 23:54:37 netransportnew go-librespot[6754]: time="2025-12-25T23:54:37+01:00" level=debug msg="update volume requested to 60292/65535" Dec 25 23:54:37 netransportnew go-librespot[6754]: time="2025-12-25T23:54:37+01:00" level=debug msg="update volume requested to 57671/65535" Dec 25 23:54:37 netransportnew volumio[6393]: SPOTIFY: received: {"type":"volume","data":{"value":96,"max":100}} Dec 25 23:54:37 netransportnew volumio[6393]: SPOTIFY: RECEIVED SPOTIFY VOLUME 96 Dec 25 23:54:37 netransportnew volumio[6393]: info: Setting Volumio Volume from Spotify: 96 Dec 25 23:54:37 netransportnew volumio[6393]: info: VolumeController::SetAlsaVolume96 Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreStateMachine::pushState Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreCommandRouter::volumioPushState Dec 25 23:54:37 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output update for this device Dec 25 23:54:37 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreCommandRouter::volumioGetState Dec 25 23:54:37 netransportnew volumio[6393]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Dec 25 23:54:37 netransportnew volumio[6393]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 25 23:54:37 netransportnew volumio[6393]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 25 23:54:37 netransportnew sudo[9536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 25 23:54:37 netransportnew sudo[9536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:37 netransportnew sudo[9536]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:37 netransportnew volumio[6393]: info: peppymeterbasic Daemon Started Dec 25 23:54:37 netransportnew go-librespot[6754]: time="2025-12-25T23:54:37+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 25 23:54:37 netransportnew go-librespot[6754]: time="2025-12-25T23:54:37+01:00" level=trace msg="emitting websocket event: volume" Dec 25 23:54:37 netransportnew volumio[6393]: SPOTIFY: received: {"type":"volume","data":{"value":88,"max":100}} Dec 25 23:54:37 netransportnew volumio[6393]: SPOTIFY: RECEIVED SPOTIFY VOLUME 88 Dec 25 23:54:37 netransportnew volumio[6393]: info: Setting Volumio Volume from Spotify: 88 Dec 25 23:54:37 netransportnew volumio[6393]: info: VolumeController::SetAlsaVolume88 Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreStateMachine::pushState Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreCommandRouter::volumioPushState Dec 25 23:54:37 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output update for this device Dec 25 23:54:37 netransportnew volumio[6393]: info: MRS: Pushing multiroomSync output Dec 25 23:54:37 netransportnew volumio[6393]: info: CoreCommandRouter::volumioGetState Dec 25 23:54:37 netransportnew volumio[6393]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 Dec 25 23:54:37 netransportnew volumio[6393]: info: PeppyMeterBasic ---peppymeterbasic status play Dec 25 23:54:37 netransportnew volumio[6393]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 25 23:54:37 netransportnew sudo[9540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Dec 25 23:54:37 netransportnew sudo[9540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:37 netransportnew sudo[9540]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:37 netransportnew volumio[6393]: info: peppymeterbasic Daemon Started Dec 25 23:54:49 netransportnew go-librespot[6754]: time="2025-12-25T23:54:49+01:00" level=debug msg="fetched chunk 11/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:54:52 netransportnew volumio[6393]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object] Dec 25 23:54:52 netransportnew volumio[6393]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter Dec 25 23:54:54 netransportnew volumio[6393]: --2025-12-25 23:54:53-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/Choose Dec 25 23:54:54 netransportnew volumio[6393]: Resolving github.com (github.com)... 140.82.121.4 Dec 25 23:54:54 netransportnew volumio[6393]: Connecting to github.com (github.com)|140.82.121.4|:443... connected. Dec 25 23:54:54 netransportnew volumio[6393]: HTTP request sent, awaiting response... 404 Not Found Dec 25 23:54:54 netransportnew volumio[6393]: 2025-12-25 23:54:53 ERROR 404: Not Found. Dec 25 23:54:54 netransportnew volumio[6393]: --2025-12-25 23:54:53-- http://a/ Dec 25 23:54:54 netransportnew volumio[6393]: Resolving a (a)... failed: Device or resource busy. Dec 25 23:54:54 netransportnew volumio[6393]: wget: unable to resolve host address ‘a’ Dec 25 23:54:54 netransportnew volumio[6393]: --2025-12-25 23:54:53-- http://packet.zip/ Dec 25 23:54:54 netransportnew volumio[6393]: Resolving packet.zip (packet.zip)... 162.255.119.167 Dec 25 23:54:54 netransportnew volumio[6393]: Connecting to packet.zip (packet.zip)|162.255.119.167|:80... connected. Dec 25 23:54:54 netransportnew volumio[6393]: HTTP request sent, awaiting response... 302 Found Dec 25 23:54:54 netransportnew volumio[6393]: Location: http://www.packet.zip/ [following] Dec 25 23:54:54 netransportnew volumio[6393]: --2025-12-25 23:54:54-- http://www.packet.zip/ Dec 25 23:54:54 netransportnew volumio[6393]: Resolving www.packet.zip (www.packet.zip)... 91.195.240.19 Dec 25 23:54:54 netransportnew volumio[6393]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected. Dec 25 23:54:54 netransportnew volumio[6393]: HTTP request sent, awaiting response... 403 Forbidden Dec 25 23:54:54 netransportnew volumio[6393]: 2025-12-25 23:54:54 ERROR 403: Forbidden. Dec 25 23:54:54 netransportnew volumio[6393]: error: PeppyMeterBasic --- An error occurs while downloading or installing Meters Dec 25 23:54:54 netransportnew volumio[6393]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory Dec 25 23:54:54 netransportnew volumio[6393]: /bin/rm: cannot remove 'a': No such file or directory Dec 25 23:54:54 netransportnew volumio[6393]: /bin/rm: cannot remove 'packet.zip*': No such file or directory Dec 25 23:54:54 netransportnew volumio[6393]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 23:54:54 netransportnew volumio[6393]: Error: Command failed: /bin/rm /tmp/Choose a packet.zip* Dec 25 23:54:54 netransportnew volumio[6393]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory Dec 25 23:54:54 netransportnew volumio[6393]: /bin/rm: cannot remove 'a': No such file or directory Dec 25 23:54:54 netransportnew volumio[6393]: /bin/rm: cannot remove 'packet.zip*': No such file or directory Dec 25 23:54:54 netransportnew volumio[6393]: at checkExecSyncError (node:child_process:887:11) Dec 25 23:54:54 netransportnew volumio[6393]: at execSync (node:child_process:959:15) Dec 25 23:54:54 netransportnew volumio[6393]: at /data/plugins/user_interface/peppymeterbasic/index.js:710:19 Dec 25 23:54:54 netransportnew volumio[6393]: at new Promise () Dec 25 23:54:54 netransportnew volumio[6393]: at peppymeterbasic.dlmeter (/data/plugins/user_interface/peppymeterbasic/index.js:685:12) Dec 25 23:54:54 netransportnew volumio[6393]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Dec 25 23:54:54 netransportnew volumio[6393]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:337:42) Dec 25 23:54:54 netransportnew volumio[6393]: at Socket.emit (node:events:514:28) Dec 25 23:54:54 netransportnew volumio[6393]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Dec 25 23:54:54 netransportnew volumio[6393]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Dec 25 23:54:54 netransportnew volumio[6393]: status: 1, Dec 25 23:54:54 netransportnew volumio[6393]: signal: null, Dec 25 23:54:54 netransportnew volumio[6393]: output: [ Dec 25 23:54:54 netransportnew volumio[6393]: null, Dec 25 23:54:54 netransportnew volumio[6393]: , Dec 25 23:54:54 netransportnew volumio[6393]: Dec 25 23:54:54 netransportnew volumio[6393]: ], Dec 25 23:54:54 netransportnew volumio[6393]: pid: 9581, Dec 25 23:54:54 netransportnew volumio[6393]: stdout: , Dec 25 23:54:54 netransportnew volumio[6393]: stderr: Dec 25 23:54:54 netransportnew volumio[6393]: } Dec 25 23:54:54 netransportnew volumio[6393]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 23:54:54 netransportnew sudo[9597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-25 23:53' Dec 25 23:54:54 netransportnew sudo[9597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:54 netransportnew sudo[9597]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:54 netransportnew vtcs[9316]: [2025-12-25 23:54:54.850] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 25 23:54:54 netransportnew qobuz-connect[9294]: 20251225 23:54:54.851 [9294.9294] INFO SampleApp: Socket closed Dec 25 23:54:54 netransportnew go-librespot[6754]: time="2025-12-25T23:54:54+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Dec 25 23:54:54 netransportnew volumio-remote-updater[768]: [2025-12-25 23:54:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 25 23:54:54 netransportnew volumio-remote-updater[768]: [2025-12-25 23:54:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 25 23:54:54 netransportnew systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 25 23:54:54 netransportnew systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 25 23:54:54 netransportnew systemd[1]: volumio.service: Consumed 1min 2.710s CPU time. Dec 25 23:54:54 netransportnew systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 25 23:54:54 netransportnew systemd[1]: dynamicswap.service: Deactivated successfully. Dec 25 23:54:55 netransportnew systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Dec 25 23:54:55 netransportnew systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 25 23:54:55 netransportnew systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 25 23:54:55 netransportnew systemd[1]: volumio.service: Consumed 1min 2.710s CPU time. Dec 25 23:54:55 netransportnew systemd[1]: Started volumio.service - Volumio Backend Module. Dec 25 23:54:55 netransportnew systemd[1]: dynamicswap.service: Deactivated successfully. Dec 25 23:54:56 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:54:56 netransportnew volumio[9624]: info: ----- Volumio3 ---- Dec 25 23:54:56 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:54:56 netransportnew volumio[9624]: info: ----- System startup ---- Dec 25 23:54:56 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:54:57 netransportnew volumio[9624]: info: MYVOLUMIO Environment detected Dec 25 23:54:57 netransportnew volumio[9624]: info: Plugin folders cleanup Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning into folder /volumio/app/plugins/ Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category audio_interface Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category miscellanea Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category music_service Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category plugins.json Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category system_controller Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category user_interface Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning into folder /data/plugins/ Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category music_service Dec 25 23:54:57 netransportnew volumio[9624]: info: Scanning category user_interface Dec 25 23:54:57 netransportnew volumio[9624]: info: Plugin folders cleanup completed Dec 25 23:54:57 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:54:57 netransportnew volumio[9624]: info: ----- Core plugins startup ---- Dec 25 23:54:57 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:54:57 netransportnew volumio[9624]: info: Loading plugins from folder /volumio/app/plugins/ Dec 25 23:54:57 netransportnew volumio[9624]: info: Adding plugin upnp to MyMusic Plugins Dec 25 23:54:57 netransportnew volumio[9624]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 25 23:54:57 netransportnew volumio[9624]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 25 23:54:57 netransportnew volumio[9624]: info: Loading plugins from folder /data/plugins/ Dec 25 23:54:57 netransportnew volumio[9624]: info: Loading plugin "system"... Dec 25 23:54:57 netransportnew volumio[9624]: info: Loading plugin "appearance"... Dec 25 23:54:57 netransportnew go-librespot[6754]: time="2025-12-25T23:54:57+01:00" level=trace msg="received accesspoint ping" Dec 25 23:54:57 netransportnew go-librespot[6754]: time="2025-12-25T23:54:57+01:00" level=trace msg="received accesspoint pong ack" Dec 25 23:54:58 netransportnew go-librespot[6754]: time="2025-12-25T23:54:58+01:00" level=trace msg="sent dealer ping" Dec 25 23:54:58 netransportnew go-librespot[6754]: time="2025-12-25T23:54:58+01:00" level=trace msg="received dealer pong" Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "network"... Dec 25 23:54:58 netransportnew volumio[9624]: info: Refreshing Cached IP Addresses Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "services"... Dec 25 23:54:58 netransportnew sudo[9654]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "alsa_controller"... Dec 25 23:54:58 netransportnew sudo[9652]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 23:54:58 netransportnew sudo[9654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:58 netransportnew sudo[9652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:58 netransportnew sudo[9654]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:58 netransportnew sudo[9652]: pam_unix(sudo:session): session closed for user root Dec 25 23:54:58 netransportnew sudo[9659]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 25 23:54:58 netransportnew sudo[9659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:54:58 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "wizard"... Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "networkfs"... Dec 25 23:54:58 netransportnew volumio[9624]: info: Starting Udev Watcher for removable devices Dec 25 23:54:58 netransportnew volumio[9624]: info: Ignoring mount for partition: boot Dec 25 23:54:58 netransportnew volumio[9624]: info: Ignoring mount for partition: volumio Dec 25 23:54:58 netransportnew volumio[9624]: info: Ignoring mount for partition: volumio_data Dec 25 23:54:58 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "volumio_command_line_client"... Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "upnp"... Dec 25 23:54:58 netransportnew volumio[9624]: info: [1766703298344] Starting Upmpd Daemon Dec 25 23:54:58 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "my_music"... Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "mpd"... Dec 25 23:54:58 netransportnew volumio[9624]: info: Loading plugin "upnp_browser"... Dec 25 23:54:59 netransportnew volumio[9624]: info: Starting UPNP Browser Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "alarm-clock"... Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "airplay_emulation"... Dec 25 23:54:59 netransportnew volumio[9624]: info: Starting Shairport Sync Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "last_100"... Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "webradio"... Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "i2s_dacs"... Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "volumiodiscovery"... Dec 25 23:54:59 netransportnew volumio[9624]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 25 23:54:59 netransportnew volumio[9624]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 25 23:54:59 netransportnew node[9624]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 25 23:54:59 netransportnew volumio[9624]: *** WARNING *** For more information see Dec 25 23:54:59 netransportnew volumio[9624]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 25 23:54:59 netransportnew volumio[9624]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 25 23:54:59 netransportnew volumio[9624]: *** WARNING *** For more information see Dec 25 23:54:59 netransportnew node[9624]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 25 23:54:59 netransportnew node[9624]: *** WARNING *** For more information see Dec 25 23:54:59 netransportnew node[9624]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 25 23:54:59 netransportnew node[9624]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 25 23:54:59 netransportnew node[9624]: *** WARNING *** For more information see Dec 25 23:54:59 netransportnew volumio[9624]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 25 23:54:59 netransportnew volumio[9624]: info: Discovery: Started advertising with name: NeTransport_New Dec 25 23:54:59 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 25 23:54:59 netransportnew volumio[9624]: info: Loading plugin "spop"... Dec 25 23:54:59 netransportnew volumio-remote-updater[768]: [2025-12-25 23:54:59] [connect] Successful connection Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "outputs"... Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "albumart"... Dec 25 23:55:00 netransportnew volumio[9624]: info: Plugin example_plugin is not enabled Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "inputs"... Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "updater_comm"... Dec 25 23:55:00 netransportnew volumio[9624]: info: Plugin mpdemulation is not enabled Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "rest_api"... Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "websocket"... Dec 25 23:55:00 netransportnew volumio[9624]: info: Starting Socket.io Server version 1.7.4 Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "peppymeterbasic"... Dec 25 23:55:00 netransportnew sudo[9659]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:00 netransportnew volumio[9684]: Forking 3 albumart workers Dec 25 23:55:00 netransportnew volumio[9624]: info: Plugin peppyspectrum is not enabled Dec 25 23:55:00 netransportnew volumio[9624]: info: Loading plugin "touch_display"... Dec 25 23:55:01 netransportnew volumio[9624]: info: Applying required configuration parameters for plugin touch_display Dec 25 23:55:01 netransportnew volumio[9624]: info: Loading i18n strings for locale de Dec 25 23:55:01 netransportnew volumio[9624]: Updating browse sources language Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::initPlayerControls Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: Express server listening on port 3000 Dec 25 23:55:01 netransportnew volumio[9624]: [Metrics] WebUI: 5s 239.05ms Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreStateMachine::resetVolumioState Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreStateMachine::getcurrentVolume Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::volumioRetrievevolume Dec 25 23:55:01 netransportnew volumio[9624]: info: Cannot read play queue from file Dec 25 23:55:01 netransportnew volumio[9624]: info: Volumio Network Manager: Network status updated: 1 Dec 25 23:55:01 netransportnew volumio[9624]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 25 23:55:01 netransportnew volumio[9624]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 25 23:55:01 netransportnew volumio[9624]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:01 netransportnew volumio[9624]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 25 23:55:01 netransportnew volumio[9624]: info: VolumeController:: Volume=undefined Mute =false Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreStateMachine::pushState Dec 25 23:55:01 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::volumioPushState Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreStateMachine::updateTrackBlock Dec 25 23:55:01 netransportnew volumio[9624]: info: CorePlayQueue::getTrackBlock Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreCommandRouter::volumioRetrievevolume Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreStateMachine::setRepeat null single undefined Dec 25 23:55:01 netransportnew volumio[9624]: info: CoreStateMachine::pushState Dec 25 23:55:02 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioPushState Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreStateMachine::setRandom null Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreStateMachine::pushState Dec 25 23:55:02 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioPushState Dec 25 23:55:02 netransportnew volumio[9624]: info: Setting Device type: Raspberry PI Dec 25 23:55:02 netransportnew volumio[9694]: Starting albumart workers Dec 25 23:55:02 netransportnew volumio[9696]: Starting albumart workers Dec 25 23:55:02 netransportnew volumio[9624]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 25 23:55:02 netransportnew volumio[9624]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03115 Dec 25 23:55:02 netransportnew volumio[9695]: Starting albumart workers Dec 25 23:55:02 netransportnew volumio[9624]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 25 23:55:02 netransportnew volumio[9624]: verbose: New Socket.io Connection to 192.168.1.43:3000 from 192.168.1.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 25 23:55:02 netransportnew volumio[9624]: info: Completed loading Core Plugins Dec 25 23:55:02 netransportnew volumio[9624]: info: Preparing to generate the ALSA configuration file Dec 25 23:55:02 netransportnew volumio[9624]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 25 23:55:02 netransportnew volumio[9624]: info: Reading ALSA contributions from plugins. Dec 25 23:55:02 netransportnew volumio[9624]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Dec 25 23:55:02 netransportnew volumio[9624]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: adding b846fe84-88bc-4da9-83c9-97be4bf99633 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: Found device NeTransport Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: Connecting to remote: 192.168.1.46 Dec 25 23:55:02 netransportnew volumio-remote-updater[768]: [2025-12-25 23:55:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1766703299 101 Dec 25 23:55:02 netransportnew volumio[9624]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 6 Dec 25 23:55:02 netransportnew volumio[9624]: verbose: New Socket.io Connection to 192.168.1.43:3000 from 192.168.1.46 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 25 23:55:02 netransportnew volumio[9624]: info: VolumeController:: Volume=undefined Mute =false Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreStateMachine::pushState Dec 25 23:55:02 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioPushState Dec 25 23:55:02 netransportnew volumio[9624]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: adding f24fea7d-cccb-40ed-bed2-16924c633fb2 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: Found device NeTransport_New Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:02 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: this is already registered, f24fea7d-cccb-40ed-bed2-16924c633fb2 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: Found device NeTransport_New Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:02 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:02 netransportnew volumio[9624]: info: Discovery: Connected to remote: 192.168.1.46 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:02 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:02 netransportnew volumio[9624]: info: Asound.conf file written Dec 25 23:55:02 netransportnew sudo[9745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 25 23:55:02 netransportnew sudo[9745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:02 netransportnew sudo[9745]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:4 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: No state is present for card Loopback Dec 25 23:55:02 netransportnew volumio[9624]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Dec 25 23:55:02 netransportnew volumio[9624]: Found hardware: "Loopback" "Loopback Mixer" "" "" "" Dec 25 23:55:02 netransportnew volumio[9624]: Hardware is initialized using a generic method Dec 25 23:55:02 netransportnew volumio[9624]: No state is present for card Loopback Dec 25 23:55:02 netransportnew volumio[9624]: info: Output device has changed, restarting MPD Dec 25 23:55:02 netransportnew volumio[9624]: info: Output device has changed, restarting Shairport Sync Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:02 netransportnew sudo[9752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 25 23:55:02 netransportnew sudo[9752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:02 netransportnew sudo[9759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 25 23:55:02 netransportnew sudo[9759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:02 netransportnew sudo[9752]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:02 netransportnew volumio[9624]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 25 23:55:02 netransportnew volumio[9624]: info: ___________ START PLUGINS ___________ Dec 25 23:55:02 netransportnew volumio[9624]: info: ControllerMpd::onStart: Initializing MPD Dec 25 23:55:02 netransportnew volumio[9624]: info: Creating MPD Configuration file Dec 25 23:55:02 netransportnew systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 25 23:55:02 netransportnew volumio[9624]: info: [1766703302808] CoreMusicLibrary::Adding element Medienserver Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 23:55:02 netransportnew sudo[9773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 25 23:55:02 netransportnew go-librespot[6754]: time="2025-12-25T23:55:02+01:00" level=debug msg="fetched chunk 12/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:02 netransportnew sudo[9773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:02 netransportnew volumio[9624]: info: UPNP Browser: Client initialized successfully Dec 25 23:55:02 netransportnew sudo[9773]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:02 netransportnew systemd[1]: mpd.service: Deactivated successfully. Dec 25 23:55:02 netransportnew systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 25 23:55:02 netransportnew systemd[1]: mpd.service: Consumed 1.474s CPU time. Dec 25 23:55:02 netransportnew systemd[1]: mpd.socket: Deactivated successfully. Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:02 netransportnew systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 25 23:55:02 netransportnew systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 25 23:55:02 netransportnew sudo[9781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 25 23:55:02 netransportnew sudo[9781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:02 netransportnew volumio[9624]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:02 netransportnew volumio[9624]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 25 23:55:02 netransportnew volumio[9624]: info: [1766703302906] CoreMusicLibrary::Adding element Last_100 Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 25 23:55:02 netransportnew volumio[9624]: info: [1766703302909] CoreMusicLibrary::Adding element Webradio Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 23:55:02 netransportnew systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 25 23:55:02 netransportnew systemd[1]: Starting mpd.service - Music Player Daemon... Dec 25 23:55:02 netransportnew volumio[9624]: info: Initializing BBC Radios Dec 25 23:55:02 netransportnew systemd[1]: mpd.service: Deactivated successfully. Dec 25 23:55:02 netransportnew systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 25 23:55:02 netransportnew systemd[1]: mpd.socket: Deactivated successfully. Dec 25 23:55:02 netransportnew systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 25 23:55:02 netransportnew systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 25 23:55:02 netransportnew systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 25 23:55:02 netransportnew systemd[1]: Starting mpd.service - Music Player Daemon... Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:02 netransportnew volumio[9624]: info: Creating Spotify config file Dec 25 23:55:02 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Dec 25 23:55:03 netransportnew volumio[9624]: info: Loading i18n strings for locale de Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 23:55:03 netransportnew volumio[9624]: info: Volumio Calling Home Dec 25 23:55:03 netransportnew sudo[9810]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Dec 25 23:55:03 netransportnew sudo[9810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew sudo[9813]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Dec 25 23:55:03 netransportnew sudo[9813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew sudo[9810]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:03 netransportnew volumio[9624]: info: Preparing to generate the ALSA configuration file Dec 25 23:55:03 netransportnew sudo[9813]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:03 netransportnew sudo[9804]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 25 23:55:03 netransportnew sudo[9804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 25 23:55:03 netransportnew sudo[9804]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:03 netransportnew sudo[9820]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Dec 25 23:55:03 netransportnew sudo[9820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew sudo[9820]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:03 netransportnew sudo[9822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Dec 25 23:55:03 netransportnew sudo[9822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew sudo[9824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Dec 25 23:55:03 netransportnew sudo[9824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew volumio[9624]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Dec 25 23:55:03 netransportnew volumio[9624]: info: Reading ALSA contributions from plugins. Dec 25 23:55:03 netransportnew systemd[1]: Reloading. Dec 25 23:55:03 netransportnew volumio[9624]: info: touch_display: Backlight interface detected. Dec 25 23:55:03 netransportnew volumio[9624]: verbose: New Socket.io Connection to 192.168.1.43 from 192.168.1.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 25 23:55:03 netransportnew volumio[9624]: info: touch_display: systemctl stop getty@tty1.service succeeded. Dec 25 23:55:03 netransportnew volumio[9624]: info: snd_dummy loaded Dec 25 23:55:03 netransportnew volumio[9624]: info: MPD Permissions set Dec 25 23:55:03 netransportnew volumio[9624]: info: MPD Permissions set Dec 25 23:55:03 netransportnew volumio[9624]: info: Volumio called home Dec 25 23:55:03 netransportnew volumio[9624]: info: Spotify config file written Dec 25 23:55:03 netransportnew volumio[9624]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew sudo[9832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Dec 25 23:55:03 netransportnew sudo[9834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 25 23:55:03 netransportnew sudo[9834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew sudo[9832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew sudo[9832]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:03 netransportnew volumio[9624]: info: No need to fix Spotify hosts Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 25 23:55:03 netransportnew volumio[9624]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetVisibleSources Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:03 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:03 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 23:55:03 netransportnew volumio[9624]: info: Received Get System Info Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 23:55:03 netransportnew volumio[9624]: info: Discovery: Getting this device information Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:03 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 23:55:03 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:03 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:03 netransportnew volumio[9624]: info: Listing playlists Dec 25 23:55:04 netransportnew volumio[9624]: info: touch_display: IframeKeyboardBridge extension installed successfully Dec 25 23:55:04 netransportnew volumio[9624]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Dec 25 23:55:04 netransportnew sudo[9865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Dec 25 23:55:04 netransportnew sudo[9865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew sudo[9867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Dec 25 23:55:04 netransportnew sudo[9867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew volumio[9624]: info: Starting Shairport Sync Dec 25 23:55:04 netransportnew sudo[9865]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:04 netransportnew sudo[9867]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:04 netransportnew sudo[9869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Dec 25 23:55:04 netransportnew sudo[9869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew sudo[9869]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:04 netransportnew volumio[9624]: info: Starting Shairport Sync Dec 25 23:55:04 netransportnew volumio[9624]: info: Starting Shairport Sync Dec 25 23:55:04 netransportnew sudo[9876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 25 23:55:04 netransportnew sudo[9874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 25 23:55:04 netransportnew sudo[9876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew sudo[9874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew sudo[9878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 25 23:55:04 netransportnew sudo[9878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew volumio[9624]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Dec 25 23:55:04 netransportnew volumio[9624]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Dec 25 23:55:04 netransportnew volumio[9624]: info: touch_display: File permissions for backlight brightness control set. Dec 25 23:55:04 netransportnew volumio[9624]: info: Asound.conf file unchanged, so no further update is needed Dec 25 23:55:04 netransportnew volumio[9624]: info: Output device has changed, restarting MPD Dec 25 23:55:04 netransportnew volumio[9624]: info: Output device has changed, restarting Shairport Sync Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:04 netransportnew sudo[9884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 25 23:55:04 netransportnew sudo[9884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew volumio[9624]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 25 23:55:04 netransportnew sudo[9884]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:04 netransportnew sudo[9886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 25 23:55:04 netransportnew sudo[9886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew volumio[9624]: info: VolumeController::SetAlsaVolume0 Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreStateMachine::pushState Dec 25 23:55:04 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::volumioPushState Dec 25 23:55:04 netransportnew volumio[9624]: info: MPD Permissions set Dec 25 23:55:04 netransportnew volumio[9624]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:04 netransportnew systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 23:55:04 netransportnew systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:04 netransportnew systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:04 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:04 netransportnew volumio[9624]: info: Starting Shairport Sync Dec 25 23:55:04 netransportnew volumio[9624]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Dec 25 23:55:04 netransportnew sudo[9906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 25 23:55:04 netransportnew sudo[9906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:04 netransportnew sudo[9822]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetVisibleSources Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:04 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 23:55:04 netransportnew systemd[1]: Reloading. Dec 25 23:55:04 netransportnew volumio[9624]: info: touch_display: systemctl disable getty@tty1.service succeeded. Dec 25 23:55:04 netransportnew volumio[9624]: info: Received Get System Info Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 23:55:04 netransportnew volumio[9624]: info: Discovery: Getting this device information Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:04 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 23:55:04 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:04 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:04 netransportnew volumio[9624]: info: Listing playlists Dec 25 23:55:05 netransportnew mpd[9826]: 2025-12-25T23:55:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 25 23:55:05 netransportnew systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:05 netransportnew systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:05 netransportnew systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:05 netransportnew systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 25 23:55:06 netransportnew autossh[8935]: starting ssh (count 11) Dec 25 23:55:06 netransportnew autossh[8935]: ssh child pid is 9927 Dec 25 23:55:06 netransportnew sudo[9824]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew systemd[1]: Started mpd.service - Music Player Daemon. Dec 25 23:55:06 netransportnew sudo[9759]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: systemctl daemon-reload succeeded. Dec 25 23:55:06 netransportnew sudo[9781]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew sudo[9929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Dec 25 23:55:06 netransportnew sudo[9929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:06 netransportnew volumio[9624]: error: MPD error: The expression evaluated to a falsy value: Dec 25 23:55:06 netransportnew volumio[9624]: assert.ok(self.idling) Dec 25 23:55:06 netransportnew volumio[9624]: error: The expression evaluated to a falsy value: Dec 25 23:55:06 netransportnew volumio[9624]: assert.ok(self.idling) Dec 25 23:55:06 netransportnew volumio[9624]: info: MPD running with PID9826 Dec 25 23:55:06 netransportnew volumio[9624]: ,establishing connection Dec 25 23:55:06 netransportnew volumio[9624]: error: updateQueue error: null Dec 25 23:55:06 netransportnew volumio[9624]: error: updateQueue error: null Dec 25 23:55:06 netransportnew systemd[1]: Starting fstrim.service - Discard unused blocks on filesystems from /etc/fstab... Dec 25 23:55:06 netransportnew systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 25 23:55:06 netransportnew systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 25 23:55:06 netransportnew systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 25 23:55:06 netransportnew sudo[9929]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: Volumio Kiosk started. Dec 25 23:55:06 netransportnew systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 25 23:55:06 netransportnew systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 25 23:55:06 netransportnew systemd[1]: go-librespot-daemon.service: Consumed 29.023s CPU time. Dec 25 23:55:06 netransportnew systemd[1]: shairport-sync.service: Deactivated successfully. Dec 25 23:55:06 netransportnew systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 25 23:55:06 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:06 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:06 netransportnew systemd[1]: shairport-sync.service: Consumed 1.907s CPU time. Dec 25 23:55:06 netransportnew volumio[9624]: info: Completed starting Core Plugins Dec 25 23:55:06 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:55:06 netransportnew volumio[9624]: info: ----- MyVolumio plugins startup ---- Dec 25 23:55:06 netransportnew volumio[9624]: info: ------------------------------------------- Dec 25 23:55:06 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 25 23:55:06 netransportnew systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 25 23:55:06 netransportnew sudo[9834]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:06 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:06 netransportnew systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 25 23:55:06 netransportnew sudo[9874]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew sudo[9876]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew sudo[9906]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew go-librespot[9936]: go-librespot daemon starting... Dec 25 23:55:06 netransportnew sudo[9878]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew systemd[1]: mpd.service: Deactivated successfully. Dec 25 23:55:06 netransportnew systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 25 23:55:06 netransportnew systemd[1]: mpd.service: Consumed 2.178s CPU time. Dec 25 23:55:06 netransportnew volumio[9624]: info: Shairport-Sync Started Dec 25 23:55:06 netransportnew volumio[9624]: Error adding Membership: Error: addMembership EINVAL Dec 25 23:55:06 netransportnew volumio[9624]: info: Shairport-Sync Started Dec 25 23:55:06 netransportnew volumio[9624]: info: Shairport-Sync Started Dec 25 23:55:06 netransportnew volumio[9624]: info: Shairport-Sync Started Dec 25 23:55:06 netransportnew systemd[1]: mpd.socket: Deactivated successfully. Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=info msg="running go-librespot 0.4.0" Dec 25 23:55:06 netransportnew systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=debug msg="app state loaded" Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=debug msg="stored credentials not found" Dec 25 23:55:06 netransportnew systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 25 23:55:06 netransportnew systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 25 23:55:06 netransportnew systemd[1]: Starting mpd.service - Music Player Daemon... Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 25 23:55:06 netransportnew fstrim[9933]: /boot: 269.7 MiB (282767360 bytes) trimmed on /dev/mmcblk0p1 Dec 25 23:55:06 netransportnew systemd[1]: fstrim.service: Deactivated successfully. Dec 25 23:55:06 netransportnew systemd[1]: Finished fstrim.service - Discard unused blocks on filesystems from /etc/fstab. Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: X display number found: 0 Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: X display number found: 0 Dec 25 23:55:06 netransportnew sudo[9945]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 25 23:55:06 netransportnew sudo[9945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 25 23:55:06 netransportnew sudo[9945]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Dec 25 23:55:06 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:06 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 25 23:55:06 netransportnew go-librespot[9938]: time="2025-12-25T23:55:06+01:00" level=info msg="zeroconf server listening on port 42947" Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: Setting screensaver timeout to 60 seconds. Dec 25 23:55:06 netransportnew volumio[9624]: info: touch_display: X display number found: 0 Dec 25 23:55:08 netransportnew mpd[9964]: 2025-12-25T23:55:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 25 23:55:08 netransportnew systemd[1]: Started mpd.service - Music Player Daemon. Dec 25 23:55:08 netransportnew sudo[9886]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:08 netransportnew volumio[9624]: error: updateQueue error: null Dec 25 23:55:08 netransportnew sudo[9990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 23:55:08 netransportnew sudo[9990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:08 netransportnew sudo[9990]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:08 netransportnew sudo[9992]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 23:55:08 netransportnew sudo[9992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:08 netransportnew sudo[9992]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:08 netransportnew sudo[9995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 25 23:55:08 netransportnew sudo[9995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:08 netransportnew sudo[9995]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:08 netransportnew volumio[9624]: info: Upmpdcli Daemon Started Dec 25 23:55:09 netransportnew sudo[9999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 25 23:55:09 netransportnew sudo[9999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:09 netransportnew sudo[10002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 25 23:55:09 netransportnew sudo[10002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:09 netransportnew systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 25 23:55:09 netransportnew systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 25 23:55:09 netransportnew systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 25 23:55:09 netransportnew systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 25 23:55:09 netransportnew mpd_monitor.sh[10004]: MPD Monitor Service: Starting MPD Monitor Service Dec 25 23:55:09 netransportnew sudo[9999]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:09 netransportnew volumio[9624]: info: Successfully started MPD Monitor Dec 25 23:55:09 netransportnew systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 25 23:55:09 netransportnew systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 25 23:55:09 netransportnew systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 25 23:55:09 netransportnew systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 25 23:55:09 netransportnew sudo[10002]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:09 netransportnew mpd_monitor.sh[10008]: MPD Monitor Service: Starting MPD Monitor Service Dec 25 23:55:09 netransportnew volumio[9624]: info: Successfully started MPD Monitor Dec 25 23:55:09 netransportnew volumio[9624]: info: go-librespot daemon successfully initialized Dec 25 23:55:11 netransportnew volumio[9624]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 25 23:55:11 netransportnew sudo[10013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 25 23:55:11 netransportnew sudo[10013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:11 netransportnew systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 25 23:55:11 netransportnew systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 25 23:55:11 netransportnew systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 25 23:55:11 netransportnew systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 25 23:55:11 netransportnew mpd_monitor.sh[10015]: MPD Monitor Service: Starting MPD Monitor Service Dec 25 23:55:11 netransportnew sudo[10013]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:11 netransportnew volumio[9624]: info: Successfully started MPD Monitor Dec 25 23:55:12 netransportnew volumio[9624]: info: Initializing connection to go-librespot Websocket Dec 25 23:55:12 netransportnew go-librespot[9938]: time="2025-12-25T23:55:12+01:00" level=debug msg="new websocket client" Dec 25 23:55:12 netransportnew volumio[9624]: info: Connection to go-librespot Websocket established Dec 25 23:55:13 netransportnew go-librespot[9938]: time="2025-12-25T23:55:13+01:00" level=debug msg="obtained new client token: AADLuAllA+mbBWf/r63gkaMJkx9viY3NvXcUa/m2UtBYx71uTnkX5FhUUgiaOm3vDTaGq7P0lUaldcgojVhNc4bTDYzbLSuV/cmYOJFNtx+WOvioppGvpC7FWrkVirEM2MzWbNntfltOGKYCYZ0b6uEvbEuZ1e9bri/xi+gVAiNMiQLfJVadKSTJAET1J4YVZXapUZdtHSc2/s7dBvZz/ACleQZnMG2GWbrdGal1r8VkxuWMwE7iTBV7DWI=" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="completed keyexchange" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="completed challenge" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=info msg="authenticated AP" username="do*****75" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=info msg="authenticated Login5" username="do*****75" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=info msg="accepted zeroconf from Redmi Andreas" username="do*****75" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="dealer connection opened" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=trace msg="starting accesspoint recv loop" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=trace msg="starting dealer recv loop" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=trace msg="received accesspoint ping" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="received connection id: ZjUxMTRhYjgtYTVj...M0EyN0JBRkFBRg==" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=trace msg="received accesspoint pong ack" Dec 25 23:55:14 netransportnew go-librespot[9938]: time="2025-12-25T23:55:14+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin bluetooth to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin multiroom to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin metavolumio to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin cd_controller to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="handling transfer player command from c440b86926bbf484350ffd2778a1090c27242a99" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="resolved context of track" uri="spotify:album:4OlAuurOASiGhOm0eueN9q" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=trace msg="fetched new page 0 with 14 items (list: 14)" uri="spotify:album:4OlAuurOASiGhOm0eueN9q" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="loading track (paused: false, position: 126207ms)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=trace msg="emitting websocket event: will_play" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1120" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="selected format OGG_VORBIS_320 (170bd690c313e809ad766a3972728057a36ec4d5)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="requested aes key for file 170bd690c313e809ad766a3972728057a36ec4d5, gid: 2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 25 23:55:15 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:15 netransportnew volumio[9624]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 23:55:15 netransportnew volumio[9624]: info: Starting MyVolumio Remote Streaming Endpoints Dec 25 23:55:15 netransportnew volumio[9624]: info: MyVolumio login type: Token Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 25 23:55:15 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched first chunk of 25, total size is 12701544 bytes" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 9/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=trace msg="seek to 126207ms (diff: 119ms, samples: 5565728, bytes: 5039095)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="created new output device" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 12/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 11/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="fetched chunk 10/24, size: 524288" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Dec 25 23:55:15 netransportnew go-librespot[9938]: time="2025-12-25T23:55:15+01:00" level=info msg="loaded track \"Playing With Madness (Instrumental) - Live in Hamburg\" (paused: false, position: 126207ms, duration: 321960ms, prefetched: false)" uri="spotify:track:2JnYsHuDMArYpYOIRqZCVz" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=trace msg="scheduling prefetch in 166s" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=trace msg="emitting websocket event: metadata" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=trace msg="emitting websocket event: active" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=debug msg="sending successful reply for dealer request" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 25 23:55:16 netransportnew go-librespot[9938]: time="2025-12-25T23:55:16+01:00" level=trace msg="emitting websocket event: playing" Dec 25 23:55:16 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 25 23:55:16 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 25 23:55:16 netransportnew volumio[9624]: info: Streaming services startup Dec 25 23:55:16 netransportnew volumio[9624]: info: Starting Streaming Daemon Dec 25 23:55:16 netransportnew sudo[10025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 25 23:55:16 netransportnew sudo[10025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 25 23:55:16 netransportnew volumio[9624]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 25 23:55:16 netransportnew sudo[10025]: pam_unix(sudo:session): session closed for user root Dec 25 23:55:16 netransportnew volumio[9624]: info: Getting Spotify volume Dec 25 23:55:16 netransportnew volumio[9624]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:4OlAuurOASiGhOm0eueN9q","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","play_origin":""}} Dec 25 23:55:16 netransportnew volumio[9624]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","name":"Playing With Madness (Instrumental) - Live in Hamburg","artist_names":["Schiller"],"album_name":"Atemlos Live","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027a886e1c6e8e149c71769b97","position":126207,"duration":321960,"release_date":"year:2010 month:11 day:26","track_number":1,"disc_number":1}} Dec 25 23:55:16 netransportnew volumio[9624]: SPOTIFY: received: {"type":"active","data":null} Dec 25 23:55:16 netransportnew volumio[9624]: info: Aligning Spotify Volume to Volumio Volume Dec 25 23:55:16 netransportnew volumio[9624]: info: CoreCommandRouter::volumioGetState Dec 25 23:55:16 netransportnew volumio[9624]: info: CorePlayQueue::getTrack 0 Dec 25 23:55:16 netransportnew volumio[9624]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:4OlAuurOASiGhOm0eueN9q","uri":"spotify:track:2JnYsHuDMArYpYOIRqZCVz","resume":false,"play_origin":""}} Dec 25 23:55:16 netransportnew volumio[9624]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 23:55:16 netransportnew volumio[9624]: TypeError: Cannot read properties of undefined (reading 'service') Dec 25 23:55:16 netransportnew volumio[9624]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Dec 25 23:55:16 netransportnew volumio[9624]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Dec 25 23:55:16 netransportnew volumio[9624]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Dec 25 23:55:16 netransportnew volumio[9624]: at WebSocket.emit (node:events:514:28) Dec 25 23:55:16 netransportnew volumio[9624]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Dec 25 23:55:16 netransportnew volumio[9624]: at Receiver.emit (node:events:514:28) Dec 25 23:55:16 netransportnew volumio[9624]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Dec 25 23:55:16 netransportnew volumio[9624]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Dec 25 23:55:16 netransportnew volumio[9624]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Dec 25 23:55:16 netransportnew volumio[9624]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Dec 25 23:55:16 netransportnew volumio[9624]: at writeOrBuffer (node:internal/streams/writable:399:12) Dec 25 23:55:16 netransportnew volumio[9624]: at _write (node:internal/streams/writable:340:10) Dec 25 23:55:16 netransportnew volumio[9624]: at Writable.write (node:internal/streams/writable:344:10) Dec 25 23:55:16 netransportnew volumio[9624]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Dec 25 23:55:16 netransportnew volumio[9624]: at Socket.emit (node:events:514:28) Dec 25 23:55:16 netransportnew volumio[9624]: at addChunk (node:internal/streams/readable:343:12) Dec 25 23:55:16 netransportnew volumio[9624]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 23:55:16 netransportnew sudo[10046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-25 23:54' Dec 25 23:55:16 netransportnew sudo[10046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"