-- 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"