-- Logs begin at Mon 2025-02-24 04:18:52 CET, end at Mon 2025-02-24 10:14:38 CET. -- Feb 24 10:13:00 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 10:13:04 volumio nmbd[754]: [2025/02/24 10:13:04.393364, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 24 10:13:04 volumio nmbd[754]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.146 for name WORKGROUP<1d>. Feb 24 10:13:04 volumio nmbd[754]: This response was from IP 192.168.1.132, reporting an IP address of 192.168.1.132. Feb 24 10:13:04 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 10:13:08 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 10:13:09 volumio go-librespot[24110]: time="2025-02-24T10:13:09+01:00" level=trace msg="received accesspoint ping" Feb 24 10:13:09 volumio go-librespot[24110]: time="2025-02-24T10:13:09+01:00" level=trace msg="received accesspoint pong ack" Feb 24 10:13:09 volumio go-librespot[24110]: time="2025-02-24T10:13:09+01:00" level=trace msg="sent dealer ping" Feb 24 10:13:09 volumio go-librespot[24110]: time="2025-02-24T10:13:09+01:00" level=trace msg="received dealer pong" Feb 24 10:13:12 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 10:13:15 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 10:13:15 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 10:13:15 volumio volumio[1092]: info: Discovery: Getting this device information Feb 24 10:13:15 volumio volumio[1092]: info: CoreCommandRouter::volumioGetState Feb 24 10:13:15 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:15 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 10:13:16 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 24 10:13:27 volumio volumio[1092]: info: CoreCommandRouter::volumioSeek Feb 24 10:13:27 volumio volumio[1092]: info: CoreStateMachine::seek Feb 24 10:13:27 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:27 volumio volumio[1092]: info: TRACKBLOCK {"service":"spop","type":"song","title":"2 hands","name":"2 hands","artist":"Tate McRae","album":"So Close To What","albumart":"https://i.scdn.co/image/ab67616d0000b273dcf7b1f201951313ce2dab96","uri":"spotify:track:0B7tnohfi83RQquo2JRHrL","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","duration":182} Feb 24 10:13:27 volumio volumio[1092]: info: CoreStateMachine::startPlaybackTimer Feb 24 10:13:27 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:27 volumio volumio[1092]: info: Spotify seek to: 31000 Feb 24 10:13:27 volumio volumio[1092]: info: Sending Spotify command with payload to local API: /player/seek Feb 24 10:13:27 volumio volumio[1092]: info: CoreStateMachine::pushState Feb 24 10:13:27 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:27 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 10:13:27 volumio volumio[1092]: info: CoreCommandRouter::volumioPushState Feb 24 10:13:27 volumio volumio[1092]: info: MRS: Pushing multiroomSync output update for this device Feb 24 10:13:27 volumio volumio[1092]: info: MRS: Pushing multiroomSync output Feb 24 10:13:29 volumio volumio[1092]: info: CoreCommandRouter::volumioPlay Feb 24 10:13:29 volumio volumio[1092]: info: CoreStateMachine::play index undefined Feb 24 10:13:29 volumio volumio[1092]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 10:13:29 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:29 volumio volumio[1092]: info: CoreStateMachine::startPlaybackTimer Feb 24 10:13:29 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:29 volumio volumio[1092]: info: [1740388409016] ControllerSpotify::clearAddPlayTrack Feb 24 10:13:29 volumio volumio[1092]: info: Sending Spotify command with payload to local API: /player/play Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=debug msg="resolved context of track" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=trace msg="emitting websocket event: will_play" Feb 24 10:13:29 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0B7tnohfi83RQquo2JRHrL","play_origin":"go-librespot"}} Feb 24 10:13:29 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0B7tnohfi83RQquo2JRHrL","play_origin":"go-librespot"}} Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=debug msg="selected format OGG_VORBIS_320 (12f1ecd6532cfae17c66b0232436299fb0d3109f)" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=debug msg="requested aes key for file 12f1ecd6532cfae17c66b0232436299fb0d3109f, gid: 0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:29 volumio go-librespot[24110]: time="2025-02-24T10:13:29+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:0B7tnohfi83RQquo2JRHrL: failed retrieving audio key: failed retrieving aes key with code 1" Feb 24 10:13:29 volumio volumio[1092]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=trace msg="sent dealer ping" Feb 24 10:13:39 volumio volumio[1092]: info: CoreCommandRouter::volumioPlay Feb 24 10:13:39 volumio volumio[1092]: info: CoreStateMachine::play index undefined Feb 24 10:13:39 volumio volumio[1092]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 10:13:39 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:39 volumio volumio[1092]: info: CoreStateMachine::startPlaybackTimer Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=trace msg="received dealer pong" Feb 24 10:13:39 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:13:39 volumio volumio[1092]: info: [1740388419318] ControllerSpotify::clearAddPlayTrack Feb 24 10:13:39 volumio volumio[1092]: info: Sending Spotify command with payload to local API: /player/play Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=debug msg="resolved context of track" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=trace msg="emitting websocket event: will_play" Feb 24 10:13:39 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0B7tnohfi83RQquo2JRHrL","play_origin":"go-librespot"}} Feb 24 10:13:39 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0B7tnohfi83RQquo2JRHrL","play_origin":"go-librespot"}} Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=debug msg="selected format OGG_VORBIS_320 (12f1ecd6532cfae17c66b0232436299fb0d3109f)" uri="spotify:track:0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=debug msg="requested aes key for file 12f1ecd6532cfae17c66b0232436299fb0d3109f, gid: 0B7tnohfi83RQquo2JRHrL" Feb 24 10:13:39 volumio go-librespot[24110]: time="2025-02-24T10:13:39+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:0B7tnohfi83RQquo2JRHrL: failed retrieving audio key: failed retrieving aes key with code 1" Feb 24 10:13:39 volumio volumio[1092]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Feb 24 10:13:41 volumio volumio[1092]: info: CoreCommandRouter::volumioNext Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::next Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::stop Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::play index undefined Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 10:13:41 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::startPlaybackTimer Feb 24 10:13:41 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:41 volumio volumio[1092]: info: [1740388421804] ControllerSpotify::clearAddPlayTrack Feb 24 10:13:41 volumio volumio[1092]: info: Sending Spotify command with payload to local API: /player/play Feb 24 10:13:41 volumio volumio[1092]: info: CoreStateMachine::updateTrackBlock Feb 24 10:13:41 volumio volumio[1092]: info: CorePlayQueue::getTrackBlock Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=debug msg="resolved context of track" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=trace msg="emitting websocket event: will_play" Feb 24 10:13:41 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:541sN2qNfIlllGn9nGOQoC","play_origin":"go-librespot"}} Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=debug msg="selected format OGG_VORBIS_320 (2f815e643966edac53d21572d778d7f85815b7b8)" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=debug msg="requested aes key for file 2f815e643966edac53d21572d778d7f85815b7b8, gid: 541sN2qNfIlllGn9nGOQoC" Feb 24 10:13:41 volumio go-librespot[24110]: time="2025-02-24T10:13:41+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:541sN2qNfIlllGn9nGOQoC: failed retrieving audio key: failed retrieving aes key with code 1" Feb 24 10:13:41 volumio volumio[1092]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Feb 24 10:13:45 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 10:13:45 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 10:13:45 volumio volumio[1092]: info: Discovery: Getting this device information Feb 24 10:13:45 volumio volumio[1092]: info: CoreCommandRouter::volumioGetState Feb 24 10:13:45 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:45 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 10:13:55 volumio volumio[1092]: info: CoreCommandRouter::volumioRandom Feb 24 10:13:55 volumio volumio[1092]: info: CoreCommandRouter::writePlayerControls Feb 24 10:13:55 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:55 volumio volumio[1092]: info: CoreStateMachine::setRandom true Feb 24 10:13:55 volumio volumio[1092]: info: CoreStateMachine::pushState Feb 24 10:13:55 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:55 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 10:13:55 volumio volumio[1092]: info: CoreCommandRouter::volumioPushState Feb 24 10:13:55 volumio volumio[1092]: info: MRS: Pushing multiroomSync output update for this device Feb 24 10:13:55 volumio volumio[1092]: info: MRS: Pushing multiroomSync output Feb 24 10:13:56 volumio volumio[1092]: info: CoreCommandRouter::volumioRandom Feb 24 10:13:56 volumio volumio[1092]: info: CoreCommandRouter::writePlayerControls Feb 24 10:13:56 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:56 volumio volumio[1092]: info: CoreStateMachine::setRandom false Feb 24 10:13:56 volumio volumio[1092]: info: CoreStateMachine::pushState Feb 24 10:13:56 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:56 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 10:13:56 volumio volumio[1092]: info: CoreCommandRouter::volumioPushState Feb 24 10:13:56 volumio volumio[1092]: info: MRS: Pushing multiroomSync output update for this device Feb 24 10:13:56 volumio volumio[1092]: info: MRS: Pushing multiroomSync output Feb 24 10:13:59 volumio volumio[1092]: info: CoreCommandRouter::volumioRandom Feb 24 10:13:59 volumio volumio[1092]: info: CoreCommandRouter::writePlayerControls Feb 24 10:13:59 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:59 volumio volumio[1092]: info: CoreStateMachine::setRandom true Feb 24 10:13:59 volumio volumio[1092]: info: CoreStateMachine::pushState Feb 24 10:13:59 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:13:59 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 10:13:59 volumio volumio[1092]: info: CoreCommandRouter::volumioPushState Feb 24 10:13:59 volumio volumio[1092]: info: MRS: Pushing multiroomSync output update for this device Feb 24 10:13:59 volumio volumio[1092]: info: MRS: Pushing multiroomSync output Feb 24 10:14:00 volumio volumio[1092]: info: CoreCommandRouter::volumioRandom Feb 24 10:14:00 volumio volumio[1092]: info: CoreCommandRouter::writePlayerControls Feb 24 10:14:00 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:14:00 volumio volumio[1092]: info: CoreStateMachine::setRandom false Feb 24 10:14:00 volumio volumio[1092]: info: CoreStateMachine::pushState Feb 24 10:14:00 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:14:00 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 10:14:00 volumio volumio[1092]: info: CoreCommandRouter::volumioPushState Feb 24 10:14:00 volumio volumio[1092]: info: MRS: Pushing multiroomSync output update for this device Feb 24 10:14:00 volumio volumio[1092]: info: MRS: Pushing multiroomSync output Feb 24 10:14:02 volumio volumio[1092]: info: CoreCommandRouter::volumioPlay Feb 24 10:14:02 volumio volumio[1092]: info: CoreStateMachine::play index undefined Feb 24 10:14:02 volumio volumio[1092]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 10:14:02 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:14:02 volumio volumio[1092]: info: CoreStateMachine::startPlaybackTimer Feb 24 10:14:02 volumio volumio[1092]: info: CorePlayQueue::getTrack 2 Feb 24 10:14:02 volumio volumio[1092]: info: [1740388442208] ControllerSpotify::clearAddPlayTrack Feb 24 10:14:02 volumio volumio[1092]: info: Sending Spotify command with payload to local API: /player/play Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=debug msg="resolved context of track" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=trace msg="emitting websocket event: will_play" Feb 24 10:14:02 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:541sN2qNfIlllGn9nGOQoC","play_origin":"go-librespot"}} Feb 24 10:14:02 volumio volumio[1092]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:541sN2qNfIlllGn9nGOQoC","play_origin":"go-librespot"}} Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=debug msg="selected format OGG_VORBIS_320 (2f815e643966edac53d21572d778d7f85815b7b8)" uri="spotify:track:541sN2qNfIlllGn9nGOQoC" Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=debug msg="requested aes key for file 2f815e643966edac53d21572d778d7f85815b7b8, gid: 541sN2qNfIlllGn9nGOQoC" Feb 24 10:14:02 volumio go-librespot[24110]: time="2025-02-24T10:14:02+01:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:541sN2qNfIlllGn9nGOQoC: failed retrieving audio key: failed retrieving aes key with code 1" Feb 24 10:14:02 volumio volumio[1092]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Feb 24 10:14:08 volumio volumio[1092]: info: CoreCommandRouter::volumioPrevious Feb 24 10:14:08 volumio volumio[1092]: info: CoreStateMachine::previous Feb 24 10:14:08 volumio volumio[1092]: info: CoreStateMachine::updateTrackBlock Feb 24 10:14:08 volumio volumio[1092]: info: CorePlayQueue::getTrackBlock Feb 24 10:14:08 volumio volumio[1092]: info: CoreStateMachine::pushState Feb 24 10:14:08 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:14:08 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 10:14:08 volumio volumio[1092]: info: CoreCommandRouter::volumioPushState Feb 24 10:14:08 volumio volumio[1092]: info: MRS: Pushing multiroomSync output update for this device Feb 24 10:14:08 volumio volumio[1092]: info: MRS: Pushing multiroomSync output Feb 24 10:14:09 volumio go-librespot[24110]: time="2025-02-24T10:14:09+01:00" level=trace msg="sent dealer ping" Feb 24 10:14:09 volumio go-librespot[24110]: time="2025-02-24T10:14:09+01:00" level=trace msg="received dealer pong" Feb 24 10:14:15 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 10:14:15 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 10:14:15 volumio volumio[1092]: info: Discovery: Getting this device information Feb 24 10:14:15 volumio volumio[1092]: info: CoreCommandRouter::volumioGetState Feb 24 10:14:15 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:14:15 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 10:14:31 volumio volumio[1092]: verbose: New Socket.io Connection to 192.168.1.146 from 192.168.1.121 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_1_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Feb 24 10:14:31 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 10:14:31 volumio volumio[1092]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 24 10:14:31 volumio volumio[1092]: info: CoreCommandRouter::volumioGetState Feb 24 10:14:31 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:14:31 volumio volumio[1092]: info: Listing playlists Feb 24 10:14:31 volumio volumio[1092]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 10:14:31 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 10:14:31 volumio volumio[1092]: info: CoreCommandRouter::volumioGetQueue Feb 24 10:14:31 volumio volumio[1092]: info: CoreStateMachine::getQueue Feb 24 10:14:31 volumio volumio[1092]: info: CorePlayQueue::getQueue Feb 24 10:14:35 volumio volumio[1092]: info: Tunnel connection is inactive, restarting it Feb 24 10:14:35 volumio volumio[1092]: info: Starting Tunnel 1 Feb 24 10:14:35 volumio volumio[1092]: info: Starting Tunnel Connection Checker Feb 24 10:14:35 volumio sudo[24642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Feb 24 10:14:35 volumio sudo[24642]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 10:14:35 volumio autossh[24187]: received signal to exit (15) Feb 24 10:14:35 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Feb 24 10:14:35 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Feb 24 10:14:35 volumio systemd[1]: sshtunnel.service: Succeeded. Feb 24 10:14:35 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Feb 24 10:14:35 volumio volumio[1092]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 24 10:14:35 volumio volumio[1092]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 24 10:14:35 volumio systemd[1]: Started MyVolumio SSH Tunnel. Feb 24 10:14:35 volumio sudo[24642]: pam_unix(sudo:session): session closed for user root Feb 24 10:14:35 volumio autossh[24651]: port set to 0, monitoring disabled Feb 24 10:14:35 volumio autossh[24651]: starting ssh (count 1) Feb 24 10:14:35 volumio autossh[24651]: ssh child pid is 24655 Feb 24 10:14:35 volumio volumio[1092]: info: Remote SSH Started Feb 24 10:14:35 volumio volumio[1092]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 24 10:14:35 volumio volumio[1092]: info: CoreCommandRouter::volumioGetState Feb 24 10:14:35 volumio volumio[1092]: info: CorePlayQueue::getTrack 1 Feb 24 10:14:37 volumio volumio[1092]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Feb 24 10:14:37 volumio volumio[1092]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Feb 24 10:14:37 volumio volumio[1092]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 10:14:37 volumio volumio[1092]: TypeError: Cannot read property 'then' of undefined Feb 24 10:14:37 volumio volumio[1092]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Feb 24 10:14:37 volumio volumio[1092]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2274:30) Feb 24 10:14:37 volumio volumio[1092]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1450:26) Feb 24 10:14:37 volumio volumio[1092]: at Socket.emit (events.js:400:28) Feb 24 10:14:37 volumio volumio[1092]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Feb 24 10:14:37 volumio volumio[1092]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Feb 24 10:14:37 volumio volumio[1092]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 10:14:38 volumio sudo[24665]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-24 10:13 Feb 24 10:14:38 volumio sudo[24665]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:11:38 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="932fc3546f7cc8faa2b4d349036752dd"