-- Logs begin at Wed 2024-11-27 00:02:40 CET, end at Wed 2024-11-27 00:53:11 CET. -- Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="obtained new client token: AADXXWpLW/8md0VSaQfDX407Gj54j8KZgDtUXGnkXric4NIBDRugmpE4f1MMwKPC67G3OoCS/d093+wAETAsihiE3/HJUlMuUEFDogKwME2k1lcbWcMLgbHqoWyGU1tGM/jyUQGOblefnv92btcLQKTHIc3mVsniKn7uQ16nxrpomKDkCOuESBTe0lVCx/eUlATmhf8pmgBjOMZoN6uG3AknP/W7EhwAC6SrOEf1kzwPtKN4OIHu+lkf7w==" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=info msg="connected to ap-gew1.spotify.com:4070" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="completed keyexchange" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="completed challenge" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="authenticated as 31yagqeopfllezodnn3kc7m2xuna" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="authenticated as 31yagqeopfllezodnn3kc7m2xuna" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="dealer connection opened" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=info msg="accepted zeroconf user 31yagqeopfllezodnn3kc7m2xuna from Galaxy S23 Ultra" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="autoplay enabled: false" Nov 27 00:52:41 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:41+01:00" level=debug msg="received connection id: ODRlZjc3ZDYtMzQwNS00NDE5LWFjNDMtMGJjYTk3OGVkZmZjK2RlYWxlcit0Y3A6Ly8wYWNhNDAyNi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMjBEQUM3OUIxNzRDODA3OTQ3QzMyQUFEQzcxNEM3OTBEREVFMjE4REY2OTRGNzE4QTc0NEE1OThEOUVDOEI5Rg==" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="handling transfer player command from ba83eb36b94ab0346b2c0af23f82f09508a178db" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="resolved context of track" uri="spotify:user:31yagqeopfllezodnn3kc7m2xuna:collection" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=trace msg="fetched new page 0 with 919 items (list: 919)" uri="spotify:user:31yagqeopfllezodnn3kc7m2xuna:collection" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="shuffled context with seed 5572020858422020027 (len: 919, keep: 385)" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="loading track (paused: false, position: 4297ms)" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=trace msg="emitting websocket event: will_play" Nov 27 00:52:42 pi-z83 volumio[1004]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0USEeJtdeeJaQ8EIeBB4cz","play_origin":"collection-songs"}} Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="selected format OGG_VORBIS_320 (3ec2dfeefab90d99bedd0d50da7271480f4e34ea)" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="requested aes key for file 3ec2dfeefab90d99bedd0d50da7271480f4e34ea, gid: 0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1711" Nov 27 00:52:42 pi-z83 volumio[1004]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/onecall?appid=5796abbde9106b7da4febfae8c44c232&lat=44.8154&lon=-0.5661: Error: Response error: 401 - Unauthorized Nov 27 00:52:42 pi-z83 volumio[1004]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Nov 27 00:52:42 pi-z83 volumio[1004]: at runMicrotasks () Nov 27 00:52:42 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 27 00:52:42 pi-z83 volumio[1004]: at async Promise.all (index 0) Nov 27 00:52:42 pi-z83 volumio[1004]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Nov 27 00:52:42 pi-z83 volumio[1004]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Nov 27 00:52:42 pi-z83 volumio[1004]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Nov 27 00:52:42 pi-z83 volumio[1004]: info: [now-playing] Fetching API key... Nov 27 00:52:42 pi-z83 volumio[1004]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/weather?appid=5796abbde9106b7da4febfae8c44c232&lat=44.8154&lon=-0.5661: Error: Response error: 401 - Unauthorized Nov 27 00:52:42 pi-z83 volumio[1004]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Nov 27 00:52:42 pi-z83 volumio[1004]: at runMicrotasks () Nov 27 00:52:42 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 27 00:52:42 pi-z83 volumio[1004]: at async Promise.all (index 1) Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1299" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="fetched first chunk of 15, total size is 7542776 bytes" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=trace msg="seek to 4297ms (diff: 156ms, samples: 189497, bytes: 160106)" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="created new output device" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=info msg="loaded track \"Humble\" (paused: false, position: 4297ms, duration: 175945ms, prefetched: false)" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=trace msg="scheduling prefetch in 142s" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=trace msg="emitting websocket event: metadata" Nov 27 00:52:42 pi-z83 volumio[1004]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0USEeJtdeeJaQ8EIeBB4cz","name":"Humble","artist_names":["Ren","Eden Nash"],"album_name":"Humble","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e7d34e5a617cb0e16d96ad8b","position":4297,"duration":175945,"release_date":"year:2019 month:2 day:28","track_number":1,"disc_number":1}} Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=trace msg="emitting websocket event: active" Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="sending successful reply for dealer request" Nov 27 00:52:42 pi-z83 volumio[1004]: SPOTIFY: received: {"type":"active","data":null} Nov 27 00:52:42 pi-z83 volumio[1004]: info: Aligning Spotify Volume to Volumio Volume Nov 27 00:52:42 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:42 pi-z83 volumio[1004]: info: CorePlayQueue::getTrack 0 Nov 27 00:52:42 pi-z83 volumio[1004]: info: Setting Spotify Volume from Volumio: 100 Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 27 00:52:42 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:42+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 27 00:52:43 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:43+01:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:43 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 00:52:43 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:43+01:00" level=trace msg="emitting websocket event: playing" Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0USEeJtdeeJaQ8EIeBB4cz","play_origin":"collection-songs"}} Nov 27 00:52:43 pi-z83 volumio[1004]: info: Spotify is playing in volatile mode Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: UNSET VOLATILE Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"random":true,"repeat":true,"repeatSingle":false,"updatedb":false,"consume":false} Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: {"status":"play","service":"spop","title":"Humble","artist":"Ren, Eden Nash","album":"Humble","albumart":"https://i.scdn.co/image/ab67616d00001e02e7d34e5a617cb0e16d96ad8b","uri":"spotify:track:0USEeJtdeeJaQ8EIeBB4cz","trackType":"spotify","seek":4297,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreCommandRouter::servicePushState Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreStateMachine::pushState Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioPushState Nov 27 00:52:43 pi-z83 volumio[1004]: info: [ASDebug] CurState: play PrevState: stop Nov 27 00:52:43 pi-z83 volumio[1004]: info: [ASDebug] Togle GPIO: ON Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 27 00:52:43 pi-z83 volumio[1004]: info: touch_display: Setting screensaver timeout to 0 seconds. Nov 27 00:52:43 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:43+01:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: {"status":"play","service":"spop","title":"Humble","artist":"Ren, Eden Nash","album":"Humble","albumart":"https://i.scdn.co/image/ab67616d00001e02e7d34e5a617cb0e16d96ad8b","uri":"spotify:track:0USEeJtdeeJaQ8EIeBB4cz","trackType":"spotify","seek":4297,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreCommandRouter::servicePushState Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreStateMachine::pushState Nov 27 00:52:43 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioPushState Nov 27 00:52:43 pi-z83 volumio[1004]: info: [ASDebug] CurState: play PrevState: play Nov 27 00:52:43 pi-z83 volumio[1004]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 27 00:52:43 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:43+01:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:43 pi-z83 volumio[1004]: info: [now-playing] OpenWeatherMap API key obtained. Nov 27 00:52:43 pi-z83 volumio[1004]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/onecall?appid=5796abbde9106b7da4febfae8c44c232&lat=44.8154&lon=-0.5661: Error: Response error: 401 - Unauthorized Nov 27 00:52:43 pi-z83 volumio[1004]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Nov 27 00:52:43 pi-z83 volumio[1004]: at runMicrotasks () Nov 27 00:52:43 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 27 00:52:43 pi-z83 volumio[1004]: at async Promise.all (index 0) Nov 27 00:52:43 pi-z83 volumio[1004]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Nov 27 00:52:43 pi-z83 volumio[1004]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Nov 27 00:52:43 pi-z83 volumio[1004]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Nov 27 00:52:43 pi-z83 volumio[1004]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not fetch weather: Response error: 401 - Unauthorized Nov 27 00:52:43 pi-z83 volumio[1004]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:114:19) Nov 27 00:52:43 pi-z83 volumio[1004]: at runMicrotasks () Nov 27 00:52:43 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 27 00:52:43 pi-z83 volumio[1004]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Nov 27 00:52:43 pi-z83 volumio[1004]: (node:1004) UnhandledPromiseRejectionWarning: Error: Response error: 401 - Unauthorized Nov 27 00:52:43 pi-z83 volumio[1004]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Nov 27 00:52:43 pi-z83 volumio[1004]: at runMicrotasks () Nov 27 00:52:43 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 27 00:52:43 pi-z83 volumio[1004]: at async Promise.all (index 0) Nov 27 00:52:43 pi-z83 volumio[1004]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Nov 27 00:52:43 pi-z83 volumio[1004]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Nov 27 00:52:43 pi-z83 volumio[1004]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Nov 27 00:52:43 pi-z83 volumio[1004]: (node:1004) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 6) Nov 27 00:52:43 pi-z83 volumio[1004]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/weather?appid=5796abbde9106b7da4febfae8c44c232&lat=44.8154&lon=-0.5661: Error: Response error: 401 - Unauthorized Nov 27 00:52:43 pi-z83 volumio[1004]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Nov 27 00:52:43 pi-z83 volumio[1004]: at runMicrotasks () Nov 27 00:52:43 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 27 00:52:43 pi-z83 volumio[1004]: at async Promise.all (index 1) Nov 27 00:52:44 pi-z83 volumio[1004]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Nov 27 00:52:44 pi-z83 volumio[1004]: info: Sending Spotify command with payload to local API: /player/volume Nov 27 00:52:47 pi-z83 ntpd[820]: 212.227.232.161 local addr 192.168.1.193 -> Nov 27 00:52:51 pi-z83 go-librespot[1266]: time="2024-11-27T00:52:51+01:00" level=debug msg="fetched chunk 4/14, size: 524288" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 00:52:52 pi-z83 volumio[1004]: info: Discovery: Getting this device information Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 00:52:52 pi-z83 volumio[1004]: verbose: New Socket.io Connection to 192.168.1.193:3000 from 192.168.1.135 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 27 00:52:52 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 00:52:53 pi-z83 volumio[1004]: info: Discovery: Getting this device information Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 00:52:53 pi-z83 volumio[1004]: info: Discovery: Getting this device information Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:53 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 00:52:54 pi-z83 sudo[2732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 27 00:52:54 pi-z83 sudo[2732]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 00:52:54 pi-z83 sudo[2733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 27 00:52:54 pi-z83 sudo[2733]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 00:52:54 pi-z83 sudo[2732]: pam_unix(sudo:session): session closed for user root Nov 27 00:52:54 pi-z83 sudo[2733]: pam_unix(sudo:session): session closed for user root Nov 27 00:52:54 pi-z83 volumio[1004]: verbose: New Socket.io Connection to 192.168.1.193 from 192.168.1.135 UA: Mozilla/5.0 (Linux; Android 14; SM-S918B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.108 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 27 00:52:54 pi-z83 sudo[2737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 27 00:52:54 pi-z83 sudo[2737]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 00:52:54 pi-z83 sudo[2737]: pam_unix(sudo:session): session closed for user root Nov 27 00:52:54 pi-z83 sudo[2739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 27 00:52:54 pi-z83 sudo[2739]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 00:52:54 pi-z83 sudo[2739]: pam_unix(sudo:session): session closed for user root Nov 27 00:52:54 pi-z83 volumio[1004]: verbose: New Socket.io Connection to 192.168.1.193 from 192.168.1.135 UA: Mozilla/5.0 (Linux; Android 14; SM-S918B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.108 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetVisibleSources Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 27 00:52:55 pi-z83 volumio[1004]: info: Received Get System Info Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 00:52:55 pi-z83 volumio[1004]: info: Discovery: Getting this device information Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:55 pi-z83 volumio[1004]: info: Listing playlists Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 27 00:52:55 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 27 00:52:56 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 27 00:52:56 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 00:52:56 pi-z83 volumio[1004]: info: Received Get System Info Nov 27 00:52:56 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 00:52:56 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 00:52:56 pi-z83 volumio[1004]: info: Discovery: Getting this device information Nov 27 00:52:56 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:56 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 00:52:57 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 00:52:57 pi-z83 volumio[1004]: info: Received Get System Info Nov 27 00:52:57 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 00:52:57 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 00:52:57 pi-z83 volumio[1004]: info: Discovery: Getting this device information Nov 27 00:52:57 pi-z83 volumio[1004]: info: CoreCommandRouter::volumioGetState Nov 27 00:52:57 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 00:52:58 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 00:52:58 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 27 00:53:02 pi-z83 volumio[1004]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 00:53:02 pi-z83 volumio[1004]: info: [ASDebug] Setting UI defaults Nov 27 00:53:02 pi-z83 volumio[1004]: info: [ASDebug] Port: 24 Nov 27 00:53:02 pi-z83 volumio[1004]: info: [ASDebug] Inverted: false Nov 27 00:53:02 pi-z83 volumio[1004]: info: [ASDebug] Latched: false Nov 27 00:53:02 pi-z83 volumio[1004]: info: [ASDebug] On pulse width: 500 Nov 27 00:53:02 pi-z83 volumio[1004]: info: [ASDebug] Off pulse width: 500 Nov 27 00:53:03 pi-z83 go-librespot[1266]: time="2024-11-27T00:53:03+01:00" level=debug msg="fetched chunk 5/14, size: 524288" uri="spotify:track:0USEeJtdeeJaQ8EIeBB4cz" Nov 27 00:53:04 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 27 00:53:07 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 00:53:07 pi-z83 volumio[1004]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 27 00:53:08 pi-z83 volumio[1004]: info: [ASDebug] Port: 24 Nov 27 00:53:08 pi-z83 volumio[1004]: info: [ASDebug] Inverted: false Nov 27 00:53:08 pi-z83 volumio[1004]: info: [ASDebug] Delay: 720 Nov 27 00:53:10 pi-z83 volumio[1004]: info: Starting Uninstall of plugin system_controller - ampswitch Nov 27 00:53:10 pi-z83 volumio[1004]: info: Uninstalling plugin ampswitch Nov 27 00:53:10 pi-z83 volumio[1004]: info: [ASDebug] Port: 24 Nov 27 00:53:10 pi-z83 volumio[1004]: info: [ASDebug] Inverted: false Nov 27 00:53:10 pi-z83 volumio[1004]: info: [ASDebug] Delay: 720 Nov 27 00:53:10 pi-z83 volumio[1004]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 27 00:53:10 pi-z83 volumio[1004]: Error: EBADF: bad file descriptor, close Nov 27 00:53:10 pi-z83 volumio[1004]: at Object.closeSync (fs.js:439:3) Nov 27 00:53:10 pi-z83 volumio[1004]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Nov 27 00:53:10 pi-z83 volumio[1004]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Nov 27 00:53:10 pi-z83 volumio[1004]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Nov 27 00:53:10 pi-z83 volumio[1004]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Nov 27 00:53:10 pi-z83 volumio[1004]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Nov 27 00:53:10 pi-z83 volumio[1004]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Nov 27 00:53:10 pi-z83 volumio[1004]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Nov 27 00:53:10 pi-z83 volumio[1004]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1465:22) Nov 27 00:53:10 pi-z83 volumio[1004]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1246:45) Nov 27 00:53:10 pi-z83 volumio[1004]: at Socket.emit (events.js:315:20) Nov 27 00:53:10 pi-z83 volumio[1004]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 27 00:53:10 pi-z83 volumio[1004]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Nov 27 00:53:10 pi-z83 volumio[1004]: errno: -9, Nov 27 00:53:10 pi-z83 volumio[1004]: syscall: 'close', Nov 27 00:53:10 pi-z83 volumio[1004]: code: 'EBADF' Nov 27 00:53:10 pi-z83 volumio[1004]: } Nov 27 00:53:10 pi-z83 volumio[1004]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 27 00:53:11 pi-z83 sudo[2755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-27 00:52 Nov 27 00:53:11 pi-z83 sudo[2755]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"