[Spce-user] Calls through peering servers fail with timeout in INVITE to caller (B2BUA)

Tue Sep 10 05:05:52 EDT 2013

Hi,
sip:provider is sending INVITE to the callee - peer at  77.72.169.134,
but receives no response, not even 100 Trying..

Andrew

On 09/09/2013 08:05 PM, Daniel Speichert wrote:
> nrep-sip is attached now :)
> 
> Regards,
> Daniel Speichert
> 
> ----- Original Message -----
>> From: "Daniel Speichert" <daniel at speichert.pl>
>> To: "Spce-user" <Spce-user at lists.sipwise.com>
>> Sent: poniedziałek, 9 wrzesień 2013 19:59:15
>> Subject: Re: [Spce-user] Calls through peering servers fail with timeout in INVITE to caller (B2BUA)
>>
>> Here are the details:
>>
>> nrep-sip is attached.
>>
>> Proxy log:
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: New request -
>> M=INVITE R=sip:0048616416630 at sip.leofon.pl:5060
>> F=sip:daniel at sip.leofon.pl:5060
>> T=sip:0048616416630 at sip.leofon.pl:5060 IP=77.255.30.119:51941
>> (127.0.0.1:5060) ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: User-Provided CLI
>> 'daniel' taken from From-User -
>> R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: User-provided CLI
>> 'daniel' rejected, using network-provided CLI '123' -
>> R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting
>> '123 at sip.leofon.pl' as initiating user-provided CLI -
>> R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting
>> '123 at sip.leofon.pl' as initiating network-provided CLI -
>> R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Callee is not
>> local - R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Call to SIP
>> Peering - R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Load gws matching
>> calling part 'sip:123 at sip.leofon.pl' and called user '0048616416630'
>> and called part 'sip:0048616416630 at sip.leofon.pl:5060' -
>> R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting
>> caller_cli_userprov/caller_domain_userprov '123 at sip.leofon.pl' for
>> upn - R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting From to
>> '<sip:123 at sip.leofon.pl>' - R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting
>> caller_cli_netprov/caller_domain_netprov '123 at sip.leofon.pl' for npn
>> - R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting PAI to
>> '<sip:123 at sip.leofon.pl>' - R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting
>> P-Called-Party-ID '<sip:0048616416630 at sip.voipdiscount.com>' -
>> R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Setting
>> 'sip:77.72.169.134:5060' taken from D-URI as next hop after lb for
>> PSTN call - R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Appending P-D-URI
>> 'sip:127.0.0.1:5060;received='sip:77.72.169.134:5060;transport=udp''
>> - R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Forcing request
>> via B2BUA 'sip:127.0.0.1:5080' -
>> R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4019]: NOTICE: <script>: Request leaving
>> server, D-URI='sip:127.0.0.1:5080' -
>> R=sip:0048616416630 at sip.voipdiscount.com
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:55 sip proxy[4014]: NOTICE: <script>: NAT-Reply - S=100
>> - Connecting M=INVITE IP=77.255.30.119:51941 (127.0.0.1:5080)
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:52:58 sip proxy[4014]: NOTICE: <script>: Authentication
>> failed, invalid user - R=sip:00441904891769 at 46.105.246.46
>> ID=a786708a44d117f882888c860e4bccdf
>> Sep  9 19:53:01 sip proxy[4015]: NOTICE: <script>: NAT-Reply - S=408
>> - Timeout M=INVITE IP=77.255.30.119:51941 (127.0.0.1:5080)
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:53:01 sip proxy[4015]: NOTICE: <script>: Failure route for
>> PSTN call - R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:53:01 sip proxy[4015]: NOTICE: <script>: No more peering
>> servers found - R=sip:0048616416630 at sip.leofon.pl:5060
>> ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>> Sep  9 19:53:01 sip proxy[4017]: NOTICE: <script>: New request -
>> M=ACK R=sip:0048616416630 at sip.leofon.pl:5060
>> F=sip:daniel at sip.leofon.pl:5060
>> T=sip:0048616416630 at sip.leofon.pl:5060 IP=77.255.30.119:51941
>> (127.0.0.1:5060) ID=MWNlYjZiNjljYjQxZTMzMzAxZjhjOTJiN2Y2ZWI1NGY.
>>
>>
>> root at sip:~# ngcp-kamctl proxy ul show daniel at sip.leofon.pl
>> Contact::
>> <sip:daniel at 77.255.30.119:51941;transport=TCP;rinstance=c7497aad0da7c9b4>;q=;expires=104;flags=0x0;cflags=0xC0;state=1;socket=<udp:127.0.0.1:5062>;methods=0x13FF;received=<sip:77.255.30.119:51941%3Btransport%3Dtcp>;user_agent=<3CXPhone
>> 6.0.26523.0>;path=<<sip:lb at 127.0.0.1;lr;received=sip:77.255.30.119:51941%3Btransport%3Dtcp;socket=sip:46.105.246.46:5060>>;reg-id=0
>>
>> Thanks for help.
>>
>> Regards,
>> Daniel Speichert
>>
>> ----- Original Message -----
>>> From: "Andrew Pogrebennyk" <apogrebennyk at sipwise.com>
>>> To: "Daniel Speichert" <daniel at speichert.pl>
>>> Cc: "Spce-user" <Spce-user at lists.sipwise.com>
>>> Sent: poniedziałek, 2 wrzesień 2013 17:53:28
>>> Subject: Re: [Spce-user] Calls through peering servers fail with
>>> timeout in INVITE to caller (B2BUA)
>>>
>>> Daniel,
>>> Please create a ngrep-sip capture of your call and also send us the
>>> proxy log of that call to see what's happening.
>>>
>>> Please show also the location entry with command:
>>> ngcp-kamctl proxy ul show user at domain
>>> where user at domain is the provisioned SIP URI of the subscriber.
>>>
>>> Andrew
>>>
>>> On 09/02/2013 05:45 PM, Daniel Speichert wrote:
>>>> Hi,
>>>>
>>>> After installing latest SPCE on a clean Debian Wheezy, it seems
>>>> that it
>>>> doesn't recognize NAT clients correctly.
>>>> In previous versions of SPCE (2.4), we used VoipDiscount as a
>>>> gateway
>>>> and calls went through successfully with exactly same
>>>> configuration.
>>>> Right now the new initialized session cannot connect to the
>>>> initiating
>>>> client and call ends with timeout. Proper ports are open on the
>>>> client end.
>>>>
>>>> Here is the log:
>>>>
>>>> Aug 21 11:54:47 sip proxy[3980]: NOTICE: <script>: Setting
>>>> P-Called-Party-ID '<sip:+48616412345 at sip.voipdiscount.com>' -
>>>> R=sip:+48616412345 at sip.voipdiscount.com
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:47 sip proxy[3980]: NOTICE: <script>: Setting
>>>> 'sip:77.72.169.131:5060' taken from D-URI as next hop after lb
>>>> for
>>>> PSTN call - R=sip:+48616412345 at sip.voipdiscount.com
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:47 sip proxy[3980]: NOTICE: <script>: Appending
>>>> P-D-URI
>>>> 'sip:127.0.0.1:5060;received='sip:77.72.169.131:5060;transport=udp''
>>>> - R=sip:+48616412345 at sip.voipdiscount.com
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:47 sip proxy[3980]: NOTICE: <script>: Forcing
>>>> request
>>>> via B2BUA 'sip:127.0.0.1:5080' -
>>>> R=sip:+48616412345 at sip.voipdiscount.com
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:47 sip proxy[3980]: NOTICE: <script>: Request
>>>> leaving
>>>> server, D-URI='sip:127.0.0.1:5080' -
>>>> R=sip:+48616412345 at sip.voipdiscount.com
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:47 sip proxy[3977]: NOTICE: <script>: NAT-Reply -
>>>> S=100 - Connecting M=INVITE IP=78.3.7.224:5060 (127.0.0.1:5080)
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:53 sip proxy[3983]: NOTICE: <script>: NAT-Reply -
>>>> S=408 - Timeout M=INVITE IP=78.3.7.224:5060 (127.0.0.1:5080)
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:53 sip proxy[3983]: NOTICE: <script>: Failure route
>>>> for PSTN call - R=sip:+48616412345 at sip.leofon.pl
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:53 sip proxy[3983]: NOTICE: <script>: No more
>>>> peering
>>>> servers found - R=sip:+48616412345 at sip.leofon.pl
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>> Aug 21 11:54:53 sip proxy[3976]: NOTICE: <script>: New request -
>>>> M=ACK R=sip:+48616412345 at sip.leofon.pl F=sip:daniel at sip.leofon.pl
>>>> T=sip:+48616412345 at sip.leofon.pl IP=78.3.7.224:5060
>>>> (127.0.0.1:5060)
>>>> ID=5d07455a21d759551767ad6d636bb116 at 0:0:0:0:0:0:0:0
>>>>
>>>>
>>>> Does anyone have any ideas? I'd appreciate any help.
>>>>
>>>> --
>>>> Regards,
>>>> Daniel Speichert
>>>>
>>>
>>
>>
>>
>> _______________________________________________
>> Spce-user mailing list
>> Spce-user at lists.sipwise.com
>> http://lists.sipwise.com/listinfo/spce-user