From b451470330fc334519bc30a240737bdc22ba9c21 Mon Sep 17 00:00:00 2001 From: Benny Prijono Date: Sun, 18 Sep 2011 14:59:56 +0000 Subject: 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 --- pjsip/src/pjsua-lib/pjsua_acc.c | 49 ++++- pjsip/src/pjsua-lib/pjsua_call.c | 435 +++++++++++++++++++++----------------- pjsip/src/pjsua-lib/pjsua_core.c | 43 ++-- pjsip/src/pjsua-lib/pjsua_media.c | 286 ++++++++++++++++++------- pjsip/src/pjsua-lib/pjsua_pres.c | 91 +++++++- pjsip/src/pjsua-lib/pjsua_vid.c | 157 +++++++++++--- 6 files changed, 737 insertions(+), 324 deletions(-) (limited to 'pjsip/src/pjsua-lib') diff --git a/pjsip/src/pjsua-lib/pjsua_acc.c b/pjsip/src/pjsua-lib/pjsua_acc.c index 57f4093a..9bcd1ddd 100644 --- a/pjsip/src/pjsua-lib/pjsua_acc.c +++ b/pjsip/src/pjsua-lib/pjsua_acc.c @@ -374,8 +374,9 @@ PJ_DEF(pj_status_t) pjsua_acc_add( const pjsua_acc_config *cfg, { pjsua_acc *acc; unsigned i, id; - pj_status_t status; + pj_status_t status = PJ_SUCCESS; + PJ_ASSERT_RETURN(cfg, PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.acc_cnt < PJ_ARRAY_SIZE(pjsua_var.acc), PJ_ETOOMANY); @@ -384,11 +385,16 @@ PJ_DEF(pj_status_t) pjsua_acc_add( const pjsua_acc_config *cfg, /* Verify media count */ #if !defined(PJMEDIA_HAS_VIDEO) || (PJMEDIA_HAS_VIDEO == 0) + /* Enable PJMEDIA_HAS_VIDEO in your config_site.h! */ PJ_ASSERT_RETURN(cfg->max_video_cnt == 0, PJ_EINVAL); #endif PJ_ASSERT_RETURN(cfg->max_audio_cnt + cfg->max_video_cnt <= PJSUA_MAX_CALL_MEDIA, PJ_ETOOMANY); + PJ_LOG(4,(THIS_FILE, "Adding account: id=%.*s", + (int)cfg->id.slen, cfg->id.ptr)); + pj_log_push_indent(); + PJSUA_LOCK(); /* Find empty account id. */ @@ -433,8 +439,11 @@ PJ_DEF(pj_status_t) pjsua_acc_add( const pjsua_acc_config *cfg, /* Check the route URI's and force loose route if required */ for (i=0; icfg.proxy_cnt; ++i) { status = normalize_route_uri(acc->pool, &acc->cfg.proxy[i]); - if (status != PJ_SUCCESS) + if (status != PJ_SUCCESS) { + PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; + } } status = initialize_acc(id); @@ -443,6 +452,7 @@ PJ_DEF(pj_status_t) pjsua_acc_add( const pjsua_acc_config *cfg, pj_pool_release(acc->pool); acc->pool = NULL; PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } @@ -468,6 +478,7 @@ PJ_DEF(pj_status_t) pjsua_acc_add( const pjsua_acc_config *cfg, pjsua_start_mwi(&pjsua_var.acc[id]); } + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -574,6 +585,9 @@ PJ_DEF(pj_status_t) pjsua_acc_del(pjsua_acc_id acc_id) PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.acc[acc_id].valid, PJ_EINVALIDOP); + PJ_LOG(4,(THIS_FILE, "Deleting account %d..", acc_id)); + pj_log_push_indent(); + PJSUA_LOCK(); /* Cancel any re-registration timer */ @@ -624,6 +638,7 @@ PJ_DEF(pj_status_t) pjsua_acc_del(pjsua_acc_id acc_id) PJ_LOG(4,(THIS_FILE, "Account id %d deleted", acc_id)); + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -655,6 +670,8 @@ PJ_DEF(pj_status_t) pjsua_acc_modify( pjsua_acc_id acc_id, PJ_ASSERT_RETURN(cfg->max_audio_cnt + cfg->max_video_cnt <= PJSUA_MAX_CALL_MEDIA, PJ_ETOOMANY); + PJ_LOG(4,(THIS_FILE, "Modifying accunt %d", acc_id)); + pj_log_push_indent(); PJSUA_LOCK(); @@ -1040,6 +1057,7 @@ PJ_DEF(pj_status_t) pjsua_acc_modify( pjsua_acc_id acc_id, on_return: PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } @@ -1055,9 +1073,15 @@ PJ_DEF(pj_status_t) pjsua_acc_set_online_status( pjsua_acc_id acc_id, PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.acc[acc_id].valid, PJ_EINVALIDOP); + PJ_LOG(4,(THIS_FILE, "Acc %d: setting online status to %d..", + acc_id, is_online)); + pj_log_push_indent(); + pjsua_var.acc[acc_id].online_status = is_online; pj_bzero(&pjsua_var.acc[acc_id].rpid, sizeof(pjrpid_element)); pjsua_pres_update_acc(acc_id, PJ_FALSE); + + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -1073,12 +1097,18 @@ PJ_DEF(pj_status_t) pjsua_acc_set_online_status2( pjsua_acc_id acc_id, PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.acc[acc_id].valid, PJ_EINVALIDOP); + PJ_LOG(4,(THIS_FILE, "Acc %d: setting online status to %d..", + acc_id, is_online)); + pj_log_push_indent(); + PJSUA_LOCK(); pjsua_var.acc[acc_id].online_status = is_online; pjrpid_element_dup(pjsua_var.acc[acc_id].pool, &pjsua_var.acc[acc_id].rpid, pr); PJSUA_UNLOCK(); pjsua_pres_update_acc(acc_id, PJ_TRUE); + pj_log_pop_indent(); + return PJ_SUCCESS; } @@ -1664,6 +1694,7 @@ static void regc_cb(struct pjsip_regc_cbparam *param) if (param->regc != acc->regc) return; + pj_log_push_indent(); PJSUA_LOCK(); /* @@ -1715,6 +1746,7 @@ static void regc_cb(struct pjsip_regc_cbparam *param) /* Check NAT bound address */ if (acc_check_nat_addr(acc, param)) { PJSUA_UNLOCK(); + pj_log_pop_indent(); return; } @@ -1777,6 +1809,7 @@ static void regc_cb(struct pjsip_regc_cbparam *param) } PJSUA_UNLOCK(); + pj_log_pop_indent(); } @@ -1964,6 +1997,10 @@ PJ_DEF(pj_status_t) pjsua_acc_set_registration( pjsua_acc_id acc_id, PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.acc[acc_id].valid, PJ_EINVALIDOP); + PJ_LOG(4,(THIS_FILE, "Acc %d: setting %sregistration..", + acc_id, (renew? "" : "un"))); + pj_log_push_indent(); + PJSUA_LOCK(); /* Cancel any re-registration timer */ @@ -2039,12 +2076,13 @@ PJ_DEF(pj_status_t) pjsua_acc_set_registration( pjsua_acc_id acc_id, pjsua_perror(THIS_FILE, "Unable to create/send REGISTER", status); } else { - PJ_LOG(3,(THIS_FILE, "%s sent", + PJ_LOG(4,(THIS_FILE, "Acc %d: %s sent", acc_id, (renew? "Registration" : "Unregistration"))); } on_return: PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } @@ -2790,6 +2828,10 @@ void pjsua_acc_on_tp_state_changed(pjsip_transport *tp, if (state != PJSIP_TP_STATE_DISCONNECTED) return; + PJ_LOG(4,(THIS_FILE, "Disconnected notification for transport %s", + tp->obj_name)); + pj_log_push_indent(); + /* Shutdown this transport, to make sure that the transport manager * will create a new transport for reconnection. */ @@ -2817,4 +2859,5 @@ void pjsua_acc_on_tp_state_changed(pjsip_transport *tp, } PJSUA_UNLOCK(); + pj_log_pop_indent(); } diff --git a/pjsip/src/pjsua-lib/pjsua_call.c b/pjsip/src/pjsua-lib/pjsua_call.c index ce4f0bda..3deeacca 100644 --- a/pjsip/src/pjsua-lib/pjsua_call.c +++ b/pjsip/src/pjsua-lib/pjsua_call.c @@ -342,7 +342,7 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, const pjsua_msg_data *msg_data, pjsua_call_id *p_call_id) { - pj_pool_t *tmp_pool; + pj_pool_t *tmp_pool = NULL; pjsip_dialog *dlg = NULL; pjmedia_sdp_session *offer; pjsip_inv_session *inv = NULL; @@ -361,6 +361,11 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, /* Check arguments */ PJ_ASSERT_RETURN(dest_uri, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Making call with acc #%d to %.*s", acc_id, + (int)dest_uri->slen, dest_uri->ptr)); + + pj_log_push_indent(); + PJSUA_LOCK(); /* Create sound port if none is instantiated, to check if sound device @@ -374,18 +379,16 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, pj_status_t status; status = pjsua_set_snd_dev(pjsua_var.cap_dev, pjsua_var.play_dev); - if (status != PJ_SUCCESS) { - PJSUA_UNLOCK(); - return status; - } + if (status != PJ_SUCCESS) + goto on_error; } acc = &pjsua_var.acc[acc_id]; if (!acc->valid) { pjsua_perror(THIS_FILE, "Unable to make call because account " "is not valid", PJ_EINVALIDOP); - PJSUA_UNLOCK(); - return PJ_EINVALIDOP; + status = PJ_EINVALIDOP; + goto on_error; } /* Find free call slot. */ @@ -393,8 +396,8 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, if (call_id == PJSUA_INVALID_ID) { pjsua_perror(THIS_FILE, "Error making call", PJ_ETOOMANY); - PJSUA_UNLOCK(); - return PJ_ETOOMANY; + status = PJ_ETOOMANY; + goto on_error; } call = &pjsua_var.calls[call_id]; @@ -421,15 +424,11 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, if (uri == NULL) { pjsua_perror(THIS_FILE, "Unable to make call", PJSIP_EINVALIDREQURI); - pj_pool_release(tmp_pool); - PJSUA_UNLOCK(); - return PJSIP_EINVALIDREQURI; + status = PJSIP_EINVALIDREQURI; + goto on_error; } } - PJ_LOG(4,(THIS_FILE, "Making call with acc #%d to %.*s", acc_id, - (int)dest_uri->slen, dest_uri->ptr)); - /* Mark call start time. */ pj_gettimeofday(&call->start_time); @@ -447,9 +446,7 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to generate Contact header", status); - pj_pool_release(tmp_pool); - PJSUA_UNLOCK(); - return status; + goto on_error; } } @@ -459,9 +456,7 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, dest_uri, dest_uri, &dlg); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Dialog creation failed", status); - pj_pool_release(tmp_pool); - PJSUA_UNLOCK(); - return status; + goto on_error; } /* Increment the dialog's lock otherwise when invite session creation @@ -587,6 +582,8 @@ PJ_DEF(pj_status_t) pjsua_call_make_call( pjsua_acc_id acc_id, pj_pool_release(tmp_pool); PJSUA_UNLOCK(); + pj_log_pop_indent(); + return PJ_SUCCESS; @@ -605,8 +602,11 @@ on_error: pjsua_media_channel_deinit(call_id); } - pj_pool_release(tmp_pool); + if (tmp_pool) + pj_pool_release(tmp_pool); PJSUA_UNLOCK(); + + pj_log_pop_indent(); return status; } @@ -668,6 +668,9 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) return PJ_TRUE; } + PJ_LOG(4,(THIS_FILE, "Incoming %s", rdata->msg_info.info)); + pj_log_push_indent(); + PJSUA_LOCK(); /* Find free call slot. */ @@ -679,8 +682,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) NULL, NULL); PJ_LOG(2,(THIS_FILE, "Unable to accept incoming call (too many calls)")); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* Clear call descriptor */ @@ -714,8 +716,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) NULL, NULL); } - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* If this INVITE request contains Replaces header, notify application @@ -745,8 +746,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsip_endpt_respond(pjsua_var.endpt, NULL, rdata, st_code, &st_text, NULL, NULL, NULL); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } } @@ -793,8 +793,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsip_endpt_respond(pjsua_var.endpt, NULL, rdata, 400, &reason, &hdr_list, NULL, NULL); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* Do quick checks on SDP before passing it to transports. More elabore @@ -804,8 +803,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) const pj_str_t reason = pj_str("Missing media in SDP"); pjsip_endpt_respond(pjsua_var.endpt, NULL, rdata, 400, &reason, NULL, NULL, NULL); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } } else { @@ -822,8 +820,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsua_perror(THIS_FILE, "Error initializing media channel", status); pjsip_endpt_respond(pjsua_var.endpt, NULL, rdata, sip_err_code, NULL, NULL, NULL, NULL); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* Create answer */ @@ -833,8 +830,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsua_perror(THIS_FILE, "Error creating SDP answer", status); pjsip_endpt_respond(pjsua_var.endpt, NULL, rdata, sip_err_code, NULL, NULL, NULL, NULL); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } @@ -871,8 +867,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) } pjsua_media_channel_deinit(call->index); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } @@ -888,8 +883,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsip_endpt_respond_stateless(pjsua_var.endpt, rdata, 500, NULL, NULL, NULL); pjsua_media_channel_deinit(call->index); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } } @@ -900,8 +894,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsip_endpt_respond_stateless(pjsua_var.endpt, rdata, 500, NULL, NULL, NULL); pjsua_media_channel_deinit(call->index); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* Set credentials */ @@ -942,8 +935,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsip_dlg_terminate(dlg); */ pjsua_media_channel_deinit(call->index); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* Init Session Timers */ @@ -958,8 +950,7 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) pjsua_media_channel_deinit(call->index); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } /* Update NAT type of remote endpoint, only when there is SDP in @@ -1006,15 +997,13 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) PJ_FALSE); } pjsua_media_channel_deinit(call->index); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } else { status = pjsip_inv_send_msg(inv, response); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send 100 response", status); - PJSUA_UNLOCK(); - return PJ_TRUE; + goto on_return; } } @@ -1087,6 +1076,8 @@ pj_bool_t pjsua_call_on_incoming(pjsip_rx_data *rdata) /* This INVITE request has been handled. */ +on_return: + pj_log_pop_indent(); PJSUA_UNLOCK(); return PJ_TRUE; } @@ -1577,16 +1568,19 @@ PJ_DEF(pj_status_t) pjsua_call_answer( pjsua_call_id call_id, const pjsua_msg_data *msg_data) { pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pjsip_tx_data *tdata; pj_status_t status; PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Answering call %d: code=%d", call_id, code)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_answer()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; if (call->res_time.sec == 0) pj_gettimeofday(&call->res_time); @@ -1599,17 +1593,14 @@ PJ_DEF(pj_status_t) pjsua_call_answer( pjsua_call_id call_id, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error creating response", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Call might have been disconnected if application is answering with * 200/OK and the media failed to start. */ - if (call->inv == NULL) { - pjsip_dlg_dec_lock(dlg); - return PJSIP_ESESSIONTERMINATED; - } + if (call->inv == NULL) + goto on_return; /* Add additional headers etc */ pjsua_process_msg_data( tdata, msg_data); @@ -1620,8 +1611,9 @@ PJ_DEF(pj_status_t) pjsua_call_answer( pjsua_call_id call_id, pjsua_perror(THIS_FILE, "Error sending response", status); - pjsip_dlg_dec_lock(dlg); - +on_return: + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); return status; } @@ -1636,7 +1628,7 @@ PJ_DEF(pj_status_t) pjsua_call_hangup(pjsua_call_id call_id, const pjsua_msg_data *msg_data) { pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pj_status_t status; pjsip_tx_data *tdata; @@ -1649,9 +1641,12 @@ PJ_DEF(pj_status_t) pjsua_call_hangup(pjsua_call_id call_id, PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Call %d hanging up: code=%d..", call_id, code)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_hangup()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; if (code==0) { if (call->inv->state == PJSIP_INV_STATE_CONFIRMED) @@ -1667,18 +1662,15 @@ PJ_DEF(pj_status_t) pjsua_call_hangup(pjsua_call_id call_id, pjsua_perror(THIS_FILE, "Failed to create end session message", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* pjsip_inv_end_session may return PJ_SUCCESS with NULL * as p_tdata when INVITE transaction has not been answered * with any provisional responses. */ - if (tdata == NULL) { - pjsip_dlg_dec_lock(dlg); - return PJ_SUCCESS; - } + if (tdata == NULL) + goto on_return; /* Add additional headers etc */ pjsua_process_msg_data( tdata, msg_data); @@ -1689,8 +1681,7 @@ PJ_DEF(pj_status_t) pjsua_call_hangup(pjsua_call_id call_id, pjsua_perror(THIS_FILE, "Failed to send end session message", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Stop lock codec timer, if it is active */ @@ -1700,9 +1691,10 @@ PJ_DEF(pj_status_t) pjsua_call_hangup(pjsua_call_id call_id, call->lock_codec.reinv_timer.id = PJ_FALSE; } - pjsip_dlg_dec_lock(dlg); - - return PJ_SUCCESS; +on_return: + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); + return status; } @@ -1740,36 +1732,35 @@ PJ_DEF(pj_status_t) pjsua_call_set_hold(pjsua_call_id call_id, { pjmedia_sdp_session *sdp; pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pjsip_tx_data *tdata; pj_status_t status; PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Putting call %d on hold", call_id)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_set_hold()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; - + goto on_return; if (call->inv->state != PJSIP_INV_STATE_CONFIRMED) { PJ_LOG(3,(THIS_FILE, "Can not hold call that is not confirmed")); - pjsip_dlg_dec_lock(dlg); - return PJSIP_ESESSIONSTATE; + status = PJSIP_ESESSIONSTATE; + goto on_return; } status = create_sdp_of_call_hold(call, &sdp); - if (status != PJ_SUCCESS) { - pjsip_dlg_dec_lock(dlg); - return status; - } + if (status != PJ_SUCCESS) + goto on_return; /* Create re-INVITE with new offer */ status = pjsip_inv_reinvite( call->inv, NULL, sdp, &tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create re-INVITE", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Add additional headers etc */ @@ -1779,16 +1770,16 @@ PJ_DEF(pj_status_t) pjsua_call_set_hold(pjsua_call_id call_id, status = pjsip_inv_send_msg( call->inv, tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send re-INVITE", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Set flag that local put the call on hold */ call->local_hold = PJ_TRUE; - pjsip_dlg_dec_lock(dlg); - - return PJ_SUCCESS; +on_return: + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); + return status; } @@ -1803,21 +1794,24 @@ PJ_DEF(pj_status_t) pjsua_call_reinvite( pjsua_call_id call_id, pj_str_t *new_contact = NULL; pjsip_tx_data *tdata; pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pj_status_t status; PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Sending re-INVITE on call %d", call_id)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_reinvite()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; if (call->inv->state != PJSIP_INV_STATE_CONFIRMED) { PJ_LOG(3,(THIS_FILE, "Can not re-INVITE call that is not confirmed")); - pjsip_dlg_dec_lock(dlg); - return PJSIP_ESESSIONSTATE; + status = PJSIP_ESESSIONSTATE; + goto on_return; } /* Create SDP */ @@ -1832,8 +1826,7 @@ PJ_DEF(pj_status_t) pjsua_call_reinvite( pjsua_call_id call_id, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to get SDP from media endpoint", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } if ((options & PJSUA_CALL_UPDATE_CONTACT) & @@ -1846,8 +1839,7 @@ PJ_DEF(pj_status_t) pjsua_call_reinvite( pjsua_call_id call_id, status = pjsip_inv_reinvite( call->inv, new_contact, sdp, &tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create re-INVITE", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Add additional headers etc */ @@ -1857,13 +1849,13 @@ PJ_DEF(pj_status_t) pjsua_call_reinvite( pjsua_call_id call_id, status = pjsip_inv_send_msg( call->inv, tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send re-INVITE", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } +on_return: pjsip_dlg_dec_lock(dlg); - - return PJ_SUCCESS; + pj_log_pop_indent(); + return status; } @@ -1878,7 +1870,7 @@ PJ_DEF(pj_status_t) pjsua_call_update( pjsua_call_id call_id, pj_str_t *new_contact = NULL; pjsip_tx_data *tdata; pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pj_status_t status; PJ_UNUSED_ARG(options); @@ -1886,9 +1878,12 @@ PJ_DEF(pj_status_t) pjsua_call_update( pjsua_call_id call_id, PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Sending UPDATE on call %d", call_id)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_update()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; /* Create SDP */ status = pjsua_media_channel_create_sdp(call->index, @@ -1897,8 +1892,7 @@ PJ_DEF(pj_status_t) pjsua_call_update( pjsua_call_id call_id, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to get SDP from media endpoint", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } if ((options & PJSUA_CALL_UPDATE_CONTACT) & @@ -1911,8 +1905,7 @@ PJ_DEF(pj_status_t) pjsua_call_update( pjsua_call_id call_id, status = pjsip_inv_update(call->inv, new_contact, sdp, &tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create UPDATE request", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Add additional headers etc */ @@ -1922,15 +1915,15 @@ PJ_DEF(pj_status_t) pjsua_call_update( pjsua_call_id call_id, status = pjsip_inv_send_msg( call->inv, tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send UPDATE request", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } call->local_hold = PJ_FALSE; - pjsip_dlg_dec_lock(dlg); - - return PJ_SUCCESS; +on_return: + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); + return status; } @@ -1944,20 +1937,23 @@ PJ_DEF(pj_status_t) pjsua_call_xfer( pjsua_call_id call_id, pjsip_evsub *sub; pjsip_tx_data *tdata; pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pjsip_generic_string_hdr *gs_hdr; const pj_str_t str_ref_by = { "Referred-By", 11 }; struct pjsip_evsub_user xfer_cb; pj_status_t status; - PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, - PJ_EINVAL); + PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls && + dest, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Transfering call %d to %.*s", call_id, + (int)dest->slen, dest->ptr)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_xfer()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; - + goto on_return; /* Create xfer client subscription. */ pj_bzero(&xfer_cb, sizeof(xfer_cb)); @@ -1966,8 +1962,7 @@ PJ_DEF(pj_status_t) pjsua_call_xfer( pjsua_call_id call_id, status = pjsip_xfer_create_uac(call->inv->dlg, &xfer_cb, &sub); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create xfer", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Associate this call with the client subscription */ @@ -1979,8 +1974,7 @@ PJ_DEF(pj_status_t) pjsua_call_xfer( pjsua_call_id call_id, status = pjsip_xfer_initiate(sub, dest, &tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create REFER request", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* Add Referred-By header */ @@ -1996,18 +1990,17 @@ PJ_DEF(pj_status_t) pjsua_call_xfer( pjsua_call_id call_id, status = pjsip_xfer_send_request(sub, tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send REFER request", status); - pjsip_dlg_dec_lock(dlg); - return status; + goto on_return; } /* For simplicity (that's what this program is intended to be!), * leave the original invite session as it is. More advanced application * may want to hold the INVITE, or terminate the invite, or whatever. */ - - pjsip_dlg_dec_lock(dlg); - - return PJ_SUCCESS; +on_return: + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); + return status; } @@ -2035,21 +2028,28 @@ PJ_DEF(pj_status_t) pjsua_call_xfer_replaces( pjsua_call_id call_id, dest_call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Transfering call %d replacing with call %d", + call_id, dest_call_id)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_xfer_replaces()", dest_call_id, &dest_call, &dest_dlg); - if (status != PJ_SUCCESS) + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); return status; + } /* * Create REFER destination URI with Replaces field. */ /* Make sure we have sufficient buffer's length */ - PJ_ASSERT_RETURN( dest_dlg->remote.info_str.slen + + PJ_ASSERT_ON_FAIL(dest_dlg->remote.info_str.slen + dest_dlg->call_id->id.slen + dest_dlg->remote.info->tag.slen + dest_dlg->local.info->tag.slen + 32 - < (long)sizeof(str_dest_buf), PJSIP_EURITOOLONG); + < (long)sizeof(str_dest_buf), + { status=PJSIP_EURITOOLONG; goto on_error; }); /* Print URI */ str_dest_buf[0] = '<'; @@ -2058,8 +2058,10 @@ PJ_DEF(pj_status_t) pjsua_call_xfer_replaces( pjsua_call_id call_id, uri = (pjsip_uri*) pjsip_uri_get_uri(dest_dlg->remote.info->uri); len = pjsip_uri_print(PJSIP_URI_IN_REQ_URI, uri, str_dest_buf+1, sizeof(str_dest_buf)-1); - if (len < 0) - return PJSIP_EURITOOLONG; + if (len < 0) { + status = PJSIP_EURITOOLONG; + goto on_error; + } str_dest.slen += len; @@ -2080,15 +2082,23 @@ PJ_DEF(pj_status_t) pjsua_call_xfer_replaces( pjsua_call_id call_id, (int)dest_dlg->local.info->tag.slen, dest_dlg->local.info->tag.ptr); - PJ_ASSERT_RETURN(len > 0 && len <= (int)sizeof(str_dest_buf)-str_dest.slen, - PJSIP_EURITOOLONG); + PJ_ASSERT_ON_FAIL(len > 0 && len <= (int)sizeof(str_dest_buf)-str_dest.slen, + { status=PJSIP_EURITOOLONG; goto on_error; }); str_dest.ptr = str_dest_buf; str_dest.slen += len; pjsip_dlg_dec_lock(dest_dlg); - return pjsua_call_xfer(call_id, &str_dest, msg_data); + status = pjsua_call_xfer(call_id, &str_dest, msg_data); + + pj_log_pop_indent(); + return status; + +on_error: + if (dest_dlg) pjsip_dlg_dec_lock(dest_dlg); + pj_log_pop_indent(); + return status; } @@ -2099,27 +2109,32 @@ PJ_DEF(pj_status_t) pjsua_call_dial_dtmf( pjsua_call_id call_id, const pj_str_t *digits) { pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pj_status_t status; PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Call %d dialing DTMF %.*s", + call_id, (int)digits->slen, digits->ptr)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_dial_dtmf()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; if (!pjsua_call_has_media(call_id)) { PJ_LOG(3,(THIS_FILE, "Media is not established yet!")); - pjsip_dlg_dec_lock(dlg); - return PJ_EINVALIDOP; + status = PJ_EINVALIDOP; + goto on_return; } status = pjmedia_stream_dial_dtmf( call->media[call->audio_idx].strm.a.stream, digits); - pjsip_dlg_dec_lock(dlg); - +on_return: + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); return status; } @@ -2134,20 +2149,23 @@ PJ_DEF(pj_status_t) pjsua_call_send_im( pjsua_call_id call_id, void *user_data) { pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; const pj_str_t mime_text_plain = pj_str("text/plain"); pjsip_media_type ctype; pjsua_im_data *im_data; pjsip_tx_data *tdata; pj_status_t status; - PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Call %d sending %d bytes MESSAGE..", + call_id, (int)content->slen)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_send_im()", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; /* Set default media type if none is specified */ if (mime_type == NULL) { @@ -2199,7 +2217,8 @@ PJ_DEF(pj_status_t) pjsua_call_send_im( pjsua_call_id call_id, } on_return: - pjsip_dlg_dec_lock(dlg); + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); return status; } @@ -2212,16 +2231,20 @@ PJ_DEF(pj_status_t) pjsua_call_send_typing_ind( pjsua_call_id call_id, const pjsua_msg_data*msg_data) { pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pjsip_tx_data *tdata; pj_status_t status; PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Call %d sending typing indication..", + call_id)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_send_typing_ind", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; /* Create request message. */ status = pjsip_dlg_create_request( call->inv->dlg, &pjsip_message_method, @@ -2246,7 +2269,8 @@ PJ_DEF(pj_status_t) pjsua_call_send_typing_ind( pjsua_call_id call_id, } on_return: - pjsip_dlg_dec_lock(dlg); + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); return status; } @@ -2259,7 +2283,7 @@ PJ_DEF(pj_status_t) pjsua_call_send_request(pjsua_call_id call_id, const pjsua_msg_data *msg_data) { pjsua_call *call; - pjsip_dialog *dlg; + pjsip_dialog *dlg = NULL; pjsip_method method; pjsip_tx_data *tdata; pj_status_t status; @@ -2267,9 +2291,13 @@ PJ_DEF(pj_status_t) pjsua_call_send_request(pjsua_call_id call_id, PJ_ASSERT_RETURN(call_id>=0 && call_id<(int)pjsua_var.ua_cfg.max_calls, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Call %d sending %.*s request..", + call_id, (int)method_str->slen, method_str->ptr)); + pj_log_push_indent(); + status = acquire_call("pjsua_call_send_request", call_id, &call, &dlg); if (status != PJ_SUCCESS) - return status; + goto on_return; /* Init method */ pjsip_method_init_np(&method, (pj_str_t*)method_str); @@ -2292,7 +2320,8 @@ PJ_DEF(pj_status_t) pjsua_call_send_request(pjsua_call_id call_id, } on_return: - pjsip_dlg_dec_lock(dlg); + if (dlg) pjsip_dlg_dec_lock(dlg); + pj_log_pop_indent(); return status; } @@ -2304,6 +2333,9 @@ PJ_DEF(void) pjsua_call_hangup_all(void) { unsigned i; + PJ_LOG(4,(THIS_FILE, "Hangup all calls..")); + pj_log_push_indent(); + PJSUA_LOCK(); for (i=0; ilock_codec.retry_cnt > LOCK_CODEC_MAX_RETRY) return PJ_SUCCESS; - PJ_LOG(3, (THIS_FILE, "Got answer with multiple codecs, scheduling " + PJ_LOG(4, (THIS_FILE, "Got answer with multiple codecs, scheduling " "updating media session to use only one codec..")); call->lock_codec.sdp_ver = local_sdp->origin.version; @@ -2634,12 +2667,14 @@ static void pjsua_call_on_state_changed(pjsip_inv_session *inv, { pjsua_call *call; + pj_log_push_indent(); PJSUA_LOCK(); call = (pjsua_call*) inv->dlg->mod_data[pjsua_var.mod.id]; if (!call) { PJSUA_UNLOCK(); + pj_log_pop_indent(); return; } @@ -2796,6 +2831,7 @@ static void pjsua_call_on_state_changed(pjsip_inv_session *inv, } PJSUA_UNLOCK(); + pj_log_pop_indent(); } /* @@ -2904,6 +2940,7 @@ static void pjsua_call_on_media_update(pjsip_inv_session *inv, const pjmedia_sdp_session *remote_sdp; //const pj_str_t st_update = {"UPDATE", 6}; + pj_log_push_indent(); PJSUA_LOCK(); call = (pjsua_call*) inv->dlg->mod_data[pjsua_var.mod.id]; @@ -2929,8 +2966,7 @@ static void pjsua_call_on_media_update(pjsip_inv_session *inv, call_disconnect(inv, PJSIP_SC_UNSUPPORTED_MEDIA_TYPE); } - PJSUA_UNLOCK(); - return; + goto on_return; } @@ -2941,8 +2977,7 @@ static void pjsua_call_on_media_update(pjsip_inv_session *inv, "Unable to retrieve currently active local SDP", status); //call_disconnect(inv, PJSIP_SC_UNSUPPORTED_MEDIA_TYPE); - PJSUA_UNLOCK(); - return; + goto on_return; } status = pjmedia_sdp_neg_get_active_remote(call->inv->neg, &remote_sdp); @@ -2951,8 +2986,7 @@ static void pjsua_call_on_media_update(pjsip_inv_session *inv, "Unable to retrieve currently active remote SDP", status); //call_disconnect(inv, PJSIP_SC_UNSUPPORTED_MEDIA_TYPE); - PJSUA_UNLOCK(); - return; + goto on_return; } /* Update remote's NAT type */ @@ -2970,8 +3004,7 @@ static void pjsua_call_on_media_update(pjsip_inv_session *inv, * state is disconnected anyway. */ /*pjsua_media_channel_deinit(call->index);*/ - PJSUA_UNLOCK(); - return; + goto on_return; } /* Ticket #476: make sure only one codec is specified in the answer. */ @@ -2984,8 +3017,9 @@ static void pjsua_call_on_media_update(pjsip_inv_session *inv, if (pjsua_var.ua_cfg.cb.on_call_media_state) pjsua_var.ua_cfg.cb.on_call_media_state(call->index); - +on_return: PJSUA_UNLOCK(); + pj_log_pop_indent(); } @@ -3104,14 +3138,14 @@ static void pjsua_call_on_rx_offer(pjsip_inv_session *inv, /* Supply candidate answer */ PJ_LOG(4,(THIS_FILE, "Call %d: received updated media offer", call->index)); + pj_log_push_indent(); status = pjsua_media_channel_create_sdp(call->index, call->inv->pool_prov, offer, &answer, NULL); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create local SDP", status); - PJSUA_UNLOCK(); - return; + goto on_return; } /* Validate media count in the generated answer */ @@ -3154,11 +3188,12 @@ static void pjsua_call_on_rx_offer(pjsip_inv_session *inv, status = pjsip_inv_set_sdp_answer(call->inv, answer); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to set answer", status); - PJSUA_UNLOCK(); - return; + goto on_return; } +on_return: PJSUA_UNLOCK(); + pj_log_pop_indent(); } @@ -3171,6 +3206,7 @@ static void pjsua_call_on_create_offer(pjsip_inv_session *inv, pjsua_call *call; pj_status_t status; + pj_log_push_indent(); PJSUA_LOCK(); call = (pjsua_call*) inv->dlg->mod_data[pjsua_var.mod.id]; @@ -3192,11 +3228,12 @@ static void pjsua_call_on_create_offer(pjsip_inv_session *inv, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create local SDP", status); - PJSUA_UNLOCK(); - return; + goto on_return; } +on_return: PJSUA_UNLOCK(); + pj_log_pop_indent(); } @@ -3209,6 +3246,8 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) PJ_UNUSED_ARG(event); + pj_log_push_indent(); + /* * When subscription is accepted (got 200/OK to REFER), check if * subscription suppressed. @@ -3296,7 +3335,7 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) if (!call || !event || !pjsua_var.ua_cfg.cb.on_call_transfer_status) { /* Application is not interested with call progress status */ - return; + goto on_return; } /* This better be a NOTIFY request */ @@ -3313,7 +3352,7 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) if (!body) { PJ_LOG(2,(THIS_FILE, "Warning: received NOTIFY without message body")); - return; + goto on_return; } /* Check for appropriate content */ @@ -3323,7 +3362,7 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) PJ_LOG(2,(THIS_FILE, "Warning: received NOTIFY with non message/sipfrag " "content")); - return; + goto on_return; } /* Try to parse the content */ @@ -3333,7 +3372,7 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) PJ_LOG(2,(THIS_FILE, "Warning: received NOTIFY with invalid " "message/sipfrag content")); - return; + goto on_return; } } else { @@ -3365,6 +3404,9 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) status = pjsip_evsub_send_request(sub, tdata); } } + +on_return: + pj_log_pop_indent(); } @@ -3374,9 +3416,10 @@ static void xfer_client_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) */ static void xfer_server_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) { - PJ_UNUSED_ARG(event); + pj_log_push_indent(); + /* * When subscription is terminated, clear the xfer_sub member of * the inv_data. @@ -3386,13 +3429,16 @@ static void xfer_server_on_evsub_state( pjsip_evsub *sub, pjsip_event *event) call = (pjsua_call*) pjsip_evsub_get_mod_data(sub, pjsua_var.mod.id); if (!call) - return; + goto on_return; pjsip_evsub_set_mod_data(sub, pjsua_var.mod.id, NULL); call->xfer_sub = NULL; PJ_LOG(4,(THIS_FILE, "Xfer server subscription terminated")); } + +on_return: + pj_log_pop_indent(); } @@ -3419,6 +3465,8 @@ static void on_call_transfered( pjsip_inv_session *inv, pjsip_status_code code; pjsip_evsub *sub; + pj_log_push_indent(); + existing_call = (pjsua_call*) inv->dlg->mod_data[pjsua_var.mod.id]; /* Find the Refer-To header */ @@ -3431,7 +3479,7 @@ static void on_call_transfered( pjsip_inv_session *inv, */ PJ_LOG(4,(THIS_FILE, "Received REFER without Refer-To header!")); pjsip_dlg_respond( inv->dlg, rdata, 400, NULL, NULL, NULL); - return; + goto on_return; } /* Find optional Refer-Sub header */ @@ -3462,7 +3510,7 @@ static void on_call_transfered( pjsip_inv_session *inv, if (code >= 300) { /* Application rejects call transfer request */ pjsip_dlg_respond( inv->dlg, rdata, code, NULL, NULL, NULL); - return; + goto on_return; } PJ_LOG(3,(THIS_FILE, "Call to %.*s is being transfered to %.*s", @@ -3484,7 +3532,7 @@ static void on_call_transfered( pjsip_inv_session *inv, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create 2xx response to REFER", status); - return; + goto on_return; } /* Add Refer-Sub header */ @@ -3500,7 +3548,7 @@ static void on_call_transfered( pjsip_inv_session *inv, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create 2xx response to REFER", status); - return; + goto on_return; } /* Don't have subscription */ @@ -3522,7 +3570,7 @@ static void on_call_transfered( pjsip_inv_session *inv, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create xfer uas", status); pjsip_dlg_respond( inv->dlg, rdata, 500, NULL, NULL, NULL); - return; + goto on_return; } /* If there's Refer-Sub header and the value is "true", send back @@ -3549,14 +3597,14 @@ static void on_call_transfered( pjsip_inv_session *inv, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create NOTIFY to REFER", status); - return; + goto on_return; } /* Send initial NOTIFY request */ status = pjsip_xfer_send_request( sub, tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send NOTIFY to REFER", status); - return; + goto on_return; } } @@ -3594,16 +3642,16 @@ static void on_call_transfered( pjsip_inv_session *inv, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create NOTIFY to REFER", status); - return; + goto on_return; } status = pjsip_xfer_send_request(sub, tdata); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to send NOTIFY to REFER", status); - return; + goto on_return; } } - return; + goto on_return; } if (sub) { @@ -3617,6 +3665,9 @@ static void on_call_transfered( pjsip_inv_session *inv, pjsip_evsub_set_mod_data(sub, pjsua_var.mod.id, &pjsua_var.calls[new_call]); } + +on_return: + pj_log_pop_indent(); } @@ -3633,14 +3684,13 @@ static void pjsua_call_on_tsx_state_changed(pjsip_inv_session *inv, { pjsua_call *call; + pj_log_push_indent(); PJSUA_LOCK(); call = (pjsua_call*) inv->dlg->mod_data[pjsua_var.mod.id]; - if (call == NULL) { - PJSUA_UNLOCK(); - return; - } + if (call == NULL) + goto on_return; if (call->inv == NULL) { /* Shouldn't happen. It happens only when we don't terminate the @@ -3648,8 +3698,7 @@ static void pjsua_call_on_tsx_state_changed(pjsip_inv_session *inv, * transfered (and this call has been disconnected), and we * receive another REFER for this call. */ - PJSUA_UNLOCK(); - return; + goto on_return; } /* Notify application callback first */ @@ -3694,8 +3743,7 @@ static void pjsua_call_on_tsx_state_changed(pjsip_inv_session *inv, pjsip_dlg_respond( inv->dlg, rdata, PJSIP_SC_NOT_ACCEPTABLE_HERE, NULL, &hdr_list, NULL ); - PJSUA_UNLOCK(); - return; + goto on_return; } /* Respond with 200 first, so that remote doesn't retransmit in case @@ -3730,8 +3778,9 @@ static void pjsua_call_on_tsx_state_changed(pjsip_inv_session *inv, } } - +on_return: PJSUA_UNLOCK(); + pj_log_pop_indent(); } @@ -3743,6 +3792,7 @@ static pjsip_redirect_op pjsua_call_on_redirected(pjsip_inv_session *inv, pjsua_call *call = (pjsua_call*) inv->dlg->mod_data[pjsua_var.mod.id]; pjsip_redirect_op op; + pj_log_push_indent(); PJSUA_LOCK(); if (pjsua_var.ua_cfg.cb.on_call_redirected) { @@ -3757,6 +3807,7 @@ static pjsip_redirect_op pjsua_call_on_redirected(pjsip_inv_session *inv, } PJSUA_UNLOCK(); + pj_log_pop_indent(); return op; } diff --git a/pjsip/src/pjsua-lib/pjsua_core.c b/pjsip/src/pjsua-lib/pjsua_core.c index 7c2929fc..9e5a56f5 100644 --- a/pjsip/src/pjsua-lib/pjsua_core.c +++ b/pjsip/src/pjsua-lib/pjsua_core.c @@ -83,7 +83,8 @@ PJ_DEF(void) pjsua_logging_config_default(pjsua_logging_config *cfg) cfg->console_level = 4; cfg->decor = PJ_LOG_HAS_SENDER | PJ_LOG_HAS_TIME | PJ_LOG_HAS_MICRO_SEC | PJ_LOG_HAS_NEWLINE | - PJ_LOG_HAS_SPACE; + PJ_LOG_HAS_SPACE | PJ_LOG_HAS_THREAD_SWC | + PJ_LOG_HAS_INDENT; #if defined(PJ_WIN32) && PJ_WIN32 != 0 cfg->decor |= PJ_LOG_HAS_COLOR; #endif @@ -628,6 +629,8 @@ PJ_DEF(pj_status_t) pjsua_create(void) status = pj_init(); PJ_ASSERT_RETURN(status == PJ_SUCCESS, status); + pj_log_push_indent(); + /* Init random seed */ init_random_seed(); @@ -659,6 +662,7 @@ PJ_DEF(pj_status_t) pjsua_create(void) status = pj_mutex_create_recursive(pjsua_var.pool, "pjsua", &pjsua_var.mutex); if (status != PJ_SUCCESS) { + pj_log_pop_indent(); pjsua_perror(THIS_FILE, "Unable to create mutex", status); return status; } @@ -672,7 +676,7 @@ PJ_DEF(pj_status_t) pjsua_create(void) PJ_ASSERT_RETURN(status == PJ_SUCCESS, status); pjsua_set_state(PJSUA_STATE_CREATED); - + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -693,6 +697,7 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, unsigned i; pj_status_t status; + pj_log_push_indent(); /* Create default configurations when the config is not supplied */ @@ -710,7 +715,7 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, if (log_cfg) { status = pjsua_reconfigure_logging(log_cfg); if (status != PJ_SUCCESS) - return status; + goto on_error; } #if defined(PJ_IPHONE_OS_HAS_MULTITASKING_SUPPORT) && \ @@ -734,7 +739,7 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, &pjsua_var.resolver); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error creating resolver", status); - return status; + goto on_error; } /* Configure nameserver for the DNS resolver */ @@ -743,14 +748,14 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, ua_cfg->nameserver, NULL); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error setting nameserver", status); - return status; + goto on_error; } /* Set this DNS resolver to be used by the SIP resolver */ status = pjsip_endpt_set_resolver(pjsua_var.endpt, pjsua_var.resolver); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error setting DNS resolver", status); - return status; + goto on_error; } /* Print nameservers */ @@ -832,7 +837,8 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, if (r == NULL) { pjsua_perror(THIS_FILE, "Invalid outbound proxy URI", PJSIP_EINVALIDURI); - return PJSIP_EINVALIDURI; + status = PJSIP_EINVALIDURI; + goto on_error; } if (pjsua_var.ua_cfg.force_lr) { @@ -840,7 +846,8 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, if (!PJSIP_URI_SCHEME_IS_SIP(r->name_addr.uri) && !PJSIP_URI_SCHEME_IS_SIP(r->name_addr.uri)) { - return PJSIP_EINVALIDSCHEME; + status = PJSIP_EINVALIDSCHEME; + goto on_error; } sip_url = (pjsip_sip_uri*)r->name_addr.uri; sip_url->lr_param = 1; @@ -871,7 +878,7 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, status = resolve_stun_server(PJ_FALSE); if (status != PJ_SUCCESS && status != PJ_EPENDING) { pjsua_perror(THIS_FILE, "Error resolving STUN server", status); - return status; + goto on_error; } /* Initialize PJSUA media subsystem */ @@ -941,11 +948,12 @@ PJ_DEF(pj_status_t) pjsua_init( const pjsua_config *ua_cfg, pj_get_version(), pj_get_sys_info()->info.ptr)); pjsua_set_state(PJSUA_STATE_INIT); - + pj_log_pop_indent(); return PJ_SUCCESS; on_error: pjsua_destroy(); + pj_log_pop_indent(); return status; } @@ -1322,6 +1330,8 @@ PJ_DEF(pj_status_t) pjsua_destroy(void) PJ_LOG(4,(THIS_FILE, "Shutting down...")); + pj_log_push_indent(); + /* Terminate all calls. */ pjsua_call_hangup_all(); @@ -1477,6 +1487,8 @@ PJ_DEF(pj_status_t) pjsua_destroy(void) pjsua_var.log_file = NULL; } + pj_log_pop_indent(); + /* Shutdown PJLIB */ pj_shutdown(); } @@ -1523,22 +1535,25 @@ PJ_DEF(pj_status_t) pjsua_start(void) pj_status_t status; pjsua_set_state(PJSUA_STATE_STARTING); + pj_log_push_indent(); status = pjsua_call_subsys_start(); if (status != PJ_SUCCESS) - return status; + goto on_return; status = pjsua_media_subsys_start(); if (status != PJ_SUCCESS) - return status; + goto on_return; status = pjsua_pres_start(); if (status != PJ_SUCCESS) - return status; + goto on_return; pjsua_set_state(PJSUA_STATE_RUNNING); - return PJ_SUCCESS; +on_return: + pj_log_pop_indent(); + return status; } diff --git a/pjsip/src/pjsua-lib/pjsua_media.c b/pjsip/src/pjsua-lib/pjsua_media.c index 0f56dd0f..ff5a0ef9 100644 --- a/pjsip/src/pjsua-lib/pjsua_media.c +++ b/pjsip/src/pjsua-lib/pjsua_media.c @@ -72,6 +72,8 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) /* To suppress warning about unused var when all codecs are disabled */ PJ_UNUSED_ARG(codec_id); + pj_log_push_indent(); + /* Specify which audio device settings are save-able */ pjsua_var.aud_svmask = 0xFFFFFFFF; /* These are not-settable */ @@ -110,7 +112,7 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) pjsua_perror(THIS_FILE, "Media stack initialization has returned error", status); - return status; + goto on_error; } /* @@ -137,7 +139,7 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error querying audio device info", status); - return status; + goto on_error; } /* Collect extended formats supported by this audio device */ @@ -174,7 +176,7 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) &codec_cfg); if (status != PJ_SUCCESS) { PJ_PERROR(1,(THIS_FILE, status, "Error registering codecs")); - return status; + goto on_error; } /* Set speex/16000 to higher priority*/ @@ -228,7 +230,7 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error creating conference bridge", status); - return status; + goto on_error; } /* Are we using the audio switchboard (a.k.a APS-Direct)? */ @@ -250,7 +252,7 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error initializing SRTP library", status); - return status; + goto on_error; } #endif @@ -258,10 +260,15 @@ pj_status_t pjsua_media_subsys_init(const pjsua_media_config *cfg) #if PJMEDIA_HAS_VIDEO status = pjsua_vid_subsys_init(); if (status != PJ_SUCCESS) - return status; + goto on_error; #endif + pj_log_pop_indent(); return PJ_SUCCESS; + +on_error: + pj_log_pop_indent(); + return status; } @@ -344,6 +351,8 @@ pj_status_t pjsua_media_subsys_start(void) { pj_status_t status; + pj_log_push_indent(); + #if DISABLED_FOR_TICKET_1185 /* Create media for calls, if none is specified */ if (pjsua_var.calls[0].media[0].tp == NULL) { @@ -354,8 +363,10 @@ pj_status_t pjsua_media_subsys_start(void) transport_cfg.port = DEFAULT_RTP_PORT; status = pjsua_media_transports_create(&transport_cfg); - if (status != PJ_SUCCESS) + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); return status; + } } #endif @@ -365,8 +376,10 @@ pj_status_t pjsua_media_subsys_start(void) /* Video */ #if PJMEDIA_HAS_VIDEO status = pjsua_vid_subsys_start(); - if (status != PJ_SUCCESS) + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); return status; + } #endif /* Perform NAT detection */ @@ -375,6 +388,7 @@ pj_status_t pjsua_media_subsys_start(void) PJ_PERROR(1,(THIS_FILE, status, "NAT type detection failed")); } + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -387,6 +401,7 @@ pj_status_t pjsua_media_subsys_destroy(void) unsigned i; PJ_LOG(4,(THIS_FILE, "Shutting down media..")); + pj_log_push_indent(); close_snd_dev(); @@ -451,6 +466,8 @@ pj_status_t pjsua_media_subsys_destroy(void) /* Reset RTP port */ next_rtp_port = 0; + pj_log_pop_indent(); + return PJ_SUCCESS; } @@ -1363,13 +1380,17 @@ pj_status_t pjsua_media_channel_init(pjsua_call_id call_id, if (pjsua_get_state() != PJSUA_STATE_RUNNING) return PJ_EBUSY; + PJ_LOG(4,(THIS_FILE, "Call %d: initializing media..", call_id)); + pj_log_push_indent(); + #if DISABLED_FOR_TICKET_1185 /* Return error if media transport has not been created yet * (e.g. application is starting) */ for (i=0; imed_cnt; ++i) { if (call->media[i].tp == NULL) { - return PJ_EBUSY; + status = PJ_EBUSY; + goto on_error; } } #endif @@ -1385,7 +1406,8 @@ pj_status_t pjsua_media_channel_init(pjsua_call_id call_id, /* Expecting audio in the offer */ if (sip_err_code) *sip_err_code = PJSIP_SC_NOT_ACCEPTABLE_HERE; pjsua_media_channel_deinit(call_id); - return PJSIP_ERRNO_FROM_SIP_STATUS(PJSIP_SC_NOT_ACCEPTABLE_HERE); + status = PJSIP_ERRNO_FROM_SIP_STATUS(PJSIP_SC_NOT_ACCEPTABLE_HERE); + goto on_error; } #if PJMEDIA_HAS_VIDEO @@ -1425,7 +1447,8 @@ pj_status_t pjsua_media_channel_init(pjsua_call_id call_id, /* Expecting at least one media */ if (sip_err_code) *sip_err_code = PJSIP_SC_NOT_ACCEPTABLE_HERE; pjsua_media_channel_deinit(call_id); - return PJSIP_ERRNO_FROM_SIP_STATUS(PJSIP_SC_NOT_ACCEPTABLE_HERE); + status = PJSIP_ERRNO_FROM_SIP_STATUS(PJSIP_SC_NOT_ACCEPTABLE_HERE); + goto on_error; } /* Initialize each media line */ @@ -1462,7 +1485,7 @@ pj_status_t pjsua_media_channel_init(pjsua_call_id call_id, security_level, sip_err_code); if (status != PJ_SUCCESS) { pjsua_media_channel_deinit(call_id); - return status; + goto on_error; } } else { /* By convention, the media is disabled if transport is NULL @@ -1500,14 +1523,19 @@ pj_status_t pjsua_media_channel_init(pjsua_call_id call_id, if (status != PJ_SUCCESS) { if (sip_err_code) *sip_err_code = PJSIP_SC_NOT_ACCEPTABLE; pjsua_media_channel_deinit(call_id); - return status; + goto on_error; } call_med->tp_st = PJSUA_MED_TP_INIT; } } + pj_log_pop_indent(); return PJ_SUCCESS; + +on_error: + pj_log_pop_indent(); + return status; } pj_status_t pjsua_media_channel_create_sdp(pjsua_call_id call_id, @@ -1790,6 +1818,8 @@ static void stop_media_session(pjsua_call_id call_id) pjsua_call *call = &pjsua_var.calls[call_id]; unsigned mi; + pj_log_push_indent(); + for (mi=0; mimed_cnt; ++mi) { pjsua_call_media *call_med = &call->media[mi]; @@ -1838,6 +1868,8 @@ static void stop_media_session(pjsua_call_id call_id) call_id, mi)); call_med->state = PJSUA_CALL_MEDIA_NONE; } + + pj_log_pop_indent(); } pj_status_t pjsua_media_channel_deinit(pjsua_call_id call_id) @@ -1845,6 +1877,9 @@ pj_status_t pjsua_media_channel_deinit(pjsua_call_id call_id) pjsua_call *call = &pjsua_var.calls[call_id]; unsigned mi; + PJ_LOG(4,(THIS_FILE, "Call %d: deinitializing media..", call_id)); + pj_log_push_indent(); + stop_media_session(call_id); for (mi=0; mimed_cnt; ++mi) { @@ -1868,6 +1903,7 @@ pj_status_t pjsua_media_channel_deinit(pjsua_call_id call_id) } check_snd_dev_idle(); + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -1881,6 +1917,8 @@ static void dtmf_callback(pjmedia_stream *strm, void *user_data, { PJ_UNUSED_ARG(strm); + pj_log_push_indent(); + /* For discussions about call mutex protection related to this * callback, please see ticket #460: * http://trac.pjsip.org/repos/ticket/460#comment:4 @@ -1891,6 +1929,8 @@ static void dtmf_callback(pjmedia_stream *strm, void *user_data, call_id = (pjsua_call_id)(long)user_data; pjsua_var.ua_cfg.cb.on_dtmf_digit(call_id, digit); } + + pj_log_pop_indent(); } @@ -1904,11 +1944,14 @@ static pj_status_t audio_channel_update(pjsua_call_media *call_med, pjmedia_port *media_port; unsigned strm_idx = call_med->idx; pj_status_t status; + + PJ_LOG(4,(THIS_FILE,"Audio channel update..")); + pj_log_push_indent(); status = pjmedia_stream_info_from_sdp(si, tmp_pool, pjsua_var.med_endpt, local_sdp, remote_sdp, strm_idx); if (status != PJ_SUCCESS) - return status; + goto on_return; /* Check if no media is active */ if (si->dir == PJMEDIA_DIR_NONE) { @@ -1926,7 +1969,7 @@ static pj_status_t audio_channel_update(pjsua_call_media *call_med, tmp_pool, local_sdp, remote_sdp, strm_idx); if (status != PJ_SUCCESS) - return status; + goto on_return; call_med->tp_st = PJSUA_MED_TP_RUNNING; @@ -1991,13 +2034,13 @@ static pj_status_t audio_channel_update(pjsua_call_media *call_med, call_med->tp, NULL, &call_med->strm.a.stream); if (status != PJ_SUCCESS) { - return status; + goto on_return; } /* Start stream */ status = pjmedia_stream_start(call_med->strm.a.stream); if (status != PJ_SUCCESS) { - return status; + goto on_return; } /* If DTMF callback is installed by application, install our @@ -2045,7 +2088,7 @@ static pj_status_t audio_channel_update(pjsua_call_media *call_med, (unsigned*) &call_med->strm.a.conf_slot); if (status != PJ_SUCCESS) { - return status; + goto on_return; } } @@ -2092,10 +2135,12 @@ static pj_status_t audio_channel_update(pjsua_call_media *call_med, dir); if (len > 0) info_len += len; - PJ_LOG(4,(THIS_FILE,"Media updates%s", info)); + PJ_LOG(4,(THIS_FILE,"Audio updated%s", info)); } - return PJ_SUCCESS; +on_return: + pj_log_pop_indent(); + return status; } pj_status_t pjsua_media_channel_update(pjsua_call_id call_id, @@ -2120,6 +2165,9 @@ pj_status_t pjsua_media_channel_update(pjsua_call_id call_id, if (pjsua_get_state() != PJSUA_STATE_RUNNING) return PJ_EBUSY; + PJ_LOG(4,(THIS_FILE, "Call %d: updating media..", call_id)); + pj_log_push_indent(); + /* Destroy existing media session, if any. */ stop_media_session(call->index); @@ -2182,7 +2230,8 @@ pj_status_t pjsua_media_channel_update(pjsua_call_id call_id, /* Something is wrong */ PJ_LOG(1,(THIS_FILE, "Error updating media for call %d: " "invalid media index %d in SDP", call_id, mi)); - return PJMEDIA_SDP_EINSDP; + status = PJMEDIA_SDP_EINSDP; + goto on_error; #endif } @@ -2235,18 +2284,23 @@ pj_status_t pjsua_media_channel_update(pjsua_call_id call_id, status = pjmedia_sdp_neg_set_remote_offer(tmp_pool, neg, remote_sdp); if (status != PJ_SUCCESS) - return status; + goto on_error; status = pjmedia_sdp_neg_set_local_answer(tmp_pool, neg, local_sdp); if (status != PJ_SUCCESS) - return status; + goto on_error; status = pjmedia_sdp_neg_negotiate(tmp_pool, neg, 0); if (status != PJ_SUCCESS) - return status; + goto on_error; } + pj_log_pop_indent(); return (got_media? PJ_SUCCESS : PJMEDIA_SDPNEG_ENOMEDIA); + +on_error: + pj_log_pop_indent(); + return status; } /* @@ -2357,6 +2411,13 @@ PJ_DEF(pj_status_t) pjsua_conf_remove_port(pjsua_conf_port_id id) PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, pjsua_conf_port_id sink) { + pj_status_t status = PJ_SUCCESS; + + PJ_LOG(4,(THIS_FILE, "%s connect: %d --> %d", + (pjsua_var.is_mswitch ? "Switch" : "Conf"), + source, sink)); + pj_log_push_indent(); + /* If sound device idle timer is active, cancel it first. */ PJSUA_LOCK(); if (pjsua_var.snd_idle_timer.id) { @@ -2377,7 +2438,6 @@ PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, pjmedia_conf_port_info peer_info; unsigned peer_id; pj_bool_t need_reopen = PJ_FALSE; - pj_status_t status; peer_id = (source!=0)? source : sink; status = pjmedia_conf_get_port_info(pjsua_var.mconf, peer_id, @@ -2419,7 +2479,7 @@ PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error opening sound device", status); - return status; + goto on_return; } /* And peer format */ @@ -2433,7 +2493,7 @@ PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error opening sound device", status); - return status; + goto on_return; } } else { /* Null-audio */ @@ -2442,7 +2502,7 @@ PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error opening sound device", status); - return status; + goto on_return; } } } else if (pjsua_var.no_snd) { @@ -2467,7 +2527,7 @@ PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, status = pjsua_set_snd_dev(pjsua_var.cap_dev, pjsua_var.play_dev); if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Error opening sound device", status); - return status; + goto on_return; } } else if (pjsua_var.no_snd && !pjsua_var.snd_is_on) { pjsua_var.snd_is_on = PJ_TRUE; @@ -2478,7 +2538,11 @@ PJ_DEF(pj_status_t) pjsua_conf_connect( pjsua_conf_port_id source, } } - return pjmedia_conf_connect_port(pjsua_var.mconf, source, sink, 0); + status = pjmedia_conf_connect_port(pjsua_var.mconf, source, sink, 0); + +on_return: + pj_log_pop_indent(); + return status; } @@ -2490,9 +2554,15 @@ PJ_DEF(pj_status_t) pjsua_conf_disconnect( pjsua_conf_port_id source, { pj_status_t status; + PJ_LOG(4,(THIS_FILE, "%s disconnect: %d -x- %d", + (pjsua_var.is_mswitch ? "Switch" : "Conf"), + source, sink)); + pj_log_push_indent(); + status = pjmedia_conf_disconnect_port(pjsua_var.mconf, source, sink); check_snd_dev_idle(); + pj_log_pop_indent(); return status; } @@ -2558,13 +2628,17 @@ PJ_DEF(pj_status_t) pjsua_player_create( const pj_str_t *filename, { unsigned slot, file_id; char path[PJ_MAXPATH]; - pj_pool_t *pool; + pj_pool_t *pool = NULL; pjmedia_port *port; - pj_status_t status; + pj_status_t status = PJ_SUCCESS; if (pjsua_var.player_cnt >= PJ_ARRAY_SIZE(pjsua_var.player)) return PJ_ETOOMANY; + PJ_LOG(4,(THIS_FILE, "Creating file player: %.*s..", + (int)filename->slen, filename->ptr)); + pj_log_push_indent(); + PJSUA_LOCK(); for (file_id=0; file_idptr, filename->slen); @@ -2584,8 +2658,8 @@ PJ_DEF(pj_status_t) pjsua_player_create( const pj_str_t *filename, pool = pjsua_pool_create(get_basename(path, filename->slen), 1000, 1000); if (!pool) { - PJSUA_UNLOCK(); - return PJ_ENOMEM; + status = PJ_ENOMEM; + goto on_error; } status = pjmedia_wav_player_port_create( @@ -2595,21 +2669,17 @@ PJ_DEF(pj_status_t) pjsua_player_create( const pj_str_t *filename, pjsua_var.media_cfg.clock_rate, options, 0, &port); if (status != PJ_SUCCESS) { - PJSUA_UNLOCK(); pjsua_perror(THIS_FILE, "Unable to open file for playback", status); - pj_pool_release(pool); - return status; + goto on_error; } status = pjmedia_conf_add_port(pjsua_var.mconf, pool, port, filename, &slot); if (status != PJ_SUCCESS) { pjmedia_port_destroy(port); - PJSUA_UNLOCK(); pjsua_perror(THIS_FILE, "Unable to add file to conference bridge", status); - pj_pool_release(pool); - return status; + goto on_error; } pjsua_var.player[file_id].type = 0; @@ -2622,7 +2692,17 @@ PJ_DEF(pj_status_t) pjsua_player_create( const pj_str_t *filename, ++pjsua_var.player_cnt; PJSUA_UNLOCK(); + + PJ_LOG(4,(THIS_FILE, "Player created, id=%d, slot=%d", file_id, slot)); + + pj_log_pop_indent(); return PJ_SUCCESS; + +on_error: + PJSUA_UNLOCK(); + if (pool) pj_pool_release(pool); + pj_log_pop_indent(); + return status; } @@ -2637,13 +2717,16 @@ PJ_DEF(pj_status_t) pjsua_playlist_create( const pj_str_t file_names[], pjsua_player_id *p_id) { unsigned slot, file_id, ptime; - pj_pool_t *pool; + pj_pool_t *pool = NULL; pjmedia_port *port; - pj_status_t status; + pj_status_t status = PJ_SUCCESS; if (pjsua_var.player_cnt >= PJ_ARRAY_SIZE(pjsua_var.player)) return PJ_ETOOMANY; + PJ_LOG(4,(THIS_FILE, "Creating playlist with %d file(s)..", file_count)); + pj_log_push_indent(); + PJSUA_LOCK(); for (file_id=0; file_idinfo.name, &slot); if (status != PJ_SUCCESS) { pjmedia_port_destroy(port); - PJSUA_UNLOCK(); pjsua_perror(THIS_FILE, "Unable to add port", status); - pj_pool_release(pool); - return status; + goto on_error; } pjsua_var.player[file_id].type = 1; @@ -2698,8 +2777,19 @@ PJ_DEF(pj_status_t) pjsua_playlist_create( const pj_str_t file_names[], ++pjsua_var.player_cnt; PJSUA_UNLOCK(); + + PJ_LOG(4,(THIS_FILE, "Playlist created, id=%d, slot=%d", file_id, slot)); + + pj_log_pop_indent(); + return PJ_SUCCESS; +on_error: + PJSUA_UNLOCK(); + if (pool) pj_pool_release(pool); + pj_log_pop_indent(); + + return status; } @@ -2752,6 +2842,9 @@ PJ_DEF(pj_status_t) pjsua_player_destroy(pjsua_player_id id) PJ_ASSERT_RETURN(id>=0&&id<(int)PJ_ARRAY_SIZE(pjsua_var.player), PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.player[id].port != NULL, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Destroying player %d..", id)); + pj_log_push_indent(); + PJSUA_LOCK(); if (pjsua_var.player[id].port) { @@ -2765,6 +2858,7 @@ PJ_DEF(pj_status_t) pjsua_player_destroy(pjsua_player_id id) } PJSUA_UNLOCK(); + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -2795,9 +2889,9 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, char path[PJ_MAXPATH]; pj_str_t ext; int file_format; - pj_pool_t *pool; + pj_pool_t *pool = NULL; pjmedia_port *port; - pj_status_t status; + pj_status_t status = PJ_SUCCESS; /* Filename must present */ PJ_ASSERT_RETURN(filename != NULL, PJ_EINVAL); @@ -2808,8 +2902,14 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, /* Don't support encoding type at present */ PJ_ASSERT_RETURN(enc_type == 0, PJ_EINVAL); - if (pjsua_var.rec_cnt >= PJ_ARRAY_SIZE(pjsua_var.recorder)) + PJ_LOG(4,(THIS_FILE, "Creating recorder %.*s..", + (int)filename->slen, filename->ptr)); + pj_log_push_indent(); + + if (pjsua_var.rec_cnt >= PJ_ARRAY_SIZE(pjsua_var.recorder)) { + pj_log_pop_indent(); return PJ_ETOOMANY; + } /* Determine the file format */ ext.ptr = filename->ptr + filename->slen - 4; @@ -2823,6 +2923,7 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, PJ_LOG(1,(THIS_FILE, "pjsua_recorder_create() error: unable to " "determine file format for %.*s", (int)filename->slen, filename->ptr)); + pj_log_pop_indent(); return PJ_ENOTSUP; } @@ -2835,9 +2936,9 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, if (file_id == PJ_ARRAY_SIZE(pjsua_var.recorder)) { /* This is unexpected */ - PJSUA_UNLOCK(); pj_assert(0); - return PJ_EBUG; + status = PJ_EBUG; + goto on_return; } pj_memcpy(path, filename->ptr, filename->slen); @@ -2845,8 +2946,8 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, pool = pjsua_pool_create(get_basename(path, filename->slen), 1000, 1000); if (!pool) { - PJSUA_UNLOCK(); - return PJ_ENOMEM; + status = PJ_ENOMEM; + goto on_return; } if (file_format == FMT_WAV) { @@ -2863,19 +2964,15 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, } if (status != PJ_SUCCESS) { - PJSUA_UNLOCK(); pjsua_perror(THIS_FILE, "Unable to open file for recording", status); - pj_pool_release(pool); - return status; + goto on_return; } status = pjmedia_conf_add_port(pjsua_var.mconf, pool, port, filename, &slot); if (status != PJ_SUCCESS) { pjmedia_port_destroy(port); - PJSUA_UNLOCK(); - pj_pool_release(pool); - return status; + goto on_return; } pjsua_var.recorder[file_id].port = port; @@ -2887,7 +2984,17 @@ PJ_DEF(pj_status_t) pjsua_recorder_create( const pj_str_t *filename, ++pjsua_var.rec_cnt; PJSUA_UNLOCK(); + + PJ_LOG(4,(THIS_FILE, "Recorder created, id=%d, slot=%d", file_id, slot)); + + pj_log_pop_indent(); return PJ_SUCCESS; + +on_return: + PJSUA_UNLOCK(); + if (pool) pj_pool_release(pool); + pj_log_pop_indent(); + return status; } @@ -2927,6 +3034,9 @@ PJ_DEF(pj_status_t) pjsua_recorder_destroy(pjsua_recorder_id id) PJ_EINVAL); PJ_ASSERT_RETURN(pjsua_var.recorder[id].port != NULL, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Destroying recorder %d..", id)); + pj_log_push_indent(); + PJSUA_LOCK(); if (pjsua_var.recorder[id].port) { @@ -2940,6 +3050,7 @@ PJ_DEF(pj_status_t) pjsua_recorder_destroy(pjsua_recorder_id id) } PJSUA_UNLOCK(); + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -3147,11 +3258,12 @@ static pj_status_t open_snd_dev(pjmedia_snd_port_param *param) param->base.clock_rate, param->base.channel_count, param->base.samples_per_frame / param->base.channel_count * 1000 / param->base.clock_rate)); + pj_log_push_indent(); status = pjmedia_snd_port_create2( pjsua_var.snd_pool, param, &pjsua_var.snd_port); if (status != PJ_SUCCESS) - return status; + goto on_error; /* Get the port0 of the conference bridge. */ conf_port = pjmedia_conf_get_master_port(pjsua_var.mconf); @@ -3188,7 +3300,7 @@ static pj_status_t open_snd_dev(pjmedia_snd_port_param *param) "Error creating resample port: %s", errmsg)); close_snd_dev(); - return status; + goto on_error; } conf_port = resample_port; @@ -3217,7 +3329,7 @@ static pj_status_t open_snd_dev(pjmedia_snd_port_param *param) "sound device", status); pjmedia_snd_port_destroy(pjsua_var.snd_port); pjsua_var.snd_port = NULL; - return status; + goto on_error; } /* Save the device IDs */ @@ -3255,7 +3367,7 @@ static pj_status_t open_snd_dev(pjmedia_snd_port_param *param) /* Any error is not major, let it through */ status = PJ_SUCCESS; - }; + } /* If this is the first time the audio device is open, retrieve some * settings from the device (such as volume settings) so that the @@ -3266,13 +3378,20 @@ static pj_status_t open_snd_dev(pjmedia_snd_port_param *param) ++pjsua_var.aud_open_cnt; } + pj_log_pop_indent(); return PJ_SUCCESS; + +on_error: + pj_log_pop_indent(); + return status; } /* Close existing sound device */ static void close_snd_dev(void) { + pj_log_push_indent(); + /* Notify app */ if (pjsua_var.snd_is_on && pjsua_var.ua_cfg.cb.on_snd_dev_operation) { (*pjsua_var.ua_cfg.cb.on_snd_dev_operation)(0); @@ -3312,6 +3431,8 @@ static void close_snd_dev(void) pj_pool_release(pjsua_var.snd_pool); pjsua_var.snd_pool = NULL; pjsua_var.snd_is_on = PJ_FALSE; + + pj_log_pop_indent(); } @@ -3327,9 +3448,15 @@ PJ_DEF(pj_status_t) pjsua_set_snd_dev( int capture_dev, unsigned i; pj_status_t status = -1; + PJ_LOG(4,(THIS_FILE, "Set sound device: capture=%d, playback=%d", + capture_dev, playback_dev)); + pj_log_push_indent(); + /* Null-sound */ if (capture_dev==NULL_SND_DEV_ID && playback_dev==NULL_SND_DEV_ID) { - return pjsua_set_null_snd_dev(); + status = pjsua_set_null_snd_dev(); + pj_log_pop_indent(); + return status; } /* Set default clock rate */ @@ -3360,7 +3487,7 @@ PJ_DEF(pj_status_t) pjsua_set_snd_dev( int capture_dev, alt_cr[i], pjsua_var.media_cfg.channel_count, samples_per_frame, 16); if (status != PJ_SUCCESS) - return status; + goto on_error; /* Open! */ param.options = 0; @@ -3371,13 +3498,18 @@ PJ_DEF(pj_status_t) pjsua_set_snd_dev( int capture_dev, if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to open sound device", status); - return status; + goto on_error; } pjsua_var.no_snd = PJ_FALSE; pjsua_var.snd_is_on = PJ_TRUE; + pj_log_pop_indent(); return PJ_SUCCESS; + +on_error: + pj_log_pop_indent(); + return status; } @@ -3408,6 +3540,10 @@ PJ_DEF(pj_status_t) pjsua_set_null_snd_dev(void) pjmedia_port *conf_port; pj_status_t status; + PJ_LOG(4,(THIS_FILE, "Setting null sound device..")); + pj_log_push_indent(); + + /* Close existing sound device */ close_snd_dev(); @@ -3434,6 +3570,7 @@ PJ_DEF(pj_status_t) pjsua_set_null_snd_dev(void) if (status != PJ_SUCCESS) { pjsua_perror(THIS_FILE, "Unable to create null sound device", status); + pj_log_pop_indent(); return status; } @@ -3447,6 +3584,7 @@ PJ_DEF(pj_status_t) pjsua_set_null_snd_dev(void) pjsua_var.no_snd = PJ_FALSE; pjsua_var.snd_is_on = PJ_TRUE; + pj_log_pop_indent(); return PJ_SUCCESS; } 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(); } diff --git a/pjsip/src/pjsua-lib/pjsua_vid.c b/pjsip/src/pjsua-lib/pjsua_vid.c index c45002d2..8af4bfbb 100644 --- a/pjsip/src/pjsua-lib/pjsua_vid.c +++ b/pjsip/src/pjsua-lib/pjsua_vid.c @@ -36,32 +36,35 @@ pj_status_t pjsua_vid_subsys_init(void) unsigned i; pj_status_t status; + PJ_LOG(4,(THIS_FILE, "Initializing video subsystem..")); + pj_log_push_indent(); + status = pjmedia_video_format_mgr_create(pjsua_var.pool, 64, 0, NULL); if (status != PJ_SUCCESS) { PJ_PERROR(1,(THIS_FILE, status, "Error creating PJMEDIA video format manager")); - return status; + goto on_error; } status = pjmedia_converter_mgr_create(pjsua_var.pool, NULL); if (status != PJ_SUCCESS) { PJ_PERROR(1,(THIS_FILE, status, "Error creating PJMEDIA converter manager")); - return status; + goto on_error; } status = pjmedia_vid_codec_mgr_create(pjsua_var.pool, NULL); if (status != PJ_SUCCESS) { PJ_PERROR(1,(THIS_FILE, status, "Error creating PJMEDIA video codec manager")); - return status; + goto on_error; } status = pjmedia_vid_dev_subsys_init(&pjsua_var.cp.factory); if (status != PJ_SUCCESS) { PJ_PERROR(1,(THIS_FILE, status, "Error creating PJMEDIA video subsystem")); - return status; + goto on_error; } #if PJMEDIA_HAS_VIDEO && PJMEDIA_HAS_FFMPEG_CODEC @@ -69,19 +72,26 @@ pj_status_t pjsua_vid_subsys_init(void) if (status != PJ_SUCCESS) { PJ_PERROR(1,(THIS_FILE, status, "Error initializing ffmpeg library")); - return status; + goto on_error; } #endif for (i=0; ivp_cap) { pjmedia_vid_port_stop(w->vp_cap); pjmedia_vid_port_disconnect(w->vp_cap); @@ -473,6 +501,8 @@ static void free_vid_win(pjsua_vid_win_id wid) pjmedia_port_destroy(w->tee); } pjsua_vid_win_reset(wid); + + pj_log_pop_indent(); } @@ -513,10 +543,13 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, unsigned strm_idx = call_med->idx; pj_status_t status; + PJ_LOG(4,(THIS_FILE, "Video channel update..")); + pj_log_push_indent(); + status = pjmedia_vid_stream_info_from_sdp(si, tmp_pool, pjsua_var.med_endpt, local_sdp, remote_sdp, strm_idx); if (status != PJ_SUCCESS) - return status; + goto on_error; /* Check if no media is active */ if (si->dir == PJMEDIA_DIR_NONE) { @@ -534,7 +567,7 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, tmp_pool, local_sdp, remote_sdp, strm_idx); if (status != PJ_SUCCESS) - return status; + goto on_error; call_med->tp_st = PJSUA_MED_TP_RUNNING; @@ -591,7 +624,7 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, status = pjmedia_vid_dev_get_info(call_med->strm.v.cap_dev, &dev_info); if (status != PJ_SUCCESS) - return status; + goto on_error; /* Find matched format ID */ for (i = 0; i < codec_info->dec_fmt_id_cnt; ++i) { @@ -616,12 +649,12 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, call_med->tp, NULL, &call_med->strm.v.stream); if (status != PJ_SUCCESS) - return status; + goto on_error; /* Start stream */ status = pjmedia_vid_stream_start(call_med->strm.v.stream); if (status != PJ_SUCCESS) - return status; + goto on_error; /* Setup decoding direction */ if (si->dir & PJMEDIA_DIR_DECODING) @@ -629,11 +662,16 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, pjsua_vid_win_id wid; pjsua_vid_win *w; + PJ_LOG(4,(THIS_FILE, "Setting up RX..")); + pj_log_push_indent(); + status = pjmedia_vid_stream_get_port(call_med->strm.v.stream, PJMEDIA_DIR_DECODING, &media_port); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Create stream video window */ status = create_vid_win(PJSUA_WND_TYPE_STREAM, @@ -643,8 +681,10 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, PJSUA_INVALID_ID, acc->cfg.vid_in_auto_show, &wid); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } w = &pjsua_var.win[wid]; @@ -658,17 +698,22 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, /* Connect renderer to stream */ status = pjmedia_vid_port_connect(w->vp_rend, media_port, PJ_FALSE); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Start renderer */ status = pjmedia_vid_port_start(w->vp_rend); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Done */ inc_vid_win(wid); call_med->strm.v.rdr_win_id = wid; + pj_log_pop_indent(); } /* Setup encoding direction */ @@ -677,11 +722,16 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, pjsua_vid_win *w; pjsua_vid_win_id wid; + PJ_LOG(4,(THIS_FILE, "Setting up TX..")); + pj_log_push_indent(); + status = pjmedia_vid_stream_get_port(call_med->strm.v.stream, PJMEDIA_DIR_ENCODING, &media_port); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Create preview video window */ status = create_vid_win(PJSUA_WND_TYPE_PREVIEW, @@ -692,8 +742,10 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, //acc->cfg.vid_cap_dev, PJ_FALSE, &wid); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } w = &pjsua_var.win[wid]; #if ENABLE_EVENT @@ -704,22 +756,29 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, /* Connect stream to capturer (via video window tee) */ status = pjmedia_vid_tee_add_dst_port2(w->tee, 0, media_port); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Start renderer */ status = pjmedia_vid_port_start(w->vp_rend); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Start capturer */ status = pjmedia_vid_port_start(w->vp_cap); - if (status != PJ_SUCCESS) - return status; + if (status != PJ_SUCCESS) { + pj_log_pop_indent(); + goto on_error; + } /* Done */ inc_vid_win(wid); call_med->strm.v.cap_win_id = wid; + pj_log_pop_indent(); } /* Call media direction */ @@ -765,17 +824,22 @@ pj_status_t video_channel_update(pjsua_call_media *call_med, dir); if (len > 0) info_len += len; - PJ_LOG(4,(THIS_FILE,"Media updates%s", info)); + PJ_LOG(4,(THIS_FILE,"Video updated%s", info)); } if (!acc->cfg.vid_out_auto_transmit && call_med->strm.v.stream) { status = pjmedia_vid_stream_pause(call_med->strm.v.stream, PJMEDIA_DIR_ENCODING); if (status != PJ_SUCCESS) - return status; + goto on_error; } + pj_log_pop_indent(); return PJ_SUCCESS; + +on_error: + pj_log_pop_indent(); + return status; } @@ -790,6 +854,9 @@ void stop_video_stream(pjsua_call_media *call_med) if (!strm) return; + PJ_LOG(4,(THIS_FILE, "Stopping video stream..")); + pj_log_push_indent(); + /* Unsubscribe events */ pjmedia_event_unsubscribe(&call_med->esub_rend); pjmedia_event_unsubscribe(&call_med->esub_cap); @@ -831,6 +898,8 @@ void stop_video_stream(pjsua_call_media *call_med) pjmedia_vid_stream_destroy(strm); call_med->strm.v.stream = NULL; + + pj_log_pop_indent(); } @@ -846,19 +915,24 @@ PJ_DEF(pj_status_t) pjsua_vid_preview_start(pjmedia_vid_dev_index id, pjsua_vid_preview_param default_param; pj_status_t status; - PJSUA_LOCK(); - if (!prm) { pjsua_vid_preview_param_default(&default_param); prm = &default_param; } + PJ_LOG(4,(THIS_FILE, "Starting preview for cap_dev=%d, show=%d", + id, prm->show)); + pj_log_push_indent(); + + PJSUA_LOCK(); + rend_id = prm->rend_id; status = create_vid_win(PJSUA_WND_TYPE_PREVIEW, NULL, rend_id, id, prm->show, &wid); if (status != PJ_SUCCESS) { PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } @@ -868,6 +942,7 @@ PJ_DEF(pj_status_t) pjsua_vid_preview_start(pjmedia_vid_dev_index id, status = pjmedia_vid_port_start(w->vp_rend); if (status != PJ_SUCCESS) { PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } @@ -875,12 +950,14 @@ PJ_DEF(pj_status_t) pjsua_vid_preview_start(pjmedia_vid_dev_index id, status = pjmedia_vid_port_start(w->vp_cap); if (status != PJ_SUCCESS) { PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } inc_vid_win(wid); PJSUA_UNLOCK(); + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -891,16 +968,21 @@ PJ_DEF(pj_status_t) pjsua_vid_preview_stop(pjmedia_vid_dev_index id) { pjsua_vid_win_id wid = PJSUA_INVALID_ID; + PJ_LOG(4,(THIS_FILE, "Stopping preview for cap_dev=%d", id)); + pj_log_push_indent(); + PJSUA_LOCK(); wid = pjsua_vid_preview_get_win(id); if (wid == PJSUA_INVALID_ID) { PJSUA_UNLOCK(); + pj_log_pop_indent(); return PJ_ENOTFOUND; } dec_vid_win(wid); PJSUA_UNLOCK(); + pj_log_pop_indent(); return PJ_SUCCESS; } @@ -1580,6 +1662,10 @@ PJ_DEF(pj_status_t) pjsua_call_set_vid_strm ( PJ_EINVAL); PJ_ASSERT_RETURN(op != PJSUA_CALL_VID_STRM_NO_OP, PJ_EINVAL); + PJ_LOG(4,(THIS_FILE, "Call %d: set video stream, op=%d", + call_id, op)); + pj_log_push_indent(); + PJSUA_LOCK(); call = &pjsua_var.calls[call_id]; @@ -1635,6 +1721,7 @@ PJ_DEF(pj_status_t) pjsua_call_set_vid_strm ( } PJSUA_UNLOCK(); + pj_log_pop_indent(); return status; } -- cgit v1.2.3