Provider registration times out, console error messages.

Discussions about using SIP Sorcery on your own computer/server
713lucid
Posts: 29
Joined: Thu Sep 17, 2009 12:48 am

Re: Provider registration times out, console error messages.

Post by 713lucid » Tue Sep 21, 2010 3:39 pm

Nebukadnezar wrote:Unfortunately, I did not have this issue solved at all; NAT(loopback) etc. had nothing to do with this issue. However, I did get it solved and I am somewhat ashamed to explain how, and what caused this.
I provisioned some services on the SpeedTouch ST780WL, and one of those services was CLIR; and it was activated (*31) by default and CLIR suppresses your identity and makes it impossible to get authenticated on sipsorcery; dialing the deactivate prefix (#31) solved the issue.
This is not the issue for me since the exact same provider info works on other machines.

Aaron
Site Admin
Posts: 4652
Joined: Thu Jul 12, 2007 12:13 am

Re: Provider registration times out, console error messages.

Post by Aaron » Tue Sep 21, 2010 10:41 pm

Can you post the whole console output you get from the time your sipsorcery instance starts until the registration attempt has been made, the output is also captured in root.log so you can cut and paste it from there.

713lucid
Posts: 29
Joined: Thu Sep 17, 2009 12:48 am

Re: Provider registration times out, console error messages.

Post by 713lucid » Wed Sep 22, 2010 3:14 am

Code: Select all

C:\Temp\sipsorcery-1.2>sipsorcery-appsvr -c
Starting logging initialisation.
Logging initialised.
SIP App Server starting
SIP App Server Console starting...
pid=3696.
os=Microsoft Windows NT 5.2.3790 Service Pack 2.
current directory=C:\Temp\sipsorcery-1.2.
base directory=C:\Temp\sipsorcery-1.2\.
 1 SIPSorcery.SIP.App.SIPAccount assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipaccounts.xml.
 1 SIPSorcery.SIP.App.SIPDialPlan assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipdialplans.xml.
 1 SIPSorcery.SIP.App.SIPProvider assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipproviders.xml.
 1 SIPSorcery.SIP.App.SIPProviderBinding assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipproviderbindings.
xml.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipdomains.xml.
 SIPDomainManager added domain: localhost.
 added domain alias 10.1.1.5.
 added domain alias 10.1.1.5:5060.
 added domain alias local.
 added domain alias *.
 SIPDomainManager wildcard domain set to localhost.
 no SIPSorcery.SIP.App.SIPRegistrarBinding assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipregistrarbindings
.xml.
 no SIPSorcery.SIP.App.SIPDialogueAsset assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipdialogues.xml.
 no SIPSorcery.SIP.App.SIPCDRAsset assets loaded from XML record set.
Starting file watch on C:\Temp\sipsorcery-1.2\xmlconfig and sipcdrs.xml.
 1 SIPSorcery.CRM.Customer assets loaded from XML record set.
Starting file watch on xmlconfig and customers.xml.
 1 SIPSorcery.CRM.CustomerSession assets loaded from XML record set.
Starting file watch on xmlconfig and customersessions.xml.
SIP Proxy daemon starting...
 SIP Proxy monitor sender initialised for 127.0.0.1:10001.
Creating SIP Channel for <socket>*:5060</socket>.
 attempting to create SIP UDP channel for 10.0.0.1:5060.
SIPUDPChannel listener created 10.0.0.1:5060.
 attempting to create SIP UDP channel for 10.0.10.2:5060.
SIPUDPChannel listener created 10.0.10.2:5060.
 attempting to create SIP UDP channel for 127.0.0.1:5060.
SIPUDPChannel socket on udp:10.0.0.1:5060 listening started.
SIPUDPChannel socket on udp:10.0.10.2:5060 listening started.
SIPUDPChannel listener created 127.0.0.1:5060.
Creating SIP Channel for <socket protocol="tcp">*:5060</socket>.
 attempting to create SIP TCP channel for 10.0.0.1:5060.
SIPUDPChannel socket on udp:127.0.0.1:5060 listening started.
SIP TCP Channel listener created 10.0.0.1:5060.
 attempting to create SIP TCP channel for 10.0.10.2:5060.
SIP TCP Channel listener created 10.0.10.2:5060.
 attempting to create SIP TCP channel for 127.0.0.1:5060.
SIP TCP Channel listener created 127.0.0.1:5060.
SIPTCPChannel socket on tcp:10.0.10.2:5060 listening started.
SIPTCPChannel socket on tcp:10.0.0.1:5060 listening started.
No call dispatcher file specified for SIP Proxy.
Exception SIPProxyDispatcher StartService. Service 'SIPSorcery.Servers.SIPProxyD
ispatcher' has zero application (non-infrastructure) endpoints. This might be be
cause no configuration file was found for your application, or because no servic
e element matching the service name could be found in the configuration file, or
 because no endpoints were defined in the service element.
Compiling IronPython script file from C:\Temp\sipsorcery-1.2\proxyscript.py.
SIPUDPChannel listener created 127.0.0.1:9001.
SIPUDPChannel socket on udp:127.0.0.1:9001 listening started.
NATKeepAlive Relay instantiated on 127.0.0.1:9001.
SIP Proxy daemon successfully started.
SIPMonitorDaemon starting...
The SIP Monitor Server was successfully started, loopback port 10001.
Exception starting internal notifications TCP hosted service. Service 'SIPSorcer
y.Web.Services.SIPMonitorClientManagerHost' has zero application (non-infrastruc
ture) endpoints. This might be because no configuration file was found for your
application, or because no service element matching the service name could be fo
und in the configuration file, or because no endpoints were defined in the servi
ce element.
SIP Registrar daemon starting...
Monitor channel initialised for 127.0.0.1:10001.
Creating SIP Channel for <sipsocket>127.0.0.1:5001</sipsocket>.
 attempting to create SIP UDP channel for 127.0.0.1:5001.
