Modified the libraries to use the new log indentation feature re #1372

git-svn-id: http://svn.pjsip.org/repos/pjproject/trunk@3753 74dad513-b988-da41-8d7b-12977e46ad98

1 files changed, 85 insertions, 6 deletions

diff --git a/pjsip/src/pjsua-lib/pjsua_pres.c b/pjsip/src/pjsua-lib/pjsua_pres.c
index 2428a2f5..88ea317f 100644
--- a/pjsip/src/pjsua-lib/pjsua_pres.c
+++ b/pjsip/src/pjsua-lib/pjsua_pres.c
@@ -389,6 +389,10 @@ PJ_DEF(pj_status_t) pjsua_buddy_add( const pjsua_buddy_config *cfg,
 			PJ_ARRAY_SIZE(pjsua_var.buddy),
 		     PJ_ETOOMANY);
 
+    PJ_LOG(4,(THIS_FILE, "Adding buddy: %.*s",
+	      (int)cfg->uri.slen, cfg->uri.ptr));
+    pj_log_push_indent();
+
     PJSUA_LOCK();
 
     /* Find empty slot */
@@ -402,6 +406,7 @@ PJ_DEF(pj_status_t) pjsua_buddy_add( const pjsua_buddy_config *cfg,
 	PJSUA_UNLOCK();
 	/* This shouldn't happen */
 	pj_assert(!"index < PJ_ARRAY_SIZE(pjsua_var.buddy)");
+	pj_log_pop_indent();
 	return PJ_ETOOMANY;
     }
 
@@ -431,6 +436,7 @@ PJ_DEF(pj_status_t) pjsua_buddy_add( const pjsua_buddy_config *cfg,
 	pj_pool_release(buddy->pool);
 	buddy->pool = NULL;
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return PJSIP_EINVALIDURI;
     }
 
@@ -439,6 +445,7 @@ PJ_DEF(pj_status_t) pjsua_buddy_add( const pjsua_buddy_config *cfg,
 	pj_pool_release(buddy->pool);
 	buddy->pool = NULL;
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return PJSIP_EINVALIDSCHEME;
     }
 
@@ -469,8 +476,11 @@ PJ_DEF(pj_status_t) pjsua_buddy_add( const pjsua_buddy_config *cfg,
 
     PJSUA_UNLOCK();
 
+    PJ_LOG(4,(THIS_FILE, "Buddy %d added.", index));
+
     pjsua_buddy_subscribe_pres(index, cfg->subscribe);
 
+    pj_log_pop_indent();
     return PJ_SUCCESS;
 }
 
@@ -495,6 +505,9 @@ PJ_DEF(pj_status_t) pjsua_buddy_del(pjsua_buddy_id buddy_id)
     if (status != PJ_SUCCESS)
 	return status;
 
+    PJ_LOG(4,(THIS_FILE, "Buddy %d: deleting..", buddy_id));
+    pj_log_push_indent();
+
     /* Unsubscribe presence */
     pjsua_buddy_subscribe_pres(buddy_id, PJ_FALSE);
 
@@ -518,6 +531,7 @@ PJ_DEF(pj_status_t) pjsua_buddy_del(pjsua_buddy_id buddy_id)
     reset_buddy(buddy_id);
 
     unlock_buddy(&lck);
+    pj_log_pop_indent();
     return PJ_SUCCESS;
 }
 
@@ -537,11 +551,15 @@ PJ_DEF(pj_status_t) pjsua_buddy_subscribe_pres( pjsua_buddy_id buddy_id,
     if (status != PJ_SUCCESS)
 	return status;
 
+    PJ_LOG(4,(THIS_FILE, "Buddy %d: unsubscribing presence..", buddy_id));
+    pj_log_push_indent();
+
     lck.buddy->monitor = subscribe;
 
     pjsua_buddy_update_pres(buddy_id);
 
     unlock_buddy(&lck);
+    pj_log_pop_indent();
     return PJ_SUCCESS;
 }
 
@@ -560,16 +578,21 @@ PJ_DEF(pj_status_t) pjsua_buddy_update_pres(pjsua_buddy_id buddy_id)
     if (status != PJ_SUCCESS)
 	return status;
 
