From a0d1575ab0b024b8198c27e69df6c9a0d55cbeee Mon Sep 17 00:00:00 2001 From: Matthew Xie Date: Wed, 31 Oct 2012 14:55:16 -0700 Subject: Turn off socket debug messages Change the message macro so that they can be turned on at runtime bug 7174712 Change-Id: I59b955720ec5de26774c58fba6d369ef34d1ac3b --- btif/src/btif_sock_rfc.c | 120 +++++++++++++++++++---------------------- btif/src/btif_sock_sdp.c | 17 ++---- btif/src/btif_sock_thread.c | 126 +++++++++++++++++--------------------------- 3 files changed, 108 insertions(+), 155 deletions(-) diff --git a/btif/src/btif_sock_rfc.c b/btif/src/btif_sock_rfc.c index 6202ca4..650549f 100644 --- a/btif/src/btif_sock_rfc.c +++ b/btif/src/btif_sock_rfc.c @@ -16,14 +16,12 @@ * ******************************************************************************/ - /************************************************************************************ * * Filename: btif_sock_rfc.c * * Description: Handsfree Profile Bluetooth Interface * - * ***********************************************************************************/ #include #include @@ -56,12 +54,7 @@ #include #include -#define info(fmt, ...) ALOGI ("%s: " fmt,__FUNCTION__, ## __VA_ARGS__) -#define debug(fmt, ...) ALOGD ("%s: " fmt,__FUNCTION__, ## __VA_ARGS__) -#define warn(fmt, ...) ALOGW ("## WARNING : %s: " fmt "##",__FUNCTION__, ## __VA_ARGS__) -#define error(fmt, ...) ALOGE ("## ERROR : %s: " fmt "##",__FUNCTION__, ## __VA_ARGS__) -#define asrt(s) if(!(s)) ALOGE ("## %s assert %s failed at line:%d ##",__FUNCTION__, #s, __LINE__) - +#define asrt(s) if(!(s)) APPL_TRACE_ERROR3("## %s assert %s failed at line:%d ##",__FUNCTION__, #s, __LINE__) extern void uuid_to_string(bt_uuid_t *p_uuid, char *str); static inline void logu(const char* title, const uint8_t * p_uuid) @@ -193,7 +186,7 @@ static inline rfc_slot_t* find_rfc_slot_by_id(uint32_t id) } } } - warn("invalid rfc slot id: %d", id); + APPL_TRACE_WARNING1("invalid rfc slot id: %d", id); return NULL; } static inline rfc_slot_t* find_rfc_slot_by_pending_sdp() @@ -224,7 +217,7 @@ static inline rfc_slot_t* find_rfc_slot_requesting_sdp() if(rfc_slots[i].id && rfc_slots[i].f.doing_sdp_request) return &rfc_slots[i]; } - debug("can not find any slot is requesting sdp"); + APPL_TRACE_DEBUG0("can not find any slot is requesting sdp"); return NULL; } @@ -241,7 +234,7 @@ static inline rfc_slot_t* find_rfc_slot_by_fd(int fd) return &rfc_slots[i]; else { - error("invalid rfc slot id, cannot be 0"); + APPL_TRACE_ERROR0("invalid rfc slot id, cannot be 0"); break; } } @@ -263,7 +256,7 @@ static rfc_slot_t* alloc_rfc_slot(const bt_bdaddr_t *addr, const char* name, con int fds[2] = {-1, -1}; if(socketpair(AF_LOCAL, SOCK_STREAM, 0, fds)) { - error("socketpair failed, errno:%d", errno); + APPL_TRACE_ERROR1("socketpair failed, errno:%d", errno); return NULL; } rs->fd = fds[0]; @@ -314,7 +307,7 @@ bt_status_t btsock_rfc_listen(const char* service_name, const uint8_t* service_u { if(sock_fd == NULL || (service_uuid == NULL && (channel < 1 || channel > 30))) { - error("invalid rfc channel:%d or sock_fd:%p, uuid:%p", channel, sock_fd, service_uuid); + APPL_TRACE_ERROR3("invalid rfc channel:%d or sock_fd:%p, uuid:%p", channel, sock_fd, service_uuid); return BT_STATUS_PARM_INVALID; } *sock_fd = -1; @@ -336,8 +329,6 @@ bt_status_t btsock_rfc_listen(const char* service_name, const uint8_t* service_u rfc_slot_t* rs = alloc_rfc_slot(NULL, service_name, service_uuid, channel, flags, TRUE); if(rs) { - debug("call BTA_JvCreateRecordByUser, slot id:%d, server fd:%d, app_fd:%d, security:0x%x, scn:%d", - rs->id, rs->fd, rs->app_fd, rs->security, rs->scn); BTA_JvCreateRecordByUser((void *)rs->id); *sock_fd = rs->app_fd; rs->app_fd = -1; //the fd ownership is transferred to app @@ -352,7 +343,8 @@ bt_status_t btsock_rfc_connect(const bt_bdaddr_t *bd_addr, const uint8_t* servic { if(sock_fd == NULL || (service_uuid == NULL && (channel < 1 || channel > 30))) { - error("invalid rfc channel:%d or sock_fd:%p, uuid:%p", channel, sock_fd, service_uuid); + APPL_TRACE_ERROR3("invalid rfc channel:%d or sock_fd:%p, uuid:%p", channel, sock_fd, + service_uuid); return BT_STATUS_PARM_INVALID; } *sock_fd = -1; @@ -365,7 +357,7 @@ bt_status_t btsock_rfc_connect(const bt_bdaddr_t *bd_addr, const uint8_t* servic { if(is_uuid_empty(service_uuid)) { - debug("connecting to rfcomm channel:%d without service discovery", channel); + APPL_TRACE_DEBUG1("connecting to rfcomm channel:%d without service discovery", channel); if(BTA_JvRfcommConnect(rs->security, rs->role, rs->scn, rs->addr.address, rfcomm_cback, (void*)rs->id) == BTA_JV_SUCCESS) { @@ -386,8 +378,6 @@ bt_status_t btsock_rfc_connect(const bt_bdaddr_t *bd_addr, const uint8_t* servic tSDP_UUID sdp_uuid; sdp_uuid.len = 16; memcpy(sdp_uuid.uu.uuid128, service_uuid, sizeof(sdp_uuid.uu.uuid128)); - debug("start service channel discovery, slot id:%d, fd:%d, app_fd:%d, security:0x%x, scn:%d", - rs->id, rs->fd, rs->app_fd, rs->security, rs->scn); logu("service_uuid", service_uuid); *sock_fd = rs->app_fd; rs->app_fd = -1; //the fd ownership is transferred to app @@ -418,13 +408,13 @@ static int create_server_sdp_record(rfc_slot_t* rs) { if(BTM_TryAllocateSCN(rs->scn) == FALSE) { - error("rfc channel:%d already in use", scn); + APPL_TRACE_ERROR1("rfc channel:%d already in use", scn); return FALSE; } } else if((rs->scn = BTM_AllocateSCN()) == 0) { - error("run out of rfc channels"); + APPL_TRACE_ERROR0("run out of rfc channels"); return FALSE; } if((rs->sdp_handle = add_rfc_sdp_rec(rs->service_name, rs->service_uuid, rs->scn)) <= 0) @@ -487,7 +477,7 @@ static inline void free_rfc_slot_scn(rfc_slot_t* rs) } static void cleanup_rfc_slot(rfc_slot_t* rs) { - debug("cleanup slot:%d, fd:%d, scn:%d", rs->id, rs->fd, rs->scn); + APPL_TRACE_DEBUG3("cleanup slot:%d, fd:%d, scn:%d", rs->id, rs->fd, rs->scn); if(rs->fd != -1) { shutdown(rs->fd, 2); @@ -506,7 +496,7 @@ static void cleanup_rfc_slot(rfc_slot_t* rs) } if(rs->rfc_handle && !rs->f.closing && !rs->f.server) { - debug("closing rfcomm connection, rfc_handle:%d", rs->rfc_handle); + APPL_TRACE_DEBUG1("closing rfcomm connection, rfc_handle:%d", rs->rfc_handle); BTA_JvRfcommClose(rs->rfc_handle); rs->rfc_handle = 0; } @@ -546,7 +536,7 @@ static BOOLEAN send_app_connect_signal(int fd, const bt_bdaddr_t* addr, int chan { if(sock_send_fd(fd, (const uint8_t*)&cs, sizeof(cs), send_fd) == sizeof(cs)) return TRUE; - else error("sock_send_fd failed, fd:%d, send_fd:%d", fd, send_fd); + else APPL_TRACE_ERROR2("sock_send_fd failed, fd:%d, send_fd:%d", fd, send_fd); } else if(sock_send_all(fd, (const uint8_t*)&cs, sizeof(cs)) == sizeof(cs)) { @@ -565,7 +555,6 @@ static void on_cl_rfc_init(tBTA_JV_RFCOMM_CL_INIT *p_init, uint32_t id) else { rs->rfc_handle = p_init->handle; - debug("on_cl_rfc_init, slot id:%d, fd:%d, rfc scn:%d, server:%d", rs->id, rs->fd, rs->scn, rs->f.server); } } unlock_slot(&slot_lock); @@ -581,11 +570,11 @@ static void on_srv_rfc_listen_started(tBTA_JV_RFCOMM_START *p_start, uint32_t i else { rs->rfc_handle = p_start->handle; - debug("call send_app_scn, slot id:%d, fd:%d, rfc scn:%d, server:%d", rs->id, rs->fd, rs->scn, rs->f.server); + if(!send_app_scn(rs)) { //closed - debug("send_app_scn() failed, close rs->id:%d", rs->id); + APPL_TRACE_DEBUG1("send_app_scn() failed, close rs->id:%d", rs->id); cleanup_rfc_slot(rs); } } @@ -606,8 +595,9 @@ static uint32_t on_srv_rfc_connect(tBTA_JV_RFCOMM_SRV_OPEN *p_open, uint32_t id) //start monitor the socket btsock_thread_add_fd(pth, srv_rs->fd, BTSOCK_RFCOMM, SOCK_THREAD_FD_EXCEPTION, srv_rs->id); btsock_thread_add_fd(pth, accept_rs->fd, BTSOCK_RFCOMM, SOCK_THREAD_FD_RD, accept_rs->id); - debug("sending connect signal & app fd:%dto app server to accept() the connection", accept_rs->app_fd); - debug("server fd:%d, scn:%d", srv_rs->fd, srv_rs->scn); + APPL_TRACE_DEBUG1("sending connect signal & app fd:%dto app server to accept() the connection", + accept_rs->app_fd); + APPL_TRACE_DEBUG2("server fd:%d, scn:%d", srv_rs->fd, srv_rs->scn); send_app_connect_signal(srv_rs->fd, &accept_rs->addr, srv_rs->scn, 0, accept_rs->app_fd); accept_rs->app_fd = -1; //the fd is closed after sent to app new_listen_slot_id = srv_rs->id; @@ -625,14 +615,16 @@ static void on_cli_rfc_connect(tBTA_JV_RFCOMM_OPEN *p_open, uint32_t id) rs->rfc_port_handle = BTA_JvRfcommGetPortHdl(p_open->handle); bd_copy(rs->addr.address, p_open->rem_bda, 0); //notify app rfc is connected - debug("call send_app_connect_signal, slot id:%d, fd:%d, rfc scn:%d, server:%d", rs->id, rs->fd, rs->scn, rs->f.server); + APPL_TRACE_DEBUG4("call send_app_connect_signal, slot id:%d, fd:%d, rfc scn:%d, server:%d", + rs->id, rs->fd, rs->scn, rs->f.server); if(send_app_connect_signal(rs->fd, &rs->addr, rs->scn, 0, -1)) { //start monitoring the socketpair to get call back when app writing data - debug("on_rfc_connect_ind, connect signal sent, slot id:%d, rfc scn:%d, server:%d", rs->id, rs->scn, rs->f.server); + APPL_TRACE_DEBUG3("on_rfc_connect_ind, connect signal sent, slot id:%d, rfc scn:%d, server:%d", + rs->id, rs->scn, rs->f.server); rs->f.connected = TRUE; } - else error("send_app_connect_signal failed"); + else APPL_TRACE_ERROR0("send_app_connect_signal failed"); } else if(rs) cleanup_rfc_slot(rs); @@ -644,7 +636,8 @@ static void on_rfc_close(tBTA_JV_RFCOMM_CLOSE * p_close, uint32_t id) rfc_slot_t* rs = find_rfc_slot_by_id(id); if(rs) { - debug("on_rfc_close, slot id:%d, fd:%d, rfc scn:%d, server:%d", rs->id, rs->fd, rs->scn, rs->f.server); + APPL_TRACE_DEBUG4("on_rfc_close, slot id:%d, fd:%d, rfc scn:%d, server:%d", + rs->id, rs->fd, rs->scn, rs->f.server); free_rfc_slot_scn(rs); //rfc_handle already closed when receiving rfcomm close event from stack. rs->rfc_handle = 0; @@ -682,54 +675,47 @@ static void *rfcomm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) { int rc; void* new_user_data = NULL; - debug("event=%s", jv_evt[event]); + APPL_TRACE_DEBUG1("event=%s", jv_evt[event]); switch (event) { case BTA_JV_RFCOMM_START_EVT: - debug("BTA_JV_RFCOMM_START_EVT"); on_srv_rfc_listen_started(&p_data->rfc_start, (uint32_t)user_data); break; case BTA_JV_RFCOMM_CL_INIT_EVT: - debug("BTA_JV_RFCOMM_CL_INIT_EVT"); on_cl_rfc_init(&p_data->rfc_cl_init, (uint32_t)user_data); break; case BTA_JV_RFCOMM_OPEN_EVT: - debug("BTA_JV_RFCOMM_OPEN_EVT"); on_cli_rfc_connect(&p_data->rfc_open, (uint32_t)user_data); break; case BTA_JV_RFCOMM_SRV_OPEN_EVT: - debug("BTA_JV_RFCOMM_SRV_OPEN_EVT"); new_user_data = (void*)on_srv_rfc_connect(&p_data->rfc_srv_open, (uint32_t)user_data); break; case BTA_JV_RFCOMM_CLOSE_EVT: - debug("BTA_JV_RFCOMM_CLOSE_EVT"); on_rfc_close(&p_data->rfc_close, (uint32_t)user_data); break; case BTA_JV_RFCOMM_READ_EVT: - debug("BTA_JV_RFCOMM_READ_EVT not used"); + APPL_TRACE_DEBUG0("BTA_JV_RFCOMM_READ_EVT not used"); break; case BTA_JV_RFCOMM_WRITE_EVT: - debug("BTA_JV_RFCOMM_WRITE_EVT"); on_rfc_write_done(&p_data->rfc_write, (uint32_t)user_data); break; case BTA_JV_RFCOMM_DATA_IND_EVT: - debug("BTA_JV_RFCOMM_DATA_IND_EVT not used"); + APPL_TRACE_DEBUG0("BTA_JV_RFCOMM_DATA_IND_EVT not used"); break; case BTA_JV_RFCOMM_CONG_EVT: //on_rfc_cong(&p_data->rfc_cong); - debug("BTA_JV_RFCOMM_CONG_EVT"); on_rfc_outgoing_congest(&p_data->rfc_cong, (uint32_t)user_data); break; default: - error("unhandled event %d, slot id:%d", event, (uint32_t)user_data); + APPL_TRACE_ERROR2("unhandled event %d, slot id:%d", event, (uint32_t)user_data); break; } return new_user_data; @@ -738,7 +724,7 @@ static void *rfcomm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) static void jv_dm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) { uint32_t id = (uint32_t)user_data; - debug("event:%d, slot id:%d", event, id); + APPL_TRACE_DEBUG2("event:%d, slot id:%d", event, id); switch(event) { case BTA_JV_CREATE_RECORD_EVT: @@ -748,9 +734,8 @@ static void jv_dm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) if(rs && create_server_sdp_record(rs)) { //now start the rfcomm server after sdp & channel # assigned - debug("BTA_JvCreateRecordByUser callback BTA_JV_CREATE_RECORD_EVT, slot id:%d, fd:%d, security:0x%x, scn:%d", - rs->id, rs->fd, rs->security, rs->scn); - BTA_JvRfcommStartServer(rs->security, rs->role, rs->scn, MAX_RFC_SESSION, rfcomm_cback, (void*)rs->id); + BTA_JvRfcommStartServer(rs->security, rs->role, rs->scn, MAX_RFC_SESSION, rfcomm_cback, + (void*)rs->id); } unlock_slot(&slot_lock); break; @@ -761,8 +746,8 @@ static void jv_dm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) lock_slot(&slot_lock); if(p_data->disc_comp.status == BTA_JV_SUCCESS && p_data->disc_comp.scn) { - error("BTA_JV_DISCOVERY_COMP_EVT, slot id:%d, found channle #, status:%d, scn:%d", id, p_data->disc_comp.status, - p_data->disc_comp.scn); + APPL_TRACE_DEBUG3("BTA_JV_DISCOVERY_COMP_EVT, slot id:%d, status:%d, scn:%d", + id, p_data->disc_comp.status, p_data->disc_comp.scn); rs = find_rfc_slot_by_id(id); if(rs && rs->f.doing_sdp_request) @@ -779,15 +764,16 @@ static void jv_dm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) } else if(rs) { - error("BTA_JV_DISCOVERY_COMP_EVT rfc can not find pending sdp request, slot id:%d, \ + APPL_TRACE_ERROR3("DISCOVERY_COMP_EVT no pending sdp request, slot id:%d, \ flag sdp pending:%d, flag sdp doing:%d", id, rs->f.pending_sdp_request, rs->f.doing_sdp_request); } } else { - error("BTA_JV_DISCOVERY_COMP_EVT slot id:%d, failed to find channle #, status:%d, scn:%d", id, p_data->disc_comp.status, - p_data->disc_comp.scn); + APPL_TRACE_ERROR3("DISCOVERY_COMP_EVT slot id:%d, failed to find channle, \ + status:%d, scn:%d", id, p_data->disc_comp.status, + p_data->disc_comp.scn); rs = find_rfc_slot_by_id(id); if(rs) cleanup_rfc_slot(rs); @@ -795,7 +781,7 @@ static void jv_dm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) rs = find_rfc_slot_by_pending_sdp(); if(rs) { - debug("BTA_JV_DISCOVERY_COMP_EVT, start another pending scn sdp request"); + APPL_TRACE_DEBUG0("BTA_JV_DISCOVERY_COMP_EVT, start another pending scn sdp request"); tSDP_UUID sdp_uuid; sdp_uuid.len = 16; memcpy(sdp_uuid.uu.uuid128, rs->service_uuid, sizeof(sdp_uuid.uu.uuid128)); @@ -807,7 +793,7 @@ static void jv_dm_cback(tBTA_JV_EVT event, tBTA_JV *p_data, void *user_data) break; } default: - debug("unhandled event:%d, slot id:%d", event, id); + APPL_TRACE_DEBUG2("unhandled event:%d, slot id:%d", event, id); break; } @@ -827,7 +813,7 @@ static int send_data_to_app(int fd, BT_HDR *p_buf) if(sent > 0 && sent < p_buf->len) { //sent partial - error("send partial, sent:%d, p_buf->len:%d", sent, p_buf->len); + APPL_TRACE_ERROR2("send partial, sent:%d, p_buf->len:%d", sent, p_buf->len); p_buf->offset += sent; p_buf->len -= sent; return SENT_PARTIAL; @@ -836,10 +822,10 @@ static int send_data_to_app(int fd, BT_HDR *p_buf) if(sent < 0 && (errno == EAGAIN || errno == EWOULDBLOCK || errno == EINTR)) { - error("send none, EAGAIN or EWOULDBLOCK, errno:%d", errno); + APPL_TRACE_ERROR1("send none, EAGAIN or EWOULDBLOCK, errno:%d", errno); return SENT_NONE; } - error("unknown send() error, sent:%d, p_buf->len:%d, errno:%d", sent, p_buf->len, errno); + APPL_TRACE_ERROR3("unknown send() error, sent:%d, p_buf->len:%d, errno:%d", sent, p_buf->len, errno); return SENT_FAILED; } static BOOLEAN flush_incoming_que_on_wr_signal(rfc_slot_t* rs) @@ -873,12 +859,11 @@ static BOOLEAN flush_incoming_que_on_wr_signal(rfc_slot_t* rs) } void btsock_rfc_signaled(int fd, int flags, uint32_t user_id) { - debug("fd:%d, flags:%x", fd, flags); lock_slot(&slot_lock); rfc_slot_t* rs = find_rfc_slot_by_id(user_id); if(rs) { - debug("rfc slot id:%d, fd:%d, flags:%x", rs->id, fd, flags); + APPL_TRACE_DEBUG3("rfc slot id:%d, fd:%d, flags:%x", rs->id, fd, flags); BOOLEAN need_close = FALSE; if(flags & SOCK_THREAD_FD_RD) { @@ -889,7 +874,8 @@ void btsock_rfc_signaled(int fd, int flags, uint32_t user_id) BTA_JvRfcommWrite(rs->rfc_handle, (UINT32)rs->id); else { - error("SOCK_THREAD_FD_RD signaled when rfc is not connected, slot id:%d, channel:%d", rs->id, rs->scn); + APPL_TRACE_ERROR2("SOCK_THREAD_FD_RD signaled when rfc is not connected, \ + slot id:%d, channel:%d", rs->id, rs->scn); need_close = TRUE; } } @@ -900,13 +886,14 @@ void btsock_rfc_signaled(int fd, int flags, uint32_t user_id) if(!rs->f.connected || !flush_incoming_que_on_wr_signal(rs)) { need_close = TRUE; - error("SOCK_THREAD_FD_WR signaled when rfc is not connected or app closed fd, slot id:%d, channel:%d", rs->id, rs->scn); + APPL_TRACE_ERROR2("SOCK_THREAD_FD_WR signaled when rfc is not connected \ + or app closed fd, slot id:%d, channel:%d", rs->id, rs->scn); } } if(need_close || (flags & SOCK_THREAD_FD_EXCEPTION)) { - debug("SOCK_THREAD_FD_EXCEPTION, flags:%x", flags); + APPL_TRACE_DEBUG1("SOCK_THREAD_FD_EXCEPTION, flags:%x", flags); rs->f.closing = TRUE; if(rs->f.server) BTA_JvRfcommStopServer(rs->rfc_handle); @@ -961,12 +948,12 @@ int bta_co_rfc_data_outgoing_size(void *user_data, int *size) { if(ioctl(rs->fd, FIONREAD, size) == 0) { - debug("ioctl read avaiable size:%d, fd:%d", *size, rs->fd); + APPL_TRACE_DEBUG2("ioctl read avaiable size:%d, fd:%d", *size, rs->fd); ret = TRUE; } else { - error("ioctl FIONREAD error, errno:%d, fd:%d", errno, rs->fd); + APPL_TRACE_ERROR2("ioctl FIONREAD error, errno:%d, fd:%d", errno, rs->fd); cleanup_rfc_slot(rs); } } @@ -986,7 +973,8 @@ int bta_co_rfc_data_outgoing(void *user_data, UINT8* buf, UINT16 size) ret = TRUE; else { - error("recv error, errno:%d, fd:%d, size:%d, received:%d", errno, rs->fd, size, received); + APPL_TRACE_ERROR4("recv error, errno:%d, fd:%d, size:%d, received:%d", + errno, rs->fd, size, received); cleanup_rfc_slot(rs); } } diff --git a/btif/src/btif_sock_sdp.c b/btif/src/btif_sock_sdp.c index 12adb6b..cf55e8a 100644 --- a/btif/src/btif_sock_sdp.c +++ b/btif/src/btif_sock_sdp.c @@ -52,13 +52,6 @@ #include "../bta/pb/bta_pbs_int.h" #include "../include/bta_op_api.h" #include -#define info(fmt, ...) ALOGI ("%s: " fmt,__FUNCTION__, ## __VA_ARGS__) -#define debug(fmt, ...) ALOGD ("%s: " fmt,__FUNCTION__, ## __VA_ARGS__) -#define error(fmt, ...) ALOGE ("## ERROR : %s: " fmt "##",__FUNCTION__, ## __VA_ARGS__) -#define asrt(s) if(!(s)) ALOGE ("## %s assert %s failed at line:%d ##",__FUNCTION__, #s, __LINE__) - - - #define RESERVED_SCN_PBS 19 #define RESERVED_SCN_OPS 12 @@ -149,11 +142,11 @@ static int add_pbap_sdp(const char* p_service_name, int scn) UINT32 sdp_handle = 0; tBTA_PBS_CFG *p_bta_pbs_cfg = (tBTA_PBS_CFG *)&bta_pbs_cfg; - info("scn %d, service name %s", scn, p_service_name); + APPL_TRACE_DEBUG2("scn %d, service name %s", scn, p_service_name); if ((sdp_handle = SDP_CreateRecord()) == 0) { - error("PBS SDP: Unable to register PBS Service"); + APPL_TRACE_ERROR0("PBS SDP: Unable to register PBS Service"); return sdp_handle; } @@ -255,7 +248,7 @@ static int add_ops_sdp(const char *p_service_name,int scn) UINT32 sdp_handle; tBTA_OP_FMT_MASK formats = BTUI_OPS_FORMATS; - info("scn %d, service name %s", scn, p_service_name); + APPL_TRACE_DEBUG2("scn %d, service name %s", scn, p_service_name); sdp_handle = SDP_CreateRecord(); @@ -318,7 +311,7 @@ static int add_spp_sdp(const char *service_name, int scn) tSDP_PROTOCOL_ELEM proto_elem_list[SPP_NUM_PROTO_ELEMS]; int sdp_handle; - info("scn %d, service name %s", scn, service_name); + APPL_TRACE_DEBUG2("scn %d, service name %s", scn, service_name); /* register the service */ if ((sdp_handle = SDP_CreateRecord()) != FALSE) @@ -357,7 +350,7 @@ static int add_rfc_sdp_by_uuid(const char* name, const uint8_t* uuid, int scn) { int handle = 0; - info("name:%s, scn:%d", name, scn); + APPL_TRACE_DEBUG2("name:%s, scn:%d", name, scn); /* Bluetooth Socket API relies on having preregistered bluez sdp records for HSAG, HFAG, OPP & PBAP diff --git a/btif/src/btif_sock_thread.c b/btif/src/btif_sock_thread.c index 599195f..475b8de 100644 --- a/btif/src/btif_sock_thread.c +++ b/btif/src/btif_sock_thread.c @@ -60,19 +60,16 @@ #include "btif_sock_util.h" #include -#define info(fmt, ...) ALOGI ("%s: " fmt,__FUNCTION__, ## __VA_ARGS__) -#define debug(fmt, ...) ALOGD ("%s: " fmt,__FUNCTION__, ## __VA_ARGS__) -#define error(fmt, ...) ALOGE ("## ERROR : %s: " fmt "##",__FUNCTION__, ## __VA_ARGS__) -#define asrt(s) if(!(s)) ALOGE ("## %s assert %s failed at line:%d ##",__FUNCTION__, #s, __LINE__) +#define asrt(s) if(!(s)) APPL_TRACE_ERROR3("## %s assert %s failed at line:%d ##",__FUNCTION__, #s, __LINE__) #define print_events(events) do { \ - debug("print poll event:%x", events); \ - if (events & POLLIN) debug( " POLLIN "); \ - if (events & POLLPRI) debug( " POLLPRI "); \ - if (events & POLLOUT) debug( " POLLOUT "); \ - if (events & POLLERR) debug( " POLLERR "); \ - if (events & POLLHUP) debug( " POLLHUP "); \ - if (events & POLLNVAL) debug(" POLLNVAL "); \ - if (events & POLLRDHUP) debug(" POLLRDHUP"); \ + APPL_TRACE_DEBUG1("print poll event:%x", events); \ + if (events & POLLIN) APPL_TRACE_DEBUG0( " POLLIN "); \ + if (events & POLLPRI) APPL_TRACE_DEBUG0( " POLLPRI "); \ + if (events & POLLOUT) APPL_TRACE_DEBUG0( " POLLOUT "); \ + if (events & POLLERR) APPL_TRACE_DEBUG0( " POLLERR "); \ + if (events & POLLHUP) APPL_TRACE_DEBUG0( " POLLHUP "); \ + if (events & POLLNVAL) APPL_TRACE_DEBUG0(" POLLNVAL "); \ + if (events & POLLRDHUP) APPL_TRACE_DEBUG0(" POLLRDHUP"); \ } while(0) #define MAX_THREAD 8 @@ -119,7 +116,7 @@ static inline void set_socket_blocking(int s, int blocking) { int opts; opts = fcntl(s, F_GETFL); - if (opts<0) error("set blocking (%s)", strerror(errno)); + if (opts<0) APPL_TRACE_ERROR1("set blocking (%s)", strerror(errno)); if(blocking) opts &= ~O_NONBLOCK; else opts |= O_NONBLOCK; @@ -129,17 +126,17 @@ static inline void set_socket_blocking(int s, int blocking) static inline int create_server_socket(const char* name) { int s = socket(AF_LOCAL, SOCK_STREAM, 0); - debug("covert name to android abstract name:%s", name); + APPL_TRACE_DEBUG1("covert name to android abstract name:%s", name); if(socket_local_server_bind(s, name, ANDROID_SOCKET_NAMESPACE_ABSTRACT) >= 0) { if(listen(s, 5) == 0) { - debug("listen to local socket:%s, fd:%d", name, s); + APPL_TRACE_DEBUG2("listen to local socket:%s, fd:%d", name, s); return s; } - else error("listen to local socket:%s, fd:%d failed, errno:%d", name, s, errno); + else APPL_TRACE_ERROR3("listen to local socket:%s, fd:%d failed, errno:%d", name, s, errno); } - else error("create local socket:%s fd:%d, failed, errno:%d", name, s, errno); + else APPL_TRACE_ERROR3("create local socket:%s fd:%d, failed, errno:%d", name, s, errno); close(s); return -1; } @@ -149,10 +146,10 @@ static inline int connect_server_socket(const char* name) set_socket_blocking(s, TRUE); if(socket_local_client_connect(s, name, ANDROID_SOCKET_NAMESPACE_ABSTRACT, SOCK_STREAM) >= 0) { - debug("connected to local socket:%s, fd:%d", name, s); + APPL_TRACE_DEBUG2("connected to local socket:%s, fd:%d", name, s); return s; } - else error("connect to local socket:%s, fd:%d failed, errno:%d", name, s, errno); + else APPL_TRACE_ERROR3("connect to local socket:%s, fd:%d failed, errno:%d", name, s, errno); close(s); return -1; } @@ -161,7 +158,7 @@ static inline int accept_server_socket(int s) struct sockaddr_un client_address; socklen_t clen; int fd = accept(s, (struct sockaddr*)&client_address, &clen); - debug("accepted fd:%d for server fd:%d", fd, s); + APPL_TRACE_DEBUG2("accepted fd:%d for server fd:%d", fd, s); return fd; } static inline pthread_t create_thread(void *(*start_routine)(void *), void * arg) @@ -172,7 +169,7 @@ static inline pthread_t create_thread(void *(*start_routine)(void *), void * arg pthread_t thread_id = -1; if( pthread_create(&thread_id, &thread_attr, start_routine, arg)!=0 ) { - error("pthread_create : %s", strerror(errno)); + APPL_TRACE_ERROR1("pthread_create : %s", strerror(errno)); return -1; } return thread_id; @@ -184,14 +181,14 @@ static int alloc_thread_slot() //revserd order to save guard uninitialized access to 0 index for(i = MAX_THREAD - 1; i >=0; i--) { - debug("ts[%d].used:%d", i, ts[i].used); + APPL_TRACE_DEBUG2("ts[%d].used:%d", i, ts[i].used); if(!ts[i].used) { ts[i].used = 1; return i; } } - error("execeeded max thread count"); + APPL_TRACE_ERROR0("execeeded max thread count"); return -1; } static void free_thread_slot(int h) @@ -201,12 +198,12 @@ static void free_thread_slot(int h) close_cmd_fd(h); ts[h].used = 0; } - else error("invalid thread handle:%d", h); + else APPL_TRACE_ERROR1("invalid thread handle:%d", h); } int btsock_thread_init() { static int initialized; - debug("in initialized:%d", initialized); + APPL_TRACE_DEBUG1("in initialized:%d", initialized); if(!initialized) { initialized = 1; @@ -231,13 +228,13 @@ int btsock_thread_create(btsock_signaled_cb callback, btsock_cmd_cb cmd_callback lock_slot(&thread_slot_lock); int h = alloc_thread_slot(); unlock_slot(&thread_slot_lock); - debug("alloc_thread_slot ret:%d", h); + APPL_TRACE_DEBUG1("alloc_thread_slot ret:%d", h); if(h >= 0) { init_poll(h); if((ts[h].thread_id = create_thread(sock_poll_thread, (void*)h)) != -1) { - debug("h:%d, thread id:%d", h, ts[h].thread_id); + APPL_TRACE_DEBUG2("h:%d, thread id:%d", h, ts[h].thread_id); ts[h].callback = callback; ts[h].cmd_callback = cmd_callback; } @@ -256,10 +253,10 @@ static inline void init_cmd_fd(int h) asrt(ts[h].cmd_fdr == -1 && ts[h].cmd_fdw == -1); if(socketpair(AF_UNIX, SOCK_STREAM, 0, &ts[h].cmd_fdr) < 0) { - error("socketpair failed: %s", strerror(errno)); + APPL_TRACE_ERROR1("socketpair failed: %s", strerror(errno)); return; } - debug("h:%d, cmd_fdr:%d, cmd_fdw:%d", h, ts[h].cmd_fdr, ts[h].cmd_fdw); + APPL_TRACE_DEBUG3("h:%d, cmd_fdr:%d, cmd_fdw:%d", h, ts[h].cmd_fdr, ts[h].cmd_fdw); //add the cmd fd for read & write add_poll(h, ts[h].cmd_fdr, 0, SOCK_THREAD_FD_RD, 0); } @@ -288,12 +285,12 @@ int btsock_thread_add_fd(int h, int fd, int type, int flags, uint32_t user_id) { if(h < 0 || h >= MAX_THREAD) { - error("invalid bt thread handle:%d", h); + APPL_TRACE_ERROR1("invalid bt thread handle:%d", h); return FALSE; } if(ts[h].cmd_fdw == -1) { - error("cmd socket is not created. socket thread may not initialized"); + APPL_TRACE_ERROR0("cmd socket is not created. socket thread may not initialized"); return FALSE; } if(flags & SOCK_THREAD_ADD_FD_SYNC) @@ -306,26 +303,26 @@ int btsock_thread_add_fd(int h, int fd, int type, int flags, uint32_t user_id) add_poll(h, fd, type, flags, user_id); return TRUE; } - debug("SOCK_THREAD_ADD_FD_SYNC is not called in poll thread context, fallback to async"); + APPL_TRACE_DEBUG0("THREAD_ADD_FD_SYNC is not called in poll thread, fallback to async"); } sock_cmd_t cmd = {CMD_ADD_FD, fd, type, flags, user_id}; - debug("adding fd:%d, flags:0x%x", fd, flags); + APPL_TRACE_DEBUG2("adding fd:%d, flags:0x%x", fd, flags); return send(ts[h].cmd_fdw, &cmd, sizeof(cmd), 0) == sizeof(cmd); } int btsock_thread_post_cmd(int h, int type, const unsigned char* data, int size, uint32_t user_id) { if(h < 0 || h >= MAX_THREAD) { - error("invalid bt thread handle:%d", h); + APPL_TRACE_ERROR1("invalid bt thread handle:%d", h); return FALSE; } if(ts[h].cmd_fdw == -1) { - error("cmd socket is not created. socket thread may not initialized"); + APPL_TRACE_ERROR0("cmd socket is not created. socket thread may not initialized"); return FALSE; } sock_cmd_t cmd = {CMD_USER_PRIVATE, 0, type, size, user_id}; - debug("post cmd type:%d, size:%d, h:%d, ", type, size, h); + APPL_TRACE_DEBUG3("post cmd type:%d, size:%d, h:%d, ", type, size, h); sock_cmd_t* cmd_send = &cmd; int size_send = sizeof(cmd); if(data && size) @@ -339,7 +336,7 @@ int btsock_thread_post_cmd(int h, int type, const unsigned char* data, int size, } else { - error("alloca failed at h:%d, cmd type:%d, size:%d", h, type, size_send); + APPL_TRACE_ERROR3("alloca failed at h:%d, cmd type:%d, size:%d", h, type, size_send); return FALSE; } } @@ -349,12 +346,12 @@ int btsock_thread_wakeup(int h) { if(h < 0 || h >= MAX_THREAD) { - error("invalid bt thread handle:%d", h); + APPL_TRACE_ERROR1("invalid bt thread handle:%d", h); return FALSE; } if(ts[h].cmd_fdw == -1) { - error("thread handle:%d, cmd socket is not created", h); + APPL_TRACE_ERROR1("thread handle:%d, cmd socket is not created", h); return FALSE; } sock_cmd_t cmd = {CMD_WAKEUP, 0, 0, 0, 0}; @@ -364,12 +361,12 @@ int btsock_thread_exit(int h) { if(h < 0 || h >= MAX_THREAD) { - error("invalid bt thread handle:%d", h); + APPL_TRACE_ERROR1("invalid bt thread handle:%d", h); return FALSE; } if(ts[h].cmd_fdw == -1) { - error("cmd socket is not created"); + APPL_TRACE_ERROR0("cmd socket is not created"); return FALSE; } sock_cmd_t cmd = {CMD_EXIT, 0, 0, 0, 0}; @@ -413,7 +410,7 @@ static inline void set_poll(poll_slot_t* ps, int fd, int type, int flags, uint32 ps->pfd.fd = fd; ps->user_id = user_id; if(ps->type != 0 && ps->type != type) - error("poll socket type should not changed! type was:%d, type now:%d", ps->type, type); + APPL_TRACE_ERROR2("poll socket type should not changed! type was:%d, type now:%d", ps->type, type); ps->type = type; ps->flags = flags; ps->pfd.events = flags2pevents(flags); @@ -430,9 +427,6 @@ static inline void add_poll(int h, int fd, int type, int flags, uint32_t user_id { if(ps[i].pfd.fd == fd) { - debug("update fd poll, count:%d, slot:%d, fd:%d, \ - type was:%d, now:%d; flags was:%x, now:%x; user_id was:%d, now:%d", - ts[h].poll_count, i, fd, ps[i].type, type, ps[i].flags, flags, ps[i].user_id, user_id); asrt(ts[h].poll_count < MAX_POLL); set_poll(&ps[i], fd, type, flags | ps[i].flags, user_id); @@ -446,11 +440,9 @@ static inline void add_poll(int h, int fd, int type, int flags, uint32_t user_id asrt(ts[h].poll_count < MAX_POLL); set_poll(&ps[empty], fd, type, flags, user_id); ++ts[h].poll_count; - debug("add new fd poll, count:%d, slot:%d, fd:%d, type:%d; flags:%x; user_id:%d", - ts[h].poll_count, empty, fd, type, flags, user_id); return; } - error("exceeded max poll slot:%d!", MAX_POLL); + APPL_TRACE_ERROR1("exceeded max poll slot:%d!", MAX_POLL); } static inline void remove_poll(int h, poll_slot_t* ps, int flags) { @@ -458,15 +450,12 @@ static inline void remove_poll(int h, poll_slot_t* ps, int flags) { //all monitored events signaled. To remove it, just clear the slot --ts[h].poll_count; - debug("remove poll, count:%d, fd:%d, flags:%x", ts[h].poll_count, ps->pfd.fd, ps->flags); memset(ps, 0, sizeof(*ps)); ps->pfd.fd = -1; } else { //one read or one write monitor event signaled, removed the accordding bit - debug("remove poll flag, count:%d, fd:%d, flags signaled:%x, poll flags was:%x, new:%x", - ts[h].poll_count, ps->pfd.fd, flags, ps->flags, ps->flags & (~flags)); ps->flags &= ~flags; //update the poll events mask ps->pfd.events = flags2pevents(ps->flags); @@ -478,37 +467,32 @@ static int process_cmd_sock(int h) int fd = ts[h].cmd_fdr; if(recv(fd, &cmd, sizeof(cmd), MSG_WAITALL) != sizeof(cmd)) { - error("recv cmd errno:%d", errno); + APPL_TRACE_ERROR1("recv cmd errno:%d", errno); return FALSE; } - debug("cmd.id:%d", cmd.id); + APPL_TRACE_DEBUG1("cmd.id:%d", cmd.id); switch(cmd.id) { case CMD_ADD_FD: - debug("CMD_ADD_FD, fd:%d, flags:%d", cmd.fd, cmd.flags); add_poll(h, cmd.fd, cmd.type, cmd.flags, cmd.user_id); break; case CMD_WAKEUP: - debug("CMD_WAKEUP"); break; case CMD_USER_PRIVATE: - debug("CMD_USER_PRIVATE"); asrt(ts[h].cmd_callback); if(ts[h].cmd_callback) ts[h].cmd_callback(fd, cmd.type, cmd.flags, cmd.user_id); break; case CMD_EXIT: - debug("CMD_EXIT"); return FALSE; default: - debug("unknown cmd: %d", cmd.id); + APPL_TRACE_DEBUG1("unknown cmd: %d", cmd.id); break; } return TRUE; } static void process_data_sock(int h, struct pollfd *pfds, int count) { - debug("in, poll count:%d ts[h].poll_count:%d", count, ts[h].poll_count); asrt(count <= ts[h].poll_count); int i; for( i= 1; i < ts[h].poll_count; i++) @@ -520,22 +504,17 @@ static void process_data_sock(int h, struct pollfd *pfds, int count) uint32_t user_id = ts[h].ps[ps_i].user_id; int type = ts[h].ps[ps_i].type; int flags = 0; - debug("signaled data fd:%d, start print poll revents[", pfds[i].fd); print_events(pfds[i].revents); - debug("signaled data fd:%d, end print poll revents]", pfds[i].fd); if(IS_READ(pfds[i].revents)) { - debug("read event signaled, fd:%d, user_id:%d", pfds[i].fd, user_id); flags |= SOCK_THREAD_FD_RD; } if(IS_WRITE(pfds[i].revents)) { - debug("write event signaled, fd:%d, user_id:%d", pfds[i].fd, user_id); flags |= SOCK_THREAD_FD_WR; } if(IS_EXCEPTION(pfds[i].revents)) { - debug("exception event signaled, fd:%d, user_id:%d", pfds[i].fd, user_id); flags |= SOCK_THREAD_FD_EXCEPTION; //remove the whole slot not flags remove_poll(h, &ts[h].ps[ps_i], ts[h].ps[ps_i].flags); @@ -546,8 +525,8 @@ static void process_data_sock(int h, struct pollfd *pfds, int count) ts[h].callback(pfds[i].fd, type, flags, user_id); } } - debug("out"); } + static void prepare_poll_fds(int h, struct pollfd* pfds) { int count = 0; @@ -559,7 +538,7 @@ static void prepare_poll_fds(int h, struct pollfd* pfds) { if(ps_i >= MAX_POLL) { - error("exceed max poll range, ps_i:%d, MAX_POLL:%d, count:%d, ts[h].poll_count:%d", + APPL_TRACE_ERROR4("exceed max poll range, ps_i:%d, MAX_POLL:%d, count:%d, ts[h].poll_count:%d", ps_i, MAX_POLL, count, ts[h].poll_count); return; } @@ -581,28 +560,21 @@ static void *sock_poll_thread(void *arg) for(;;) { prepare_poll_fds(h, pfds); - debug("call poll, thread handle h:%d, cmd fd read:%d, ts[h].poll_count:%d", - h, ts[h].cmd_fdr, ts[h].poll_count); int ret = poll(pfds, ts[h].poll_count, -1); if(ret == -1) { - error("poll ret -1, exit the thread, errno:%d, err:%s", errno, strerror(errno)); - debug("ts[%d].poll_count:%d", h, ts[h].poll_count); + APPL_TRACE_ERROR2("poll ret -1, exit the thread, errno:%d, err:%s", errno, strerror(errno)); break; } if(ret != 0) { - debug("select wake up, h:%d, ret:%d, ts[h].poll_count:%d", h, ret, ts[h].poll_count); int need_process_data_fd = TRUE; if(pfds[0].revents) //cmd fd always is the first one { - debug("signaled cmd_fd:%d, start print poll revents[", pfds[0].fd); - print_events(pfds[0].revents); - debug("signaled cmd_fd:%d, end print poll revents]", pfds[0].fd); asrt(pfds[0].fd == ts[h].cmd_fdr); if(!process_cmd_sock(h)) { - debug("h:%d, process_cmd_sock return false, exit...", h); + APPL_TRACE_DEBUG1("h:%d, process_cmd_sock return false, exit...", h); break; } if(ret == 1) @@ -612,10 +584,10 @@ static void *sock_poll_thread(void *arg) if(need_process_data_fd) process_data_sock(h, pfds, ret); } - else debug("no data, select ret: %d", ret); + else {APPL_TRACE_DEBUG1("no data, select ret: %d", ret)}; } ts[h].thread_id = -1; - debug("socket poll thread exiting, h:%d", h); + APPL_TRACE_DEBUG1("socket poll thread exiting, h:%d", h); return 0; } -- cgit v1.1