-- Logs begin at Thu 2019-02-14 12:12:00 EET, end at Sat 2024-11-30 17:52:13 EET. -- Nov 30 17:51:00 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:00 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:08 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3546 Nov 30 17:51:08 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:08 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:08 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:11 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:11 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=trace msg="emitting websocket event: not_playing" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:12 volumio2 volumio[1002]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","play_origin":"go-librespot"}} Nov 30 17:51:12 volumio2 volumio[1002]: error: Failed to decode event: not_playing Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=trace msg="emitting websocket event: will_play" Nov 30 17:51:12 volumio2 volumio[1002]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","play_origin":"go-librespot"}} Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="selected format OGG_VORBIS_320 (43cd4af8e3b1184c4f1c96f879d957aa4051948d)" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="requested aes key for file 43cd4af8e3b1184c4f1c96f879d957aa4051948d, gid: 2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="fetched first chunk of 20, total size is 10228120 bytes" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=trace msg="cleared closed output device" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="created new output device" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=info msg="loaded track \"Informer\" (paused: true, position: 0ms, duration: 268910ms, prefetched: false)" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:12 volumio2 go-librespot[1381]: time="2024-11-30T17:51:12+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:2LjiPAQOVazT8sRyXL3XRs" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=trace msg="emitting websocket event: metadata" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=trace msg="emitting websocket event: stopped" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=trace msg="emitting websocket event: stopped" Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","name":"Informer","artist_names":["Snow"],"album_name":"12 Inches Of Snow","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0250cb0dcd257aea8ae4e44c85","position":0,"duration":268910,"release_date":"year:1993","track_number":7,"disc_number":1}} Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}} Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: {"status":"stop","service":"spop","title":"Informer","artist":"Snow","album":"12 Inches Of Snow","albumart":"https://i.scdn.co/image/ab67616d00001e0250cb0dcd257aea8ae4e44c85","uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","trackType":"spotify","seek":0,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3546 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3546 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Informer","artist":"Snow","album":"12 Inches Of Snow","albumart":"https://i.scdn.co/image/ab67616d00001e0250cb0dcd257aea8ae4e44c85","uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","trackType":"spotify","seek":0,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3546 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService stop Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::play index undefined Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}} Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: {"status":"stop","service":"spop","title":"Informer","artist":"Snow","album":"12 Inches Of Snow","albumart":"https://i.scdn.co/image/ab67616d00001e0250cb0dcd257aea8ae4e44c85","uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","trackType":"spotify","seek":0,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received spop Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::startPlaybackTimer Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::clearAddPlayTracks USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand stop Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: stop PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] InitTimeout - Amp off in: 700 ms Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: stop PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] InitTimeout - Amp off in: 700 ms Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: stop PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] InitTimeout - Amp off in: 700 ms Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 30 17:51:13 volumio2 go-librespot[1381]: time="2024-11-30T17:51:13+02:00" level=trace msg="emitting websocket event: paused" Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand stop took 30 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand clear Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces system playlist update Nov 30 17:51:13 volumio2 volumio[1002]: info: Ignoring MPD Status Update Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand clear took 4 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand add "USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav" Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","play_origin":"go-librespot"}} Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: PUSH STATE SPOTIFY Nov 30 17:51:13 volumio2 volumio[1002]: SPOTIFY: {"status":"pause","service":"spop","title":"Informer","artist":"Snow","album":"12 Inches Of Snow","albumart":"https://i.scdn.co/image/ab67616d00001e0250cb0dcd257aea8ae4e44c85","uri":"spotify:track:2LjiPAQOVazT8sRyXL3XRs","trackType":"spotify","seek":0,"duration":268,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received spop Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces system playlist update Nov 30 17:51:13 volumio2 volumio[1002]: info: Ignoring MPD Status Update Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces system playlist update Nov 30 17:51:13 volumio2 volumio[1002]: info: Ignoring MPD Status Update Nov 30 17:51:13 volumio2 volumio[1002]: error: updateQueue error: null Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces system playlist update Nov 30 17:51:13 volumio2 volumio[1002]: info: Ignoring MPD Status Update Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 23ms Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand add "USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav" took 20 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 14ms Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 12ms Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand play Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces system playlist update Nov 30 17:51:13 volumio2 volumio[1002]: info: Ignoring MPD Status Update Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces system playlist update Nov 30 17:51:13 volumio2 volumio[1002]: info: Ignoring MPD Status Update Nov 30 17:51:13 volumio2 volumio[1002]: error: Upnp client error: Error: This socket has been ended by the other party Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 12ms Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand play took 9 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 8ms Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 7ms Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces state update: player Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::getState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand status Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces state update: player Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::getState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand status Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces state update: player Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::getState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand status Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces state update: player Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::getState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand status Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand status took 8 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand status took 5 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand status took 4 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces state update: player Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::getState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand status Nov 30 17:51:13 volumio2 volumio[1002]: info: Nov 30 17:51:13 volumio2 volumio[1002]: ---------------------------- MPD announces state update: player Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::getState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand status Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand status took 14 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand status took 6 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand status took 4 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseTrackInfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseTrackInfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseTrackInfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseState Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":460,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Song Of Life (Betoko remix)","artist":"LEFTFIELD","album":"Song Of Life","uri":"USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","trackType":"wav"} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus stop Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":460,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Song Of Life (Betoko remix)","artist":"LEFTFIELD","album":"Song Of Life","uri":"USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","trackType":"wav"} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus play Nov 30 17:51:13 volumio2 volumio[1002]: info: Received an update from plugin. extracting info from payload Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":460,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Song Of Life (Betoko remix)","artist":"LEFTFIELD","album":"Song Of Life","uri":"USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","trackType":"wav"} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus play Nov 30 17:51:13 volumio2 volumio[1002]: info: Received an update from plugin. extracting info from payload Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 63ms Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 70ms Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 69ms Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand playlistinfo took 54 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand playlistinfo took 51 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: info: sendMpdCommand playlistinfo took 51 milliseconds Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseTrackInfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseTrackInfo Nov 30 17:51:13 volumio2 volumio[1002]: verbose: ControllerMpd::parseTrackInfo Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":460,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Song Of Life (Betoko remix)","artist":"LEFTFIELD","album":"Song Of Life","uri":"USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","trackType":"wav"} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus play Nov 30 17:51:13 volumio2 volumio[1002]: info: Received an update from plugin. extracting info from payload Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":460,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Song Of Life (Betoko remix)","artist":"LEFTFIELD","album":"Song Of Life","uri":"USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","trackType":"wav"} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus play Nov 30 17:51:13 volumio2 volumio[1002]: info: Received an update from plugin. extracting info from payload Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: ControllerMpd::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::servicePushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":460,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Song Of Life (Betoko remix)","artist":"LEFTFIELD","album":"Song Of Life","uri":"USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","trackType":"wav"} Nov 30 17:51:13 volumio2 volumio[1002]: verbose: CURRENT POSITION 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState stateService play Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::syncState currentStatus play Nov 30 17:51:13 volumio2 volumio[1002]: info: Received an update from plugin. extracting info from payload Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreStateMachine::pushState Nov 30 17:51:13 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:13 volumio2 volumio[1002]: info: CoreCommandRouter::volumioPushState Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 129ms Nov 30 17:51:13 volumio2 volumio[1002]: info: ------------------------------ 120ms Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:13 volumio2 volumio[1002]: info: [ASDebug] CurState: play PrevState: play Nov 30 17:51:14 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:14 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:16 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:17 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:17 volumio2 volumio[1002]: info: Preloading song: upnp/http://192.168.1.135:8200/ctl/ContentDir@1$14$0$1$0$0 Nov 30 17:51:17 volumio2 volumio[1002]: info: Preloading song: upnp/http://192.168.1.135:8200/ctl/ContentDir@1$14$0$1$0$1 Nov 30 17:51:17 volumio2 volumio[1002]: info: Preloading song: upnp/http://192.168.1.135:8200/ctl/ContentDir@1$14$0$1$0$2 Nov 30 17:51:17 volumio2 volumio[1002]: info: Exploding uri upnp/http://192.168.1.135:8200/ctl/ContentDir@1$14$0$1$0$0 in service upnp_browser Nov 30 17:51:17 volumio2 volumio[1002]: info: Exploding uri upnp/http://192.168.1.135:8200/ctl/ContentDir@1$14$0$1$0$1 in service upnp_browser Nov 30 17:51:17 volumio2 volumio[1002]: info: Exploding uri upnp/http://192.168.1.135:8200/ctl/ContentDir@1$14$0$1$0$2 in service upnp_browser Nov 30 17:51:28 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 17:51:28 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 17:51:28 volumio2 volumio[1002]: info: Discovery: Getting this device information Nov 30 17:51:28 volumio2 volumio[1002]: info: CoreCommandRouter::volumioGetState Nov 30 17:51:28 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:28 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 17:51:36 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:36 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:40 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:40 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:44 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:51:44 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:51:50 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Nov 30 17:51:50 volumio2 volumio[1002]: verbose: ControllerMpd::sendMpdCommand update Nov 30 17:51:57 volumio2 volumio[1002]: info: Adding mnt/USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav to favourites using generic method Nov 30 17:51:57 volumio2 volumio[1002]: info: Saving local item favourites Nov 30 17:51:57 volumio2 volumio[1002]: info: Pushing Favourites {"uri":"mnt/USB/USBX/Musikk/Leftfield - Song Of Life (Betoko Remix) (Hope Recordings 115, 2013) - wav/1-Leftfield_-_Song_Of_Life_(Betoko_remix).wav","favourite":true} Nov 30 17:51:58 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 17:51:58 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 17:51:58 volumio2 volumio[1002]: info: Discovery: Getting this device information Nov 30 17:51:58 volumio2 volumio[1002]: info: CoreCommandRouter::volumioGetState Nov 30 17:51:58 volumio2 volumio[1002]: info: CorePlayQueue::getTrack 3547 Nov 30 17:51:58 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 17:52:11 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:52:11 volumio2 volumio[1002]: info: Preload queue cleared Nov 30 17:52:13 volumio2 volumio[1002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 30 17:52:13 volumio2 volumio[1002]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 17:52:13 volumio2 volumio[1002]: TypeError: Cannot read property 'length' of undefined Nov 30 17:52:13 volumio2 volumio[1002]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 30 17:52:13 volumio2 volumio[1002]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 30 17:52:13 volumio2 volumio[1002]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 30 17:52:13 volumio2 volumio[1002]: at Parser.emit (events.js:315:20) Nov 30 17:52:13 volumio2 volumio[1002]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 30 17:52:13 volumio2 volumio[1002]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 30 17:52:13 volumio2 volumio[1002]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 30 17:52:13 volumio2 volumio[1002]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 30 17:52:13 volumio2 volumio[1002]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 30 17:52:13 volumio2 volumio[1002]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 30 17:52:13 volumio2 volumio[1002]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 30 17:52:13 volumio2 volumio[1002]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 30 17:52:13 volumio2 volumio[1002]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 30 17:52:13 volumio2 volumio[1002]: at IncomingMessage.emit (events.js:327:22) Nov 30 17:52:13 volumio2 volumio[1002]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 30 17:52:13 volumio2 volumio[1002]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 30 17:52:13 volumio2 volumio[1002]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 17:52:13 volumio2 sudo[18619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-30 17:51 Nov 30 17:52:13 volumio2 sudo[18619]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"