+    PJ_LOG(4,(THIS_FILE, "Buddy %d: updating presence..", buddy_id));
+    pj_log_push_indent();
+
     /* Is this an unsubscribe request? */
     if (!lck.buddy->monitor) {
 	unsubscribe_buddy_presence(buddy_id);
 	unlock_buddy(&lck);
+	pj_log_pop_indent();
 	return PJ_SUCCESS;
     }
 
     /* Ignore if presence is already active for the buddy */
     if (lck.buddy->sub) {
 	unlock_buddy(&lck);
+	pj_log_pop_indent();
 	return PJ_SUCCESS;
     }
 
@@ -577,7 +600,7 @@ PJ_DEF(pj_status_t) pjsua_buddy_update_pres(pjsua_buddy_id buddy_id)
     subscribe_buddy_presence(buddy_id);
 
     unlock_buddy(&lck);
-
+    pj_log_pop_indent();
     return PJ_SUCCESS;
 }
 
@@ -745,6 +768,7 @@ static void pres_evsub_on_srv_state( pjsip_evsub *sub, pjsip_event *event)
 
 	PJ_LOG(4,(THIS_FILE, "Server subscription to %s is %s",
 		  uapres->remote, pjsip_evsub_get_state_name(sub)));
+	pj_log_push_indent();
 
 	state = pjsip_evsub_get_state(sub);
 
@@ -761,6 +785,7 @@ static void pres_evsub_on_srv_state( pjsip_evsub *sub, pjsip_event *event)
 	    pjsip_evsub_set_mod_data(sub, pjsua_var.mod.id, NULL);
 	    pj_list_erase(uapres);
 	}
+	pj_log_pop_indent();
     }
 
     PJSUA_UNLOCK();
@@ -806,6 +831,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 
     PJ_LOG(4,(THIS_FILE, "Creating server subscription, using account %d",
 	      acc_id));
+    pj_log_push_indent();
     
     /* Create suitable Contact header */
     if (acc->contact.slen) {
@@ -819,6 +845,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 	    PJSUA_UNLOCK();
 	    pjsip_endpt_respond_stateless(pjsua_var.endpt, rdata, 400, NULL,
 					  NULL, NULL);
+	    pj_log_pop_indent();
 	    return PJ_TRUE;
 	}
     }
@@ -833,6 +860,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 	PJSUA_UNLOCK();
 	pjsip_endpt_respond_stateless(pjsua_var.endpt, rdata, 400, NULL,
 				      NULL, NULL);
+	pj_log_pop_indent();
 	return PJ_TRUE;
     }
 
@@ -864,6 +892,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 	}
 
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return PJ_TRUE;
     }
 
@@ -934,6 +963,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 	    pj_list_erase(uapres);
 	    pjsip_pres_terminate(sub, PJ_FALSE);
 	    PJSUA_UNLOCK();
+	    pj_log_pop_indent();
 	    return PJ_FALSE;
 	}
 
@@ -952,6 +982,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 	pj_list_erase(uapres);
 	pjsip_pres_terminate(sub, PJ_FALSE);
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return PJ_TRUE;
     }
 
@@ -963,6 +994,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
 	pj_list_erase(uapres);
 	pjsip_pres_terminate(sub, PJ_FALSE);
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return PJ_FALSE;
     }
 
@@ -975,7 +1007,7 @@ static pj_bool_t pres_on_rx_request(pjsip_rx_data *rdata)
     /* Done: */
 
     PJSUA_UNLOCK();
-
+    pj_log_pop_indent();
     return PJ_TRUE;
 }
 
