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

Md. Samiul Aftad Chowdhury voip.lover at gmail.com
Thu Dec 7 12:02:45 CET 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 scenario:

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 scenario but problem is that this "CANCEL" is
not generated by the
end point (in my case IP Phone in public IP). This "CANCEL" generated
from openser just after receiving the 200 OK of INVITE request.

Why openser generating a CANCEL while it already received 200 OK for
that INVITE??

Here is my openser configuration script: openser.cfg

===========Script Begin============
debug=3
fork=yes
log_stderror=no

log_facility=LOG_LOCAL0

listen= 54.15.32.44
alias=" sip.myfone.com"

check_via=no
dns=no
rev_dns=no
port=5060
children=4
fifo="/tmp/openser_fifo"

mpath="/usr/local/openser/lib/openser/modules/"

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"

modparam("usrloc", "db_mode",   0)

modparam("rr", "enable_full_lr", 1)

modparam("tm", "fr_inv_timer", 60 )
modparam("tm", "fr_timer", 30 )

modparam("acc", "radius_flag", 1 )
modparam("acc", "radius_missed_flag", 3 )

modparam("registrar", "nat_flag", 6)
modparam("nathelper", "natping_interval", 30)
modparam("nathelper", "ping_nated_only", 1)

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);
    };

        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);
            };
            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")){
        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):

IP Phone -> Openser
INVITE sip:9128222570841 at 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 at 54.15.32.44 >;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <sip:9128222570841 at 54.15.32.44>
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
Contact: <sip:561705239298 at 58.88.13.13:5060>
Authorization: Digest username="561705239298", realm=" 54.15.32.44",
nonce="4577de9a6e32a8fafc108687cbc9b520cfd2b1ea", uri="
sip:9128222570841 at 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

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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <  sip:9128222570841 at 54.15.32.44>
Call-ID: BCmB3zph5YmuC8oz at 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 at 54.15.32.44
out_uri=sip:9128222570841 at 52.132.36.43:5060 via_cnt==1"

Openser -> Mera
INVITE sip:9128222570841 at 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 at 54.15.32.44 >;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" < sip:9128222570841 at 54.15.32.44>
Call-ID:  BCmB3zph5YmuC8oz at 58.88.13.13
Contact: <sip:561705239298 at 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

Openser -> Mera
INVITE sip:9128222570841 at 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 at 54.15.32.44 >;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <sip:9128222570841 at 54.15.32.44>
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
Contact: <sip:561705239298 at 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

 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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" < sip:9128222570841 at 54.15.32.44 >
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
CSeq: 2 INVITE
Content-Length: 0

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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <sip:9128222570841 at 54.15.32.44 >
Call-ID:  BCmB3zph5YmuC8oz at 58.88.13.13
CSeq: 2 INVITE
Content-Length: 0


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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841"
<sip:9128222570841 at 54.15.32.44>;tag=ffff1200ffff7710ff00000f1f6fff3b
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
CSeq: 2 INVITE
Server: MERA MSIP v.1.0.2
Contact: <sip:9128222570841 at 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


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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <sip:9128222570841 at 54.15.32.44
>;tag=ffff1200ffff7710ff00000f1f6fff3b
 Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
CSeq: 2 INVITE
Server: MERA MSIP v.1.0.2
Contact: < sip:9128222570841 at 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

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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy.
To: "9128222570841" <sip:9128222570841 at 54.15.32.44
>;tag=ffff1200ffff7710ff00000f1f6fff3b
 Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
CSeq: 2 INVITE
Server: MERA MSIP v.1.0.2
Contact: < sip:9128222570841 at 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


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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <
sip:9128222570841 at 54.15.32.44>;tag=ffff1200ffff7710ff00000f1f6fff3b
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
CSeq: 2 INVITE
Server: MERA MSIP v.1.0.2
Contact: < sip:9128222570841 at 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

Openser -> Mera
CANCEL sip:9128222570841 at 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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
Call-ID:  BCmB3zph5YmuC8oz at 58.88.13.13
To: "9128222570841" < sip:9128222570841 at 54.15.32.44>
CSeq: 2 CANCEL
User-Agent: openser (1.1.0 (i386/linux))
Content-Length: 0

Mera -> Openser
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.15.32.44;branch=z9hG4bKa124.220e0023.1
From: "561705239298" < sip:561705239298 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
To: "9128222570841" < sip:9128222570841 at 54.15.32.44>
CSeq: 2 CANCEL
Content-Length: 0


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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
Call-ID:  BCmB3zph5YmuC8oz at 58.88.13.13
To: "9128222570841" < sip:9128222570841 at 54.15.32.44>
CSeq: 2 INVITE
Content-Length: 0


Openser -> Mera
ACK sip:9128222570841 at 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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
 Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
To: "9128222570841" < sip:9128222570841 at 54.15.32.44>
CSeq: 2 ACK
User-Agent: openser (1.1.0 (i386/linux))
Content-Length: 0


IP Phone -> Openser
ACK sip:9128222570841 at 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 at 54.15.32.44 >;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" <
sip:9128222570841 at 54.15.32.44>;tag=ffff1200ffff7710ff00000f1f6fff3b
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
Contact: <sip:561705239298 at 58.88.13.13:5060>
Authorization: Digest username="561705239298", realm="54.15.32.44",
nonce="4577de9a6e32a8fafc108687cbc9b520cfd2b1ea", uri="
sip:9128222570841 at 52.132.36.43 :5060",
response="7b312414aa7de3f999f8fd4a2a81c8a5", algorithm=MD5
CSeq: 2 ACK
Content-Length: 0


Openser -> Mera
ACK sip:9128222570841 at 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 at 54.15.32.44>;tag=1pRGOP6lOmlBFIxy
To: "9128222570841" < sip:9128222570841 at 54.15.32.44
>;tag=ffff1200ffff7710ff00000f1f6fff3b
Call-ID: BCmB3zph5YmuC8oz at 58.88.13.13
Contact: < sip:561705239298 at 58.88.13.13:5060>
Authorization: Digest username="561705239298", realm=" 54.15.32.44",
nonce="4577de9a6e32a8fafc108687cbc9b520cfd2b1ea",
uri="sip:9128222570841 at 52.132.36.43 :5060",
response="7b312414aa7de3f999f8fd4a2a81c8a5", algorithm=MD5
CSeq: 2 ACK
Content-Length: 0
P-hint: rr-enforced

==
Regards,

Aftad




More information about the sr-users mailing list