-- Logs begin at Thu 2019-02-14 19:12:01 JST, end at Thu 2024-04-04 08:58:17 JST. -- Apr 04 08:57:00 volumio volumio[1735]: error: MPD error: The expression evaluated to a falsy value: Apr 04 08:57:00 volumio volumio[1735]: assert.ok(self.idling) Apr 04 08:57:00 volumio volumio[1735]: error: The expression evaluated to a falsy value: Apr 04 08:57:00 volumio volumio[1735]: assert.ok(self.idling) Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:00 volumio volumio[1735]: info: VolumeController:: Volume=86 Mute =false Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::pushState Apr 04 08:57:00 volumio volumio[1735]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::updateTrackBlock Apr 04 08:57:00 volumio volumio[1735]: info: CorePlayQueue::getTrackBlock Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::volumioRetrievevolume Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::setRepeat true single undefined Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::pushState Apr 04 08:57:00 volumio volumio[1735]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::setRandom true Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::pushState Apr 04 08:57:00 volumio volumio[1735]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:00 volumio volumio[1735]: info: Setting Device type: Raspberry PI Apr 04 08:57:00 volumio volumio[1735]: info: Reloading queue from file Apr 04 08:57:00 volumio volumio[1735]: error: updateQueue error: null Apr 04 08:57:00 volumio volumio[1735]: info: VolumeController:: Volume=86 Mute =false Apr 04 08:57:00 volumio volumio[1735]: info: CoreStateMachine::pushState Apr 04 08:57:00 volumio volumio[1735]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:00 volumio volumio[1735]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:56:59.4649] 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 Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:56:59.7788] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0265] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0270] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0274] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0307] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0319] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0326] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0342] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0385] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.0403] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Apr 04 08:57:02 volumio squeezeboxserver[1846]: [24-04-04 08:57:02.1862] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Apr 04 08:57:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Apr 04 08:57:02 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:02 volumio volumio[1735]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:57:02 volumio volumio[1735]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:57:02 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:02 volumio go-librespot[1890]: Librespot-go daemon starting... Apr 04 08:57:02 volumio go-librespot[1890]: time="2024-04-04T08:57:02+09:00" level=info msg="generated new device id: 3aec7749498a730bc4cfb2254cf311b1228fd333" Apr 04 08:57:02 volumio go-librespot[1890]: time="2024-04-04T08:57:02+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:02 volumio go-librespot[1890]: time="2024-04-04T08:57:02+09: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" Apr 04 08:57:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:02 volumio sudo[1898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:02 volumio sudo[1898]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:02 volumio sudo[1898]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:02 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:02 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:02 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:02 volumio volumio[1735]: info: Cannot mount NAS share at system boot, trial number 2 ,retrying in 5 seconds Apr 04 08:57:03 volumio sudo[1903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 04 08:57:03 volumio sudo[1903]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:03 volumio sudo[1903]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:03 volumio sudo[1906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 04 08:57:03 volumio sudo[1906]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:03 volumio sudo[1906]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:03 volumio sudo[1909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 04 08:57:03 volumio sudo[1909]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:03 volumio sudo[1909]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:03 volumio volumio[1735]: info: Upmpdcli Daemon Started Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.3815] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9506] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9881] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9886] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9905] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9941] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9947] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9951] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.000 seconds. Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9957] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9969] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9973] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Apr 04 08:57:03 volumio squeezeboxserver[1846]: [24-04-04 08:57:03.9990] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0599] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0611] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0621] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0671] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0755] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0761] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.080 seconds. Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0767] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0781] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.001 seconds. Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0797] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0801] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.001 seconds. Apr 04 08:57:04 volumio squeezeboxserver[1846]: [24-04-04 08:57:04.0808] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Apr 04 08:57:05 volumio mpd[1788]: exception: No database Apr 04 08:57:05 volumio mpd[1788]: exception: No database Apr 04 08:57:05 volumio mpd[1788]: exception: No database Apr 04 08:57:05 volumio volumio[1735]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database Apr 04 08:57:05 volumio squeezeboxserver[1846]: [24-04-04 08:57:05.1490] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 1.068 seconds. Apr 04 08:57:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Apr 04 08:57:05 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:05 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:05 volumio go-librespot[1911]: Librespot-go daemon starting... Apr 04 08:57:05 volumio go-librespot[1911]: time="2024-04-04T08:57:05+09:00" level=info msg="generated new device id: ff60d2ccbb47eb835f3a960d7680fd8194ae8558" Apr 04 08:57:05 volumio go-librespot[1911]: time="2024-04-04T08:57:05+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:05 volumio go-librespot[1911]: time="2024-04-04T08:57:05+09: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" Apr 04 08:57:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:05 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:07 volumio volumio[1735]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:57:07 volumio volumio[1735]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:57:07 volumio volumio-remote-updater[515]: [2024-04-04 08:57:07] [connect] Successful connection Apr 04 08:57:07 volumio volumio-remote-updater[515]: [2024-04-04 08:57:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712188627 101 Apr 04 08:57:07 volumio volumio[1735]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Apr 04 08:57:07 volumio sudo[1919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:07 volumio sudo[1919]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:07 volumio sudo[1919]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:07 volumio volumio[1735]: info: Cannot mount NAS share at system boot, trial number 3 ,retrying in 5 seconds Apr 04 08:57:07 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:07 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:07 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Apr 04 08:57:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:08 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:08 volumio go-librespot[1923]: Librespot-go daemon starting... Apr 04 08:57:08 volumio go-librespot[1923]: time="2024-04-04T08:57:08+09:00" level=info msg="generated new device id: 775986a425c41a5e41f5037cfa2b72e7be6b4bbd" Apr 04 08:57:08 volumio go-librespot[1923]: time="2024-04-04T08:57:08+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:08 volumio go-librespot[1923]: time="2024-04-04T08:57:08+09: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" Apr 04 08:57:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Apr 04 08:57:11 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:12 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:12 volumio go-librespot[1930]: Librespot-go daemon starting... Apr 04 08:57:12 volumio go-librespot[1930]: time="2024-04-04T08:57:12+09:00" level=info msg="generated new device id: 3d480977312d41c51828fe85f80e293d55b637c2" Apr 04 08:57:12 volumio go-librespot[1930]: time="2024-04-04T08:57:12+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:12 volumio go-librespot[1930]: time="2024-04-04T08:57:12+09: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" Apr 04 08:57:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:12 volumio volumio[1735]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:57:12 volumio volumio[1735]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:57:12 volumio sudo[1938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:12 volumio sudo[1938]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:12 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:12 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:12 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:12 volumio sudo[1938]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:12 volumio volumio[1735]: info: Cannot mount NAS share at system boot, trial number 4 ,retrying in 5 seconds Apr 04 08:57:13 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Apr 04 08:57:15 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:15 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:15 volumio go-librespot[1942]: Librespot-go daemon starting... Apr 04 08:57:15 volumio go-librespot[1942]: time="2024-04-04T08:57:15+09:00" level=info msg="generated new device id: 2144dd9c57d6df8015e722112327d66e806b605c" Apr 04 08:57:15 volumio go-librespot[1942]: time="2024-04-04T08:57:15+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:15 volumio go-librespot[1942]: time="2024-04-04T08:57:15+09: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" Apr 04 08:57:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:17 volumio volumio[1735]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:57:17 volumio volumio[1735]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:57:17 volumio sudo[1950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:17 volumio sudo[1950]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:17 volumio sudo[1950]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:17 volumio volumio[1735]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Apr 04 08:57:17 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:17 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:17 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Apr 04 08:57:18 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:18 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:18 volumio go-librespot[1954]: Librespot-go daemon starting... Apr 04 08:57:18 volumio go-librespot[1954]: time="2024-04-04T08:57:18+09:00" level=info msg="generated new device id: 876e0ff5900fee899f9837cbe3ad483d35515f6c" Apr 04 08:57:18 volumio go-librespot[1954]: time="2024-04-04T08:57:18+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:18 volumio go-librespot[1954]: time="2024-04-04T08:57:18+09: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" Apr 04 08:57:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:19 volumio ntpd[652]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 04 08:57:19 volumio ntpd[652]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 04 08:57:20 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:21 volumio ntpd[652]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 04 08:57:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Apr 04 08:57:21 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:21 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:21 volumio go-librespot[1961]: Librespot-go daemon starting... Apr 04 08:57:21 volumio go-librespot[1961]: time="2024-04-04T08:57:21+09:00" level=info msg="generated new device id: 1686e8e81473ab783059a2b8dab895fe2636c05e" Apr 04 08:57:21 volumio go-librespot[1961]: time="2024-04-04T08:57:21+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:21 volumio go-librespot[1961]: time="2024-04-04T08:57:21+09: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" Apr 04 08:57:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:23 volumio ntpd[652]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 04 08:57:24 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:24 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 04 08:57:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Apr 04 08:57:24 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:25 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:25 volumio go-librespot[1968]: Librespot-go daemon starting... Apr 04 08:57:25 volumio go-librespot[1968]: time="2024-04-04T08:57:25+09:00" level=info msg="generated new device id: 72666f486172d29d8c1e367d5f12ff628bf027ee" Apr 04 08:57:25 volumio go-librespot[1968]: time="2024-04-04T08:57:25+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:25 volumio go-librespot[1968]: time="2024-04-04T08:57:25+09: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" Apr 04 08:57:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:25 volumio kernel: EXT4-fs (mmcblk0p3): error count since last fsck: 33 Apr 04 08:57:25 volumio kernel: EXT4-fs (mmcblk0p3): initial error at time 1550139119: ext4_validate_block_bitmap:420 Apr 04 08:57:25 volumio kernel: EXT4-fs (mmcblk0p3): last error at time 28: ext4_validate_block_bitmap:420 Apr 04 08:57:26 volumio volumio[1735]: error: Plugin audio_interface bluetooth_controller failed to complete 'onVolumioStart' in a timely fashion Apr 04 08:57:26 volumio volumio[1735]: info: Preparing to generate the ALSA configuration file Apr 04 08:57:26 volumio volumio[1735]: info: Asound.conf file unchanged, so no further update is needed Apr 04 08:57:26 volumio volumio[1735]: info: Output device has changed, restarting MPD Apr 04 08:57:26 volumio sudo[1977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 04 08:57:26 volumio sudo[1977]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:27 volumio volumio[1735]: info: Output device has changed, restarting Shairport Sync Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:27 volumio sudo[1980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 04 08:57:27 volumio sudo[1980]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:27 volumio systemd[1]: Stopping Music Player Daemon... Apr 04 08:57:27 volumio volumio[1735]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 04 08:57:27 volumio systemd[1]: mpd.service: Succeeded. Apr 04 08:57:27 volumio volumio[1735]: info: ___________ START PLUGINS ___________ Apr 04 08:57:27 volumio systemd[1]: Stopped Music Player Daemon. Apr 04 08:57:27 volumio volumio[1735]: info: Set bluetooth disvoverable to true Apr 04 08:57:27 volumio volumio[1735]: info: Starting bluetooth device scan Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:57:27 volumio volumio[1735]: info: [1712188647111] CoreMusicLibrary::Adding element Media Servers Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:57:27 volumio systemd[1]: Starting Music Player Daemon... Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:57:27 volumio volumio[1735]: info: [1712188647214] CoreMusicLibrary::Adding element Last_100 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:57:27 volumio volumio[1735]: info: [1712188647216] CoreMusicLibrary::Adding element Webradio Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 04 08:57:27 volumio volumio[1735]: info: Creating Spotify config file Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: [squeezelite_mc] Starting proxy server... Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:57:27 volumio volumio[1735]: info: [1712188647296] CoreMusicLibrary::Adding element YouTube2 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:57:27 volumio volumio[1735]: Cannot find translation for source YouTube2 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:57:27 volumio volumio[1735]: info: [1712188647302] CoreMusicLibrary::Adding element YouTube Music Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:57:27 volumio volumio[1735]: Cannot find translation for source YouTube2 Apr 04 08:57:27 volumio volumio[1735]: Cannot find translation for source YouTube Music Apr 04 08:57:27 volumio volumio[1735]: info: AutoStart - onStart Apr 04 08:57:27 volumio volumio[1735]: info: Volumio Calling Home Apr 04 08:57:27 volumio sudo[1996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Apr 04 08:57:27 volumio sudo[1996]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:27 volumio systemd[1]: Stopping Logitech Media Server Daemon... Apr 04 08:57:27 volumio volumio[1735]: info: [squeezelite_mc] Proxy server started on port 38109 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioRetrievevolume Apr 04 08:57:27 volumio volumio[1735]: Unhandled rejection Error: No sockets available, cannot start. Apr 04 08:57:27 volumio volumio[1735]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Apr 04 08:57:27 volumio volumio[1735]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Apr 04 08:57:27 volumio volumio[1735]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Apr 04 08:57:27 volumio volumio[1735]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Apr 04 08:57:27 volumio volumio[1735]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Apr 04 08:57:27 volumio volumio[1735]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Apr 04 08:57:27 volumio volumio[1735]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Apr 04 08:57:27 volumio volumio[1735]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Apr 04 08:57:27 volumio volumio[1735]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Apr 04 08:57:27 volumio volumio[1735]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Apr 04 08:57:27 volumio volumio[1735]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Apr 04 08:57:27 volumio volumio[1735]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 04 08:57:27 volumio volumio[1735]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 04 08:57:27 volumio volumio[1735]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Apr 04 08:57:27 volumio volumio[1735]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Apr 04 08:57:27 volumio volumio[1735]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 04 08:57:27 volumio volumio[1735]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Apr 04 08:57:27 volumio volumio[1735]: info: Spotify config file written Apr 04 08:57:27 volumio sudo[2004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 04 08:57:27 volumio volumio[1735]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Apr 04 08:57:27 volumio sudo[2004]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:27 volumio volumio[1735]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: VolumeController:: Volume=86 Mute =false Apr 04 08:57:27 volumio volumio[1735]: info: CoreStateMachine::pushState Apr 04 08:57:27 volumio volumio[1735]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:27 volumio volumio[1735]: info: [squeezelite_mc] Server discovery started Apr 04 08:57:27 volumio volumio[1735]: info: [squeezelite_mc] Player finder started Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:27 volumio volumio[1735]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Apr 04 08:57:27 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:27 volumio go-librespot[2006]: Librespot-go daemon starting... Apr 04 08:57:27 volumio sudo[2004]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:27 volumio volumio[1735]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 04 08:57:27 volumio volumio[1735]: Error: send ENETUNREACH 255.255.255.255:3483 Apr 04 08:57:27 volumio volumio[1735]: at doSend (dgram.js:692:16) Apr 04 08:57:27 volumio volumio[1735]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Apr 04 08:57:27 volumio volumio[1735]: at afterDns (dgram.js:638:5) Apr 04 08:57:27 volumio volumio[1735]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Apr 04 08:57:27 volumio volumio[1735]: errno: -101, Apr 04 08:57:27 volumio volumio[1735]: code: 'ENETUNREACH', Apr 04 08:57:27 volumio volumio[1735]: syscall: 'send', Apr 04 08:57:27 volumio volumio[1735]: address: '255.255.255.255', Apr 04 08:57:27 volumio volumio[1735]: port: 3483 Apr 04 08:57:27 volumio volumio[1735]: } Apr 04 08:57:27 volumio volumio[1735]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 04 08:57:27 volumio go-librespot[2006]: time="2024-04-04T08:57:27+09:00" level=info msg="generated new device id: 796e9c7b964b36fbb56ebd73572feb26f5053bd4" Apr 04 08:57:27 volumio go-librespot[2006]: time="2024-04-04T08:57:27+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:27 volumio go-librespot[2006]: time="2024-04-04T08:57:27+09: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" Apr 04 08:57:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:28 volumio sudo[2027]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-04 08:56 Apr 04 08:57:28 volumio sudo[2027]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:28 volumio sudo[2027]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:28 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:30 volumio sudo[1977]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:30 volumio mpd[1994]: Apr 04 08:57 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 04 08:57:30 volumio mpd[1994]: Apr 04 08:57 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 04 08:57:30 volumio mpd[1994]: Apr 04 08:57 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 04 08:57:30 volumio systemd[1]: Started Music Player Daemon. Apr 04 08:57:30 volumio sudo[1980]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Apr 04 08:57:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:30 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:30 volumio go-librespot[2036]: Librespot-go daemon starting... Apr 04 08:57:30 volumio go-librespot[2036]: time="2024-04-04T08:57:30+09:00" level=info msg="generated new device id: b9a0a8d31e0efe6929b795ef65562923d5f869ec" Apr 04 08:57:30 volumio go-librespot[2036]: time="2024-04-04T08:57:30+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:30 volumio go-librespot[2036]: time="2024-04-04T08:57:30+09: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" Apr 04 08:57:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Apr 04 08:57:33 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:34 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:34 volumio go-librespot[2043]: Librespot-go daemon starting... Apr 04 08:57:34 volumio go-librespot[2043]: time="2024-04-04T08:57:34+09:00" level=info msg="generated new device id: 1194f08a01aaaf885bc97a9a3849cefea5a86316" Apr 04 08:57:34 volumio go-librespot[2043]: time="2024-04-04T08:57:34+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:34 volumio go-librespot[2043]: time="2024-04-04T08:57:34+09: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" Apr 04 08:57:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:35 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Apr 04 08:57:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:37 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:37 volumio go-librespot[2050]: Librespot-go daemon starting... Apr 04 08:57:37 volumio go-librespot[2050]: time="2024-04-04T08:57:37+09:00" level=info msg="generated new device id: 2d206fdc0d3ebd7e4c6564da8707e9ad08cf1e6b" Apr 04 08:57:37 volumio go-librespot[2050]: time="2024-04-04T08:57:37+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:37 volumio go-librespot[2050]: time="2024-04-04T08:57:37+09: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" Apr 04 08:57:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:37 volumio volumio-remote-updater[515]: [2024-04-04 08:57:37] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Apr 04 08:57:37 volumio volumio-remote-updater[515]: [2024-04-04 08:57:37] [error] handle_read_frame error: websocketpp.transport:2 (Underlying Transport Error) Apr 04 08:57:37 volumio volumio-remote-updater[515]: [2024-04-04 08:57:37] [disconnect] Disconnect close local:[1006,Underlying Transport Error] remote:[1006] Apr 04 08:57:37 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:37 volumio sudo[1996]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:37 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 04 08:57:37 volumio systemd[1]: Started dynamicswap service. Apr 04 08:57:37 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 04 08:57:37 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Apr 04 08:57:37 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Apr 04 08:57:37 volumio systemd[1]: Stopped Volumio Backend Module. Apr 04 08:57:38 volumio systemd[1]: Started Volumio Backend Module. Apr 04 08:57:38 volumio systemd[1]: Started dynamicswap service. Apr 04 08:57:38 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 04 08:57:39 volumio volumio[2065]: info: ------------------------------------------- Apr 04 08:57:39 volumio volumio[2065]: info: ----- Volumio3 ---- Apr 04 08:57:39 volumio volumio[2065]: info: ------------------------------------------- Apr 04 08:57:39 volumio volumio[2065]: info: ----- System startup ---- Apr 04 08:57:39 volumio volumio[2065]: info: ------------------------------------------- Apr 04 08:57:39 volumio volumio[2065]: info: MYVOLUMIO Environment detected Apr 04 08:57:39 volumio volumio[2065]: info: Plugin folders cleanup Apr 04 08:57:39 volumio volumio[2065]: info: Scanning into folder /volumio/app/plugins/ Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category audio_interface Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category miscellanea Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category music_service Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category plugins.json Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category system_controller Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category user_interface Apr 04 08:57:39 volumio volumio[2065]: info: Scanning into folder /data/plugins/ Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category audio_interface Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category music_service Apr 04 08:57:39 volumio volumio[2065]: info: Scanning category system_controller Apr 04 08:57:39 volumio volumio[2065]: info: Plugin folders cleanup completed Apr 04 08:57:39 volumio volumio[2065]: info: ------------------------------------------- Apr 04 08:57:39 volumio volumio[2065]: info: ----- Core plugins startup ---- Apr 04 08:57:39 volumio volumio[2065]: info: ------------------------------------------- Apr 04 08:57:39 volumio volumio[2065]: info: Loading plugins from folder /volumio/app/plugins/ Apr 04 08:57:39 volumio volumio[2065]: info: Adding plugin upnp to MyMusic Plugins Apr 04 08:57:39 volumio volumio[2065]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 04 08:57:39 volumio volumio[2065]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 04 08:57:39 volumio volumio[2065]: info: Loading plugins from folder /data/plugins/ Apr 04 08:57:39 volumio volumio[2065]: info: Loading plugin "system"... Apr 04 08:57:39 volumio volumio[2065]: info: Loading plugin "bluetooth_controller"... Apr 04 08:57:39 volumio volumio[2065]: info: Loading plugin "appearance"... Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "network"... Apr 04 08:57:40 volumio volumio[2065]: info: Refreshing Cached IP Addresses Apr 04 08:57:40 volumio sudo[2092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 04 08:57:40 volumio sudo[2092]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:40 volumio sudo[2092]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:40 volumio sudo[2094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 04 08:57:40 volumio sudo[2094]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "services"... Apr 04 08:57:40 volumio sudo[2094]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "alsa_controller"... Apr 04 08:57:40 volumio sudo[2098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 04 08:57:40 volumio sudo[2098]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Apr 04 08:57:40 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:40 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:40 volumio go-librespot[2101]: Librespot-go daemon starting... Apr 04 08:57:40 volumio go-librespot[2101]: time="2024-04-04T08:57:40+09:00" level=info msg="generated new device id: 723d315538dedb712d4bf449a188c6a8748314e0" Apr 04 08:57:40 volumio go-librespot[2101]: time="2024-04-04T08:57:40+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:40 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "wizard"... Apr 04 08:57:40 volumio go-librespot[2101]: time="2024-04-04T08:57:40+09: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" Apr 04 08:57:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "volumio_command_line_client"... Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "upnp"... Apr 04 08:57:40 volumio volumio[2065]: info: [1712188660487] Starting Upmpd Daemon Apr 04 08:57:40 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "my_music"... Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "mpd"... Apr 04 08:57:40 volumio volumio[2065]: info: Creating MPD Configuration file Apr 04 08:57:40 volumio sudo[2113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 04 08:57:40 volumio sudo[2113]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "upnp_browser"... Apr 04 08:57:40 volumio sudo[2113]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:40 volumio sudo[2115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 04 08:57:40 volumio sudo[2115]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:40 volumio systemd[1]: Stopping Music Player Daemon... Apr 04 08:57:40 volumio systemd[1]: mpd.service: Succeeded. Apr 04 08:57:40 volumio systemd[1]: Stopped Music Player Daemon. Apr 04 08:57:40 volumio systemd[1]: Starting Music Player Daemon... Apr 04 08:57:40 volumio volumio[2065]: info: Loading plugin "networkfs"... Apr 04 08:57:41 volumio volumio[2065]: info: Starting Udev Watcher for removable devices Apr 04 08:57:41 volumio sudo[2123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:41 volumio sudo[2123]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:41 volumio sudo[2123]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:41 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:41 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:41 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:41 volumio volumio[2065]: info: Ignoring mount for partition: boot Apr 04 08:57:41 volumio volumio[2065]: info: Ignoring mount for partition: volumio Apr 04 08:57:41 volumio volumio[2065]: info: Ignoring mount for partition: volumio_data Apr 04 08:57:41 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "alarm-clock"... Apr 04 08:57:41 volumio volumio[2065]: info: Alarm: Scheduling Playlist jazz at 6:20 Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "airplay_emulation"... Apr 04 08:57:41 volumio volumio[2065]: info: Starting Shairport Sync Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "last_100"... Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "webradio"... Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "i2s_dacs"... Apr 04 08:57:41 volumio volumio[2065]: info: I2S DAC not set, start Auto-detection Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "volumiodiscovery"... Apr 04 08:57:41 volumio mpd[2120]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 04 08:57:41 volumio mpd[2120]: config: Found database setting without music_directory - disabling database Apr 04 08:57:41 volumio mpd[2120]: output: No 'audio_output' defined in config file Apr 04 08:57:41 volumio mpd[2120]: output: Attempt to detect audio output device Apr 04 08:57:41 volumio mpd[2120]: output: Attempting to detect a alsa audio device Apr 04 08:57:41 volumio mpd[2120]: output: Successfully detected a alsa audio device Apr 04 08:57:41 volumio mpd[2120]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 04 08:57:41 volumio mpd[2120]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 04 08:57:41 volumio volumio[2065]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 04 08:57:41 volumio volumio[2065]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 04 08:57:41 volumio volumio[2065]: *** WARNING *** For more information see Apr 04 08:57:41 volumio node[2065]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 04 08:57:41 volumio volumio[2065]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 04 08:57:41 volumio volumio[2065]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 04 08:57:41 volumio volumio[2065]: *** WARNING *** For more information see Apr 04 08:57:41 volumio node[2065]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 04 08:57:41 volumio node[2065]: *** WARNING *** For more information see Apr 04 08:57:41 volumio node[2065]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 04 08:57:41 volumio node[2065]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 04 08:57:41 volumio node[2065]: *** WARNING *** For more information see Apr 04 08:57:41 volumio volumio[2065]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 04 08:57:41 volumio mpd[2120]: zeroconf: No global port, disabling zeroconf Apr 04 08:57:41 volumio systemd[1]: Started Music Player Daemon. Apr 04 08:57:41 volumio volumio[2065]: info: Discovery: Started advertising with name: Volumio Apr 04 08:57:41 volumio sudo[2115]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:41 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 04 08:57:41 volumio volumio[2065]: info: Loading plugin "spop"... Apr 04 08:57:42 volumio volumio[2065]: info: Loading plugin "squeezelite_mc"... Apr 04 08:57:42 volumio volumio[2065]: info: Loading plugin "youtube2"... Apr 04 08:57:42 volumio volumio-remote-updater[515]: [2024-04-04 08:57:42] [connect] Successful connection Apr 04 08:57:43 volumio volumio[2065]: info: Loading plugin "ytmusic"... Apr 04 08:57:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Apr 04 08:57:43 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:43 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:43 volumio go-librespot[2131]: Librespot-go daemon starting... Apr 04 08:57:43 volumio go-librespot[2131]: time="2024-04-04T08:57:43+09:00" level=info msg="generated new device id: 2f5f7eb74ae66788ceb6cf77001a3f92267b1653" Apr 04 08:57:43 volumio go-librespot[2131]: time="2024-04-04T08:57:43+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:43 volumio go-librespot[2131]: time="2024-04-04T08:57:43+09: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" Apr 04 08:57:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "autostart"... Apr 04 08:57:45 volumio squeezeboxserver[1846]: [24-04-04 08:57:05.4132] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Apr 04 08:57:45 volumio squeezeboxserver[1846]: [24-04-04 08:57:24.2408] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting https://www.mysqueezebox.com/api/sounds/v1/opml Apr 04 08:57:45 volumio squeezeboxserver[1846]: Couldn't resolve IP address for: www.mysqueezebox.com Apr 04 08:57:45 volumio squeezeboxserver[1846]: [24-04-04 08:57:24.2412] Slim::Plugin::Sounds::Plugin::_gotSoundsError (82) Error: Unable to cache Sounds & Effects menu from SN: Couldn't resolve IP address for: www.mysqueezebox.com Apr 04 08:57:45 volumio systemd[1]: logitechmediaserver.service: Succeeded. Apr 04 08:57:45 volumio systemd[1]: Stopped Logitech Media Server Daemon. Apr 04 08:57:45 volumio systemd[1]: Starting Logitech Media Server Daemon... Apr 04 08:57:45 volumio systemd[1]: Started Logitech Media Server Daemon. Apr 04 08:57:45 volumio volumio[2065]: info: Applying required configuration parameters for plugin autostart Apr 04 08:57:45 volumio volumio[2065]: info: AutoStart - onVolumioStart - read config.json Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "outputs"... Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "albumart"... Apr 04 08:57:45 volumio volumio[2065]: info: Plugin example_plugin is not enabled Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "inputs"... Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "updater_comm"... Apr 04 08:57:45 volumio volumio[2065]: info: Plugin mpdemulation is not enabled Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "rest_api"... Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "websocket"... Apr 04 08:57:45 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "lms"... Apr 04 08:57:45 volumio sudo[2098]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:45 volumio volumio[2065]: info: Loading plugin "backup_restore"... Apr 04 08:57:45 volumio volumio[2065]: Forking 3 albumart workers Apr 04 08:57:45 volumio volumio[2065]: info: Applying required configuration parameters for plugin backup_restore Apr 04 08:57:45 volumio volumio[2065]: info: Loading i18n strings for locale en Apr 04 08:57:45 volumio volumio[2065]: Updating browse sources language Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::initPlayerControls Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 04 08:57:45 volumio volumio[2065]: Express server listening on port 3000 Apr 04 08:57:45 volumio volumio[2065]: [Metrics] WebUI: 7s 203.78ms Apr 04 08:57:45 volumio volumio[2065]: info: CoreStateMachine::resetVolumioState Apr 04 08:57:45 volumio volumio[2065]: info: CoreStateMachine::getcurrentVolume Apr 04 08:57:45 volumio volumio[2065]: info: CoreCommandRouter::volumioRetrievevolume Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: bluetooth controller exists Apr 04 08:57:46 volumio volumio[2065]: info: Cannot mount NAS share at system boot, trial number 1 ,retrying in 5 seconds Apr 04 08:57:46 volumio mpd[2120]: client: [0] opened from local Apr 04 08:57:46 volumio volumio[2065]: info: MPD Permissions set Apr 04 08:57:46 volumio volumio[2065]: adding device 84:30:95:C9:D4:C5 Apr 04 08:57:46 volumio volumio[2065]: adding device 40:DE:17:96:F3:C7 Apr 04 08:57:46 volumio volumio-remote-updater[515]: [2024-04-04 08:57:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712188662 101 Apr 04 08:57:46 volumio volumio[2065]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Apr 04 08:57:46 volumio volumio[2065]: info: MPD running with PID2120 Apr 04 08:57:46 volumio volumio[2065]: ,establishing connection Apr 04 08:57:46 volumio mpd[2120]: client: [1] opened from local Apr 04 08:57:46 volumio volumio[2065]: Starting albumart workers Apr 04 08:57:46 volumio volumio[2065]: Starting albumart workers Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:57:46 volumio volumio[2065]: error: updateQueue error: null Apr 04 08:57:46 volumio volumio[2065]: info: VolumeController:: Volume=86 Mute =false Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::pushState Apr 04 08:57:46 volumio volumio[2065]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::updateTrackBlock Apr 04 08:57:46 volumio volumio[2065]: info: CorePlayQueue::getTrackBlock Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::volumioRetrievevolume Apr 04 08:57:46 volumio volumio[2065]: Starting albumart workers Apr 04 08:57:46 volumio volumio[2065]: info: Reloading queue from file Apr 04 08:57:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Apr 04 08:57:46 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::setRepeat true single undefined Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::pushState Apr 04 08:57:46 volumio volumio[2065]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::setRandom true Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::pushState Apr 04 08:57:46 volumio volumio[2065]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:46 volumio volumio[2065]: info: Setting Device type: Raspberry PI Apr 04 08:57:46 volumio volumio[2065]: error: updateQueue error: null Apr 04 08:57:46 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:46 volumio go-librespot[2187]: Librespot-go daemon starting... Apr 04 08:57:46 volumio go-librespot[2187]: time="2024-04-04T08:57:46+09:00" level=info msg="generated new device id: 1350f037a9edffe0d20742569cfc82cd9a92d205" Apr 04 08:57:46 volumio go-librespot[2187]: time="2024-04-04T08:57:46+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:46 volumio volumio[2065]: info: VolumeController:: Volume=86 Mute =false Apr 04 08:57:46 volumio volumio[2065]: info: CoreStateMachine::pushState Apr 04 08:57:46 volumio volumio[2065]: info: CorePlayQueue::getTrack 0 Apr 04 08:57:46 volumio volumio[2065]: info: CoreCommandRouter::volumioPushState Apr 04 08:57:46 volumio go-librespot[2187]: time="2024-04-04T08:57:46+09: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" Apr 04 08:57:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:47.7157] 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 Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:48.0321] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1 Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5067] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5072] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5075] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5109] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5120] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5128] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5144] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5187] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.5205] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Apr 04 08:57:49 volumio squeezeboxserver[2141]: [24-04-04 08:57:49.6668] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Apr 04 08:57:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Apr 04 08:57:49 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:50 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:50 volumio go-librespot[2220]: Librespot-go daemon starting... Apr 04 08:57:50 volumio go-librespot[2220]: time="2024-04-04T08:57:50+09:00" level=info msg="generated new device id: d52ccf8916fc5ea48067df1f3de5185f37512529" Apr 04 08:57:50 volumio go-librespot[2220]: time="2024-04-04T08:57:50+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:50 volumio go-librespot[2220]: time="2024-04-04T08:57:50+09: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" Apr 04 08:57:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:50 volumio sudo[2228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 04 08:57:50 volumio sudo[2228]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:50 volumio sudo[2228]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:50 volumio sudo[2231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 04 08:57:50 volumio sudo[2231]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:50 volumio sudo[2231]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:50 volumio sudo[2234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 04 08:57:50 volumio sudo[2234]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:50 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 04 08:57:50 volumio sudo[2234]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:50 volumio volumio[2065]: info: Upmpdcli Daemon Started Apr 04 08:57:50 volumio mpd[2120]: client: [2] opened from 127.0.0.1:51428 Apr 04 08:57:50 volumio mpd[2120]: client: [3] opened from 127.0.0.1:51436 Apr 04 08:57:50 volumio squeezeboxserver[2141]: [24-04-04 08:57:50.8725] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Apr 04 08:57:51 volumio volumio[2065]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:57:51 volumio volumio[2065]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:57:51 volumio sudo[2250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:51 volumio sudo[2250]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:51 volumio sudo[2250]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:51 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:51 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:51 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:51 volumio volumio[2065]: info: Cannot mount NAS share at system boot, trial number 2 ,retrying in 5 seconds Apr 04 08:57:51 volumio mpd[2120]: exception: No database Apr 04 08:57:51 volumio mpd[2120]: exception: No database Apr 04 08:57:51 volumio mpd[2120]: exception: No database Apr 04 08:57:51 volumio volumio[2065]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.4574] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (System error) Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.4955] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.4962] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.4983] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5021] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (System error) Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5030] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5044] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5050] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5068] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5691] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5706] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5719] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5770] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5865] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5874] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.084 seconds. Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5883] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5889] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5897] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5912] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.001 seconds. Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5930] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5936] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.001 seconds. Apr 04 08:57:51 volumio squeezeboxserver[2141]: [24-04-04 08:57:51.5944] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Apr 04 08:57:52 volumio squeezeboxserver[2141]: [24-04-04 08:57:52.5978] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 1.003 seconds. Apr 04 08:57:53 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:57:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Apr 04 08:57:53 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:53 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:53 volumio go-librespot[2254]: Librespot-go daemon starting... Apr 04 08:57:53 volumio go-librespot[2254]: time="2024-04-04T08:57:53+09:00" level=info msg="generated new device id: b59ce96d4712eed68ccf6b71ff36f959692e3a56" Apr 04 08:57:53 volumio go-librespot[2254]: time="2024-04-04T08:57:53+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:53 volumio go-librespot[2254]: time="2024-04-04T08:57:53+09: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" Apr 04 08:57:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:54 volumio volumio[2065]: adding device F4:73:35:9D:A0:E8 Apr 04 08:57:54 volumio volumio[2065]: deleting device F4:73:35:9D:A0:E8 Apr 04 08:57:56 volumio volumio[2065]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:57:56 volumio volumio[2065]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:57:56 volumio volumio[2065]: adding device F4:73:35:9D:A0:E8 Apr 04 08:57:56 volumio sudo[2263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:57:56 volumio sudo[2263]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:57:56 volumio sudo[2263]: pam_unix(sudo:session): session closed for user root Apr 04 08:57:56 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:57:56 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:57:56 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:57:56 volumio volumio[2065]: info: Cannot mount NAS share at system boot, trial number 3 ,retrying in 5 seconds Apr 04 08:57:56 volumio volumio[2065]: deleting device F4:73:35:9D:A0:E8 Apr 04 08:57:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Apr 04 08:57:56 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:56 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:56 volumio go-librespot[2267]: Librespot-go daemon starting... Apr 04 08:57:56 volumio go-librespot[2267]: time="2024-04-04T08:57:56+09:00" level=info msg="generated new device id: d0145da8ebc3f59665ef7fd523a116834488de61" Apr 04 08:57:56 volumio go-librespot[2267]: time="2024-04-04T08:57:56+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:56 volumio go-librespot[2267]: time="2024-04-04T08:57:56+09: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" Apr 04 08:57:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:57:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:57:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Apr 04 08:57:59 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:57:59 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:57:59 volumio go-librespot[2274]: Librespot-go daemon starting... Apr 04 08:57:59 volumio go-librespot[2274]: time="2024-04-04T08:57:59+09:00" level=info msg="generated new device id: 6a7b42f6c7b165b4a978abf54044869b59436ef0" Apr 04 08:57:59 volumio go-librespot[2274]: time="2024-04-04T08:57:59+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:57:59 volumio go-librespot[2274]: time="2024-04-04T08:57:59+09: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" Apr 04 08:57:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:57:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:00 volumio wpa_supplicant[757]: wlan0: Failed to initiate sched scan Apr 04 08:58:01 volumio volumio[2065]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:58:01 volumio volumio[2065]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:58:01 volumio sudo[2282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:58:01 volumio sudo[2282]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:58:01 volumio sudo[2282]: pam_unix(sudo:session): session closed for user root Apr 04 08:58:01 volumio volumio[2065]: info: Cannot mount NAS share at system boot, trial number 4 ,retrying in 5 seconds Apr 04 08:58:01 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:58:01 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:58:01 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:58:02 volumio kernel: usb 1-1.4: new low-speed USB device number 3 using xhci_hcd Apr 04 08:58:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:58:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Apr 04 08:58:02 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:58:02 volumio kernel: usb 1-1.4: New USB device found, idVendor=04d9, idProduct=1203, bcdDevice= 2.80 Apr 04 08:58:02 volumio kernel: usb 1-1.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Apr 04 08:58:02 volumio kernel: input: HID 04d9:1203 as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4:1.0/0003:04D9:1203.0001/input/input0 Apr 04 08:58:02 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:58:02 volumio go-librespot[2286]: Librespot-go daemon starting... Apr 04 08:58:02 volumio go-librespot[2286]: time="2024-04-04T08:58:02+09:00" level=info msg="generated new device id: 93e81665e75c8f80e6ac60fcabb5468b02b41a99" Apr 04 08:58:02 volumio go-librespot[2286]: time="2024-04-04T08:58:02+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:58:02 volumio go-librespot[2286]: time="2024-04-04T08:58:02+09: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" Apr 04 08:58:02 volumio kernel: hid-generic 0003:04D9:1203.0001: input,hidraw0: USB HID v1.11 Keyboard [HID 04d9:1203] on usb-0000:01:00.0-1.4/input0 Apr 04 08:58:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:58:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:02 volumio kernel: input: HID 04d9:1203 System Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4:1.1/0003:04D9:1203.0002/input/input1 Apr 04 08:58:02 volumio kernel: input: HID 04d9:1203 Consumer Control as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4:1.1/0003:04D9:1203.0002/input/input2 Apr 04 08:58:02 volumio kernel: hid-generic 0003:04D9:1203.0002: input,hidraw1: USB HID v1.11 Device [HID 04d9:1203] on usb-0000:01:00.0-1.4/input1 Apr 04 08:58:03 volumio systemd-udevd[2297]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 04 08:58:03 volumio systemd-logind[514]: Watching system buttons on /dev/input/event0 (HID 04d9:1203) Apr 04 08:58:03 volumio systemd-udevd[2295]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 04 08:58:03 volumio systemd-udevd[2298]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 04 08:58:03 volumio systemd-logind[514]: Watching system buttons on /dev/input/event1 (HID 04d9:1203 System Control) Apr 04 08:58:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:58:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Apr 04 08:58:05 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:58:06 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:58:06 volumio go-librespot[2304]: Librespot-go daemon starting... Apr 04 08:58:06 volumio go-librespot[2304]: time="2024-04-04T08:58:06+09:00" level=info msg="generated new device id: 6b5323bd5d062901681a9cf625a2cfaf58d88a96" Apr 04 08:58:06 volumio volumio[2065]: checking info of 84:30:95:C9:D4:C5 Apr 04 08:58:06 volumio volumio[2065]: checking info of 40:DE:17:96:F3:C7 Apr 04 08:58:06 volumio go-librespot[2304]: time="2024-04-04T08:58:06+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:58:06 volumio go-librespot[2304]: time="2024-04-04T08:58:06+09: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" Apr 04 08:58:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:58:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:06 volumio sudo[2312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=yasuhiro,password=7unboboj@mwakana,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.11.2/share /mnt/NAS/share Apr 04 08:58:06 volumio sudo[2312]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:58:06 volumio sudo[2312]: pam_unix(sudo:session): session closed for user root Apr 04 08:58:06 volumio volumio[2065]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Apr 04 08:58:06 volumio kernel: CIFS: Attempting to mount \\192.168.11.2\share Apr 04 08:58:06 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Apr 04 08:58:06 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Apr 04 08:58:08 volumio wpa_supplicant[757]: wlan0: CTRL-EVENT-SSID-REENABLED id=1 ssid="Buffalo-G-3000" Apr 04 08:58:08 volumio wpa_supplicant[757]: wlan0: Trying to associate with SSID 'Buffalo-G-3000' Apr 04 08:58:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:58:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Apr 04 08:58:09 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:58:09 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:58:09 volumio go-librespot[2316]: Librespot-go daemon starting... Apr 04 08:58:09 volumio go-librespot[2316]: time="2024-04-04T08:58:09+09:00" level=info msg="generated new device id: 92996860c1897ad5487840d4b0acfc04d6c0fef0" Apr 04 08:58:09 volumio go-librespot[2316]: time="2024-04-04T08:58:09+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:58:09 volumio go-librespot[2316]: time="2024-04-04T08:58:09+09: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" Apr 04 08:58:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:58:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: carrier acquired Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: connected to Access Point `Buffalo-G-3000' Apr 04 08:58:11 volumio wpa_supplicant[757]: wlan0: Associated with 00:e5:f1:8d:50:87 Apr 04 08:58:11 volumio wpa_supplicant[757]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:e5:f1:8d:50:87 completed [id=1 id_str=] Apr 04 08:58:11 volumio wpa_supplicant[757]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 04 08:58:11 volumio wpa_supplicant[757]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=JP Apr 04 08:58:11 volumio dhcpcd[769]: DUID 00:01:00:01:2c:c5:42:9f:d8:3a:dd:13:64:dd Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: IAID dd:13:64:dd Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: adding address fe80::da3a:ddff:fe13:64dd Apr 04 08:58:11 volumio dhcpcd[769]: ipv6_addaddr1: Permission denied Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: carrier lost Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: carrier acquired Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: IAID dd:13:64:dd Apr 04 08:58:11 volumio login[684]: pam_unix(login:auth): authentication failure; logname=LOGIN uid=0 euid=0 tty=/dev/tty1 ruser= rhost= user=volumio Apr 04 08:58:11 volumio dhcpcd[769]: wlan0: soliciting an IPv6 router Apr 04 08:58:12 volumio dhcpcd[769]: wlan0: rebinding lease of 192.168.11.19 Apr 04 08:58:12 volumio dhcpcd[769]: wlan0: probing address 192.168.11.19/24 Apr 04 08:58:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:58:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Apr 04 08:58:12 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:58:12 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:58:12 volumio go-librespot[2335]: Librespot-go daemon starting... Apr 04 08:58:12 volumio go-librespot[2335]: time="2024-04-04T08:58:12+09:00" level=info msg="generated new device id: 469a108eaff5138b6ae00913261ef2d1e6b63ec7" Apr 04 08:58:12 volumio go-librespot[2335]: time="2024-04-04T08:58:12+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:58:12 volumio go-librespot[2335]: time="2024-04-04T08:58:12+09: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" Apr 04 08:58:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:58:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:14 volumio login[684]: FAILED LOGIN (1) on '/dev/tty1' FOR 'volumio', Authentication failure Apr 04 08:58:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 04 08:58:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Apr 04 08:58:15 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:58:15 volumio volumio[2065]: error: Plugin audio_interface bluetooth_controller failed to complete 'onVolumioStart' in a timely fashion Apr 04 08:58:15 volumio volumio[2065]: info: Preparing to generate the ALSA configuration file Apr 04 08:58:15 volumio volumio[2065]: info: Asound.conf file unchanged, so no further update is needed Apr 04 08:58:15 volumio volumio[2065]: info: Output device has changed, restarting MPD Apr 04 08:58:15 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:58:15 volumio go-librespot[2342]: Librespot-go daemon starting... Apr 04 08:58:15 volumio go-librespot[2342]: time="2024-04-04T08:58:15+09:00" level=info msg="generated new device id: 5135756eda28be0ed62526bf3f8ccae8d822fa3b" Apr 04 08:58:15 volumio go-librespot[2342]: time="2024-04-04T08:58:15+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:58:15 volumio go-librespot[2342]: time="2024-04-04T08:58:15+09: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" Apr 04 08:58:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:58:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:15 volumio sudo[2350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 04 08:58:15 volumio sudo[2350]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:58:15 volumio sudo[2350]: pam_unix(sudo:session): session closed for user root Apr 04 08:58:15 volumio volumio[2065]: info: Output device has changed, restarting Shairport Sync Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:58:15 volumio sudo[2353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 04 08:58:15 volumio sudo[2353]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:58:15 volumio systemd[1]: Stopping Music Player Daemon... Apr 04 08:58:15 volumio systemd[1]: mpd.service: Succeeded. Apr 04 08:58:15 volumio systemd[1]: Stopped Music Player Daemon. Apr 04 08:58:15 volumio volumio[2065]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 04 08:58:15 volumio volumio[2065]: info: ___________ START PLUGINS ___________ Apr 04 08:58:15 volumio systemd[1]: Starting Music Player Daemon... Apr 04 08:58:15 volumio volumio[2065]: info: Set bluetooth disvoverable to true Apr 04 08:58:15 volumio volumio[2065]: info: Starting bluetooth device scan Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:58:15 volumio volumio[2065]: info: [1712188695945] CoreMusicLibrary::Adding element Media Servers Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:15 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:58:16 volumio volumio[2065]: info: [1712188696049] CoreMusicLibrary::Adding element Last_100 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:58:16 volumio volumio[2065]: info: [1712188696052] CoreMusicLibrary::Adding element Webradio Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 04 08:58:16 volumio volumio[2065]: info: Creating Spotify config file Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: [squeezelite_mc] Starting proxy server... Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:58:16 volumio volumio[2065]: info: [1712188696130] CoreMusicLibrary::Adding element YouTube2 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:58:16 volumio volumio[2065]: Cannot find translation for source YouTube2 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 04 08:58:16 volumio volumio[2065]: info: [1712188696135] CoreMusicLibrary::Adding element YouTube Music Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 04 08:58:16 volumio volumio[2065]: Cannot find translation for source YouTube2 Apr 04 08:58:16 volumio volumio[2065]: Cannot find translation for source YouTube Music Apr 04 08:58:16 volumio volumio[2065]: info: AutoStart - onStart Apr 04 08:58:16 volumio volumio[2065]: info: Volumio Calling Home Apr 04 08:58:16 volumio sudo[2369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Apr 04 08:58:16 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:58:16 volumio systemd[1]: Stopping Logitech Media Server Daemon... Apr 04 08:58:16 volumio volumio[2065]: info: [squeezelite_mc] Proxy server started on port 34503 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::volumioRetrievevolume Apr 04 08:58:16 volumio squeezeboxserver[2141]: [24-04-04 08:57:52.8764] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Apr 04 08:58:16 volumio squeezeboxserver[2141]: [24-04-04 08:58:11.7261] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting https://www.mysqueezebox.com/api/sounds/v1/opml Apr 04 08:58:16 volumio squeezeboxserver[2141]: Couldn't resolve IP address for: www.mysqueezebox.com Apr 04 08:58:16 volumio squeezeboxserver[2141]: [24-04-04 08:58:11.7265] Slim::Plugin::Sounds::Plugin::_gotSoundsError (82) Error: Unable to cache Sounds & Effects menu from SN: Couldn't resolve IP address for: www.mysqueezebox.com Apr 04 08:58:16 volumio volumio[2065]: Unhandled rejection Error: No sockets available, cannot start. Apr 04 08:58:16 volumio volumio[2065]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Apr 04 08:58:16 volumio volumio[2065]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Apr 04 08:58:16 volumio volumio[2065]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Apr 04 08:58:16 volumio volumio[2065]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Apr 04 08:58:16 volumio volumio[2065]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Apr 04 08:58:16 volumio volumio[2065]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Apr 04 08:58:16 volumio volumio[2065]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Apr 04 08:58:16 volumio volumio[2065]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Apr 04 08:58:16 volumio volumio[2065]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Apr 04 08:58:16 volumio volumio[2065]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Apr 04 08:58:16 volumio volumio[2065]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Apr 04 08:58:16 volumio volumio[2065]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 04 08:58:16 volumio volumio[2065]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 04 08:58:16 volumio volumio[2065]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Apr 04 08:58:16 volumio volumio[2065]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Apr 04 08:58:16 volumio volumio[2065]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 04 08:58:16 volumio volumio[2065]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org Apr 04 08:58:16 volumio volumio[2065]: info: MPD Permissions set Apr 04 08:58:16 volumio volumio[2065]: info: Spotify config file written Apr 04 08:58:16 volumio systemd[1]: logitechmediaserver.service: Succeeded. Apr 04 08:58:16 volumio systemd[1]: Stopped Logitech Media Server Daemon. Apr 04 08:58:16 volumio sudo[2378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 04 08:58:16 volumio sudo[2378]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 04 08:58:16 volumio volumio[2065]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Apr 04 08:58:16 volumio volumio[2065]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio systemd[1]: Starting Logitech Media Server Daemon... Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 04 08:58:16 volumio systemd[1]: Started go-librespot Daemon. Apr 04 08:58:16 volumio sudo[2378]: pam_unix(sudo:session): session closed for user root Apr 04 08:58:16 volumio go-librespot[2385]: Librespot-go daemon starting... Apr 04 08:58:16 volumio systemd[1]: Started Logitech Media Server Daemon. Apr 04 08:58:16 volumio sudo[2369]: pam_unix(sudo:session): session closed for user root Apr 04 08:58:16 volumio go-librespot[2385]: time="2024-04-04T08:58:16+09:00" level=info msg="generated new device id: 5f99c03e52d951821e01d23ffbb038a2896230e3" Apr 04 08:58:16 volumio go-librespot[2385]: time="2024-04-04T08:58:16+09:00" level=debug msg="stored credentials found for 315wy7c33abzyqqrxscdlcmly6ci" Apr 04 08:58:16 volumio go-librespot[2385]: time="2024-04-04T08:58:16+09: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" Apr 04 08:58:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 04 08:58:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 04 08:58:16 volumio volumio[2065]: info: VolumeController:: Volume=86 Mute =false Apr 04 08:58:16 volumio volumio[2065]: info: CoreStateMachine::pushState Apr 04 08:58:16 volumio volumio[2065]: info: CorePlayQueue::getTrack 0 Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::volumioPushState Apr 04 08:58:16 volumio volumio[2065]: info: [squeezelite_mc] Server discovery started Apr 04 08:58:16 volumio volumio[2065]: info: [squeezelite_mc] Player finder started Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 04 08:58:16 volumio volumio[2065]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Apr 04 08:58:16 volumio volumio[2065]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 04 08:58:16 volumio volumio[2065]: Error: send ENETUNREACH 255.255.255.255:3483 Apr 04 08:58:16 volumio volumio[2065]: at doSend (dgram.js:692:16) Apr 04 08:58:16 volumio volumio[2065]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Apr 04 08:58:16 volumio volumio[2065]: at afterDns (dgram.js:638:5) Apr 04 08:58:16 volumio volumio[2065]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Apr 04 08:58:16 volumio volumio[2065]: errno: -101, Apr 04 08:58:16 volumio volumio[2065]: code: 'ENETUNREACH', Apr 04 08:58:16 volumio volumio[2065]: syscall: 'send', Apr 04 08:58:16 volumio volumio[2065]: address: '255.255.255.255', Apr 04 08:58:16 volumio volumio[2065]: port: 3483 Apr 04 08:58:16 volumio volumio[2065]: } Apr 04 08:58:16 volumio volumio[2065]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 04 08:58:16 volumio mpd[2367]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 04 08:58:16 volumio mpd[2367]: config: Found database setting without music_directory - disabling database Apr 04 08:58:16 volumio mpd[2367]: output: No 'audio_output' defined in config file Apr 04 08:58:16 volumio mpd[2367]: output: Attempt to detect audio output device Apr 04 08:58:16 volumio mpd[2367]: output: Attempting to detect a alsa audio device Apr 04 08:58:16 volumio mpd[2367]: output: Successfully detected a alsa audio device Apr 04 08:58:16 volumio mpd[2367]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 04 08:58:16 volumio mpd[2367]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 04 08:58:16 volumio mpd[2367]: zeroconf: No global port, disabling zeroconf Apr 04 08:58:16 volumio systemd[1]: Started Music Player Daemon. Apr 04 08:58:16 volumio sudo[2353]: pam_unix(sudo:session): session closed for user root Apr 04 08:58:16 volumio dhcpcd[769]: wlan0: leased 192.168.11.19 for 172800 seconds Apr 04 08:58:16 volumio avahi-daemon[501]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.11.19. Apr 04 08:58:16 volumio dhcpcd[769]: wlan0: adding route to 192.168.11.0/24 Apr 04 08:58:16 volumio dhcpcd[769]: wlan0: adding default route via 192.168.11.1 Apr 04 08:58:16 volumio avahi-daemon[501]: New relevant interface wlan0.IPv4 for mDNS. Apr 04 08:58:16 volumio avahi-daemon[501]: Registering new address record for 192.168.11.19 on wlan0.IPv4. Apr 04 08:58:17 volumio sudo[2427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-04 08:57 Apr 04 08:58:17 volumio sudo[2427]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"