@@ -1006,6 +1038,10 @@ PJ_DEF(pj_status_t) pjsua_pres_notify( pjsua_acc_id acc_id,
     /* Check that account is valid */
     PJ_ASSERT_RETURN(pjsua_var.acc[acc_id].valid, PJ_EINVALIDOP);
 
+    PJ_LOG(4,(THIS_FILE, "Acc %d: sending NOTIFY for srv_pres=0x%p..",
+	      acc_id, (int)(long)srv_pres));
+    pj_log_push_indent();
+
     PJSUA_LOCK();
 
     acc = &pjsua_var.acc[acc_id];
@@ -1014,6 +1050,7 @@ PJ_DEF(pj_status_t) pjsua_pres_notify( pjsua_acc_id acc_id,
     if (pj_list_find_node(&acc->pres_srv_list, srv_pres) == NULL) {
 	/* Subscription has been terminated */
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return PJ_EINVALIDOP;
     }
 
@@ -1055,6 +1092,7 @@ PJ_DEF(pj_status_t) pjsua_pres_notify( pjsua_acc_id acc_id,
 	pj_list_erase(srv_pres);
 	pjsip_pres_terminate(srv_pres->sub, PJ_FALSE);
 	PJSUA_UNLOCK();
+	pj_log_pop_indent();
 	return status;
     }
 
@@ -1071,7 +1109,7 @@ PJ_DEF(pj_status_t) pjsua_pres_notify( pjsua_acc_id acc_id,
     }
 
     PJSUA_UNLOCK();
-
+    pj_log_pop_indent();
     return PJ_SUCCESS;
 }
 
@@ -1131,6 +1169,9 @@ static pj_status_t send_publish(int acc_id, pj_bool_t active)
     pjsip_tx_data *tdata;
     pj_status_t status;
 
+    PJ_LOG(5,(THIS_FILE, "Acc %d: sending %sPUBLISH..",
+	      acc_id, (active ? "" : "un-")));
+    pj_log_push_indent();
 
     /* Create PUBLISH request */
     if (active) {
@@ -1199,6 +1240,7 @@ static pj_status_t send_publish(int acc_id, pj_bool_t active)
     }
 
     acc->publish_state = acc->online_status;
+    pj_log_pop_indent();
     return PJ_SUCCESS;
 
 on_error:
@@ -1206,6 +1248,7 @@ on_error:
 	pjsip_publishc_destroy(acc->publish_sess);
 	acc->publish_sess = NULL;
     }
+    pj_log_pop_indent();
     return status;
 }
 
@@ -1454,6 +1497,7 @@ static void pjsua_evsub_on_state( pjsip_evsub *sub, pjsip_event *event)
 		  (int)pjsua_var.buddy[buddy->index].uri.slen,
 		  pjsua_var.buddy[buddy->index].uri.ptr, 
 		  pjsip_evsub_get_state_name(sub)));
+	pj_log_push_indent();
 
 	if (pjsip_evsub_get_state(sub) == PJSIP_EVSUB_STATE_TERMINATED) {
 	    int resub_delay = -1;
@@ -1573,6 +1617,8 @@ static void pjsua_evsub_on_state( pjsip_evsub *sub, pjsip_event *event)
 	    buddy->dlg = NULL;
 	    pjsip_evsub_set_mod_data(sub, pjsua_var.mod.id, NULL);
 	}
+
+	pj_log_pop_indent();
     }
 }
 
@@ -1684,8 +1730,9 @@ static void subscribe_buddy_presence(pjsua_buddy_id buddy_id)
 
     acc = &pjsua_var.acc[acc_id];
 
-    PJ_LOG(4,(THIS_FILE, "Using account %d for buddy %d subscription",
-			 acc_id, buddy_id));
+    PJ_LOG(4,(THIS_FILE, "Buddy %d: subscribing presence,using account %d..",
+	      buddy_id, acc_id));
+    pj_log_push_indent();
 
     /* Generate suitable Contact header unless one is already set in
      * the account
@@ -1701,6 +1748,7 @@ static void subscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	    pjsua_perror(THIS_FILE, "Unable to generate Contact header", 
 		         status);
 	    pj_pool_release(tmp_pool);
+	    pj_log_pop_indent();
 	    return;
 	}
     }
@@ -1715,6 +1763,7 @@ static void subscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	pjsua_perror(THIS_FILE, "Unable to create dialog", 
 		     status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
@@ -1734,6 +1783,7 @@ static void subscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	 */
 	if (buddy->dlg) pjsip_dlg_dec_lock(buddy->dlg);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
@@ -1773,6 +1823,7 @@ static void subscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	pjsua_perror(THIS_FILE, "Unable to create initial SUBSCRIBE", 
 		     status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
@@ -1788,11 +1839,13 @@ static void subscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	pjsua_perror(THIS_FILE, "Unable to send initial SUBSCRIBE", 
 		     status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
     pjsip_dlg_dec_lock(buddy->dlg);
     if (tmp_pool) pj_pool_release(tmp_pool);
+    pj_log_pop_indent();
 }
 
 
@@ -1813,6 +1866,9 @@ static void unsubscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	return;
     }
 
+    PJ_LOG(5,(THIS_FILE, "Buddy %d: unsubscribing..", buddy_id));
+    pj_log_push_indent();
+
     status = pjsip_pres_initiate( buddy->sub, 0, &tdata);
     if (status == PJ_SUCCESS) {
 	pjsua_process_msg_data(tdata, NULL);
@@ -1825,6 +1881,8 @@ static void unsubscribe_buddy_presence(pjsua_buddy_id buddy_id)
 	pjsua_perror(THIS_FILE, "Unable to unsubscribe presence", 
 		     status);
     }
