-- Logs begin at Fri 2024-03-29 21:56:52 CET, end at Mon 2024-04-01 12:37:32 CEST. -- Apr 01 12:36:15 volumio go-librespot[5989]: time="2024-04-01T12:36:15+02:00" level=debug msg="handling transfer player command from 33ab87867000ddc53e47de29f2bc6e95ea1c4ed8" Apr 01 12:36:15 volumio go-librespot[5989]: time="2024-04-01T12:36:15+02:00" level=debug msg="loading track spotify:track:5x0qufZkT7XVcOhyg0S7XI (paused: true, position: 26168ms)" Apr 01 12:36:15 volumio go-librespot[5989]: time="2024-04-01T12:36:15+02:00" level=debug msg="renewing login5 access token" Apr 01 12:36:16 volumio go-librespot[5989]: time="2024-04-01T12:36:16+02:00" level=debug msg="authenticated as 21bldj6w74brdm5obmp7av3ka" Apr 01 12:36:16 volumio go-librespot[5989]: time="2024-04-01T12:36:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:36:16 volumio go-librespot[5989]: time="2024-04-01T12:36:16+02:00" level=trace msg="emitting websocket event: will_play" Apr 01 12:36:16 volumio volumio[822]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5x0qufZkT7XVcOhyg0S7XI","play_origin":"album"}} Apr 01 12:36:16 volumio go-librespot[5989]: time="2024-04-01T12:36:16+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5x0qufZkT7XVcOhyg0S7XI" Apr 01 12:36:16 volumio go-librespot[5989]: time="2024-04-01T12:36:16+02:00" level=debug msg="requested aes key for file 405d55869b2df4d59c5f8d629856080ec31cf543, track: spotify:track:5x0qufZkT7XVcOhyg0S7XI" Apr 01 12:36:16 volumio go-librespot[5989]: time="2024-04-01T12:36:16+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2328" Apr 01 12:36:17 volumio go-librespot[5989]: time="2024-04-01T12:36:17+02:00" level=debug msg="fetched first chunk of 21, total size is 10646088 bytes" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="fetched chunk 3/20, size: 524288" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="fetched chunk 2/20, size: 524288" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="fetched chunk 1/20, size: 524288" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=trace msg="seek to 26168ms (diff: 56ms, samples: 1154008, bytes: 909401)" Apr 01 12:36:18 volumio kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="fetched chunk 4/20, size: 524288" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=info msg="loaded track \"No Jane\" (uri: spotify:track:5x0qufZkT7XVcOhyg0S7XI, paused: true, position: 26168ms, duration: 320626ms)" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=trace msg="emitting websocket event: metadata" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=trace msg="emitting websocket event: active" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="sending successful reply for delaer request" Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5x0qufZkT7XVcOhyg0S7XI","name":"No Jane","artist_names":["Radio Moscow"],"album_name":"Brain Cycles","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023ae820020865f6589d06aa01","position":26168,"duration":320626}} Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: received: {"type":"active","data":null} Apr 01 12:36:18 volumio volumio[822]: info: Aligning Spotify Volume to Volumio Volume Apr 01 12:36:18 volumio volumio[822]: info: CoreCommandRouter::volumioGetState Apr 01 12:36:18 volumio volumio[822]: info: CorePlayQueue::getTrack 0 Apr 01 12:36:18 volumio volumio[822]: info: Setting Spotify Volume from Volumio: 100 Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 01 12:36:18 volumio volumio[822]: info: Sending Spotify command with payload to local API: /player/volume Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=trace msg="emitting websocket event: paused" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="update volume to 65535/65535" Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5x0qufZkT7XVcOhyg0S7XI","play_origin":"album"}} Apr 01 12:36:18 volumio volumio[822]: info: Spotify is playing in volatile mode Apr 01 12:36:18 volumio volumio[822]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: UNSET VOLATILE Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: {"status":"play","position":0,"title":"Yello - I Love You","artist":"80s80s Party","album":"","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music114/v4/1e/23/30/1e233090-d396-f2f7-fc92-3d7c7e90f1a6/source/600x600bb.jpg","uri":"http://streams.80s80s.de/party/mp3-192/volumio","trackType":"80s80s Radio","seek":0,"duration":"245","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Apr 01 12:36:18 volumio volumio[822]: info: Setting Spotify stop after unset volatile call Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: PUSH STATE SPOTIFY Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: {"status":"pause","service":"spop","title":"No Jane","artist":"Radio Moscow","album":"Brain Cycles","albumart":"https://i.scdn.co/image/ab67616d00001e023ae820020865f6589d06aa01","uri":"spotify:track:5x0qufZkT7XVcOhyg0S7XI","trackType":"spotify","seek":26168,"duration":320,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2} Apr 01 12:36:18 volumio volumio[822]: info: CoreCommandRouter::servicePushState Apr 01 12:36:18 volumio volumio[822]: info: CoreStateMachine::pushState Apr 01 12:36:18 volumio volumio[822]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 01 12:36:18 volumio volumio[822]: info: CoreCommandRouter::volumioPushState Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2332" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=trace msg="emitting websocket event: volume" Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2328" Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 01 12:36:18 volumio go-librespot[5989]: time="2024-04-01T12:36:18+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 01 12:36:18 volumio volumio[822]: info: Spotify Stop Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: SPOTIFY STOP Apr 01 12:36:18 volumio volumio[822]: SPOTIFY: {"status":"pause","title":"No Jane","artist":"Radio Moscow","album":"Brain Cycles","albumart":"https://i.scdn.co/image/ab67616d00001e023ae820020865f6589d06aa01","uri":"spotify:track:5x0qufZkT7XVcOhyg0S7XI","trackType":"spotify","seek":26168,"duration":320,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Apr 01 12:36:20 volumio go-librespot[5989]: time="2024-04-01T12:36:20+02:00" level=debug msg="handling play player command from 33ab87867000ddc53e47de29f2bc6e95ea1c4ed8" Apr 01 12:36:20 volumio go-librespot[5989]: time="2024-04-01T12:36:20+02:00" level=debug msg="loading track spotify:track:4ABXkvilk9vyS5FXkunxF4 (paused: false, position: 0ms)" Apr 01 12:36:20 volumio go-librespot[5989]: time="2024-04-01T12:36:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:36:20 volumio go-librespot[5989]: time="2024-04-01T12:36:20+02:00" level=trace msg="emitting websocket event: will_play" Apr 01 12:36:20 volumio volumio[822]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","play_origin":"playlist"}} Apr 01 12:36:20 volumio go-librespot[5989]: time="2024-04-01T12:36:20+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4ABXkvilk9vyS5FXkunxF4" Apr 01 12:36:20 volumio go-librespot[5989]: time="2024-04-01T12:36:20+02:00" level=debug msg="requested aes key for file be897efe90a5d1c1ea2aaa29a4d4017f1e072c33, track: spotify:track:4ABXkvilk9vyS5FXkunxF4" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="fetched first chunk of 16, total size is 8101996 bytes" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Apr 01 12:36:21 volumio kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=info msg="loaded track \"Cuban Cigar\" (uri: spotify:track:4ABXkvilk9vyS5FXkunxF4, paused: false, position: 0ms, duration: 192626ms)" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=trace msg="emitting websocket event: metadata" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="sending successful reply for delaer request" Apr 01 12:36:21 volumio volumio[822]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","name":"Cuban Cigar","artist_names":["Peter Godfrey"],"album_name":"Peter Godfrey, Vol. 7","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0252fd3ed8a796362bee08d319","position":0,"duration":192626}} Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="fetched chunk 2/15, size: 524288" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="fetched chunk 3/15, size: 524288" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=trace msg="emitting websocket event: playing" Apr 01 12:36:21 volumio volumio[822]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","play_origin":"playlist"}} Apr 01 12:36:21 volumio volumio[822]: SPOTIFY: PUSH STATE SPOTIFY Apr 01 12:36:21 volumio volumio[822]: SPOTIFY: {"status":"play","service":"spop","title":"Cuban Cigar","artist":"Peter Godfrey","album":"Peter Godfrey, Vol. 7","albumart":"https://i.scdn.co/image/ab67616d00001e0252fd3ed8a796362bee08d319","uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"stream":false,"repeatMode":"all"} Apr 01 12:36:21 volumio volumio[822]: info: CoreCommandRouter::servicePushState Apr 01 12:36:21 volumio volumio[822]: info: CoreStateMachine::pushState Apr 01 12:36:21 volumio volumio[822]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 01 12:36:21 volumio volumio[822]: info: CoreCommandRouter::volumioPushState Apr 01 12:36:21 volumio volumio[822]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 01 12:36:21 volumio go-librespot[5989]: time="2024-04-01T12:36:21+02:00" level=debug msg="fetched chunk 1/15, size: 524288" Apr 01 12:36:22 volumio volumio[822]: SPOTIFY: PUSH STATE SPOTIFY Apr 01 12:36:22 volumio volumio[822]: SPOTIFY: {"status":"play","service":"spop","title":"Cuban Cigar","artist":"Peter Godfrey","album":"Peter Godfrey, Vol. 7","albumart":"https://i.scdn.co/image/ab67616d00001e0252fd3ed8a796362bee08d319","uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"stream":false,"repeatMode":"all"} Apr 01 12:36:22 volumio volumio[822]: info: CoreCommandRouter::servicePushState Apr 01 12:36:22 volumio volumio[822]: info: CoreStateMachine::pushState Apr 01 12:36:22 volumio volumio[822]: info: CoreCommandRouter::volumioPushState Apr 01 12:36:22 volumio volumio[822]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 01 12:36:32 volumio go-librespot[5989]: time="2024-04-01T12:36:32+02:00" level=debug msg="fetched chunk 4/15, size: 524288" Apr 01 12:36:38 volumio go-librespot[5989]: time="2024-04-01T12:36:38+02:00" level=debug msg="handling set_queue player command from 33ab87867000ddc53e47de29f2bc6e95ea1c4ed8" Apr 01 12:36:38 volumio go-librespot[5989]: time="2024-04-01T12:36:38+02:00" level=warning msg="failed handling dealer request" error="unsupported player command: set_queue" Apr 01 12:36:45 volumio go-librespot[5989]: time="2024-04-01T12:36:45+02:00" level=debug msg="fetched chunk 5/15, size: 524288" Apr 01 12:36:57 volumio go-librespot[5989]: time="2024-04-01T12:36:57+02:00" level=debug msg="fetched chunk 6/15, size: 524288" Apr 01 12:37:10 volumio go-librespot[5989]: time="2024-04-01T12:37:10+02:00" level=debug msg="fetched chunk 7/15, size: 524288" Apr 01 12:37:13 volumio volumio[822]: info: [1711967833667] [80s80s] Pushing the next song state Prince & The Revolution - Raspberry Beret and getting next track. Apr 01 12:37:13 volumio volumio[822]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 01 12:37:13 volumio volumio[822]: TypeError: Cannot set property 'name' of undefined Apr 01 12:37:13 volumio volumio[822]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Apr 01 12:37:13 volumio volumio[822]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Apr 01 12:37:13 volumio volumio[822]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Apr 01 12:37:13 volumio volumio[822]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Apr 01 12:37:13 volumio volumio[822]: at processImmediate (internal/timers.js:461:21) Apr 01 12:37:13 volumio volumio[822]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 01 12:37:14 volumio sudo[8725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-01 12:36 Apr 01 12:37:14 volumio sudo[8725]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:14 volumio sudo[8725]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:14 volumio volumio-remote-updater[495]: [2024-04-01 12:37:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 01 12:37:14 volumio volumio-remote-updater[495]: [2024-04-01 12:37:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 01 12:37:14 volumio go-librespot[5989]: time="2024-04-01T12:37:14+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Apr 01 12:37:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 01 12:37:14 volumio ntfs-3g[876]: Unmounting /dev/sda1 (TOSHIBA EXT) Apr 01 12:37:14 volumio systemd[1]: media-TOSHIBA_EXT.mount: Succeeded. Apr 01 12:37:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 01 12:37:14 volumio systemd[1]: Started dynamicswap service. Apr 01 12:37:14 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 01 12:37:14 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Apr 01 12:37:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Apr 01 12:37:14 volumio systemd[1]: Stopped Volumio Backend Module. Apr 01 12:37:14 volumio systemd[1]: Started Volumio Backend Module. Apr 01 12:37:14 volumio systemd[1]: Started dynamicswap service. Apr 01 12:37:14 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 01 12:37:15 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:15 volumio volumio[8739]: info: ----- Volumio3 ---- Apr 01 12:37:15 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:15 volumio volumio[8739]: info: ----- System startup ---- Apr 01 12:37:15 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:16 volumio volumio[8739]: info: MYVOLUMIO Environment detected Apr 01 12:37:16 volumio volumio[8739]: info: Plugin folders cleanup Apr 01 12:37:16 volumio volumio[8739]: info: Scanning into folder /volumio/app/plugins/ Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category audio_interface Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category miscellanea Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category music_service Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category plugins.json Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category system_controller Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category user_interface Apr 01 12:37:16 volumio volumio[8739]: info: Scanning into folder /data/plugins/ Apr 01 12:37:16 volumio volumio[8739]: info: Scanning category music_service Apr 01 12:37:16 volumio volumio[8739]: info: Plugin folders cleanup completed Apr 01 12:37:16 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:16 volumio volumio[8739]: info: ----- Core plugins startup ---- Apr 01 12:37:16 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugins from folder /volumio/app/plugins/ Apr 01 12:37:16 volumio volumio[8739]: info: Adding plugin upnp to MyMusic Plugins Apr 01 12:37:16 volumio volumio[8739]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 01 12:37:16 volumio volumio[8739]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugins from folder /data/plugins/ Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "system"... Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "appearance"... Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "network"... Apr 01 12:37:16 volumio volumio[8739]: info: Refreshing Cached IP Addresses Apr 01 12:37:16 volumio sudo[8763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 01 12:37:16 volumio sudo[8763]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:16 volumio sudo[8763]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:16 volumio sudo[8766]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "services"... Apr 01 12:37:16 volumio sudo[8766]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "alsa_controller"... Apr 01 12:37:16 volumio sudo[8766]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:16 volumio sudo[8768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 01 12:37:16 volumio sudo[8768]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:16 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "wizard"... Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "volumio_command_line_client"... Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "upnp"... Apr 01 12:37:16 volumio volumio[8739]: info: [1711967836826] Starting Upmpd Daemon Apr 01 12:37:16 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "my_music"... Apr 01 12:37:16 volumio volumio[8739]: info: Loading plugin "mpd"... Apr 01 12:37:17 volumio volumio[8739]: info: Creating MPD Configuration file Apr 01 12:37:17 volumio volumio[8739]: info: Loading plugin "upnp_browser"... Apr 01 12:37:17 volumio sudo[8776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 01 12:37:17 volumio sudo[8776]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:17 volumio sudo[8776]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:17 volumio sudo[8778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 01 12:37:17 volumio sudo[8778]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:17 volumio systemd[1]: Stopping Music Player Daemon... Apr 01 12:37:17 volumio systemd[1]: mpd.service: Succeeded. Apr 01 12:37:17 volumio systemd[1]: Stopped Music Player Daemon. Apr 01 12:37:17 volumio systemd[1]: Starting Music Player Daemon... Apr 01 12:37:17 volumio volumio[8739]: info: Loading plugin "networkfs"... Apr 01 12:37:17 volumio volumio[8739]: info: Starting Udev Watcher for removable devices Apr 01 12:37:17 volumio volumio[8739]: info: Ignoring mount for partition: boot Apr 01 12:37:17 volumio volumio[8739]: info: Ignoring mount for partition: volumio Apr 01 12:37:17 volumio volumio[8739]: info: Ignoring mount for partition: volumio_data Apr 01 12:37:17 volumio volumio[8739]: info: Mounting Device TOSHIBA_EXT Apr 01 12:37:17 volumio sudo[8789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/TOSHIBA_EXT -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 01 12:37:17 volumio sudo[8789]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:17 volumio mpd[8783]: Apr 01 12:37 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 01 12:37:18 volumio ntfs-3g[8792]: Version 2017.3.23AR.3 integrated FUSE 28 Apr 01 12:37:18 volumio ntfs-3g[8792]: Mounted /dev/sda1 (Read-Write, label "TOSHIBA EXT", NTFS 3.1) Apr 01 12:37:18 volumio ntfs-3g[8792]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 01 12:37:18 volumio ntfs-3g[8792]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Apr 01 12:37:18 volumio ntfs-3g[8792]: Global ownership and permissions enforced, configuration type 7 Apr 01 12:37:18 volumio sudo[8789]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:18 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "alarm-clock"... Apr 01 12:37:18 volumio mpd[8783]: Apr 01 12:37 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 01 12:37:18 volumio mpd[8783]: Apr 01 12:37 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 01 12:37:18 volumio systemd[1]: Started Music Player Daemon. Apr 01 12:37:18 volumio sudo[8778]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "airplay_emulation"... Apr 01 12:37:18 volumio volumio[8739]: info: Starting Shairport Sync Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "last_100"... Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "webradio"... Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "i2s_dacs"... Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "volumiodiscovery"... Apr 01 12:37:18 volumio volumio[8739]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 01 12:37:18 volumio volumio[8739]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 01 12:37:18 volumio node[8739]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 01 12:37:18 volumio volumio[8739]: *** WARNING *** For more information see Apr 01 12:37:18 volumio volumio[8739]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 01 12:37:18 volumio volumio[8739]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 01 12:37:18 volumio volumio[8739]: *** WARNING *** For more information see Apr 01 12:37:18 volumio node[8739]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 01 12:37:18 volumio node[8739]: *** WARNING *** For more information see Apr 01 12:37:18 volumio node[8739]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 01 12:37:18 volumio node[8739]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 01 12:37:18 volumio node[8739]: *** WARNING *** For more information see Apr 01 12:37:18 volumio volumio[8739]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 01 12:37:18 volumio volumio[8739]: info: Discovery: Started advertising with name: Volumio Apr 01 12:37:18 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 01 12:37:18 volumio volumio[8739]: info: Loading plugin "spop"... Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "outputs"... Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "albumart"... Apr 01 12:37:19 volumio volumio[8739]: info: Plugin example_plugin is not enabled Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "inputs"... Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "updater_comm"... Apr 01 12:37:19 volumio volumio[8739]: info: Plugin mpdemulation is not enabled Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "rest_api"... Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "websocket"... Apr 01 12:37:19 volumio volumio[8739]: info: Loading plugin "80s80s"... Apr 01 12:37:19 volumio volumio[8739]: Forking 3 albumart workers Apr 01 12:37:19 volumio volumio[8739]: info: Applying required configuration parameters for plugin 80s80s Apr 01 12:37:19 volumio volumio[8739]: info: [1711967839331] [80s80s] API delay: 30 Apr 01 12:37:19 volumio volumio[8739]: info: Loading i18n strings for locale en Apr 01 12:37:19 volumio volumio[8739]: Updating browse sources language Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 01 12:37:19 volumio volumio-remote-updater[495]: [2024-04-01 12:37:19] [connect] Successful connection Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::initPlayerControls Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: Express server listening on port 3000 Apr 01 12:37:19 volumio volumio[8739]: [Metrics] WebUI: 4s 212.06ms Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::resetVolumioState Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::getcurrentVolume Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::volumioRetrievevolume Apr 01 12:37:19 volumio volumio[8739]: info: MPD Permissions set Apr 01 12:37:19 volumio volumio-remote-updater[495]: [2024-04-01 12:37:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1711967839 101 Apr 01 12:37:19 volumio volumio[8739]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Apr 01 12:37:19 volumio volumio[8739]: info: MPD running with PID8783 Apr 01 12:37:19 volumio volumio[8739]: ,establishing connection Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 01 12:37:19 volumio volumio[8739]: info: Executing start script for DAC IQaudIO DAC Plus Apr 01 12:37:19 volumio volumio[8739]: info: Reloading queue from file Apr 01 12:37:19 volumio volumio[8739]: error: updateQueue error: null Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::setRepeat null single undefined Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::pushState Apr 01 12:37:19 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::volumioPushState Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::setRandom null Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::pushState Apr 01 12:37:19 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::volumioPushState Apr 01 12:37:19 volumio volumio[8739]: info: VolumeController:: Volume=100 Mute =false Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::pushState Apr 01 12:37:19 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::volumioPushState Apr 01 12:37:19 volumio volumio[8739]: info: CoreStateMachine::updateTrackBlock Apr 01 12:37:19 volumio volumio[8739]: info: CorePlayQueue::getTrackBlock Apr 01 12:37:19 volumio volumio[8739]: info: CoreCommandRouter::volumioRetrievevolume Apr 01 12:37:19 volumio volumio[8739]: Starting albumart workers Apr 01 12:37:19 volumio volumio[8739]: info: Setting Device type: Raspberry PI Apr 01 12:37:19 volumio volumio[8739]: Starting albumart workers Apr 01 12:37:19 volumio volumio[8739]: error: updateQueue error: null Apr 01 12:37:19 volumio volumio[8739]: Starting albumart workers Apr 01 12:37:19 volumio volumio[8739]: info: DAC script executed Apr 01 12:37:19 volumio volumio[8739]: info: Completed loading Core Plugins Apr 01 12:37:19 volumio volumio[8739]: info: Preparing to generate the ALSA configuration file Apr 01 12:37:19 volumio volumio[8739]: info: Asound.conf file unchanged, so no further update is needed Apr 01 12:37:19 volumio volumio[8739]: info: Output device has changed, restarting MPD Apr 01 12:37:20 volumio sudo[8768]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:20 volumio sudo[8848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 01 12:37:20 volumio sudo[8848]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:20 volumio volumio[8739]: info: Output device has changed, restarting Shairport Sync Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 01 12:37:20 volumio sudo[8848]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:20 volumio sudo[8851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 01 12:37:20 volumio sudo[8851]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:20 volumio systemd[1]: Stopping Music Player Daemon... Apr 01 12:37:20 volumio volumio[8739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 01 12:37:20 volumio volumio[8739]: info: ___________ START PLUGINS ___________ Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 01 12:37:20 volumio volumio[8739]: info: [1711967840159] CoreMusicLibrary::Adding element Media Servers Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 01 12:37:20 volumio systemd[1]: mpd.service: Succeeded. Apr 01 12:37:20 volumio systemd[1]: Stopped Music Player Daemon. Apr 01 12:37:20 volumio systemd[1]: Starting Music Player Daemon... Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 01 12:37:20 volumio volumio[8739]: info: [1711967840319] CoreMusicLibrary::Adding element Last_100 Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 01 12:37:20 volumio volumio[8739]: info: [1711967840322] CoreMusicLibrary::Adding element Webradio Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 01 12:37:20 volumio volumio[8739]: info: Creating Spotify config file Apr 01 12:37:20 volumio volumio[8739]: info: Starting Volume Timer Limit Guard Apr 01 12:37:20 volumio volumio[8739]: info: Loading Spotify Daemon to Volumio volume map Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 01 12:37:20 volumio volumio[8739]: info: [1711967840432] CoreMusicLibrary::Adding element 80s80s Radio Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 01 12:37:20 volumio volumio[8739]: Cannot find translation for source 80s80s Radio Apr 01 12:37:20 volumio volumio[8739]: info: Volumio Calling Home Apr 01 12:37:20 volumio volumio[8739]: info: Completed starting Core Plugins Apr 01 12:37:20 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:20 volumio volumio[8739]: info: ----- MyVolumio plugins startup ---- Apr 01 12:37:20 volumio volumio[8739]: info: ------------------------------------------- Apr 01 12:37:20 volumio volumio[8739]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 01 12:37:20 volumio volumio[8739]: info: Discovery: adding 3bc2fa63-be3c-4772-91e4-cdb81f46fb9e Apr 01 12:37:20 volumio volumio[8739]: info: Discovery: Found device Volumio Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::volumioGetState Apr 01 12:37:20 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:20 volumio volumio[8739]: info: MPD Permissions set Apr 01 12:37:20 volumio volumio[8739]: info: VolumeController:: Volume=100 Mute =false Apr 01 12:37:20 volumio volumio[8739]: info: CoreStateMachine::pushState Apr 01 12:37:20 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::volumioPushState Apr 01 12:37:20 volumio volumio[8739]: info: Spotify config file written Apr 01 12:37:20 volumio sudo[8894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 01 12:37:20 volumio sudo[8894]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:20 volumio volumio[8739]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio systemd[1]: Stopping go-librespot Daemon... Apr 01 12:37:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 01 12:37:20 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Apr 01 12:37:20 volumio systemd[1]: Stopped go-librespot Daemon. Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio systemd[1]: Started go-librespot Daemon. Apr 01 12:37:20 volumio sudo[8894]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:20 volumio go-librespot[8896]: Librespot-go daemon starting... Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 01 12:37:20 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 01 12:37:20 volumio go-librespot[8896]: time="2024-04-01T12:37:20+02:00" level=info msg="generated new device id: d80d18294255470a773d4fe70b18006f7d399613" Apr 01 12:37:20 volumio volumio[8739]: info: Volumio called home Apr 01 12:37:20 volumio volumio[8739]: info: Starting Shairport Sync Apr 01 12:37:20 volumio volumio[8739]: info: Starting Shairport Sync Apr 01 12:37:20 volumio sudo[8908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 01 12:37:20 volumio sudo[8908]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:20 volumio volumio[8739]: info: Starting Shairport Sync Apr 01 12:37:20 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 01 12:37:20 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 01 12:37:20 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 01 12:37:20 volumio sudo[8911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 01 12:37:20 volumio sudo[8911]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:20 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 01 12:37:20 volumio sudo[8908]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:20 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 01 12:37:20 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 01 12:37:20 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 01 12:37:20 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 01 12:37:20 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 01 12:37:20 volumio sudo[8911]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:20 volumio sudo[8916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 01 12:37:20 volumio sudo[8916]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:20 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 01 12:37:20 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 01 12:37:20 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 01 12:37:20 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 01 12:37:20 volumio go-librespot[8896]: time="2024-04-01T12:37:20+02:00" level=debug msg="obtained new client token: AACOP49OoWtxyeOtPZfbYldejeVp4haGHHbncJGLiD0cgn5isUJdG96oBnEvOJBwGaZg6jsT/4cIso8DHnv9vASttk2hDdZ8XF/xV7ci1OLfYvJcpyOOHSoGJjk0Axj+o6BZcAixx+NLgueXowE1mOECWdZH4z6NX0y+sIon6di75wthIYxaBvsGjsFl92zSLrdhIMlTlqsOgR5uUHY0G5l7dNUKhGkg8fMbZb5oFWh+Qsu+2Lv3ruAxgeLMtw==" Apr 01 12:37:20 volumio go-librespot[8896]: time="2024-04-01T12:37:20+02:00" level=debug msg="stored credentials found for 21bldj6w74brdm5obmp7av3ka" Apr 01 12:37:20 volumio sudo[8916]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:20 volumio volumio[8739]: info: Shairport-Sync Started Apr 01 12:37:21 volumio volumio[8739]: Error adding Membership: Error: addMembership EINVAL Apr 01 12:37:21 volumio volumio[8739]: info: Shairport-Sync Started Apr 01 12:37:21 volumio volumio[8739]: info: Shairport-Sync Started Apr 01 12:37:21 volumio volumio[8739]: info: CoreCommandRouter::volumioGetState Apr 01 12:37:21 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:21 volumio volumio[8739]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 01 12:37:21 volumio volumio[8739]: SPOTIFY: BQDYI7dGK-11EYzjYlr8UfBXNKjpv-bi7DRwljHcKoqLa6VWAuVqJ9_IYUcmzMUDcIH82yvkZ2lmsjGr0cpf0DVbijNp-WhKBmT3NxRUKUkhWRSdL0tTK-xB4Kyr-t4wnvh_HXvIMom9H1tFAh09yOAJ5vNHkIMftgfjo4sK7dfNco0UmvMcmUM3EG2qi1Gu4_sNIKapnIp-fGReHSN3Prf-aSCXbQSm9BkFqCR8S135dMFzX5VsZBzoytcipr2aNA Apr 01 12:37:21 volumio volumio[8739]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 01 12:37:21 volumio volumio[8739]: info: New Spotify access token = BQDYI7dGK-11EYzjYlr8UfBXNKjpv-bi7DRwljHcKoqLa6VWAuVqJ9_IYUcmzMUDcIH82yvkZ2lmsjGr0cpf0DVbijNp-WhKBmT3NxRUKUkhWRSdL0tTK-xB4Kyr-t4wnvh_HXvIMom9H1tFAh09yOAJ5vNHkIMftgfjo4sK7dfNco0UmvMcmUM3EG2qi1Gu4_sNIKapnIp-fGReHSN3Prf-aSCXbQSm9BkFqCR8S135dMFzX5VsZBzoytcipr2aNA Apr 01 12:37:21 volumio volumio[8739]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 01 12:37:21 volumio mpd[8869]: Apr 01 12:37 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="completed keyexchange" Apr 01 12:37:21 volumio volumio[8739]: SPOTIFY: User informations: {"display_name":"Kovács Tamás","external_urls":{"spotify":"https://open.spotify.com/user/21bldj6w74brdm5obmp7av3ka"},"href":"https://api.spotify.com/v1/users/21bldj6w74brdm5obmp7av3ka","id":"21bldj6w74brdm5obmp7av3ka","images":[{"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=931308460258439&height=50&width=50&ext=1714559765&hash=AfrjudIPLzvUVaArSNwEKgen90dt8yCrFC9wUonpM30dEw","height":64,"width":64},{"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=931308460258439&height=300&width=300&ext=1714559765&hash=AfrktUuaLSCWU-CLkbn7BTBnU-DONxUzplIfeQdoVInd9w","height":300,"width":300}],"type":"user","uri":"spotify:user:21bldj6w74brdm5obmp7av3ka","followers":{"href":null,"total":13},"country":"HU","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"thom388@gmail.com"} Apr 01 12:37:21 volumio volumio[8739]: info: Spotify Successfully logged in Apr 01 12:37:21 volumio volumio[8739]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 01 12:37:21 volumio volumio[8739]: info: [1711967841207] CoreMusicLibrary::Adding element Spotify Apr 01 12:37:21 volumio volumio[8739]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 01 12:37:21 volumio volumio[8739]: Cannot find translation for source 80s80s Radio Apr 01 12:37:21 volumio volumio[8739]: Cannot find translation for source Spotify Apr 01 12:37:21 volumio mpd[8869]: Apr 01 12:37 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 01 12:37:21 volumio mpd[8869]: Apr 01 12:37 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 01 12:37:21 volumio systemd[1]: Started Music Player Daemon. Apr 01 12:37:21 volumio sudo[8851]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:21 volumio volumio[8739]: error: updateQueue error: null Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="completed challenge" Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="authenticated as 21bldj6w74brdm5obmp7av3ka" Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="authenticated as 21bldj6w74brdm5obmp7av3ka" Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 01 12:37:21 volumio go-librespot[8896]: time="2024-04-01T12:37:21+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="dealer connection opened" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="received connection id: Zjg4ZWJmY2QtMTNjNS00OWRiLTlhYjQtYzE0MThjYWNjYmNkK2RlYWxlcit0Y3A6Ly9nZXcxLWRlYWxlci1hLWpiMnguZ2V3MS5zcG90aWZ5Lm5ldDo1NzAwKzg0MTg3MjhCMTcxRkQwODUzMzYzOEQ0NTY4NTJCQzU0N0VDNTdFQjU2NkMzQ0VBQTIwMkQ0RkYyOTEwMkM4Rjk=" Apr 01 12:37:22 volumio go-librespot[8896]: time="2024-04-01T12:37:22+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 01 12:37:23 volumio volumio[8739]: info: go-librespot daemon successfully initialized Apr 01 12:37:26 volumio volumio[8739]: info: Initializing connection to go-librespot Websocket Apr 01 12:37:26 volumio sudo[8928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 01 12:37:26 volumio sudo[8928]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:26 volumio sudo[8928]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:26 volumio sudo[8931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 01 12:37:26 volumio sudo[8931]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:26 volumio sudo[8931]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:27 volumio go-librespot[8896]: time="2024-04-01T12:37:27+02:00" level=debug msg="new websocket client" Apr 01 12:37:27 volumio volumio[8739]: info: Connection to go-librespot Websocket established Apr 01 12:37:28 volumio sudo[8934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 01 12:37:28 volumio sudo[8934]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 01 12:37:28 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 01 12:37:28 volumio sudo[8934]: pam_unix(sudo:session): session closed for user root Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=debug msg="handling transfer player command from 33ab87867000ddc53e47de29f2bc6e95ea1c4ed8" Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=debug msg="loading track spotify:track:4ABXkvilk9vyS5FXkunxF4 (paused: false, position: 68061ms)" Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=trace msg="emitting websocket event: will_play" Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4ABXkvilk9vyS5FXkunxF4" Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=debug msg="requested aes key for file be897efe90a5d1c1ea2aaa29a4d4017f1e072c33, track: spotify:track:4ABXkvilk9vyS5FXkunxF4" Apr 01 12:37:28 volumio go-librespot[8896]: time="2024-04-01T12:37:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2332" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2325" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched first chunk of 16, total size is 8101996 bytes" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched chunk 2/15, size: 524288" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched chunk 1/15, size: 524288" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched chunk 5/15, size: 524288" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=trace msg="seek to 68061ms (diff: 159ms, samples: 3001490, bytes: 2849209)" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched chunk 7/15, size: 524288" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched chunk 8/15, size: 524288" Apr 01 12:37:29 volumio kernel: pcm512x 1-004c: No SCLK, using BCLK: -2 Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=info msg="loaded track \"Cuban Cigar\" (uri: spotify:track:4ABXkvilk9vyS5FXkunxF4, paused: false, position: 68061ms, duration: 192626ms)" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="fetched chunk 6/15, size: 524288" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=trace msg="emitting websocket event: metadata" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=trace msg="emitting websocket event: active" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="sending successful reply for delaer request" Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 01 12:37:29 volumio go-librespot[8896]: time="2024-04-01T12:37:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 01 12:37:30 volumio go-librespot[8896]: time="2024-04-01T12:37:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 01 12:37:30 volumio go-librespot[8896]: time="2024-04-01T12:37:30+02:00" level=trace msg="emitting websocket event: playing" Apr 01 12:37:30 volumio go-librespot[8896]: time="2024-04-01T12:37:30+02:00" level=debug msg="fetched chunk 3/15, size: 524288" Apr 01 12:37:30 volumio volumio[8739]: info: Upmpdcli Daemon Started Apr 01 12:37:31 volumio volumio[8739]: info: Getting Spotify volume Apr 01 12:37:31 volumio volumio[8739]: Cannot compose Albumart path Apr 01 12:37:32 volumio volumio[8739]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","play_origin":"playlist"}} Apr 01 12:37:32 volumio volumio[8739]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","name":"Cuban Cigar","artist_names":["Peter Godfrey"],"album_name":"Peter Godfrey, Vol. 7","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0252fd3ed8a796362bee08d319","position":68061,"duration":192626}} Apr 01 12:37:32 volumio volumio[8739]: SPOTIFY: received: {"type":"active","data":null} Apr 01 12:37:32 volumio volumio[8739]: info: Aligning Spotify Volume to Volumio Volume Apr 01 12:37:32 volumio volumio[8739]: info: CoreCommandRouter::volumioGetState Apr 01 12:37:32 volumio volumio[8739]: info: CorePlayQueue::getTrack 0 Apr 01 12:37:32 volumio volumio[8739]: info: Setting Spotify Volume from Volumio: 100 Apr 01 12:37:32 volumio volumio[8739]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 01 12:37:32 volumio volumio[8739]: info: Sending Spotify command with payload to local API: /player/volume Apr 01 12:37:32 volumio volumio[8739]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4ABXkvilk9vyS5FXkunxF4","play_origin":"playlist"}} Apr 01 12:37:32 volumio volumio[8739]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 01 12:37:32 volumio volumio[8739]: TypeError: Cannot read property 'service' of undefined Apr 01 12:37:32 volumio volumio[8739]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:306:50) Apr 01 12:37:32 volumio volumio[8739]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:249:18) Apr 01 12:37:32 volumio volumio[8739]: at WebSocket.message (/data/plugins/music_service/spop/index.js:179:14) Apr 01 12:37:32 volumio volumio[8739]: at WebSocket.emit (events.js:315:20) Apr 01 12:37:32 volumio volumio[8739]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1192:20) Apr 01 12:37:32 volumio volumio[8739]: at Receiver.emit (events.js:315:20) Apr 01 12:37:32 volumio volumio[8739]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:560:14) Apr 01 12:37:32 volumio volumio[8739]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:478:17) Apr 01 12:37:32 volumio volumio[8739]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:22) Apr 01 12:37:32 volumio volumio[8739]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:180:18 Apr 01 12:37:32 volumio volumio[8739]: at internal/process/task_queues.js:149:7 Apr 01 12:37:32 volumio volumio[8739]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Apr 01 12:37:32 volumio volumio[8739]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Apr 01 12:37:32 volumio volumio[8739]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Apr 01 12:37:32 volumio volumio[8739]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 01 12:37:32 volumio sudo[8947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-01 12:36 Apr 01 12:37:32 volumio sudo[8947]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"