<p>keith <strong>merged</strong> this change.</p><p><a href="https://gerrit.osmocom.org/c/osmo-sip-connector/+/15078">View Change</a></p><div style="white-space:pre-wrap">Approvals:
Jenkins Builder: Verified
laforge: Looks good to me, but someone else must approve
pespin: Looks good to me, approved
</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">Logging: Make use of Levels, clarify some messages<br><br>Up to now most logging is on LDEBUG, lets make more use of Log Levels.<br>reserve NOTICE for unusual events<br>INFO: normal call setup/teardown<br>DEBUG, well.. it's DEBUG<br><br>* BYE is not an Error.<br>* 4XX or 5XX response to INVITE is not an Error don't log as such.<br>* 183 does not necessarily mean "ringing".<br>Change those log messages for clarity.<br><br>Change-Id: Ie0014043d93303a87cbb8bb351e439ff78651cbe<br>---<br>M src/mncc.c<br>M src/sip.c<br>2 files changed, 20 insertions(+), 20 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/src/mncc.c b/src/mncc.c</span><br><span>index d8545da..739f50b 100644</span><br><span>--- a/src/mncc.c</span><br><span>+++ b/src/mncc.c</span><br><span>@@ -422,7 +422,7 @@</span><br><span> /* TODO.. now we can continue with the call */</span><br><span> struct in_addr net = { .s_addr = leg->base.ip };</span><br><span> inet_ntop(AF_INET, &net, ip_addr, sizeof(ip_addr));</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DMNCC, LOGL_DEBUG,</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DMNCC, LOGL_INFO,</span><br><span> "RTP continue leg(%u) ip(%s), port(%u) pt(%u) ptm(%u)\n",</span><br><span> leg->callref, ip_addr, leg->base.port,</span><br><span> leg->base.payload_type, leg->base.payload_msg_type);</span><br><span>@@ -515,7 +515,7 @@</span><br><span> memcpy(&leg->calling, &data->calling, sizeof(leg->calling));</span><br><span> memcpy(&leg->imsi, data->imsi, sizeof(leg->imsi));</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DMNCC, LOGL_DEBUG,</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DMNCC, LOGL_INFO,</span><br><span> "Created call(%u) with MNCC leg(%u) IMSI(%.16s)\n",</span><br><span> call->id, leg->callref, data->imsi);</span><br><span> </span><br><span>@@ -624,7 +624,7 @@</span><br><span> if (!leg)</span><br><span> return;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DMNCC, LOGL_NOTICE, "leg(%u) is now connected.\n", leg->callref);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DMNCC, LOGL_INFO, "leg(%u) is now connected.\n", leg->callref);</span><br><span> stop_cmd_timer(leg, MNCC_SETUP_COMPL_IND);</span><br><span> leg->state = MNCC_CC_CONNECTED;</span><br><span> }</span><br><span>diff --git a/src/sip.c b/src/sip.c</span><br><span>index 327e90f..103eb33 100644</span><br><span>--- a/src/sip.c</span><br><span>+++ b/src/sip.c</span><br><span>@@ -76,7 +76,7 @@</span><br><span> if (status == 183)</span><br><span> sdp_extract_sdp(leg, sip, false);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "leg(%p) is now ringing.\n", leg);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "leg(%p) is now progressing.\n", leg);</span><br><span> other->ring_call(other);</span><br><span> }</span><br><span> </span><br><span>@@ -98,7 +98,7 @@</span><br><span> return;</span><br><span> }</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "leg(%p) is now connected(%s).\n", leg, sip->sip_call_id->i_id);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "leg(%p) is now connected(%s).\n", leg, sip->sip_call_id->i_id);</span><br><span> leg->state = SIP_CC_CONNECTED;</span><br><span> other->connect_call(other);</span><br><span> nua_ack(leg->nua_handle, TAG_END());</span><br><span>@@ -112,7 +112,7 @@</span><br><span> const char *from = NULL, *to = NULL;</span><br><span> char ip_addr[INET_ADDRSTRLEN];</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_DEBUG, "Incoming call(%s) handle(%p)\n", sip->sip_call_id->i_id, nh);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "Incoming call(%s) handle(%p)\n", sip->sip_call_id->i_id, nh);</span><br><span> </span><br><span> if (!sdp_screen_sdp(sip)) {</span><br><span> LOGP(DSIP, LOGL_ERROR, "No supported codec.\n");</span><br><span>@@ -161,7 +161,7 @@</span><br><span> }</span><br><span> struct in_addr net = { .s_addr = leg->base.ip };</span><br><span> inet_ntop(AF_INET, &net, ip_addr, sizeof(ip_addr));</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_DEBUG, "SDP Extracted: IP=(%s) PORT=(%u) PAYLOAD=(%u).\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "SDP Extracted: IP=(%s) PORT=(%u) PAYLOAD=(%u).\n",</span><br><span> ip_addr,</span><br><span> leg->base.port,</span><br><span> leg->base.payload_type);</span><br><span>@@ -190,7 +190,7 @@</span><br><span> uint16_t port = leg->base.port;</span><br><span> char ip_addr[INET_ADDRSTRLEN];</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "re-INVITE for call %s\n", sip->sip_call_id->i_id);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "re-INVITE for call %s\n", sip->sip_call_id->i_id);</span><br><span> </span><br><span> struct call_leg *other = call_leg_other(&leg->base);</span><br><span> if (!sdp_get_sdp_mode(sip, &mode)) {</span><br><span>@@ -209,7 +209,7 @@</span><br><span> </span><br><span> struct in_addr net = { .s_addr = leg->base.ip };</span><br><span> inet_ntop(AF_INET, &net, ip_addr, sizeof(ip_addr));</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "pre re-INVITE have IP:port (%s:%u)\n", ip_addr, leg->base.port);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_DEBUG, "pre re-INVITE have IP:port (%s:%u)\n", ip_addr, leg->base.port);</span><br><span> </span><br><span> if (mode == sdp_sendonly) {</span><br><span> /* SIP side places call on HOLD */</span><br><span>@@ -226,9 +226,9 @@</span><br><span> }</span><br><span> struct in_addr net = { .s_addr = leg->base.ip };</span><br><span> inet_ntop(AF_INET, &net, ip_addr, sizeof(ip_addr));</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "Media IP:port in re-INVITE: (%s:%u)\n", ip_addr, leg->base.port);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_DEBUG, "Media IP:port in re-INVITE: (%s:%u)\n", ip_addr, leg->base.port);</span><br><span> if (ip != leg->base.ip || port != leg->base.port) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "re-INVITE changes media connection.\n");</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "re-INVITE changes media connection.\n");</span><br><span> if (other->update_rtp)</span><br><span> other->update_rtp(leg->base.call->remote);</span><br><span> }</span><br><span>@@ -343,13 +343,13 @@</span><br><span> else if (status >= 300) {</span><br><span> struct call_leg *other = call_leg_other(&leg->base);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_ERROR, "leg(%p) unknown SIP status(%d), releasing.\n", leg, status);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "INVITE got status(%d), releasing leg(%p).\n", status, leg);</span><br><span> nua_cancel(leg->nua_handle, TAG_END());</span><br><span> nua_handle_destroy(leg->nua_handle);</span><br><span> call_leg_release(&leg->base);</span><br><span> </span><br><span> if (other) {</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_DEBUG, "Releasing other leg (%p) with status(%d)\n", other, status);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "Releasing MNCC leg (%p) with status(%d)\n", other, status);</span><br><span> other->cause = status2cause(status);</span><br><span> other->release_call(other);</span><br><span> }</span><br><span>@@ -365,7 +365,7 @@</span><br><span> } else if (event == nua_r_bye || event == nua_r_cancel) {</span><br><span> /* our bye or hang up is answered */</span><br><span> struct sip_call_leg *leg = (struct sip_call_leg *) hmagic;</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "leg(%p) got resp to %s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "leg(%p) got resp to %s\n",</span><br><span> leg, event == nua_r_bye ? "bye" : "cancel");</span><br><span> nua_handle_destroy(leg->nua_handle);</span><br><span> call_leg_release(&leg->base);</span><br><span>@@ -374,7 +374,7 @@</span><br><span> struct sip_call_leg *leg = (struct sip_call_leg *) hmagic;</span><br><span> struct call_leg *other = call_leg_other(&leg->base);</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_ERROR, "leg(%p) got bye, releasing.\n", leg);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "leg(%p) got bye, releasing.\n", leg);</span><br><span> nua_handle_destroy(leg->nua_handle);</span><br><span> call_leg_release(&leg->base);</span><br><span> </span><br><span>@@ -382,7 +382,7 @@</span><br><span> other->release_call(other);</span><br><span> } else if (event == nua_i_invite) {</span><br><span> /* new incoming leg or re-INVITE */</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "Processing INVITE Call-ID: %s\n", sip->sip_call_id->i_id);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "Processing INVITE Call-ID: %s\n", sip->sip_call_id->i_id);</span><br><span> </span><br><span> if (status == 100) {</span><br><span> struct sip_call_leg *leg = sip_find_leg(nh);</span><br><span>@@ -395,7 +395,7 @@</span><br><span> struct sip_call_leg *leg;</span><br><span> struct call_leg *other;</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_ERROR, "Cancelled on leg(%p)\n", hmagic);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "Cancelled on leg(%p)\n", hmagic);</span><br><span> </span><br><span> leg = (struct sip_call_leg *) hmagic;</span><br><span> other = call_leg_other(&leg->base);</span><br><span>@@ -447,18 +447,18 @@</span><br><span> * to help us here.</span><br><span> */</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_DEBUG, "%s(): Release with MNCC cause(%s)\n", __func__, gsm48_cc_cause_name(_leg->cause));</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "%s(): Release with MNCC cause(%s)\n", __func__, gsm48_cc_cause_name(_leg->cause));</span><br><span> cause2status(_leg->cause, &sip_cause, &sip_phrase, &reason_text);</span><br><span> snprintf(reason, sizeof reason, "Q.850;cause=%u;text=\"%s\"", _leg->cause, reason_text);</span><br><span> </span><br><span> switch (leg->state) {</span><br><span> case SIP_CC_INITIAL:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "Cancelling leg(%p) in initial state\n", leg);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "Cancelling leg(%p) in initial state\n", leg);</span><br><span> nua_handle_destroy(leg->nua_handle);</span><br><span> call_leg_release(&leg->base);</span><br><span> break;</span><br><span> case SIP_CC_DLG_CNFD:</span><br><span style="color: hsl(0, 100%, 40%);">- LOGP(DSIP, LOGL_NOTICE, "Cancelling leg(%p) in confirmed state\n", leg);</span><br><span style="color: hsl(120, 100%, 40%);">+ LOGP(DSIP, LOGL_INFO, "Cancelling leg(%p) in confirmed state\n", leg);</span><br><span> if (leg->dir == SIP_DIR_MT)</span><br><span> nua_cancel(leg->nua_handle, TAG_END());</span><br><span> else {</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.osmocom.org/c/osmo-sip-connector/+/15078">change 15078</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.osmocom.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.osmocom.org/c/osmo-sip-connector/+/15078"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: osmo-sip-connector </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-Change-Id: Ie0014043d93303a87cbb8bb351e439ff78651cbe </div>
<div style="display:none"> Gerrit-Change-Number: 15078 </div>
<div style="display:none"> Gerrit-PatchSet: 3 </div>
<div style="display:none"> Gerrit-Owner: keith <keith@rhizomatica.org> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder </div>
<div style="display:none"> Gerrit-Reviewer: keith <keith@rhizomatica.org> </div>
<div style="display:none"> Gerrit-Reviewer: laforge <laforge@gnumonks.org> </div>
<div style="display:none"> Gerrit-Reviewer: pespin <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-CC: fixeria <axilirator@gmail.com> </div>
<div style="display:none"> Gerrit-MessageType: merged </div>