From df474867ccf5a75d0d1ddc8348877c4250103350 Mon Sep 17 00:00:00 2001 From: Donat Zenichev Date: Thu, 10 Apr 2025 14:51:13 +0200 Subject: [PATCH] MT#62253 log: AmSipDialog: add call-id based logging Introduce usage of `ILOG_DLG()` Change-Id: I16f08674c9dbccf11a2f2755c94fb980b195c585 --- core/AmSipDialog.cpp | 80 +++++++++++++++++++++++--------------------- 1 file changed, 41 insertions(+), 39 deletions(-) diff --git a/core/AmSipDialog.cpp b/core/AmSipDialog.cpp index 3e6685db..b3d42dbc 100644 --- a/core/AmSipDialog.cpp +++ b/core/AmSipDialog.cpp @@ -41,6 +41,8 @@ #include "global_defs.h" +#define GET_CALL_ID() (getCallid().c_str()) + // // helper functions // @@ -230,12 +232,12 @@ bool AmSipDialog::oaExpectingOffer() { } void AmSipDialog::setRel100State(Am100rel::State rel100_state) { - DBG("setting 100rel state for '%s' to %i\n", local_tag.c_str(), rel100_state); + ILOG_DLG(L_DBG, "setting 100rel state for '%s' to %i\n", local_tag.c_str(), rel100_state); rel100.setState(rel100_state); } void AmSipDialog::setOAEnabled(bool oa_enabled) { - DBG("%sabling offer_answer on SIP dialog '%s'\n", + ILOG_DLG(L_DBG, "%sabling offer_answer on SIP dialog '%s'\n", oa_enabled?"en":"dis", local_tag.c_str()); offeranswer_enabled = oa_enabled; } @@ -277,7 +279,7 @@ int AmSipDialog::onTxReply(const AmSipRequest& req, AmSipReply& reply, int& flag /* if generated by OA, save it */ if (!sdp_body.empty()) { - DBG("OA generated an SDP body, saving as established_body.\n"); + ILOG_DLG(L_DBG, "OA generated an SDP body, saving as established_body.\n"); established_body = sdp_body; } } @@ -296,7 +298,7 @@ int AmSipDialog::onTxReply(const AmSipRequest& req, AmSipReply& reply, int& flag (reply.code < 200) ) { // refuse local provisional replies // when state is Cancelling - ERROR("refuse local provisional replies when state is Cancelling\n"); + ILOG_DLG(L_ERR, "refuse local provisional replies when state is Cancelling\n"); return -1; } // else continue with final @@ -393,7 +395,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) Dialog established only by 101-199 or 2xx responses to INVITE */ - DBG("onRxReplyStatus: reply.code = <%d>, reply.route = <%s>, status = <%d>\n", + ILOG_DLG(L_DBG, "onRxReplyStatus: reply.code = <%d>, reply.route = <%s>, status = <%d>\n", reply.code, reply.route.c_str(), status); /* INVITE */ @@ -404,7 +406,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) case Trying: case Proceeding: - DBG("This is the Proceeding stage of the dialog.\n"); + ILOG_DLG(L_DBG, "This is the Proceeding stage of the dialog.\n"); /* 100-199 */ if (reply.code < 200) { @@ -421,7 +423,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) /* we should always keep Route set for this leg updated in case the provisional response updates the list of routes for any reason */ if ((reply.code == 180 || reply.code == 183) && !reply.route.empty()) { - DBG("<%d> Response code is processed, reset the Route set for the leg.\n", + ILOG_DLG(L_DBG, "<%d> Response code is processed, reset the Route set for the leg.\n", reply.code); setRouteSet(reply.route); } @@ -439,13 +441,13 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) - play-last-caller - office-hours */ if (reply.code == 183 && getForcedEarlyAnnounce()) { - DBG("This is 183 with <;%s=%s>, treated exceptionally as 200OK.\n", DSM_PARAM_EARLY_AN, DSM_VALUE_FORCE); + ILOG_DLG(L_DBG, "This is 183 with <;%s=%s>, treated exceptionally as 200OK.\n", DSM_PARAM_EARLY_AN, DSM_VALUE_FORCE); setStatus(Connected); setFaked183As200(true); /* remember that this is a faked 200OK, indeed 183 */ if (reply.to_tag.empty()) { - DBG("received 2xx reply without to-tag (callid=%s): sending BYE\n", + ILOG_DLG(L_DBG, "received 2xx reply without to-tag (callid=%s): sending BYE\n", reply.callid.c_str()); sendRequest(SIP_METH_BYE); } else { @@ -459,7 +461,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) setRouteSet(reply.route); if (reply.to_tag.empty()){ - DBG("received 2xx reply without to-tag (callid=%s): sending BYE\n", + ILOG_DLG(L_DBG, "received 2xx reply without to-tag (callid=%s): sending BYE\n", reply.callid.c_str()); send_200_ack(reply.cseq); sendRequest(SIP_METH_BYE); @@ -476,7 +478,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) case Early: - DBG("This is the Early stage of the dialog.\n"); + ILOG_DLG(L_DBG, "This is the Early stage of the dialog.\n"); /* 100-199 */ if (reply.code < 200) { @@ -486,7 +488,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) /* we should always keep Route set for this leg updated in case the provisional response updates the list of routes for any reason */ if ((reply.code == 180 || reply.code == 183) && !reply.route.empty()) { - DBG("<%d> Response code is processed, reset the Route set for the leg.\n", + ILOG_DLG(L_DBG, "<%d> Response code is processed, reset the Route set for the leg.\n", reply.code); setRouteSet(reply.route); } @@ -504,13 +506,13 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) - play-last-caller - office-hours */ if (reply.code == 183 && getForcedEarlyAnnounce()) { - DBG("This is 183 with <;%s=%s>, treated exceptionally as 200OK.\n", DSM_PARAM_EARLY_AN, DSM_VALUE_FORCE); + ILOG_DLG(L_DBG, "This is 183 with <;%s=%s>, treated exceptionally as 200OK.\n", DSM_PARAM_EARLY_AN, DSM_VALUE_FORCE); setStatus(Connected); setFaked183As200(true); /* remember that this is a faked 200OK, indeed 183 */ if (reply.to_tag.empty()) { - DBG("received 2xx reply without to-tag (callid=%s): sending BYE\n", + ILOG_DLG(L_DBG, "received 2xx reply without to-tag (callid=%s): sending BYE\n", reply.callid.c_str()); sendRequest(SIP_METH_BYE); } else { @@ -528,7 +530,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) setFaked183As200(false); if (reply.to_tag.empty()) { - DBG("received 2xx reply without to-tag (callid=%s): sending BYE\n", + ILOG_DLG(L_DBG, "received 2xx reply without to-tag (callid=%s): sending BYE\n", reply.callid.c_str()); sendRequest(SIP_METH_BYE); } else { @@ -546,11 +548,11 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) case Cancelling: if (reply.code >= 300) { /* CANCEL accepted */ - DBG("CANCEL accepted, status -> Disconnected\n"); + ILOG_DLG(L_DBG, "CANCEL accepted, status -> Disconnected\n"); setStatus(Disconnected); } else if(reply.code < 300) { /* CANCEL rejected */ - DBG("CANCEL rejected/too late - bye()\n"); + ILOG_DLG(L_DBG, "CANCEL rejected/too late - bye()\n"); setRemoteTag(reply.to_tag); setStatus(Connected); bye(); @@ -564,7 +566,7 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) * -> ACK + BYE (+absorb answer) */ case Connected: - DBG("This is the Connected stage of the dialog.\n"); + ILOG_DLG(L_DBG, "This is the Connected stage of the dialog.\n"); /* treat 4XX class of responses for the faked connected state of the dlg * as those which finilize a DSM playback (check additionally P-DSM-App header) @@ -586,17 +588,17 @@ bool AmSipDialog::onRxReplyStatus(const AmSipReply& reply) /* do not update call leg status for transactions not involving INVITE. * In this case just update the to-tag and route set */ if (!reply.to_tag.empty()) { - DBG("Updating remote tag (to tag) to: '%s'.\n", reply.to_tag.c_str()); + ILOG_DLG(L_DBG, "Updating remote tag (to tag) to: '%s'.\n", reply.to_tag.c_str()); setRemoteTag(reply.to_tag); } if (!reply.route.empty()) { - DBG("Updating route set to: '%s'.\n", reply.route.c_str()); + ILOG_DLG(L_DBG, "Updating route set to: '%s'.\n", reply.route.c_str()); setRouteSet(reply.route); } } if (status == Disconnecting || status == Cancelling) { - DBG("%s: cseq_method = %s; code = %i\n", + ILOG_DLG(L_DBG, "%s: cseq_method = %s; code = %i\n", status == Disconnecting ? "Disconnecting" : "Cancelling", reply.cseq_method.c_str(), reply.code); @@ -636,7 +638,7 @@ void AmSipDialog::uasTimeout(AmSipTimeoutEvent* to_ev) switch(to_ev->type){ case AmSipTimeoutEvent::noACK: - DBG("Timeout: missing ACK\n"); + ILOG_DLG(L_DBG, "Timeout: missing ACK\n"); if (offeranswer_enabled) { oa.onNoAck(to_ev->cseq); } @@ -644,7 +646,7 @@ void AmSipDialog::uasTimeout(AmSipTimeoutEvent* to_ev) break; case AmSipTimeoutEvent::noPRACK: - DBG("Timeout: missing PRACK\n"); + ILOG_DLG(L_DBG, "Timeout: missing PRACK\n"); rel100.onTimeout(to_ev->req, to_ev->rpl); break; @@ -747,7 +749,7 @@ int AmSipDialog::bye(const string& hdrs, int flags) /* missing AmSipRequest to be able * to send the reply on behalf of the app. */ - ERROR("ignoring bye() in %s state: " + ILOG_DLG(L_ERR, "ignoring bye() in %s state: " "no UAC transaction to cancel or UAS transaction to reply.\n", getStatusStr()); setStatus(Disconnected); @@ -767,12 +769,12 @@ int AmSipDialog::bye(const string& hdrs, int flags) /* missing AmSipRequest to be able * to send the reply on behalf of the app. */ - DBG("ignoring bye() in %s state: no UAS transaction to reply", getStatusStr()); + ILOG_DLG(L_DBG, "ignoring bye() in %s state: no UAS transaction to reply", getStatusStr()); setStatus(Disconnected); return 0; default: - DBG("bye(): we are not connected " + ILOG_DLG(L_DBG, "bye(): we are not connected " "(status=%s). do nothing!\n", getStatusStr()); return 0; } @@ -786,7 +788,7 @@ int AmSipDialog::reinvite(const string& hdrs, return sendRequest(SIP_METH_INVITE, body, hdrs, flags); } else { - DBG("reinvite(): we are not connected " + ILOG_DLG(L_DBG, "reinvite(): we are not connected " "(status=%s). do nothing!\n",getStatusStr()); } @@ -798,12 +800,12 @@ int AmSipDialog::invite(const string& hdrs, { if(getStatus() == Disconnected) { int res = sendRequest(SIP_METH_INVITE, body, hdrs); - DBG("TODO: is status already 'trying'? status=%s\n",getStatusStr()); + ILOG_DLG(L_DBG, "TODO: is status already 'trying'? status=%s\n",getStatusStr()); //status = Trying; return res; } else { - DBG("invite(): we are already connected " + ILOG_DLG(L_DBG, "invite(): we are already connected " "(status=%s). do nothing!\n",getStatusStr()); } @@ -815,7 +817,7 @@ int AmSipDialog::update(const AmMimeBody* body, { switch(getStatus()){ case Connected://if Connected, we should send a re-INVITE instead... - DBG("re-INVITE should be used instead (see RFC3311, section 5.1)\n"); + ILOG_DLG(L_DBG, "re-INVITE should be used instead (see RFC3311, section 5.1)\n"); case Trying: case Proceeding: case Early: @@ -825,7 +827,7 @@ int AmSipDialog::update(const AmMimeBody* body, case Cancelling: case Disconnected: case Disconnecting: - DBG("update(): dialog not connected " + ILOG_DLG(L_DBG, "update(): dialog not connected " "(status=%s). do nothing!\n",getStatusStr()); } @@ -846,7 +848,7 @@ int AmSipDialog::refer(const string& refer_to, return sendRequest("REFER", NULL, hdrs); } else { - DBG("refer(): we are not Connected." + ILOG_DLG(L_DBG, "refer(): we are not Connected." "(status=%s). do nothing!\n",getStatusStr()); return 0; @@ -858,7 +860,7 @@ int AmSipDialog::info(const string& hdrs, const AmMimeBody* body) if(getStatus() == Connected) { return sendRequest("INFO", body, hdrs); } else { - DBG("info(): we are not Connected." + ILOG_DLG(L_DBG, "info(): we are not Connected." "(status=%s). do nothing!\n", getStatusStr()); return 0; } @@ -896,7 +898,7 @@ int AmSipDialog::transfer(const string& target) return ret; } - DBG("transfer(): we are not connected " + ILOG_DLG(L_DBG, "transfer(): we are not connected " "(status=%i). do nothing!\n",status); return 0; @@ -915,10 +917,10 @@ int AmSipDialog::prack(const AmSipReply &reply1xx, break; case Disconnected: case Disconnecting: - ERROR("can not send PRACK while dialog is in state '%d'.\n", status); + ILOG_DLG(L_ERR, "can not send PRACK while dialog is in state '%d'.\n", status); return -1; default: - ERROR("BUG: unexpected dialog state '%d'.\n", status); + ILOG_DLG(L_ERR, "BUG: unexpected dialog state '%d'.\n", status); return -1; } string h = hdrs + @@ -942,13 +944,13 @@ int AmSipDialog::cancel() t->first, t->second.hdrs); } else { - ERROR("INVITE transaction has already been cancelled\n"); + ILOG_DLG(L_ERR, "INVITE transaction has already been cancelled\n"); return -1; } } } - ERROR("could not find INVITE transaction to cancel\n"); + ILOG_DLG(L_ERR, "could not find INVITE transaction to cancel\n"); return -1; } @@ -972,7 +974,7 @@ int AmSipDialog::send_200_ack(unsigned int inv_cseq, TransMap::iterator inv_it = uac_trans.find(inv_cseq); if (inv_it == uac_trans.end()) { - ERROR("trying to ACK a non-existing transaction (cseq=%i;local_tag=%s)\n", + ILOG_DLG(L_ERR, "trying to ACK a non-existing transaction (cseq=%i;local_tag=%s)\n", inv_cseq,local_tag.c_str()); return -1; }