-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Wed 2024-11-27 13:30:05 EST. -- Nov 27 13:29:53 living-room-stereo systemd-timedated[1038]: Changed local time to Wed Nov 27 13:29:53 2024 Nov 27 13:29:53 living-room-stereo sudo[1036]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:53 living-room-stereo volumio-time-update[595]: volumio-time-update-util: System time updated successfully. Nov 27 13:29:53 living-room-stereo systemd[1]: Starting Daily apt download activities... Nov 27 13:29:53 living-room-stereo systemd[1]: Started Volumio Time Update Utility. Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Plugin folders cleanup Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning into folder /volumio/app/plugins/ Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category audio_interface Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category miscellanea Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category music_service Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category plugins.json Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category system_controller Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category user_interface Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning into folder /data/plugins/ Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Scanning category music_service Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Plugin folders cleanup completed Nov 27 13:29:53 living-room-stereo volumio[1003]: info: ------------------------------------------- Nov 27 13:29:53 living-room-stereo volumio[1003]: info: ----- Core plugins startup ---- Nov 27 13:29:53 living-room-stereo volumio[1003]: info: ------------------------------------------- Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Loading plugins from folder /volumio/app/plugins/ Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Adding plugin upnp to MyMusic Plugins Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Loading plugins from folder /data/plugins/ Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Loading plugin "system"... Nov 27 13:29:53 living-room-stereo volumio[1003]: info: Loading plugin "appearance"... Nov 27 13:29:53 living-room-stereo systemd[1]: apt-daily.service: Succeeded. Nov 27 13:29:53 living-room-stereo systemd[1]: Started Daily apt download activities. Nov 27 13:29:53 living-room-stereo systemd[1]: Starting Daily apt upgrade and clean activities... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "network"... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Refreshing Cached IP Addresses Nov 27 13:29:54 living-room-stereo sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 27 13:29:54 living-room-stereo sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:54 living-room-stereo systemd[1]: apt-daily-upgrade.service: Succeeded. Nov 27 13:29:54 living-room-stereo systemd[1]: Started Daily apt upgrade and clean activities. Nov 27 13:29:54 living-room-stereo sudo[1140]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:54 living-room-stereo sudo[1143]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 27 13:29:54 living-room-stereo sudo[1143]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:54 living-room-stereo sudo[1143]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "services"... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "alsa_controller"... Nov 27 13:29:54 living-room-stereo sudo[1152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 27 13:29:54 living-room-stereo sudo[1152]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:54 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "wizard"... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "networkfs"... Nov 27 13:29:54 living-room-stereo systemd[1]: systemd-fsckd.service: Succeeded. Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Starting Udev Watcher for removable devices Nov 27 13:29:54 living-room-stereo nmbd[704]: [2024/11/27 13:29:54.501541, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 27 13:29:54 living-room-stereo systemd[1]: Started Samba NMB Daemon. Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Ignoring mount for partition: boot Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Ignoring mount for partition: volumio Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Ignoring mount for partition: volumio_data Nov 27 13:29:54 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "volumio_command_line_client"... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "upnp"... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: [1732732194542] Starting Upmpd Daemon Nov 27 13:29:54 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "my_music"... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "mpd"... Nov 27 13:29:54 living-room-stereo nmbd[704]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 27 13:29:54 living-room-stereo sudo[1169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=adamdouglasstone@gmail.com,password=Osca1600,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.68.128/Music /mnt/NAS/HTPC Nov 27 13:29:54 living-room-stereo sudo[1169]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:54 living-room-stereo systemd[1]: Starting Samba Winbind Daemon... Nov 27 13:29:54 living-room-stereo kernel: Key type cifs.spnego registered Nov 27 13:29:54 living-room-stereo kernel: Key type cifs.idmap registered Nov 27 13:29:54 living-room-stereo 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. Nov 27 13:29:54 living-room-stereo kernel: CIFS: Attempting to mount //192.168.68.128/Music Nov 27 13:29:54 living-room-stereo winbindd[1171]: [2024/11/27 13:29:54.790941, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 27 13:29:54 living-room-stereo winbindd[1171]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 27 13:29:54 living-room-stereo winbindd[1171]: [2024/11/27 13:29:54.814676, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 27 13:29:54 living-room-stereo winbindd[1171]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 27 13:29:54 living-room-stereo systemd[1]: Started Samba Winbind Daemon. Nov 27 13:29:54 living-room-stereo systemd[1]: Starting Samba SMB Daemon... Nov 27 13:29:54 living-room-stereo volumio[1003]: info: Loading plugin "upnp_browser"... Nov 27 13:29:55 living-room-stereo sudo[1169]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:55 living-room-stereo smbd[1197]: [2024/11/27 13:29:55.228798, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 27 13:29:55 living-room-stereo systemd[1]: Started Samba SMB Daemon. Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "alarm-clock"... Nov 27 13:29:55 living-room-stereo smbd[1197]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 27 13:29:55 living-room-stereo systemd[1]: Reached target Multi-User System. Nov 27 13:29:55 living-room-stereo systemd[1]: Reached target Graphical Interface. Nov 27 13:29:55 living-room-stereo systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 27 13:29:55 living-room-stereo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 27 13:29:55 living-room-stereo systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 27 13:29:55 living-room-stereo systemd[1]: Startup finished in 13.568s (kernel) + 34.923s (userspace) = 48.491s. Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "airplay_emulation"... Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Starting Shairport Sync Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "last_100"... Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "webradio"... Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "i2s_dacs"... Nov 27 13:29:55 living-room-stereo volumio[1003]: info: I2S DAC not set, start Auto-detection Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "volumiodiscovery"... Nov 27 13:29:55 living-room-stereo volumio[1003]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 27 13:29:55 living-room-stereo volumio[1003]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 27 13:29:55 living-room-stereo volumio[1003]: *** WARNING *** For more information see Nov 27 13:29:55 living-room-stereo node[1003]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 27 13:29:55 living-room-stereo volumio[1003]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 27 13:29:55 living-room-stereo volumio[1003]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 27 13:29:55 living-room-stereo volumio[1003]: *** WARNING *** For more information see Nov 27 13:29:55 living-room-stereo node[1003]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 27 13:29:55 living-room-stereo node[1003]: *** WARNING *** For more information see Nov 27 13:29:55 living-room-stereo node[1003]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 27 13:29:55 living-room-stereo node[1003]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 27 13:29:55 living-room-stereo node[1003]: *** WARNING *** For more information see Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Discovery: Started advertising with name: Living Room Stereo Nov 27 13:29:55 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 27 13:29:55 living-room-stereo volumio[1003]: info: Loading plugin "spop"... Nov 27 13:29:56 living-room-stereo wpa_supplicant[864]: RRM: Ignoring radio measurement request: Not RRM network Nov 27 13:29:56 living-room-stereo sh[485]: timed out Nov 27 13:29:56 living-room-stereo dhcpcd[518]: timed out Nov 27 13:29:56 living-room-stereo sh[485]: dhcpcd exited Nov 27 13:29:56 living-room-stereo dhcpcd[518]: dhcpcd exited Nov 27 13:29:56 living-room-stereo sh[485]: ifup: failed to bring up eth0 Nov 27 13:29:56 living-room-stereo systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Nov 27 13:29:56 living-room-stereo systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading plugin "outputs"... Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading plugin "albumart"... Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Plugin example_plugin is not enabled Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading plugin "inputs"... Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading plugin "updater_comm"... Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Plugin mpdemulation is not enabled Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading plugin "rest_api"... Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading plugin "websocket"... Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Starting Socket.io Server version 2.3.0 Nov 27 13:29:56 living-room-stereo volumio[1003]: info: Loading i18n strings for locale en Nov 27 13:29:57 living-room-stereo volumio[1003]: Updating browse sources language Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 13:29:57 living-room-stereo volumio[1003]: Forking 3 albumart workers Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::initPlayerControls Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: Express server listening on port 3000 Nov 27 13:29:57 living-room-stereo volumio[1003]: [Metrics] WebUI: 5s 657.55ms Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::resetVolumioState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::getcurrentVolume Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioRetrievevolume Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Volumio Network Manager: Network status updated: 2 Nov 27 13:29:57 living-room-stereo volumio[1003]: verbose: New Socket.io Connection to 192.168.68.115:3000 from 192.168.68.168 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 27 13:29:57 living-room-stereo volumio[1003]: info: VolumeController:: Volume=100 Mute =false Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::pushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioPushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::updateTrackBlock Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrackBlock Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioRetrievevolume Nov 27 13:29:57 living-room-stereo volumio[1003]: Starting albumart workers Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Reloading queue from file Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Setting Device type: Raspberry PI Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::setRepeat null single undefined Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::pushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioPushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::setRandom null Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::pushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioPushState Nov 27 13:29:57 living-room-stereo volumio[1003]: Starting albumart workers Nov 27 13:29:57 living-room-stereo volumio[1003]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 27 13:29:57 living-room-stereo volumio[1003]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03111 Nov 27 13:29:57 living-room-stereo volumio[1003]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Nov 27 13:29:57 living-room-stereo volumio[1003]: info: VolumeController:: Volume=100 Mute =false Nov 27 13:29:57 living-room-stereo volumio[1003]: Starting albumart workers Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreStateMachine::pushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioPushState Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Completed loading Core Plugins Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Preparing to generate the ALSA configuration file Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Asound.conf file written Nov 27 13:29:57 living-room-stereo sudo[1256]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 27 13:29:57 living-room-stereo sudo[1256]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:57 living-room-stereo sudo[1256]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Output device has changed, restarting MPD Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Output device has changed, restarting Shairport Sync Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:57 living-room-stereo sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 27 13:29:57 living-room-stereo sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:57 living-room-stereo sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 27 13:29:57 living-room-stereo sudo[1261]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:57 living-room-stereo sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 27 13:29:57 living-room-stereo systemd[1]: Stopping Music Player Daemon... Nov 27 13:29:57 living-room-stereo volumio[1003]: info: ___________ START PLUGINS ___________ Nov 27 13:29:57 living-room-stereo volumio[1003]: info: ControllerMpd::onStart: Initializing MPD Nov 27 13:29:57 living-room-stereo volumio[1003]: info: Creating MPD Configuration file Nov 27 13:29:57 living-room-stereo sudo[1278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 27 13:29:57 living-room-stereo sudo[1278]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:57 living-room-stereo sudo[1278]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:57 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 27 13:29:58 living-room-stereo volumio[1003]: info: [1732732198007] CoreMusicLibrary::Adding element Media Servers Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 13:29:58 living-room-stereo sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 27 13:29:58 living-room-stereo sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:58 living-room-stereo systemd[1]: mpd.service: Succeeded. Nov 27 13:29:58 living-room-stereo systemd[1]: Stopped Music Player Daemon. Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:58 living-room-stereo systemd[1]: Starting Music Player Daemon... Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 27 13:29:58 living-room-stereo volumio[1003]: info: [1732732198138] CoreMusicLibrary::Adding element Last_100 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 27 13:29:58 living-room-stereo volumio[1003]: info: [1732732198141] CoreMusicLibrary::Adding element Webradio Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Initializing BBC Radios Nov 27 13:29:58 living-room-stereo sudo[1283]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 27 13:29:58 living-room-stereo sudo[1283]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:58 living-room-stereo sudo[1283]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Creating Spotify config file Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Volumio Calling Home Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Discovery: adding 8eb51673-91a3-45ff-af2c-0ab3293cf2c6 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Discovery: Found device Volumio-Rec-room Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Discovery: Connecting to remote: 192.168.68.168 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Discovery: adding a0dcfffb-3a3a-4887-9ba3-2321b54dad32 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Discovery: Found device Living Room Stereo Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioGetState Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioGetState Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: MPD Permissions set Nov 27 13:29:58 living-room-stereo volumio[1003]: info: MPD Permissions set Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Spotify config file written Nov 27 13:29:58 living-room-stereo volumio[1003]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo sudo[1152]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo sudo[1322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 27 13:29:58 living-room-stereo sudo[1322]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Discovery: Connected to remote: 192.168.68.168 Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Starting Shairport Sync Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Starting Shairport Sync Nov 27 13:29:58 living-room-stereo systemd[1]: Started go-librespot Daemon. Nov 27 13:29:58 living-room-stereo go-librespot[1328]: Librespot-go daemon starting... Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Starting Shairport Sync Nov 27 13:29:58 living-room-stereo sudo[1322]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:58 living-room-stereo sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 27 13:29:58 living-room-stereo sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:58 living-room-stereo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 27 13:29:58 living-room-stereo sudo[1340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 27 13:29:58 living-room-stereo sudo[1337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 27 13:29:58 living-room-stereo sudo[1340]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:58 living-room-stereo systemd[1]: shairport-sync.service: Succeeded. Nov 27 13:29:58 living-room-stereo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 27 13:29:58 living-room-stereo sudo[1337]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:29:58 living-room-stereo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 27 13:29:58 living-room-stereo sudo[1334]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:58 living-room-stereo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 27 13:29:58 living-room-stereo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 27 13:29:58 living-room-stereo systemd[1]: shairport-sync.service: Succeeded. Nov 27 13:29:58 living-room-stereo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioGetState Nov 27 13:29:58 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:29:58 living-room-stereo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Shairport-Sync Started Nov 27 13:29:58 living-room-stereo volumio[1003]: Error adding Membership: Error: addMembership EINVAL Nov 27 13:29:58 living-room-stereo sudo[1337]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:58 living-room-stereo sudo[1340]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Shairport-Sync Started Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Shairport-Sync Started Nov 27 13:29:58 living-room-stereo volumio[1003]: info: Volumio called home Nov 27 13:29:58 living-room-stereo go-librespot[1328]: time="2024-11-27T13:29:58-05:00" level=info msg="generated new device id: bca215690e297bed06ef2f96ce4d770ec3eb7549" Nov 27 13:29:58 living-room-stereo go-librespot[1328]: time="2024-11-27T13:29:58-05:00" level=debug msg="stored credentials found for 127875834" Nov 27 13:29:58 living-room-stereo systemd[1]: systemd-hostnamed.service: Succeeded. Nov 27 13:29:59 living-room-stereo volumio[1003]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 27 13:29:59 living-room-stereo volumio[1003]: SPOTIFY: BQC8CFsG3TGhr6NgpUeyURn_izBU1cC-4R8bBP2tBjbayjrAFnkDb5IwqgZPkVun3gStJHQ06JHKB8ApTOCA_BwVVZ6mxfkdcr2EjH8jyJttiu-epKXurOBUy3qV7gt3PFiQ8DUam4o8YOAgjngkcEo_VyV1rsqN1nw-LUJcbnNs8JVkZv0Ulh4canQk4mP49UDU10xC7gJukTzvdZ9rwAXKuQSDM7yqmUPdaA0ZlIAta6X7xXrElyP09A Nov 27 13:29:59 living-room-stereo volumio[1003]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 27 13:29:59 living-room-stereo volumio[1003]: info: New Spotify access token = BQC8CFsG3TGhr6NgpUeyURn_izBU1cC-4R8bBP2tBjbayjrAFnkDb5IwqgZPkVun3gStJHQ06JHKB8ApTOCA_BwVVZ6mxfkdcr2EjH8jyJttiu-epKXurOBUy3qV7gt3PFiQ8DUam4o8YOAgjngkcEo_VyV1rsqN1nw-LUJcbnNs8JVkZv0Ulh4canQk4mP49UDU10xC7gJukTzvdZ9rwAXKuQSDM7yqmUPdaA0ZlIAta6X7xXrElyP09A Nov 27 13:29:59 living-room-stereo volumio[1003]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 27 13:29:59 living-room-stereo mpd[1314]: Nov 27 13:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 27 13:29:59 living-room-stereo systemd[1]: Started Music Player Daemon. Nov 27 13:29:59 living-room-stereo sudo[1263]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:59 living-room-stereo sudo[1281]: pam_unix(sudo:session): session closed for user root Nov 27 13:29:59 living-room-stereo volumio[1003]: info: Completed starting Core Plugins Nov 27 13:29:59 living-room-stereo volumio[1003]: info: ------------------------------------------- Nov 27 13:29:59 living-room-stereo volumio[1003]: info: ----- MyVolumio plugins startup ---- Nov 27 13:29:59 living-room-stereo volumio[1003]: info: ------------------------------------------- Nov 27 13:29:59 living-room-stereo volumio[1003]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 27 13:29:59 living-room-stereo volumio[1003]: info: MPD running with PID1314 Nov 27 13:29:59 living-room-stereo volumio[1003]: ,establishing connection Nov 27 13:29:59 living-room-stereo volumio[1003]: error: MPD error: The expression evaluated to a falsy value: Nov 27 13:29:59 living-room-stereo volumio[1003]: assert.ok(self.idling) Nov 27 13:29:59 living-room-stereo volumio[1003]: error: The expression evaluated to a falsy value: Nov 27 13:29:59 living-room-stereo volumio[1003]: assert.ok(self.idling) Nov 27 13:29:59 living-room-stereo volumio[1003]: error: MPD error: The expression evaluated to a falsy value: Nov 27 13:29:59 living-room-stereo volumio[1003]: assert.ok(self.idling) Nov 27 13:29:59 living-room-stereo volumio[1003]: error: The expression evaluated to a falsy value: Nov 27 13:29:59 living-room-stereo volumio[1003]: assert.ok(self.idling) Nov 27 13:29:59 living-room-stereo volumio[1003]: error: updateQueue error: null Nov 27 13:29:59 living-room-stereo volumio[1003]: SPOTIFY: User informations: {"country":"US","display_name":"Adam Stone","email":"adamdouglasstone@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/127875834"},"followers":{"href":null,"total":21},"href":"https://api.spotify.com/v1/users/127875834","id":"127875834","images":[{"height":300,"url":"https://scontent-iad3-2.xx.fbcdn.net/v/t39.30808-1/342224071_109296358803421_7575863134389556957_n.jpg?stp=dst-jpg_s320x320&_nc_cat=105&ccb=1-7&_nc_sid=3e9727&_nc_ohc=_hzNJI_JvXsQ7kNvgEO6RGh&_nc_zt=24&_nc_ht=scontent-iad3-2.xx&edm=AP4hL3IEAAAA&_nc_gid=AEYocZ6LTfquijl1e7KZDC4&oh=00_AYDLZ1AT11uudbi2Qdbhe9vjTV1XtLTUXzelH3Wr0aRkWw&oe=674CFD37","width":300},{"height":64,"url":"https://scontent-iad3-2.xx.fbcdn.net/v/t39.30808-1/342224071_109296358803421_7575863134389556957_n.jpg?stp=cp0_dst-jpg_s50x50&_nc_cat=105&ccb=1-7&_nc_sid=6738e8&_nc_ohc=_hzNJI_JvXsQ7kNvgEO6RGh&_nc_zt=24&_nc_ht=scontent-iad3-2.xx&edm=AP4hL3IEAAAA&_nc_gid=AEYocZ6LTfquijl1e7KZDC4&oh=00_AYAXINMAv8dYn4vYyOb2IQu73XsvwrRhpiH9VouJHq2kqQ&oe=674CFD37","width":64}],"product":"premium","type":"user","uri":"spotify:user:127875834"} Nov 27 13:29:59 living-room-stereo volumio[1003]: info: Spotify Successfully logged in Nov 27 13:29:59 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 27 13:29:59 living-room-stereo volumio[1003]: info: [1732732199273] CoreMusicLibrary::Adding element Spotify Nov 27 13:29:59 living-room-stereo volumio[1003]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 13:29:59 living-room-stereo volumio[1003]: Cannot find translation for source Spotify Nov 27 13:29:59 living-room-stereo go-librespot[1328]: time="2024-11-27T13:29:59-05:00" level=debug msg="obtained new client token: AAA3dl6GsqgFbnmsYlz7xZ2R3DBle9fxOB/54raQrxNTKK3rJoDJgUxNETUXDjXIK3liTk/a9waZMSRWfT/IPc/kd81dyDZSQmSGOhGtWFf96e8R450RLPQsEb1VIgNjF8T7Rby85z6DqSHXbHSSIDAD45ZPcKHmmUHld97AFAtedD7fvJ8JyLiPSQ/pFMKpc0Nk6DgLsHzGHRBXGqBboKUq7jjtNYZVTDfXdXxJsTHHCgjbLIp5boeEP+mLqA==" Nov 27 13:29:59 living-room-stereo go-librespot[1328]: time="2024-11-27T13:29:59-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Nov 27 13:29:59 living-room-stereo volumio-remote-updater[579]: [2024-11-27 13:29:59] [connect] Successful connection Nov 27 13:29:59 living-room-stereo volumio-remote-updater[579]: [2024-11-27 13:29:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1732732199 101 Nov 27 13:29:59 living-room-stereo volumio[1003]: 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: 3 Nov 27 13:29:59 living-room-stereo go-librespot[1328]: time="2024-11-27T13:29:59-05:00" level=debug msg="completed keyexchange" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="completed challenge" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="authenticated as 127875834" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="authenticated as 127875834" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="dealer connection opened" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="received connection id: ODhkNmJkYzktMzM4My00NWQxLWFmOTAtOTc4ZjkxMWEwODE3K2RlYWxlcit0Y3A6Ly8wYWNiZmExMy5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArNjlFRTM5M0RBNjdERDJEOTYwQTU0MzBCNjg5MzEyMTI0RDI4NjE2OTlBQkU3NzQ1OTMzMkQ4NkVGQUU2RjYwQw==" Nov 27 13:30:00 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:00-05:00" level=debug msg="put connect state because NEW_DEVICE" Nov 27 13:30:01 living-room-stereo volumio[1003]: info: go-librespot daemon successfully initialized Nov 27 13:30:02 living-room-stereo wpa_supplicant[864]: RRM: Ignoring radio measurement request: Not RRM network Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="handling transfer player command from 2f6265f1812520772742a7b11ec8ad970a627149" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=trace msg="fetched new page 0 with 102 items (list: 102)" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="loading track spotify:track:4uUG5RXrOk84mYEfFvj3cK (paused: false, position: 38977ms)" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=trace msg="emitting websocket event: will_play" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4uUG5RXrOk84mYEfFvj3cK" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="requested aes key for file d8e403ce3c4b3be263b1ced80c412a7994c2fcce, gid: 4uUG5RXrOk84mYEfFvj3cK" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2785" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1842" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="fetched first chunk of 17, total size is 8683396 bytes" Nov 27 13:30:02 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:02-05:00" level=debug msg="fetched chunk 1/16, size: 524288" Nov 27 13:30:03 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:03-05:00" level=debug msg="fetched chunk 2/16, size: 524288" Nov 27 13:30:04 living-room-stereo volumio[1003]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 27 13:30:04 living-room-stereo volumio[1003]: Cannot compose Albumart path Nov 27 13:30:04 living-room-stereo sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 27 13:30:04 living-room-stereo sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:30:04 living-room-stereo sudo[1380]: pam_unix(sudo:session): session closed for user root Nov 27 13:30:04 living-room-stereo volumio[1003]: info: Initializing connection to go-librespot Websocket Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=debug msg="new websocket client" Nov 27 13:30:04 living-room-stereo sudo[1383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 27 13:30:04 living-room-stereo sudo[1383]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:30:04 living-room-stereo volumio[1003]: info: Connection to go-librespot Websocket established Nov 27 13:30:04 living-room-stereo sudo[1383]: pam_unix(sudo:session): session closed for user root Nov 27 13:30:04 living-room-stereo sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 27 13:30:04 living-room-stereo sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 13:30:04 living-room-stereo systemd[1]: Started UPnP Renderer front-end to MPD. Nov 27 13:30:04 living-room-stereo sudo[1386]: pam_unix(sudo:session): session closed for user root Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=debug msg="fetched chunk 6/16, size: 524288" Nov 27 13:30:04 living-room-stereo volumio[1003]: info: Upmpdcli Daemon Started Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=debug msg="fetched chunk 3/16, size: 524288" Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=debug msg="fetched chunk 4/16, size: 524288" Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=trace msg="seek to 38977ms (diff: 87ms, samples: 1718885, bytes: 1987813)" Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=debug msg="fetched chunk 5/16, size: 524288" Nov 27 13:30:04 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:04-05:00" level=info msg="loaded track \"I'm Good (Blue)\" (uri: spotify:track:4uUG5RXrOk84mYEfFvj3cK, paused: false, position: 38977ms, duration: 175238ms)" Nov 27 13:30:04 living-room-stereo volumio[1388]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=trace msg="emitting websocket event: metadata" Nov 27 13:30:05 living-room-stereo volumio[1003]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4uUG5RXrOk84mYEfFvj3cK","name":"I'm Good (Blue)","artist_names":["David Guetta","Bebe Rexha"],"album_name":"I'm Good (Blue)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02933c036cd61cd40d3f17a9c4","position":38977,"duration":175238,"release_date":"year:2022 month:8 day:26","track_number":1,"disc_number":1}} Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=trace msg="emitting websocket event: active" Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="sending successful reply for delaer request" Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 27 13:30:05 living-room-stereo volumio[1003]: SPOTIFY: received: {"type":"active","data":null} Nov 27 13:30:05 living-room-stereo volumio[1003]: info: Aligning Spotify Volume to Volumio Volume Nov 27 13:30:05 living-room-stereo volumio[1003]: info: CoreCommandRouter::volumioGetState Nov 27 13:30:05 living-room-stereo volumio[1003]: info: CorePlayQueue::getTrack 0 Nov 27 13:30:05 living-room-stereo volumio[1003]: info: Setting Spotify Volume from Volumio: 100 Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="fetched chunk 7/16, size: 524288" Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 13:30:05 living-room-stereo go-librespot[1328]: time="2024-11-27T13:30:05-05:00" level=trace msg="emitting websocket event: playing" Nov 27 13:30:05 living-room-stereo volumio[1003]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4uUG5RXrOk84mYEfFvj3cK","play_origin":"jumpstart"}} Nov 27 13:30:05 living-room-stereo volumio[1003]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 27 13:30:05 living-room-stereo volumio[1003]: TypeError: Cannot read property 'service' of undefined Nov 27 13:30:05 living-room-stereo volumio[1003]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Nov 27 13:30:05 living-room-stereo volumio[1003]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Nov 27 13:30:05 living-room-stereo volumio[1003]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Nov 27 13:30:05 living-room-stereo volumio[1003]: at WebSocket.emit (events.js:315:20) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1209:20) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver.emit (events.js:315:20) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:594:14) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Nov 27 13:30:05 living-room-stereo volumio[1003]: at writeOrBuffer (internal/streams/writable.js:358:12) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1303:35) Nov 27 13:30:05 living-room-stereo volumio[1003]: at Socket.emit (events.js:315:20) Nov 27 13:30:05 living-room-stereo volumio[1003]: at addChunk (internal/streams/readable.js:309:12) Nov 27 13:30:05 living-room-stereo volumio[1003]: at readableAddChunk (internal/streams/readable.js:284:9) Nov 27 13:30:05 living-room-stereo volumio[1003]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 27 13:30:05 living-room-stereo sudo[1413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-27 13:29 Nov 27 13:30:05 living-room-stereo sudo[1413]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"