-- Logs begin at Thu 2019-02-14 07:12:00 -03, end at Sat 2024-08-17 20:30:33 -04. -- Aug 17 20:29:00 living volumio-remote-updater[634]: [2024-08-17 20:29:00] [connect] Successful connection Aug 17 20:29:03 living volumio[971]: info: Checking if install.sh is present Aug 17 20:29:03 living volumio[971]: error: [ytcr] Error connecting MPD: Aug 17 20:29:03 living volumio[971]: (Error) connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:03 living volumio[971]: Error: connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:03 living volumio[971]: at PipeConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 17 20:29:03 living volumio[971]: Retrying in 5 seconds... Aug 17 20:29:03 living volumio[971]: info: Executing install.sh Aug 17 20:29:03 living volumio[971]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 10.5.0.103 from 10.5.0.100 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Aug 17 20:29:03 living volumio-remote-updater[634]: [2024-08-17 20:29:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1723940940 101 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 6 Aug 17 20:29:03 living volumio[971]: verbose: New Socket.io Connection to 10.5.0.103 from 10.5.0.100 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 17 20:29:04 living sudo[3412]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/youtube2/install.sh Aug 17 20:29:04 living sudo[3412]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 20:29:04 living sudo[3412]: pam_unix(sudo:session): session closed for user root Aug 17 20:29:04 living volumio[971]: info: Install script completed Aug 17 20:29:04 living volumio[971]: info: Done installing plugin. Aug 17 20:29:04 living volumio[971]: info: Enabling plugin youtube2 Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 17 20:29:04 living volumio[971]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.0","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"1.2.2","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.0.5","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Music","name":"ytmusic","category":"music_service","version":"1.1.2","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Touch Display","name":"touch_display","category":"user_interface","version":"3.4.0","icon":"fa-hand-pointer-o","isManuallyInstalled":false,"enabled":true,"active":true}] Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 17 20:29:04 living volumio[971]: info: Folder /tmp/plugins removed Aug 17 20:29:04 living volumio[971]: info: Folder /tmp/downloaded_plugin.zip removed Aug 17 20:29:04 living volumio[971]: info: Folder /data/temp removed Aug 17 20:29:04 living go-librespot[2042]: time="2024-08-17T20:29:04-04:00" level=debug msg="fetched chunk 10/13, size: 524288" uri="spotify:track:4zzvMG8KrsykYtvFEJ99Cl" Aug 17 20:29:04 living volumio[971]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:04 living volumio[971]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Aug 17 20:29:04 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 17 20:29:04 living volumio[971]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::volumioGetVisibleSources Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 17 20:29:04 living volumio[971]: info: Received Get System Info Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 20:29:04 living volumio[971]: info: Discovery: Getting this device information Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 20:29:04 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:04 living volumio[971]: info: Listing playlists Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 17 20:29:05 living volumio[971]: verbose: New Socket.io Connection to 10.5.0.103 from 10.5.0.100 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Aug 17 20:29:05 living volumio[971]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Aug 17 20:29:05 living volumio[971]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::volumioGetVisibleSources Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::volumioGetQueue Aug 17 20:29:05 living volumio[971]: info: CoreStateMachine::getQueue Aug 17 20:29:05 living volumio[971]: info: CorePlayQueue::getQueue Aug 17 20:29:05 living volumio[971]: info: Listing playlists Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 17 20:29:05 living volumio[971]: info: Received Get System Info Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 20:29:05 living volumio[971]: info: Discovery: Getting this device information Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:05 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 17 20:29:08 living volumio[971]: error: [ytcr] Error connecting MPD: Aug 17 20:29:08 living volumio[971]: (Error) connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:08 living volumio[971]: Error: connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:08 living volumio[971]: at PipeConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 17 20:29:08 living volumio[971]: Retrying in 5 seconds... Aug 17 20:29:13 living volumio[971]: error: [ytcr] Error connecting MPD: Aug 17 20:29:13 living volumio[971]: (Error) connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:13 living volumio[971]: Error: connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:13 living volumio[971]: at PipeConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 17 20:29:13 living volumio[971]: Retrying in 5 seconds... Aug 17 20:29:18 living go-librespot[2042]: time="2024-08-17T20:29:18-04:00" level=debug msg="fetched chunk 11/13, size: 524288" uri="spotify:track:4zzvMG8KrsykYtvFEJ99Cl" Aug 17 20:29:18 living volumio[971]: error: [ytcr] Error connecting MPD: Aug 17 20:29:18 living volumio[971]: (Error) connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:18 living volumio[971]: Error: connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:18 living volumio[971]: at PipeConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 17 20:29:18 living volumio[971]: Retrying in 5 seconds... Aug 17 20:29:21 living volumio[971]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/ytcr/volumio/buster/armhf Aug 17 20:29:23 living volumio[971]: error: [ytcr] Error connecting MPD: Aug 17 20:29:23 living volumio[971]: (Error) connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:23 living volumio[971]: Error: connect ECONNREFUSED /run/mpd/socket Aug 17 20:29:23 living volumio[971]: at PipeConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 17 20:29:23 living volumio[971]: Retrying in 5 seconds... Aug 17 20:29:26 living volumio[971]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/ytcr/volumio/buster/armhf Aug 17 20:29:26 living volumio[971]: info: [yt-cast-receiver] Player.reset() Aug 17 20:29:26 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:29:31 living volumio[971]: info: Check plugin dependencies Aug 17 20:29:31 living go-librespot[2042]: time="2024-08-17T20:29:31-04:00" level=debug msg="fetched chunk 12/13, size: 524288" uri="spotify:track:4zzvMG8KrsykYtvFEJ99Cl" Aug 17 20:29:45 living go-librespot[2042]: time="2024-08-17T20:29:45-04:00" level=debug msg="fetched chunk 13/13, size: 177796" uri="spotify:track:4zzvMG8KrsykYtvFEJ99Cl" Aug 17 20:29:52 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 17 20:29:52 living volumio[971]: info: Rename folder Aug 17 20:29:52 living volumio[971]: info: Folder /tmp/downloaded_plugin.zip removed Aug 17 20:29:52 living volumio[971]: info: Move to category Aug 17 20:30:03 living go-librespot[2042]: time="2024-08-17T20:30:03-04:00" level=debug msg="prefetching next track" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=debug msg="selected format OGG_VORBIS_320 (9fd315929ba7ae31d69c0b8c9fd8a64e595f315e)" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=debug msg="requested aes key for file 9fd315929ba7ae31d69c0b8c9fd8a64e595f315e, gid: 48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=debug msg="fetched first chunk of 27, total size is 13848288 bytes" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=info msg="prefetched track \"Californication\" (duration: 329733ms)" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=debug msg="fetched chunk 2/26, size: 524288" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=debug msg="fetched chunk 3/26, size: 524288" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:04 living go-librespot[2042]: time="2024-08-17T20:30:04-04:00" level=debug msg="fetched chunk 1/26, size: 524288" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:26 living volumio[971]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 17 20:30:27 living volumio[971]: verbose: New Socket.io Connection to 10.5.0.103 from 10.5.0.100 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::volumioGetVisibleSources Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:30:27 living volumio[971]: info: CorePlayQueue::getTrack 96 Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::volumioGetQueue Aug 17 20:30:27 living volumio[971]: info: CoreStateMachine::getQueue Aug 17 20:30:27 living volumio[971]: info: CorePlayQueue::getQueue Aug 17 20:30:27 living volumio[971]: info: Listing playlists Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 17 20:30:27 living volumio[971]: info: Received Get System Info Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 20:30:27 living volumio[971]: info: Discovery: Getting this device information Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:30:27 living volumio[971]: info: CorePlayQueue::getTrack 96 Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 20:30:27 living volumio[971]: info: CoreCommandRouter::volumioGetState Aug 17 20:30:27 living volumio[971]: info: CorePlayQueue::getTrack 96 Aug 17 20:30:32 living volumio[971]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 17 20:30:32 living volumio[971]: TypeError: Cannot read property 'plugin_type' of undefined Aug 17 20:30:32 living volumio[971]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1644:56) Aug 17 20:30:32 living volumio[971]: at CoreCommandRouter.getInstalledPlugins (/volumio/app/index.js:1521:29) Aug 17 20:30:32 living volumio[971]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1321:45) Aug 17 20:30:32 living volumio[971]: at Socket.emit (events.js:315:20) Aug 17 20:30:32 living volumio[971]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Aug 17 20:30:32 living volumio[971]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Aug 17 20:30:32 living volumio[971]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 17 20:30:32 living go-librespot[2042]: time="2024-08-17T20:30:32-04:00" level=trace msg="emitting websocket event: not_playing" Aug 17 20:30:32 living go-librespot[2042]: time="2024-08-17T20:30:32-04:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:32 living go-librespot[2042]: time="2024-08-17T20:30:32-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 17 20:30:32 living go-librespot[2042]: time="2024-08-17T20:30:32-04:00" level=trace msg="emitting websocket event: will_play" Aug 17 20:30:32 living go-librespot[2042]: time="2024-08-17T20:30:32-04:00" level=info msg="loaded track \"Californication\" (paused: false, position: 1ms, duration: 329733ms, prefetched: true)" uri="spotify:track:48UPSzbZjgc449aqz8bxox" Aug 17 20:30:33 living sudo[3521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-17 20:29 Aug 17 20:30:33 living sudo[3521]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 20:30:33 living go-librespot[2042]: time="2024-08-17T20:30:33-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 17 20:30:33 living go-librespot[2042]: time="2024-08-17T20:30:33-04:00" level=trace msg="scheduling prefetch in 299s" Aug 17 20:30:33 living go-librespot[2042]: time="2024-08-17T20:30:33-04:00" level=trace msg="emitting websocket event: metadata" 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"