[Users] OpenSer Sending CANCEL after receiving 200 OK for a INVITE - sr-users

7 Dec 2006


      Hello Everyone,
I am facing a problem when I am trying  to send calls from my Openser(1.1.0)
to another
sip switch "MERA MSIP v.1.0.2."
Here is the senario:
openser( PublicIP 54.15.32.44)  <====>  Mera Sip Switch(PublicIP
52.132.36.43)
=======================               ==========================
              INVITE               ------------------>
                                       <-----------------    100 Trying
                                       <-----------------    183 Session
Progress
                                       <-----------------    200 OK (for
invite)
              CANCEL            ------------------->
                                       <-----------------    200 OK (for
cancel)
                                       <-----------------    487 Request
Terminated
               ACK                 ------------------->
This seems quite normal senario but prolem is that this "CANCEL" is not
generated by the
end point (in mycase IP Phone in public IP). This "CANCEL" generated from
openser just after receiving the 200 OK of INVITE request.
Why openser generateing a CANCEL while it already received 200 OK for that
INVITE??
Here is my openser configuration script: openser.cfg
===================Script Begin===========================
# USE THIS VERSION IS REGISTER
# ----------- global configuration parameters ------------------------
debug=3         # debug level (cmd line: -dddddddddd)
fork=yes
log_stderror=no    # (cmd line: -E)
/* Uncomment these lines to enter debugging mode
fork=no
log_stderror=yes
*/
log_facility=LOG_LOCAL0
listen=54.15.32.44
alias="sip.myfone.com"
check_via=no    # (cmd. line: -v)
dns=no           # (cmd. line: -r)
rev_dns=no      # (cmd. line: -R)
port=5060
children=4
fifo="/tmp/openser_fifo"
# ------------------ module loading ----------------------------------
mpath="/usr/local/openser/lib/openser/modules/"
# Uncomment this if you want to use SQL database
#loadmodule "mysql.so"
loadmodule "exec.so"
loadmodule "sl.so"
loadmodule "tm.so"
loadmodule "rr.so"
loadmodule "maxfwd.so"
loadmodule "usrloc.so"
loadmodule "registrar.so"
loadmodule "textops.so"
loadmodule "xlog.so"
loadmodule "auth.so"
loadmodule "auth_radius.so"
loadmodule "acc.so"
loadmodule "nathelper.so"
# ----------------- setting module-specific parameters ---------------
# -- usrloc params --
modparam("usrloc", "db_mode",   0)
# -- rr params --
# add value to ;lr param to make some broken UAs happy
modparam("rr", "enable_full_lr", 1)
#modparam("rr", "enable_double_rr", 1)
# For fail over
# -- tm params --
# set time for which ser will be waiting for a final response;
# fr_inv_timer sets value for INVITE transactions, fr_timer
# for all others
modparam("tm", "fr_inv_timer", 60 )
modparam("tm", "fr_timer", 30 )
#for Radius Accounting
modparam("acc", "radius_flag", 1 )
modparam("acc", "radius_missed_flag", 3 )
# !! Nathelper
modparam("registrar", "nat_flag", 6)
modparam("nathelper", "natping_interval", 30) # Ping interval 30 s
modparam("nathelper", "ping_nated_only", 1)   # Ping only clients behind NAT
## Just for Fun,It shows color Log
modparam("xlog", "force_color", 1)
# -------------------------  request routing logic -------------------
# main routing logic
route{
    if (!mf_process_maxfwd_header("10")) {
        sl_send_reply("483","Too Many Hops");
        exit;
    };
    if (msg:len >=  2048 ) {
        sl_send_reply("513", "Message too big");
        exit;
    };
route(2);
if (!method=="REGISTER")
        record_route();
if(method=="INVITE" || method=="BYE")
            setflag(1);
if (loose_route()) {
        append_hf("P-hint: rr-enforced\r\n");
        route(1);
    };
if (!uri==myself) {
        append_hf("P-hint: outbound\r\n");
        route(1);
    };
#This is the best place for rewrite host port
if (!method=="REGISTER") {
            rewritehostport("52.132.36.43:5060");
        };
if (uri==myself) {
        if (method=="REGISTER") {
if (!radius_www_authorize("54.15.32.44")) {
                        www_challenge("54.15.32.44", "0");
                               exit;
                    };
if (isflagset(5)) {
                setflag(6);
                # if you want OPTIONS natpings uncomment next
                # setflag(7);
            };
            save("location");
            exit;
        };
if (!lookup("location")) {
            sl_send_reply("404", "Not Found");
            exit;
        };
        append_hf("P-hint: usrloc applied\r\n");
    };
route(1);
}
route[1] {
    if (subst_uri('/(sip:.*);nat=yes/\1/')){
        setflag(6);
    };
if (isflagset(5)||isflagset(6)) {
        route(3);
    }
if (!t_relay()) {
        sl_reply_error();
    };
    exit;
}
route[2]{
    force_rport();
    if (nat_uac_test("19")) {
        if (method=="REGISTER") {
            fix_nated_register();
        } else {
            fix_nated_contact();
        };
        setflag(5);
    };
if (method=="INVITE") {
        xlog("L_INFO", "Invite -> [CallerID=$fu] and [DialedNo=$tU]\n");
                if(uri=~"sip:[0-9]{20,}@.+")
                {
                        sl_send_reply("513", "Message too big");
                        exit;
                };
if (!radius_www_authorize("54.15.32.44")) {
            www_challenge("54.15.32.44", "0");
            exit;
        };
        consume_credentials();
    };
}
route[3] {
    if (is_method("BYE|CANCEL")) {
        unforce_rtp_proxy();
    } else if (is_method("INVITE")){
#        xlog("L_INFO","Invite -> Force Rtp Proxy");
        if (!search("^Content-Length:[ ]*0"))
        {
            force_rtp_proxy();
        }
        t_on_failure("1");
    };
    if (isflagset(5))
        search_append('Contact:.*sip:[^>[:cntrl:]]*', ';nat=yes;lr=on');
t_on_reply("1");
}
failure_route[1] {
if(!t_was_cancelled())
    {
            rewritehostport("52.132.36.43:5060");
            xlog("L_INFO","Invite -> Fail Over Route 1  at Time [$Tf]");
            if (!search("^Content-Length:[ ]*0"))
            {
                force_rtp_proxy();
            }
t_on_failure("2");
            t_relay();
    }
}
failure_route[2] {
if(!t_was_cancelled())
   {
        rewritehostport("52.132.36.43:5060");
        xlog("L_INFO","Invite -> Fail Over Route 2  at Time [$Tf]");
        if (!search("^Content-Length:[ ]*0"))
        {
            force_rtp_proxy();
        }
t_on_failure("3");
        t_relay();
   }
}
failure_route[3] {
if(!t_was_cancelled())
   {
        rewritehostport("52.132.36.43:5060");
        xlog("L_INFO","Invite -> Fail Over Route 3  at Time [$Tf]");
        if (!search("^Content-Length:[ ]*0"))
        {
            force_rtp_proxy();
        }
t_on_failure("4");
        t_relay();
   }
}
failure_route[4] {
if(!t_was_cancelled())
   {
        rewritehostport("52.132.36.43:5060");
        xlog("L_INFO","Invite -> Fail Over Route 4  at Time [$Tf]");
        if (!search("^Content-Length:[ ]*0"))
        {
                force_rtp_proxy();
        }
t_on_failure("5");
        t_relay();
   }
}
failure_route[5] {
       if (isflagset(6) || isflagset(5)) {
               unforce_rtp_proxy();
       }
}
onreply_route[1] {
if (!search("^Content-Length:[ ]*0"))
        {
            force_rtp_proxy("r");
        }
search_append('Contact:.*sip:[^>[:cntrl:]]*', ';nat=yes');
if (isflagset(6)) {
        fix_nated_contact();
    }
exit;
}
==========================Script End======================
Here is the sip trace (from ngrep):
U IP Phone -> Openser
INVITE sip:9128222570841@54.15.32.44 SIP/2.0.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport.
Max-Forwards: 70.
User-Agent: PA168S V1.55.013 CFG0 .
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" sip:9128222570841@54.15.32.44.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
Contact: sip:561705239298@58.88.13.13:5060.
Authorization: Digest username="561705239298", realm="54.15.32.44",
nonce="4577de9a6e32a8fafc108687cbc9b520cfd2b1ea", uri="
sip:9128222570841@54.15.32.44", response="c18eeb314b2c5524ab3d7fe50b52851c",
algorithm=MD5.
CSeq: 2 INVITE.
Supported: replaces.
Content-Type: application/sdp.
Content-Length: 134.
.
v=0.
o=- 12369099 22311551 IN IP4 58.88.13.13.
s=SIP CALL.
c=IN IP4 58.88.13.13.
t=0 0.
m=audio 8704 RTP/AVP 4.
a=rtpmap:4 G723/8000.
#
U Openser -> IP PHONE
SIP/2.0 100 trying -- your call is important to us.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" sip:9128222570841@54.15.32.44.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Server: openser (1.1.0 (i386/linux)).
Content-Length: 0.
Warning: 392 54.15.32.44:5060 "Noisy feedback tells:  pid=27317 req_src_ip=
58.88.13.13 req_src_port=5060 in_uri=sip:9128222570841@54.15.32.44 out_uri=
sip:9128222570841@52.132.36.43:5060 via_cnt==1".
.
#
U Openser -> Mera
INVITE sip:9128222570841@52.132.36.43:5060 SIP/2.0.
Record-Route: sip:54.15.32.44;lr=on;ftag=1pRGOP6lOmlBFIxy.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.0.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
Max-Forwards: 69.
User-Agent: PA168S V1.55.013 CFG0 .
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" sip:9128222570841@54.15.32.44.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
Contact: sip:561705239298@58.88.13.13:5060.
CSeq: 2 INVITE.
Supported: replaces.
Content-Type: application/sdp.
Content-Length: 152.
.
v=0.
o=- 12369099 22311551 IN IP4 58.88.13.13.
s=SIP CALL.
c=IN IP4 54.15.32.44.
t=0 0.
m=audio 39780 RTP/AVP 4.
a=rtpmap:4 G723/8000.
a=nortpproxy:yes.
#
U Openser -> Mera
INVITE sip:9128222570841@52.132.36.43:5060 SIP/2.0.
Record-Route: sip:54.15.32.44;lr=on;ftag=1pRGOP6lOmlBFIxy.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
Max-Forwards: 69.
User-Agent: PA168S V1.55.013 CFG0 .
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" sip:9128222570841@54.15.32.44.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
Contact: sip:561705239298@58.88.13.13:5060.
CSeq: 2 INVITE.
Supported: replaces.
Content-Type: application/sdp.
Content-Length: 152.
.
v=0.
o=- 12369099 22311551 IN IP4 58.88.13.13.
s=SIP CALL.
c=IN IP4 54.15.32.44.
t=0 0.
m=audio 39780 RTP/AVP 4.
a=rtpmap:4 G723/8000.
a=nortpproxy:yes.
#
U Mera -> Openser
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.0,SIP/2.0/UDP
58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" sip:9128222570841@54.15.32.44.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Content-Length: 0.
.
#
U Mera -> Openser
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1,SIP/2.0/UDP
58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" sip:9128222570841@54.15.32.44.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Content-Length: 0.
.
#
U Mera -> Openser
SIP/2.0 183 Session Progress.
Record-Route: sip:52.132.36.43:5060;lr,sip:54.15.32.44
;lr=on;ftag=1pRGOP6lOmlBFIxy.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841@54.15.32.44
...
;tag=ffff1200ffff7710ff00000f1f6fff3b.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Server: MERA MSIP v.1.0.2.
Contact: sip:9128222570841@52.132.36.43:5060.
Content-Type: application/sdp.
Via: SIP/2.0/UDP 54.15.32.44:5060;branch=z9hG4bKa124.220e0023.0,SIP/2.0/UDP
58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
Content-Length: 136.
.
v=0.
o=- 1165483497 1165483497 IN IP4 52.132.36.43.
s=-.
c=IN IP4 52.132.36.43.
t=0 0.
m=audio 37548 RTP/AVP 4.
a=rtpmap:4 G723/8000.
.
#
U Openser  -> IP PHONE
SIP/2.0 183 Session Progress.
Record-Route: sip:52.132.36.43:5060;lr,sip:54.15.32.44
;lr=on;ftag=1pRGOP6lOmlBFIxy.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841@54.15.32.44
...
;tag=ffff1200ffff7710ff00000f1f6fff3b.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Server: MERA MSIP v.1.0.2.
Contact: sip:9128222570841@52.132.36.43:5060;nat=yes.
Content-Type: application/sdp.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
Content-Length: 153.
.
v=0.
o=- 1165483497 1165483497 IN IP4 52.132.36.43.
s=-.
c=IN IP4 54.15.32.44.
t=0 0.
m=audio 39784 RTP/AVP 4.
a=rtpmap:4 G723/8000.
.
a=nortpproxy:yes.
#
U Mera -> Openser
SIP/2.0 200 OK.
Record-Route: sip:52.132.36.43:5060;lr,sip:54.15.32.44
;lr=on;ftag=1pRGOP6lOmlBFIxy.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841@54.15.32.44
...
;tag=ffff1200ffff7710ff00000f1f6fff3b.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Server: MERA MSIP v.1.0.2.
Contact: sip:9128222570841@52.132.36.43:5060.
Content-Type: application/sdp.
Via: SIP/2.0/UDP 54.15.32.44:5060;branch=z9hG4bKa124.220e0023.0,SIP/2.0/UDP
58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
Content-Length: 136.
.
v=0.
o=- 1165483501 1165483501 IN IP4 52.132.36.43.
s=-.
c=IN IP4 52.132.36.43.
t=0 0.
m=audio 37548 RTP/AVP 4.
a=rtpmap:4 G723/8000.
.
#
U Openser -> IP Phone
SIP/2.0 200 OK.
Record-Route: sip:52.132.36.43:5060;lr,sip:54.15.32.44
;lr=on;ftag=1pRGOP6lOmlBFIxy.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841@54.15.32.44
...
;tag=ffff1200ffff7710ff00000f1f6fff3b.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
CSeq: 2 INVITE.
Server: MERA MSIP v.1.0.2.
Contact: sip:9128222570841@52.132.36.43:5060;nat=yes.
Content-Type: application/sdp.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKI7LP7qhgGKFHt904;rport=5060.
Content-Length: 153.
.
v=0.
o=- 1165483501 1165483501 IN IP4 52.132.36.43.
s=-.
c=IN IP4 54.15.32.44.
t=0 0.
m=audio 39784 RTP/AVP 4.
a=rtpmap:4 G723/8000.
.
a=nortpproxy:yes.
#
U Openser -> Mera
CANCEL sip:9128222570841@52.132.36.43:5060 SIP/2.0.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
To: "9128222570841" sip:9128222570841@54.15.32.44.
CSeq: 2 CANCEL.
User-Agent: openser (1.1.0 (i386/linux)).
Content-Length: 0.
.
#
U Mera -> Openser
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
To: "9128222570841" sip:9128222570841@54.15.32.44.
CSeq: 2 CANCEL.
Content-Length: 0.
.
#
U Mera -> Openser
SIP/2.0 487 Request Terminated.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
To: "9128222570841" sip:9128222570841@54.15.32.44.
CSeq: 2 INVITE.
Content-Length: 0.
.
#
U Openser -> Mera
ACK sip:9128222570841@52.132.36.43:5060 SIP/2.0.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1.
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
To: "9128222570841" sip:9128222570841@54.15.32.44.
CSeq: 2 ACK.
User-Agent: openser (1.1.0 (i386/linux)).
Content-Length: 0.
.
#
U IP Phone -> Openser
ACK sip:9128222570841@52.132.36.43:5060 SIP/2.0.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKTpMoqwSSNb4LvZrv;rport.
Route: sip:54.15.32.44;lr=on;ftag=1pRGOP6lOmlBFIxy, sip:52.132.36.43:5060
;lr.
Max-Forwards: 70.
User-Agent: PA168S V1.55.013 CFG0 .
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841@54.15.32.44
...
;tag=ffff1200ffff7710ff00000f1f6fff3b.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
Contact: sip:561705239298@58.88.13.13:5060.
Authorization: Digest username="561705239298", realm="54.15.32.44",
nonce="4577de9a6e32a8fafc108687cbc9b520cfd2b1ea", uri="
sip:9128222570841@52.132.36.43:5060",
response="7b312414aa7de3f999f8fd4a2a81c8a5", algorithm=MD5.
CSeq: 2 ACK.
Content-Length: 0.
.
#
U Openser -> Mera
ACK sip:9128222570841@52.132.36.43:5060 SIP/2.0.
Record-Route: sip:54.15.32.44;lr=on;ftag=1pRGOP6lOmlBFIxy.
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.3.
Via: SIP/2.0/UDP 58.88.13.13:5060;branch=z9hG4bKTpMoqwSSNb4LvZrv;rport=5060.
Route: sip:52.132.36.43:5060;lr.
Max-Forwards: 69.
User-Agent: PA168S V1.55.013 CFG0 .
From: "561705239298" sip:561705239298@54.15.32.44;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841@54.15.32.44
...
;tag=ffff1200ffff7710ff00000f1f6fff3b.
Call-ID: BCmB3zph5YmuC8oz@58.88.13.13.
Contact: sip:561705239298@58.88.13.13:5060.
Authorization: Digest username="561705239298", realm="54.15.32.44",
nonce="4577de9a6e32a8fafc108687cbc9b520cfd2b1ea", uri="
sip:9128222570841@52.132.36.43:5060",
response="7b312414aa7de3f999f8fd4a2a81c8a5", algorithm=MD5.
CSeq: 2 ACK.
Content-Length: 0.
P-hint: rr-enforced.
.