+
+    pj_log_pop_indent();
 }
 
 /* It does what it says.. */
@@ -1914,10 +1972,15 @@ static void mwi_evsub_on_rx_notify(pjsip_evsub *sub,
     mwi_info.evsub = sub;
     mwi_info.rdata = rdata;
 
+    PJ_LOG(4,(THIS_FILE, "MWI got NOTIFY.."));
+    pj_log_push_indent();
+
     /* Call callback */
     if (pjsua_var.ua_cfg.cb.on_mwi_info) {
 	(*pjsua_var.ua_cfg.cb.on_mwi_info)(acc->index, &mwi_info);
     }
+
+    pj_log_pop_indent();
 }
 
 
@@ -1973,6 +2036,9 @@ void pjsua_start_mwi(pjsua_acc *acc)
 
     }
 
+    PJ_LOG(4,(THIS_FILE, "Starting MWI subscription.."));
+    pj_log_push_indent();
+
     /* Generate suitable Contact header unless one is already set in 
      * the account
      */
@@ -1986,6 +2052,7 @@ void pjsua_start_mwi(pjsua_acc *acc)
 	    pjsua_perror(THIS_FILE, "Unable to generate Contact header", 
 		         status);
 	    pj_pool_release(tmp_pool);
+	    pj_log_pop_indent();
 	    return;
 	}
     }
@@ -1999,6 +2066,7 @@ void pjsua_start_mwi(pjsua_acc *acc)
     if (status != PJ_SUCCESS) {
 	pjsua_perror(THIS_FILE, "Unable to create dialog", status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
@@ -2014,6 +2082,7 @@ void pjsua_start_mwi(pjsua_acc *acc)
 	pjsua_perror(THIS_FILE, "Error creating MWI subscription", status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
 	if (acc->mwi_dlg) pjsip_dlg_dec_lock(acc->mwi_dlg);
+	pj_log_pop_indent();
 	return;
     }
 
@@ -2054,6 +2123,7 @@ void pjsua_start_mwi(pjsua_acc *acc)
 	pjsua_perror(THIS_FILE, "Unable to create initial MWI SUBSCRIBE", 
 		     status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
@@ -2070,12 +2140,14 @@ void pjsua_start_mwi(pjsua_acc *acc)
 	pjsua_perror(THIS_FILE, "Unable to send initial MWI SUBSCRIBE", 
 		     status);
 	if (tmp_pool) pj_pool_release(tmp_pool);
+	pj_log_pop_indent();
 	return;
     }
 
     pjsip_dlg_dec_lock(acc->mwi_dlg);
     if (tmp_pool) pj_pool_release(tmp_pool);
 
+    pj_log_pop_indent();
 }
 
 
@@ -2105,6 +2177,10 @@ static pj_bool_t unsolicited_mwi_on_rx_request(pjsip_rx_data *rdata)
 	return PJ_FALSE;
     }
 
+    PJ_LOG(4,(THIS_FILE, "Got unsolicited NOTIFY from %s:%d..",
+	      rdata->pkt_info.src_name, rdata->pkt_info.src_port));
+    pj_log_push_indent();
+
     /* Got unsolicited MWI request, respond with 200/OK first */
     pjsip_endpt_respond(pjsua_get_pjsip_endpt(), NULL, rdata, 200, NULL,
 			NULL, NULL, NULL);
@@ -2123,7 +2199,7 @@ static pj_bool_t unsolicited_mwi_on_rx_request(pjsip_rx_data *rdata)
 	(*pjsua_var.ua_cfg.cb.on_mwi_info)(acc_id, &mwi_info);
     }
 
-    
+    pj_log_pop_indent();
     return PJ_TRUE;
 }
 
@@ -2253,6 +2329,7 @@ void pjsua_pres_shutdown(void)
     unsigned i;
 
     PJ_LOG(4,(THIS_FILE, "Shutting down presence.."));
+    pj_log_push_indent();
 
     if (pjsua_var.pres_timer.id != 0) {
 	pjsip_endpt_cancel_timer(pjsua_var.endpt, &pjsua_var.pres_timer);
@@ -2275,4 +2352,6 @@ void pjsua_pres_shutdown(void)
 	if (pjsua_var.acc[i].valid)
 	    pjsua_pres_update_acc(i, PJ_FALSE);
     }
+
+    pj_log_pop_indent();
 }