-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2024-04-23 23:28:46 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) Apr 23 23:28:13 volumio sudo[10450]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:13 volumio volumio-remote-updater[532]: [2024-04-23 23:28:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 23 23:28:13 volumio volumio-remote-updater[532]: [2024-04-23 23:28:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 23 23:28:13 volumio vtcs[10236]: [2024-04-23 23:28:13.711] [tisoc] [error] [SpkconServer.cpp:377] recv error. socket disconnected Apr 23 23:28:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 23 23:28:13 volumio go-librespot[9952]: time="2024-04-23T23:28:13+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Apr 23 23:28:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 23 23:28:13 volumio systemd[1]: Started dynamicswap service. Apr 23 23:28:13 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 23 23:28:13 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Apr 23 23:28:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Apr 23 23:28:13 volumio systemd[1]: Stopped Volumio Backend Module. Apr 23 23:28:13 volumio systemd[1]: Started Volumio Backend Module. Apr 23 23:28:13 volumio systemd[1]: Started dynamicswap service. Apr 23 23:28:13 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 23 23:28:15 volumio volumio[10463]: info: ------------------------------------------- Apr 23 23:28:15 volumio volumio[10463]: info: ----- Volumio3 ---- Apr 23 23:28:15 volumio volumio[10463]: info: ------------------------------------------- Apr 23 23:28:15 volumio volumio[10463]: info: ----- System startup ---- Apr 23 23:28:15 volumio volumio[10463]: info: ------------------------------------------- Apr 23 23:28:15 volumio volumio[10463]: info: MYVOLUMIO Environment detected Apr 23 23:28:15 volumio volumio[10463]: info: Plugin folders cleanup Apr 23 23:28:15 volumio volumio[10463]: info: Scanning into folder /volumio/app/plugins/ Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category audio_interface Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category miscellanea Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category music_service Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category plugins.json Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category system_controller Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category user_interface Apr 23 23:28:15 volumio volumio[10463]: info: Scanning into folder /data/plugins/ Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category music_service Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category system_controller Apr 23 23:28:15 volumio volumio[10463]: info: Scanning category user_interface Apr 23 23:28:15 volumio volumio[10463]: info: Plugin folders cleanup completed Apr 23 23:28:15 volumio volumio[10463]: info: ------------------------------------------- Apr 23 23:28:15 volumio volumio[10463]: info: ----- Core plugins startup ---- Apr 23 23:28:15 volumio volumio[10463]: info: ------------------------------------------- Apr 23 23:28:15 volumio volumio[10463]: info: Loading plugins from folder /volumio/app/plugins/ Apr 23 23:28:15 volumio volumio[10463]: info: Adding plugin upnp to MyMusic Plugins Apr 23 23:28:15 volumio volumio[10463]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 23 23:28:15 volumio volumio[10463]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 23 23:28:15 volumio volumio[10463]: info: Loading plugins from folder /data/plugins/ Apr 23 23:28:15 volumio volumio[10463]: info: Loading plugin "system"... Apr 23 23:28:15 volumio volumio[10463]: info: Loading plugin "appearance"... Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "network"... Apr 23 23:28:16 volumio volumio[10463]: info: Refreshing Cached IP Addresses Apr 23 23:28:16 volumio sudo[10491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 23:28:16 volumio sudo[10491]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:16 volumio sudo[10491]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "services"... Apr 23 23:28:16 volumio sudo[10493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "alsa_controller"... Apr 23 23:28:16 volumio sudo[10493]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:16 volumio sudo[10493]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:16 volumio sudo[10496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 23 23:28:16 volumio sudo[10496]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:16 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "wizard"... Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "networkfs"... Apr 23 23:28:16 volumio volumio[10463]: info: Starting Udev Watcher for removable devices Apr 23 23:28:16 volumio sudo[10504]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=ddtmax,password=Massimo$8772,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.50/Multimedia /mnt/NAS/Nas Apr 23 23:28:16 volumio sudo[10504]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:16 volumio volumio[10463]: info: Ignoring mount for partition: boot Apr 23 23:28:16 volumio volumio[10463]: info: Ignoring mount for partition: volumio Apr 23 23:28:16 volumio volumio[10463]: info: Ignoring mount for partition: volumio_data Apr 23 23:28:16 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "volumio_command_line_client"... Apr 23 23:28:16 volumio kernel: CIFS: Attempting to mount \\192.168.1.50\Multimedia Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "upnp"... Apr 23 23:28:16 volumio volumio[10463]: info: [1713907696464] Starting Upmpd Daemon Apr 23 23:28:16 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "my_music"... Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "mpd"... Apr 23 23:28:16 volumio sudo[10504]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:16 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Apr 23 23:28:16 volumio kernel: CIFS: VFS: \\192.168.1.50 Send error in SessSetup = -13 Apr 23 23:28:16 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "upnp_browser"... Apr 23 23:28:16 volumio volumio[10463]: info: Loading plugin "alarm-clock"... Apr 23 23:28:17 volumio go-librespot[9952]: time="2024-04-23T23:28:17+02:00" level=debug msg="fetched chunk 5/20, size: 524288" Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "airplay_emulation"... Apr 23 23:28:17 volumio volumio[10463]: info: Starting Shairport Sync Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "last_100"... Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "webradio"... Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "i2s_dacs"... Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "volumiodiscovery"... Apr 23 23:28:17 volumio volumio[10463]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 23 23:28:17 volumio volumio[10463]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 23:28:17 volumio volumio[10463]: *** WARNING *** For more information see Apr 23 23:28:17 volumio node[10463]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 23 23:28:17 volumio volumio[10463]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 23 23:28:17 volumio volumio[10463]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 23:28:17 volumio volumio[10463]: *** WARNING *** For more information see Apr 23 23:28:17 volumio node[10463]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 23:28:17 volumio node[10463]: *** WARNING *** For more information see Apr 23 23:28:17 volumio node[10463]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 23 23:28:17 volumio node[10463]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 23:28:17 volumio node[10463]: *** WARNING *** For more information see Apr 23 23:28:17 volumio volumio[10463]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 23 23:28:17 volumio volumio[10463]: info: Discovery: Started advertising with name: Volumio Apr 23 23:28:17 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "spop"... Apr 23 23:28:17 volumio volumio[10463]: info: Loading plugin "youtube2"... Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "autostart"... Apr 23 23:28:18 volumio volumio[10463]: info: Applying required configuration parameters for plugin autostart Apr 23 23:28:18 volumio volumio[10463]: info: AutoStart - onVolumioStart - read config.json Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "outputs"... Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "albumart"... Apr 23 23:28:18 volumio volumio[10463]: info: Plugin example_plugin is not enabled Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "inputs"... Apr 23 23:28:18 volumio volumio-remote-updater[532]: [2024-04-23 23:28:18] [connect] Successful connection Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "updater_comm"... Apr 23 23:28:18 volumio volumio[10463]: info: Plugin mpdemulation is not enabled Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "rest_api"... Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "websocket"... Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "minidlna"... Apr 23 23:28:18 volumio volumio[10463]: info: Applying required configuration parameters for plugin minidlna Apr 23 23:28:18 volumio volumio[10463]: Forking 3 albumart workers Apr 23 23:28:18 volumio volumio[10463]: info: Loading plugin "backup_restore"... Apr 23 23:28:19 volumio volumio[10463]: info: Applying required configuration parameters for plugin backup_restore Apr 23 23:28:19 volumio volumio[10463]: info: Loading plugin "lastfm"... Apr 23 23:28:19 volumio volumio[10463]: info: Loading plugin "touch_display"... Apr 23 23:28:19 volumio volumio[10463]: Starting albumart workers Apr 23 23:28:19 volumio volumio[10463]: Starting albumart workers Apr 23 23:28:19 volumio volumio[10463]: Starting albumart workers Apr 23 23:28:19 volumio volumio[10463]: info: Applying required configuration parameters for plugin touch_display Apr 23 23:28:19 volumio volumio[10463]: info: Loading i18n strings for locale it Apr 23 23:28:19 volumio volumio[10463]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Apr 23 23:28:19 volumio volumio[10463]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Apr 23 23:28:19 volumio volumio[10463]: Updating browse sources language Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 23:28:19 volumio sudo[10496]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::initPlayerControls Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 23:28:19 volumio volumio[10463]: Express server listening on port 3000 Apr 23 23:28:19 volumio volumio[10463]: [Metrics] WebUI: 5s 296.38ms Apr 23 23:28:19 volumio volumio[10463]: info: CoreStateMachine::resetVolumioState Apr 23 23:28:19 volumio volumio[10463]: info: CoreStateMachine::getcurrentVolume Apr 23 23:28:19 volumio volumio[10463]: info: CoreCommandRouter::volumioRetrievevolume Apr 23 23:28:20 volumio volumio[10463]: info: Cannot mount NAS Nas at system boot, trial number 1 ,retrying in 5 seconds Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.52 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36 Total Clients: 1 Apr 23 23:28:20 volumio volumio[10463]: 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 Total Clients: 2 Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.52 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36 Total Clients: 3 Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.52 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36 Total Clients: 4 Apr 23 23:28:20 volumio volumio[10463]: 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 Total Clients: 5 Apr 23 23:28:20 volumio volumio-remote-updater[532]: [2024-04-23 23:28:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1713907698 101 Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 6 Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.52 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36 Total Clients: 7 Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 23:28:20 volumio volumio[10463]: info: Reloading queue from file Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::setRepeat null single undefined Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::pushState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioPushState Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::setRandom null Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::pushState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioPushState Apr 23 23:28:20 volumio volumio[10463]: info: Setting Device type: Raspberry PI Apr 23 23:28:20 volumio volumio[10463]: info: VolumeController:: Volume=68 Mute =false Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::pushState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioPushState Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::updateTrackBlock Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrackBlock Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioRetrievevolume Apr 23 23:28:20 volumio volumio[10463]: info: Discovery: adding 9bda9bbf-4454-46ab-bb6f-bac4eb431e86 Apr 23 23:28:20 volumio volumio[10463]: info: Discovery: Found device Volumio Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: VolumeController:: Volume=68 Mute =false Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::pushState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioPushState Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetVisibleSources Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetQueue Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::getQueue Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getQueue Apr 23 23:28:20 volumio volumio[10463]: info: Listing playlists Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 23 23:28:20 volumio volumio[10463]: verbose: New Socket.io Connection to 192.168.1.40 from 192.168.1.52 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36 Total Clients: 10 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetVisibleSources Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::volumioGetQueue Apr 23 23:28:20 volumio volumio[10463]: info: CoreStateMachine::getQueue Apr 23 23:28:20 volumio volumio[10463]: info: CorePlayQueue::getQueue Apr 23 23:28:20 volumio volumio[10463]: info: Listing playlists Apr 23 23:28:20 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 23 23:28:21 volumio volumio[10463]: 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 Total Clients: 11 Apr 23 23:28:21 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:21 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:21 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 23 23:28:21 volumio volumio[10463]: info: CoreCommandRouter::volumioGetVisibleSources Apr 23 23:28:21 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 23:28:21 volumio volumio[10463]: info: Listing playlists Apr 23 23:28:22 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:22 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:25 volumio sudo[10577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=ddtmax,password=Massimo$8772,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.50/Multimedia /mnt/NAS/Nas Apr 23 23:28:25 volumio sudo[10577]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:25 volumio kernel: CIFS: Attempting to mount \\192.168.1.50\Multimedia Apr 23 23:28:25 volumio sudo[10577]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:25 volumio volumio[10463]: info: Cannot mount NAS Nas at system boot, trial number 2 ,retrying in 5 seconds Apr 23 23:28:25 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Apr 23 23:28:25 volumio kernel: CIFS: VFS: \\192.168.1.50 Send error in SessSetup = -13 Apr 23 23:28:25 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Apr 23 23:28:26 volumio sudo[10583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 23:28:26 volumio sudo[10583]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:26 volumio sudo[10583]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:26 volumio sudo[10586]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 23:28:26 volumio sudo[10586]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:26 volumio sudo[10586]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:26 volumio sudo[10589]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 23 23:28:26 volumio sudo[10589]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:26 volumio sudo[10589]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:26 volumio volumio[10463]: info: Upmpdcli Daemon Started Apr 23 23:28:27 volumio go-librespot[9952]: time="2024-04-23T23:28:27+02:00" level=debug msg="fetched chunk 6/20, size: 524288" Apr 23 23:28:28 volumio volumio[10463]: info: CoreCommandRouter::volumioPlay Apr 23 23:28:28 volumio volumio[10463]: info: CoreStateMachine::play index undefined Apr 23 23:28:28 volumio volumio[10463]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 23:28:28 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:28 volumio volumio[10463]: info: CoreStateMachine::startPlaybackTimer Apr 23 23:28:28 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:28 volumio volumio[10463]: info: [1713907708801] ControllerSpotify::clearAddPlayTrack Apr 23 23:28:28 volumio volumio[10463]: info: Sending Spotify command with payload to local API: /player/play Apr 23 23:28:28 volumio go-librespot[9952]: time="2024-04-23T23:28:28+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 23 23:28:28 volumio go-librespot[9952]: time="2024-04-23T23:28:28+02:00" level=debug msg="loading track spotify:track:0lXVWzLwDnKB7Ro5p0AJPg (paused: false, position: 57ms)" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=trace msg="emitting websocket event: will_play" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0lXVWzLwDnKB7Ro5p0AJPg" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="requested aes key for file 65b29740a73d18b62fd8aefe7f838e940431d682, gid: 0lXVWzLwDnKB7Ro5p0AJPg" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="fetched first chunk of 15, total size is 7662885 bytes" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=trace msg="seek to 57ms (diff: 57ms, samples: 2513, bytes: 0)" Apr 23 23:28:29 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=info msg="loaded track \"COME UN TUONO (feat. Guè)\" (uri: spotify:track:0lXVWzLwDnKB7Ro5p0AJPg, paused: false, position: 57ms, duration: 175293ms)" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=trace msg="emitting websocket event: metadata" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="fetched chunk 1/14, size: 524288" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=trace msg="emitting websocket event: playing" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="fetched chunk 2/14, size: 524288" Apr 23 23:28:29 volumio go-librespot[9952]: time="2024-04-23T23:28:29+02:00" level=debug msg="fetched chunk 3/14, size: 524288" Apr 23 23:28:30 volumio sudo[10592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=ddtmax,password=Massimo$8772,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.50/Multimedia /mnt/NAS/Nas Apr 23 23:28:30 volumio sudo[10592]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:30 volumio kernel: CIFS: Attempting to mount \\192.168.1.50\Multimedia Apr 23 23:28:30 volumio sudo[10592]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:30 volumio volumio[10463]: info: Cannot mount NAS Nas at system boot, trial number 3 ,retrying in 5 seconds Apr 23 23:28:30 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Apr 23 23:28:30 volumio kernel: CIFS: VFS: \\192.168.1.50 Send error in SessSetup = -13 Apr 23 23:28:30 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Apr 23 23:28:32 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:32 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:32 volumio volumio[10463]: info: Listing playlists Apr 23 23:28:32 volumio volumio[10463]: info: Listing playlists Apr 23 23:28:35 volumio sudo[10599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=ddtmax,password=Massimo$8772,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.50/Multimedia /mnt/NAS/Nas Apr 23 23:28:35 volumio sudo[10599]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:35 volumio kernel: CIFS: Attempting to mount \\192.168.1.50\Multimedia Apr 23 23:28:35 volumio sudo[10599]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:35 volumio volumio[10463]: info: Cannot mount NAS Nas at system boot, trial number 4 ,retrying in 5 seconds Apr 23 23:28:35 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Apr 23 23:28:35 volumio kernel: CIFS: VFS: \\192.168.1.50 Send error in SessSetup = -13 Apr 23 23:28:35 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Apr 23 23:28:40 volumio sudo[10605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=ddtmax,password=Massimo$8772,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.50/Multimedia /mnt/NAS/Nas Apr 23 23:28:40 volumio sudo[10605]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 23:28:40 volumio kernel: CIFS: Attempting to mount \\192.168.1.50\Multimedia Apr 23 23:28:40 volumio sudo[10605]: pam_unix(sudo:session): session closed for user root Apr 23 23:28:40 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Apr 23 23:28:40 volumio kernel: CIFS: VFS: \\192.168.1.50 Send error in SessSetup = -13 Apr 23 23:28:40 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Apr 23 23:28:40 volumio volumio[10463]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=debug msg="fetched chunk 4/14, size: 524288" Apr 23 23:28:41 volumio volumio[10463]: info: CoreCommandRouter::volumioPlay Apr 23 23:28:41 volumio volumio[10463]: info: CoreStateMachine::play index undefined Apr 23 23:28:41 volumio volumio[10463]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 23:28:41 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:41 volumio volumio[10463]: info: CoreStateMachine::startPlaybackTimer Apr 23 23:28:41 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:41 volumio volumio[10463]: info: [1713907721401] ControllerSpotify::clearAddPlayTrack Apr 23 23:28:41 volumio volumio[10463]: info: Sending Spotify command with payload to local API: /player/play Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=debug msg="loading track spotify:track:0lXVWzLwDnKB7Ro5p0AJPg (paused: false, position: 112ms)" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=trace msg="emitting websocket event: will_play" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0lXVWzLwDnKB7Ro5p0AJPg" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=debug msg="requested aes key for file 65b29740a73d18b62fd8aefe7f838e940431d682, gid: 0lXVWzLwDnKB7Ro5p0AJPg" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=debug msg="fetched first chunk of 15, total size is 7662885 bytes" Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=trace msg="seek to 112ms (diff: 112ms, samples: 4939, bytes: 0)" Apr 23 23:28:41 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 23 23:28:41 volumio go-librespot[9952]: time="2024-04-23T23:28:41+02:00" level=info msg="loaded track \"COME UN TUONO (feat. Guè)\" (uri: spotify:track:0lXVWzLwDnKB7Ro5p0AJPg, paused: false, position: 112ms, duration: 175293ms)" Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=trace msg="emitting websocket event: metadata" Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=debug msg="fetched chunk 1/14, size: 524288" Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=trace msg="emitting websocket event: playing" Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=debug msg="fetched chunk 3/14, size: 524288" Apr 23 23:28:42 volumio volumio[10463]: info: CoreCommandRouter::volumioGetState Apr 23 23:28:42 volumio volumio[10463]: info: CorePlayQueue::getTrack 0 Apr 23 23:28:42 volumio go-librespot[9952]: time="2024-04-23T23:28:42+02:00" level=debug msg="fetched chunk 2/14, size: 524288" Apr 23 23:28:46 volumio volumio[10463]: info: Preload queue cleared Apr 23 23:28:46 volumio volumio[10463]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 23 23:28:46 volumio volumio[10463]: info: CoreStateMachine::ClearQueue Apr 23 23:28:46 volumio volumio[10463]: info: CoreStateMachine::stop Apr 23 23:28:46 volumio volumio[10463]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 23:28:46 volumio volumio[10463]: info: CorePlayQueue::clearPlayQueue Apr 23 23:28:46 volumio volumio[10463]: info: CorePlayQueue::saveQueue Apr 23 23:28:46 volumio volumio[10463]: info: CoreCommandRouter::volumioPushQueue Apr 23 23:28:46 volumio volumio[10463]: info: CoreStateMachine::addQueueItems Apr 23 23:28:46 volumio volumio[10463]: info: CorePlayQueue::addQueueItems Apr 23 23:28:46 volumio volumio[10463]: info: Preload queue cleared Apr 23 23:28:46 volumio volumio[10463]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s93965 Apr 23 23:28:46 volumio volumio[10463]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 23 23:28:46 volumio volumio[10463]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 23:28:46 volumio volumio[10463]: TypeError: Cannot read property 'tune_radio' of undefined Apr 23 23:28:46 volumio volumio[10463]: at ControllerWebradio.explodeUri (/volumio/app/plugins/music_service/webradio/index.js:539:33) Apr 23 23:28:46 volumio volumio[10463]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Apr 23 23:28:46 volumio volumio[10463]: at CorePlayQueue.explodeUri (/volumio/app/playqueue.js:179:33) Apr 23 23:28:46 volumio volumio[10463]: at CorePlayQueue.addQueueItems (/volumio/app/playqueue.js:223:30) Apr 23 23:28:46 volumio volumio[10463]: at CoreStateMachine.addQueueItems (/volumio/app/statemachine.js:247:25) Apr 23 23:28:46 volumio volumio[10463]: at CoreCommandRouter.replaceAndPlay (/volumio/app/index.js:507:23) Apr 23 23:28:46 volumio volumio[10463]: at CoreCommandRouter.playItemsList (/volumio/app/index.js:477:17) Apr 23 23:28:46 volumio volumio[10463]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:118:33) Apr 23 23:28:46 volumio volumio[10463]: at Socket.emit (events.js:315:20) Apr 23 23:28:46 volumio volumio[10463]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 23 23:28:46 volumio volumio[10463]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 23 23:28:46 volumio volumio[10463]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 23:28:46 volumio sudo[10619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-23 23:27 Apr 23 23:28:46 volumio sudo[10619]: 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"