-- Logs begin at Fri 2022-04-08 15:29:57 UTC, end at Sun 2024-07-21 06:56:37 UTC. -- Jul 21 06:55:03 opera volumio[3444]: error: Failed request for metavolumio API Jul 21 06:55:04 opera volumio[3444]: info: Executing endpoint metavolumio Jul 21 06:55:04 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 21 06:55:11 opera volumio[3444]: error: Failed request for metavolumio API Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::volumioPlay Jul 21 06:55:12 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::play index 2 Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::stop Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:12 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::play index undefined Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:12 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::startPlaybackTimer Jul 21 06:55:12 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:12 opera volumio[3444]: info: [1721544912488] ControllerUPNPBrowser::clearAddPlayTrack Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand stop Jul 21 06:55:12 opera volumio[3444]: info: Jul 21 06:55:12 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand stop took 7 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand clear Jul 21 06:55:12 opera volumio[3444]: info: Jul 21 06:55:12 opera volumio[3444]: ---------------------------- MPD announces system playlist update Jul 21 06:55:12 opera volumio[3444]: info: Ignoring MPD Status Update Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand status took 2 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand clear took 3 milliseconds Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.19:8200/MediaItems/2486.wav" Jul 21 06:55:12 opera volumio[3444]: error: updateQueue error: null Jul 21 06:55:12 opera volumio[3444]: info: ------------------------------ 5ms Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:55:12 opera volumio[3444]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 21 06:55:12 opera volumio[3444]: info: ------------------------------ 9ms Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.19:8200/MediaItems/2486.wav" Jul 21 06:55:12 opera volumio[3444]: info: Jul 21 06:55:12 opera volumio[3444]: ---------------------------- MPD announces system playlist update Jul 21 06:55:12 opera volumio[3444]: info: Ignoring MPD Status Update Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand add "http://192.168.1.19:8200/MediaItems/2486.wav" took 2 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand play Jul 21 06:55:12 opera volumio[3444]: info: ------------------------------ 3ms Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand play took 2 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: Jul 21 06:55:12 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:55:12 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:55:12 opera volumio[3444]: info: Jul 21 06:55:12 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand clearerror Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand status took 19 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand clearerror took 3 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand status took 2 milliseconds Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:55:12 opera volumio[3444]: info: ControllerMpd::pushState Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::servicePushState Jul 21 06:55:12 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:12 opera volumio[3444]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":165,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2486.wav","artist":null,"album":null,"uri":"http://192.168.1.19:8200/MediaItems/2486.wav","trackType":"wav"} Jul 21 06:55:12 opera volumio[3444]: verbose: CURRENT POSITION 2 Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::syncState stateService pause Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::syncState currentStatus stop Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:55:12 opera volumio[3444]: info: ------------------------------ 34ms Jul 21 06:55:12 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:55:12 opera volumio[3444]: info: sendMpdCommand playlistinfo took 14 milliseconds Jul 21 06:55:12 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:55:12 opera volumio[3444]: info: ControllerMpd::pushState Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::servicePushState Jul 21 06:55:12 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:12 opera volumio[3444]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":165,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2486.wav","artist":null,"album":null,"uri":"http://192.168.1.19:8200/MediaItems/2486.wav","trackType":"wav"} Jul 21 06:55:12 opera volumio[3444]: verbose: CURRENT POSITION 2 Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::syncState stateService pause Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::syncState currentStatus stop Jul 21 06:55:12 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:55:12 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:55:12 opera volumio[3444]: info: ------------------------------ 39ms Jul 21 06:55:12 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:55:13 opera volumio[3444]: info: CoreCommandRouter::volumioPlay Jul 21 06:55:13 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::play index 2 Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::stop Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:13 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::play index undefined Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:13 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::startPlaybackTimer Jul 21 06:55:13 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:13 opera volumio[3444]: info: [1721544913906] ControllerUPNPBrowser::clearAddPlayTrack Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand stop Jul 21 06:55:13 opera volumio[3444]: info: Jul 21 06:55:13 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:55:13 opera volumio[3444]: info: sendMpdCommand stop took 5 milliseconds Jul 21 06:55:13 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand clear Jul 21 06:55:13 opera volumio[3444]: info: Jul 21 06:55:13 opera volumio[3444]: ---------------------------- MPD announces system playlist update Jul 21 06:55:13 opera volumio[3444]: info: Ignoring MPD Status Update Jul 21 06:55:13 opera volumio[3444]: info: sendMpdCommand status took 2 milliseconds Jul 21 06:55:13 opera volumio[3444]: info: sendMpdCommand clear took 1 milliseconds Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.19:8200/MediaItems/2486.wav" Jul 21 06:55:13 opera volumio[3444]: error: updateQueue error: null Jul 21 06:55:13 opera volumio[3444]: info: ------------------------------ 3ms Jul 21 06:55:13 opera volumio[3444]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:55:13 opera volumio[3444]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 21 06:55:13 opera volumio[3444]: info: ------------------------------ 6ms Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.19:8200/MediaItems/2486.wav" Jul 21 06:55:13 opera volumio[3444]: info: Jul 21 06:55:13 opera volumio[3444]: ---------------------------- MPD announces system playlist update Jul 21 06:55:13 opera volumio[3444]: info: Ignoring MPD Status Update Jul 21 06:55:13 opera volumio[3444]: info: sendMpdCommand add "http://192.168.1.19:8200/MediaItems/2486.wav" took 1 milliseconds Jul 21 06:55:13 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 21 06:55:13 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand play Jul 21 06:55:13 opera volumio[3444]: info: ------------------------------ 2ms Jul 21 06:55:13 opera volumio[3444]: info: sendMpdCommand play took 2 milliseconds Jul 21 06:55:14 opera volumio[3444]: info: Jul 21 06:55:14 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:55:14 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:55:14 opera volumio[3444]: info: Jul 21 06:55:14 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:55:14 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand clearerror Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand status took 9 milliseconds Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand status took 9 milliseconds Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand clearerror Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand status took 12 milliseconds Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand clearerror took 5 milliseconds Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand playlistinfo took 9 milliseconds Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand clearerror took 5 milliseconds Jul 21 06:55:14 opera volumio[3444]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:55:14 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:55:14 opera volumio[3444]: info: ControllerMpd::pushState Jul 21 06:55:14 opera volumio[3444]: info: CoreCommandRouter::servicePushState Jul 21 06:55:14 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:14 opera volumio[3444]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":165,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2486.wav","artist":null,"album":null,"uri":"http://192.168.1.19:8200/MediaItems/2486.wav","trackType":"wav"} Jul 21 06:55:14 opera volumio[3444]: verbose: CURRENT POSITION 2 Jul 21 06:55:14 opera volumio[3444]: info: CoreStateMachine::syncState stateService pause Jul 21 06:55:14 opera volumio[3444]: info: CoreStateMachine::syncState currentStatus stop Jul 21 06:55:14 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:55:14 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:55:14 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:55:14 opera volumio[3444]: info: ControllerMpd::pushState Jul 21 06:55:14 opera volumio[3444]: info: CoreCommandRouter::servicePushState Jul 21 06:55:14 opera volumio[3444]: info: CorePlayQueue::getTrack 2 Jul 21 06:55:14 opera volumio[3444]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":165,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2486.wav","artist":null,"album":null,"uri":"http://192.168.1.19:8200/MediaItems/2486.wav","trackType":"wav"} Jul 21 06:55:14 opera volumio[3444]: verbose: CURRENT POSITION 2 Jul 21 06:55:14 opera volumio[3444]: info: CoreStateMachine::syncState stateService pause Jul 21 06:55:14 opera volumio[3444]: info: CoreStateMachine::syncState currentStatus stop Jul 21 06:55:14 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:55:14 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:55:14 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:55:14 opera volumio[3444]: info: ------------------------------ 35ms Jul 21 06:55:14 opera volumio[3444]: info: ------------------------------ 34ms Jul 21 06:55:14 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:55:14 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:55:32 opera kernel: rtk_btcoex: hci accept connreq, notify wifi page start Jul 21 06:55:33 opera kernel: rtk_btcoex: notify wifi page success end Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 2, len 16, out 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: RX l2cap conn req, hndl 0x0005, PSM 0x0001, scid 0x0040 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: PSM(0x0001) do not need parse Jul 21 06:55:33 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0040, scid 0x0040, result 0x0000 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 6, len 16, out 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: RX l2cap disconn req, hndl 0x0005, dcid 0x0040, scid 0x0040 Jul 21 06:55:33 opera kernel: rtk_btcoex: handle_l2cap_discon_req: handle 0x0005, dcid 0x0040, scid 0x0040, dir 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 2, len 16, out 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: RX l2cap conn req, hndl 0x0005, PSM 0x0019, scid 0x0041 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0040, scid 0x0041, result 0x0001 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0040, scid 0x0041, result 0x0001 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0040, scid 0x0041, result 0x0000 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap connection success, update connection Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: is_add 1, profile_index 2 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_bitmap 0x04 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[0] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[1] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[4] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[5] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[6] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[7] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:33 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:33 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x04 Jul 21 06:55:33 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x00 Jul 21 06:55:33 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 2, len 16, out 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: RX l2cap conn req, hndl 0x0005, PSM 0x0019, scid 0x0042 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0041, scid 0x0042, result 0x0001 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:33 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0041, scid 0x0042, result 0x0000 Jul 21 06:55:33 opera kernel: rtk_btcoex: l2cap connection success, update connection Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: is_add 1, profile_index 2 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_bitmap 0x04 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[0] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[1] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 2 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[4] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[5] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[6] = 0 Jul 21 06:55:33 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[7] = 0 Jul 21 06:55:34 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 2, len 16, out 1 Jul 21 06:55:35 opera kernel: rtk_btcoex: TX l2cap conn req, hndl 0x0005, PSM 0x0017, scid 0x0042 Jul 21 06:55:35 opera kernel: rtk_btcoex: PSM(0x0017) do not need parse Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: RX l2cap conn rsp, hndl 0x0005, dcid 0x0043, scid 0x0042, result 0x0000 Jul 21 06:55:35 opera kernel: input: D4:BB:E6:BC:94:B9 as /devices/virtual/input/input6 Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 2, len 16, out 1 Jul 21 06:55:35 opera kernel: rtk_btcoex: TX l2cap conn req, hndl 0x0005, PSM 0x001b, scid 0x0043 Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 2, len 16, out 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: RX l2cap conn req, hndl 0x0005, PSM 0x0001, scid 0x0044 Jul 21 06:55:35 opera kernel: rtk_btcoex: PSM(0x0001) do not need parse Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 1 Jul 21 06:55:35 opera kernel: rtk_btcoex: TX l2cap conn rsp, hndl 0x0005, dcid 0x0044, scid 0x0044, result 0x0000 Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 3, len 20, out 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: RX l2cap conn rsp, hndl 0x0005, dcid 0x0045, scid 0x0043, result 0x0000 Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap connection success, update connection Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: is_add 1, profile_index 3 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_bitmap 0x0c Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[0] = 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[1] = 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 2 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 1 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[4] = 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[5] = 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[6] = 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[7] = 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:35 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:35 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:35 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x0c Jul 21 06:55:35 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x00 Jul 21 06:55:35 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:35 opera kernel: rtk_btcoex: l2cap op 6, len 16, out 0 Jul 21 06:55:35 opera kernel: rtk_btcoex: RX l2cap disconn req, hndl 0x0005, dcid 0x0044, scid 0x0044 Jul 21 06:55:35 opera kernel: rtk_btcoex: handle_l2cap_discon_req: handle 0x0005, dcid 0x0044, scid 0x0044, dir 0 Jul 21 06:55:36 opera volumio[3444]: BT PLUGIN MESSAGE: Duration is 356066 Jul 21 06:55:36 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 0 Jul 21 06:55:36 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 7 Jul 21 06:55:36 opera kernel: rtk_btcoex: timeout_handler: pan idle->busy! Jul 21 06:55:36 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profie_bitmap = c Jul 21 06:55:36 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profile_status = 8 Jul 21 06:55:36 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:36 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:36 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:36 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x0c Jul 21 06:55:36 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x08 Jul 21 06:55:36 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:37 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 0 Jul 21 06:55:37 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:37 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan busy->idle! Jul 21 06:55:37 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profie_bitmap = c Jul 21 06:55:37 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profile_status = 0 Jul 21 06:55:37 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:37 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:37 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:37 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x0c Jul 21 06:55:37 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x00 Jul 21 06:55:37 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:38 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 0 Jul 21 06:55:38 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:39 opera bluetoothd[892]: /org/bluez/hci0/dev_D4_BB_E6_BC_94_B9/fd2: fd(19) ready Jul 21 06:55:39 opera volumio[3444]: ------------------------------------ BT MESSAGE: BT STATUS: pending Jul 21 06:55:39 opera volumio[3444]: ------------------------------------ BT MESSAGE: BT STATUS: active Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: Playing: true Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: VOLATILE: undefined Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: STATE:undefined Jul 21 06:55:39 opera volumio[3444]: info: CoreCommandRouter::volumioStop Jul 21 06:55:39 opera volumio[3444]: info: CoreStateMachine::stop Jul 21 06:55:39 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:55:39 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: BLUETOOTH: Starting Playback Routine Jul 21 06:55:39 opera volumio[3444]: info: Enabling Bluetooth Audio Output Jul 21 06:55:39 opera pulseaudio[1798]: Failed to load module "module-alsa-sink" (argument: "device=plughw:5,0"): initialization failed. Jul 21 06:55:39 opera volumio[3444]: error: Cannot load module of audio hardware: Error: Command failed: /usr/bin/pactl load-module module-alsa-sink device=plughw:5,0 Jul 21 06:55:39 opera volumio[3444]: No protocol specified Jul 21 06:55:39 opera volumio[3444]: xcb_connection_has_error() returned true Jul 21 06:55:39 opera volumio[3444]: Failure: Module initialization failed Jul 21 06:55:39 opera volumio[3444]: No protocol specified Jul 21 06:55:39 opera volumio[3444]: xcb_connection_has_error() returned true Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: SINK LOADED: 3 Jul 21 06:55:39 opera volumio[3444]: info: Alsa Sink Already Loaded Jul 21 06:55:39 opera volumio[3444]: ------------------------------------ BT MESSAGE: BT STATUS: playing Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: Playing: true Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: VOLATILE: bluetooth Jul 21 06:55:39 opera volumio[3444]: BT PLUGIN MESSAGE: STATE:undefined Jul 21 06:55:39 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profie_bitmap = c Jul 21 06:55:39 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profile_status = 4 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x0c Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x04 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtp: v 2, cc 0, pt 96 Jul 21 06:55:39 opera kernel: rtk_btcoex: syncword: 9c Jul 21 06:55:39 opera kernel: rtk_btcoex: freq 44.1kHz Jul 21 06:55:39 opera kernel: rtk_btcoex: blocks 16 Jul 21 06:55:39 opera kernel: rtk_btcoex: channel mode JOINT_STEREO Jul 21 06:55:39 opera kernel: rtk_btcoex: allocation method LOUDNESS Jul 21 06:55:39 opera kernel: rtk_btcoex: subbands 8 Jul 21 06:55:39 opera kernel: rtk_btcoex: bitpool 53 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc51 Jul 21 06:55:39 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 34 Jul 21 06:55:39 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 5 Jul 21 06:55:39 opera kernel: rtk_btcoex: timeout_handler: pan idle->busy! Jul 21 06:55:39 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profie_bitmap = c Jul 21 06:55:39 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profile_status = c Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x0c Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x0c Jul 21 06:55:39 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:40 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 66 Jul 21 06:55:40 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:40 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan busy->idle! Jul 21 06:55:40 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profie_bitmap = c Jul 21 06:55:40 opera kernel: rtk_btcoex: update_profile_state: btrtl_coex.profile_status = 4 Jul 21 06:55:40 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:55:40 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:55:40 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:55:40 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x0c Jul 21 06:55:40 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x04 Jul 21 06:55:40 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:55:41 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 73 Jul 21 06:55:41 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:42 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:55:42 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:43 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:55:43 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:44 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 67 Jul 21 06:55:44 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:45 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:55:45 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:46 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 71 Jul 21 06:55:46 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:47 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:55:47 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:48 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 66 Jul 21 06:55:48 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:49 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:55:49 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:50 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:55:50 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:51 opera dhcpd[1348]: DHCPDISCOVER from 48:e7:da:4f:05:97 (opera) via wlan0 Jul 21 06:55:51 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:55:51 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:52 opera dhcpd[1348]: DHCPOFFER on 192.168.211.4 to 48:e7:da:4f:05:97 (opera) via wlan0 Jul 21 06:55:52 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 67 Jul 21 06:55:52 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:53 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:55:53 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:54 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:55:54 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:55 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 67 Jul 21 06:55:55 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:56 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:55:56 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:57 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:55:57 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:58 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:55:58 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:55:59 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 68 Jul 21 06:55:59 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:00 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 68 Jul 21 06:56:00 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:01 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:56:01 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:02 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:56:02 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:03 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:56:03 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:04 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 66 Jul 21 06:56:04 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:05 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 70 Jul 21 06:56:05 opera kernel: rtk_btcoex: count_pan_packet_timeout: pan_packet_count 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: count_a2dp_packet_timeout: a2dp_packet_count 69 Jul 21 06:56:06 opera kernel: rtk_btcoex: process disconn complete event. Jul 21 06:56:06 opera kernel: rtk_btcoex: hci disconn, hndl 5, psm 19, dcid 41, scid 40 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: is_add 0, profile_index 2 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 1 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_bitmap 0x0c Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[0] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[1] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 1 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 1 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[4] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[5] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[6] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[7] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: Delete profile: hndl 0x0005, psm 0x0019, dcid 0x0041, scid 0x0040 Jul 21 06:56:06 opera kernel: rtk_btcoex: hci disconn, hndl 5, psm 19, dcid 42, scid 41 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: is_add 0, profile_index 2 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_bitmap 0x08 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[0] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[1] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 1 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[4] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[5] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[6] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[7] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 5 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 1 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: handle 0x0005 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_bitmap 0x08 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x00 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:56:06 opera kernel: rtk_btcoex: Delete profile: hndl 0x0005, psm 0x0019, dcid 0x0042, scid 0x0041 Jul 21 06:56:06 opera kernel: rtk_btcoex: hci disconn, hndl 5, psm 1b, dcid 45, scid 43 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: is_add 0, profile_index 3 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_bitmap 0x00 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[0] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[1] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[2] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[3] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[4] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[5] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[6] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: update_profile_connection: btrtl_coex.profile_refcount[7] = 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: BufferSize 2 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: NumberOfHandles 0 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_notify_profileinfo_to_fw: profile_status 0x00 Jul 21 06:56:06 opera kernel: rtk_btcoex: rtk_vendor_cmd_to_fw: opcode 0xfc19 Jul 21 06:56:06 opera kernel: rtk_btcoex: Delete profile: hndl 0x0005, psm 0x001b, dcid 0x0045, scid 0x0043 Jul 21 06:56:06 opera dbus[746]: [system] Rejected send message, 3 matched rules; type="method_return", sender=":1.21" (uid=1000 pid=1798 comm="/usr/bin/pulseaudio ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.7" (uid=0 pid=892 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Jul 21 06:56:08 opera volumio[3444]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E9%BB%84%E7%BA%A2%E8%8B%B1/9c59738e-3e4f-4d13-9a41-4cd8c5bb6e43.jpg' Jul 21 06:56:16 opera volumio[3444]: info: CoreCommandRouter::volumioGetState Jul 21 06:56:24 opera volumio[3444]: info: CoreCommandRouter::volumioGetState Jul 21 06:56:25 opera volumio[3444]: info: CoreCommandRouter::volumioGetState Jul 21 06:56:25 opera sudo[8440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 21 06:56:25 opera sudo[8440]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 06:56:25 opera sudo[8440]: pam_unix(sudo:session): session closed for user root Jul 21 06:56:25 opera sudo[8444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 21 06:56:25 opera sudo[8444]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 06:56:25 opera sudo[8444]: pam_unix(sudo:session): session closed for user root Jul 21 06:56:25 opera sudo[8458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 21 06:56:25 opera sudo[8458]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 06:56:25 opera sudo[8460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 21 06:56:25 opera sudo[8458]: pam_unix(sudo:session): session closed for user root Jul 21 06:56:25 opera sudo[8460]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 06:56:25 opera sudo[8460]: pam_unix(sudo:session): session closed for user root Jul 21 06:56:26 opera volumio[3444]: info: CoreCommandRouter::volumioGetState Jul 21 06:56:26 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 21 06:56:26 opera volumio[3444]: error: Could not retrieve plugin audio_interface multiroom Jul 21 06:56:26 opera volumio[3444]: info: Listing playlists Jul 21 06:56:26 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 21 06:56:26 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 21 06:56:26 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 21 06:56:26 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 21 06:56:28 opera volumio[3444]: info: CoreCommandRouter::volumioVolatilePlay Jul 21 06:56:28 opera volumio[3444]: info: CoreStateMachine::volatilePlay Jul 21 06:56:28 opera volumio[3444]: error: Could not retrieve plugin music_service bluetooth Jul 21 06:56:28 opera volumio[3444]: info: WARNING: No play method for volatile plugin bluetooth Jul 21 06:56:31 opera volumio[3444]: info: CoreCommandRouter::volumioGetState Jul 21 06:56:33 opera volumio[3444]: info: CoreCommandRouter::volumioGetQueue Jul 21 06:56:33 opera volumio[3444]: info: CoreStateMachine::getQueue Jul 21 06:56:33 opera volumio[3444]: info: CorePlayQueue::getQueue Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::volumioPlay Jul 21 06:56:35 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:56:35 opera volumio[3444]: info: Bluetooth Detach Command Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::play index 1 Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::stop Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:56:35 opera volumio[3444]: verbose: UNSET VOLATILE Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::play index undefined Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 06:56:35 opera volumio[3444]: info: CorePlayQueue::getTrack 1 Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::startPlaybackTimer Jul 21 06:56:35 opera volumio[3444]: info: CorePlayQueue::getTrack 1 Jul 21 06:56:35 opera volumio[3444]: info: [1721544995406] ControllerUPNPBrowser::clearAddPlayTrack Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand stop Jul 21 06:56:35 opera volumio[3444]: info: Jul 21 06:56:35 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand stop took 22 milliseconds Jul 21 06:56:35 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand clear Jul 21 06:56:35 opera volumio[3444]: info: Jul 21 06:56:35 opera volumio[3444]: ---------------------------- MPD announces system playlist update Jul 21 06:56:35 opera volumio[3444]: info: Ignoring MPD Status Update Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand status took 7 milliseconds Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand clear took 7 milliseconds Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.19:8200/MediaItems/2485.wav" Jul 21 06:56:35 opera volumio[3444]: error: updateQueue error: null Jul 21 06:56:35 opera volumio[3444]: info: ------------------------------ 11ms Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:56:35 opera volumio[3444]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 21 06:56:35 opera volumio[3444]: info: ------------------------------ 24ms Jul 21 06:56:35 opera volumio[3444]: info: Bluetooth Audio successfully Disabled Jul 21 06:56:35 opera volumio[3444]: info: Bluetooth Successfully Detached Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.19:8200/MediaItems/2485.wav" Jul 21 06:56:35 opera volumio[3444]: info: Jul 21 06:56:35 opera volumio[3444]: ---------------------------- MPD announces system playlist update Jul 21 06:56:35 opera volumio[3444]: info: Ignoring MPD Status Update Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand add "http://192.168.1.19:8200/MediaItems/2485.wav" took 5 milliseconds Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand play Jul 21 06:56:35 opera volumio[3444]: info: ------------------------------ 11ms Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand play took 4 milliseconds Jul 21 06:56:35 opera volumio[3444]: info: Jul 21 06:56:35 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:56:35 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:56:35 opera volumio[3444]: info: Jul 21 06:56:35 opera volumio[3444]: ---------------------------- MPD announces state update: player Jul 21 06:56:35 opera volumio[3444]: info: ControllerMpd::getState Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand status Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand status took 2 milliseconds Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand status took 6 milliseconds Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::parseState Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:56:35 opera volumio[3444]: info: ControllerMpd::pushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::servicePushState Jul 21 06:56:35 opera volumio[3444]: info: CorePlayQueue::getTrack 1 Jul 21 06:56:35 opera volumio[3444]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2485.wav","artist":null,"album":null,"uri":"http://192.168.1.19:8200/MediaItems/2485.wav","trackType":"wav"} Jul 21 06:56:35 opera volumio[3444]: verbose: CURRENT POSITION 1 Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::syncState stateService play Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::syncState currentStatus stop Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:56:35 opera volumio[3444]: info: ------------------------------ 37ms Jul 21 06:56:35 opera volumio[3444]: info: sendMpdCommand playlistinfo took 16 milliseconds Jul 21 06:56:35 opera volumio[3444]: verbose: ControllerMpd::parseTrackInfo Jul 21 06:56:35 opera volumio[3444]: info: ControllerMpd::pushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::servicePushState Jul 21 06:56:35 opera volumio[3444]: info: CorePlayQueue::getTrack 1 Jul 21 06:56:35 opera volumio[3444]: verbose: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2485.wav","artist":null,"album":null,"uri":"http://192.168.1.19:8200/MediaItems/2485.wav","trackType":"wav"} Jul 21 06:56:35 opera volumio[3444]: verbose: CURRENT POSITION 1 Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::syncState stateService play Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::syncState currentStatus play Jul 21 06:56:35 opera volumio[3444]: info: Received an update from plugin. extracting info from payload Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:56:35 opera volumio[3444]: info: CoreStateMachine::pushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::volumioPushState Jul 21 06:56:35 opera volumio[3444]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 06:56:35 opera volumio[3444]: info: ------------------------------ 46ms Jul 21 06:56:35 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:56:35 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:56:35 opera volumio[3444]: info: Updating RAAT Signal Path Jul 21 06:56:37 opera volumio[3444]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 06:56:37 opera volumio[3444]: { Error: connect ETIMEDOUT 185.60.216.36:80 Jul 21 06:56:37 opera volumio[3444]: at Object._errnoException (util.js:1022:11) Jul 21 06:56:37 opera volumio[3444]: at _exceptionWithHostPort (util.js:1044:20) Jul 21 06:56:37 opera volumio[3444]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Jul 21 06:56:37 opera volumio[3444]: code: 'ETIMEDOUT', Jul 21 06:56:37 opera volumio[3444]: errno: 'ETIMEDOUT', Jul 21 06:56:37 opera volumio[3444]: syscall: 'connect', Jul 21 06:56:37 opera volumio[3444]: address: '185.60.216.36', Jul 21 06:56:37 opera volumio[3444]: port: 80 } Jul 21 06:56:37 opera volumio[3444]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 06:56:37 opera sudo[8515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-21 06:55 Jul 21 06:56:37 opera sudo[8515]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 8 (jessie)" NAME="Debian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=debian HOME_URL="http://www.debian.org/" SUPPORT_URL="http://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03" VOLUMIO_FE_VERSION="047a38c6e11e7058b10d3038ac9dcbff94f92828" VOLUMIO_BE_VERSION="3e944f35d34b575025d16b976b4cb4d9aed53b66" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="opera" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Apr 8 17:29:57 CEST 2022" VOLUMIO_VERSION="1.033" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_VENDOR="Opera Consonance" VOLUMIO_MODEL="X5" VOLUMIO_VENDOR_MODEL="Opera X5" VOLUMIO_HASH="77fa3b0bf86939c934741dd9bb62adcc"