-- Logs begin at Thu 2024-10-03 19:11:12 CEST, end at Fri 2024-10-04 11:57:58 CEST. -- Oct 04 11:56:06 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:56:06 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:56:06 amp volumio[17701]: info: Listing playlists Oct 04 11:56:06 amp volumio[17701]: info: Listing playlists Oct 04 11:56:16 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:56:16 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:56:26 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:56:26 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:56:26 amp volumio[17701]: info: Listing playlists Oct 04 11:56:26 amp volumio[17701]: info: Listing playlists Oct 04 11:56:36 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:56:36 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:56:46 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:56:46 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:56:46 amp volumio[17701]: info: Listing playlists Oct 04 11:56:46 amp volumio[17701]: info: Listing playlists Oct 04 11:56:56 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:56:56 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:04 amp go-librespot[30612]: time="2024-10-04T11:57:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.124:4070: connect: connection timed out" Oct 04 11:57:04 amp systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 04 11:57:04 amp systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 04 11:57:04 amp volumio[17701]: (node:17701) UnhandledPromiseRejectionWarning: Error: socket hang up Oct 04 11:57:04 amp volumio[17701]: at connResetException (internal/errors.js:607:14) Oct 04 11:57:04 amp volumio[17701]: at Socket.socketOnEnd (_http_client.js:493:23) Oct 04 11:57:04 amp volumio[17701]: at Socket.emit (events.js:327:22) Oct 04 11:57:04 amp volumio[17701]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 04 11:57:04 amp volumio[17701]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 04 11:57:04 amp volumio[17701]: (node:17701) 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: 435) Oct 04 11:57:04 amp volumio[17701]: info: Connection to go-librespot Websocket closed Oct 04 11:57:06 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:06 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:06 amp volumio[17701]: info: Listing playlists Oct 04 11:57:06 amp volumio[17701]: info: Listing playlists Oct 04 11:57:07 amp volumio[17701]: info: Initializing connection to go-librespot Websocket Oct 04 11:57:07 amp volumio[17701]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 04 11:57:07 amp systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 04 11:57:07 amp systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 435. Oct 04 11:57:07 amp systemd[1]: Stopped go-librespot Daemon. Oct 04 11:57:07 amp systemd[1]: Started go-librespot Daemon. Oct 04 11:57:07 amp go-librespot[30708]: Librespot-go daemon starting... Oct 04 11:57:08 amp go-librespot[30708]: time="2024-10-04T11:57:08+02:00" level=info msg="generated new device id: d588ec700b639f6cc7ecfaef1a900c2ef7a6c820" Oct 04 11:57:08 amp go-librespot[30708]: time="2024-10-04T11:57:08+02:00" level=debug msg="stored credentials found for 42dp5j7fufrulr52sd94k83wv" Oct 04 11:57:08 amp go-librespot[30708]: time="2024-10-04T11:57:08+02:00" level=warning msg="stored credentials found for wrong username 42dp5j7fufrulr52sd94k83wv != 31ovq6iejwlkqono5dxyeoqubwi4" Oct 04 11:57:09 amp go-librespot[30708]: time="2024-10-04T11:57:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 04 11:57:09 amp go-librespot[30708]: time="2024-10-04T11:57:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 04 11:57:09 amp go-librespot[30708]: time="2024-10-04T11:57:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 04 11:57:09 amp go-librespot[30708]: time="2024-10-04T11:57:09+02:00" level=debug msg="zeroconf server listening on port 35851" Oct 04 11:57:09 amp go-librespot[30708]: time="2024-10-04T11:57:09+02:00" level=debug msg="obtained new client token: AABTZ4cUNwbCULvO4mHwtatLYkR/Qq7Fjmt3hFTuCPk05U660UxR/mbNSc5eT3I0Rzfzt4KF2Z5UReyDkyNIZqhG/906d0IeThKJkW254v/NUOxGZfOEEZKz310Og3PUP5EZJv9NYpjs3JyPLkS7o7IijdjhSQk18IcrEIMjRV3T/Vs/PgQhY93xHR3d12s8/TDsIda/6tENKA8sT1SDSFRtUVm/9+nQybLWa5HS/HRf0KgVK+t+yhiv1+k=" Oct 04 11:57:10 amp volumio[17701]: info: Initializing connection to go-librespot Websocket Oct 04 11:57:10 amp volumio[17701]: info: Connection to go-librespot Websocket established Oct 04 11:57:10 amp go-librespot[30708]: time="2024-10-04T11:57:10+02:00" level=debug msg="new websocket client" Oct 04 11:57:13 amp volumio[17701]: info: Getting Spotify volume Oct 04 11:57:13 amp volumio[17701]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Oct 04 11:57:13 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:13 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:13 amp volumio[17701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Oct 04 11:57:16 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:16 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:26 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:26 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:26 amp volumio[17701]: info: Listing playlists Oct 04 11:57:26 amp volumio[17701]: info: Listing playlists Oct 04 11:57:36 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:36 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:44 amp volumio[17701]: info: Clearing queue after UPNP request Oct 04 11:57:44 amp volumio[17701]: info: CoreStateMachine::ClearQueue Oct 04 11:57:44 amp volumio[17701]: info: CoreStateMachine::stop Oct 04 11:57:44 amp volumio[17701]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 04 11:57:44 amp volumio[17701]: info: CorePlayQueue::clearPlayQueue Oct 04 11:57:44 amp volumio[17701]: info: CorePlayQueue::saveQueue Oct 04 11:57:44 amp volumio[17701]: info: CoreCommandRouter::volumioPushState Oct 04 11:57:44 amp volumio[17701]: info: CoreCommandRouter::volumioPushQueue Oct 04 11:57:44 amp volumio[17701]: info: Oct 04 11:57:44 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:44 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:44 amp volumio[17701]: info: Oct 04 11:57:44 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:44 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:44 amp volumio[17701]: info: Oct 04 11:57:44 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:44 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:44 amp volumio[17701]: error: updateQueue error: null Oct 04 11:57:44 amp volumio[17701]: error: updateQueue error: null Oct 04 11:57:44 amp volumio[17701]: error: updateQueue error: null Oct 04 11:57:44 amp volumio[17701]: info: ------------------------------ 165ms Oct 04 11:57:44 amp volumio[17701]: info: ------------------------------ 139ms Oct 04 11:57:44 amp volumio[17701]: info: ------------------------------ 130ms Oct 04 11:57:44 amp volumio[17701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Oct 04 11:57:45 amp volumio[17701]: info: Starting UPNP Playback Oct 04 11:57:45 amp volumio[17701]: info: Preparing playback through UPNP Oct 04 11:57:45 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:45 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:45 amp volumio[17701]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 47ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 39ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 31ms Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 40ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 30ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 21ms Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 39ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 29ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 20ms Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 48ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 38ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 30ms Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 38ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 29ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 21ms Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: Oct 04 11:57:45 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:45 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 40ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 29ms Oct 04 11:57:45 amp volumio[17701]: info: ------------------------------ 21ms Oct 04 11:57:46 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:46 amp volumio[17701]: info: Listing playlists Oct 04 11:57:46 amp volumio[17701]: info: Listing playlists Oct 04 11:57:48 amp volumio[17701]: info: Oct 04 11:57:48 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:48 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:48 amp volumio[17701]: info: Oct 04 11:57:48 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:48 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:48 amp volumio[17701]: info: Oct 04 11:57:48 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:48 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:48 amp volumio[17701]: info: Oct 04 11:57:48 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:48 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:48 amp volumio[17701]: info: sendMpdCommand status took 177 milliseconds Oct 04 11:57:48 amp volumio[17701]: info: sendMpdCommand status took 110 milliseconds Oct 04 11:57:48 amp volumio[17701]: info: sendMpdCommand status took 116 milliseconds Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:48 amp volumio[17701]: info: Oct 04 11:57:48 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:48 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:48 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:48 amp volumio[17701]: info: sendMpdCommand status took 181 milliseconds Oct 04 11:57:48 amp volumio[17701]: info: sendMpdCommand playlistinfo took 71 milliseconds Oct 04 11:57:49 amp volumio[17701]: info: sendMpdCommand playlistinfo took 292 milliseconds Oct 04 11:57:49 amp volumio[17701]: info: sendMpdCommand playlistinfo took 323 milliseconds Oct 04 11:57:49 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:49 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:49 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:49 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:49 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:49 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:49 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:49 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Music Assistant","artist":null,"album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:49 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus stop Oct 04 11:57:49 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:49 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:49 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Music Assistant","artist":null,"album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:49 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:49 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::volumioPushState Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::volumioPushState Oct 04 11:57:49 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:49 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:49 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Music Assistant","artist":null,"album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:49 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:49 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::volumioPushState Oct 04 11:57:49 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:49 amp volumio[17701]: info: CoreCommandRouter::volumioPushState Oct 04 11:57:49 amp volumio[17701]: info: ------------------------------ 1476ms Oct 04 11:57:49 amp volumio[17701]: info: ------------------------------ 1342ms Oct 04 11:57:49 amp volumio[17701]: info: ------------------------------ 1330ms Oct 04 11:57:49 amp volumio[17701]: info: Oct 04 11:57:49 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:49 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:49 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:50 amp volumio[17701]: info: Oct 04 11:57:50 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:50 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:50 amp volumio[17701]: info: Oct 04 11:57:50 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand status took 1180 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand playlistinfo took 926 milliseconds Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:50 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:50 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:50 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:50 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","artist":"Music Assistant","album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:50 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:50 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:50 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:50 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:50 amp volumio[17701]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:50 amp volumio[17701]: info: ------------------------------ 1572ms Oct 04 11:57:50 amp volumio[17701]: info: Oct 04 11:57:50 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:50 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:50 amp volumio[17701]: info: Oct 04 11:57:50 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:50 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:50 amp volumio[17701]: info: Oct 04 11:57:50 amp volumio[17701]: ---------------------------- MPD announces system playlist update Oct 04 11:57:50 amp volumio[17701]: info: Ignoring MPD Status Update Oct 04 11:57:50 amp volumio[17701]: info: Oct 04 11:57:50 amp volumio[17701]: ---------------------------- MPD announces state update: player Oct 04 11:57:50 amp volumio[17701]: info: ControllerMpd::getState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand status Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand status took 391 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: ------------------------------ 403ms Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand status took 364 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand playlistinfo took 315 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: ------------------------------ 191ms Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand status took 192 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: ------------------------------ 183ms Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand status took 119 milliseconds Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseState Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 11:57:50 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:50 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:50 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:50 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","artist":"Music Assistant","album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:50 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:50 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:50 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:50 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:50 amp volumio[17701]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:50 amp volumio[17701]: info: ------------------------------ 1800ms Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand playlistinfo took 377 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand playlistinfo took 353 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand playlistinfo took 339 milliseconds Oct 04 11:57:50 amp volumio[17701]: info: sendMpdCommand playlistinfo took 331 milliseconds Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:50 amp volumio[17701]: verbose: ControllerMpd::parseTrackInfo Oct 04 11:57:50 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:50 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:50 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:50 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1868,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1899 Kbps","isStreaming":false,"title":"83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","artist":"Music Assistant","album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:50 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:50 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:50 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 04 11:57:50 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:50 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:51 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:51 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:51 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:51 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1989,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1918 Kbps","isStreaming":false,"title":"83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","artist":"Music Assistant","album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:51 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:51 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:51 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:51 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:51 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:51 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:51 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:51 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2115,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1983 Kbps","isStreaming":false,"title":"83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","artist":"Music Assistant","album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:51 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:51 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:51 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:51 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:51 amp volumio[17701]: info: ControllerMpd::pushState Oct 04 11:57:51 amp volumio[17701]: info: CoreCommandRouter::servicePushState Oct 04 11:57:51 amp volumio[17701]: verbose: In UPNP mode Oct 04 11:57:51 amp volumio[17701]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2241,"duration":0,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1977 Kbps","isStreaming":false,"title":"83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","artist":"Music Assistant","album":null,"uri":"http://192.168.2.141:8097/flow/uuid:b19cfe56-b78e-81fc-d782-b827eba49de1/83b466a3e6a54390b37600982998e5fa.flac?ts=1728035863","trackType":""} Oct 04 11:57:51 amp volumio[17701]: verbose: CURRENT POSITION 0 Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::syncState stateService play Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::syncState currentStatus play Oct 04 11:57:51 amp volumio[17701]: info: Received an update from plugin. extracting info from payload Oct 04 11:57:51 amp volumio[17701]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 04 11:57:51 amp volumio[17701]: info: CoreStateMachine::pushState Oct 04 11:57:51 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:51 amp volumio[17701]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:51 amp volumio[17701]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:51 amp volumio[17701]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:51 amp volumio[17701]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:51 amp volumio[17701]: info: ------------------------------ 1312ms Oct 04 11:57:51 amp volumio[17701]: info: ------------------------------ 1278ms Oct 04 11:57:51 amp volumio[17701]: info: ------------------------------ 1096ms Oct 04 11:57:51 amp volumio[17701]: info: ------------------------------ 1047ms Oct 04 11:57:51 amp volumio[17701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Oct 04 11:57:51 amp volumio[17701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Oct 04 11:57:51 amp volumio[17701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Oct 04 11:57:52 amp volumio[17701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Oct 04 11:57:52 amp volumio[17701]: info: Starting UPNP Playback Oct 04 11:57:52 amp volumio[17701]: info: Preparing playback through UPNP Oct 04 11:57:52 amp volumio[17701]: info: Consume mode Oct 04 11:57:52 amp volumio[17701]: info: CoreCommandRouter::volumioGetState Oct 04 11:57:52 amp volumio[17701]: info: CorePlayQueue::getTrack 0 Oct 04 11:57:52 amp volumio[17701]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 04 11:57:52 amp volumio[17701]: TypeError: Cannot read property 'name' of undefined Oct 04 11:57:52 amp volumio[17701]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Oct 04 11:57:52 amp volumio[17701]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:107:28) Oct 04 11:57:52 amp volumio[17701]: at UpnpInterface.prepareUpnpPlayback (/volumio/app/plugins/audio_interface/upnp/index.js:257:34) Oct 04 11:57:52 amp volumio[17701]: at Socket. (/volumio/app/plugins/audio_interface/upnp/index.js:44:14) Oct 04 11:57:52 amp volumio[17701]: at Socket.emit (events.js:315:20) Oct 04 11:57:52 amp volumio[17701]: at addChunk (internal/streams/readable.js:309:12) Oct 04 11:57:52 amp volumio[17701]: at readableAddChunk (internal/streams/readable.js:280:11) Oct 04 11:57:52 amp volumio[17701]: at Socket.Readable.push (internal/streams/readable.js:223:10) Oct 04 11:57:52 amp volumio[17701]: at TCP.onStreamRead (internal/stream_base_commons.js:188:23) Oct 04 11:57:52 amp volumio[17701]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 04 11:57:58 amp sudo[30793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-04 11:56 Oct 04 11:57:58 amp sudo[30793]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"