-- Logs begin at Wed 2024-10-23 08:34:19 EEST, end at Wed 2024-10-23 09:05:49 EEST. -- Oct 23 09:04:02 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:04:20 volumio volumio[1236]: error: error Oct 23 09:04:20 volumio volumio[1236]: error: error Oct 23 09:04:23 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:04:43 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces system playlist update Oct 23 09:04:54 volumio volumio[1236]: info: Ignoring MPD Status Update Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces state update: player Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::getState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand status Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces system playlist update Oct 23 09:04:54 volumio volumio[1236]: info: Ignoring MPD Status Update Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces state update: player Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::getState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand status Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces system playlist update Oct 23 09:04:54 volumio volumio[1236]: info: Ignoring MPD Status Update Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces state update: player Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::getState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand status Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces system playlist update Oct 23 09:04:54 volumio volumio[1236]: info: Ignoring MPD Status Update Oct 23 09:04:54 volumio volumio[1236]: info: Oct 23 09:04:54 volumio volumio[1236]: ---------------------------- MPD announces state update: player Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::getState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand status Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 6ms Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand status took 5 milliseconds Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 5ms Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand status took 4 milliseconds Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 4ms Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand status took 8 milliseconds Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 9ms Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand status took 8 milliseconds Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseState Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseTrackInfo Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseTrackInfo Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::pushState Oct 23 09:04:54 volumio volumio[1236]: info: CoreCommandRouter::servicePushState Oct 23 09:04:54 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:04:54 volumio volumio[1236]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::pushState Oct 23 09:04:54 volumio volumio[1236]: info: CoreCommandRouter::servicePushState Oct 23 09:04:54 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:04:54 volumio volumio[1236]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 15ms Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 14ms Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 23 09:04:54 volumio volumio[1236]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseTrackInfo Oct 23 09:04:54 volumio volumio[1236]: verbose: ControllerMpd::parseTrackInfo Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::pushState Oct 23 09:04:54 volumio volumio[1236]: info: CoreCommandRouter::servicePushState Oct 23 09:04:54 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:04:54 volumio volumio[1236]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 23 09:04:54 volumio volumio[1236]: info: ControllerMpd::pushState Oct 23 09:04:54 volumio volumio[1236]: info: CoreCommandRouter::servicePushState Oct 23 09:04:54 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:04:54 volumio volumio[1236]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 15ms Oct 23 09:04:54 volumio volumio[1236]: info: ------------------------------ 14ms Oct 23 09:05:03 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:03 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:09 volumio volumio[1236]: error: error Oct 23 09:05:09 volumio volumio[1236]: error: error Oct 23 09:05:23 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:23 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:29 volumio volumio[1236]: info: [1729663529430] [80s80s] Pushing the next song state Eurythmics - Sweet Dreams (Are Made of This) and getting next track. Oct 23 09:05:29 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:05:29 volumio volumio[1236]: info: CoreCommandRouter::servicePushState Oct 23 09:05:29 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:05:29 volumio volumio[1236]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music114/v4/ee/bc/55/eebc5593-3a6d-99c4-8b9c-063692fd3389/source/600x600bb.jpg","name":"Eurythmics - Sweet Dreams (Are Made of This)","title":"Sweet Dreams (Are Made of This)","artist":"80s80s Party","album":"","streaming":true,"disableUiControls":true,"duration":"203","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Oct 23 09:05:29 volumio volumio[1236]: verbose: CURRENT POSITION 0 Oct 23 09:05:29 volumio volumio[1236]: info: CoreStateMachine::syncState stateService play Oct 23 09:05:29 volumio volumio[1236]: info: CoreStateMachine::syncState currentStatus play Oct 23 09:05:29 volumio volumio[1236]: info: Received an update from plugin. extracting info from payload Oct 23 09:05:29 volumio volumio[1236]: info: CoreStateMachine::pushState Oct 23 09:05:29 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:05:29 volumio volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 23 09:05:29 volumio volumio[1236]: info: CoreCommandRouter::volumioPushState Oct 23 09:05:29 volumio volumio[1236]: info: CoreStateMachine::pushState Oct 23 09:05:29 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:05:29 volumio volumio[1236]: info: CoreCommandRouter::volumioPushState Oct 23 09:05:29 volumio volumio[1236]: info: [1729663529452] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=252&count=1 Oct 23 09:05:29 volumio volumio[1236]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 23 09:05:29 volumio volumio[1236]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 23 09:05:29 volumio sudo[6071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 23 09:05:29 volumio sudo[6071]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 23 09:05:29 volumio sudo[6071]: pam_unix(sudo:session): session closed for user root Oct 23 09:05:29 volumio volumio[1236]: info: peppymeterbasic Daemon Started Oct 23 09:05:29 volumio sudo[6075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 23 09:05:29 volumio sudo[6075]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 23 09:05:29 volumio volumio[1236]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 23 09:05:29 volumio volumio[1236]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Eurythmics - Sweet Dreams","album":"","artist":"80s80s Party","duration":"203","uri":"http://streams.80s80s.de/party/mp3-192/volumio","service":""} Oct 23 09:05:29 volumio sudo[6075]: pam_unix(sudo:session): session closed for user root Oct 23 09:05:29 volumio volumio[1236]: info: peppymeterbasic Daemon Started Oct 23 09:05:29 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:05:29 volumio volumio[1236]: info: CorePlayQueue::getTrack 0 Oct 23 09:05:29 volumio volumio[1236]: info: Prefetching next song Oct 23 09:05:43 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:43 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:43 volumio volumio[4716]: libpng warning: iCCP: known incorrect sRGB profile Oct 23 09:05:45 volumio volumio[1236]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/weather?appid=5796abbde9106b7da4febfae8c44c232&lat=45.452995&lon=26.337554: Error: Response error: 401 - Unauthorized Oct 23 09:05:45 volumio volumio[1236]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 23 09:05:45 volumio volumio[1236]: at runMicrotasks () Oct 23 09:05:45 volumio volumio[1236]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 23 09:05:45 volumio volumio[1236]: at async Promise.all (index 1) Oct 23 09:05:45 volumio volumio[1236]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Oct 23 09:05:45 volumio volumio[1236]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Oct 23 09:05:45 volumio volumio[1236]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Oct 23 09:05:45 volumio volumio[1236]: info: [now-playing] Fetching API key... Oct 23 09:05:45 volumio volumio[1236]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/onecall?appid=5796abbde9106b7da4febfae8c44c232&lat=45.452995&lon=26.337554: Error: Response error: 401 - Unauthorized Oct 23 09:05:45 volumio volumio[1236]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 23 09:05:45 volumio volumio[1236]: at runMicrotasks () Oct 23 09:05:45 volumio volumio[1236]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 23 09:05:45 volumio volumio[1236]: at async Promise.all (index 0) Oct 23 09:05:46 volumio volumio[1236]: info: [now-playing] OpenWeatherMap API key obtained. Oct 23 09:05:46 volumio volumio[1236]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/onecall?appid=5796abbde9106b7da4febfae8c44c232&lat=45.452995&lon=26.337554: Error: Response error: 401 - Unauthorized Oct 23 09:05:46 volumio volumio[1236]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 23 09:05:46 volumio volumio[1236]: at runMicrotasks () Oct 23 09:05:46 volumio volumio[1236]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 23 09:05:46 volumio volumio[1236]: at async Promise.all (index 0) Oct 23 09:05:46 volumio volumio[1236]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Oct 23 09:05:46 volumio volumio[1236]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Oct 23 09:05:46 volumio volumio[1236]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Oct 23 09:05:46 volumio volumio[1236]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not fetch weather: Response error: 401 - Unauthorized Oct 23 09:05:46 volumio volumio[1236]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:114:19) Oct 23 09:05:46 volumio volumio[1236]: at runMicrotasks () Oct 23 09:05:46 volumio volumio[1236]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 23 09:05:46 volumio volumio[1236]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:28) Oct 23 09:05:46 volumio volumio[1236]: (node:1236) UnhandledPromiseRejectionWarning: Error: Response error: 401 - Unauthorized Oct 23 09:05:46 volumio volumio[1236]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 23 09:05:46 volumio volumio[1236]: at runMicrotasks () Oct 23 09:05:46 volumio volumio[1236]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 23 09:05:46 volumio volumio[1236]: at async Promise.all (index 0) Oct 23 09:05:46 volumio volumio[1236]: at async fetchData (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:84:24) Oct 23 09:05:46 volumio volumio[1236]: at async OpenWeatherMapAPI.getWeather (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:97:45) Oct 23 09:05:46 volumio volumio[1236]: at async /data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:297:25 Oct 23 09:05:46 volumio volumio[1236]: (node:1236) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 10) Oct 23 09:05:46 volumio volumio[1236]: error: [now-playing] Error fetching https://openweathermap.org/data/2.5/weather?appid=5796abbde9106b7da4febfae8c44c232&lat=45.452995&lon=26.337554: Error: Response error: 401 - Unauthorized Oct 23 09:05:46 volumio volumio[1236]: at fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:29:15) Oct 23 09:05:46 volumio volumio[1236]: at runMicrotasks () Oct 23 09:05:46 volumio volumio[1236]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Oct 23 09:05:46 volumio volumio[1236]: at async Promise.all (index 1) Oct 23 09:05:48 volumio volumio[1236]: info: [1729663548917] [80s80s] Failed to query api, status code: 503 Oct 23 09:05:48 volumio volumio[1236]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 23 09:05:48 volumio volumio[1236]: Error: ENOENT: no such file or directory, open '/data/plugins/music_service/80s80s/fake-data.json' Oct 23 09:05:48 volumio volumio[1236]: at Object.openSync (fs.js:498:3) Oct 23 09:05:48 volumio volumio[1236]: at Object.readFileSync (fs.js:394:35) Oct 23 09:05:48 volumio volumio[1236]: at ClientRequest. (/data/plugins/music_service/80s80s/index.js:485:23) Oct 23 09:05:48 volumio volumio[1236]: at Object.onceWrapper (events.js:520:26) Oct 23 09:05:48 volumio volumio[1236]: at ClientRequest.emit (events.js:400:28) Oct 23 09:05:48 volumio volumio[1236]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Oct 23 09:05:48 volumio volumio[1236]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Oct 23 09:05:48 volumio volumio[1236]: at Socket.socketOnData (_http_client.js:515:22) Oct 23 09:05:48 volumio volumio[1236]: at Socket.emit (events.js:400:28) Oct 23 09:05:48 volumio volumio[1236]: at addChunk (internal/streams/readable.js:293:12) Oct 23 09:05:48 volumio volumio[1236]: at readableAddChunk (internal/streams/readable.js:267:9) Oct 23 09:05:48 volumio volumio[1236]: at Socket.Readable.push (internal/streams/readable.js:206:10) Oct 23 09:05:48 volumio volumio[1236]: at TCP.onStreamRead (internal/stream_base_commons.js:188:23) { Oct 23 09:05:48 volumio volumio[1236]: errno: -2, Oct 23 09:05:48 volumio volumio[1236]: syscall: 'open', Oct 23 09:05:48 volumio volumio[1236]: code: 'ENOENT', Oct 23 09:05:48 volumio volumio[1236]: path: '/data/plugins/music_service/80s80s/fake-data.json' Oct 23 09:05:48 volumio volumio[1236]: } Oct 23 09:05:48 volumio volumio[1236]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 23 09:05:49 volumio sudo[6161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-23 09:04 Oct 23 09:05:49 volumio sudo[6161]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"