Merge "Turn off socket debug messages" into jb-mr1-dev

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 <hardware/bluetooth.h>
 #include <hardware/bt_sock.h>
@@ -56,12 +54,7 @@
 
 #include <cutils/log.h>
 #include <hardware/bluetooth.h>
-#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 <cutils/log.h>
-#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 <cutils/log.h>
-#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;
 }