-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2024-04-23 23:28:13 CEST. -- Apr 23 23:27:02 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:27:02 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:04 volumio volumio[9724]: Searching plugin music_service/webradio Apr 23 23:27:04 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: webradio , search Apr 23 23:27:05 volumio volumio[9724]: (node:9724) UnhandledPromiseRejectionWarning: Error: Start tag expected, '<' not found Apr 23 23:27:05 volumio volumio[9724]: at Object.module.exports.fromXml (/volumio/node_modules/libxmljs/lib/document.js:168:21) Apr 23 23:27:05 volumio volumio[9724]: at /volumio/app/plugins/music_service/webradio/index.js:971:31 Apr 23 23:27:05 volumio volumio[9724]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Apr 23 23:27:05 volumio volumio[9724]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 23 23:27:05 volumio volumio[9724]: (node:9724) 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: 1) Apr 23 23:27:05 volumio volumio[9724]: (node:9724) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Apr 23 23:27:07 volumio go-librespot[9952]: time="2024-04-23T23:27:07+02:00" level=debug msg="fetched chunk 14/14, size: 322853" Apr 23 23:27:08 volumio volumio[9724]: Searching plugin music_service/webradio Apr 23 23:27:08 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: webradio , search Apr 23 23:27:08 volumio volumio[9724]: info: All search sources collected, pushing search results Apr 23 23:27:11 volumio volumio[9724]: info: Saving Cloud item radio-favourites Apr 23 23:27:11 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Apr 23 23:27:11 volumio volumio[9724]: info: Pushing Favourites {"uri":"http://opml.radiotime.com/Tune.ashx?id=s95080","favourite":false} Apr 23 23:27:12 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:27:12 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:12 volumio volumio[9724]: info: Listing playlists Apr 23 23:27:12 volumio volumio[9724]: info: Listing playlists Apr 23 23:27:20 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 23 23:27:20 volumio volumio[9724]: info: Preload queue cleared Apr 23 23:27:22 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:27:22 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:27 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 23 23:27:27 volumio volumio[9724]: info: TuneIn handleBrowseUri: tunein/local Apr 23 23:27:28 volumio volumio[9724]: info: Preload queue cleared Apr 23 23:27:28 volumio volumio[9724]: info: Preload queue cleared Apr 23 23:27:32 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:27:32 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:32 volumio volumio[9724]: info: Listing playlists Apr 23 23:27:32 volumio volumio[9724]: info: Listing playlists Apr 23 23:27:37 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: lastfm , handleBrowseUri Apr 23 23:27:37 volumio volumio[9724]: error: Failed to execute browseSource, failure: TypeError: Cannot read property 'then' of undefined Apr 23 23:27:42 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:27:42 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:49 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:49 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:49 volumio volumio[9724]: info: Prefetching next song Apr 23 23:27:52 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:27:52 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:52 volumio volumio[9724]: info: Listing playlists Apr 23 23:27:52 volumio volumio[9724]: info: Listing playlists Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=trace msg="emitting websocket event: not_playing" Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=debug msg="loading track spotify:track:0lXVWzLwDnKB7Ro5p0AJPg (paused: true, position: 0ms)" Apr 23 23:27:52 volumio volumio[9724]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:0lXVWzLwDnKB7Ro5p0AJPg","play_origin":"go-librespot"}} Apr 23 23:27:52 volumio volumio[9724]: error: Failed to decode event: not_playing Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=trace msg="emitting websocket event: will_play" Apr 23 23:27:52 volumio volumio[9724]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0lXVWzLwDnKB7Ro5p0AJPg","play_origin":"go-librespot"}} Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0lXVWzLwDnKB7Ro5p0AJPg" Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=debug msg="requested aes key for file 65b29740a73d18b62fd8aefe7f838e940431d682, gid: 0lXVWzLwDnKB7Ro5p0AJPg" Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=debug msg="fetched first chunk of 15, total size is 7662885 bytes" Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Apr 23 23:27:52 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 23 23:27:52 volumio go-librespot[9952]: time="2024-04-23T23:27:52+02:00" level=info msg="loaded track \"COME UN TUONO (feat. Guè)\" (uri: spotify:track:0lXVWzLwDnKB7Ro5p0AJPg, paused: true, position: 0ms, duration: 175293ms)" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched chunk 2/14, size: 524288" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="emitting websocket event: metadata" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="emitting websocket event: stopped" Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0lXVWzLwDnKB7Ro5p0AJPg","name":"COME UN TUONO (feat. Guè)","artist_names":["Rose Villain","Guè"],"album_name":"RADIO SAKURA","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027d3c7c72548a5c8bff302714","position":0,"duration":175293,"release_date":"year:2024 month:3 day:8","track_number":10,"disc_number":1}} Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}} Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: {"status":"stop","service":"spop","title":"COME UN TUONO (feat. Guè)","artist":"Rose Villain, Guè","album":"RADIO SAKURA","albumart":"https://i.scdn.co/image/ab67616d00001e027d3c7c72548a5c8bff302714","uri":"spotify:track:0lXVWzLwDnKB7Ro5p0AJPg","trackType":"spotify","seek":0,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::servicePushState Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::pushState Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::volumioPushState Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 0 Apr 23 23:27:53 volumio volumio[9724]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"COME UN TUONO (feat. Guè)","artist":"Rose Villain, Guè","album":"RADIO SAKURA","albumart":"https://i.scdn.co/image/ab67616d00001e027d3c7c72548a5c8bff302714","uri":"spotify:track:0lXVWzLwDnKB7Ro5p0AJPg","trackType":"spotify","seek":0,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:53 volumio volumio[9724]: verbose: CURRENT POSITION 0 Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::syncState stateService stop Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::syncState currentStatus play Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::play index undefined Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::pushState Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::volumioPushState Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::startPlaybackTimer Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: info: [1713907673104] ControllerSpotify::clearAddPlayTrack Apr 23 23:27:53 volumio volumio[9724]: info: Sending Spotify command with payload to local API: /player/play Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::pushState Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::volumioPushState Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="emitting websocket event: paused" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched chunk 1/14, size: 524288" Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0lXVWzLwDnKB7Ro5p0AJPg","play_origin":"go-librespot"}} Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::servicePushState Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:53 volumio volumio[9724]: verbose: CURRENT POSITION 1 Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::syncState stateService pause Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::syncState currentStatus stop Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::pushState Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::volumioPushState Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:27:53 volumio volumio[9724]: info: MRS: Pushing multiroomSync output Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="loading track spotify:track:5bXgMzxuNymWhpwkgvYn4O (paused: false, position: 0ms)" Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 23 23:27:53 volumio volumio[9724]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched chunk 3/14, size: 524288" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="emitting websocket event: will_play" Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","play_origin":"go-librespot"}} Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5bXgMzxuNymWhpwkgvYn4O" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="requested aes key for file e09088e949e5ca01531039aec98d259225e8e474, gid: 5bXgMzxuNymWhpwkgvYn4O" Apr 23 23:27:53 volumio volumio[9724]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 23 23:27:53 volumio volumio[9724]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched first chunk of 21, total size is 10943127 bytes" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" Apr 23 23:27:53 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=info msg="loaded track \"100 MESSAGGI\" (uri: spotify:track:5bXgMzxuNymWhpwkgvYn4O, paused: false, position: 0ms, duration: 244096ms)" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched chunk 1/20, size: 524288" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="emitting websocket event: metadata" Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","name":"100 MESSAGGI","artist_names":["Lazza"],"album_name":"100 MESSAGGI","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02643268ac0b8c58e88584ee59","position":0,"duration":244096,"release_date":"year:2024 month:2 day:27","track_number":1,"disc_number":1}} Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched chunk 2/20, size: 524288" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=trace msg="emitting websocket event: playing" Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","play_origin":"go-librespot"}} Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 23:27:53 volumio volumio[9724]: SPOTIFY: {"status":"play","service":"spop","title":"100 MESSAGGI","artist":"Lazza","album":"100 MESSAGGI","albumart":"https://i.scdn.co/image/ab67616d00001e02643268ac0b8c58e88584ee59","uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","trackType":"spotify","seek":0,"duration":244,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:53 volumio volumio[9724]: info: CoreCommandRouter::servicePushState Apr 23 23:27:53 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:53 volumio volumio[9724]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"100 MESSAGGI","artist":"Lazza","album":"100 MESSAGGI","albumart":"https://i.scdn.co/image/ab67616d00001e02643268ac0b8c58e88584ee59","uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","trackType":"spotify","seek":0,"duration":244,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:53 volumio volumio[9724]: verbose: CURRENT POSITION 1 Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::syncState stateService play Apr 23 23:27:53 volumio volumio[9724]: info: CoreStateMachine::syncState currentStatus stop Apr 23 23:27:53 volumio go-librespot[9952]: time="2024-04-23T23:27:53+02:00" level=debug msg="fetched chunk 3/20, size: 524288" Apr 23 23:27:54 volumio volumio[9724]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 23:27:54 volumio volumio[9724]: SPOTIFY: {"status":"play","service":"spop","title":"100 MESSAGGI","artist":"Lazza","album":"100 MESSAGGI","albumart":"https://i.scdn.co/image/ab67616d00001e02643268ac0b8c58e88584ee59","uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","trackType":"spotify","seek":0,"duration":244,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:54 volumio volumio[9724]: info: CoreCommandRouter::servicePushState Apr 23 23:27:54 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:54 volumio volumio[9724]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"100 MESSAGGI","artist":"Lazza","album":"100 MESSAGGI","albumart":"https://i.scdn.co/image/ab67616d00001e02643268ac0b8c58e88584ee59","uri":"spotify:track:5bXgMzxuNymWhpwkgvYn4O","trackType":"spotify","seek":0,"duration":244,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 23 23:27:54 volumio volumio[9724]: verbose: CURRENT POSITION 1 Apr 23 23:27:54 volumio volumio[9724]: info: CoreStateMachine::syncState stateService play Apr 23 23:27:54 volumio volumio[9724]: info: CoreStateMachine::syncState currentStatus play Apr 23 23:27:54 volumio volumio[9724]: info: Received an update from plugin. extracting info from payload Apr 23 23:27:54 volumio volumio[9724]: info: CoreStateMachine::pushState Apr 23 23:27:54 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:54 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 23:27:54 volumio volumio[9724]: info: CoreCommandRouter::volumioPushState Apr 23 23:27:54 volumio volumio[9724]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:27:54 volumio volumio[9724]: info: MRS: Pushing multiroomSync output Apr 23 23:27:54 volumio volumio[9724]: info: CoreStateMachine::pushState Apr 23 23:27:54 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:27:54 volumio volumio[9724]: info: CoreCommandRouter::volumioPushState Apr 23 23:27:54 volumio volumio[9724]: info: MRS: Pushing multiroomSync output update for this device Apr 23 23:27:54 volumio volumio[9724]: info: MRS: Pushing multiroomSync output Apr 23 23:27:54 volumio volumio[9724]: info: [LastFM] Current track has sufficient metadata: title (100 MESSAGGI) and artist (Lazza) passed on explicitly Apr 23 23:27:54 volumio volumio[9724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 23 23:27:54 volumio volumio[9724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 68 Apr 23 23:27:54 volumio volumio[9724]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"100 Messaggi","url":"https://www.last.fm/music/Lazza/_/100+Messaggi","duration":"244000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"11319","playcount":"169185","artist":{"name":"Lazza","url":"https://www.last.fm/music/Lazza"},"album":{"artist":"Lazza","title":"100 Messaggi - Single","url":"https://www.last.fm/music/Lazza/100+Messaggi+-+Single","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/f2f580732ef33a9d1cbc15f0acf22e9b.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/f2f580732ef33a9d1cbc15f0acf22e9b.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/f2f580732ef33a9d1cbc15f0acf22e9b.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/f2f580732ef33a9d1cbc15f0acf22e9b.png","@":{"size":"extralarge"}}]},"userplaycount":"1","userloved":"0","toptags":{"tag":{"name":"MySpotigramBot","url":"https://www.last.fm/tag/MySpotigramBot"}},"wiki":{"published":"19 Feb 2024, 02:17","summary":"Jacopo Lazzarini, in arte Lazza, ha cantato questa canzone al Teatro Aristo di Sanremo durante la finale di Sanremo 2024, regalando al pubblico del teatro ed agli ascoltatori da casa una possibile canzone presente nel suo prossimo album. Read more on Last.fm.","content":"Jacopo Lazzarini, in arte Lazza, ha cantato questa canzone al Teatro Aristo di Sanremo durante la finale di Sanremo 2024, regalando al pubblico del teatro ed agli ascoltatori da casa una possibile canzone presente nel suo prossimo album. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:02 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:02 volumio volumio[9724]: error: MRS: impossible to set Smart-TV-02248cf9347f833d833f4184038ad6ef volume: device not found Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:02 volumio volumio[9724]: error: MRS: impossible to set Smart-TV-02248cf9347f833d833f4184038ad6ef volume: device not found Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:02 volumio volumio[9724]: error: MRS: impossible to set Smart-TV-02248cf9347f833d833f4184038ad6ef volume: device not found Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:02 volumio volumio[9724]: error: MRS: impossible to set Smart-TV-02248cf9347f833d833f4184038ad6ef volume: device not found Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:02 volumio volumio[9724]: error: MRS: impossible to set Smart-TV-02248cf9347f833d833f4184038ad6ef volume: device not found Apr 23 23:28:02 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:02 volumio volumio[9724]: error: MRS: impossible to set Smart-TV-02248cf9347f833d833f4184038ad6ef volume: device not found Apr 23 23:28:05 volumio go-librespot[9952]: time="2024-04-23T23:28:05+02:00" level=debug msg="fetched chunk 4/20, size: 524288" Apr 23 23:28:10 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:10 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:10 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:10 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:10 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:10 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:10 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:10 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:10 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:10 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:11 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:11 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:11 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:11 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:11 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:11 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:11 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:11 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:11 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Apr 23 23:28:11 volumio volumio[9724]: error: MRS: impossible to set Chromecast-HD-1416f4dbb7f6a8a143e82ac71153b3ad volume: device not found Apr 23 23:28:12 volumio volumio[9724]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:12 volumio volumio[9724]: info: CorePlayQueue::getTrack 1 Apr 23 23:28:12 volumio volumio[9724]: info: Listing playlists Apr 23 23:28:12 volumio volumio[9724]: info: Listing playlists Apr 23 23:28:12 volumio volumio[9724]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Apr 23 23:28:12 volumio volumio[9724]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Apr 23 23:28:12 volumio volumio[9724]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 23:28:12 volumio volumio[9724]: TypeError: Cannot read property 'then' of undefined Apr 23 23:28:12 volumio volumio[9724]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Apr 23 23:28:12 volumio volumio[9724]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2249:30) Apr 23 23:28:12 volumio volumio[9724]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1411:26) Apr 23 23:28:12 volumio volumio[9724]: at Socket.emit (events.js:315:20) Apr 23 23:28:12 volumio volumio[9724]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 23 23:28:12 volumio volumio[9724]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 23 23:28:12 volumio volumio[9724]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 23:28:13 volumio sudo[10450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-23 23:27 Apr 23 23:28:13 volumio sudo[10450]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"