-- Logs begin at Fri 2024-04-19 10:27:50 UTC, end at Fri 2024-04-19 10:30:38 UTC. -- Apr 19 10:29:00 volumio volumio[1073]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 19 10:29:00 volumio volumio[1073]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 19 10:29:00 volumio volumio[1073]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 19 10:29:00 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 19 10:29:00 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 19 10:29:00 volumio volumio[1073]: info: Starting MyVolumio Remote Streaming Endpoints Apr 19 10:29:01 volumio volumio[1073]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 19 10:29:01 volumio volumio[1073]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 19 10:29:01 volumio volumio[1073]: info: Streaming services startup Apr 19 10:29:01 volumio volumio[1073]: info: Starting Streaming Daemon Apr 19 10:29:01 volumio sudo[1232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 19 10:29:01 volumio volumio[1073]: info: MyVolumio not started Apr 19 10:29:01 volumio volumio[1073]: info: Initializing device activation check Apr 19 10:29:01 volumio sudo[1232]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 19 10:29:01 volumio systemd[1]: Stopping Volumio Streaming Daemon... Apr 19 10:29:01 volumio volumio[1073]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 19 10:29:01 volumio systemd[1]: Starting Volumio Streaming Daemon... Apr 19 10:29:01 volumio systemd[1]: Started Volumio Streaming Daemon. Apr 19 10:29:01 volumio sudo[1232]: pam_unix(sudo:session): session closed for user root Apr 19 10:29:01 volumio volumio-streaming-daemon[1242]: ############################ Apr 19 10:29:01 volumio volumio-streaming-daemon[1242]: # Volumio Streaming Daemon # Apr 19 10:29:01 volumio volumio-streaming-daemon[1242]: # Running on port 7777 # Apr 19 10:29:01 volumio volumio-streaming-daemon[1242]: ############################ Apr 19 10:29:01 volumio volumio-streaming-daemon[1242]: Environment: production Apr 19 10:29:03 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand status Apr 19 10:29:03 volumio volumio[1073]: info: Apr 19 10:29:03 volumio volumio[1073]: ---------------------------- MPD announces state update: update Apr 19 10:29:03 volumio volumio[1073]: info: ControllerMpd::getState Apr 19 10:29:03 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand status Apr 19 10:29:03 volumio volumio[1073]: verbose: ControllerMpd::parseState Apr 19 10:29:03 volumio dhcpcd[547]: timed out Apr 19 10:29:03 volumio dhcpcd[547]: exited Apr 19 10:29:03 volumio ifup[525]: dhcpcd[547]: timed out Apr 19 10:29:03 volumio ifup[525]: dhcpcd[547]: exited Apr 19 10:29:03 volumio ifup[525]: Failed to bring up eth0. Apr 19 10:29:07 volumio volumio[1073]: info: Command Router : Notfying DB Updatefalse Apr 19 10:29:07 volumio volumio[1073]: info: CoreCommandRouter::Close All Modals sent Apr 19 10:29:07 volumio volumio[1073]: verbose: ControllerMpd::parseState Apr 19 10:29:07 volumio volumio[1073]: info: ControllerMpd::pushState Apr 19 10:29:07 volumio volumio[1073]: info: CoreCommandRouter::servicePushState Apr 19 10:29:07 volumio volumio[1073]: info: CoreStateMachine::pushState Apr 19 10:29:08 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:08 volumio volumio[1073]: info: CoreCommandRouter::volumioPushState Apr 19 10:29:08 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 10:29:08 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:08 volumio volumio[1073]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 19 10:29:08 volumio volumio[1073]: info: ------------------------------ 4909ms Apr 19 10:29:08 volumio volumio[1073]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.861&uuid=092cfaf002ff8684a2d496083d40a25f" http://updates.volumio.org:7070/downloader-v1/track-device Apr 19 10:29:08 volumio volumio[1073]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 19 10:29:08 volumio volumio[1073]: Dload Upload Total Spent Left Speed Apr 19 10:29:08 volumio volumio[1073]: 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused Apr 19 10:29:08 volumio volumio[1073]: retrying in 5 seconds, trial 0 Apr 19 10:29:08 volumio volumio[1073]: Volumio Calling Home Apr 19 10:29:08 volumio volumio-streaming-daemon[1242]: Environment: production Apr 19 10:29:08 volumio volumio[1073]: info: Fetching Streaming Services browse cache Apr 19 10:29:18 volumio volumio[1073]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.861&uuid=092cfaf002ff8684a2d496083d40a25f" http://updates.volumio.org:7070/downloader-v1/track-device Apr 19 10:29:18 volumio volumio[1073]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 19 10:29:18 volumio volumio[1073]: Dload Upload Total Spent Left Speed Apr 19 10:29:18 volumio volumio[1073]: [235B blob data] Apr 19 10:29:18 volumio volumio[1073]: retrying in 5 seconds, trial 1 Apr 19 10:29:18 volumio volumio[1073]: Volumio Calling Home Apr 19 10:29:19 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 19 10:29:19 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 19 10:29:21 volumio volumio[1073]: info: CoreCommandRouter::volumioGetVisibleSources Apr 19 10:29:21 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 19 10:29:21 volumio volumio[1073]: info: CoreCommandRouter::volumioGetState Apr 19 10:29:21 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:21 volumio volumio[1073]: info: CoreCommandRouter::volumioGetQueue Apr 19 10:29:21 volumio volumio[1073]: info: CoreStateMachine::getQueue Apr 19 10:29:21 volumio volumio[1073]: info: CorePlayQueue::getQueue Apr 19 10:29:21 volumio volumio[1073]: info: Listing playlists Apr 19 10:29:21 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 19 10:29:30 volumio volumio[1073]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=2.861&uuid=092cfaf002ff8684a2d496083d40a25f" http://updates.volumio.org:7070/downloader-v1/track-device Apr 19 10:29:30 volumio volumio[1073]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 19 10:29:30 volumio volumio[1073]: Dload Upload Total Spent Left Speed Apr 19 10:29:30 volumio volumio[1073]: [314B blob data] Apr 19 10:29:30 volumio volumio[1073]: retrying in 5 seconds, trial 2 Apr 19 10:29:30 volumio volumio[1073]: Volumio Calling Home Apr 19 10:29:32 volumio volumio[1073]: info: CoreCommandRouter::volumioPlay Apr 19 10:29:32 volumio volumio[1073]: UNSET VOLATILE Apr 19 10:29:32 volumio volumio[1073]: info: CoreStateMachine::play index undefined Apr 19 10:29:32 volumio volumio[1073]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 19 10:29:32 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:32 volumio volumio[1073]: info: CoreStateMachine::startPlaybackTimer Apr 19 10:29:32 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:32 volumio volumio[1073]: info: [1713522572972] ControllerWebradio::clearAddPlayTrack Apr 19 10:29:32 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand stop Apr 19 10:29:32 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand clear Apr 19 10:29:32 volumio volumio[1073]: info: Apr 19 10:29:32 volumio volumio[1073]: ---------------------------- MPD announces system playlist update Apr 19 10:29:32 volumio volumio[1073]: info: Ignoring MPD Status Update Apr 19 10:29:32 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand load "http://svr1.msmn.co:8136" Apr 19 10:29:32 volumio volumio[1073]: error: updateQueue error: null Apr 19 10:29:32 volumio volumio[1073]: info: ------------------------------ 2ms Apr 19 10:29:37 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand add "http://svr1.msmn.co:8136" Apr 19 10:29:37 volumio volumio[1073]: info: Apr 19 10:29:37 volumio volumio[1073]: ---------------------------- MPD announces system playlist update Apr 19 10:29:37 volumio volumio[1073]: info: Ignoring MPD Status Update Apr 19 10:29:37 volumio volumio[1073]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 19 10:29:37 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand play Apr 19 10:29:37 volumio volumio[1073]: info: ------------------------------ 3ms Apr 19 10:29:40 volumio volumio[1073]: info: Apr 19 10:29:40 volumio volumio[1073]: ---------------------------- MPD announces state update: player Apr 19 10:29:40 volumio volumio[1073]: info: ControllerMpd::getState Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand status Apr 19 10:29:40 volumio volumio[1073]: info: Apr 19 10:29:40 volumio volumio[1073]: ---------------------------- MPD announces system playlist update Apr 19 10:29:40 volumio volumio[1073]: info: Ignoring MPD Status Update Apr 19 10:29:40 volumio volumio[1073]: info: Apr 19 10:29:40 volumio volumio[1073]: ---------------------------- MPD announces state update: player Apr 19 10:29:40 volumio volumio[1073]: info: ControllerMpd::getState Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand status Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::parseState Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 10:29:40 volumio volumio[1073]: info: ------------------------------ 5ms Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::parseState Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::parseTrackInfo Apr 19 10:29:40 volumio volumio[1073]: info: ControllerMpd::pushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::servicePushState Apr 19 10:29:40 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:40 volumio volumio[1073]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"GIFT - Wish Me Away","artist":null,"album":null,"uri":"http://svr1.msmn.co:8136","trackType":"co:8136"} Apr 19 10:29:40 volumio volumio[1073]: verbose: CURRENT POSITION 0 Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::syncState stateService play Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::syncState currentStatus stop Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::pushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::volumioPushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 10:29:40 volumio volumio[1073]: info: ------------------------------ 16ms Apr 19 10:29:40 volumio volumio[1073]: verbose: ControllerMpd::parseTrackInfo Apr 19 10:29:40 volumio volumio[1073]: info: ControllerMpd::pushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::servicePushState Apr 19 10:29:40 volumio volumio[1073]: info: CorePlayQueue::getTrack 0 Apr 19 10:29:40 volumio volumio[1073]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"GIFT - Wish Me Away","artist":null,"album":null,"uri":"http://svr1.msmn.co:8136","trackType":"co:8136"} Apr 19 10:29:40 volumio volumio[1073]: verbose: CURRENT POSITION 0 Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::syncState stateService play Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::syncState currentStatus play Apr 19 10:29:40 volumio volumio[1073]: info: Received an update from plugin. extracting info from payload Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::pushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::volumioPushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 10:29:40 volumio volumio[1073]: info: CoreStateMachine::pushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::volumioPushState Apr 19 10:29:40 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 19 10:29:40 volumio volumio[1073]: info: ------------------------------ 22ms Apr 19 10:29:52 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 19 10:30:04 volumio volumio[1073]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 19 10:30:04 volumio volumio[1073]: info: CURURI: albums:// Apr 19 10:30:04 volumio volumio[1073]: listAlbums - loading Albums from cache Apr 19 10:30:04 volumio volumio[1073]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%A6%B9S%EF%BC%88%E3%82%B7%E3%82%B9%E3%82%BF%E3%83%BC%E3%82%BA%EF%BC%89/%E3%81%8B%E3%81%8F%E3%81%97%E3%82%93%E7%9A%84%E2%98%86%E3%82%81%E3%81%9F%E3%81%BE%E3%82%8B%E3%81%B5%E3%81%89%EF%BD%9E%E3%81%9C%E3%81%A3%EF%BC%81/24dac14c-73a9-4786-a4ba-1953d13da9aa.jpg' Apr 19 10:30:04 volumio volumio[1073]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%9B%9B%E6%9C%88%E3%81%AF%E5%90%9B%E3%81%AE%E5%98%98%E3%80%80%E3%83%88%E3%82%A5%E3%82%A4%E3%83%B3%E3%82%AF%E3%83%AB%20%E3%83%AA%E3%83%88%E3%83%AB%E3%82%B9%E3%82%BF%E3%83%BC/%E5%9B%9B%E6%9C%88%E3%81%AF%E5%90%9B%E3%81%AE%E5%98%98%20%E3%83%88%E3%82%A5%E3%82%A4%E3%83%B3%E3%82%AF%E3%83%AB%20%E3%83%AA%E3%83%88%E3%83%AB%E3%82%B9%E3%82%BF%E3%83%BC/8e2959d4-a409-4a9b-b07e-44ed3c21b815.jpg' Apr 19 10:30:04 volumio volumio[1073]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E8%A5%BF%E6%B2%A2%20%E5%B9%B8%E5%A5%8F/%E5%90%B9%E9%9B%AA/8f41dcd7-0576-4146-8db9-f7fa686e4823.jpg' Apr 19 10:30:04 volumio volumio[1073]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/AKINO%20from%20bless4/%E6%B5%B7%E8%89%B2/d0845b7f-0908-49c3-9bdf-ff898ba05ce4.jpg' Apr 19 10:30:04 volumio volumio[1073]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E4%BD%90%E5%92%B2%E7%B4%97%E8%8A%B1/SAYAKAVER./46598a90-ff10-421c-ae9a-8135d0b7e164.png' Apr 19 10:30:04 volumio volumio[1073]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/angela/%E5%AE%9D%E7%AE%B1%20-TREASURE%20BOX-/b47f6d53-227d-4e93-9219-38ffdeb5a7ab.jpg' Apr 19 10:30:37 volumio volumio[1073]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 19 10:30:37 volumio volumio[1073]: { Error: connect ETIMEDOUT 31.13.95.48:443 Apr 19 10:30:37 volumio volumio[1073]: at Object._errnoException (util.js:1022:11) Apr 19 10:30:37 volumio volumio[1073]: at _exceptionWithHostPort (util.js:1044:20) Apr 19 10:30:37 volumio volumio[1073]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Apr 19 10:30:37 volumio volumio[1073]: code: 'ETIMEDOUT', Apr 19 10:30:37 volumio volumio[1073]: errno: 'ETIMEDOUT', Apr 19 10:30:37 volumio volumio[1073]: syscall: 'connect', Apr 19 10:30:37 volumio volumio[1073]: address: '31.13.95.48', Apr 19 10:30:37 volumio volumio[1073]: port: 443 } Apr 19 10:30:37 volumio volumio[1073]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 19 10:30:38 volumio sudo[1489]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-19 10:29 Apr 19 10:30:38 volumio sudo[1489]: 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="168ba7444df98cd868db72f24faec0b6346489cc" VOLUMIO_FE_VERSION="847a48ecf32d35cc502a0053d585d1a69236e391" VOLUMIO_BE_VERSION="03f7bbd984817e093cac62b7ff876f3c2cfabc1d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Dec 22 14:39:52 CET 2020" VOLUMIO_VERSION="2.861" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="097e28ee6263e31d0bf6b690a02dcab3"