[Spce-user] Call hangs at about 15 seconds
Daniel Grotti
dgrotti at sipwise.com
Fri Aug 1 08:52:09 EDT 2014
Hi,
looks like in the ACK the port 5062 is missing from one of the Route header.
Do you have all the trace ? I mean also messages inside spce
(lb,proxy,sems).
Daniel
On 08/01/2014 02:27 PM, Leopoldo Iglesia wrote:
> Check this call in the pervious trace, is the same call but 2
> minutes before
>
> 6869 at 154.58.3.158
>
> El 01/08/2014 14:18, Daniel Grotti escribió:
>> Hi,
>> there is no such call (ID=16888 at 154.58.3.158) in the trace attached.
>>
>> Also you have a lot of ERROR:
>>
>> ERROR: rtpengine [rtpengine.c:1491]: rtpp_function_call(): proxy
>> replied with error: Failed to parse SDP
>>
>> But the reason why the call is drop is because the ACK is wrong and
>> it is not delivered:
>>
>> NOTICE: <script>: New request - M=ACK R=sip:127.0.0.1:5080
>> F=sip:x1009 at 154.58.3.135 T=sip:606105877 at 154.58.3.135
>> IP=127.0.0.1:5060 (127.0.0.1:5060) ID=16888 at 154.58.3.158
>> NOTICE: <script>: Dropping mis-routed request - R=sip:127.0.0.1:5080
>> ID=16888 at 154.58.3.158
>>
>>
>> Can't check the ACK inside cause there is no trace for that callid
>> 16888 at 154.58.3.158.
>>
>>
>> Daniel
>>
>>
>>
>> On 08/01/2014 01:50 PM, Leopoldo Iglesia wrote:
>>> If i call, from a suscriber to a foreign number, via peering, or to
>>> other suscriber it hangs at about 15 secs.
>>>
>>> I send a wireshark capture and proxy log.
>>>
>>>
>>> Aug 1 13:13:37 sipwise proxy[4400]: NOTICE: <script>:
>>> Authentication failed, no credentials - R=sip:606105877 at 154.58.3.135
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: New request -
>>> M=INVITE R=sip:606105877 at 154.58.3.135 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=154.58.3.158:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: User-Provided
>>> CLI 'x1009' taken from From-User as fallback, should be from
>>> 'rpid_user' - R=sip:606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: User-provided
>>> CLI 'x1009' rejected, using network-provided CLI '34984099519' -
>>> R=sip:606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> '34984099519 at 154.58.3.135' as initiating user-provided CLI -
>>> R=sip:606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> '34984099519 at 154.58.3.135' as initiating network-provided CLI -
>>> R=sip:606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Rewriting
>>> called party '606105877' to '34606105877' -
>>> R=sip:606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Callee is not
>>> local - R=sip:34606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Call to SIP
>>> Peering - R=sip:34606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Load gws
>>> matching calling part 'sip:34984099519 at 154.58.3.135' and called user
>>> '34606105877' and called part 'sip:34606105877 at 154.58.3.135' -
>>> R=sip:34606105877 at 154.58.3.135 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting acc
>>> source-leg for uuid 'c2731ab4-e7f5-4440-a821-d95c5d94eeac':
>>> 'c2731ab4-e7f5-4440-a821-d95c5d94eeac|x1009|154.58.3.135|34984099519|||2|||0|call|154.58.3.158|1406891617.480275'
>>> - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting acc
>>> destination-leg for uuid '0':
>>> '0|||0|606105877|0|34606105877|212.231.4.206|34606105877|154.58.3.135'
>>> - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: ERROR: rtpengine
>>> [rtpengine.c:1491]: rtpp_function_call(): proxy replied with error:
>>> Failed to parse SDP
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Rewriting
>>> first user-provided CLI '34984099519' to '984099519' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Rewriting
>>> first network-provided CLI '34984099519' to '984099519' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> caller_cli_netprov/caller_domain_netprov '984099519 at 154.58.3.135'
>>> for npn - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> caller_cli_netprov/caller_domain_netprov '984099519 at 154.58.3.135'
>>> for npn - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting From
>>> to '984099519 <sip:984099519 at 154.58.3.135>' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> caller_cli_netprov/caller_domain_netprov '984099519 at 154.58.3.135'
>>> for npn - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting PAI
>>> to '<sip:984099519 at 154.58.3.135>' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> P-Called-Party-ID '<sip:34606105877 at 212.231.4.206>' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Setting
>>> 'sip:212.231.4.206:5060' taken from R-URI as next hop after lb for
>>> PSTN call - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Appending
>>> P-D-URI
>>> 'sip:127.0.0.1:5060;received='sip:212.231.4.206:5060;lr;transport=udp''
>>> - R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Forcing
>>> request via B2BUA 'sip:127.0.0.1:5080' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4402]: NOTICE: <script>: Request
>>> leaving server, D-URI='sip:127.0.0.1:5080' -
>>> R=sip:34606105877 at 212.231.4.206:5060;transport=udp
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:37 sipwise proxy[4404]: NOTICE: <script>: NAT-Reply -
>>> S=100 - Connecting M=INVITE IP=154.58.3.158:5060 (127.0.0.1:5080)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:38 sipwise proxy[4408]: NOTICE: <script>: NAT-Reply -
>>> S=183 - Session Progress M=INVITE IP=154.58.3.158:5060
>>> (127.0.0.1:5080) ID=16888 at 154.58.3.158
>>> Aug 1 13:13:38 sipwise proxy[4408]: ERROR: rtpengine
>>> [rtpengine.c:1491]: rtpp_function_call(): proxy replied with error:
>>> Unknown call-id
>>> Aug 1 13:13:48 sipwise proxy[4400]: NOTICE: <script>: NAT-Reply -
>>> S=200 - OK M=INVITE IP=154.58.3.158:5060 (127.0.0.1:5080)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:48 sipwise proxy[4400]: ERROR: rtpengine
>>> [rtpengine.c:1491]: rtpp_function_call(): proxy replied with error:
>>> Unknown call-id
>>> Aug 1 13:13:48 sipwise proxy[4398]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:48 sipwise proxy[4398]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:48 sipwise proxy[4412]: ERROR: db_mysql
>>> [km_dbase.c:122]: db_mysql_submit_query(): driver error on query:
>>> Duplicate entry 'uloc-53db7100-112e-1' for key 'ruid_idx'
>>> Aug 1 13:13:48 sipwise proxy[4412]: ERROR: <core> [db_query.c:235]:
>>> db_do_insert_cmd(): error while submitting query
>>> Aug 1 13:13:48 sipwise proxy[4412]: ERROR: usrloc [ucontact.c:627]:
>>> db_insert_ucontact(): inserting contact in db failed
>>> Aug 1 13:13:48 sipwise proxy[4412]: ERROR: usrloc [urecord.c:386]:
>>> wb_timer(): inserting contact into database failed (aor:
>>> x984099517 at 154.58.3.135)
>>> Aug 1 13:13:48 sipwise proxy[4402]: NOTICE: <script>: NAT-Reply -
>>> S=200 - OK M=INVITE IP=154.58.3.158:5060 (127.0.0.1:5080)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:48 sipwise proxy[4402]: ERROR: rtpengine
>>> [rtpengine.c:1491]: rtpp_function_call(): proxy replied with error:
>>> Unknown call-id
>>> Aug 1 13:13:48 sipwise proxy[4404]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:49 sipwise proxy[4404]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:49 sipwise proxy[4408]: NOTICE: <script>: New request -
>>> M=REGISTER R=sip:154.58.3.135 F=sip:x1010 at 154.58.3.135
>>> T=sip:x1010 at 154.58.3.135 IP=154.58.3.149:5060 (127.0.0.1:5060)
>>> ID=cx0.Aa34erSB8FN6X7KRy.pHLfN3V9Y-
>>> Aug 1 13:13:49 sipwise proxy[4408]: NOTICE: <script>:
>>> Authentication failed, no credentials - R=sip:154.58.3.135
>>> ID=cx0.Aa34erSB8FN6X7KRy.pHLfN3V9Y-
>>> Aug 1 13:13:49 sipwise proxy[4410]: NOTICE: <script>: NAT-Reply -
>>> S=200 - OK M=INVITE IP=154.58.3.158:5060 (127.0.0.1:5080)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:49 sipwise proxy[4410]: ERROR: rtpengine
>>> [rtpengine.c:1491]: rtpp_function_call(): proxy replied with error:
>>> Unknown call-id
>>> Aug 1 13:13:50 sipwise proxy[4397]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:50 sipwise proxy[4397]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:53 sipwise proxy[4400]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:53 sipwise proxy[4400]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> Aug 1 13:13:57 sipwise proxy[4404]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:13:57 sipwise proxy[4404]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> Aug 1 13:14:01 sipwise proxy[4410]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:x1009 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:14:01 sipwise proxy[4410]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> Aug 1 13:14:03 sipwise proxy[4406]: NOTICE: <script>: New request -
>>> M=BYE R=sip:x1009 at 154.58.3.158:5060 F=sip:606105877 at 154.58.3.135
>>> T=sip:984099519 at 154.58.3.135 IP=127.0.0.1:5080 (127.0.0.1:5080)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:14:03 sipwise proxy[4398]: NOTICE: <script>: NAT-Reply -
>>> S=200 - OK M=BYE IP=127.0.0.1:5080 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:14:05 sipwise proxy[4402]: NOTICE: <script>: New request -
>>> M=ACK R=sip:127.0.0.1:5080 F=sip:984099519 at 154.58.3.135
>>> T=sip:606105877 at 154.58.3.135 IP=127.0.0.1:5060 (127.0.0.1:5060)
>>> ID=16888 at 154.58.3.158
>>> Aug 1 13:14:05 sipwise proxy[4402]: NOTICE: <script>: Dropping
>>> mis-routed request - R=sip:127.0.0.1:5080 ID=16888 at 154.58.3.158
>>> root at sipwise:/var/log/ngcp# tail -n 1000 kamailio-proxy.log
>>>
>>>
>>>
>>> _______________________________________________
>>> Spce-user mailing list
>>> Spce-user at lists.sipwise.com
>>> https://lists.sipwise.com/listinfo/spce-user
>>
>>
>>
>> _______________________________________________
>> Spce-user mailing list
>> Spce-user at lists.sipwise.com
>> https://lists.sipwise.com/listinfo/spce-user
>
>
>
> _______________________________________________
> Spce-user mailing list
> Spce-user at lists.sipwise.com
> https://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/20140801/18a418e8/attachment-0001.html>
More information about the Spce-user
mailing list