-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Wed 2023-11-15 21:13:14 CET. -- Nov 15 21:12:00 volumio volumio[3348]: info: Loading plugin "updater_comm"... Nov 15 21:12:00 volumio volumio[3348]: info: Plugin mpdemulation is not enabled Nov 15 21:12:00 volumio volumio[3348]: info: Loading plugin "rest_api"... Nov 15 21:12:00 volumio volumio[3348]: info: Loading plugin "websocket"... Nov 15 21:12:00 volumio volumio[3348]: info: Loading plugin "fusiondsp"... Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:11:53.0654] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:11:53.6306] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0318] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0329] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0339] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0415] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0441] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0462] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0499] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0593] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.0644] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:00 volumio squeezeboxserver[3336]: [23-11-15 21:12:00.3638] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Nov 15 21:12:00 volumio volumio[3348]: Forking 3 albumart workers Nov 15 21:12:00 volumio volumio[3348]: info: Applying required configuration parameters for plugin fusiondsp Nov 15 21:12:00 volumio volumio[3348]: info: Loading plugin "80s80s"... Nov 15 21:12:01 volumio volumio[3348]: info: Applying required configuration parameters for plugin 80s80s Nov 15 21:12:01 volumio volumio[3348]: info: [1700079121126] [80s80s] API delay: 30 Nov 15 21:12:01 volumio volumio[3348]: info: Loading plugin "lms"... Nov 15 21:12:01 volumio volumio[3348]: info: Loading plugin "motherearthradio"... Nov 15 21:12:01 volumio volumio[3348]: info: Applying required configuration parameters for plugin motherearthradio Nov 15 21:12:01 volumio volumio[3348]: info: [1700079121655] [MotherEarth] API delay: 5 Nov 15 21:12:01 volumio volumio[3348]: info: Loading plugin "rad357pl"... Nov 15 21:12:01 volumio volumio[3348]: Starting albumart workers Nov 15 21:12:02 volumio volumio[3348]: info: Applying required configuration parameters for plugin rad357pl Nov 15 21:12:02 volumio volumio[3348]: info: [1700079122045] [rad357pl] API delay: 5 Nov 15 21:12:02 volumio volumio[3348]: info: Loading plugin "radio_paradise"... Nov 15 21:12:02 volumio volumio[3348]: Starting albumart workers Nov 15 21:12:02 volumio volumio[3348]: Starting albumart workers Nov 15 21:12:02 volumio volumio[3348]: info: Applying required configuration parameters for plugin radio_paradise Nov 15 21:12:02 volumio volumio[3348]: info: [1700079122553] [RadioParadise] API delay: 5 Nov 15 21:12:02 volumio volumio[3348]: info: Loading plugin "lastfm"... Nov 15 21:12:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Nov 15 21:12:02 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:02 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:02 volumio go-librespot[3448]: Librespot-go daemon starting... Nov 15 21:12:02 volumio go-librespot[3448]: time="2023-11-15T21:12:02+01:00" level=info msg="generated new device id: 5d0ae862ceb136a3cdea60e5b8c323e16bbe7ed5" Nov 15 21:12:02 volumio go-librespot[3448]: time="2023-11-15T21:12:02+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:02 volumio go-librespot[3448]: time="2023-11-15T21:12:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:03 volumio squeezeboxserver[3336]: [23-11-15 21:12:03.1506] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Nov 15 21:12:03 volumio volumio[3348]: info: Loading plugin "touch_display"... Nov 15 21:12:03 volumio volumio[3348]: info: Applying required configuration parameters for plugin touch_display Nov 15 21:12:03 volumio volumio[3348]: info: Loading i18n strings for locale pl Nov 15 21:12:03 volumio volumio[3348]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:03 volumio volumio[3348]: Updating browse sources language Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::initPlayerControls Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:03 volumio volumio[3348]: Express server listening on port 3000 Nov 15 21:12:03 volumio volumio[3348]: [Metrics] WebUI: 12s 83.79ms Nov 15 21:12:03 volumio volumio[3348]: info: CoreStateMachine::resetVolumioState Nov 15 21:12:03 volumio volumio[3348]: info: CoreStateMachine::getcurrentVolume Nov 15 21:12:03 volumio volumio[3348]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:04 volumio volumio[3348]: info: MPD Permissions set Nov 15 21:12:04 volumio volumio[3348]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Nov 15 21:12:04 volumio volumio[3348]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 15 21:12:04 volumio volumio[3348]: info: MPD running with PID3399 Nov 15 21:12:04 volumio volumio[3348]: ,establishing connection Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.1957] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2711] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2721] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Nov 15 21:12:04 volumio volumio[3348]: info: Reloading queue from file Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2750] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Nov 15 21:12:04 volumio volumio[3348]: error: updateQueue error: null Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2818] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2830] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2857] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2866] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.2901] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:04 volumio volumio[3348]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::pushState Nov 15 21:12:04 volumio volumio[3348]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::updateTrackBlock Nov 15 21:12:04 volumio volumio[3348]: info: CorePlayQueue::getTrackBlock Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::setRepeat false single undefined Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::pushState Nov 15 21:12:04 volumio volumio[3348]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::setRandom null Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::pushState Nov 15 21:12:04 volumio volumio[3348]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:04 volumio volumio[3348]: info: Setting Device type: Raspberry PI Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4070] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4098] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:04 volumio volumio[3348]: info: Completed loading Core Plugins Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4119] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:04 volumio volumio[3348]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4212] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4391] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4403] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.157 seconds. Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4419] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4430] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4443] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Nov 15 21:12:04 volumio volumio[3348]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4472] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.003 seconds. Nov 15 21:12:04 volumio volumio[3348]: info: Reading ALSA contributions from plugins. Nov 15 21:12:04 volumio volumio[3348]: error: updateQueue error: null Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4507] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4516] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.002 seconds. Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.4531] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Nov 15 21:12:04 volumio sudo[3497]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:04 volumio sudo[3497]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:04 volumio sudo[3497]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:04 volumio sudo[3500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:04 volumio sudo[3500]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:04 volumio sudo[3500]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:04 volumio volumio[3348]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:04 volumio volumio[3348]: info: CoreStateMachine::pushState Nov 15 21:12:04 volumio volumio[3348]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:04 volumio volumio[3348]: info: Asound.conf file unchanged, so no further update is needed Nov 15 21:12:04 volumio volumio[3348]: info: Output device has changed, restarting MPD Nov 15 21:12:04 volumio sudo[3503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 15 21:12:04 volumio sudo[3503]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:04 volumio sudo[3503]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:04 volumio sudo[3506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:04 volumio volumio[3348]: info: Output device has changed, restarting Shairport Sync Nov 15 21:12:04 volumio sudo[3506]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:04 volumio sudo[3506]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:04 volumio sudo[3508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:04 volumio sudo[3508]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:04 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:04 volumio volumio[3348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:04 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:04 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:04 volumio volumio[3348]: info: ___________ START PLUGINS ___________ Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:04 volumio volumio[3348]: info: [1700079124843] CoreMusicLibrary::Adding element Media Servers Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:04 volumio squeezeboxserver[3336]: [23-11-15 21:12:04.8449] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 0.391 seconds. Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:04 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:04 volumio volumio[3348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:04 volumio volumio[3348]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:04 volumio volumio[3348]: info: [1700079124978] CoreMusicLibrary::Adding element Last_100 Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:04 volumio volumio[3348]: info: [1700079124989] CoreMusicLibrary::Adding element Webradio Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:04 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:05 volumio volumio[3348]: info: Creating Spotify config file Nov 15 21:12:05 volumio volumio[3348]: info: [squeezelite_mc] Starting proxy server... Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125103] CoreMusicLibrary::Adding element YouTube2 Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125110] CoreMusicLibrary::Adding element YouTube Music Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube Music Nov 15 21:12:05 volumio volumio[3348]: info: Loading i18n strings for locale pl Nov 15 21:12:05 volumio volumio[3348]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: FusionDsp - mixtype--------------------- Hardware Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125135] CoreMusicLibrary::Adding element 80s80s Radio Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube Music Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source 80s80s Radio Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125172] CoreMusicLibrary::Adding element Mother Earth Radio Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube Music Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source 80s80s Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125181] CoreMusicLibrary::Adding element RADIO 357 Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube Music Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source 80s80s Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source RADIO 357 Nov 15 21:12:05 volumio sudo[3524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125190] CoreMusicLibrary::Adding element Radio Paradise Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube Music Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source 80s80s Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source RADIO 357 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source Radio Paradise Nov 15 21:12:05 volumio sudo[3524]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:05 volumio volumio[3348]: info: [1700079125196] CoreMusicLibrary::Adding element LastFM Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube2 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source YouTube Music Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source 80s80s Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source RADIO 357 Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source Radio Paradise Nov 15 21:12:05 volumio volumio[3348]: Cannot find translation for source LastFM Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] scrobbler initiated! Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] extended logging: false Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] try scrobble stream/radio plays: true Nov 15 21:12:05 volumio systemd[1]: Stopping Logitech Media Server Daemon... Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] Left init routine Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] Socket already connected: true Nov 15 21:12:05 volumio volumio[3348]: info: Loading i18n strings for locale pl Nov 15 21:12:05 volumio volumio[3348]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:05 volumio volumio[3348]: info: Volumio Calling Home Nov 15 21:12:05 volumio volumio[3348]: info: [squeezelite_mc] Proxy server started on port 34011 Nov 15 21:12:05 volumio volumio[3348]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:05 volumio volumio[3348]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:05 volumio sudo[3530]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 15 21:12:05 volumio sudo[3530]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:05 volumio systemd[1]: Reloading. Nov 15 21:12:05 volumio volumio[3348]: Unhandled rejection Error: No sockets available, cannot start. Nov 15 21:12:05 volumio volumio[3348]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 15 21:12:05 volumio volumio[3348]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 15 21:12:05 volumio volumio[3348]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 15 21:12:05 volumio volumio[3348]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 15 21:12:05 volumio volumio[3348]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 15 21:12:05 volumio volumio[3348]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 15 21:12:05 volumio volumio[3348]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 15 21:12:05 volumio volumio[3348]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 15 21:12:05 volumio volumio[3348]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 15 21:12:05 volumio volumio[3348]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 15 21:12:05 volumio volumio[3348]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 15 21:12:05 volumio volumio[3348]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 15 21:12:05 volumio volumio[3348]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 15 21:12:05 volumio volumio[3348]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 15 21:12:05 volumio volumio[3348]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 15 21:12:05 volumio volumio[3348]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 15 21:12:05 volumio volumio[3348]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Nov 15 21:12:05 volumio volumio[3348]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:05 volumio volumio[3348]: info: Reading ALSA contributions from plugins. Nov 15 21:12:05 volumio volumio[3348]: info: MPD Permissions set Nov 15 21:12:05 volumio volumio[3348]: info: Upmpdcli Daemon Started Nov 15 21:12:05 volumio volumio[3348]: info: Spotify config file written Nov 15 21:12:05 volumio sudo[3548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 15 21:12:05 volumio sudo[3548]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:05 volumio volumio[3348]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:05 volumio volumio[3348]: info: CoreStateMachine::pushState Nov 15 21:12:05 volumio volumio[3348]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:05 volumio volumio[3348]: info: [squeezelite_mc] Server discovery started Nov 15 21:12:05 volumio volumio[3348]: info: [squeezelite_mc] Player finder started Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:05 volumio volumio[3348]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Nov 15 21:12:05 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 15 21:12:05 volumio volumio[3348]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:05 volumio volumio[3348]: Error: send ENETUNREACH 255.255.255.255:3483 Nov 15 21:12:05 volumio volumio[3348]: at doSend (dgram.js:692:16) Nov 15 21:12:05 volumio volumio[3348]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Nov 15 21:12:05 volumio volumio[3348]: at afterDns (dgram.js:638:5) Nov 15 21:12:05 volumio volumio[3348]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Nov 15 21:12:05 volumio volumio[3348]: errno: -101, Nov 15 21:12:05 volumio volumio[3348]: code: 'ENETUNREACH', Nov 15 21:12:05 volumio volumio[3348]: syscall: 'send', Nov 15 21:12:05 volumio volumio[3348]: address: '255.255.255.255', Nov 15 21:12:05 volumio volumio[3348]: port: 3483 Nov 15 21:12:05 volumio volumio[3348]: } Nov 15 21:12:05 volumio volumio[3348]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:05 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Nov 15 21:12:06 volumio squeezeboxserver[3336]: [23-11-15 21:12:05.7446] Slim::Schema::Storage::throw_exception (121) Error: DBI Exception: DBD::SQLite::db prepare_cached failed: attempt to fetch on inactive database handle Nov 15 21:12:06 volumio squeezeboxserver[3336]: [23-11-15 21:12:05.7508] Slim::Schema::Storage::throw_exception (121) Backtrace: Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 121) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1007) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 2058) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 3: DBIx::Class::Storage::DBI::_dbh_sth (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 574) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 4: DBIx::Class::Storage::DBI::dbh_do (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 2071) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 5: DBIx::Class::Storage::DBI::sth (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1264) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 6: DBIx::Class::Storage::DBI::_dbh_execute (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 584) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 7: (eval) (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 581) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 8: DBIx::Class::Storage::DBI::dbh_do (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1297) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 9: DBIx::Class::Storage::DBI::_execute (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1532) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 10: DBIx::Class::Storage::DBI::_select (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 2031) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 11: DBIx::Class::Storage::DBI::select_single (/usr/share/squeezeboxserver/lib/DBIx/Class/ResultSet.pm line 747) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 12: DBIx::Class::ResultSet::single (/usr/share/squeezeboxserver/lib/DBIx/Class/ResultSet.pm line 540) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 13: DBIx::Class::ResultSet::find (/usr/share/squeezeboxserver/lib/DBIx/Class/ResultSet.pm line 2364) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 14: DBIx::Class::ResultSet::find_or_create (/usr/share/perl5/Slim/Music/Import.pm line 337) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 15: Slim::Music::Import::setIsScanning (/usr/share/perl5/Slim/Music/Import.pm line 739) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 16: Slim::Music::Import::stillScanning (/usr/sbin/squeezeboxserver line 1165) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 17: main::cleanup (/usr/share/perl5/Slim/bootstrap.pm line 417) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 18: Slim::bootstrap::sigterm (/usr/share/perl5/Slim/Schema.pm line 327) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 19: (eval) (/usr/share/perl5/Slim/Schema.pm line 327) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 20: (eval) (/usr/share/perl5/Slim/Schema.pm line 327) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 21: Slim::Schema::disconnect (/usr/share/perl5/Slim/Utils/SQLiteHelper.pm line 624) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 22: Slim::Utils::SQLiteHelper::_notifyFromScanner (/usr/share/perl5/Slim/Control/Request.pm line 1880) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 23: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1880) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 24: Slim::Control::Request::execute (/usr/share/perl5/Slim/Web/JSONRPC.pm line 472) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 25: Slim::Web::JSONRPC::requestMethod (/usr/share/perl5/Slim/Web/JSONRPC.pm line 274) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 26: (eval) (/usr/share/perl5/Slim/Web/JSONRPC.pm line 274) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 27: Slim::Web::JSONRPC::handleURI (/usr/share/perl5/Slim/Web/HTTP.pm line 484) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 28: Slim::Web::HTTP::processHTTP (/usr/share/perl5/Slim/Networking/IO/Select.pm line 122) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 29: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 118) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 30: Slim::Networking::IO::Select::__ANON__ (/usr/share/perl5/Slim/Networking/IO/Select.pm line 167) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 31: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 167) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 32: Slim::Networking::IO::Select::loop (/usr/sbin/squeezeboxserver line 721) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 33: main::idle (/usr/sbin/squeezeboxserver line 671) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 34: main::main (/usr/sbin/squeezeboxserver line 1210) Nov 15 21:12:06 volumio squeezeboxserver[3336]: [23-11-15 21:12:05.7692] Slim::Schema::Storage::throw_exception (121) Error: DBI Exception: DBD::SQLite::db prepare failed: attempt to prepare on inactive database handle [for Statement " Nov 15 21:12:06 volumio squeezeboxserver[3336]: UPDATE progress Nov 15 21:12:06 volumio squeezeboxserver[3336]: SET active = 0, finish = ?, info = '' Nov 15 21:12:06 volumio squeezeboxserver[3336]: WHERE type = ? AND active = 1 AND name != 'failure' Nov 15 21:12:06 volumio squeezeboxserver[3336]: "] Nov 15 21:12:06 volumio squeezeboxserver[3336]: [23-11-15 21:12:05.7708] Slim::Schema::Storage::throw_exception (121) Backtrace: Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Schema/Storage.pm line 121) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 1: Slim::Schema::Storage::throw_exception (/usr/share/squeezeboxserver/CPAN/DBIx/Class/Storage/DBI.pm line 1007) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 2: DBIx::Class::Storage::DBI::__ANON__ (/usr/share/perl5/Slim/Utils/Progress.pm line 376) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 3: Slim::Utils::Progress::cleanup (/usr/share/perl5/Slim/Music/Import.pm line 741) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 4: Slim::Music::Import::stillScanning (/usr/sbin/squeezeboxserver line 1165) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 5: main::cleanup (/usr/share/perl5/Slim/bootstrap.pm line 417) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 6: Slim::bootstrap::sigterm (/usr/share/perl5/Slim/Schema.pm line 327) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 7: (eval) (/usr/share/perl5/Slim/Schema.pm line 327) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 8: (eval) (/usr/share/perl5/Slim/Schema.pm line 327) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 9: Slim::Schema::disconnect (/usr/share/perl5/Slim/Utils/SQLiteHelper.pm line 624) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 10: Slim::Utils::SQLiteHelper::_notifyFromScanner (/usr/share/perl5/Slim/Control/Request.pm line 1880) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 11: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1880) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 12: Slim::Control::Request::execute (/usr/share/perl5/Slim/Web/JSONRPC.pm line 472) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 13: Slim::Web::JSONRPC::requestMethod (/usr/share/perl5/Slim/Web/JSONRPC.pm line 274) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 14: (eval) (/usr/share/perl5/Slim/Web/JSONRPC.pm line 274) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 15: Slim::Web::JSONRPC::handleURI (/usr/share/perl5/Slim/Web/HTTP.pm line 484) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 16: Slim::Web::HTTP::processHTTP (/usr/share/perl5/Slim/Networking/IO/Select.pm line 122) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 17: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 118) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 18: Slim::Networking::IO::Select::__ANON__ (/usr/share/perl5/Slim/Networking/IO/Select.pm line 167) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 19: (eval) (/usr/share/perl5/Slim/Networking/IO/Select.pm line 167) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 20: Slim::Networking::IO::Select::loop (/usr/sbin/squeezeboxserver line 721) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 21: main::idle (/usr/sbin/squeezeboxserver line 671) Nov 15 21:12:06 volumio squeezeboxserver[3336]: frame 22: main::main (/usr/sbin/squeezeboxserver line 1210) Nov 15 21:12:06 volumio squeezeboxserver[3336]: [23-11-15 21:12:06.0291] Slim::Control::Request::execute (1885) Error: While trying to run function coderef [Slim::Utils::SQLiteHelper::_notifyFromScanner]: [Can't call method "func" on an undefined value at /usr/share/perl5/Slim/Utils/SQLiteHelper.pm line 359. Nov 15 21:12:06 volumio squeezeboxserver[3336]: ] Nov 15 21:12:06 volumio squeezeboxserver[3336]: [23-11-15 21:12:06.0305] Slim::Web::JSONRPC::requestMethod (477) Request failed with error: Bad dispatch! Nov 15 21:12:06 volumio sudo[3530]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:06 volumio systemd[1]: logitechmediaserver.service: Succeeded. Nov 15 21:12:06 volumio systemd[1]: Stopped Logitech Media Server Daemon. Nov 15 21:12:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Nov 15 21:12:06 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:06 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:06 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=9c:63:5b:7b:1f:5e status_code=16 Nov 15 21:12:06 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="RouterTR" auth_failures=5 duration=75 reason=CONN_FAILED Nov 15 21:12:06 volumio sudo[3548]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:06 volumio go-librespot[3564]: Librespot-go daemon starting... Nov 15 21:12:06 volumio systemd[1]: Starting Logitech Media Server Daemon... Nov 15 21:12:06 volumio go-librespot[3564]: time="2023-11-15T21:12:06+01:00" level=info msg="generated new device id: f355f4e9a86ef84ce5450a497cfaaff72c25f88e" Nov 15 21:12:06 volumio go-librespot[3564]: time="2023-11-15T21:12:06+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:06 volumio go-librespot[3564]: time="2023-11-15T21:12:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:06 volumio systemd[1]: Started Logitech Media Server Daemon. Nov 15 21:12:06 volumio sudo[3524]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:06 volumio mpd[3522]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:06 volumio mpd[3522]: config: Found database setting without music_directory - disabling database Nov 15 21:12:06 volumio mpd[3522]: output: No 'audio_output' defined in config file Nov 15 21:12:06 volumio mpd[3522]: output: Attempt to detect audio output device Nov 15 21:12:06 volumio mpd[3522]: output: Attempting to detect a alsa audio device Nov 15 21:12:06 volumio mpd[3522]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:06 volumio mpd[3522]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:06 volumio mpd[3522]: output: Attempting to detect a oss audio device Nov 15 21:12:06 volumio mpd[3522]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:06 volumio mpd[3522]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:06 volumio mpd[3522]: output: Attempting to detect a pulse audio device Nov 15 21:12:06 volumio mpd[3522]: output: Attempting to detect a jack audio device Nov 15 21:12:06 volumio mpd[3522]: output: Successfully detected a jack audio device Nov 15 21:12:06 volumio mpd[3522]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:06 volumio mpd[3522]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:06 volumio mpd[3522]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:06 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:06 volumio sudo[3508]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:06 volumio sudo[3579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-11-15 21:11 Nov 15 21:12:06 volumio sudo[3579]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:06 volumio sudo[3579]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 15 21:12:07 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:07 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:07 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 15 21:12:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11. Nov 15 21:12:07 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:07 volumio systemd[1]: Stopped Volumio Backend Module. Nov 15 21:12:07 volumio systemd[1]: Started Volumio Backend Module. Nov 15 21:12:07 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:07 volumio volumio-remote-updater[542]: [2023-11-15 21:12:07] [info] asio async_connect error: system:111 (Connection refused) Nov 15 21:12:07 volumio volumio-remote-updater[542]: [2023-11-15 21:12:07] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 15 21:12:07 volumio volumio-remote-updater[542]: [2023-11-15 21:12:07] [error] handle_connect error: Underlying Transport Error Nov 15 21:12:09 volumio volumio[3593]: info: ------------------------------------------- Nov 15 21:12:09 volumio volumio[3593]: info: ----- Volumio3 ---- Nov 15 21:12:09 volumio volumio[3593]: info: ------------------------------------------- Nov 15 21:12:09 volumio volumio[3593]: info: ----- System startup ---- Nov 15 21:12:09 volumio volumio[3593]: info: ------------------------------------------- Nov 15 21:12:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Nov 15 21:12:09 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:09 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:09 volumio go-librespot[3613]: Librespot-go daemon starting... Nov 15 21:12:09 volumio go-librespot[3613]: time="2023-11-15T21:12:09+01:00" level=info msg="generated new device id: 5bdf85651931b4bfbe2fb0c6f1c784d72b7c916c" Nov 15 21:12:09 volumio go-librespot[3613]: time="2023-11-15T21:12:09+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:09 volumio go-librespot[3613]: time="2023-11-15T21:12:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:09 volumio volumio[3593]: info: MYVOLUMIO Environment detected Nov 15 21:12:09 volumio volumio[3593]: info: Plugin folders cleanup Nov 15 21:12:09 volumio volumio[3593]: info: Scanning into folder /volumio/app/plugins/ Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category audio_interface Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category miscellanea Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category music_service Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category plugins.json Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category system_controller Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category user_interface Nov 15 21:12:09 volumio volumio[3593]: info: Scanning into folder /data/plugins/ Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category audio_interface Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category music_service Nov 15 21:12:09 volumio volumio[3593]: info: Scanning category user_interface Nov 15 21:12:09 volumio volumio[3593]: info: Plugin folders cleanup completed Nov 15 21:12:09 volumio volumio[3593]: info: ------------------------------------------- Nov 15 21:12:09 volumio volumio[3593]: info: ----- Core plugins startup ---- Nov 15 21:12:09 volumio volumio[3593]: info: ------------------------------------------- Nov 15 21:12:09 volumio volumio[3593]: info: Loading plugins from folder /volumio/app/plugins/ Nov 15 21:12:09 volumio volumio[3593]: info: Adding plugin upnp to MyMusic Plugins Nov 15 21:12:09 volumio volumio[3593]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 15 21:12:09 volumio volumio[3593]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 15 21:12:09 volumio volumio[3593]: info: Loading plugins from folder /data/plugins/ Nov 15 21:12:09 volumio volumio[3593]: info: Loading plugin "system"... Nov 15 21:12:09 volumio volumio[3593]: info: Loading plugin "appearance"... Nov 15 21:12:10 volumio volumio[3593]: info: Loading plugin "network"... Nov 15 21:12:10 volumio volumio[3593]: info: Refreshing Cached IP Addresses Nov 15 21:12:10 volumio sudo[3623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:10 volumio sudo[3623]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:10 volumio sudo[3623]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "services"... Nov 15 21:12:11 volumio sudo[3625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:11 volumio sudo[3625]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "alsa_controller"... Nov 15 21:12:11 volumio sudo[3625]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:11 volumio sudo[3628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 15 21:12:11 volumio sudo[3628]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:11 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "wizard"... Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "volumio_command_line_client"... Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "upnp"... Nov 15 21:12:11 volumio volumio[3593]: info: [1700079131127] Starting Upmpd Daemon Nov 15 21:12:11 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "my_music"... Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "mpd"... Nov 15 21:12:11 volumio volumio[3593]: info: Creating MPD Configuration file Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "upnp_browser"... Nov 15 21:12:11 volumio sudo[3636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:11 volumio sudo[3636]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:11 volumio sudo[3636]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:11 volumio sudo[3638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:11 volumio sudo[3638]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:11 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:11 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:11 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:11 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:11 volumio volumio[3593]: info: Loading plugin "networkfs"... Nov 15 21:12:12 volumio volumio[3593]: info: Starting Udev Watcher for removable devices Nov 15 21:12:12 volumio volumio[3593]: info: Ignoring mount for partition: boot Nov 15 21:12:12 volumio volumio[3593]: info: Ignoring mount for partition: volumio Nov 15 21:12:12 volumio volumio[3593]: info: Ignoring mount for partition: volumio_data Nov 15 21:12:12 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "alarm-clock"... Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "airplay_emulation"... Nov 15 21:12:12 volumio volumio[3593]: info: Starting Shairport Sync Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "last_100"... Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "webradio"... Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "i2s_dacs"... Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "volumiodiscovery"... Nov 15 21:12:12 volumio volumio[3593]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:12 volumio volumio[3593]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:12 volumio volumio[3593]: *** WARNING *** For more information see Nov 15 21:12:12 volumio node[3593]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:12 volumio volumio[3593]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:12 volumio volumio[3593]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:12 volumio volumio[3593]: *** WARNING *** For more information see Nov 15 21:12:12 volumio node[3593]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:12 volumio node[3593]: *** WARNING *** For more information see Nov 15 21:12:12 volumio node[3593]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:12 volumio node[3593]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:12 volumio node[3593]: *** WARNING *** For more information see Nov 15 21:12:12 volumio volumio[3593]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 15 21:12:12 volumio volumio[3593]: info: Discovery: Started advertising with name: Volumio Nov 15 21:12:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Nov 15 21:12:12 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:12 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:12 volumio volumio[3593]: info: Loading plugin "spop"... Nov 15 21:12:12 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:12 volumio go-librespot[3647]: Librespot-go daemon starting... Nov 15 21:12:12 volumio go-librespot[3647]: time="2023-11-15T21:12:12+01:00" level=info msg="generated new device id: 0c67779cf43fa363044b22f2091c480aa5b6d027" Nov 15 21:12:12 volumio go-librespot[3647]: time="2023-11-15T21:12:12+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:12 volumio go-librespot[3647]: time="2023-11-15T21:12:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:13 volumio mpd[3643]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:13 volumio mpd[3643]: config: Found database setting without music_directory - disabling database Nov 15 21:12:13 volumio mpd[3643]: output: No 'audio_output' defined in config file Nov 15 21:12:13 volumio mpd[3643]: output: Attempt to detect audio output device Nov 15 21:12:13 volumio mpd[3643]: output: Attempting to detect a alsa audio device Nov 15 21:12:13 volumio mpd[3643]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:13 volumio mpd[3643]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:13 volumio mpd[3643]: output: Attempting to detect a oss audio device Nov 15 21:12:13 volumio mpd[3643]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:13 volumio mpd[3643]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:13 volumio mpd[3643]: output: Attempting to detect a pulse audio device Nov 15 21:12:13 volumio mpd[3643]: output: Attempting to detect a jack audio device Nov 15 21:12:13 volumio mpd[3643]: output: Successfully detected a jack audio device Nov 15 21:12:13 volumio mpd[3643]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:13 volumio mpd[3643]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:13 volumio mpd[3643]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:13 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:13 volumio sudo[3638]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:14 volumio volumio[3593]: info: Loading plugin "squeezelite_mc"... Nov 15 21:12:14 volumio volumio[3593]: info: Loading plugin "youtube2"... Nov 15 21:12:14 volumio sudo[3628]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:15 volumio volumio[3593]: info: Loading plugin "ytmusic"... Nov 15 21:12:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Nov 15 21:12:16 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:09.6974] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:10.2664] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8044] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8054] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8062] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8131] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8225] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8239] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8265] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8349] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:15.8391] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:16 volumio squeezeboxserver[3574]: [23-11-15 21:12:16.0822] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Nov 15 21:12:16 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:16 volumio go-librespot[3657]: Librespot-go daemon starting... Nov 15 21:12:16 volumio go-librespot[3657]: time="2023-11-15T21:12:16+01:00" level=info msg="generated new device id: 4a9f288d7b4f1d68437c8d15af23e57cd8d19d50" Nov 15 21:12:16 volumio go-librespot[3657]: time="2023-11-15T21:12:16+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:16 volumio go-librespot[3657]: time="2023-11-15T21:12:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:16 volumio volumio[3593]: info: Loading plugin "outputs"... Nov 15 21:12:16 volumio volumio[3593]: info: Loading plugin "albumart"... Nov 15 21:12:16 volumio volumio[3593]: info: Plugin example_plugin is not enabled Nov 15 21:12:16 volumio volumio[3593]: info: Loading plugin "inputs"... Nov 15 21:12:16 volumio volumio[3593]: info: Loading plugin "updater_comm"... Nov 15 21:12:17 volumio volumio[3593]: info: Plugin mpdemulation is not enabled Nov 15 21:12:17 volumio volumio[3593]: info: Loading plugin "rest_api"... Nov 15 21:12:17 volumio volumio[3593]: info: Loading plugin "websocket"... Nov 15 21:12:17 volumio volumio[3593]: info: Loading plugin "fusiondsp"... Nov 15 21:12:17 volumio volumio[3593]: Forking 3 albumart workers Nov 15 21:12:17 volumio volumio[3593]: info: Applying required configuration parameters for plugin fusiondsp Nov 15 21:12:17 volumio volumio-remote-updater[542]: [2023-11-15 21:12:17] [connect] Successful connection Nov 15 21:12:17 volumio volumio[3593]: info: Loading plugin "80s80s"... Nov 15 21:12:18 volumio squeezeboxserver[3574]: [23-11-15 21:12:18.4194] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Nov 15 21:12:18 volumio volumio[3593]: info: Applying required configuration parameters for plugin 80s80s Nov 15 21:12:18 volumio volumio[3593]: info: [1700079138511] [80s80s] API delay: 30 Nov 15 21:12:18 volumio volumio[3593]: info: Loading plugin "lms"... Nov 15 21:12:18 volumio volumio[3593]: Starting albumart workers Nov 15 21:12:18 volumio volumio[3593]: Starting albumart workers Nov 15 21:12:18 volumio volumio[3593]: Starting albumart workers Nov 15 21:12:18 volumio volumio[3593]: info: Loading plugin "motherearthradio"... Nov 15 21:12:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Nov 15 21:12:19 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:19 volumio volumio[3593]: info: Applying required configuration parameters for plugin motherearthradio Nov 15 21:12:19 volumio volumio[3593]: info: [1700079139357] [MotherEarth] API delay: 5 Nov 15 21:12:19 volumio volumio[3593]: info: Loading plugin "rad357pl"... Nov 15 21:12:19 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:19 volumio go-librespot[3693]: Librespot-go daemon starting... Nov 15 21:12:19 volumio go-librespot[3693]: time="2023-11-15T21:12:19+01:00" level=info msg="generated new device id: 87137aedc6480a72ecb8927383a1c2d77a0ecb98" Nov 15 21:12:19 volumio go-librespot[3693]: time="2023-11-15T21:12:19+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:19 volumio go-librespot[3693]: time="2023-11-15T21:12:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:19 volumio volumio[3593]: info: Applying required configuration parameters for plugin rad357pl Nov 15 21:12:19 volumio volumio[3593]: info: [1700079139862] [rad357pl] API delay: 5 Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.8623] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:19 volumio volumio[3593]: info: Loading plugin "radio_paradise"... Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9367] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9376] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9406] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9472] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9485] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9495] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9508] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9535] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9542] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:19 volumio squeezeboxserver[3574]: [23-11-15 21:12:19.9578] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:20 volumio volumio[3593]: info: Applying required configuration parameters for plugin radio_paradise Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.0767] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:20 volumio volumio[3593]: info: [1700079140078] [RadioParadise] API delay: 5 Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.0792] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.0813] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:20 volumio volumio[3593]: info: Loading plugin "lastfm"... Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.0904] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1062] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1074] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.157 seconds. Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1088] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1113] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.002 seconds. Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1144] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1152] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.002 seconds. Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.1166] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Nov 15 21:12:20 volumio squeezeboxserver[3574]: [23-11-15 21:12:20.4992] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 0.382 seconds. Nov 15 21:12:20 volumio volumio[3593]: info: Loading plugin "touch_display"... Nov 15 21:12:20 volumio volumio[3593]: info: Applying required configuration parameters for plugin touch_display Nov 15 21:12:20 volumio volumio[3593]: info: Loading i18n strings for locale pl Nov 15 21:12:20 volumio volumio[3593]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:20 volumio volumio[3593]: Updating browse sources language Nov 15 21:12:20 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:20 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:20 volumio volumio[3593]: info: CoreCommandRouter::initPlayerControls Nov 15 21:12:20 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: Express server listening on port 3000 Nov 15 21:12:21 volumio volumio[3593]: [Metrics] WebUI: 12s 629.88ms Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::resetVolumioState Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::getcurrentVolume Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:21 volumio mpd[3643]: client: [0] opened from local Nov 15 21:12:21 volumio volumio[3593]: info: MPD Permissions set Nov 15 21:12:21 volumio sudo[3732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:21 volumio sudo[3732]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:21 volumio sudo[3732]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:21 volumio sudo[3735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:21 volumio sudo[3735]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:21 volumio sudo[3735]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:21 volumio volumio-remote-updater[542]: [2023-11-15 21:12:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1700079137 101 Nov 15 21:12:21 volumio volumio[3593]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Nov 15 21:12:21 volumio volumio[3593]: info: MPD running with PID3643 Nov 15 21:12:21 volumio volumio[3593]: ,establishing connection Nov 15 21:12:21 volumio mpd[3643]: client: [1] opened from local Nov 15 21:12:21 volumio volumio[3593]: error: MPD error: The expression evaluated to a falsy value: Nov 15 21:12:21 volumio volumio[3593]: assert.ok(self.idling) Nov 15 21:12:21 volumio volumio[3593]: error: The expression evaluated to a falsy value: Nov 15 21:12:21 volumio volumio[3593]: assert.ok(self.idling) Nov 15 21:12:21 volumio volumio[3593]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 15 21:12:21 volumio volumio[3593]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: Reloading queue from file Nov 15 21:12:21 volumio volumio[3593]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::pushState Nov 15 21:12:21 volumio volumio[3593]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::updateTrackBlock Nov 15 21:12:21 volumio volumio[3593]: info: CorePlayQueue::getTrackBlock Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::setRepeat false single undefined Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::pushState Nov 15 21:12:21 volumio volumio[3593]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::setRandom null Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::pushState Nov 15 21:12:21 volumio volumio[3593]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:21 volumio volumio[3593]: info: Setting Device type: Raspberry PI Nov 15 21:12:21 volumio volumio[3593]: error: updateQueue error: null Nov 15 21:12:21 volumio volumio[3593]: info: Completed loading Core Plugins Nov 15 21:12:21 volumio volumio[3593]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:21 volumio volumio[3593]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:21 volumio volumio[3593]: info: Reading ALSA contributions from plugins. Nov 15 21:12:21 volumio sudo[3749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 15 21:12:21 volumio sudo[3749]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:21 volumio sudo[3749]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:21 volumio volumio[3593]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:21 volumio volumio[3593]: info: CoreStateMachine::pushState Nov 15 21:12:21 volumio volumio[3593]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:21 volumio volumio[3593]: info: Upmpdcli Daemon Started Nov 15 21:12:21 volumio volumio[3593]: info: Asound.conf file unchanged, so no further update is needed Nov 15 21:12:21 volumio volumio[3593]: info: Output device has changed, restarting MPD Nov 15 21:12:21 volumio sudo[3752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:21 volumio sudo[3752]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:21 volumio volumio[3593]: info: Output device has changed, restarting Shairport Sync Nov 15 21:12:21 volumio sudo[3752]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:21 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:21 volumio sudo[3755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:21 volumio sudo[3755]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:21 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:22 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:22 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:22 volumio volumio[3593]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:22 volumio volumio[3593]: info: ___________ START PLUGINS ___________ Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142033] CoreMusicLibrary::Adding element Media Servers Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:22 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:22 volumio volumio[3593]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142162] CoreMusicLibrary::Adding element Last_100 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142167] CoreMusicLibrary::Adding element Webradio Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:22 volumio volumio[3593]: info: Creating Spotify config file Nov 15 21:12:22 volumio volumio[3593]: info: [squeezelite_mc] Starting proxy server... Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142299] CoreMusicLibrary::Adding element YouTube2 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142306] CoreMusicLibrary::Adding element YouTube Music Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube Music Nov 15 21:12:22 volumio volumio[3593]: info: Loading i18n strings for locale pl Nov 15 21:12:22 volumio volumio[3593]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: FusionDsp - mixtype--------------------- Hardware Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142332] CoreMusicLibrary::Adding element 80s80s Radio Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube Music Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source 80s80s Radio Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142367] CoreMusicLibrary::Adding element Mother Earth Radio Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube Music Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source 80s80s Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:22 volumio sudo[3770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Nov 15 21:12:22 volumio sudo[3770]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142382] CoreMusicLibrary::Adding element RADIO 357 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube Music Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source 80s80s Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source RADIO 357 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio systemd[1]: Stopping Logitech Media Server Daemon... Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142413] CoreMusicLibrary::Adding element Radio Paradise Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube Music Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source 80s80s Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source RADIO 357 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source Radio Paradise Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:22 volumio volumio[3593]: info: [1700079142422] CoreMusicLibrary::Adding element LastFM Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube2 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source YouTube Music Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source 80s80s Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source RADIO 357 Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source Radio Paradise Nov 15 21:12:22 volumio volumio[3593]: Cannot find translation for source LastFM Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] scrobbler initiated! Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] extended logging: false Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] try scrobble stream/radio plays: true Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] Left init routine Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] Socket already connected: true Nov 15 21:12:22 volumio volumio[3593]: info: Loading i18n strings for locale pl Nov 15 21:12:22 volumio volumio[3593]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:22 volumio volumio[3593]: info: Volumio Calling Home Nov 15 21:12:22 volumio volumio[3593]: info: [squeezelite_mc] Proxy server started on port 38997 Nov 15 21:12:22 volumio volumio[3593]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:22 volumio volumio[3593]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Nov 15 21:12:22 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:22 volumio sudo[3777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 15 21:12:22 volumio sudo[3777]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:22 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:22 volumio go-librespot[3775]: Librespot-go daemon starting... Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:22 volumio go-librespot[3775]: time="2023-11-15T21:12:22+01:00" level=info msg="generated new device id: d4943f7dee4379886b06d2736297e1ad72e7c13e" Nov 15 21:12:22 volumio go-librespot[3775]: time="2023-11-15T21:12:22+01:00" level=fatal msg="unknown credentials: " Nov 15 21:12:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:22 volumio systemd[1]: Reloading. Nov 15 21:12:22 volumio volumio[3593]: Unhandled rejection Error: No sockets available, cannot start. Nov 15 21:12:22 volumio volumio[3593]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 15 21:12:22 volumio volumio[3593]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 15 21:12:22 volumio volumio[3593]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 15 21:12:22 volumio volumio[3593]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 15 21:12:22 volumio volumio[3593]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 15 21:12:22 volumio volumio[3593]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 15 21:12:22 volumio volumio[3593]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 15 21:12:22 volumio volumio[3593]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 15 21:12:22 volumio volumio[3593]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 15 21:12:22 volumio volumio[3593]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 15 21:12:22 volumio volumio[3593]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 15 21:12:22 volumio volumio[3593]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 15 21:12:22 volumio volumio[3593]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 15 21:12:22 volumio volumio[3593]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 15 21:12:22 volumio volumio[3593]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 15 21:12:22 volumio volumio[3593]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 15 21:12:22 volumio volumio[3593]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Nov 15 21:12:22 volumio volumio[3593]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:22 volumio volumio[3593]: info: Reading ALSA contributions from plugins. Nov 15 21:12:22 volumio volumio[3593]: info: MPD Permissions set Nov 15 21:12:22 volumio volumio[3593]: info: Spotify config file written Nov 15 21:12:22 volumio sudo[3802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 15 21:12:22 volumio sudo[3802]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:22 volumio volumio[3593]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:22 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:23 volumio volumio[3593]: info: CoreStateMachine::pushState Nov 15 21:12:23 volumio volumio[3593]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:23 volumio volumio[3593]: info: [squeezelite_mc] Server discovery started Nov 15 21:12:23 volumio volumio[3593]: info: [squeezelite_mc] Player finder started Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:23 volumio volumio[3593]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Nov 15 21:12:23 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 15 21:12:23 volumio volumio[3593]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:23 volumio volumio[3593]: Error: send ENETUNREACH 255.255.255.255:3483 Nov 15 21:12:23 volumio volumio[3593]: at doSend (dgram.js:692:16) Nov 15 21:12:23 volumio volumio[3593]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Nov 15 21:12:23 volumio volumio[3593]: at afterDns (dgram.js:638:5) Nov 15 21:12:23 volumio volumio[3593]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Nov 15 21:12:23 volumio volumio[3593]: errno: -101, Nov 15 21:12:23 volumio volumio[3593]: code: 'ENETUNREACH', Nov 15 21:12:23 volumio volumio[3593]: syscall: 'send', Nov 15 21:12:23 volumio volumio[3593]: address: '255.255.255.255', Nov 15 21:12:23 volumio volumio[3593]: port: 3483 Nov 15 21:12:23 volumio volumio[3593]: } Nov 15 21:12:23 volumio volumio[3593]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:23 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Nov 15 21:12:23 volumio squeezeboxserver[3574]: [23-11-15 21:12:21.8291] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:23 volumio systemd[1]: logitechmediaserver.service: Succeeded. Nov 15 21:12:23 volumio systemd[1]: Stopped Logitech Media Server Daemon. Nov 15 21:12:23 volumio sudo[3777]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:23 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:23 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:23 volumio go-librespot[3818]: Librespot-go daemon starting... Nov 15 21:12:23 volumio systemd[1]: Starting Logitech Media Server Daemon... Nov 15 21:12:23 volumio sudo[3802]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:23 volumio systemd[1]: Started Logitech Media Server Daemon. Nov 15 21:12:23 volumio sudo[3770]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:23 volumio go-librespot[3818]: time="2023-11-15T21:12:23+01:00" level=info msg="generated new device id: eb04827c603143bd45a82f6e48826c978974038c" Nov 15 21:12:23 volumio go-librespot[3818]: time="2023-11-15T21:12:23+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:23 volumio go-librespot[3818]: time="2023-11-15T21:12:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:23 volumio mpd[3768]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:23 volumio mpd[3768]: config: Found database setting without music_directory - disabling database Nov 15 21:12:23 volumio mpd[3768]: output: No 'audio_output' defined in config file Nov 15 21:12:23 volumio mpd[3768]: output: Attempt to detect audio output device Nov 15 21:12:23 volumio mpd[3768]: output: Attempting to detect a alsa audio device Nov 15 21:12:23 volumio mpd[3768]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:23 volumio mpd[3768]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:23 volumio mpd[3768]: output: Attempting to detect a oss audio device Nov 15 21:12:23 volumio mpd[3768]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:23 volumio mpd[3768]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:23 volumio mpd[3768]: output: Attempting to detect a pulse audio device Nov 15 21:12:23 volumio mpd[3768]: output: Attempting to detect a jack audio device Nov 15 21:12:23 volumio mpd[3768]: output: Successfully detected a jack audio device Nov 15 21:12:23 volumio mpd[3768]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:23 volumio mpd[3768]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:23 volumio mpd[3768]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:23 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:23 volumio sudo[3755]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:23 volumio sudo[3832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-11-15 21:11 Nov 15 21:12:23 volumio sudo[3832]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:24 volumio sudo[3832]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:24 volumio volumio-remote-updater[542]: [2023-11-15 21:12:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 15 21:12:24 volumio volumio-remote-updater[542]: [2023-11-15 21:12:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 15 21:12:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 15 21:12:24 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:24 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:24 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 15 21:12:24 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12. Nov 15 21:12:24 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:24 volumio systemd[1]: Stopped Volumio Backend Module. Nov 15 21:12:24 volumio systemd[1]: Started Volumio Backend Module. Nov 15 21:12:24 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:26 volumio volumio[3846]: info: ------------------------------------------- Nov 15 21:12:26 volumio volumio[3846]: info: ----- Volumio3 ---- Nov 15 21:12:26 volumio volumio[3846]: info: ------------------------------------------- Nov 15 21:12:26 volumio volumio[3846]: info: ----- System startup ---- Nov 15 21:12:26 volumio volumio[3846]: info: ------------------------------------------- Nov 15 21:12:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Nov 15 21:12:26 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:26 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:26 volumio go-librespot[3866]: Librespot-go daemon starting... Nov 15 21:12:26 volumio go-librespot[3866]: time="2023-11-15T21:12:26+01:00" level=info msg="generated new device id: 07aa181ebadcd65df905b9ec81f1f3fdf3723372" Nov 15 21:12:26 volumio go-librespot[3866]: time="2023-11-15T21:12:26+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:26 volumio go-librespot[3866]: time="2023-11-15T21:12:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:27 volumio volumio[3846]: info: MYVOLUMIO Environment detected Nov 15 21:12:27 volumio volumio[3846]: info: Plugin folders cleanup Nov 15 21:12:27 volumio volumio[3846]: info: Scanning into folder /volumio/app/plugins/ Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category audio_interface Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category miscellanea Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category music_service Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category plugins.json Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category system_controller Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category user_interface Nov 15 21:12:27 volumio volumio[3846]: info: Scanning into folder /data/plugins/ Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category audio_interface Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category music_service Nov 15 21:12:27 volumio volumio[3846]: info: Scanning category user_interface Nov 15 21:12:27 volumio volumio[3846]: info: Plugin folders cleanup completed Nov 15 21:12:27 volumio volumio[3846]: info: ------------------------------------------- Nov 15 21:12:27 volumio volumio[3846]: info: ----- Core plugins startup ---- Nov 15 21:12:27 volumio volumio[3846]: info: ------------------------------------------- Nov 15 21:12:27 volumio volumio[3846]: info: Loading plugins from folder /volumio/app/plugins/ Nov 15 21:12:27 volumio volumio[3846]: info: Adding plugin upnp to MyMusic Plugins Nov 15 21:12:27 volumio volumio[3846]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 15 21:12:27 volumio volumio[3846]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 15 21:12:27 volumio volumio[3846]: info: Loading plugins from folder /data/plugins/ Nov 15 21:12:27 volumio volumio[3846]: info: Loading plugin "system"... Nov 15 21:12:27 volumio volumio[3846]: info: Loading plugin "appearance"... Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "network"... Nov 15 21:12:28 volumio volumio[3846]: info: Refreshing Cached IP Addresses Nov 15 21:12:28 volumio sudo[3876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:28 volumio sudo[3876]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:28 volumio sudo[3876]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "services"... Nov 15 21:12:28 volumio sudo[3878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:28 volumio sudo[3878]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "alsa_controller"... Nov 15 21:12:28 volumio sudo[3881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 15 21:12:28 volumio sudo[3881]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:28 volumio sudo[3878]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:28 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "wizard"... Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "volumio_command_line_client"... Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "upnp"... Nov 15 21:12:28 volumio volumio[3846]: info: [1700079148376] Starting Upmpd Daemon Nov 15 21:12:28 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "my_music"... Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "mpd"... Nov 15 21:12:28 volumio volumio[3846]: info: Creating MPD Configuration file Nov 15 21:12:28 volumio volumio[3846]: info: Loading plugin "upnp_browser"... Nov 15 21:12:28 volumio sudo[3889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:28 volumio sudo[3889]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:28 volumio sudo[3889]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:28 volumio sudo[3891]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:28 volumio sudo[3891]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:28 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:28 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:28 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:28 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:29 volumio volumio[3846]: info: Loading plugin "networkfs"... Nov 15 21:12:29 volumio volumio-remote-updater[542]: [2023-11-15 21:12:29] [connect] Successful connection Nov 15 21:12:29 volumio volumio[3846]: info: Starting Udev Watcher for removable devices Nov 15 21:12:29 volumio volumio[3846]: info: Ignoring mount for partition: boot Nov 15 21:12:29 volumio volumio[3846]: info: Ignoring mount for partition: volumio Nov 15 21:12:29 volumio volumio[3846]: info: Ignoring mount for partition: volumio_data Nov 15 21:12:29 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:29 volumio volumio[3846]: info: Loading plugin "alarm-clock"... Nov 15 21:12:29 volumio volumio[3846]: info: Loading plugin "airplay_emulation"... Nov 15 21:12:29 volumio volumio[3846]: info: Starting Shairport Sync Nov 15 21:12:29 volumio volumio[3846]: info: Loading plugin "last_100"... Nov 15 21:12:29 volumio volumio[3846]: info: Loading plugin "webradio"... Nov 15 21:12:29 volumio volumio[3846]: info: Loading plugin "i2s_dacs"... Nov 15 21:12:30 volumio volumio[3846]: info: Loading plugin "volumiodiscovery"... Nov 15 21:12:30 volumio volumio[3846]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:30 volumio volumio[3846]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:30 volumio node[3846]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:30 volumio volumio[3846]: *** WARNING *** For more information see Nov 15 21:12:30 volumio volumio[3846]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:30 volumio volumio[3846]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:30 volumio volumio[3846]: *** WARNING *** For more information see Nov 15 21:12:30 volumio node[3846]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:30 volumio node[3846]: *** WARNING *** For more information see Nov 15 21:12:30 volumio node[3846]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:30 volumio node[3846]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:30 volumio node[3846]: *** WARNING *** For more information see Nov 15 21:12:30 volumio volumio[3846]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 15 21:12:30 volumio volumio[3846]: info: Discovery: Started advertising with name: Volumio Nov 15 21:12:30 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:30 volumio volumio[3846]: info: Loading plugin "spop"... Nov 15 21:12:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Nov 15 21:12:30 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:30 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:30 volumio go-librespot[3900]: Librespot-go daemon starting... Nov 15 21:12:30 volumio go-librespot[3900]: time="2023-11-15T21:12:30+01:00" level=info msg="generated new device id: d403b18803c922858d66d0310bcd34d2dc2e4ac2" Nov 15 21:12:30 volumio go-librespot[3900]: time="2023-11-15T21:12:30+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:30 volumio go-librespot[3900]: time="2023-11-15T21:12:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:30 volumio mpd[3896]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:30 volumio mpd[3896]: config: Found database setting without music_directory - disabling database Nov 15 21:12:30 volumio mpd[3896]: output: No 'audio_output' defined in config file Nov 15 21:12:30 volumio mpd[3896]: output: Attempt to detect audio output device Nov 15 21:12:30 volumio mpd[3896]: output: Attempting to detect a alsa audio device Nov 15 21:12:30 volumio mpd[3896]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:30 volumio mpd[3896]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:30 volumio mpd[3896]: output: Attempting to detect a oss audio device Nov 15 21:12:30 volumio mpd[3896]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:30 volumio mpd[3896]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:30 volumio mpd[3896]: output: Attempting to detect a pulse audio device Nov 15 21:12:30 volumio mpd[3896]: output: Attempting to detect a jack audio device Nov 15 21:12:30 volumio mpd[3896]: output: Successfully detected a jack audio device Nov 15 21:12:30 volumio mpd[3896]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:30 volumio mpd[3896]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:30 volumio mpd[3896]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:30 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:30 volumio sudo[3891]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:31 volumio volumio[3846]: info: Loading plugin "squeezelite_mc"... Nov 15 21:12:31 volumio sudo[3881]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:31 volumio volumio[3846]: info: Loading plugin "youtube2"... Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:27.0716] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:27.6660] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7046] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7055] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7064] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7125] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7149] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7166] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7198] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7281] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.7320] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:32 volumio squeezeboxserver[3825]: [23-11-15 21:12:31.9850] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Nov 15 21:12:33 volumio volumio[3846]: info: Loading plugin "ytmusic"... Nov 15 21:12:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Nov 15 21:12:33 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:33 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:33 volumio go-librespot[3912]: Librespot-go daemon starting... Nov 15 21:12:33 volumio go-librespot[3912]: time="2023-11-15T21:12:33+01:00" level=info msg="generated new device id: 51fec8e9f1aa6fa7c2442ba641b301d654822708" Nov 15 21:12:33 volumio go-librespot[3912]: time="2023-11-15T21:12:33+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:33 volumio go-librespot[3912]: time="2023-11-15T21:12:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:34 volumio squeezeboxserver[3825]: [23-11-15 21:12:34.0985] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "outputs"... Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "albumart"... Nov 15 21:12:34 volumio volumio[3846]: info: Plugin example_plugin is not enabled Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "inputs"... Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "updater_comm"... Nov 15 21:12:34 volumio volumio[3846]: info: Plugin mpdemulation is not enabled Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "rest_api"... Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "websocket"... Nov 15 21:12:34 volumio volumio[3846]: info: Loading plugin "fusiondsp"... Nov 15 21:12:34 volumio volumio[3846]: Forking 3 albumart workers Nov 15 21:12:35 volumio volumio[3846]: info: Applying required configuration parameters for plugin fusiondsp Nov 15 21:12:35 volumio volumio[3846]: info: Loading plugin "80s80s"... Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.3409] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4638] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4652] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4691] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4781] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4799] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4812] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4831] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4870] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4885] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.4932] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6364] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6398] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6430] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6551] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6790] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6807] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.198 seconds. Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6828] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6869] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.004 seconds. Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6917] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6930] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.003 seconds. Nov 15 21:12:35 volumio squeezeboxserver[3825]: [23-11-15 21:12:35.6952] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Nov 15 21:12:35 volumio volumio[3846]: info: Applying required configuration parameters for plugin 80s80s Nov 15 21:12:35 volumio volumio[3846]: info: [1700079155781] [80s80s] API delay: 30 Nov 15 21:12:35 volumio volumio[3846]: info: Loading plugin "lms"... Nov 15 21:12:35 volumio volumio[3846]: info: Loading plugin "motherearthradio"... Nov 15 21:12:36 volumio volumio[3846]: Starting albumart workers Nov 15 21:12:36 volumio squeezeboxserver[3825]: [23-11-15 21:12:36.0642] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 0.368 seconds. Nov 15 21:12:36 volumio volumio[3846]: Starting albumart workers Nov 15 21:12:36 volumio volumio[3846]: info: Applying required configuration parameters for plugin motherearthradio Nov 15 21:12:36 volumio volumio[3846]: info: [1700079156235] [MotherEarth] API delay: 5 Nov 15 21:12:36 volumio volumio[3846]: info: Loading plugin "rad357pl"... Nov 15 21:12:36 volumio volumio[3846]: Starting albumart workers Nov 15 21:12:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Nov 15 21:12:36 volumio volumio[3846]: info: Applying required configuration parameters for plugin rad357pl Nov 15 21:12:36 volumio volumio[3846]: info: [1700079156648] [rad357pl] API delay: 5 Nov 15 21:12:36 volumio volumio[3846]: info: Loading plugin "radio_paradise"... Nov 15 21:12:36 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:36 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:36 volumio go-librespot[3947]: Librespot-go daemon starting... Nov 15 21:12:36 volumio go-librespot[3947]: time="2023-11-15T21:12:36+01:00" level=info msg="generated new device id: cf58877f0ffda7e85e01d9290373ba53e5277b2c" Nov 15 21:12:36 volumio go-librespot[3947]: time="2023-11-15T21:12:36+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:36 volumio go-librespot[3947]: time="2023-11-15T21:12:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:36 volumio volumio[3846]: info: Applying required configuration parameters for plugin radio_paradise Nov 15 21:12:36 volumio volumio[3846]: info: [1700079156938] [RadioParadise] API delay: 5 Nov 15 21:12:36 volumio volumio[3846]: info: Loading plugin "lastfm"... Nov 15 21:12:37 volumio volumio[3846]: info: Loading plugin "touch_display"... Nov 15 21:12:37 volumio volumio[3846]: info: Applying required configuration parameters for plugin touch_display Nov 15 21:12:37 volumio volumio[3846]: info: Loading i18n strings for locale pl Nov 15 21:12:37 volumio volumio[3846]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:37 volumio volumio[3846]: Updating browse sources language Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::initPlayerControls Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:37 volumio volumio[3846]: Express server listening on port 3000 Nov 15 21:12:37 volumio volumio[3846]: [Metrics] WebUI: 12s 210.27ms Nov 15 21:12:37 volumio volumio[3846]: info: CoreStateMachine::resetVolumioState Nov 15 21:12:37 volumio volumio[3846]: info: CoreStateMachine::getcurrentVolume Nov 15 21:12:37 volumio volumio[3846]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:37 volumio mpd[3896]: client: [0] opened from local Nov 15 21:12:38 volumio volumio[3846]: info: MPD Permissions set Nov 15 21:12:38 volumio volumio[3846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Nov 15 21:12:38 volumio volumio[3846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 15 21:12:38 volumio volumio[3846]: info: MPD running with PID3896 Nov 15 21:12:38 volumio volumio[3846]: ,establishing connection Nov 15 21:12:38 volumio mpd[3896]: client: [1] opened from local Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: Reloading queue from file Nov 15 21:12:38 volumio volumio[3846]: error: updateQueue error: null Nov 15 21:12:38 volumio volumio[3846]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::pushState Nov 15 21:12:38 volumio volumio[3846]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::updateTrackBlock Nov 15 21:12:38 volumio volumio[3846]: info: CorePlayQueue::getTrackBlock Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:38 volumio volumio[3846]: info: Setting Device type: Raspberry PI Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::setRepeat false single undefined Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::pushState Nov 15 21:12:38 volumio volumio[3846]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::setRandom null Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::pushState Nov 15 21:12:38 volumio volumio[3846]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:38 volumio volumio[3846]: info: Completed loading Core Plugins Nov 15 21:12:38 volumio volumio[3846]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:38 volumio volumio[3846]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:38 volumio volumio[3846]: info: Reading ALSA contributions from plugins. Nov 15 21:12:38 volumio volumio[3846]: error: updateQueue error: null Nov 15 21:12:38 volumio sudo[3996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:38 volumio sudo[3996]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:38 volumio sudo[3996]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:38 volumio sudo[3998]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:38 volumio sudo[3998]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:38 volumio sudo[3998]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:38 volumio volumio[3846]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:38 volumio volumio[3846]: info: CoreStateMachine::pushState Nov 15 21:12:38 volumio volumio[3846]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:38 volumio volumio[3846]: info: Asound.conf file unchanged, so no further update is needed Nov 15 21:12:38 volumio volumio[3846]: info: Output device has changed, restarting MPD Nov 15 21:12:38 volumio sudo[4002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 15 21:12:38 volumio sudo[4002]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:38 volumio sudo[4002]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:38 volumio sudo[4005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:38 volumio volumio[3846]: info: Output device has changed, restarting Shairport Sync Nov 15 21:12:38 volumio sudo[4005]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:38 volumio sudo[4005]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:38 volumio sudo[4007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:38 volumio sudo[4007]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:38 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:38 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:38 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:38 volumio volumio[3846]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:38 volumio volumio[3846]: info: ___________ START PLUGINS ___________ Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:38 volumio volumio[3846]: info: [1700079158742] CoreMusicLibrary::Adding element Media Servers Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:38 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:38 volumio volumio[3846]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:38 volumio volumio[3846]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:38 volumio volumio[3846]: info: [1700079158894] CoreMusicLibrary::Adding element Last_100 Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:38 volumio volumio[3846]: info: [1700079158900] CoreMusicLibrary::Adding element Webradio Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:38 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:38 volumio volumio[3846]: info: Creating Spotify config file Nov 15 21:12:39 volumio volumio[3846]: info: [squeezelite_mc] Starting proxy server... Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159033] CoreMusicLibrary::Adding element YouTube2 Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159048] CoreMusicLibrary::Adding element YouTube Music Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube Music Nov 15 21:12:39 volumio volumio[3846]: info: Loading i18n strings for locale pl Nov 15 21:12:39 volumio volumio[3846]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: FusionDsp - mixtype--------------------- Hardware Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159076] CoreMusicLibrary::Adding element 80s80s Radio Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube Music Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source 80s80s Radio Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159104] CoreMusicLibrary::Adding element Mother Earth Radio Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube Music Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source 80s80s Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:39 volumio sudo[4023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Nov 15 21:12:39 volumio sudo[4023]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159136] CoreMusicLibrary::Adding element RADIO 357 Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube Music Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source 80s80s Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source RADIO 357 Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159145] CoreMusicLibrary::Adding element Radio Paradise Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube Music Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source 80s80s Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source RADIO 357 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source Radio Paradise Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:39 volumio volumio[3846]: info: [1700079159152] CoreMusicLibrary::Adding element LastFM Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube2 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source YouTube Music Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source 80s80s Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source RADIO 357 Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source Radio Paradise Nov 15 21:12:39 volumio volumio[3846]: Cannot find translation for source LastFM Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] scrobbler initiated! Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] extended logging: false Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] try scrobble stream/radio plays: true Nov 15 21:12:39 volumio systemd[1]: Stopping Logitech Media Server Daemon... Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] Left init routine Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] Socket already connected: true Nov 15 21:12:39 volumio volumio[3846]: info: Loading i18n strings for locale pl Nov 15 21:12:39 volumio volumio[3846]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:39 volumio volumio[3846]: info: Volumio Calling Home Nov 15 21:12:39 volumio volumio[3846]: info: [squeezelite_mc] Proxy server started on port 44027 Nov 15 21:12:39 volumio volumio[3846]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:39 volumio volumio[3846]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:39 volumio sudo[4029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 15 21:12:39 volumio sudo[4029]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:39 volumio systemd[1]: Reloading. Nov 15 21:12:39 volumio volumio[3846]: Unhandled rejection Error: No sockets available, cannot start. Nov 15 21:12:39 volumio volumio[3846]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 15 21:12:39 volumio volumio[3846]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 15 21:12:39 volumio volumio[3846]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 15 21:12:39 volumio volumio[3846]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 15 21:12:39 volumio volumio[3846]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 15 21:12:39 volumio volumio[3846]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 15 21:12:39 volumio volumio[3846]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 15 21:12:39 volumio volumio[3846]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 15 21:12:39 volumio volumio[3846]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 15 21:12:39 volumio volumio[3846]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 15 21:12:39 volumio volumio[3846]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 15 21:12:39 volumio volumio[3846]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 15 21:12:39 volumio volumio[3846]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 15 21:12:39 volumio volumio[3846]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 15 21:12:39 volumio volumio[3846]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 15 21:12:39 volumio volumio[3846]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 15 21:12:39 volumio volumio[3846]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Nov 15 21:12:39 volumio volumio[3846]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:39 volumio volumio[3846]: info: Reading ALSA contributions from plugins. Nov 15 21:12:39 volumio volumio[3846]: info: MPD Permissions set Nov 15 21:12:39 volumio volumio[3846]: info: Upmpdcli Daemon Started Nov 15 21:12:39 volumio ntpd[672]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Nov 15 21:12:39 volumio volumio[3846]: info: Spotify config file written Nov 15 21:12:39 volumio sudo[4046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 15 21:12:39 volumio sudo[4046]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:39 volumio volumio[3846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:39 volumio volumio[3846]: info: CoreStateMachine::pushState Nov 15 21:12:39 volumio volumio[3846]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:39 volumio volumio[3846]: info: [squeezelite_mc] Server discovery started Nov 15 21:12:39 volumio volumio[3846]: info: [squeezelite_mc] Player finder started Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:39 volumio volumio[3846]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Nov 15 21:12:39 volumio volumio[3846]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:39 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 15 21:12:39 volumio volumio[3846]: Error: send ENETUNREACH 255.255.255.255:3483 Nov 15 21:12:39 volumio volumio[3846]: at doSend (dgram.js:692:16) Nov 15 21:12:39 volumio volumio[3846]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Nov 15 21:12:39 volumio volumio[3846]: at afterDns (dgram.js:638:5) Nov 15 21:12:39 volumio volumio[3846]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Nov 15 21:12:39 volumio volumio[3846]: errno: -101, Nov 15 21:12:39 volumio volumio[3846]: code: 'ENETUNREACH', Nov 15 21:12:39 volumio volumio[3846]: syscall: 'send', Nov 15 21:12:39 volumio volumio[3846]: address: '255.255.255.255', Nov 15 21:12:39 volumio volumio[3846]: port: 3483 Nov 15 21:12:39 volumio volumio[3846]: } Nov 15 21:12:39 volumio volumio[3846]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:39 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Nov 15 21:12:40 volumio squeezeboxserver[3825]: [23-11-15 21:12:38.8438] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:40 volumio systemd[1]: logitechmediaserver.service: Succeeded. Nov 15 21:12:40 volumio sudo[4029]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:40 volumio systemd[1]: Stopped Logitech Media Server Daemon. Nov 15 21:12:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Nov 15 21:12:40 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:40 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:40 volumio systemd[1]: Starting Logitech Media Server Daemon... Nov 15 21:12:40 volumio go-librespot[4063]: Librespot-go daemon starting... Nov 15 21:12:40 volumio sudo[4046]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:40 volumio systemd[1]: Started Logitech Media Server Daemon. Nov 15 21:12:40 volumio go-librespot[4063]: time="2023-11-15T21:12:40+01:00" level=info msg="generated new device id: f4d430863237822c02ee5eda77e3f6d649c80ad3" Nov 15 21:12:40 volumio go-librespot[4063]: time="2023-11-15T21:12:40+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:40 volumio go-librespot[4063]: time="2023-11-15T21:12:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:40 volumio sudo[4023]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:40 volumio mpd[4021]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:40 volumio mpd[4021]: config: Found database setting without music_directory - disabling database Nov 15 21:12:40 volumio mpd[4021]: output: No 'audio_output' defined in config file Nov 15 21:12:40 volumio mpd[4021]: output: Attempt to detect audio output device Nov 15 21:12:40 volumio mpd[4021]: output: Attempting to detect a alsa audio device Nov 15 21:12:40 volumio mpd[4021]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:40 volumio mpd[4021]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:40 volumio mpd[4021]: output: Attempting to detect a oss audio device Nov 15 21:12:40 volumio mpd[4021]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:40 volumio mpd[4021]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:40 volumio mpd[4021]: output: Attempting to detect a pulse audio device Nov 15 21:12:40 volumio mpd[4021]: output: Attempting to detect a jack audio device Nov 15 21:12:40 volumio mpd[4021]: output: Successfully detected a jack audio device Nov 15 21:12:40 volumio mpd[4021]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:40 volumio mpd[4021]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:40 volumio ntpd[672]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Nov 15 21:12:40 volumio ntpd[672]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Nov 15 21:12:40 volumio mpd[4021]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:40 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:40 volumio sudo[4007]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:40 volumio sudo[4077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-11-15 21:11 Nov 15 21:12:40 volumio sudo[4077]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:40 volumio sudo[4077]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:40 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:40 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 15 21:12:40 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:40 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:41 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 15 21:12:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13. Nov 15 21:12:41 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:41 volumio systemd[1]: Stopped Volumio Backend Module. Nov 15 21:12:41 volumio systemd[1]: Started Volumio Backend Module. Nov 15 21:12:41 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:41 volumio ntpd[672]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Nov 15 21:12:41 volumio volumio-remote-updater[542]: [2023-11-15 21:12:41] [info] asio async_connect error: system:111 (Connection refused) Nov 15 21:12:41 volumio volumio-remote-updater[542]: [2023-11-15 21:12:41] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Nov 15 21:12:41 volumio volumio-remote-updater[542]: [2023-11-15 21:12:41] [error] handle_connect error: Underlying Transport Error Nov 15 21:12:43 volumio volumio[4091]: info: ------------------------------------------- Nov 15 21:12:43 volumio volumio[4091]: info: ----- Volumio3 ---- Nov 15 21:12:43 volumio volumio[4091]: info: ------------------------------------------- Nov 15 21:12:43 volumio volumio[4091]: info: ----- System startup ---- Nov 15 21:12:43 volumio volumio[4091]: info: ------------------------------------------- Nov 15 21:12:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Nov 15 21:12:43 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:43 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:43 volumio go-librespot[4111]: Librespot-go daemon starting... Nov 15 21:12:43 volumio go-librespot[4111]: time="2023-11-15T21:12:43+01:00" level=info msg="generated new device id: c8425d1ff6b35226fd3ef9a7fc83e551ae8c928e" Nov 15 21:12:43 volumio go-librespot[4111]: time="2023-11-15T21:12:43+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:43 volumio go-librespot[4111]: time="2023-11-15T21:12:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:43 volumio volumio[4091]: info: MYVOLUMIO Environment detected Nov 15 21:12:43 volumio volumio[4091]: info: Plugin folders cleanup Nov 15 21:12:43 volumio volumio[4091]: info: Scanning into folder /volumio/app/plugins/ Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category audio_interface Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category miscellanea Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category music_service Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category plugins.json Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category system_controller Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category user_interface Nov 15 21:12:43 volumio volumio[4091]: info: Scanning into folder /data/plugins/ Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category audio_interface Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category music_service Nov 15 21:12:43 volumio volumio[4091]: info: Scanning category user_interface Nov 15 21:12:43 volumio volumio[4091]: info: Plugin folders cleanup completed Nov 15 21:12:43 volumio volumio[4091]: info: ------------------------------------------- Nov 15 21:12:43 volumio volumio[4091]: info: ----- Core plugins startup ---- Nov 15 21:12:43 volumio volumio[4091]: info: ------------------------------------------- Nov 15 21:12:43 volumio volumio[4091]: info: Loading plugins from folder /volumio/app/plugins/ Nov 15 21:12:43 volumio volumio[4091]: info: Adding plugin upnp to MyMusic Plugins Nov 15 21:12:43 volumio volumio[4091]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 15 21:12:43 volumio volumio[4091]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 15 21:12:43 volumio volumio[4091]: info: Loading plugins from folder /data/plugins/ Nov 15 21:12:44 volumio volumio[4091]: info: Loading plugin "system"... Nov 15 21:12:44 volumio volumio[4091]: info: Loading plugin "appearance"... Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "network"... Nov 15 21:12:45 volumio volumio[4091]: info: Refreshing Cached IP Addresses Nov 15 21:12:45 volumio sudo[4121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:45 volumio sudo[4121]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:45 volumio sudo[4121]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:45 volumio sudo[4123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:45 volumio sudo[4123]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "services"... Nov 15 21:12:45 volumio sudo[4123]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "alsa_controller"... Nov 15 21:12:45 volumio sudo[4126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 15 21:12:45 volumio sudo[4126]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:45 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "wizard"... Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "volumio_command_line_client"... Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "upnp"... Nov 15 21:12:45 volumio volumio[4091]: info: [1700079165219] Starting Upmpd Daemon Nov 15 21:12:45 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "my_music"... Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "mpd"... Nov 15 21:12:45 volumio volumio[4091]: info: Creating MPD Configuration file Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "upnp_browser"... Nov 15 21:12:45 volumio sudo[4134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:45 volumio sudo[4134]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:45 volumio sudo[4134]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:45 volumio sudo[4136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:45 volumio sudo[4136]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:45 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:45 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:45 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:45 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:45 volumio volumio[4091]: info: Loading plugin "networkfs"... Nov 15 21:12:46 volumio volumio[4091]: info: Starting Udev Watcher for removable devices Nov 15 21:12:46 volumio volumio[4091]: info: Ignoring mount for partition: boot Nov 15 21:12:46 volumio volumio[4091]: info: Ignoring mount for partition: volumio Nov 15 21:12:46 volumio volumio[4091]: info: Ignoring mount for partition: volumio_data Nov 15 21:12:46 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "alarm-clock"... Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "airplay_emulation"... Nov 15 21:12:46 volumio volumio[4091]: info: Starting Shairport Sync Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "last_100"... Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "webradio"... Nov 15 21:12:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Nov 15 21:12:46 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "i2s_dacs"... Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "volumiodiscovery"... Nov 15 21:12:46 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:46 volumio go-librespot[4143]: Librespot-go daemon starting... Nov 15 21:12:46 volumio volumio[4091]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:46 volumio volumio[4091]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:46 volumio volumio[4091]: *** WARNING *** For more information see Nov 15 21:12:46 volumio volumio[4091]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:46 volumio volumio[4091]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:46 volumio volumio[4091]: *** WARNING *** For more information see Nov 15 21:12:46 volumio node[4091]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:46 volumio node[4091]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:46 volumio node[4091]: *** WARNING *** For more information see Nov 15 21:12:46 volumio node[4091]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:12:46 volumio node[4091]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:12:46 volumio node[4091]: *** WARNING *** For more information see Nov 15 21:12:46 volumio volumio[4091]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 15 21:12:46 volumio volumio[4091]: info: Discovery: Started advertising with name: Volumio Nov 15 21:12:46 volumio go-librespot[4143]: time="2023-11-15T21:12:46+01:00" level=info msg="generated new device id: 65ffc14de906027fe927df93287ef7b935a93152" Nov 15 21:12:46 volumio go-librespot[4143]: time="2023-11-15T21:12:46+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:46 volumio go-librespot[4143]: time="2023-11-15T21:12:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:46 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:12:46 volumio volumio[4091]: info: Loading plugin "spop"... Nov 15 21:12:47 volumio mpd[4141]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:47 volumio mpd[4141]: config: Found database setting without music_directory - disabling database Nov 15 21:12:47 volumio mpd[4141]: output: No 'audio_output' defined in config file Nov 15 21:12:47 volumio mpd[4141]: output: Attempt to detect audio output device Nov 15 21:12:47 volumio mpd[4141]: output: Attempting to detect a alsa audio device Nov 15 21:12:47 volumio mpd[4141]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:47 volumio mpd[4141]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:47 volumio mpd[4141]: output: Attempting to detect a oss audio device Nov 15 21:12:47 volumio mpd[4141]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:47 volumio mpd[4141]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:47 volumio mpd[4141]: output: Attempting to detect a pulse audio device Nov 15 21:12:47 volumio mpd[4141]: output: Attempting to detect a jack audio device Nov 15 21:12:47 volumio mpd[4141]: output: Successfully detected a jack audio device Nov 15 21:12:47 volumio mpd[4141]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:47 volumio mpd[4141]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:47 volumio mpd[4141]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:47 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:47 volumio sudo[4136]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:48 volumio volumio[4091]: info: Loading plugin "squeezelite_mc"... Nov 15 21:12:48 volumio sudo[4126]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:43.7686] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:44.3634] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4777] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4789] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4798] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4865] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4890] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4909] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.4943] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.5031] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.5073] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:48 volumio squeezeboxserver[4072]: [23-11-15 21:12:48.7721] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Nov 15 21:12:48 volumio volumio[4091]: info: Loading plugin "youtube2"... Nov 15 21:12:50 volumio volumio[4091]: info: Loading plugin "ytmusic"... Nov 15 21:12:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Nov 15 21:12:50 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:50 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:50 volumio go-librespot[4156]: Librespot-go daemon starting... Nov 15 21:12:50 volumio go-librespot[4156]: time="2023-11-15T21:12:50+01:00" level=info msg="generated new device id: 39d84a8ffd875e3762c1d362543be9dcc12edaf8" Nov 15 21:12:50 volumio go-librespot[4156]: time="2023-11-15T21:12:50+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:50 volumio go-librespot[4156]: time="2023-11-15T21:12:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:50 volumio squeezeboxserver[4072]: [23-11-15 21:12:50.8047] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "outputs"... Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "albumart"... Nov 15 21:12:51 volumio volumio[4091]: info: Plugin example_plugin is not enabled Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "inputs"... Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "updater_comm"... Nov 15 21:12:51 volumio volumio[4091]: info: Plugin mpdemulation is not enabled Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "rest_api"... Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "websocket"... Nov 15 21:12:51 volumio volumio[4091]: info: Loading plugin "fusiondsp"... Nov 15 21:12:51 volumio volumio-remote-updater[542]: [2023-11-15 21:12:51] [connect] Successful connection Nov 15 21:12:51 volumio volumio[4091]: info: Applying required configuration parameters for plugin fusiondsp Nov 15 21:12:51 volumio volumio[4091]: Forking 3 albumart workers Nov 15 21:12:51 volumio squeezeboxserver[4072]: [23-11-15 21:12:51.9049] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:51 volumio squeezeboxserver[4072]: [23-11-15 21:12:51.9978] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Nov 15 21:12:51 volumio squeezeboxserver[4072]: [23-11-15 21:12:51.9994] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.002 seconds. Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0028] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Nov 15 21:12:52 volumio volumio[4091]: info: Loading plugin "80s80s"... Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0206] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0222] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0235] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0255] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0287] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0299] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.0344] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.1682] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.1715] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.1744] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.1853] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2057] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2074] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.182 seconds. Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2098] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2139] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.004 seconds. Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2187] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2201] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.003 seconds. Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.2224] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Nov 15 21:12:52 volumio volumio[4091]: info: Applying required configuration parameters for plugin 80s80s Nov 15 21:12:52 volumio volumio[4091]: info: [1700079172464] [80s80s] API delay: 30 Nov 15 21:12:52 volumio volumio[4091]: info: Loading plugin "lms"... Nov 15 21:12:52 volumio squeezeboxserver[4072]: [23-11-15 21:12:52.5960] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 0.372 seconds. Nov 15 21:12:52 volumio volumio[4091]: info: Loading plugin "motherearthradio"... Nov 15 21:12:52 volumio volumio[4091]: info: Applying required configuration parameters for plugin motherearthradio Nov 15 21:12:52 volumio volumio[4091]: info: [1700079172892] [MotherEarth] API delay: 5 Nov 15 21:12:52 volumio volumio[4091]: info: Loading plugin "rad357pl"... Nov 15 21:12:52 volumio volumio[4091]: Starting albumart workers Nov 15 21:12:52 volumio volumio[4091]: Starting albumart workers Nov 15 21:12:53 volumio volumio[4091]: Starting albumart workers Nov 15 21:12:53 volumio volumio[4091]: info: Applying required configuration parameters for plugin rad357pl Nov 15 21:12:53 volumio volumio[4091]: info: [1700079173159] [rad357pl] API delay: 5 Nov 15 21:12:53 volumio volumio[4091]: info: Loading plugin "radio_paradise"... Nov 15 21:12:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Nov 15 21:12:53 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:53 volumio volumio[4091]: info: Applying required configuration parameters for plugin radio_paradise Nov 15 21:12:53 volumio volumio[4091]: info: [1700079173443] [RadioParadise] API delay: 5 Nov 15 21:12:53 volumio volumio[4091]: info: Loading plugin "lastfm"... Nov 15 21:12:53 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:53 volumio go-librespot[4191]: Librespot-go daemon starting... Nov 15 21:12:53 volumio go-librespot[4191]: time="2023-11-15T21:12:53+01:00" level=info msg="generated new device id: 1a345e018131aeafb20602d8b2ad568a26f68577" Nov 15 21:12:53 volumio go-librespot[4191]: time="2023-11-15T21:12:53+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:53 volumio go-librespot[4191]: time="2023-11-15T21:12:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:54 volumio volumio[4091]: info: Loading plugin "touch_display"... Nov 15 21:12:54 volumio volumio[4091]: info: Applying required configuration parameters for plugin touch_display Nov 15 21:12:54 volumio volumio[4091]: info: Loading i18n strings for locale pl Nov 15 21:12:54 volumio volumio[4091]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:54 volumio volumio[4091]: Updating browse sources language Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::initPlayerControls Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: Express server listening on port 3000 Nov 15 21:12:54 volumio volumio[4091]: [Metrics] WebUI: 12s 99.94ms Nov 15 21:12:54 volumio volumio[4091]: info: CoreStateMachine::resetVolumioState Nov 15 21:12:54 volumio volumio[4091]: info: CoreStateMachine::getcurrentVolume Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:54 volumio mpd[4141]: client: [0] opened from local Nov 15 21:12:54 volumio volumio[4091]: info: MPD Permissions set Nov 15 21:12:54 volumio volumio-remote-updater[542]: [2023-11-15 21:12:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1700079171 101 Nov 15 21:12:54 volumio volumio[4091]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Nov 15 21:12:54 volumio volumio[4091]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 15 21:12:54 volumio volumio[4091]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 15 21:12:54 volumio volumio[4091]: info: MPD running with PID4141 Nov 15 21:12:54 volumio volumio[4091]: ,establishing connection Nov 15 21:12:54 volumio mpd[4141]: client: [1] opened from local Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:54 volumio volumio[4091]: info: Reloading queue from file Nov 15 21:12:54 volumio volumio[4091]: error: updateQueue error: null Nov 15 21:12:54 volumio volumio[4091]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:54 volumio volumio[4091]: info: CoreStateMachine::pushState Nov 15 21:12:55 volumio volumio[4091]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:55 volumio volumio[4091]: info: CoreStateMachine::updateTrackBlock Nov 15 21:12:55 volumio volumio[4091]: info: CorePlayQueue::getTrackBlock Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:55 volumio volumio[4091]: info: CoreStateMachine::setRepeat false single undefined Nov 15 21:12:55 volumio volumio[4091]: info: CoreStateMachine::pushState Nov 15 21:12:55 volumio volumio[4091]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:55 volumio volumio[4091]: info: CoreStateMachine::setRandom null Nov 15 21:12:55 volumio volumio[4091]: info: CoreStateMachine::pushState Nov 15 21:12:55 volumio volumio[4091]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:55 volumio volumio[4091]: info: Setting Device type: Raspberry PI Nov 15 21:12:55 volumio volumio[4091]: info: Completed loading Core Plugins Nov 15 21:12:55 volumio volumio[4091]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:55 volumio volumio[4091]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:55 volumio volumio[4091]: info: Reading ALSA contributions from plugins. Nov 15 21:12:55 volumio volumio[4091]: error: updateQueue error: null Nov 15 21:12:55 volumio volumio[4091]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:55 volumio volumio[4091]: info: CoreStateMachine::pushState Nov 15 21:12:55 volumio volumio[4091]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:55 volumio sudo[4240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:12:55 volumio sudo[4240]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:55 volumio sudo[4240]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:55 volumio sudo[4243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:12:55 volumio sudo[4243]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:55 volumio sudo[4243]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:55 volumio volumio[4091]: info: Asound.conf file unchanged, so no further update is needed Nov 15 21:12:55 volumio volumio[4091]: info: Output device has changed, restarting MPD Nov 15 21:12:55 volumio sudo[4246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:12:55 volumio sudo[4246]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:55 volumio volumio[4091]: info: Output device has changed, restarting Shairport Sync Nov 15 21:12:55 volumio sudo[4246]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:55 volumio sudo[4249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:12:55 volumio sudo[4249]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:55 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:12:55 volumio volumio[4091]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:55 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:12:55 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:12:55 volumio volumio[4091]: info: ___________ START PLUGINS ___________ Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175450] CoreMusicLibrary::Adding element Media Servers Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:55 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:12:55 volumio volumio[4091]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:55 volumio volumio[4091]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175583] CoreMusicLibrary::Adding element Last_100 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175588] CoreMusicLibrary::Adding element Webradio Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:55 volumio volumio[4091]: info: Creating Spotify config file Nov 15 21:12:55 volumio volumio[4091]: info: [squeezelite_mc] Starting proxy server... Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175713] CoreMusicLibrary::Adding element YouTube2 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175723] CoreMusicLibrary::Adding element YouTube Music Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube Music Nov 15 21:12:55 volumio volumio[4091]: info: Loading i18n strings for locale pl Nov 15 21:12:55 volumio volumio[4091]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:55 volumio volumio[4091]: info: FusionDsp - mixtype--------------------- Hardware Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175772] CoreMusicLibrary::Adding element 80s80s Radio Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube Music Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source 80s80s Radio Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175803] CoreMusicLibrary::Adding element Mother Earth Radio Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube Music Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source 80s80s Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175814] CoreMusicLibrary::Adding element RADIO 357 Nov 15 21:12:55 volumio sudo[4264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Nov 15 21:12:55 volumio sudo[4264]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube Music Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source 80s80s Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source RADIO 357 Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175828] CoreMusicLibrary::Adding element Radio Paradise Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube Music Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source 80s80s Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source RADIO 357 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source Radio Paradise Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:12:55 volumio volumio[4091]: info: [1700079175836] CoreMusicLibrary::Adding element LastFM Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube2 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source YouTube Music Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source 80s80s Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source Mother Earth Radio Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source RADIO 357 Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source Radio Paradise Nov 15 21:12:55 volumio volumio[4091]: Cannot find translation for source LastFM Nov 15 21:12:55 volumio volumio[4091]: info: [LastFM] scrobbler initiated! Nov 15 21:12:55 volumio volumio[4091]: info: [LastFM] extended logging: false Nov 15 21:12:55 volumio volumio[4091]: info: [LastFM] try scrobble stream/radio plays: true Nov 15 21:12:55 volumio systemd[1]: Stopping Logitech Media Server Daemon... Nov 15 21:12:55 volumio volumio[4091]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:55 volumio volumio[4091]: info: [LastFM] Left init routine Nov 15 21:12:55 volumio volumio[4091]: info: [LastFM] Socket already connected: true Nov 15 21:12:55 volumio volumio[4091]: info: Loading i18n strings for locale pl Nov 15 21:12:55 volumio volumio[4091]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:12:55 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:12:55 volumio volumio[4091]: info: Volumio Calling Home Nov 15 21:12:55 volumio volumio[4091]: info: [squeezelite_mc] Proxy server started on port 43307 Nov 15 21:12:55 volumio volumio[4091]: info: Preparing to generate the ALSA configuration file Nov 15 21:12:56 volumio volumio[4091]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:12:56 volumio sudo[4270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 15 21:12:56 volumio sudo[4270]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:12:56 volumio systemd[1]: Reloading. Nov 15 21:12:56 volumio volumio[4091]: Unhandled rejection Error: No sockets available, cannot start. Nov 15 21:12:56 volumio volumio[4091]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 15 21:12:56 volumio volumio[4091]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 15 21:12:56 volumio volumio[4091]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 15 21:12:56 volumio volumio[4091]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 15 21:12:56 volumio volumio[4091]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 15 21:12:56 volumio volumio[4091]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 15 21:12:56 volumio volumio[4091]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 15 21:12:56 volumio volumio[4091]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 15 21:12:56 volumio volumio[4091]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 15 21:12:56 volumio volumio[4091]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 15 21:12:56 volumio volumio[4091]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 15 21:12:56 volumio volumio[4091]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 15 21:12:56 volumio volumio[4091]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 15 21:12:56 volumio volumio[4091]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 15 21:12:56 volumio volumio[4091]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 15 21:12:56 volumio volumio[4091]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 15 21:12:56 volumio volumio[4091]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Nov 15 21:12:56 volumio volumio[4091]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:12:56 volumio volumio[4091]: info: Reading ALSA contributions from plugins. Nov 15 21:12:56 volumio volumio[4091]: info: MPD Permissions set Nov 15 21:12:56 volumio volumio[4091]: info: Spotify config file written Nov 15 21:12:56 volumio sudo[4274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 15 21:12:56 volumio sudo[4274]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:56 volumio sudo[4288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 15 21:12:56 volumio sudo[4288]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:56 volumio volumio[4091]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:12:56 volumio volumio[4091]: info: CoreStateMachine::pushState Nov 15 21:12:56 volumio volumio[4091]: info: CorePlayQueue::getTrack 0 Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::volumioPushState Nov 15 21:12:56 volumio volumio[4091]: info: [squeezelite_mc] Server discovery started Nov 15 21:12:56 volumio volumio[4091]: info: [squeezelite_mc] Player finder started Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:12:56 volumio volumio[4091]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Nov 15 21:12:56 volumio volumio[4091]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:56 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 15 21:12:56 volumio volumio[4091]: Error: send ENETUNREACH 255.255.255.255:3483 Nov 15 21:12:56 volumio volumio[4091]: at doSend (dgram.js:692:16) Nov 15 21:12:56 volumio volumio[4091]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Nov 15 21:12:56 volumio volumio[4091]: at afterDns (dgram.js:638:5) Nov 15 21:12:56 volumio volumio[4091]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Nov 15 21:12:56 volumio volumio[4091]: errno: -101, Nov 15 21:12:56 volumio volumio[4091]: code: 'ENETUNREACH', Nov 15 21:12:56 volumio volumio[4091]: syscall: 'send', Nov 15 21:12:56 volumio volumio[4091]: address: '255.255.255.255', Nov 15 21:12:56 volumio volumio[4091]: port: 3483 Nov 15 21:12:56 volumio volumio[4091]: } Nov 15 21:12:56 volumio volumio[4091]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:12:56 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Nov 15 21:12:56 volumio squeezeboxserver[4072]: [23-11-15 21:12:53.8834] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:12:57 volumio mpd[4262]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:12:57 volumio mpd[4262]: config: Found database setting without music_directory - disabling database Nov 15 21:12:57 volumio mpd[4262]: output: No 'audio_output' defined in config file Nov 15 21:12:57 volumio mpd[4262]: output: Attempt to detect audio output device Nov 15 21:12:57 volumio mpd[4262]: output: Attempting to detect a alsa audio device Nov 15 21:12:57 volumio systemd[1]: logitechmediaserver.service: Succeeded. Nov 15 21:12:57 volumio systemd[1]: Stopped Logitech Media Server Daemon. Nov 15 21:12:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:12:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Nov 15 21:12:57 volumio mpd[4262]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:12:57 volumio mpd[4262]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:12:57 volumio mpd[4262]: output: Attempting to detect a oss audio device Nov 15 21:12:57 volumio mpd[4262]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:12:57 volumio mpd[4262]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:12:57 volumio mpd[4262]: output: Attempting to detect a pulse audio device Nov 15 21:12:57 volumio mpd[4262]: output: Attempting to detect a jack audio device Nov 15 21:12:57 volumio mpd[4262]: output: Successfully detected a jack audio device Nov 15 21:12:57 volumio mpd[4262]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:12:57 volumio mpd[4262]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:12:57 volumio sudo[4270]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:57 volumio mpd[4262]: zeroconf: No global port, disabling zeroconf Nov 15 21:12:57 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:12:57 volumio sudo[4249]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:57 volumio sudo[4274]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:57 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:12:57 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:12:57 volumio sudo[4288]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:57 volumio systemd[1]: Starting Logitech Media Server Daemon... Nov 15 21:12:57 volumio go-librespot[4310]: Librespot-go daemon starting... Nov 15 21:12:57 volumio go-librespot[4310]: time="2023-11-15T21:12:57+01:00" level=info msg="generated new device id: 2080b8a7d78434b61c311c28e4e83ef715e24028" Nov 15 21:12:57 volumio go-librespot[4310]: time="2023-11-15T21:12:57+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:12:57 volumio systemd[1]: Started Logitech Media Server Daemon. Nov 15 21:12:57 volumio sudo[4264]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:57 volumio go-librespot[4310]: time="2023-11-15T21:12:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:12:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:12:57 volumio sudo[4321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-11-15 21:11 Nov 15 21:12:57 volumio sudo[4321]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:12:57 volumio sudo[4321]: pam_unix(sudo:session): session closed for user root Nov 15 21:12:57 volumio volumio-remote-updater[542]: [2023-11-15 21:12:57] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 15 21:12:57 volumio volumio-remote-updater[542]: [2023-11-15 21:12:57] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 15 21:12:57 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:12:57 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 15 21:12:57 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:57 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:57 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Nov 15 21:12:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14. Nov 15 21:12:57 volumio systemd[1]: Stopped Volumio Backend Module. Nov 15 21:12:57 volumio systemd[1]: Started Volumio Backend Module. Nov 15 21:12:57 volumio systemd[1]: Started dynamicswap service. Nov 15 21:12:57 volumio systemd[1]: dynamicswap.service: Succeeded. Nov 15 21:12:59 volumio volumio[4334]: info: ------------------------------------------- Nov 15 21:12:59 volumio volumio[4334]: info: ----- Volumio3 ---- Nov 15 21:12:59 volumio volumio[4334]: info: ------------------------------------------- Nov 15 21:12:59 volumio volumio[4334]: info: ----- System startup ---- Nov 15 21:12:59 volumio volumio[4334]: info: ------------------------------------------- Nov 15 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Nov 15 21:13:00 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:13:00 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:13:00 volumio go-librespot[4355]: Librespot-go daemon starting... Nov 15 21:13:00 volumio go-librespot[4355]: time="2023-11-15T21:13:00+01:00" level=info msg="generated new device id: 5d58ba08181fd2ffc261aa8f221d94e2df00804e" Nov 15 21:13:00 volumio go-librespot[4355]: time="2023-11-15T21:13:00+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:13:00 volumio go-librespot[4355]: time="2023-11-15T21:13:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:13:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:13:00 volumio volumio[4334]: info: MYVOLUMIO Environment detected Nov 15 21:13:00 volumio volumio[4334]: info: Plugin folders cleanup Nov 15 21:13:00 volumio volumio[4334]: info: Scanning into folder /volumio/app/plugins/ Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category audio_interface Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category miscellanea Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category music_service Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category plugins.json Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category system_controller Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category user_interface Nov 15 21:13:00 volumio volumio[4334]: info: Scanning into folder /data/plugins/ Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category audio_interface Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category music_service Nov 15 21:13:00 volumio volumio[4334]: info: Scanning category user_interface Nov 15 21:13:00 volumio volumio[4334]: info: Plugin folders cleanup completed Nov 15 21:13:00 volumio volumio[4334]: info: ------------------------------------------- Nov 15 21:13:00 volumio volumio[4334]: info: ----- Core plugins startup ---- Nov 15 21:13:00 volumio volumio[4334]: info: ------------------------------------------- Nov 15 21:13:00 volumio volumio[4334]: info: Loading plugins from folder /volumio/app/plugins/ Nov 15 21:13:00 volumio volumio[4334]: info: Adding plugin upnp to MyMusic Plugins Nov 15 21:13:00 volumio volumio[4334]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 15 21:13:00 volumio volumio[4334]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 15 21:13:00 volumio volumio[4334]: info: Loading plugins from folder /data/plugins/ Nov 15 21:13:00 volumio volumio[4334]: info: Loading plugin "system"... Nov 15 21:13:00 volumio volumio[4334]: info: Loading plugin "appearance"... Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "network"... Nov 15 21:13:01 volumio volumio[4334]: info: Refreshing Cached IP Addresses Nov 15 21:13:01 volumio sudo[4365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:13:01 volumio sudo[4365]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:01 volumio sudo[4365]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:01 volumio sudo[4367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:13:01 volumio sudo[4367]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "services"... Nov 15 21:13:01 volumio sudo[4367]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "alsa_controller"... Nov 15 21:13:01 volumio sudo[4370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 15 21:13:01 volumio sudo[4370]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:01 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "wizard"... Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "volumio_command_line_client"... Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "upnp"... Nov 15 21:13:01 volumio volumio[4334]: info: [1700079181912] Starting Upmpd Daemon Nov 15 21:13:01 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "my_music"... Nov 15 21:13:01 volumio volumio[4334]: info: Loading plugin "mpd"... Nov 15 21:13:02 volumio volumio[4334]: info: Creating MPD Configuration file Nov 15 21:13:02 volumio volumio[4334]: info: Loading plugin "upnp_browser"... Nov 15 21:13:02 volumio sudo[4378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:13:02 volumio sudo[4378]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:02 volumio sudo[4380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:13:02 volumio sudo[4380]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:02 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:13:02 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:13:02 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:13:02 volumio sudo[4378]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:02 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:13:02 volumio volumio[4334]: info: Loading plugin "networkfs"... Nov 15 21:13:02 volumio volumio-remote-updater[542]: [2023-11-15 21:13:02] [connect] Successful connection Nov 15 21:13:02 volumio volumio[4334]: info: Starting Udev Watcher for removable devices Nov 15 21:13:03 volumio volumio[4334]: info: Ignoring mount for partition: boot Nov 15 21:13:03 volumio volumio[4334]: info: Ignoring mount for partition: volumio Nov 15 21:13:03 volumio volumio[4334]: info: Ignoring mount for partition: volumio_data Nov 15 21:13:03 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "alarm-clock"... Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "airplay_emulation"... Nov 15 21:13:03 volumio volumio[4334]: info: Starting Shairport Sync Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "last_100"... Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "webradio"... Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "i2s_dacs"... Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "volumiodiscovery"... Nov 15 21:13:03 volumio volumio[4334]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:13:03 volumio node[4334]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 15 21:13:03 volumio volumio[4334]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:13:03 volumio node[4334]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:13:03 volumio volumio[4334]: *** WARNING *** For more information see Nov 15 21:13:03 volumio node[4334]: *** WARNING *** For more information see Nov 15 21:13:03 volumio volumio[4334]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:13:03 volumio node[4334]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 15 21:13:03 volumio volumio[4334]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:13:03 volumio node[4334]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 15 21:13:03 volumio volumio[4334]: *** WARNING *** For more information see Nov 15 21:13:03 volumio node[4334]: *** WARNING *** For more information see Nov 15 21:13:03 volumio volumio[4334]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 15 21:13:03 volumio volumio[4334]: info: Discovery: Started advertising with name: Volumio Nov 15 21:13:03 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 15 21:13:03 volumio volumio[4334]: info: Loading plugin "spop"... Nov 15 21:13:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:13:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Nov 15 21:13:03 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:13:03 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:13:03 volumio go-librespot[4389]: Librespot-go daemon starting... Nov 15 21:13:03 volumio go-librespot[4389]: time="2023-11-15T21:13:03+01:00" level=info msg="generated new device id: cf4de104d1c1849cd9148315b64371275cd7fcd1" Nov 15 21:13:03 volumio go-librespot[4389]: time="2023-11-15T21:13:03+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:13:03 volumio go-librespot[4389]: time="2023-11-15T21:13:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:13:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:13:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:13:03 volumio mpd[4385]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:13:03 volumio mpd[4385]: config: Found database setting without music_directory - disabling database Nov 15 21:13:03 volumio mpd[4385]: output: No 'audio_output' defined in config file Nov 15 21:13:03 volumio mpd[4385]: output: Attempt to detect audio output device Nov 15 21:13:03 volumio mpd[4385]: output: Attempting to detect a alsa audio device Nov 15 21:13:03 volumio mpd[4385]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:13:03 volumio mpd[4385]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:13:03 volumio mpd[4385]: output: Attempting to detect a oss audio device Nov 15 21:13:03 volumio mpd[4385]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:13:03 volumio mpd[4385]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:13:03 volumio mpd[4385]: output: Attempting to detect a pulse audio device Nov 15 21:13:03 volumio mpd[4385]: output: Attempting to detect a jack audio device Nov 15 21:13:03 volumio mpd[4385]: output: Successfully detected a jack audio device Nov 15 21:13:03 volumio mpd[4385]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:13:03 volumio mpd[4385]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:13:03 volumio mpd[4385]: zeroconf: No global port, disabling zeroconf Nov 15 21:13:03 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:13:03 volumio sudo[4380]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:04 volumio volumio[4334]: info: Loading plugin "squeezelite_mc"... Nov 15 21:13:05 volumio volumio[4334]: info: Loading plugin "youtube2"... Nov 15 21:13:05 volumio sudo[4370]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:06 volumio ifplugd(eth0)[686]: Link beat detected. Nov 15 21:13:06 volumio ifplugd(eth0)[686]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Nov 15 21:13:06 volumio volumio[4334]: info: Loading plugin "ytmusic"... Nov 15 21:13:06 volumio ifplugd(eth0)[686]: client: sending commands to master dhcpcd process Nov 15 21:13:06 volumio dhcpcd[4420]: sending commands to master dhcpcd process Nov 15 21:13:06 volumio dhcpcd[798]: control command: /sbin/dhcpcd eth0 Nov 15 21:13:06 volumio ifplugd(eth0)[686]: Program executed successfully. Nov 15 21:13:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:13:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Nov 15 21:13:06 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:13:06 volumio dhcpcd[798]: eth0: carrier acquired Nov 15 21:13:06 volumio kernel: lan78xx 1-1.1.1:1.0 eth0: Link is Up - 1Gbps/Full - flow control off Nov 15 21:13:06 volumio kernel: NOHZ tick-stop error: local softirq work is pending, handler #08!!! Nov 15 21:13:06 volumio dhcpcd[798]: eth0: IAID eb:04:11:f4 Nov 15 21:13:06 volumio dhcpcd[798]: eth0: adding address fe80::7dc0:4a18:726a:213f Nov 15 21:13:06 volumio dhcpcd[798]: ipv6_addaddr1: Permission denied Nov 15 21:13:06 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:13:06 volumio go-librespot[4445]: Librespot-go daemon starting... Nov 15 21:13:06 volumio go-librespot[4445]: time="2023-11-15T21:13:06+01:00" level=info msg="generated new device id: 7fd53b34b1307fa5cb2f886247ae02ec5e82ab6a" Nov 15 21:13:06 volumio go-librespot[4445]: time="2023-11-15T21:13:06+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:13:06 volumio go-librespot[4445]: time="2023-11-15T21:13:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:13:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:13:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:00.3508] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:00.9236] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6858] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6866] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6872] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6929] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6951] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6967] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.6998] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.7072] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.7106] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:13:06 volumio squeezeboxserver[4319]: [23-11-15 21:13:06.9682] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Nov 15 21:13:07 volumio dhcpcd[798]: eth0: soliciting a DHCP lease Nov 15 21:13:07 volumio dhcpcd[798]: eth0: soliciting an IPv6 router Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "outputs"... Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "albumart"... Nov 15 21:13:07 volumio volumio[4334]: info: Plugin example_plugin is not enabled Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "inputs"... Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "updater_comm"... Nov 15 21:13:07 volumio volumio[4334]: info: Plugin mpdemulation is not enabled Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "rest_api"... Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "websocket"... Nov 15 21:13:07 volumio volumio[4334]: info: Loading plugin "fusiondsp"... Nov 15 21:13:08 volumio volumio[4334]: Forking 3 albumart workers Nov 15 21:13:08 volumio volumio[4334]: info: Applying required configuration parameters for plugin fusiondsp Nov 15 21:13:08 volumio volumio[4334]: info: Loading plugin "80s80s"... Nov 15 21:13:09 volumio volumio[4334]: info: Applying required configuration parameters for plugin 80s80s Nov 15 21:13:09 volumio volumio[4334]: info: [1700079189111] [80s80s] API delay: 30 Nov 15 21:13:09 volumio volumio[4334]: info: Loading plugin "lms"... Nov 15 21:13:09 volumio volumio[4334]: Starting albumart workers Nov 15 21:13:09 volumio dhcpcd[798]: eth0: offered 192.168.1.119 from 192.168.1.1 Nov 15 21:13:09 volumio volumio[4334]: info: Loading plugin "motherearthradio"... Nov 15 21:13:09 volumio squeezeboxserver[4319]: [23-11-15 21:13:09.4732] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Nov 15 21:13:09 volumio dhcpcd[798]: eth0: probing address 192.168.1.119/24 Nov 15 21:13:09 volumio volumio[4334]: Starting albumart workers Nov 15 21:13:09 volumio volumio[4334]: Starting albumart workers Nov 15 21:13:09 volumio volumio[4334]: info: Applying required configuration parameters for plugin motherearthradio Nov 15 21:13:09 volumio volumio[4334]: info: [1700079189806] [MotherEarth] API delay: 5 Nov 15 21:13:09 volumio volumio[4334]: info: Loading plugin "rad357pl"... Nov 15 21:13:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:13:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Nov 15 21:13:10 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:13:10 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:13:10 volumio go-librespot[4482]: Librespot-go daemon starting... Nov 15 21:13:10 volumio go-librespot[4482]: time="2023-11-15T21:13:10+01:00" level=info msg="generated new device id: f23d27f1c40b967775b487cefa05edfa60ade151" Nov 15 21:13:10 volumio go-librespot[4482]: time="2023-11-15T21:13:10+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:13:10 volumio go-librespot[4482]: time="2023-11-15T21:13:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:13:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:13:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:13:10 volumio volumio[4334]: info: Applying required configuration parameters for plugin rad357pl Nov 15 21:13:10 volumio volumio[4334]: info: [1700079190320] [rad357pl] API delay: 5 Nov 15 21:13:10 volumio volumio[4334]: info: Loading plugin "radio_paradise"... Nov 15 21:13:10 volumio volumio[4334]: info: Applying required configuration parameters for plugin radio_paradise Nov 15 21:13:10 volumio volumio[4334]: info: [1700079190653] [RadioParadise] API delay: 5 Nov 15 21:13:10 volumio volumio[4334]: info: Loading plugin "lastfm"... Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9043] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9771] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9781] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9812] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9883] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9897] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9907] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9921] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9948] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9957] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Nov 15 21:13:10 volumio squeezeboxserver[4319]: [23-11-15 21:13:10.9993] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1147] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1174] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1207] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1310] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1467] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1482] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.156 seconds. Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1497] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1522] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.002 seconds. Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1556] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1566] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.002 seconds. Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.1582] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Nov 15 21:13:11 volumio volumio[4334]: info: Loading plugin "touch_display"... Nov 15 21:13:11 volumio volumio[4334]: info: Applying required configuration parameters for plugin touch_display Nov 15 21:13:11 volumio volumio[4334]: info: Loading i18n strings for locale pl Nov 15 21:13:11 volumio volumio[4334]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:13:11 volumio volumio[4334]: Updating browse sources language Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:11 volumio squeezeboxserver[4319]: [23-11-15 21:13:11.5074] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 0.348 seconds. Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::initPlayerControls Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:13:11 volumio volumio[4334]: Express server listening on port 3000 Nov 15 21:13:11 volumio volumio[4334]: [Metrics] WebUI: 12s 457.86ms Nov 15 21:13:11 volumio volumio[4334]: info: CoreStateMachine::resetVolumioState Nov 15 21:13:11 volumio volumio[4334]: info: CoreStateMachine::getcurrentVolume Nov 15 21:13:11 volumio volumio[4334]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:13:11 volumio mpd[4385]: client: [0] opened from local Nov 15 21:13:11 volumio volumio[4334]: info: MPD Permissions set Nov 15 21:13:11 volumio volumio[4334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Nov 15 21:13:11 volumio volumio[4334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 15 21:13:11 volumio volumio[4334]: info: MPD running with PID4385 Nov 15 21:13:11 volumio volumio[4334]: ,establishing connection Nov 15 21:13:11 volumio mpd[4385]: client: [1] opened from local Nov 15 21:13:11 volumio sudo[4521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 15 21:13:11 volumio sudo[4521]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:11 volumio sudo[4521]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:11 volumio sudo[4524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 15 21:13:11 volumio sudo[4524]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:11 volumio sudo[4524]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: Reloading queue from file Nov 15 21:13:12 volumio volumio[4334]: error: updateQueue error: null Nov 15 21:13:12 volumio volumio[4334]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::pushState Nov 15 21:13:12 volumio volumio[4334]: info: CorePlayQueue::getTrack 0 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioPushState Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::updateTrackBlock Nov 15 21:13:12 volumio volumio[4334]: info: CorePlayQueue::getTrackBlock Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::setRepeat false single undefined Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::pushState Nov 15 21:13:12 volumio volumio[4334]: info: CorePlayQueue::getTrack 0 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioPushState Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::setRandom null Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::pushState Nov 15 21:13:12 volumio volumio[4334]: info: CorePlayQueue::getTrack 0 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioPushState Nov 15 21:13:12 volumio volumio[4334]: info: Setting Device type: Raspberry PI Nov 15 21:13:12 volumio volumio[4334]: info: Completed loading Core Plugins Nov 15 21:13:12 volumio volumio[4334]: info: Preparing to generate the ALSA configuration file Nov 15 21:13:12 volumio volumio[4334]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:13:12 volumio volumio[4334]: info: Reading ALSA contributions from plugins. Nov 15 21:13:12 volumio volumio[4334]: error: updateQueue error: null Nov 15 21:13:12 volumio volumio[4334]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:13:12 volumio volumio[4334]: info: CoreStateMachine::pushState Nov 15 21:13:12 volumio volumio[4334]: info: CorePlayQueue::getTrack 0 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioPushState Nov 15 21:13:12 volumio sudo[4537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 15 21:13:12 volumio sudo[4537]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:12 volumio sudo[4537]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:12 volumio volumio[4334]: info: Upmpdcli Daemon Started Nov 15 21:13:12 volumio volumio[4334]: info: Asound.conf file unchanged, so no further update is needed Nov 15 21:13:12 volumio volumio[4334]: info: Output device has changed, restarting MPD Nov 15 21:13:12 volumio sudo[4540]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 15 21:13:12 volumio sudo[4540]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:12 volumio volumio[4334]: info: Output device has changed, restarting Shairport Sync Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:13:12 volumio sudo[4540]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:12 volumio sudo[4542]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 15 21:13:12 volumio sudo[4542]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:12 volumio systemd[1]: Stopping Music Player Daemon... Nov 15 21:13:12 volumio volumio[4334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:13:12 volumio volumio[4334]: info: ___________ START PLUGINS ___________ Nov 15 21:13:12 volumio systemd[1]: mpd.service: Succeeded. Nov 15 21:13:12 volumio systemd[1]: Stopped Music Player Daemon. Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192537] CoreMusicLibrary::Adding element Media Servers Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:13:12 volumio systemd[1]: Starting Music Player Daemon... Nov 15 21:13:12 volumio volumio[4334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192665] CoreMusicLibrary::Adding element Last_100 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192669] CoreMusicLibrary::Adding element Webradio Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:13:12 volumio volumio[4334]: info: Creating Spotify config file Nov 15 21:13:12 volumio volumio[4334]: info: [squeezelite_mc] Starting proxy server... Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192807] CoreMusicLibrary::Adding element YouTube2 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192821] CoreMusicLibrary::Adding element YouTube Music Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube Music Nov 15 21:13:12 volumio volumio[4334]: info: Loading i18n strings for locale pl Nov 15 21:13:12 volumio volumio[4334]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:12 volumio volumio[4334]: info: FusionDsp - mixtype--------------------- Hardware Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192876] CoreMusicLibrary::Adding element 80s80s Radio Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube Music Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source 80s80s Radio Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192908] CoreMusicLibrary::Adding element Mother Earth Radio Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube Music Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source 80s80s Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source Mother Earth Radio Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192917] CoreMusicLibrary::Adding element RADIO 357 Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube Music Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source 80s80s Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source Mother Earth Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source RADIO 357 Nov 15 21:13:12 volumio sudo[4558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192925] CoreMusicLibrary::Adding element Radio Paradise Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube Music Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source 80s80s Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source Mother Earth Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source RADIO 357 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source Radio Paradise Nov 15 21:13:12 volumio sudo[4558]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 15 21:13:12 volumio volumio[4334]: info: [1700079192932] CoreMusicLibrary::Adding element LastFM Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube2 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source YouTube Music Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source 80s80s Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source Mother Earth Radio Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source RADIO 357 Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source Radio Paradise Nov 15 21:13:12 volumio volumio[4334]: Cannot find translation for source LastFM Nov 15 21:13:12 volumio volumio[4334]: info: [LastFM] scrobbler initiated! Nov 15 21:13:12 volumio volumio[4334]: info: [LastFM] extended logging: false Nov 15 21:13:12 volumio volumio[4334]: info: [LastFM] try scrobble stream/radio plays: true Nov 15 21:13:12 volumio volumio[4334]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:13:12 volumio volumio[4334]: info: [LastFM] Left init routine Nov 15 21:13:12 volumio volumio[4334]: info: [LastFM] Socket already connected: true Nov 15 21:13:12 volumio volumio[4334]: info: Loading i18n strings for locale pl Nov 15 21:13:12 volumio systemd[1]: Stopping Logitech Media Server Daemon... Nov 15 21:13:12 volumio volumio[4334]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Nov 15 21:13:12 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 15 21:13:12 volumio volumio[4334]: info: Volumio Calling Home Nov 15 21:13:13 volumio volumio[4334]: info: [squeezelite_mc] Proxy server started on port 36345 Nov 15 21:13:13 volumio volumio[4334]: info: Preparing to generate the ALSA configuration file Nov 15 21:13:13 volumio volumio[4334]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Nov 15 21:13:13 volumio sudo[4564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Nov 15 21:13:13 volumio sudo[4564]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::volumioRetrievevolume Nov 15 21:13:13 volumio systemd[1]: Reloading. Nov 15 21:13:13 volumio volumio[4334]: Unhandled rejection Error: No sockets available, cannot start. Nov 15 21:13:13 volumio volumio[4334]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Nov 15 21:13:13 volumio volumio[4334]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Nov 15 21:13:13 volumio volumio[4334]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Nov 15 21:13:13 volumio volumio[4334]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Nov 15 21:13:13 volumio volumio[4334]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Nov 15 21:13:13 volumio volumio[4334]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Nov 15 21:13:13 volumio volumio[4334]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Nov 15 21:13:13 volumio volumio[4334]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Nov 15 21:13:13 volumio volumio[4334]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Nov 15 21:13:13 volumio volumio[4334]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Nov 15 21:13:13 volumio volumio[4334]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Nov 15 21:13:13 volumio volumio[4334]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 15 21:13:13 volumio volumio[4334]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 15 21:13:13 volumio volumio[4334]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Nov 15 21:13:13 volumio volumio[4334]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Nov 15 21:13:13 volumio volumio[4334]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 15 21:13:13 volumio volumio[4334]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Nov 15 21:13:13 volumio volumio[4334]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 15 21:13:13 volumio volumio[4334]: info: Reading ALSA contributions from plugins. Nov 15 21:13:13 volumio volumio[4334]: info: MPD Permissions set Nov 15 21:13:13 volumio volumio[4334]: info: Spotify config file written Nov 15 21:13:13 volumio volumio[4334]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio sudo[4576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 15 21:13:13 volumio sudo[4576]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: VolumeController:: Volume=100 Mute =false Nov 15 21:13:13 volumio volumio[4334]: info: CoreStateMachine::pushState Nov 15 21:13:13 volumio volumio[4334]: info: CorePlayQueue::getTrack 0 Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::volumioPushState Nov 15 21:13:13 volumio volumio[4334]: info: [squeezelite_mc] Server discovery started Nov 15 21:13:13 volumio volumio[4334]: info: [squeezelite_mc] Player finder started Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 15 21:13:13 volumio volumio[4334]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Nov 15 21:13:13 volumio volumio[4334]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:13:13 volumio volumio[4334]: Error: send ENETUNREACH 255.255.255.255:3483 Nov 15 21:13:13 volumio volumio[4334]: at doSend (dgram.js:692:16) Nov 15 21:13:13 volumio volumio[4334]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Nov 15 21:13:13 volumio volumio[4334]: at afterDns (dgram.js:638:5) Nov 15 21:13:13 volumio volumio[4334]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Nov 15 21:13:13 volumio volumio[4334]: errno: -101, Nov 15 21:13:13 volumio volumio[4334]: code: 'ENETUNREACH', Nov 15 21:13:13 volumio volumio[4334]: syscall: 'send', Nov 15 21:13:13 volumio volumio[4334]: address: '255.255.255.255', Nov 15 21:13:13 volumio volumio[4334]: port: 3483 Nov 15 21:13:13 volumio volumio[4334]: } Nov 15 21:13:13 volumio volumio[4334]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 15 21:13:13 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Nov 15 21:13:13 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Nov 15 21:13:13 volumio squeezeboxserver[4319]: [23-11-15 21:13:12.8848] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Nov 15 21:13:14 volumio sudo[4564]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:14 volumio systemd[1]: logitechmediaserver.service: Succeeded. Nov 15 21:13:14 volumio systemd[1]: Stopped Logitech Media Server Daemon. Nov 15 21:13:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 15 21:13:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Nov 15 21:13:14 volumio systemd[1]: Stopped go-librespot Daemon. Nov 15 21:13:14 volumio systemd[1]: Started go-librespot Daemon. Nov 15 21:13:14 volumio mpd[4556]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 15 21:13:14 volumio mpd[4556]: config: Found database setting without music_directory - disabling database Nov 15 21:13:14 volumio mpd[4556]: output: No 'audio_output' defined in config file Nov 15 21:13:14 volumio mpd[4556]: output: Attempt to detect audio output device Nov 15 21:13:14 volumio mpd[4556]: output: Attempting to detect a alsa audio device Nov 15 21:13:14 volumio go-librespot[4598]: Librespot-go daemon starting... Nov 15 21:13:14 volumio systemd[1]: Starting Logitech Media Server Daemon... Nov 15 21:13:14 volumio mpd[4556]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Nov 15 21:13:14 volumio mpd[4556]: alsa_output: Error opening default ALSA device: No such file or directory Nov 15 21:13:14 volumio mpd[4556]: output: Attempting to detect a oss audio device Nov 15 21:13:14 volumio mpd[4556]: oss_output: Error opening OSS device "/dev/dsp": No such file or directory Nov 15 21:13:14 volumio mpd[4556]: oss_output: Error opening OSS device "/dev/sound/dsp": No such file or directory Nov 15 21:13:14 volumio mpd[4556]: output: Attempting to detect a pulse audio device Nov 15 21:13:14 volumio mpd[4556]: output: Attempting to detect a jack audio device Nov 15 21:13:14 volumio mpd[4556]: output: Successfully detected a jack audio device Nov 15 21:13:14 volumio mpd[4556]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Nov 15 21:13:14 volumio mpd[4556]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Nov 15 21:13:14 volumio mpd[4556]: zeroconf: No global port, disabling zeroconf Nov 15 21:13:14 volumio systemd[1]: Started Music Player Daemon. Nov 15 21:13:14 volumio sudo[4542]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:14 volumio sudo[4576]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:14 volumio go-librespot[4598]: time="2023-11-15T21:13:14+01:00" level=info msg="generated new device id: a9a7b18b3149e06b01ed1f24238462bb20d05edf" Nov 15 21:13:14 volumio go-librespot[4598]: time="2023-11-15T21:13:14+01:00" level=debug msg="stored credentials found for tomala68" Nov 15 21:13:14 volumio systemd[1]: Started Logitech Media Server Daemon. Nov 15 21:13:14 volumio go-librespot[4598]: time="2023-11-15T21:13:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Nov 15 21:13:14 volumio sudo[4558]: pam_unix(sudo:session): session closed for user root Nov 15 21:13:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 15 21:13:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 15 21:13:14 volumio sudo[4614]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-11-15 21:12 Nov 15 21:13:14 volumio sudo[4614]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 15 21:13:14 volumio dhcpcd[798]: eth0: leased 192.168.1.119 for 86400 seconds Nov 15 21:13:14 volumio dhcpcd[798]: eth0: adding route to 192.168.1.0/24 Nov 15 21:13:14 volumio avahi-daemon[534]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.119. Nov 15 21:13:14 volumio avahi-daemon[534]: New relevant interface eth0.IPv4 for mDNS. Nov 15 21:13:14 volumio dhcpcd[798]: eth0: adding default route via 192.168.1.1 Nov 15 21:13:14 volumio avahi-daemon[534]: Registering new address record for 192.168.1.119 on eth0.IPv4. 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="893d2e91c55a7857b58762e70c2f65b9d163562b" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="30b77d58bf3c2745acc494ddafed946392a79905" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 20 Oct 2023 03:38:28 PM CEST" VOLUMIO_VERSION="3.569" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4163d3756b55b3bf7c480d7285f68954"