[Spce-user] Call hangs at about 15 seconds

Leopoldo Iglesia liglesia at por-aire.es
Fri Aug 1 08:27:46 EDT 2014 

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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20140801/15b36893/attachment-0001.html>

More information about the Spce-user mailing list