SIPUDPChannel listener created 127.0.0.1:5001.
SIPUDPChannel socket on udp:127.0.0.1:5001 listening started.
Added useragent config, useragent=fring, expiry=3600s, contact lists=True.
Added useragent config, useragent=Nokia, expiry=3600s, contact lists=False.
Added useragent config, useragent=Cisco-CP7960G/8.0, expiry=60s, contact lists=F
alse.
Added useragent config, useragent=.*, expiry=113s, contact lists=True.
SIP Registrar successfully started.
SIP Registration Agent daemon starting...
Monitor channel initialised for 127.0.0.1:10001.
Creating SIP Channel for <sipsocket>127.0.0.1:5002</sipsocket>.
 attempting to create SIP UDP channel for 127.0.0.1:5002.
SIPUDPChannel listener created 127.0.0.1:5002.
SIPUDPChannel socket on udp:127.0.0.1:5002 listening started.
SIPRegistrationAgent thread started.
Starting 1 monitor registration threads.
SIP Registration Agent successfully started.
SSHServerDaemon starting...
Initiating SIP Application Server Agent.
Creating SIP Channel for <socket>127.0.0.1:5065</socket>.
 attempting to create SIP UDP channel for 127.0.0.1:5065.
SIPUDPChannel listener created 127.0.0.1:5065.
SIPUDPChannel socket on udp:127.0.0.1:5065 listening started.
Ruby common script file changed, reloading ruby common script.
Starting file watch on Ruby Common Script C:\Temp\sipsorcery-1.2\dialplan-common
.rby.
SIPTCPChannel socket on tcp:127.0.0.1:5060 listening started.
Provisioning hosted service successfully started on http://bkupsrv:8080/provisio
ning.svc.
CrossDomain hosted service successfully started on http://bkupsrv:8080/.
CallManager hosted service successfully started on http://bkupsrv:8080/callmanag
er.svc.
SIPNotificationsService hosted service successfully started on http://bkupsrv:80
80/notificationspull.svc.
SIPProxyDaemon STUN client started.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
Binding to IP endpoint: [0.0.0.0:22]
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
ra: Checking SIP Provider registration for Sipgate.
Initialising DNS resolver with operating system DNS server entries.
Lookup queueud for NAPTR sipgate.com, queue size=1, in progress=1.
Thread dnslookup-1 looking up NAPTR sipgate.com.
Sending UDP DNS request to 4.2.2.1:53 for NAPTR sipgate.com..
Resolve time for sipgate.com NAPTR 171.875ms.
Complete event fired for DNS lookup on NAPTR sipgate.com.
Lookup queueud for SRV _sip._udp.sipgate.com, queue size=1, in progress=1.
Thread dnslookup-1 looking up SRV _sip._udp.sipgate.com.
Sending UDP DNS request to 4.2.2.1:53 for SRV _sip._udp.sipgate.com..
Resolve time for _sip._udp.sipgate.com SRV 93.75ms.
 result: priority=0, weight=0, port=5060, target=sipgate.com..
