-- Logs begin at Sat 2024-11-23 15:38:56 UTC, end at Sat 2024-11-23 15:57:24 UTC. -- Nov 23 15:56:02 fph volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 23 15:56:02 fph volumio[4457]: info: CURURI: albums:// Nov 23 15:56:02 fph volumio[4457]: listAlbums - loading Albums from cache Nov 23 15:56:02 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/HOYO-MiX/Da%20Capo/d3b3a109-c014-4797-be31-449e15eff49d.jpg' Nov 23 15:56:02 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Delacey/Dream%20It%20Possible/ad7e94f2-7db8-4281-98d6-68693b089d58.jpg' Nov 23 15:56:02 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Michael%20Hunter/Grand%20Theft%20Auto%3A%20San%20Andreas%20Official%20Soundtrack/7df991f0-d63e-4ac7-a4d7-d7ef1638a568.jpg' Nov 23 15:56:02 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Against%20the%20Current/Legends%20Never%20Die/59b0f245-29cb-4bfd-8f40-73b5f2091902.jpg' Nov 23 15:56:03 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E8%A2%81%E5%A8%85%E7%BB%B4TIA%20RAY/Starfall/46477470-251f-47be-aff6-bfd0b4f640a7.png' Nov 23 15:56:04 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/HOYO-MiX/%E5%8E%9F%E7%A5%9E-%E5%95%81%E5%93%B3%E6%B5%81%E5%8F%98%E4%B9%8B%E7%A0%82%20The%20Unfathomable%20Sand%20Dunes/7b95e6ec-38cb-4f71-92a8-003526cb61c9.jpg' Nov 23 15:56:04 fph volumio[4457]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E9%99%88%E8%87%B4%E9%80%B8%2FHOYO-MiX/%E5%8E%9F%E7%A5%9E-%E5%AF%82%E8%BF%9C%E6%97%A0%E5%A6%84%E4%B9%8B%E5%9B%BD%20Realm%20of%20Tranquil%20Eternity/2f92224e-c1ba-483b-9b7a-3d846326926e.png' Nov 23 15:56:16 fph volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 23 15:56:16 fph volumio[4457]: info: CURURI: albums://HOYO-MiX%E3%80%81Reol/%E5%B4%A9%E5%9D%8F%E6%98%9F%E7%A9%B9%E9%93%81%E9%81%93-%E4%B8%8D%E4%B9%B1%E4%B8%8D%E7%A0%B4%20No%20Dazzle%2C%20No%20Break Nov 23 15:56:21 fph volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 23 15:56:21 fph volumio[4457]: info: CURURI: playlists Nov 23 15:56:21 fph volumio[4457]: info: Listing playlists Nov 23 15:56:28 fph volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 23 15:56:28 fph volumio[4457]: info: CURURI: artists:// Nov 23 15:56:36 fph volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 23 15:56:36 fph volumio[4457]: info: CURURI: playlists Nov 23 15:56:36 fph volumio[4457]: info: Listing playlists Nov 23 15:56:37 fph volumio[4457]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 15:56:37 fph volumio[4457]: { Error: connect ETIMEDOUT 157.240.1.9:443 Nov 23 15:56:37 fph volumio[4457]: at Object._errnoException (util.js:1022:11) Nov 23 15:56:37 fph volumio[4457]: at _exceptionWithHostPort (util.js:1044:20) Nov 23 15:56:37 fph volumio[4457]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Nov 23 15:56:37 fph volumio[4457]: code: 'ETIMEDOUT', Nov 23 15:56:37 fph volumio[4457]: errno: 'ETIMEDOUT', Nov 23 15:56:37 fph volumio[4457]: syscall: 'connect', Nov 23 15:56:37 fph volumio[4457]: address: '157.240.1.9', Nov 23 15:56:37 fph volumio[4457]: port: 443 } Nov 23 15:56:37 fph volumio[4457]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 15:56:38 fph sudo[5081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-23 15:55 Nov 23 15:56:38 fph sudo[5081]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:38 fph sudo[5081]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:40 fph volumio-remote-updater[598]: [2024-11-23 15:56:40] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 23 15:56:40 fph volumio-remote-updater[598]: [2024-11-23 15:56:40] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 23 15:56:40 fph systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE Nov 23 15:56:40 fph systemd[1]: Unit volumio.service entered failed state. Nov 23 15:56:40 fph systemd[1]: Starting dynamicswap service... Nov 23 15:56:40 fph systemd[1]: Started dynamicswap service. Nov 23 15:56:40 fph systemd[1]: volumio.service holdoff time over, scheduling restart. Nov 23 15:56:40 fph systemd[1]: Starting dynamicswap service... Nov 23 15:56:40 fph systemd[1]: Started dynamicswap service. Nov 23 15:56:40 fph systemd[1]: Stopping Volumio Backend Module... Nov 23 15:56:40 fph systemd[1]: Starting Volumio Backend Module... Nov 23 15:56:40 fph systemd[1]: Started Volumio Backend Module. Nov 23 15:56:42 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:42 fph volumio[5110]: info: ----- Volumio2 ---- Nov 23 15:56:42 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:42 fph volumio[5110]: info: ----- System startup ---- Nov 23 15:56:42 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:43 fph volumio[5110]: info: MYVOLUMIO Environment detected Nov 23 15:56:43 fph volumio[5110]: info: Plugin folders cleanup Nov 23 15:56:43 fph volumio[5110]: info: Scanning into folder /volumio/app/plugins/ Nov 23 15:56:43 fph volumio[5110]: info: Scanning category audio_interface Nov 23 15:56:43 fph volumio[5110]: info: Scanning category miscellanea Nov 23 15:56:43 fph volumio[5110]: info: Scanning category music_service Nov 23 15:56:43 fph volumio[5110]: info: Scanning category plugins.json Nov 23 15:56:43 fph volumio[5110]: info: Scanning category system_controller Nov 23 15:56:43 fph volumio[5110]: info: Scanning category user_interface Nov 23 15:56:43 fph volumio[5110]: info: Scanning into folder /data/plugins/ Nov 23 15:56:43 fph volumio[5110]: info: Plugin folders cleanup completed Nov 23 15:56:43 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:43 fph volumio[5110]: info: ----- Core plugins startup ---- Nov 23 15:56:43 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:43 fph volumio[5110]: info: Loading plugins from folder /volumio/app/plugins/ Nov 23 15:56:43 fph volumio[5110]: info: Adding plugin upnp to MyMusic Plugins Nov 23 15:56:43 fph volumio[5110]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 23 15:56:43 fph volumio[5110]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 23 15:56:43 fph volumio[5110]: info: Loading plugins from folder /data/plugins/ Nov 23 15:56:43 fph volumio[5110]: info: Loading plugin "system"... Nov 23 15:56:43 fph volumio[5110]: info: Loading plugin "appearance"... Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "network"... Nov 23 15:56:44 fph volumio[5110]: info: Refreshing Cached IP Addresses Nov 23 15:56:44 fph sudo[5131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "services"... Nov 23 15:56:44 fph sudo[5131]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "alsa_controller"... Nov 23 15:56:44 fph sudo[5131]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:44 fph sudo[5135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 23 15:56:44 fph sudo[5135]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:44 fph sudo[5135]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "wizard"... Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "volumio_command_line_client"... Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "upnp"... Nov 23 15:56:44 fph volumio[5110]: info: [1732377404848] Starting Upmpd Daemon Nov 23 15:56:44 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "my_music"... Nov 23 15:56:44 fph volumio[5110]: info: Loading plugin "mpd"... Nov 23 15:56:45 fph volumio-remote-updater[598]: [2024-11-23 15:56:45] [connect] Successful connection Nov 23 15:56:45 fph volumio[5110]: info: Loading plugin "upnp_browser"... Nov 23 15:56:45 fph volumio[5110]: info: Loading plugin "networkfs"... Nov 23 15:56:45 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 15:56:45 fph volumio[5110]: info: Loading plugin "alarm-clock"... Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "airplay_emulation"... Nov 23 15:56:46 fph volumio[5110]: info: Starting Shairport Sync Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "last_100"... Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "webradio"... Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "i2s_dacs"... Nov 23 15:56:46 fph volumio[5110]: info: I2S DAC not set, start Auto-detection Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "volumiodiscovery"... Nov 23 15:56:46 fph volumio[5110]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 23 15:56:46 fph node[5110]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 23 15:56:46 fph node[5110]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 15:56:46 fph node[5110]: *** WARNING *** For more information see Nov 23 15:56:46 fph node[5110]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 23 15:56:46 fph node[5110]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 15:56:46 fph node[5110]: *** WARNING *** For more information see Nov 23 15:56:46 fph volumio[5110]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 15:56:46 fph volumio[5110]: *** WARNING *** For more information see Nov 23 15:56:46 fph volumio[5110]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 23 15:56:46 fph volumio[5110]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 15:56:46 fph volumio[5110]: *** WARNING *** For more information see Nov 23 15:56:46 fph volumio[5110]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 23 15:56:46 fph volumio[5110]: Discovery: StartAdv! undefined Nov 23 15:56:46 fph volumio[5110]: Discovery: Started advertising... fph - undefined Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "outputs"... Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "albumart"... Nov 23 15:56:46 fph volumio[5110]: info: Plugin example_plugin is not enabled Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "inputs"... Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "updater_comm"... Nov 23 15:56:46 fph volumio[5110]: info: Plugin mpdemulation is not enabled Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "rest_api"... Nov 23 15:56:46 fph volumio[5110]: info: Loading plugin "websocket"... Nov 23 15:56:46 fph volumio[5110]: info: ___________ START PLUGINS ___________ Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 15:56:46 fph volumio[5110]: info: [1732377406644] CoreMusicLibrary::Adding element Media Servers Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:56:46 fph volumio[5110]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 15:56:46 fph volumio[5110]: Forking 3 albumart workers Nov 23 15:56:46 fph volumio[5110]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 15:56:46 fph volumio[5110]: info: [1732377406786] CoreMusicLibrary::Adding element Last_100 Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 15:56:46 fph volumio[5110]: info: [1732377406794] CoreMusicLibrary::Adding element Webradio Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 15:56:46 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:46 fph volumio[5110]: info: ----- MyVolumio plugins startup ---- Nov 23 15:56:46 fph volumio[5110]: info: ------------------------------------------- Nov 23 15:56:46 fph volumio[5110]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 23 15:56:46 fph volumio[5110]: info: Loading i18n strings for locale zh Nov 23 15:56:46 fph volumio[5110]: Updating browse sources language Nov 23 15:56:46 fph volumio[5110]: Cannot find translation for sourceMedia Servers Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::initPlayerControls Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 15:56:46 fph volumio[5110]: info: BOOT COMPLETED Nov 23 15:56:46 fph volumio[5110]: [Metrics] CommandRouter: 4s 540.45ms Nov 23 15:56:46 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 15:56:47 fph volumio[5110]: aplay: main:722: audio open error: Device or resource busy Nov 23 15:56:47 fph volumio[5110]: Cannot play startup sound Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::Close All Modals sent Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::Close All Modals sent Nov 23 15:56:47 fph volumio[5110]: Express server listening on port 3000 Nov 23 15:56:47 fph volumio[5110]: [Metrics] WebUI: 5s 248.82ms Nov 23 15:56:47 fph volumio[5110]: Volumio Calling Home Nov 23 15:56:47 fph volumio[5110]: info: CoreStateMachine::resetVolumioState Nov 23 15:56:47 fph volumio[5110]: info: CoreStateMachine::getcurrentVolume Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::volumioRetrievevolume Nov 23 15:56:47 fph volumio[5110]: info: Setting Device type: Raspberry PI Nov 23 15:56:47 fph volumio[5110]: info: MPD running with PID4774 Nov 23 15:56:47 fph volumio[5110]: ,establishing connection Nov 23 15:56:47 fph sudo[5203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cdetect -y 1 Nov 23 15:56:47 fph sudo[5203]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:47 fph sudo[5203]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:47 fph volumio-remote-updater[598]: [2024-11-23 15:56:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1732377405 101 Nov 23 15:56:47 fph volumio[5110]: Starting albumart workers Nov 23 15:56:47 fph volumio[5110]: Starting albumart workers Nov 23 15:56:47 fph volumio[5110]: Starting albumart workers Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 15:56:47 fph volumio[5110]: info: VolumeController:: Volume=20 Mute =false Nov 23 15:56:47 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:47 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:47 fph volumio[5110]: info: CoreStateMachine::updateTrackBlock Nov 23 15:56:47 fph volumio[5110]: info: CorePlayQueue::getTrackBlock Nov 23 15:56:47 fph volumio[5110]: info: CoreCommandRouter::volumioRetrievevolume Nov 23 15:56:48 fph volumio[5110]: info: Reloading queue from file Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 23 15:56:48 fph volumio[5110]: info: CoreStateMachine::setRepeat null single undefined Nov 23 15:56:48 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:48 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:48 fph volumio[5110]: info: CoreStateMachine::setRandom null Nov 23 15:56:48 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:48 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:48 fph volumio[5110]: info: Starting Shairport Sync Nov 23 15:56:48 fph volumio[5110]: info: Starting Shairport Sync Nov 23 15:56:48 fph sudo[5217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 15:56:48 fph sudo[5217]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:48 fph sudo[5220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 15:56:48 fph systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 23 15:56:48 fph systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Nov 23 15:56:48 fph sudo[5217]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:48 fph systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 23 15:56:48 fph sudo[5220]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:48 fph systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 23 15:56:48 fph systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Nov 23 15:56:48 fph systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 23 15:56:48 fph sudo[5220]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:48 fph volumio[5110]: info: VolumeController:: Volume=20 Mute =false Nov 23 15:56:48 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:48 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:48 fph volumio[5110]: Discovery: adding 6208a7e1-d9d7-420b-9d75-4187f19b1d7f Nov 23 15:56:48 fph volumio[5110]: info: mDNS: Found device fph Nov 23 15:56:48 fph volumio[5110]: info: CoreCommandRouter::volumioGetState Nov 23 15:56:48 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:48 fph volumio[5110]: info: Shairport-Sync Started Nov 23 15:56:48 fph volumio[5110]: Error adding Membership: Error: addMembership EINVAL Nov 23 15:56:48 fph volumio[5110]: info: Shairport-Sync Started Nov 23 15:56:49 fph volumio[5110]: info: Nov 23 15:56:49 fph volumio[5110]: ---------------------------- Client requests Volume 20 Nov 23 15:56:49 fph volumio[5110]: info: VolumeController::SetAlsaVolume20 Nov 23 15:56:49 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:49 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:49 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:49 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:49 fph volumio[5110]: info: Setting volume on startup at 20 Nov 23 15:56:49 fph volumio[5110]: info: CoreCommandRouter::volumioGetState Nov 23 15:56:49 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:50 fph volumio[5110]: info: Nov 23 15:56:50 fph volumio[5110]: ---------------------------- MPD announces state update: player Nov 23 15:56:50 fph volumio[5110]: info: ControllerMpd::getState Nov 23 15:56:50 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand status Nov 23 15:56:50 fph volumio[5110]: verbose: ControllerMpd::parseState Nov 23 15:56:50 fph volumio[5110]: info: ControllerMpd::pushState Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::servicePushState Nov 23 15:56:50 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:50 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:50 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:50 fph volumio[5110]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 23 15:56:50 fph volumio[5110]: verbose: CURRENT POSITION 0 Nov 23 15:56:50 fph volumio[5110]: info: CoreStateMachine::syncState stateService stop Nov 23 15:56:50 fph volumio[5110]: info: CoreStateMachine::syncState currentStatus stop Nov 23 15:56:50 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:50 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:50 fph volumio[5110]: info: No code Nov 23 15:56:50 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:56:50 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:56:50 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:56:50 fph volumio[5110]: info: ------------------------------ 43ms Nov 23 15:56:51 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 15:56:51 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 15:56:55 fph sudo[5296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 23 15:56:55 fph sudo[5296]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:55 fph sudo[5296]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:55 fph sudo[5299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 23 15:56:55 fph sudo[5299]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:55 fph sudo[5299]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:55 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 23 15:56:55 fph volumio[5110]: info: CoreCommandRouter::volumioGetState Nov 23 15:56:55 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:56:55 fph sudo[5316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 23 15:56:55 fph sudo[5316]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:56:55 fph systemd[1]: Started UPnP Renderer front-end to MPD. Nov 23 15:56:55 fph sudo[5316]: pam_unix(sudo:session): session closed for user root Nov 23 15:56:55 fph volumio[5110]: info: Upmpdcli Daemon Started Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 23 15:56:57 fph volumio[5110]: info: Adding plugin bluetooth to MyMusic Plugins Nov 23 15:56:57 fph volumio[5110]: info: Adding plugin cd_controller to MyMusic Plugins Nov 23 15:56:57 fph volumio[5110]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 23 15:56:57 fph volumio[5110]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 23 15:56:58 fph volumio[5110]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 23 15:56:59 fph volumio[5110]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 23 15:56:59 fph volumio[5110]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 23 15:56:59 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 15:56:59 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 15:56:59 fph volumio[5110]: info: Starting MyVolumio Remote Streaming Endpoints Nov 23 15:56:59 fph volumio[5110]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 23 15:56:59 fph volumio[5110]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 23 15:56:59 fph volumio[5110]: info: Streaming services startup Nov 23 15:56:59 fph volumio[5110]: info: Starting Streaming Daemon Nov 23 15:56:59 fph volumio[5110]: info: MyVolumio not started Nov 23 15:56:59 fph volumio[5110]: info: Initializing device activation check Nov 23 15:56:59 fph sudo[5327]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 23 15:57:00 fph sudo[5327]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 15:57:00 fph systemd[1]: Stopping Volumio Streaming Daemon... Nov 23 15:57:00 fph volumio[5110]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 23 15:57:00 fph systemd[1]: Starting Volumio Streaming Daemon... Nov 23 15:57:00 fph systemd[1]: Started Volumio Streaming Daemon. Nov 23 15:57:00 fph sudo[5327]: pam_unix(sudo:session): session closed for user root Nov 23 15:57:00 fph volumio-streaming-daemon[5333]: ############################ Nov 23 15:57:00 fph volumio-streaming-daemon[5333]: # Volumio Streaming Daemon # Nov 23 15:57:00 fph volumio-streaming-daemon[5333]: # Running on port 7777 # Nov 23 15:57:00 fph volumio-streaming-daemon[5333]: ############################ Nov 23 15:57:00 fph volumio-streaming-daemon[5333]: Environment: production Nov 23 15:57:00 fph volumio[5110]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.834&uuid=d3edd34654f211fa5ebda10adecd2d54" http://updates.volumio.org:7070/downloader-v1/track-device Nov 23 15:57:00 fph volumio[5110]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 23 15:57:00 fph volumio[5110]: Dload Upload Total Spent Left Speed Nov 23 15:57:00 fph volumio[5110]: [235B blob data] Nov 23 15:57:00 fph volumio[5110]: retrying in 5 seconds, trial 0 Nov 23 15:57:00 fph volumio[5110]: Volumio Calling Home Nov 23 15:57:02 fph volumio-streaming-daemon[5333]: Environment: production Nov 23 15:57:02 fph volumio[5110]: info: Fetching Streaming Services browse cache Nov 23 15:57:02 fph volumio[5110]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesTIDAL Nov 23 15:57:02 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:57:02 fph volumio[5110]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesQOBUZ Nov 23 15:57:02 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetState Nov 23 15:57:04 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 23 15:57:04 fph volumio[5110]: info: Listing playlists Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetQueue Nov 23 15:57:04 fph volumio[5110]: info: CoreStateMachine::getQueue Nov 23 15:57:04 fph volumio[5110]: info: CorePlayQueue::getQueue Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetVisibleSources Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetState Nov 23 15:57:04 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 23 15:57:04 fph volumio[5110]: info: Listing playlists Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetQueue Nov 23 15:57:04 fph volumio[5110]: info: CoreStateMachine::getQueue Nov 23 15:57:04 fph volumio[5110]: info: CorePlayQueue::getQueue Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetVisibleSources Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetState Nov 23 15:57:04 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 23 15:57:04 fph volumio[5110]: info: Listing playlists Nov 23 15:57:04 fph volumio[5110]: info: CoreCommandRouter::volumioGetQueue Nov 23 15:57:04 fph volumio[5110]: info: CoreStateMachine::getQueue Nov 23 15:57:04 fph volumio[5110]: info: CorePlayQueue::getQueue Nov 23 15:57:05 fph volumio[5110]: info: CoreCommandRouter::volumioGetVisibleSources Nov 23 15:57:05 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 15:57:10 fph volumio[5110]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.834&uuid=d3edd34654f211fa5ebda10adecd2d54" http://updates.volumio.org:7070/downloader-v1/track-device Nov 23 15:57:10 fph volumio[5110]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 23 15:57:10 fph volumio[5110]: Dload Upload Total Spent Left Speed Nov 23 15:57:10 fph volumio[5110]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused Nov 23 15:57:10 fph volumio[5110]: retrying in 5 seconds, trial 1 Nov 23 15:57:10 fph volumio[5110]: Volumio Calling Home Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::volumioPlay Nov 23 15:57:11 fph systemd[1]: Starting Cleanup of Temporary Directories... Nov 23 15:57:11 fph volumio[5110]: UNSET VOLATILE Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::play index undefined Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::startPlaybackTimer Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::clearAddPlayTracks USB/FPH/music/HOYO-MiX - Da Capo.flac Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand stop Nov 23 15:57:11 fph systemd[1]: Started Cleanup of Temporary Directories. Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand clear Nov 23 15:57:11 fph volumio[5110]: info: Nov 23 15:57:11 fph volumio[5110]: ---------------------------- MPD announces system playlist update Nov 23 15:57:11 fph volumio[5110]: info: Ignoring MPD Status Update Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand add "USB/FPH/music/HOYO-MiX - Da Capo.flac" Nov 23 15:57:11 fph volumio[5110]: error: updateQueue error: null Nov 23 15:57:11 fph volumio[5110]: info: Nov 23 15:57:11 fph volumio[5110]: ---------------------------- MPD announces system playlist update Nov 23 15:57:11 fph volumio[5110]: info: Ignoring MPD Status Update Nov 23 15:57:11 fph volumio[5110]: info: ------------------------------ 8ms Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand play Nov 23 15:57:11 fph volumio[5110]: info: ------------------------------ 5ms Nov 23 15:57:11 fph volumio[5110]: info: Nov 23 15:57:11 fph volumio[5110]: ---------------------------- MPD announces state update: player Nov 23 15:57:11 fph volumio[5110]: info: ControllerMpd::getState Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand status Nov 23 15:57:11 fph volumio[5110]: info: Nov 23 15:57:11 fph volumio[5110]: ---------------------------- MPD announces state update: player Nov 23 15:57:11 fph volumio[5110]: info: ControllerMpd::getState Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand status Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::parseState Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::parseState Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::parseTrackInfo Nov 23 15:57:11 fph volumio[5110]: info: ControllerMpd::pushState Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::servicePushState Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: verbose: STATE SERVICE {"status":"play","position":0,"seek":95,"duration":135,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2534 Kbps","isStreaming":false,"title":"Da Capo","artist":"HOYO-MiX","album":"Da Capo","uri":"USB/FPH/music/HOYO-MiX - Da Capo.flac","trackType":"flac"} Nov 23 15:57:11 fph volumio[5110]: verbose: CURRENT POSITION 0 Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::syncState stateService play Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::syncState currentStatus stop Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:11 fph volumio[5110]: info: ------------------------------ 33ms Nov 23 15:57:11 fph volumio[5110]: verbose: ControllerMpd::parseTrackInfo Nov 23 15:57:11 fph volumio[5110]: info: ControllerMpd::pushState Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::servicePushState Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: verbose: STATE SERVICE {"status":"play","position":0,"seek":416,"duration":135,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2527 Kbps","isStreaming":false,"title":"Da Capo","artist":"HOYO-MiX","album":"Da Capo","uri":"USB/FPH/music/HOYO-MiX - Da Capo.flac","trackType":"flac"} Nov 23 15:57:11 fph volumio[5110]: verbose: CURRENT POSITION 0 Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::syncState stateService play Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::syncState currentStatus play Nov 23 15:57:11 fph volumio[5110]: info: Received an update from plugin. extracting info from payload Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:11 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:11 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:11 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:11 fph volumio[5110]: info: ------------------------------ 66ms Nov 23 15:57:13 fph volumio[5110]: info: CoreCommandRouter::volumioPause Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::pause Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::stPlaybackTimer Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::servicePause Nov 23 15:57:13 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:13 fph volumio[5110]: info: CoreCommandRouter::servicePause Nov 23 15:57:13 fph volumio[5110]: info: ControllerMpd::pause Nov 23 15:57:13 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand pause Nov 23 15:57:13 fph volumio[5110]: info: Nov 23 15:57:13 fph volumio[5110]: ---------------------------- MPD announces state update: player Nov 23 15:57:13 fph volumio[5110]: info: ControllerMpd::getState Nov 23 15:57:13 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand status Nov 23 15:57:13 fph volumio[5110]: verbose: ControllerMpd::parseState Nov 23 15:57:13 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 15:57:13 fph volumio[5110]: verbose: ControllerMpd::parseTrackInfo Nov 23 15:57:13 fph volumio[5110]: info: ControllerMpd::pushState Nov 23 15:57:13 fph volumio[5110]: info: CoreCommandRouter::servicePushState Nov 23 15:57:13 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:13 fph volumio[5110]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":1866,"duration":135,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2830 Kbps","isStreaming":false,"title":"Da Capo","artist":"HOYO-MiX","album":"Da Capo","uri":"USB/FPH/music/HOYO-MiX - Da Capo.flac","trackType":"flac"} Nov 23 15:57:13 fph volumio[5110]: verbose: CURRENT POSITION 0 Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::syncState stateService pause Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::syncState currentStatus pause Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:13 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:13 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:13 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:13 fph volumio[5110]: info: CoreStateMachine::stPlaybackTimer Nov 23 15:57:13 fph volumio[5110]: info: ------------------------------ 19ms Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::volumioPlay Nov 23 15:57:16 fph volumio[5110]: UNSET VOLATILE Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::play index undefined Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 15:57:16 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::startPlaybackTimer Nov 23 15:57:16 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:16 fph volumio[5110]: info: ControllerMpd::resume Nov 23 15:57:16 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand play Nov 23 15:57:16 fph volumio[5110]: info: Nov 23 15:57:16 fph volumio[5110]: ---------------------------- MPD announces state update: player Nov 23 15:57:16 fph volumio[5110]: info: ControllerMpd::getState Nov 23 15:57:16 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand status Nov 23 15:57:16 fph volumio[5110]: verbose: ControllerMpd::parseState Nov 23 15:57:16 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 15:57:16 fph volumio[5110]: verbose: ControllerMpd::parseTrackInfo Nov 23 15:57:16 fph volumio[5110]: info: ControllerMpd::pushState Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::servicePushState Nov 23 15:57:16 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:16 fph volumio[5110]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2165,"duration":135,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2812 Kbps","isStreaming":false,"title":"Da Capo","artist":"HOYO-MiX","album":"Da Capo","uri":"USB/FPH/music/HOYO-MiX - Da Capo.flac","trackType":"flac"} Nov 23 15:57:16 fph volumio[5110]: verbose: CURRENT POSITION 0 Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::syncState stateService play Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::syncState currentStatus pause Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:16 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:16 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:16 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:16 fph volumio[5110]: info: ------------------------------ 31ms Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 15:57:16 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 15:57:17 fph volumio[5110]: info: CoreCommandRouter::volumioPause Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::pause Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::stPlaybackTimer Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::servicePause Nov 23 15:57:17 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:17 fph volumio[5110]: info: CoreCommandRouter::servicePause Nov 23 15:57:17 fph volumio[5110]: info: ControllerMpd::pause Nov 23 15:57:17 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand pause Nov 23 15:57:17 fph volumio[5110]: info: Nov 23 15:57:17 fph volumio[5110]: ---------------------------- MPD announces state update: player Nov 23 15:57:17 fph volumio[5110]: info: ControllerMpd::getState Nov 23 15:57:17 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand status Nov 23 15:57:17 fph volumio[5110]: verbose: ControllerMpd::parseState Nov 23 15:57:17 fph volumio[5110]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 15:57:17 fph volumio[5110]: verbose: ControllerMpd::parseTrackInfo Nov 23 15:57:17 fph volumio[5110]: info: ControllerMpd::pushState Nov 23 15:57:17 fph volumio[5110]: info: CoreCommandRouter::servicePushState Nov 23 15:57:17 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:17 fph volumio[5110]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3114,"duration":135,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2806 Kbps","isStreaming":false,"title":"Da Capo","artist":"HOYO-MiX","album":"Da Capo","uri":"USB/FPH/music/HOYO-MiX - Da Capo.flac","trackType":"flac"} Nov 23 15:57:17 fph volumio[5110]: verbose: CURRENT POSITION 0 Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::syncState stateService pause Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::syncState currentStatus pause Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::pushState Nov 23 15:57:17 fph volumio[5110]: info: CorePlayQueue::getTrack 0 Nov 23 15:57:17 fph volumio[5110]: info: CoreCommandRouter::volumioPushState Nov 23 15:57:17 fph volumio[5110]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 15:57:17 fph volumio[5110]: info: CoreStateMachine::stPlaybackTimer Nov 23 15:57:17 fph volumio[5110]: info: ------------------------------ 18ms Nov 23 15:57:21 fph volumio[5110]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.834&uuid=d3edd34654f211fa5ebda10adecd2d54" http://updates.volumio.org:7070/downloader-v1/track-device Nov 23 15:57:21 fph volumio[5110]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 23 15:57:21 fph volumio[5110]: Dload Upload Total Spent Left Speed Nov 23 15:57:21 fph volumio[5110]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused Nov 23 15:57:21 fph volumio[5110]: retrying in 5 seconds, trial 2 Nov 23 15:57:21 fph volumio[5110]: Volumio Calling Home Nov 23 15:57:23 fph volumio[5110]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 15:57:23 fph volumio[5110]: { Error: connect ETIMEDOUT 208.77.47.172:80 Nov 23 15:57:23 fph volumio[5110]: at Object._errnoException (util.js:1022:11) Nov 23 15:57:23 fph volumio[5110]: at _exceptionWithHostPort (util.js:1044:20) Nov 23 15:57:23 fph volumio[5110]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Nov 23 15:57:23 fph volumio[5110]: code: 'ETIMEDOUT', Nov 23 15:57:23 fph volumio[5110]: errno: 'ETIMEDOUT', Nov 23 15:57:23 fph volumio[5110]: syscall: 'connect', Nov 23 15:57:23 fph volumio[5110]: address: '208.77.47.172', Nov 23 15:57:23 fph volumio[5110]: port: 80 } Nov 23 15:57:23 fph volumio[5110]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 15:57:24 fph sudo[5432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-23 15:56 Nov 23 15:57:24 fph sudo[5432]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="74e4cc9de715c64d553d35948d017f973a622b6d" VOLUMIO_FE_VERSION="2be6c28eb9de74ec1f9662ca333f7bd51a232c33" VOLUMIO_BE_VERSION="259a7f2894e1376413ffac331be84e0e9a6173dd" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Sep 24 22:42:43 CEST 2020" VOLUMIO_VERSION="2.834" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="e41ef0f29aa50c1af109d3064a380c69"