-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sun 2025-01-12 15:11:33 CET. -- Jan 12 15:11:04 maison systemd-timedated[935]: Changed local time to Sun Jan 12 15:11:04 2025 Jan 12 15:11:04 maison sudo[930]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:04 maison volumio-time-update[578]: volumio-time-update-util: System time updated successfully. Jan 12 15:11:04 maison systemd[1]: Starting Daily apt download activities... Jan 12 15:11:04 maison systemd[1]: Started Volumio Time Update Utility. Jan 12 15:11:04 maison systemd[1]: Reached target Multi-User System. Jan 12 15:11:04 maison systemd[1]: Reached target Graphical Interface. Jan 12 15:11:04 maison systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 12 15:11:04 maison systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 12 15:11:04 maison systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 12 15:11:05 maison volumio-remote-updater[553]: [2025-01-12 15:11:05] [info] asio async_connect error: system:111 (Connection refused) Jan 12 15:11:05 maison volumio-remote-updater[553]: [2025-01-12 15:11:05] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 12 15:11:05 maison volumio-remote-updater[553]: [2025-01-12 15:11:05] [error] handle_connect error: Underlying Transport Error Jan 12 15:11:05 maison systemd[1]: apt-daily.service: Succeeded. Jan 12 15:11:05 maison systemd[1]: Started Daily apt download activities. Jan 12 15:11:05 maison systemd[1]: Starting Daily apt upgrade and clean activities... Jan 12 15:11:07 maison systemd[1]: apt-daily-upgrade.service: Succeeded. Jan 12 15:11:07 maison systemd[1]: Started Daily apt upgrade and clean activities. Jan 12 15:11:07 maison systemd[1]: Startup finished in 14.807s (kernel) + 24.327s (userspace) = 39.134s. Jan 12 15:11:08 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:08 maison volumio[899]: info: ----- Volumio3 ---- Jan 12 15:11:08 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:08 maison volumio[899]: info: ----- System startup ---- Jan 12 15:11:08 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:10 maison volumio[899]: info: MYVOLUMIO Environment detected Jan 12 15:11:10 maison volumio[899]: info: Plugin folders cleanup Jan 12 15:11:10 maison volumio[899]: info: Scanning into folder /volumio/app/plugins/ Jan 12 15:11:10 maison volumio[899]: info: Scanning category audio_interface Jan 12 15:11:10 maison volumio[899]: info: Scanning category miscellanea Jan 12 15:11:10 maison volumio[899]: info: Scanning category music_service Jan 12 15:11:10 maison volumio[899]: info: Scanning category plugins.json Jan 12 15:11:10 maison volumio[899]: info: Scanning category system_controller Jan 12 15:11:10 maison volumio[899]: info: Scanning category user_interface Jan 12 15:11:10 maison volumio[899]: info: Scanning into folder /data/plugins/ Jan 12 15:11:10 maison volumio[899]: info: Scanning category music_service Jan 12 15:11:10 maison volumio[899]: info: Plugin folders cleanup completed Jan 12 15:11:10 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:10 maison volumio[899]: info: ----- Core plugins startup ---- Jan 12 15:11:10 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:10 maison volumio[899]: info: Loading plugins from folder /volumio/app/plugins/ Jan 12 15:11:10 maison volumio[899]: info: Adding plugin upnp to MyMusic Plugins Jan 12 15:11:10 maison volumio[899]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 12 15:11:10 maison volumio[899]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 12 15:11:10 maison volumio[899]: info: Loading plugins from folder /data/plugins/ Jan 12 15:11:10 maison volumio[899]: info: Loading plugin "system"... Jan 12 15:11:10 maison volumio[899]: info: Loading plugin "appearance"... Jan 12 15:11:13 maison volumio[899]: info: Loading plugin "network"... Jan 12 15:11:13 maison volumio[899]: info: Refreshing Cached IP Addresses Jan 12 15:11:13 maison sudo[1053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 15:11:13 maison sudo[1053]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:13 maison sudo[1053]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:13 maison sudo[1055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 15:11:13 maison sudo[1055]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:13 maison sudo[1055]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:13 maison volumio[899]: info: Loading plugin "services"... Jan 12 15:11:13 maison volumio[899]: info: Loading plugin "alsa_controller"... Jan 12 15:11:13 maison sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 12 15:11:13 maison sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:13 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 15:11:14 maison volumio[899]: info: Loading plugin "wizard"... Jan 12 15:11:14 maison volumio[899]: info: Loading plugin "networkfs"... Jan 12 15:11:14 maison volumio[899]: info: Starting Udev Watcher for removable devices Jan 12 15:11:14 maison sudo[1079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.254/Films 2/Musiques /mnt/NAS/Films_2 Jan 12 15:11:14 maison sudo[1079]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:14 maison volumio[899]: info: Ignoring mount for partition: boot Jan 12 15:11:14 maison volumio[899]: info: Ignoring mount for partition: volumio Jan 12 15:11:14 maison volumio[899]: info: Ignoring mount for partition: volumio_data Jan 12 15:11:14 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 15:11:14 maison volumio[899]: info: Loading plugin "volumio_command_line_client"... Jan 12 15:11:14 maison volumio[899]: info: Loading plugin "upnp"... Jan 12 15:11:14 maison volumio[899]: info: [1736691074280] Starting Upmpd Daemon Jan 12 15:11:14 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 15:11:14 maison volumio[899]: info: Loading plugin "my_music"... Jan 12 15:11:14 maison volumio[899]: info: Loading plugin "mpd"... Jan 12 15:11:14 maison kernel: Key type cifs.spnego registered Jan 12 15:11:14 maison kernel: Key type cifs.idmap registered Jan 12 15:11:14 maison kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jan 12 15:11:14 maison kernel: CIFS: Attempting to mount //192.168.1.254/Films 2/Musiques Jan 12 15:11:14 maison kernel: cryptd: max_cpu_qlen set to 1000 Jan 12 15:11:15 maison sudo[1079]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:15 maison volumio-remote-updater[553]: [2025-01-12 15:11:15] [connect] Successful connection Jan 12 15:11:15 maison volumio[899]: info: Loading plugin "upnp_browser"... Jan 12 15:11:16 maison volumio[899]: info: Loading plugin "alarm-clock"... Jan 12 15:11:16 maison volumio[899]: info: Plugin airplay_emulation is not enabled Jan 12 15:11:16 maison volumio[899]: info: Loading plugin "last_100"... Jan 12 15:11:16 maison volumio[899]: info: Loading plugin "webradio"... Jan 12 15:11:16 maison volumio[899]: info: Loading plugin "i2s_dacs"... Jan 12 15:11:17 maison volumio[899]: info: Loading plugin "volumiodiscovery"... Jan 12 15:11:17 maison volumio[899]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 15:11:17 maison volumio[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 15:11:17 maison volumio[899]: *** WARNING *** For more information see Jan 12 15:11:17 maison volumio[899]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 15:11:17 maison node[899]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 15:11:17 maison volumio[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 15:11:17 maison volumio[899]: *** WARNING *** For more information see Jan 12 15:11:17 maison node[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 15:11:17 maison node[899]: *** WARNING *** For more information see Jan 12 15:11:17 maison node[899]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 15:11:17 maison node[899]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 15:11:17 maison node[899]: *** WARNING *** For more information see Jan 12 15:11:17 maison volumio[899]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 12 15:11:17 maison volumio[899]: info: Discovery: Started advertising with name: Maison Jan 12 15:11:17 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 15:11:17 maison volumio[899]: info: Loading plugin "spop"... Jan 12 15:11:17 maison sudo[1064]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:18 maison systemd[1]: systemd-fsckd.service: Succeeded. Jan 12 15:11:20 maison volumio[899]: info: Loading plugin "outputs"... Jan 12 15:11:20 maison volumio[899]: info: Loading plugin "albumart"... Jan 12 15:11:20 maison volumio[899]: info: Plugin example_plugin is not enabled Jan 12 15:11:20 maison volumio[899]: info: Loading plugin "inputs"... Jan 12 15:11:20 maison volumio[899]: info: Loading plugin "updater_comm"... Jan 12 15:11:20 maison volumio[899]: info: Plugin mpdemulation is not enabled Jan 12 15:11:20 maison volumio[899]: info: Loading plugin "rest_api"... Jan 12 15:11:20 maison volumio[899]: info: Loading plugin "websocket"... Jan 12 15:11:20 maison volumio[899]: info: Starting Socket.io Server version 2.3.0 Jan 12 15:11:20 maison volumio[899]: info: Loading i18n strings for locale fr Jan 12 15:11:20 maison volumio[899]: Updating browse sources language Jan 12 15:11:20 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 15:11:20 maison volumio[899]: Forking 3 albumart workers Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::initPlayerControls Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:11:21 maison volumio[899]: Express server listening on port 3000 Jan 12 15:11:21 maison volumio[899]: [Metrics] WebUI: 14s 779.32ms Jan 12 15:11:21 maison volumio[899]: info: CoreStateMachine::resetVolumioState Jan 12 15:11:21 maison volumio[899]: info: CoreStateMachine::getcurrentVolume Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 15:11:21 maison volumio[899]: info: CoreStateMachine::pushState Jan 12 15:11:21 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 15:11:21 maison volumio[899]: info: CoreCommandRouter::volumioPushState Jan 12 15:11:21 maison volumio[899]: info: Volumio Network Manager: Network status updated: 1 Jan 12 15:11:21 maison volumio[899]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.8 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 12 15:11:22 maison volumio[899]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.8 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 12 15:11:22 maison volumio[899]: info: Discovery: Getting this device information Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:22 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 12 15:11:22 maison volumio[899]: info: Reloading queue from file Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:11:22 maison volumio[899]: info: CoreStateMachine::setRepeat null single undefined Jan 12 15:11:22 maison volumio[899]: info: CoreStateMachine::pushState Jan 12 15:11:22 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioPushState Jan 12 15:11:22 maison volumio[899]: info: CoreStateMachine::setRandom null Jan 12 15:11:22 maison volumio[899]: info: CoreStateMachine::pushState Jan 12 15:11:22 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioPushState Jan 12 15:11:22 maison volumio[899]: info: Setting Device type: Raspberry PI Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jan 12 15:11:22 maison volumio[899]: verbose: New Socket.io Connection to 192.168.1.4:3000 from 192.168.1.45 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 Jan 12 15:11:22 maison volumio[899]: info: Completed loading Core Plugins Jan 12 15:11:22 maison volumio[899]: info: Preparing to generate the ALSA configuration file Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:22 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:22 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:22 maison volumio[899]: info: Discovery: adding 8357a9cf-9099-432e-aefd-89b963598198 Jan 12 15:11:22 maison volumio[899]: info: Discovery: Found device Maison Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:22 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:22 maison volumio[899]: info: Asound.conf file unchanged, so no further update is needed Jan 12 15:11:22 maison volumio[899]: info: Output device has changed, restarting MPD Jan 12 15:11:22 maison volumio[899]: info: ___________ START PLUGINS ___________ Jan 12 15:11:22 maison sudo[1158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 15:11:22 maison sudo[1158]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:22 maison volumio[899]: info: ControllerMpd::onStart: Initializing MPD Jan 12 15:11:22 maison volumio[899]: info: Creating MPD Configuration file Jan 12 15:11:22 maison sudo[1158]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:22 maison sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 15:11:22 maison sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:22 maison sudo[1164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 15:11:22 maison sudo[1164]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:22 maison sudo[1164]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 15:11:22 maison systemd[1]: Stopping Music Player Daemon... Jan 12 15:11:22 maison sudo[1167]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 15:11:22 maison sudo[1167]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:22 maison volumio[899]: info: [1736691082826] CoreMusicLibrary::Adding element Serveurs Média Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 15:11:22 maison volumio[899]: info: [1736691082892] CoreMusicLibrary::Adding element Last_100 Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 15:11:22 maison volumio[899]: info: [1736691082900] CoreMusicLibrary::Adding element Webradio Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 15:11:22 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 15:11:22 maison volumio[899]: Starting albumart workers Jan 12 15:11:22 maison volumio[899]: info: Initializing BBC Radios Jan 12 15:11:23 maison volumio[899]: Starting albumart workers Jan 12 15:11:23 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 15:11:23 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:11:23 maison volumio[899]: Starting albumart workers Jan 12 15:11:23 maison volumio[899]: info: Creating Spotify config file Jan 12 15:11:23 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:23 maison volumio[899]: info: Volumio Calling Home Jan 12 15:11:23 maison systemd[1]: mpd.service: Succeeded. Jan 12 15:11:23 maison systemd[1]: Stopped Music Player Daemon. Jan 12 15:11:23 maison systemd[1]: Starting Music Player Daemon... Jan 12 15:11:23 maison sudo[1180]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 15:11:23 maison sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:23 maison sudo[1180]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:24 maison volumio[899]: info: Discovery: this is already registered, 8357a9cf-9099-432e-aefd-89b963598198 Jan 12 15:11:24 maison volumio[899]: info: Discovery: Found device Maison Jan 12 15:11:24 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:24 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:24 maison volumio[899]: info: Discovery: adding 6bc4b200-9cd5-4c7f-b977-0311c15aac4b Jan 12 15:11:24 maison volumio[899]: info: Discovery: Found device Volumio HD Jan 12 15:11:24 maison volumio[899]: info: Discovery: Connecting to remote: 192.168.1.8 Jan 12 15:11:24 maison volumio[899]: info: MPD Permissions set Jan 12 15:11:24 maison volumio[899]: info: MPD Permissions set Jan 12 15:11:24 maison sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 15:11:24 maison sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:24 maison volumio[899]: info: Volumio called home Jan 12 15:11:24 maison sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 15:11:24 maison sudo[1203]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:24 maison sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:24 maison volumio[899]: info: Spotify config file written Jan 12 15:11:24 maison sudo[1205]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:24 maison sudo[1209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 12 15:11:24 maison sudo[1209]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:24 maison systemd[1]: Started go-librespot Daemon. Jan 12 15:11:24 maison go-librespot[1215]: Librespot-go daemon starting... Jan 12 15:11:24 maison sudo[1209]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:25 maison volumio[899]: info: Discovery: Connected to remote: 192.168.1.8 Jan 12 15:11:25 maison systemd[1]: systemd-hostnamed.service: Succeeded. Jan 12 15:11:25 maison volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:11:25 maison volumio[899]: info: No need to fix Spotify hosts Jan 12 15:11:25 maison go-librespot[1215]: time="2025-01-12T15:11:25+01:00" level=info msg="generated new device id: ceb10ea2b930851df37ebc67a6d6d0b290392ac2" Jan 12 15:11:25 maison systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 12 15:11:25 maison systemd[1]: mpd.service: Failed with result 'protocol'. Jan 12 15:11:25 maison systemd[1]: Failed to start Music Player Daemon. Jan 12 15:11:25 maison sudo[1160]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:25 maison sudo[1167]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:25 maison systemd[1]: Starting Music Player Daemon... Jan 12 15:11:25 maison volumio[899]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Jan 12 15:11:25 maison volumio[899]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Jan 12 15:11:25 maison volumio[899]: See "systemctl status mpd.service" and "journalctl -xe" for details. Jan 12 15:11:25 maison volumio[899]: info: Completed starting Core Plugins Jan 12 15:11:25 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:25 maison volumio[899]: info: ----- MyVolumio plugins startup ---- Jan 12 15:11:25 maison volumio[899]: info: ------------------------------------------- Jan 12 15:11:25 maison volumio[899]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 12 15:11:25 maison volumio[899]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Jan 12 15:11:25 maison volumio[899]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Jan 12 15:11:25 maison volumio[899]: See "systemctl status mpd.service" and "journalctl -xe" for details. Jan 12 15:11:26 maison sudo[1256]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 15:11:26 maison sudo[1256]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:26 maison sudo[1256]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:26 maison go-librespot[1215]: time="2025-01-12T15:11:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 12 15:11:26 maison go-librespot[1215]: time="2025-01-12T15:11:26+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 12 15:11:26 maison go-librespot[1215]: time="2025-01-12T15:11:26+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 12 15:11:26 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:26 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:26 maison go-librespot[1215]: time="2025-01-12T15:11:26+01:00" level=debug msg="zeroconf server listening on port 46475" Jan 12 15:11:26 maison sudo[1262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 12 15:11:26 maison sudo[1262]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:26 maison systemd[1]: Started UPnP Renderer front-end to MPD. Jan 12 15:11:26 maison sudo[1262]: pam_unix(sudo:session): session closed for user root Jan 12 15:11:26 maison volumio[899]: info: Upmpdcli Daemon Started Jan 12 15:11:28 maison volumio[899]: info: go-librespot daemon successfully initialized Jan 12 15:11:28 maison mpd[1260]: Jan 12 15:11 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 15:11:30 maison volumio-remote-updater[553]: [2025-01-12 15:11:30] [connect] Successful connection Jan 12 15:11:30 maison volumio-remote-updater[553]: [2025-01-12 15:11:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736691090 101 Jan 12 15:11:30 maison volumio[899]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 5 Jan 12 15:11:30 maison go-librespot[1215]: time="2025-01-12T15:11:30+01:00" level=debug msg="obtained new client token: AACn24sdogqRhslEz3C+OI8DQZOE2DMFHZuSYYux5VIPdpsWn4XlDtkhkKIXyiTsv3Wg72QrGtd+pwyRUXmYKsKYuEI1R/vsneVDao3LgP0XywkGfqB11XJ9dg5VFJqzPx28zneGfIunRcwp0GuSDxFpqKl/Q6KqX42wuqBWhuUMxJ5cTzxz7HdWEJhEP7+WFTXh3QDf21ubS38F1l512W+hU13r7bKhpjcGPUKavLPkx3bLEqtzax8NwAJs" Jan 12 15:11:30 maison go-librespot[1215]: time="2025-01-12T15:11:30+01:00" level=info msg="connected to ap-gew1.spotify.com:4070" Jan 12 15:11:30 maison go-librespot[1215]: time="2025-01-12T15:11:30+01:00" level=debug msg="completed keyexchange" Jan 12 15:11:31 maison systemd[1]: Started Music Player Daemon. Jan 12 15:11:31 maison volumio[899]: Upnp client error: Error: This socket has been ended by the other party Jan 12 15:11:31 maison mpd_monitor.sh[596]: MPD restarted due to no mpc output. Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="completed challenge" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="authenticated as dgbertin41" Jan 12 15:11:31 maison volumio[899]: error: MPD error: The expression evaluated to a falsy value: Jan 12 15:11:31 maison volumio[899]: assert.ok(self.idling) Jan 12 15:11:31 maison volumio[899]: error: The expression evaluated to a falsy value: Jan 12 15:11:31 maison volumio[899]: assert.ok(self.idling) Jan 12 15:11:31 maison volumio[899]: error: updateQueue error: null Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="authenticated as dgbertin41" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="dealer connection opened" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=info msg="accepted zeroconf user dgbertin41 from Xperia 1 IV" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="received connection id: ZDkyOWQwNTItOTJlNC00OWUyLWJiNzMtZDQ0MDBlYjZiMmI0K2RlYWxlcit0Y3A6Ly8wYWNhNDEzYy5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArOTY0NzFFODBEMDI4MzNCMTdCRUJBNEZGREI4RDk3MzEyOTkxREZDNERGMDJGRDk1QUQ5M0U3RkMyQ0VEODdGNw==" Jan 12 15:11:31 maison volumio[1264]: Generating RSA private key, 4096 bit long modulus (2 primes) Jan 12 15:11:31 maison volumio[899]: info: Initializing connection to go-librespot Websocket Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="new websocket client" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="autoplay enabled: false" Jan 12 15:11:31 maison volumio[899]: info: Connection to go-librespot Websocket established Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="handling transfer player command from 8c1e35f7c78d7cbbf3db8b81e94a6c1cd68de21c" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:3AqtHNTvEasvldDtKcq58o" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=trace msg="fetched new page 0 with 16 items (list: 16)" uri="spotify:playlist:3AqtHNTvEasvldDtKcq58o" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="loading track (paused: false, position: 483395ms)" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=trace msg="emitting websocket event: will_play" Jan 12 15:11:31 maison volumio[899]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0KzAbK6nItSqNh8q70tb0K","play_origin":"playlist"}} Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1114" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="selected format OGG_VORBIS_320 (fa797dc0d53365b211fb4ee86c28572d2f8f4ef4)" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:31 maison go-librespot[1215]: time="2025-01-12T15:11:31+01:00" level=debug msg="requested aes key for file fa797dc0d53365b211fb4ee86c28572d2f8f4ef4, gid: 0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="fetched first chunk of 20, total size is 10176596 bytes" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="fetched chunk 19/19, size: 215124" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="seek to 229226ms (diff: 181ms, samples: 10108866, bytes: 10165236)" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+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" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="created new output device" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=info msg="loaded track \"Where Is My Mind?\" (paused: false, position: 483395ms, duration: 229226ms, prefetched: false)" uri="spotify:track:0KzAbK6nItSqNh8q70tb0K" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="cleared closed output device" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="scheduling prefetch in 199s" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="emitting websocket event: metadata" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="emitting websocket event: active" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="sending successful reply for dealer request" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 12 15:11:32 maison volumio[899]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0KzAbK6nItSqNh8q70tb0K","name":"Where Is My Mind?","artist_names":["Pixies"],"album_name":"Death to the Pixies","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b17d34882944eaf0695153f2","position":483395,"duration":229226,"release_date":"year:1997 month:10 day:6","track_number":14,"disc_number":1}} Jan 12 15:11:32 maison volumio[899]: SPOTIFY: received: {"type":"active","data":null} Jan 12 15:11:32 maison volumio[899]: info: Aligning Spotify Volume to Volumio Volume Jan 12 15:11:32 maison volumio[899]: info: CoreCommandRouter::volumioGetState Jan 12 15:11:32 maison volumio[899]: info: CorePlayQueue::getTrack 0 Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="emitting websocket event: playing" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="emitting websocket event: not_playing" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:32 maison volumio[899]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0KzAbK6nItSqNh8q70tb0K","play_origin":"playlist"}} Jan 12 15:11:32 maison volumio[899]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 15:11:32 maison volumio[899]: TypeError: Cannot read property 'service' of undefined Jan 12 15:11:32 maison volumio[899]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Jan 12 15:11:32 maison volumio[899]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Jan 12 15:11:32 maison volumio[899]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Jan 12 15:11:32 maison volumio[899]: at WebSocket.emit (events.js:315:20) Jan 12 15:11:32 maison volumio[899]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jan 12 15:11:32 maison volumio[899]: at Receiver.emit (events.js:315:20) Jan 12 15:11:32 maison volumio[899]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jan 12 15:11:32 maison volumio[899]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jan 12 15:11:32 maison volumio[899]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jan 12 15:11:32 maison volumio[899]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jan 12 15:11:32 maison volumio[899]: at writeOrBuffer (internal/streams/writable.js:358:12) Jan 12 15:11:32 maison volumio[899]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jan 12 15:11:32 maison volumio[899]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jan 12 15:11:32 maison volumio[899]: at Socket.emit (events.js:315:20) Jan 12 15:11:32 maison volumio[899]: at addChunk (internal/streams/readable.js:309:12) Jan 12 15:11:32 maison volumio[899]: at readableAddChunk (internal/streams/readable.js:284:9) Jan 12 15:11:32 maison volumio[899]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="emitting websocket event: will_play" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="selected format OGG_VORBIS_320 (4a4264aa7939714d71f438170f4f019a4cb50e4d)" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="requested aes key for file 4a4264aa7939714d71f438170f4f019a4cb50e4d, gid: 2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="fetched first chunk of 10, total size is 5162120 bytes" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+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" Jan 12 15:11:32 maison go-librespot[1215]: time="2025-01-12T15:11:32+01:00" level=debug msg="created new output device" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="cleared closed output device" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=info msg="loaded track \"Be My Baby\" (paused: false, position: 0ms, duration: 160906ms, prefetched: false)" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched chunk 1/9, size: 524288" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched chunk 2/9, size: 524288" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="scheduling prefetch in 131s" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: metadata" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: stopped" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched chunk 3/9, size: 524288" uri="spotify:track:2G2YzndIA6jeWFPBXhUjh5" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: playing" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: stopped" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: not_playing" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: will_play" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="selected format OGG_VORBIS_320 (51b1e507cbd5ca16f27b597e6c1f36c8f9b2d557)" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="requested aes key for file 51b1e507cbd5ca16f27b597e6c1f36c8f9b2d557, gid: 6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched first chunk of 17, total size is 8856776 bytes" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+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" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="created new output device" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=info msg="loaded track \"Footloose\" (paused: false, position: 0ms, duration: 220706ms, prefetched: false)" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="scheduling prefetch in 191s" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: metadata" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=trace msg="emitting websocket event: playing" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison go-librespot[1215]: time="2025-01-12T15:11:33+01:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:6W2VbtvMrDXm5vYeB7amkO" Jan 12 15:11:33 maison sudo[1294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-12 15:10 Jan 12 15:11:33 maison sudo[1294]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 12 15:11:34 maison systemd[1]: systemd-timedated.service: Succeeded. 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"