Complete event fired for DNS lookup on SRV _sip._udp.sipgate.com.
Lookup queueud for A sipgate.com., queue size=1, in progress=1.
Thread dnslookup-1 looking up A sipgate.com..
Sending UDP DNS request to 4.2.2.1:53 for A sipgate.com..
Resolved A record for sipgate.com. to 204.155.28.10 in 78.125ms.
Complete event fired for DNS lookup on A sipgate.com..
ra: Sending initial register for username and Sipgate to udp:204.155.28.10:5060.

ra: Initiating registration for username on sip:sipgate.com.
Binding entry processing took 453.
SIPProviderBindingSynchroniser SIPProviderUpdated for username and Sipgate.
ra: SIP Provider registration request for Sipgate too frequent, delaying by 44s
to 2010-09-22T03:00:31.3118575+00:00.
Binding entry processing took 0.
ra: Registration timed out for username and provider Sipgate registering to udp:
204.155.28.10:5060, next attempt in 300s.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
ra: Checking SIP Provider registration for Sipgate.
ra: Sending initial register for username and Sipgate to udp:204.155.28.10:5060.

ra: Initiating registration for username on sip:sipgate.com.
Binding entry processing took 0.
STUNClient attempting to determine public IP from stun.ekiga.net.
STUNClient Response to initial STUN message received from 75.101.138.128:3478.
STUNClient Public IP=72.150.16.84.
ra: Registration timed out for username and provider Sipgate registering to udp:
204.155.28.10:5060, next attempt in 300s.
I know the sipdomain is incorrect, but this works fine for registration on other machines -- just not the two servers I would like it on.

I compared the logs from the working machines and this one and they look pretty much the same to me, but I didn't look closely.

Aaron
Site Admin
Posts: 4652
Joined: Thu Jul 12, 2007 12:13 am

Re: Provider registration times out, console error messages.

Post by Aaron » Wed Sep 22, 2010 8:42 am

It looks to me like there's something awry with your IP addresses.

Code: Select all

attempting to create SIP UDP channel for 10.0.0.1:5060.
SIPUDPChannel listener created 10.0.0.1:5060.
attempting to create SIP UDP channel for 10.0.10.2:5060.
SIPUDPChannel listener created 10.0.10.2:5060.
Does your server have both those addresses?

713lucid
Posts: 29
Joined: Thu Sep 17, 2009 12:48 am

Re: Provider registration times out, console error messages.

Post by 713lucid » Wed Sep 22, 2010 1:29 pm

Thanks! That was it, there is a network adapter on the server that is unused (cable unplugged) but has a static ip that apparently SS was trying to use. I just disabled it and all is well.

webzone
Posts: 1
Joined: Fri Oct 01, 2010 2:15 am

Re: Provider registration times out, console error messages.

Post by webzone » Fri Oct 01, 2010 2:20 am

Hi Aaron,

If my computer has tow network adapters and both have their own ip addresses. Could sipsorcery work on this computer? Is there a way, I can configure sipsorcery to work on a assigned ip? I mean to bind sipsorcery with the ip out of those ips?


Thanks,
Chris

Aaron
Site Admin
Posts: 4652
Joined: Thu Jul 12, 2007 12:13 am

Re: Provider registration times out, console error messages.

Post by Aaron » Fri Oct 01, 2010 2:29 am

Yes you can specify the IP address & port you want each of the sipsorcery server agents to bind to in the sipsorcery-appsvr.config.exe. You will also need to double check the values at the top of proxyscript.py to make sure they are the same as the ones used in the config file.

Post Reply