Module: sems Branch: master Commit: 5bd402c8bdc530ab607b13ebb17636b42bfb5b25 URL: http://git.sip-router.org/cgi-bin/gitweb.cgi/sems/?a=commit;h=5bd402c8bdc530ab607b13ebb17636b42bfb5b25
Author: Stefan Sayer <[email protected]> Committer: Stefan Sayer <[email protected]> Date: Fri Feb 11 13:17:21 2011 +0100 unified and cleaned up debug log SIP message processing and Session event processing are now enclosed in blocks with the form vv <type> [<callid>|<ltag>] ... vv ^^ <type> [<callid>|<ltag>] ... ^^ where <type> = M SIP message processing <type> = S Session event processing --- core/AmB2BSession.cpp | 10 +++++----- core/AmSession.cpp | 16 +++++++++++----- core/AmSessionProcessor.cpp | 14 +++----------- core/AmSipDispatcher.cpp | 8 +++++--- core/SipCtrlInterface.cpp | 7 +++++++ core/sip/sip_parser.cpp | 2 +- core/sip/udp_trsp.cpp | 3 ++- core/sip/wheeltimer.cpp | 2 +- 8 files changed, 35 insertions(+), 27 deletions(-) diff --git a/core/AmB2BSession.cpp b/core/AmB2BSession.cpp index d49cfe3..e0d7696 100644 --- a/core/AmB2BSession.cpp +++ b/core/AmB2BSession.cpp @@ -212,9 +212,9 @@ void AmB2BSession::onSipReply(const AmSipReply& reply, TransMap::iterator t = relayed_req.find(reply.cseq); bool fwd = (t != relayed_req.end()) && (reply.code != 100); - DBG("onSipReply: %s -> %i %s (fwd=%s)\n", - trans_method.c_str(), reply.code,reply.reason.c_str(),fwd?"true":"false"); - DBG("onSipReply: content-type = %s\n",reply.content_type.c_str()); + DBG("onSipReply: %s -> %i %s (fwd=%s), c-t=%s\n", + trans_method.c_str(), reply.code,reply.reason.c_str(),fwd?"true":"false", + reply.content_type.c_str()); if(fwd) { updateRefreshMethod(reply.hdrs); @@ -254,7 +254,7 @@ void AmB2BSession::onInvite2xx(const AmSipReply& reply) int AmB2BSession::relayEvent(AmEvent* ev) { - DBG("AmB2BSession::relayEvent: id=%s\n", + DBG("AmB2BSession::relayEvent: to other_id='%s'\n", other_id.c_str()); if(!other_id.empty()) { @@ -370,7 +370,7 @@ bool AmB2BSession::refresh(int flags) { if (dlg.getStatus() != AmSipDialog::Connected) return false; - DBG(" *** AmB2BSession::refresh *** \n"); + DBG(" AmB2BSession::refresh: refreshing session\n"); // not in B2B mode if (other_id.empty() || // UPDATE as refresh handled like normal session diff --git a/core/AmSession.cpp b/core/AmSession.cpp index a149db9..3b67c14 100644 --- a/core/AmSession.cpp +++ b/core/AmSession.cpp @@ -427,9 +427,8 @@ bool AmSession::processEventsCatchExceptions() { this should be called until it returns false. */ bool AmSession::processingCycle() { - DBG("%s/%s vv %c, %s, %s, %i UACTransPending\n", + DBG("vv S [%s|%s] %s, %s, %i UACTransPending vv\n", dlg.callid.c_str(),getLocalTag().c_str(), - processing_status == SESSION_PROCESSING_EVENTS ? 'P':'W', AmSipDialog::status2str[dlg.getStatus()], sess_stopped.get()?"stopped":"running", dlg.getUACTransPending()); @@ -446,9 +445,8 @@ bool AmSession::processingCycle() { int dlg_status = dlg.getStatus(); bool s_stopped = sess_stopped.get(); - DBG("%s/%s ^^ %c, %s, %s, %i UACTransPending\n", + DBG("^^ S [%s|%s] %s, %s, %i UACTransPending ^^\n", dlg.callid.c_str(),getLocalTag().c_str(), - processing_status == SESSION_PROCESSING_EVENTS ? 'P':'W', AmSipDialog::status2str[dlg_status], s_stopped?"stopped":"running", dlg.getUACTransPending()); @@ -489,9 +487,17 @@ bool AmSession::processingCycle() { processing_status = SESSION_ENDED_DISCONNECTED; return false; // exception occured, stop processing } + bool res = dlg.getStatus() != AmSipDialog::Disconnected; if (!res) processing_status = SESSION_ENDED_DISCONNECTED; + + DBG("^^ S [%s|%s] %s, %s, %i UACTransPending ^^\n", + dlg.callid.c_str(),getLocalTag().c_str(), + AmSipDialog::status2str[dlg.getStatus()], + sess_stopped.get()?"stopped":"running", + dlg.getUACTransPending()); + return res; }; break; @@ -639,7 +645,7 @@ void AmSession::process(AmEvent* ev) { CALL_EVENT_H(process,ev); - DBG("AmSession::process\n"); + DBG("AmSession processing event\n"); if (ev->event_id == E_SYSTEM) { AmSystemEvent* sys_ev = dynamic_cast<AmSystemEvent*>(ev); diff --git a/core/AmSessionProcessor.cpp b/core/AmSessionProcessor.cpp index 97c00ed..400fb06 100644 --- a/core/AmSessionProcessor.cpp +++ b/core/AmSessionProcessor.cpp @@ -108,9 +108,6 @@ void AmSessionProcessorThread::run() { events.processEvents(); // startup all new sessions - DBG("startup_sessions.size() == %zd [%p]\n", - startup_sessions.size(), &startup_sessions); - if (!startup_sessions.empty()) { DBG("starting up %zd sessions\n", startup_sessions.size()); @@ -118,8 +115,8 @@ void AmSessionProcessorThread::run() { startup_sessions.begin(); it != startup_sessions.end(); it++) { - DBG("starting up [%p/ltag %s]\n", - *it, (*it)->getLocalTag().c_str()); + DBG("starting up [%s|%s]: [%p]\n", + (*it)->getCallID().c_str(), (*it)->getLocalTag().c_str(),*it); if ((*it)->startup()) { sessions.push_back(*it); // startup successful // make sure this session is being processed for startup events @@ -132,7 +129,7 @@ void AmSessionProcessorThread::run() { std::vector<AmSession*> fin_sessions; - DBG("processing events for <=%zd sessions\n", + DBG("processing events for up to %zd sessions\n", pending_process_sessions.size()); std::list<AmSession*>::iterator it=sessions.begin(); @@ -176,12 +173,7 @@ void AmSessionProcessorThread::process(AmEvent* e) { return; } - DBG("scheduling session [%p/%s] for startup\n", - add_ev->s, add_ev->s->getCallID().c_str()); startup_sessions.push_back(add_ev->s); - - DBG("%zd sessions waiting for startup [%p]\n", - startup_sessions.size(), &startup_sessions); } void AmSessionProcessorThread::startSession(AmSession* s) { diff --git a/core/AmSipDispatcher.cpp b/core/AmSipDispatcher.cpp index 84c7ddc..0745c31 100644 --- a/core/AmSipDispatcher.cpp +++ b/core/AmSipDispatcher.cpp @@ -43,14 +43,15 @@ AmSipDispatcher* AmSipDispatcher::instance() void AmSipDispatcher::handleSipMsg(AmSipReply &reply) { AmSipReplyEvent* ev = new AmSipReplyEvent(reply); + if(!AmEventDispatcher::instance()->post(reply.local_tag,ev)){ if ((reply.code >= 100) && (reply.code < 300)) { if (AmConfig::UnhandledReplyLoglevel >= 0) { _LOG(AmConfig::UnhandledReplyLoglevel, - "unhandled prov/positive reply: %s\n", reply.print().c_str()); + "unhandled SIP reply: %s\n", reply.print().c_str()); } } else { - ERROR("unhandled reply: %s\n", reply.print().c_str()); + ERROR("unhandled SIP reply: %s\n", reply.print().c_str()); } delete ev; } @@ -75,7 +76,8 @@ void AmSipDispatcher::handleSipMsg(AmSipRequest &req) "Call leg/Transaction does not exist"); } else { - ERROR("received ACK for non-existing dialog (callid=%s;remote_tag=%s;local_tag=%s)\n", + ERROR("received ACK for non-existing dialog " + "(callid=%s;remote_tag=%s;local_tag=%s)\n", callid.c_str(),remote_tag.c_str(),local_tag.c_str()); } } diff --git a/core/SipCtrlInterface.cpp b/core/SipCtrlInterface.cpp index 576e866..dd829a8 100644 --- a/core/SipCtrlInterface.cpp +++ b/core/SipCtrlInterface.cpp @@ -570,6 +570,9 @@ void SipCtrlInterface::handle_sip_request(const trans_ticket& tt, sip_msg* msg) } AmSipDispatcher::instance()->handleSipMsg(req); + + DBG("^^ M [%s|%s] Ru SIP request %s handled ^^\n", + req.callid.c_str(), req.to_tag.c_str(), req.method.c_str()); } void SipCtrlInterface::handle_sip_reply(sip_msg* msg) @@ -589,6 +592,10 @@ void SipCtrlInterface::handle_sip_reply(sip_msg* msg) DBG("cseq = <%i>\n",reply.cseq); AmSipDispatcher::instance()->handleSipMsg(reply); + + DBG("^^ M [%s|%s] ru SIP reply %u %s handled ^^\n", + reply.callid.c_str(), reply.local_tag.c_str(), + reply.code, reply.reason.c_str()); } void SipCtrlInterface::handle_reply_timeout(AmSipTimeoutEvent::EvType evt, diff --git a/core/sip/sip_parser.cpp b/core/sip/sip_parser.cpp index 29fcffc..fbcb2c5 100644 --- a/core/sip/sip_parser.cpp +++ b/core/sip/sip_parser.cpp @@ -94,7 +94,7 @@ sip_msg::sip_msg() sip_msg::~sip_msg() { - DBG("~sip_msg()\n"); + // DBG("~sip_msg()\n"); delete [] buf; diff --git a/core/sip/udp_trsp.cpp b/core/sip/udp_trsp.cpp index 6e7243f..d6e9d78 100644 --- a/core/sip/udp_trsp.cpp +++ b/core/sip/udp_trsp.cpp @@ -208,7 +208,8 @@ void udp_trsp::run() if (SipCtrlInterface::log_raw_messages >= 0) { _LOG(SipCtrlInterface::log_raw_messages, - "recvd msg\n--++--\n%.*s--++--\n", s_msg->len, s_msg->buf); + "vv M [|] u recvd msg via UDP vv\n--++--\n%.*s--++--\n", + s_msg->len, s_msg->buf); } memcpy(&s_msg->remote_ip,msg.msg_name,msg.msg_namelen); diff --git a/core/sip/wheeltimer.cpp b/core/sip/wheeltimer.cpp index 3330455..0fee595 100644 --- a/core/sip/wheeltimer.cpp +++ b/core/sip/wheeltimer.cpp @@ -39,7 +39,7 @@ timer::~timer() { - DBG("timer::~timer(this=%p)\n",this); + // DBG("timer::~timer(this=%p)\n",this); } _wheeltimer::_wheeltimer() _______________________________________________ Semsdev mailing list [email protected] http://lists.iptel.org/mailman/listinfo/semsdev
