-- Logs begin at Thu 2019-02-14 10:11:58 UTC, end at Wed 2024-08-28 07:38:34 UTC. -- Aug 28 07:38:26 frankenslag1 systemd[1]: Starting Daily apt download activities... Aug 28 07:38:26 frankenslag1 systemd[1]: Starting Daily man-db regeneration... Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Completed starting Core Plugins Aug 28 07:38:26 frankenslag1 volumio[1067]: info: ------------------------------------------- Aug 28 07:38:26 frankenslag1 volumio[1067]: info: ----- MyVolumio plugins startup ---- Aug 28 07:38:26 frankenslag1 volumio[1067]: info: ------------------------------------------- Aug 28 07:38:26 frankenslag1 volumio[1067]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Discovery: adding 1a7809a1-8024-4fd5-b5d0-c9b19386e838 Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Discovery: Found device frankenslag1 Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CoreCommandRouter::volumioGetState Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CorePlayQueue::getTrack 0 Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Volumio called home Aug 28 07:38:26 frankenslag1 volumio[1067]: info: MPD Permissions set Aug 28 07:38:26 frankenslag1 volumio-remote-updater[460]: [2024-08-28 07:38:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1673864477 101 Aug 28 07:38:26 frankenslag1 volumio[1067]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2 Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Spotify config file written Aug 28 07:38:26 frankenslag1 systemd[1]: man-db.service: Succeeded. Aug 28 07:38:26 frankenslag1 systemd[1]: Started Daily man-db regeneration. Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Discovery: A device disappeared from network Aug 28 07:38:26 frankenslag1 volumio[1067]: info: Discovery: Device frankenslag1 disappeared from network Aug 28 07:38:26 frankenslag1 volumio[1067]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 07:38:26 frankenslag1 sudo[1320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 28 07:38:26 frankenslag1 sudo[1320]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 28 07:38:26 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 28 07:38:26 frankenslag1 systemd[1]: Started go-librespot Daemon. Aug 28 07:38:26 frankenslag1 sudo[1320]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:26 frankenslag1 go-librespot[1336]: Librespot-go daemon starting... Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Starting Shairport Sync Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Starting Shairport Sync Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Starting Shairport Sync Aug 28 07:38:27 frankenslag1 sudo[1357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 28 07:38:27 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:27Z" level=info msg="generated new device id: 9928f97821d3eb10e2990d748d11149f528f4b58" Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Discovery: adding 1a7809a1-8024-4fd5-b5d0-c9b19386e838 Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Discovery: Found device frankenslag1 Aug 28 07:38:27 frankenslag1 volumio[1067]: info: CoreCommandRouter::volumioGetState Aug 28 07:38:27 frankenslag1 volumio[1067]: info: CorePlayQueue::getTrack 0 Aug 28 07:38:27 frankenslag1 sudo[1367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 28 07:38:27 frankenslag1 sudo[1361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 28 07:38:27 frankenslag1 sudo[1367]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:27 frankenslag1 sudo[1357]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:27 frankenslag1 sudo[1361]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:27 frankenslag1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 28 07:38:27 frankenslag1 systemd[1]: shairport-sync.service: Succeeded. Aug 28 07:38:27 frankenslag1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 28 07:38:27 frankenslag1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 28 07:38:27 frankenslag1 sudo[1367]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:27 frankenslag1 sudo[1361]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:27 frankenslag1 sudo[1357]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:27 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 28 07:38:27 frankenslag1 volumio[1067]: (node:1067) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Aug 28 07:38:27 frankenslag1 volumio[1067]: (Use `node --trace-deprecation ...` to show where the warning was created) Aug 28 07:38:27 frankenslag1 volumio[1067]: (node:1067) [DEP0106] DeprecationWarning: crypto.createDecipher is deprecated. Aug 28 07:38:27 frankenslag1 volumio[1067]: info: CoreCommandRouter::volumioGetState Aug 28 07:38:27 frankenslag1 volumio[1067]: info: CorePlayQueue::getTrack 0 Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Shairport-Sync Started Aug 28 07:38:27 frankenslag1 volumio[1067]: Error adding Membership: Error: addMembership EINVAL Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Shairport-Sync Started Aug 28 07:38:27 frankenslag1 volumio[1067]: info: Shairport-Sync Started Aug 28 07:38:27 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:27Z" 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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 28 07:38:27 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:27Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 28 07:38:27 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:27Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 28 07:38:27 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:27Z" level=debug msg="zeroconf server listening on port 44950" Aug 28 07:38:27 frankenslag1 mpd[1317]: Aug 28 07:38 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 28 07:38:27 frankenslag1 mpd[1317]: Aug 28 07:38 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Aug 28 07:38:27 frankenslag1 mpd[1317]: Aug 28 07:38 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Aug 28 07:38:27 frankenslag1 systemd[1]: Started Music Player Daemon. Aug 28 07:38:27 frankenslag1 sudo[1284]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:27 frankenslag1 volumio[1067]: error: updateQueue error: null Aug 28 07:38:28 frankenslag1 systemd[1]: apt-daily.service: Succeeded. Aug 28 07:38:28 frankenslag1 systemd[1]: Started Daily apt download activities. Aug 28 07:38:28 frankenslag1 systemd[1]: Starting Daily apt upgrade and clean activities... Aug 28 07:38:28 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 28 07:38:28 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 28 07:38:28 frankenslag1 volumio[1067]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 28 07:38:29 frankenslag1 systemd[1]: apt-daily-upgrade.service: Succeeded. Aug 28 07:38:29 frankenslag1 systemd[1]: Started Daily apt upgrade and clean activities. Aug 28 07:38:30 frankenslag1 volumio[1067]: info: go-librespot daemon successfully initialized Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="obtained new client token: AAAmRBfdVERVTMlEox3WIIexrcKsRyzVSdS7LqaQK3FFuuGcbITql8zLw0hhMzp0qMOr/4dH1L7hlFZ5cYRF9OdmHQwgguAaAzm96VE8kuIblUw0fOLjYF/zq8UNCSa4EdwT/LNgFTAA0aMzm1ac2iOvG01pAbavLPKxtivwRrvBZy09w7GNViHRYSVXXPadWHRXPaMSfbuAzZeiTFkArJRsPyPjMg67KpNmY8ps17PwBbjQmTJaaZs=" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="completed keyexchange" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="completed challenge" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="authenticated as 31xwk6czm6ezuutacns4joxk4jhm" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="authenticated as 31xwk6czm6ezuutacns4joxk4jhm" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="dealer connection opened" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=info msg="accepted zeroconf user 31xwk6czm6ezuutacns4joxk4jhm from S20 FE van jan" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="autoplay enabled: false" Aug 28 07:38:31 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:31Z" level=debug msg="received connection id: YmIwNmI1MWMtOGM4Ny00YTgxLWI0NWEtYjUxMDA0Mzk0NGUxK2RlYWxlcit0Y3A6Ly8wYWNhNTk1NC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQUNGOEI5MDgzODFFMDdBRjIwM0FGRDkzN0JGRUE5MzI5Q0FERDRGOUYxNjNCRDM3MjM0MUZGRkQ0RkI4MjAxNw==" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="put connect state because NEW_DEVICE" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="handling transfer player command from 943c242eafe682b24d53dede5a7ed5ebeb614b34" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="resolved context of track" uri="spotify:album:3XpE3fiM5Gbt14k6o1cVuW" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=trace msg="fetched new page 0 with 10 items (list: 10)" uri="spotify:album:3XpE3fiM5Gbt14k6o1cVuW" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="loading track (paused: false, position: 185209ms)" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=trace msg="emitting websocket event: will_play" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="selected format OGG_VORBIS_320 (0a0cd43e511c68c25b095919000768f33059c172)" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="requested aes key for file 0a0cd43e511c68c25b095919000768f33059c172, gid: 3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1403" Aug 28 07:38:32 frankenslag1 sudo[1482]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 28 07:38:32 frankenslag1 sudo[1481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 28 07:38:32 frankenslag1 sudo[1481]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:32 frankenslag1 sudo[1482]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:32 frankenslag1 sudo[1486]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 28 07:38:32 frankenslag1 sudo[1482]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:32 frankenslag1 sudo[1481]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:32 frankenslag1 sudo[1486]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 28 07:38:32 frankenslag1 systemd[1]: Started UPnP Renderer front-end to MPD. Aug 28 07:38:32 frankenslag1 sudo[1486]: pam_unix(sudo:session): session closed for user root Aug 28 07:38:32 frankenslag1 volumio[1067]: info: Upmpdcli Daemon Started Aug 28 07:38:32 frankenslag1 volumio[1506]: Generating RSA private key, 4096 bit long modulus (2 primes) Aug 28 07:38:32 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:32Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1158" Aug 28 07:38:32 frankenslag1 systemd[1]: systemd-fsckd.service: Succeeded. Aug 28 07:38:33 frankenslag1 volumio[1067]: info: Initializing connection to go-librespot Websocket Aug 28 07:38:33 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:33Z" level=debug msg="new websocket client" Aug 28 07:38:33 frankenslag1 volumio[1067]: info: Connection to go-librespot Websocket established Aug 28 07:38:33 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:33Z" level=debug msg="fetched first chunk of 39, total size is 20371240 bytes" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:33 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:33Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Aug 28 07:38:33 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:33Z" level=debug msg="fetched chunk 1/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:33 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:33Z" level=debug msg="fetched chunk 2/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 sh[406]: timed out Aug 28 07:38:34 frankenslag1 dhcpcd[444]: timed out Aug 28 07:38:34 frankenslag1 sh[406]: dhcpcd exited Aug 28 07:38:34 frankenslag1 dhcpcd[444]: dhcpcd exited Aug 28 07:38:34 frankenslag1 sh[406]: ifup: failed to bring up eth0 Aug 28 07:38:34 frankenslag1 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Aug 28 07:38:34 frankenslag1 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="fetched chunk 3/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 dhcpcd[1539]: sending commands to master dhcpcd process Aug 28 07:38:34 frankenslag1 ifplugd(eth0)[764]: client: sending commands to master dhcpcd process Aug 28 07:38:34 frankenslag1 dhcpcd[564]: control command: /sbin/dhcpcd eth0 Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="fetched chunk 11/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=trace msg="seek to 185209ms (diff: 160ms, samples: 8167716, bytes: 6232385)" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="fetched chunk 12/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 systemd[1]: systemd-hostnamed.service: Succeeded. Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="fetched chunk 13/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 ifplugd(eth0)[764]: Program executed successfully. Aug 28 07:38:34 frankenslag1 ifplugd(eth0)[764]: Link beat lost. Aug 28 07:38:34 frankenslag1 ifplugd[726]: Network Interface Plugging Daemon...start eth0...done. Aug 28 07:38:34 frankenslag1 systemd[1]: Started LSB: Brings up/down network automatically. Aug 28 07:38:34 frankenslag1 systemd[1]: Reached target Multi-User System. Aug 28 07:38:34 frankenslag1 systemd[1]: Reached target Graphical Interface. Aug 28 07:38:34 frankenslag1 startx[1068]: xinit: giving up Aug 28 07:38:34 frankenslag1 startx[1068]: xinit: unable to connect to X server: Connection refused Aug 28 07:38:34 frankenslag1 startx[1068]: xinit: server error Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" 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" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="created new output device" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=info msg="loaded track \"Trio Serenade, Op. 73: Trio Serenade, Op. 73\" (paused: false, position: 185209ms, duration: 596218ms, prefetched: false)" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="fetched chunk 14/38, size: 524288" uri="spotify:track:3o5pWy3K9SD1ooUKUar1wz" Aug 28 07:38:34 frankenslag1 systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 28 07:38:34 frankenslag1 systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Aug 28 07:38:34 frankenslag1 systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Aug 28 07:38:34 frankenslag1 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 28 07:38:34 frankenslag1 systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 28 07:38:34 frankenslag1 systemd[1]: Startup finished in 16.420s (kernel) + 33.625s (userspace) = 50.045s. Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=trace msg="scheduling prefetch in 381s" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=trace msg="emitting websocket event: metadata" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=trace msg="emitting websocket event: active" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="sending successful reply for dealer request" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 28 07:38:34 frankenslag1 volumio[1067]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3o5pWy3K9SD1ooUKUar1wz","name":"Trio Serenade, Op. 73: Trio Serenade, Op. 73","artist_names":["Robert Kahn","Delphine Trio"],"album_name":"Adrift","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d9ed2591453133736c38f9b7","position":185209,"duration":596218,"release_date":"year:2024 month:2 day:2","track_number":2,"disc_number":1}} Aug 28 07:38:34 frankenslag1 volumio[1067]: SPOTIFY: received: {"type":"active","data":null} Aug 28 07:38:34 frankenslag1 volumio[1067]: info: Aligning Spotify Volume to Volumio Volume Aug 28 07:38:34 frankenslag1 volumio[1067]: info: CoreCommandRouter::volumioGetState Aug 28 07:38:34 frankenslag1 volumio[1067]: info: CorePlayQueue::getTrack 0 Aug 28 07:38:34 frankenslag1 volumio[1067]: info: Setting Spotify Volume from Volumio: 89 Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 28 07:38:34 frankenslag1 go-librespot[1336]: time="2024-08-28T07:38:34Z" level=trace msg="emitting websocket event: playing" Aug 28 07:38:34 frankenslag1 volumio[1067]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3o5pWy3K9SD1ooUKUar1wz","play_origin":"playlist"}} Aug 28 07:38:34 frankenslag1 volumio[1067]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 07:38:34 frankenslag1 volumio[1067]: TypeError: Cannot read property 'service' of undefined Aug 28 07:38:34 frankenslag1 volumio[1067]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Aug 28 07:38:34 frankenslag1 volumio[1067]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Aug 28 07:38:34 frankenslag1 volumio[1067]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Aug 28 07:38:34 frankenslag1 volumio[1067]: at WebSocket.emit (events.js:400:28) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver.emit (events.js:400:28) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Aug 28 07:38:34 frankenslag1 volumio[1067]: at writeOrBuffer (internal/streams/writable.js:358:12) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Aug 28 07:38:34 frankenslag1 volumio[1067]: at Socket.emit (events.js:400:28) Aug 28 07:38:34 frankenslag1 volumio[1067]: at addChunk (internal/streams/readable.js:293:12) Aug 28 07:38:34 frankenslag1 volumio[1067]: at readableAddChunk (internal/streams/readable.js:267:9) Aug 28 07:38:34 frankenslag1 volumio[1067]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 07:38:34 frankenslag1 sudo[1594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-28 07:37 Aug 28 07:38:34 frankenslag1 sudo[1594]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="91e88ea6c5c4ec4f00aff63f7c3a2944b14ec939" VOLUMIO_FE_VERSION="c433755e569617abac52264d17ad61be303ef463" VOLUMIO_FE3_VERSION="2419ddd8e895c5bdc456962163c9dc7c0f187aa7" VOLUMIO_BE_VERSION="85acf7bbbceb3e3dec447156a39a88033f921210" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 30 Sep 2022 11:00:38 AM CEST" VOLUMIO_VERSION="3.378" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="fe86b0efdeb8db8d4b4189184b795a4c"