[Spce-user] call drop immediately

Tue Sep 17 15:22:08 EDT 2013

Hi Theo,

Do the packets still reach the peer with the extra headers or were they
removed as intended?

Best,

Lorenzo Mangani

HOMER DEV TEAM
QXIP - Capture Engineering

On Tue, Sep 17, 2013 at 9:11 PM, Theo <axessofficetheo at gmail.com> wrote:

> Hi
>
> CSI has nothing on us! I have corrected the sems config - the whitelist is
> back. Applied. I still have the same problem though...
>
> Any more thoughts?
>
>
> On Tue, Sep 17, 2013 at 3:49 PM, Lorenzo Mangani <
> lorenzo.mangani at gmail.com> wrote:
>
>> All,
>>
>> A little update on this interesting rabbit-hole case - the following was
>> the result of a CSI:Style intercontinental investigation with the help of
>> Daniel Grotti from sip:wise.
>>
>> The issue Theo was experiencing was surely caused by MTU fragmentation.
>> The MTU fragmentation was caused by the messages being oversize, but the
>> messages were really oversize because still carrying a few SPCE internal
>> headers, not removed due to a previous customization of the sems config in
>> fact disabling is header filtering completely - just to allow Refer
>> messages to pass.
>> Quite a backlog story for this case! Now the solution to both old and new
>> issues here is clearly to correct SEMS crippled configuration by defining a
>> "header_filter" mode (whitelist)  and extending the "header_list" parameter
>> list with the whole Refer family of headers (or whatever else needed within
>> reason) and let the B2BUA remove all the remaining internal-only headers
>> from the peering sessions. This should bring the situation back to normal
>> as of packet size without impacting any additional functionality.
>>
>> Theo, let us know if this resolved your case,
>>
>> Best,
>>
>> Lorenzo Mangani
>>
>> HOMER DEV TEAM
>> QXIP - Capture Engineering
>>
>>
>>
>> On Tue, Sep 17, 2013 at 8:13 AM, Theo <axessofficetheo at gmail.com> wrote:
>>
>>> Hi
>>>
>>> I have no solution for my problem. Part of this is kept in private with
>>> Andreas because of the info in the log files. The issue is bizarre as far
>>> as I can judge this. We have 3 providers. In this case each of those
>>> transit calls from a number of carriers which go through to this one
>>> customer. All works fine. EXCEPT for the transit from carrier 1, through
>>> provider A, who also transit for other carriers, through the same trunk
>>> without issues. The same carrier also sends calls through another provider
>>> without issues. However, calls from carrier 1 through provider A cut after
>>> 5 seconds, about 80% of the time.
>>>
>>> ngrep-sip complains about "SIP/2.0 400 missing CSeq header field'" - but
>>> The carrier, nor the provider, nor me see anything missing. Ngrep-sip from
>>> the point of the invite. I have decided not to worry about the sensitive
>>> details at this point as I have to get this resolved urgently. I see
>>> nothing missing in the invite. What I do see is, the second last line, that
>>> doesn't make sense. That should be a full domain, but where does that come
>>> from???
>>>
>>> Is this an issue on our box? if so, why only with this particular
>>> upstream carrier through this particular provider. If not, how do I get the
>>> other party to fix it?
>>>
>>> Thanks for any input
>>>
>>>
>>>
>>> U 2013/09/17 08:07:20.226723 127.0.0.1:5060 -> 127.0.0.1:5062
>>> INVITE sip:127.0.0.1:5080 SIP/2.0'
>>> Record-Route:
>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODM;ngcplb=yes;socket=udp:
>>> 196.41.123.113:5060>'
>>> Record-Route:
>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODM;ngcplb=yes;socket=udp:
>>> 196.41.123.113:5060>'
>>> Route: <sip:ngcp-lb at 127.0.0.1:5062
>>> ;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODM;did=3f2.531;mpd=ii;ice_caller=strip;ice_callee=strip;rtpprx=yes;vsf=V3V3Z0VMeGFUOU1OZkthYTonJjQKayohWlMrByZQLi8IKhkEHQdJAThbDQY->'
>>> Via: SIP/2.0/UDP
>>> 127.0.0.1;branch=z9hG4bK7239.6843b44cb370e058f995c996d166891a.0'
>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bK7239.908cd0b7.0'
>>> Via: SIP/2.0/UDP 92.240.0.12:5083;branch=z9hG4bK685c.a3419e67.0'
>>> From:  <sip:27214482133 at 92.240.1.12
>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEyOjUwODM'
>>> To:  <sip:27110254990 at 196.41.123.113
>>> ;user=phone>;tag=62DF6E4A-5237F1970000DBD6-69F4A700'
>>> Call-ID: hs4_bhs6_bSDg3ivb01-4893e0c5872c548cdb6488e80b76e5db-ctvvfv3'
>>> CSeq: 2 INVITE'
>>> Accept:
>>> application/sdp,application/isup,multipart/mixed,application/vnd.siemens.key-event,application/vnd.siemens.surpass,application/dtmf-relay'
>>> Contact: <sip:27214482133 at 92.240.0.12:5083;transport=udp>'
>>> MIME-Version: 1.0'
>>> Supported: timer,100rel'
>>> Max-Forwards: 63'
>>> Session-Expires: 1800;refresher=uac'
>>> Allow: ACK, INFO, BYE, CANCEL, INVITE, OPTIONS, NOTIFY, PRACK, UPDATE'
>>> Content-Type: application/sdp'
>>> Content-Length: 234'
>>> P-NGCP-Src-Ip: 92.240.1.12'
>>> P-NGCP-Src-Port: 5060'
>>> P-NGCP-Src-Proto: udp'
>>> P-NGCP-Src-Af: 4'
>>> P-Sock-Info: udp:196.41.123.113:5060'
>>> '
>>> v=0'
>>> o=- 2445083187 307757073 IN IP4 92.240.0.61'
>>> s=-'
>>> c=IN IP4 92.240.0.61'
>>> t=0 0'
>>> m=audio 52438 RTP/AVP 18 101'
>>> a=rtpmap:18 G729/8000'
>>> a=fmtp:18 annexb=no'
>>> a=rtpmap:101 telephone-event/8000'
>>> a=fmtp:101 0-15'
>>> a=sendrecv'
>>> a=ptime:60'
>>>
>>> #
>>> U 2013/09/17 08:07:20.226832 127.0.0.1:5062 -> 127.0.0.1:5060
>>> SIP/2.0 100 Trying'
>>> Via: SIP/2.0/UDP
>>> 127.0.0.1;branch=z9hG4bK7239.6843b44cb370e058f995c996d166891a.0'
>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bK7239.908cd0b7.0'
>>> Via: SIP/2.0/UDP 92.240.0.12:5083;branch=z9hG4bK685c.a3419e67.0'
>>> From:  <sip:27214482133 at 92.240.1.12
>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEyOjUwODM'
>>> To:  <sip:27110254990 at 196.41.123.113
>>> ;user=phone>;tag=62DF6E4A-5237F1970000DBD6-69F4A700'
>>> Call-ID: hs4_bhs6_bSDg3ivb01-4893e0c5872c548cdb6488e80b76e5db-ctvvfv3'
>>> CSeq: 2 INVITE'
>>> P-Out-Socket: udp:196.41.123.113:5060'
>>> Server: Sipwise NGCP Proxy 2.X'
>>> Content-Length: 0'
>>> '
>>>
>>> #
>>> U 2013/09/17 08:07:20.227036 196.41.123.113:5060 -> 92.240.1.12:5060
>>> SIP/2.0 100 Trying'
>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bK7239.908cd0b7.0'
>>> Via: SIP/2.0/UDP 92.240.0.12:5083;branch=z9hG4bK685c.a3419e67.0'
>>> From:  <sip:27214482133 at 92.240.1.12
>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEyOjUwODM'
>>> To:  <sip:27110254990 at 196.41.123.113
>>> ;user=phone>;tag=62DF6E4A-5237F1970000DBD6-69F4A700'
>>> Call-ID: hs4_bhs6_bSDg3ivb01-4893e0c5872c548cdb6488e80b76e5db-ctvvfv3'
>>> CSeq: 2 INVITE'
>>> Server: Sipwise NGCP Proxy 2.X'
>>> Content-Length: 0'
>>> '
>>>
>>> #
>>> U 2013/09/17 08:07:20.227510 127.0.0.1:5062 -> 127.0.0.1:5060
>>> SIP/2.0 400 missing CSeq header field'
>>> Record-Route: <sip:127.0.0.1:5062
>>> ;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODM;rtpprx=yes;ice_callee=strip;ice_caller=strip;mpd=ii>'
>>> Record-Route:
>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODM;ngcplb=yes;socket=udp:
>>> 196.41.123.113:5060>'
>>> Record-Route:
>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODM;ngcplb=yes;socket=udp:
>>> 196.41.123.113:5060>'
>>> Via: SIP/2.0/UDP
>>> 127.0.0.1;branch=z9hG4bK7239.6843b44cb370e058f995c996d166891a.0'
>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bK7239.908cd0b7.0'
>>> Via: SIP/2.0/UDP 92.240.0.12:5083;branch=z9hG4bK685c.a3419e67.0'
>>> From: <sip:27214482133 at maodi.sw1.a]''''S'''
>>> Content-Length: 0'
>>> '
>>>
>>>
>>>
>>>
>>>
>>> On Fri, Sep 13, 2013 at 4:28 PM, Theo <axessofficetheo at gmail.com> wrote:
>>>
>>>> I starting to think this is a problem on my box. However, it ONLY does
>>>> it with this client and ONLY from one upstream provider who route calls to
>>>> us from various carriers. It only happens with calls from one carrier. From
>>>> the sems log I have made the line below in BOLD. that should read @
>>>> maodi.sw1.africanaxess.co.za. It does on the first invite. Where does
>>>> this change into the mangled part??? And why only on calls through one
>>>> provider from one carrier specifically.
>>>>
>>>>
>>>>
>>>> Sep 13 16:01:18 sipwise sems[2424]: [#7ffb69f4a700] [parse_sip_uri,
>>>> parse_uri.cpp:332] DEBUG: Converted URI port (5080) to int (5080)
>>>> Sep 13 16:01:18 sipwise sems[2424]: [#7ffb69f4a700] [parse_headers,
>>>> parse_header.cpp:391] DEBUG: Illegal CR or LF in header name
>>>> Sep 13 16:01:18 sipwise sems[2424]: [#7ffb69f4a700] [received_msg,
>>>> trans_layer.cpp:1093] DEBUG: parse_sip_msg returned -5
>>>> Sep 13 16:01:18 sipwise sems[2424]: [#7ffb69f4a700] [received_msg,
>>>> trans_layer.cpp:1099] DEBUG: parsing error: missing CSeq header field
>>>> Sep 13 16:01:18 sipwise sems[2424]: [#7ffb69f4a700] [received_msg,
>>>> trans_layer.cpp:1101] DEBUG: Message was: "INVITE sip:127.0.0.1:5080SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;rtpprx=yes;ice_callee=strip;ice_caller=strip;mpd=ii>#015#012Record-Route:
>>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Record-Route:
>>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKdf2f.16949b1e10816e7aeabf87354bed5bba.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 127.0.0.1;branch=z9hG4bKdf2f.7bc23c3315f2e5d9705a33335a27931e.0#015#012
>>>> *Via: SIP/2.0/UDP
>>>> 92.240.1.13;rport=5060;branch=z9hG4bKdf2f.584bf716.0#015#012Via:
>>>> SIP/2.0/UDP 92.240.0.12:5081;branch=z9hG4bKbb6b.792a931.0#015#012From:
>>>>  <sip:27214482133 at maodi.sw1.a]#007#032#006#023S#021#020#012#035#
>>>> 026.co.za*>;tag=KmsqOjkyLjI0MC4wLjEyOjUwODE#015#012To:  <
>>>> sip:27110254990 at 196.41.123.113;user=phone>;tag=580524BE-52331AAE00079EFB-69F4A700#015#012Call-ID:
>>>> hs4_bhs6_bSDdbf7b01-fb9203bf7ff514193081e8be537bc659-ctvvfv3#015#012CSeq: 2
>>>> INVITE#015#012Accept:
>>>> application/sdp,application/isup,multipart/mixed,application/vnd.siemens.key-event,application/vnd.siemens.surpass,application/dtmf-relay#015#012Contact:
>>>> <sip:27214482133 at 92.240.0.12:5081;transport=udp>#015#012MIME-Version:
>>>> 1.0#015#012Supported: timer,100rel#015#012Max-Forwards:
>>>> 62#015#012Session-Expires: 1800;refresher=uac#015#012Allow: ACK, INFO, BYE,
>>>> CANCEL, INVITE, OPTIONS, NOTIFY, PRACK, UPDATE#015#012Content-Type:
>>>> application/sdp#015#012Content-Length: 254#015#012#015#012v=0#015#012o=-
>>>> 4048552998 309592175 IN IP4 196.41.123.113#015#012s=-#015#012c=IN IP4
>>>> 196.41.123.113#015#012t=0 0#015#012m=audio 31636 RTP/AVP 18
>>>> 101#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18
>>>> annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
>>>> 0-15#015#012a=sendrecv#015#012a=ptime:60#015#012a=rtcp:31637#015#012"
>>>> Sep 13 16:01:18 sipwise sems[2424]: [#7ffb69f4a700] [send,
>>>> transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2.0 400 missing CSeq
>>>> header field#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;rtpprx=yes;ice_callee=strip;ice_caller=strip;mpd=ii>#015#012Record-Route:
>>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Record-Route:
>>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKdf2f.16949b1e10816e7aeabf87354bed5bba.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 127.0.0.1;branch=z9hG4bKdf2f.7bc23c3315f2e5d9705a33335a27931e.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 92.240.1.13;rport=5060;branch=z9hG4bKdf2f.584bf716.0#015#012Via:
>>>> SIP/2.0/UDP 92.240.0.12:5081;branch=z9hG4bKbb6b.792a931.0#015#012From:
>>>> <sip:27214482133 at maodi.sw1.a]#007#032#006#023S#021#020#015#012Content-Length:
>>>> 0#015#012#015#012--++--
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [run,
>>>> udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP
>>>> vv#012--++--#012INVITE sip:127.0.0.1:5080 SIP/2.0#015#012Record-Route:
>>>> <sip:127.0.0.1:5062;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;rtpprx=yes;ice_callee=strip;ice_caller=strip;mpd=ii>#015#012Record-Route:
>>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Record-Route:
>>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKdf2f.16949b1e10816e7aeabf87354bed5bba.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 127.0.0.1;branch=z9hG4bKdf2f.7bc23c3315f2e5d9705a33335a27931e.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 92.240.1.13;rport=5060;branch=z9hG4bKdf2f.584bf716.0#015#012Via:
>>>> SIP/2.0/UDP 92.240.0.12:5081;branch=z9hG4bKbb6b.792a931.0#015#012From:
>>>>  <sip:27214482133 at maodi.sw1.a]#007#032#006#023S#021#020#012#035#
>>>> 026.co.za>;tag=KmsqOjkyLjI0MC4wLjEyOjUwODE#015#012To:  <
>>>> sip:27110254990 at 196.41.123.113;user=phone>;tag=580524BE-52331AAE00079EFB-69F4A700#015#012Call-ID:
>>>> hs4_bhs6_bSDdbf7b01-fb9203bf7ff514193081e8be537bc659-ctvvfv3#015#012CSeq: 2
>>>> INVITE#015#012Accept:
>>>> application/sdp,application/isup,multipart/mixed,application/vnd.siemens.key-event,application/vnd.siemens.surpass,application/dtmf-relay#015#012Contact:
>>>> <sip:27214482133 at 92.240.0.12:5081;transport=udp>#015#012MIME-Version:
>>>> 1.0#015#012Supported: timer,100rel#015#012Max-Forwards:
>>>> 62#015#012Session-Expires: 1800;refresher=uac#015#012Allow: ACK, INFO, BYE,
>>>> CANCEL, INVITE, OPTIONS, NOTIFY, PRACK, UPDATE#015#012Content-Type:
>>>> application/sdp#015#012Content-Length: 254#015#012#015#012v=0#015#012o=-
>>>> 4048552998 309592175 IN IP4 196.41.123.113#015#012s=-#015#012c=IN IP4
>>>> 196.41.123.113#015#012t=0 0#015#012m=audio 31636 RTP/AVP 18
>>>> 101#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18
>>>> annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
>>>> 0-15#015#012a=sendrecv#015#012a=ptime:60#015#012a=rtcp:31637#015#012--++--
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [parse_sip_uri,
>>>> parse_uri.cpp:332] DEBUG: Converted URI port (5080) to int (5080)
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [parse_headers,
>>>> parse_header.cpp:391] DEBUG: Illegal CR or LF in header name
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [received_msg,
>>>> trans_layer.cpp:1093] DEBUG: parse_sip_msg returned -5
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [received_msg,
>>>> trans_layer.cpp:1099] DEBUG: parsing error: missing CSeq header field
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [received_msg,
>>>> trans_layer.cpp:1101] DEBUG: Message was: "INVITE sip:127.0.0.1:5080SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;rtpprx=yes;ice_callee=strip;ice_caller=strip;mpd=ii>#015#012Record-Route:
>>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Record-Route:
>>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEyOjUwODE;ngcplb=yes;socket=udp:
>>>> 196.41.123.113:5060>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKdf2f.16949b1e10816e7aeabf87354bed5bba.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 127.0.0.1;branch=z9hG4bKdf2f.7bc23c3315f2e5d9705a33335a27931e.0#015#012Via:
>>>> SIP/2.0/UDP
>>>> 92.240.1.13;rport=5060;branch=z9hG4bKdf2f.584bf716.0#015#012Via:
>>>> SIP/2.0/UDP 92.240.0.12:5081;branch=z9hG4bKbb6b.792a931.0#015#012From:
>>>>  <sip:27214482133 at maodi.sw1.a]#007#032#006#023S#021#020#012#035#
>>>> 026.co.za>;tag=KmsqOjkyLjI0MC4wLjEyOjUwODE#015#012To:  <
>>>> sip:27110254990 at 196.41.123.113;user=phone>;tag=580524BE-52331AAE00079EFB-69F4A700#015#012Call-ID:
>>>> hs4_bhs6_bSDdbf7b01-fb9203bf7ff514193081e8be537bc659-ctvvfv3#015#012CSeq: 2
>>>> INVITE#015#012Accept:
>>>> application/sdp,application/isup,multipart/mixed,application/vnd.siemens.key-event,application/vnd.siemens.surpass,application/dtmf-relay#015#012Contact:
>>>> <sip:27214482133 at 92.240.0.12:5081;transport=udp>#015#012MIME-Version:
>>>> 1.0#015#012Supported: timer,100rel#015#012Max-Forwards:
>>>> 62#015#012Session-Expires: 1800;refresher=uac#015#012Allow: ACK, INFO, BYE,
>>>> CANCEL, INVITE, OPTIONS, NOTIFY, PRACK, UPDATE#015#012Content-Type:
>>>> application/sdp#015#012Content-Length: 254#015#012#015#012v=0#015#012o=-
>>>> 4048552998 309592175 IN IP4 196.41.123.113#015#012s=-#015#012c=IN IP4
>>>> 196.41.123.113#015#012t=0 0#015#012m=audio 31636 RTP/AVP 18
>>>> 101#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18
>>>> annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101
>>>> 0-15#015#012a=sendrecv#015#012a=ptime:60#015#012a=rtcp:31637#015#012"
>>>> Sep 13 16:01:19 sipwise sems[2424]: [#7ffb69e49700] [send,
>>>> transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2
>>>>
>>>>
>>>> On Fri, Sep 13, 2013 at 1:00 PM, Theo <axessofficetheo at gmail.com>wrote:
>>>>
>>>>> Hi Andreas,
>>>>>
>>>>> Apologies for keeping this off list - once I've figured out the
>>>>> problem and if worth it for other people I will post the correct solution
>>>>> here. I have in the meantime figured out WHY the call is dropping, and you
>>>>> were spot on with the missing CSeq header field. This is a snippet of a
>>>>> dropped call and clearly we are sending back the SIP/2.0 400 missing CSeq
>>>>> header field'. What I just cannot figure out is, WHAT is missing exactly.
>>>>> The upstream guys are saying "nothing is missing".
>>>>>
>>>>> I do see From: <sip:27214482133 at maodi.sw1.a]''''S''' which is
>>>>> worrying. this should be maodi.sw1.africanaxess.co.za which is the
>>>>> domain associated with this customer.
>>>>>
>>>>> U 2013/09/13 11:58:07.520589 92.240.1.12:5060 -> 196.41.123.113:5060
>>>>>
>>>>> INVITE sip:ngcp-lb at 196.41.123.113;ngcpct=c2lwOjEyNy4wLjAuMTo1MDgw
>>>>> SIP/2.0'
>>>>>
>>>>> Route: <sip:ngcp-lb at 196.41.123.113
>>>>> ;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;ngcplb=yes;socket=udp:
>>>>> 196.41.123.113:5060>, <sip:ngcp-lb at 127.0.0.1
>>>>> ;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;ngcplb=yes;socket=udp:
>>>>> 196.41.123.113:5060>, <sip:ngcp-lb at 127.0.0.1:5062
>>>>> ;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;did=63b.e412;mpd=ii;ice_caller=strip;ice_callee=strip;rtpprx=yes;vsf=V3V3Z0VMeGFUOU1OZkthYTonJjQKayohWlMrByZQLi8IKhkEHQdJAThbDQY->'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.1.12;branch=z9hG4bKa6b5.0d018653.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.0.13:5081;branch=z9hG4bKf784.ce567e76.0'
>>>>>
>>>>> From:  <sip:27214482133 at 92.240.1.12
>>>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEzOjUwODE'
>>>>>
>>>>> To:  <sip:27110254990 at 196.41.123.113
>>>>> ;user=phone>;tag=3D4A701D-5232E1AF0004AA9D-69F4A700'
>>>>>
>>>>> Call-ID: hs4_bhs6_bSDtqpbc01-50b38cb585afe88c67431dd52af8b9dd-ctvvfv3'
>>>>>
>>>>> CSeq: 2 INVITE'
>>>>>
>>>>> Accept:
>>>>> application/sdp,application/isup,multipart/mixed,application/vnd.siemens.key-event,application/vnd.siemens.surpass,application/dtmf-relay'
>>>>>
>>>>> Contact: <sip:27214482133 at 92.240.0.13:5081;transport=udp>'
>>>>>
>>>>> MIME-Version: 1.0'
>>>>>
>>>>> Supported: timer,100rel'
>>>>>
>>>>> Max-Forwards: 64'
>>>>>
>>>>> Session-Expires: 1800;refresher=uac'
>>>>>
>>>>> Allow: ACK, INFO, BYE, CANCEL, INVITE, OPTIONS, NOTIFY, PRACK, UPDATE'
>>>>>
>>>>> Content-Type: application/sdp'
>>>>>
>>>>> Content-Length: 235'
>>>>>
>>>>> '
>>>>>
>>>>> v=0'
>>>>>
>>>>> o=- 3522956930 307888210 IN IP4 92.240.0.62'
>>>>>
>>>>> s=-'
>>>>>
>>>>> c=IN IP4 92.240.0.62'
>>>>>
>>>>> t=0 0'
>>>>>
>>>>> m=audio 51314 RTP/AVP 18 101'
>>>>>
>>>>> a=rtpmap:18 G729/8000'
>>>>>
>>>>> a=fmtp:18 ann
>>>>>
>>>>> #
>>>>>
>>>>> U 2013/09/13 11:58:07.520787 127.0.0.1:5060 -> 127.0.0.1:5062
>>>>>
>>>>> INVITE sip:127.0.0.1:5080 SIP/2.0'
>>>>>
>>>>> Record-Route:
>>>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;ngcplb=yes;socket=udp:
>>>>> 196.41.123.113:5060>'
>>>>>
>>>>> Record-Route:
>>>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;ngcplb=yes;socket=udp:
>>>>> 196.41.123.113:5060>'
>>>>>
>>>>> Route: <sip:ngcp-lb at 127.0.0.1:5062
>>>>> ;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;did=63b.e412;mpd=ii;ice_caller=strip;ice_callee=strip;rtpprx=yes;vsf=V3V3Z0VMeGFUOU1OZkthYTonJjQKayohWlMrByZQLi8IKhkEHQdJAThbDQY->'
>>>>>
>>>>> Via: SIP/2.0/UDP
>>>>> 127.0.0.1;branch=z9hG4bKa6b5.242fbc2bf219d6f43d00babcdc3c29f3.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bKa6b5.0d018653.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.0.13:5081;branch=z9hG4bKf784.ce567e76.0'
>>>>>
>>>>> From:  <sip:27214482133 at 92.240.1.12
>>>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEzOjUwODE'
>>>>>
>>>>> To:  <sip:27110254990 at 196.41.123.113
>>>>> ;user=phone>;tag=3D4A701D-5232E1AF0004AA9D-69F4A700'
>>>>>
>>>>> Call-ID: hs4_bhs6_bSDtqpbc01-50b38cb585afe88c67431dd52af8b9dd-ctvvfv3'
>>>>>
>>>>> CSeq: 2 INVITE'
>>>>>
>>>>> Accept:
>>>>> application/sdp,application/isup,multipart/mixed,application/vnd.siemens.key-event,application/vnd.siemens.surpass,application/dtmf-relay'
>>>>>
>>>>> Contact: <sip:27214482133 at 92.240.0.13:5081;transport=udp>'
>>>>>
>>>>> MIME-Version: 1.0'
>>>>>
>>>>> Supported: timer,100rel'
>>>>>
>>>>> Max-Forwards: 63'
>>>>>
>>>>> Session-Expires: 1800;refresher=uac'
>>>>>
>>>>> Allow: ACK, INFO, BYE, CANCEL, INVITE, OPTIONS, NOTIFY, PRACK, UPDATE'
>>>>>
>>>>> Content-Type: application/sdp'
>>>>>
>>>>> Content-Length: 235'
>>>>>
>>>>> P-NGCP-Src-Ip: 92.240.1.12'
>>>>>
>>>>> P-NGCP-Src-Port: 5060'
>>>>>
>>>>> P-NGCP-Src-Proto: udp'
>>>>>
>>>>> P-NGCP-Src-Af: 4'
>>>>>
>>>>> P-Sock-Info: udp:196.41.123.113:5060'
>>>>>
>>>>> '
>>>>>
>>>>> v=0'
>>>>>
>>>>> o=- 3522956930 307888210 IN IP4 92.240.0.62'
>>>>>
>>>>> s=-'
>>>>>
>>>>> c=IN IP4 92.240.0.62'
>>>>>
>>>>> t=0 0'
>>>>>
>>>>> m=audio 51314 RTP/AVP 18 101'
>>>>>
>>>>> a=rtpmap:18 G729/8000'
>>>>>
>>>>> a=fmtp:18 annexb=no'
>>>>>
>>>>> a=rtpmap:101 telephone-event/8000'
>>>>>
>>>>> a=fmtp:101 0-15'
>>>>>
>>>>> a=sendrecv'
>>>>>
>>>>> a=pmft: T38'
>>>>>
>>>>>
>>>>> #
>>>>>
>>>>> U 2013/09/13 11:58:07.520906 127.0.0.1:5062 -> 127.0.0.1:5060
>>>>>
>>>>> SIP/2.0 100 Trying'
>>>>>
>>>>> Via: SIP/2.0/UDP
>>>>> 127.0.0.1;branch=z9hG4bKa6b5.242fbc2bf219d6f43d00babcdc3c29f3.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bKa6b5.0d018653.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.0.13:5081;branch=z9hG4bKf784.ce567e76.0'
>>>>>
>>>>> From:  <sip:27214482133 at 92.240.1.12
>>>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEzOjUwODE'
>>>>>
>>>>> To:  <sip:27110254990 at 196.41.123.113
>>>>> ;user=phone>;tag=3D4A701D-5232E1AF0004AA9D-69F4A700'
>>>>>
>>>>> Call-ID: hs4_bhs6_bSDtqpbc01-50b38cb585afe88c67431dd52af8b9dd-ctvvfv3'
>>>>>
>>>>> CSeq: 2 INVITE'
>>>>>
>>>>> P-Out-Socket: udp:196.41.123.113:5060'
>>>>>
>>>>> Server: Sipwise NGCP Proxy 2.X'
>>>>>
>>>>> Content-Length: 0'
>>>>>
>>>>> '
>>>>>
>>>>>
>>>>> #
>>>>>
>>>>> U 2013/09/13 11:58:07.521217 196.41.123.113:5060 -> 92.240.1.12:5060
>>>>>
>>>>> SIP/2.0 100 Trying'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bKa6b5.0d018653.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.0.13:5081;branch=z9hG4bKf784.ce567e76.0'
>>>>>
>>>>> From:  <sip:27214482133 at 92.240.1.12
>>>>> ;user=phone>;tag=KmsqOjkyLjI0MC4wLjEzOjUwODE'
>>>>>
>>>>> To:  <sip:27110254990 at 196.41.123.113
>>>>> ;user=phone>;tag=3D4A701D-5232E1AF0004AA9D-69F4A700'
>>>>>
>>>>> Call-ID: hs4_bhs6_bSDtqpbc01-50b38cb585afe88c67431dd52af8b9dd-ctvvfv3'
>>>>>
>>>>> CSeq: 2 INVITE'
>>>>>
>>>>> Server: Sipwise NGCP Proxy 2.X'
>>>>>
>>>>> Content-Length: 0'
>>>>>
>>>>> '
>>>>>
>>>>>
>>>>> #
>>>>>
>>>>> U 2013/09/13 11:58:07.521712 127.0.0.1:5062 -> 127.0.0.1:5060
>>>>>
>>>>> SIP/2.0 400 missing CSeq header field'
>>>>>
>>>>> Record-Route: <sip:127.0.0.1:5062
>>>>> ;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;rtpprx=yes;ice_callee=strip;ice_caller=strip;mpd=ii>'
>>>>>
>>>>> Record-Route:
>>>>> <sip:127.0.0.1;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;ngcplb=yes;socket=udp:
>>>>> 196.41.123.113:5060>'
>>>>>
>>>>> Record-Route:
>>>>> <sip:196.41.123.113;r2=on;lr=on;ftag=KmsqOjkyLjI0MC4wLjEzOjUwODE;ngcplb=yes;socket=udp:
>>>>> 196.41.123.113:5060>'
>>>>>
>>>>> Via: SIP/2.0/UDP
>>>>> 127.0.0.1;branch=z9hG4bKa6b5.242fbc2bf219d6f43d00babcdc3c29f3.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.1.12;rport=5060;branch=z9hG4bKa6b5.0d018653.0'
>>>>>
>>>>> Via: SIP/2.0/UDP 92.240.0.13:5081;branch=z9hG4bKf784.ce567e76.0'
>>>>>
>>>>> From: <sip:27214482133 at maodi.sw1.a]''''S'''
>>>>>
>>>>> Content-Length: 0'
>>>>>
>>>>> '
>>>>>
>>>>>
>>>>> On Tue, Sep 10, 2013 at 2:43 PM, Theo <axessofficetheo at gmail.com>wrote:
>>>>>
>>>>>> Hi
>>>>>>
>>>>>> Any idea why the tcpdump get mangled when saving to a file?
>>>>>>
>>>>>> ?E???#@??){q)?3???i?SIP/2.0 200 OK
>>>>>>
>>>>>> for example? when watching it in real-time it looks fine
>>>>>>
>>>>>>
>>>>>> On Tue, Sep 10, 2013 at 1:33 PM, Theo <axessofficetheo at gmail.com>wrote:
>>>>>>
>>>>>>> Hi
>>>>>>>
>>>>>>> Homer is on my list of things :-) Lorenzo has been telling how great
>>>>>>> it is.
>>>>>>>
>>>>>>> I didn't see that in the log, but mainly because of ignorance. For
>>>>>>> example, I have no idea what a CSeq header field is, but straight after
>>>>>>> this mail i will consult my friend google on that one. I will run the
>>>>>>> tcpdump and wait for more examples.
>>>>>>>
>>>>>>> And speed up my homer box I guess.
>>>>>>>
>>>>>>>
>>>>>>> On Tue, Sep 10, 2013 at 1:03 PM, Andreas Granig <agranig at sipwise.com
>>>>>>> > wrote:
>>>>>>>
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> Did you recognize the "SIP/2.0 400 missing CSeq header field" in
>>>>>>>> the sems log? Seems like there is quite a lot broken with the clients
>>>>>>>> involved here.
>>>>>>>>
>>>>>>>> I think the only way to pin it down exactly is to do something like
>>>>>>>>
>>>>>>>>         tcpdump -i any -s 0 -w /path/to/trace.pcap host
>>>>>>>> xxx.xxx.xxx.xxx
>>>>>>>>
>>>>>>>> where xxx.xxx.xxx.xxx is this asterisk box to get a clear overview
>>>>>>>> of what's going on. Another (better) way to troubleshoot this stuff post
>>>>>>>> mortem is to install Homer, so you're able to analyze call flows which
>>>>>>>> happened in the past.
>>>>>>>>
>>>>>>>> Andreas
>>>>>>>>
>>>>>>>>
>>>>>>>> On 09/10/2013 12:54 PM, Andreas Granig wrote:
>>>>>>>>
>>>>>>>>> Hi,
>>>>>>>>>
>>>>>>>>> On 09/10/2013 12:42 PM, Theo wrote:
>>>>>>>>>
>>>>>>>>>> Sep 10 11:16:06 sipwise /usr/sbin/kamailio[1971]: INFO: <script>:
>>>>>>>>>> New
>>>>>>>>>> request - M=BYE R=sip:ngcp-lb at 196.41.123.113
>>>>>>>>>> <mailto:sip%3Angcp-lb at 196.41.**123.113<sip%253Angcp-lb at 196.41.123.113>>
>>>>>>>>>> F=sip:27219763939 at 92.240.1.12
>>>>>>>>>> <mailto:sip%3A27219763939 at 92.**240.1.12<sip%253A27219763939 at 92.240.1.12>>
>>>>>>>>>> T=sip:27214235154 at 196.41.123.**113<sip%3A27214235154 at 196.41.123.113>
>>>>>>>>>> <mailto:sip%3A27214235154 at 196.**41.123.113<sip%253A27214235154 at 196.41.123.113>>
>>>>>>>>>> IP=udp:92.240.1.12:5060
>>>>>>>>>> <http://92.240.1.12:5060>
>>>>>>>>>> ID=hs4_bhs6_bSDh3kvb01-**12c39d503671664b04bbf109d85784**
>>>>>>>>>> 78-ctvvfv3
>>>>>>>>>>
>>>>>>>>>> In this case, which party tore the call down?
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> In this case, the IP 92.240.1.12 sent the BYE (look for IP=xxxx)
>>>>>>>>> in the
>>>>>>>>> log line.
>>>>>>>>>
>>>>>>>>> I think you're actually running into an end-to-end media
>>>>>>>>> negotiation
>>>>>>>>> issue. Caller sends SDP offer, the callee sends the answer, and the
>>>>>>>>> caller is not happy with it and sends the BYE. Just a wild guess,
>>>>>>>>> need
>>>>>>>>> to check the logs in detail.
>>>>>>>>>
>>>>>>>>> Andreas
>>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>> _______________________________________________
>>> Spce-user mailing list
>>> Spce-user at lists.sipwise.com
>>> http://lists.sipwise.com/listinfo/spce-user
>>>
>>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20130917/780ebb07/attachment-0001.html>