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

Mon Sep 9 13:59:15 EDT 2013

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
> > 
> 