Call delayed by INVITE retransmissions

Discussion in '3CX Phone System - General' started by mtaylor, Sep 1, 2007.

  1. mtaylor

    Joined:
    Aug 31, 2007
    Messages:
    1
    Likes Received:
    0
    I am testing a VoIP phone in development by my company with 3CX
    and seeing a strange thing I can't explain.

    The phone sends an INVITE. It receives a 407 challenge from
    the proxy. It ACKs that 407 and resends the INVITE with
    authorization. Then it receives no further messages from the
    proxy for several seconds. During this time naturally it retransmits
    the INVITE several times. Finally, it gets the expected 100 and 180
    replies and eventually the call is connected when the remote party
    answers.

    I have confirmed that if I disable authentication by removing
    the username/password from the line configuration then
    the problem goes away.

    I have tried two other softphones - Eyebeam and SJphone - and
    I get no such behavior. This testing is on a LAN with no routers
    and no NAT, just using direct IP addresses so it is a pretty simple
    scenario.

    I have been analyzing the packets sent by our phone and have even
    made changes to make them closer to those sent by the other
    phones but to no avail. I can't explain why this happens and we
    have tested with numerous other proxies and never seen anything
    like it.

    The server log from the proxy doesn't seem to reflect the delay.
    It shows the incoming call followed almost immediately by the
    ringing indication from the called phone.

    Here are the packets followed by the log. The phone with the
    problem is 192.168.0.107 (sending the INVITE). The 3CX proxy is
    192.168.0.104, and the called phone is 192.168.0.102 (Eyebeam).

    INVITE sip:100@192.168.0.104 SIP/2.0
    v: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079;rport
    f: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    t: <sip:100@192.168.0.104>
    CSeq: 2 INVITE
    Max-Forwards: 70
    i: 2783131795@192.168.0.107
    m: <sip:103@192.168.0.107:43101>
    l: 220
    c: application/sdp
    User-Agent: Win32 VG
    v=0
    o=103@192.168.0.107 1188601585 1188601585 IN IP4 192.168.0.107
    s=-
    c=IN IP4 192.168.0.107
    t=0 0
    m=audio 34220 RTP/AVP 0 101
    a=sendrecv
    a=rtpmap:0 PCMU/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15

    SIP/2.0 407 Proxy Authentication Required
    Via: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079;rport=43101
    Proxy-Authenticate: Digest nonce="12833075186:5113719773f231b8820d2ffeda83d705",algorithm=MD5,realm="3CXPhoneSystem"
    To: <sip:100@192.168.0.104>;tag=96317623
    From: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    Call-ID: 2783131795@192.168.0.107
    CSeq: 2 INVITE
    User-Agent: 3CXPhoneSystem
    Content-Length: 0

    ACK sip:100@192.168.0.104 SIP/2.0
    v: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079
    f: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    t: <sip:100@192.168.0.104>;tag=96317623
    CSeq: 2 ACK
    Max-Forwards: 70
    i: 2783131795@192.168.0.107
    User-Agent: Win32 VG
    l: 0

    INVITE sip:100@192.168.0.104 SIP/2.0
    v: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079;rport
    f: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    t: <sip:100@192.168.0.104>
    CSeq: 3 INVITE
    Max-Forwards: 70
    i: 2783131795@192.168.0.107
    m: <sip:103@192.168.0.107:43101>
    l: 220
    c: application/sdp
    User-Agent: Win32 VG
    Proxy-Authorization: Digest username="103",realm="3CXPhoneSystem",nonce="12833075186:5113719773f231b8820d2ffeda83d705",uri="sip:100@192.168.0.104",response="270834b9aee2ac3e9c6863b94d42882f",algorithm=MD5
    v=0
    o=103@192.168.0.107 1188601585 1188601585 IN IP4 192.168.0.107
    s=-
    c=IN IP4 192.168.0.107
    t=0 0
    m=audio 34220 RTP/AVP 0 101
    a=sendrecv
    a=rtpmap:0 PCMU/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15

    (first retransmission)

    INVITE sip:100@192.168.0.104 SIP/2.0
    v: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079;rport
    f: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    t: <sip:100@192.168.0.104>
    CSeq: 3 INVITE
    Max-Forwards: 70
    i: 2783131795@192.168.0.107
    m: <sip:103@192.168.0.107:43101>
    l: 220
    c: application/sdp
    User-Agent: Win32 VG
    Proxy-Authorization: Digest username="103",realm="3CXPhoneSystem",nonce="12833075186:5113719773f231b8820d2ffeda83d705",uri="sip:100@192.168.0.104",response="270834b9aee2ac3e9c6863b94d42882f",algorithm=MD5
    v=0
    o=103@192.168.0.107 1188601585 1188601585 IN IP4 192.168.0.107
    s=-
    c=IN IP4 192.168.0.107
    t=0 0
    m=audio 34220 RTP/AVP 0 101
    a=sendrecv
    a=rtpmap:0 PCMU/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15

    (Remaining retransmitted packets omitted as they are identical.
    Then about 8 seconds after the first INVITE with the Proxy-Authorization
    header was sent a 100 is finally received from 3CX)

    SIP/2.0 100 Trying
    Via: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079;rport=43101
    To: <sip:100@192.168.0.104>;tag=7145f349
    From: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    Call-ID: 2783131795@192.168.0.107
    CSeq: 3 INVITE
    User-Agent: 3CXPhoneSystem
    Content-Length: 0

    (Then here is the INVITE sent from 3CX to the called party)

    INVITE sip:100@192.168.0.102:42434;rinstance=ba3290d993993549 SIP/2.0
    Via: SIP/2.0/UDP 192.168.0.104:5060;branch=z9hG4bK-d87543-ef092f3c772a8542-1--d87543-;rport
    Max-Forwards: 70
    Contact: <sip:103@192.168.0.104:5060>
    To: "100"<sip:100@192.168.0.102:42434;rinstance=ba3290d993993549>
    From: "103"<sip:103@192.168.0.104:5060>;tag=5c6d8b6e
    Call-ID: ZmFkNTU4YTc3NTJjODk1ZjcyMTBlYWU0OWMzYTNlNzQ.
    CSeq: 1 INVITE
    Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO
    Content-Type: application/sdp
    User-Agent: 3CXPhoneSystem
    Content-Length: 219
    v=0
    o=3cxPS 12833075195171 12833075195173 IN IP4 192.168.0.104
    s=3cxPS Audio call
    c=IN IP4 192.168.0.107
    t=0 0
    m=audio 34220 RTP/AVP 0 101
    a=rtpmap:0 PCMU/8000
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-15

    (Then the 180 from the called party to 3CX)

    SIP/2.0 180 Ringing
    Via: SIP/2.0/UDP 192.168.0.104:5060;branch=z9hG4bK-d87543-ef092f3c772a8542-1--d87543-;rport=5060
    Contact: <sip:100@192.168.0.102:42434;rinstance=ba3290d993993549>
    To: "100"<sip:100@192.168.0.102:42434;rinstance=ba3290d993993549>;tag=c65a9445
    From: "103"<sip:103@192.168.0.104:5060>;tag=5c6d8b6e
    Call-ID: ZmFkNTU4YTc3NTJjODk1ZjcyMTBlYWU0OWMzYTNlNzQ.
    CSeq: 1 INVITE
    User-Agent: eyeBeam release 1011s stamp 41121
    Content-Length: 0

    (Then the 180 forwarded from 3CX to the caller)

    SIP/2.0 180 Ringing
    Via: SIP/2.0/UDP 192.168.0.107:43101;branch=z9hG4bK1596188079;rport=43101
    Contact: <sip:3cxPbx@192.168.0.104:5060>
    To: <sip:100@192.168.0.104>;tag=7145f349
    From: "Win32 VG"<sip:103@192.168.0.104>;tag=2258520665
    Call-ID: 2783131795@192.168.0.107
    CSeq: 3 INVITE
    User-Agent: 3CXPhoneSystem
    Content-Length: 0

    The 200 is then sent from the callee and forwarded to
    the caller and the call connects and seems fine.

    Here are the relevant entries from the 3CX proxy log

    16:06:46.890 StratLink::eek:nHangUp [CM104001] Call(23): Ext.103 hung up call; cause: BYE; from IP:192.168.0.107

    16:06:36.859 CallLegImpl::eek:nConnected [CM103001] Call(23): Created audio channel for Ext.100 (192.168.0.102:6314) with third party (192.168.0.107:34220)

    16:06:36.859 StratInOut::eek:nConnected [CM104005] Call(23): Setup completed for call from Ext.103 to Ext.100

    16:06:36.859 CallLegImpl::eek:nConnected [CM103001] Call(23): Created audio channel for Ext.103 (192.168.0.107:34220) with third party (192.168.0.102:6314)

    16:06:35.453 CallConf::eek:nProvisional [CM103003] Call(23): Ext.100 is ringing

    16:06:35.156 CallConf::eek:nIncoming [CM103002] Call(23): Incoming call from 103 (Ext.103) to sip:100@192.168.0.104

    Any help understanding how this is happening will be greatly
    appreciated.

    Regards,

    Mike
     

Share This Page