K Wong
2004-Dec-09 23:41 UTC
[Asterisk-Users] Asterisk started but doesn't register SIP client
Hi: We just setup the Asterisk and it seems to start ok. We checked the log, and beside the timer warning, there isn't other error message. However, we tried both SIPURA and XLite, but their registration is not accepted (timed out and failed). Could someone tell me what's wrong? [message] Dec 10 01:33:22 WARNING[2649]: Unable to open IAX timing interface: Permission denied Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database [debug] Dec 10 01:33:22 DEBUG[2649]: VM Review Option disabled globally Dec 10 01:33:22 DEBUG[2649]: VM Operator break disabled globally Dec 10 01:33:22 DEBUG[2649]: VM CID Info before msg disabled globally Dec 10 01:33:22 DEBUG[2649]: Send Voicemail msg disabled globally Dec 10 01:33:22 DEBUG[2649]: ENVELOPE before msg enabled globally Dec 10 01:33:22 DEBUG[2649]: We are not going to skip to the next msg after save/delete Dec 10 01:33:22 DEBUG[2649]: 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:22 DEBUG[2649]: 69.73.19.178/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:23 DEBUG[2649]: 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:23 DEBUG[2649]: 69.73.19.178/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:23 DEBUG[2649]: Scheduled a timeout # 1 Dec 10 01:33:23 DEBUG[2661]: Stopping retransmission on '366b24810a0bb91355fbb4ba7d9a27ef@127.0.0.1' of Request 102: Found Dec 10 01:33:23 DEBUG[2661]: Setting NAT on RTP to 4 Dec 10 01:33:23 DEBUG[2661]: Stopping retransmission on '366b24810a0bb91355fbb4ba7d9a27ef@127.0.0.1' of Request 103: Found Dec 10 01:33:23 DEBUG[2661]: Registration successful Dec 10 01:33:23 DEBUG[2661]: Cancelling timeout 1 Dec 10 01:33:23 DEBUG[2661]: Setting NAT on RTP to 4 Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got hostname of localhost Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got port of 3306 Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got sock file of /var/lib/mysql/mysql.sock Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got user of XXXXXXX Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got dbname of XXXXXX Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got password of XXXXXX Dec 10 01:33:23 DEBUG[2649]: Successfully connected to MySQL database. Dec 10 01:33:39 DEBUG[2661]: Auto destroying call '950c71b7-7fa51914@192.168.0.218' [full] .................... Dec 10 01:33:23 DEBUG[2649]: Successfully connected to MySQL database. Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_callingcard.so[0;37;40m]Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_callingcard.so[0;37;40m] => ([33;40mCalling Card Application[0;37;40m) Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/callingcard.conf': Dec 10 01:33:23 VERBOSE[2649]: =Parsing '/etc/asterisk/callingcard.conf': Found Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_prepaid_auth_cid.so[0;37;40m]Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_prepaid_auth_cid.so[0;37;40m] => ([33;40m PrepaidAuthCID(Destination,Tariffplan): Returns the Tariff rate for th) Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/prepaid.conf': Dec 10 01:33:23 VERBOSE[2649]: =Parsing '/etc/asterisk/prepaid.conf': Found Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_prepaid_rate.so[0;37;40m]Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_prepaid_rate.so[0;37;40m] => ([33;40m PrepaidRate(Destination,Tariffplan): Returns the Tariff rate for the d) Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/prepaid.conf': Dec 10 01:33:23 VERBOSE[2649]: =Parsing '/etc/asterisk/prepaid.conf': Found Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_prepaid_rateplan.so[0;37;40m]Dec 10 01:33:23 VERBOSE[2649]: [[1;37;40mapp_prepaid_rateplan.so[0;37;40m] => ([33;40m PrepaidRatePlan(User): Returns the Tariff plan for the specified User.) Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/prepaid.conf': Dec 10 01:33:23 VERBOSE[2649]: =Parsing '/etc/asterisk/prepaid.conf': Found Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': Found Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/extconfig.conf': Dec 10 01:33:23 VERBOSE[2649]: =Parsing '/etc/asterisk/extconfig.conf': Found Dec 10 01:33:23 VERBOSE[2649]: Asterisk Event Logger restarted Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/manager.conf': Dec 10 01:33:23 VERBOSE[2649]: =Parsing '/etc/asterisk/manager.conf': Found Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': Found Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/rtp.conf': Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/rtp.conf': Found Dec 10 01:33:23 VERBOSE[2649]: == RTP Allocating from port range 10000 -> 20000 Dec 10 01:33:23 VERBOSE[2649]: [1;37;40mAsterisk Ready. [0;37;40mDec 10 01:33:39 DEBUG[2661]: Auto destroying call '950c71b7-7fa51914@192.168.0.218' ----------------------------------------------------------------------------------------------------------------- Note that the 192.168.0.218' is our SIPURA Thanks. Andy
Howard Lowndes
2004-Dec-09 23:46 UTC
[Asterisk-Users] Asterisk started but doesn't register SIP client
Try doing a "sip debug" and see what happens to the SIP stream. On Fri, 2004-12-10 at 01:41, K Wong wrote:> Hi: > > We just setup the Asterisk and it seems to start ok. We checked the > log, and beside the timer warning, there isn't other error message. > However, we tried both SIPURA and XLite, but their registration is not > accepted (timed out and failed). > > Could someone tell me what's wrong? > > [message] > Dec 10 01:33:22 WARNING[2649]: Unable to open IAX timing interface: > Permission denied > Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database > Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database > Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database > Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database > > > [debug] > Dec 10 01:33:22 DEBUG[2649]: VM Review Option disabled globally > Dec 10 01:33:22 DEBUG[2649]: VM Operator break disabled globally > Dec 10 01:33:22 DEBUG[2649]: VM CID Info before msg disabled globally > Dec 10 01:33:22 DEBUG[2649]: Send Voicemail msg disabled globally > Dec 10 01:33:22 DEBUG[2649]: ENVELOPE before msg enabled globally > Dec 10 01:33:22 DEBUG[2649]: We are not going to skip to the next msg > after save/delete > Dec 10 01:33:22 DEBUG[2649]: > 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for > peer > Dec 10 01:33:22 DEBUG[2649]: > 69.73.19.178/255.255.255.255/255.255.255.255 appended to acl for peer > Dec 10 01:33:23 DEBUG[2649]: > 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for > peer > Dec 10 01:33:23 DEBUG[2649]: > 69.73.19.178/255.255.255.255/255.255.255.255 appended to acl for peer > Dec 10 01:33:23 DEBUG[2649]: Scheduled a timeout # 1 > Dec 10 01:33:23 DEBUG[2661]: Stopping retransmission on > '366b24810a0bb91355fbb4ba7d9a27ef@127.0.0.1' of Request 102: Found > Dec 10 01:33:23 DEBUG[2661]: Setting NAT on RTP to 4 > Dec 10 01:33:23 DEBUG[2661]: Stopping retransmission on > '366b24810a0bb91355fbb4ba7d9a27ef@127.0.0.1' of Request 103: Found > Dec 10 01:33:23 DEBUG[2661]: Registration successful > Dec 10 01:33:23 DEBUG[2661]: Cancelling timeout 1 > Dec 10 01:33:23 DEBUG[2661]: Setting NAT on RTP to 4 > Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got hostname of localhost > Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got port of 3306 > Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got sock file of > /var/lib/mysql/mysql.sock > Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got user of XXXXXXX > Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got dbname of XXXXXX > Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got password of XXXXXX > Dec 10 01:33:23 DEBUG[2649]: Successfully connected to MySQL database. > Dec 10 01:33:39 DEBUG[2661]: Auto destroying call > '950c71b7-7fa51914@192.168.0.218' > > [full] > .................... > > Dec 10 01:33:23 DEBUG[2649]: Successfully connected to MySQL database. > Dec 10 01:33:23 VERBOSE[2649]: > [[1;37;40mapp_callingcard.so[0;37;40m]Dec 10 01:33:23 VERBOSE[2649]: > [[1;37;40mapp_callingcard.so[0;37;40m] => ([33;40mCalling Card > Application[0;37;40m) > Dec 10 01:33:23 VERBOSE[2649]: == Parsing > '/etc/asterisk/callingcard.conf': Dec 10 01:33:23 VERBOSE[2649]: => Parsing '/etc/asterisk/callingcard.conf': Found > Dec 10 01:33:23 VERBOSE[2649]: > [[1;37;40mapp_prepaid_auth_cid.so[0;37;40m]Dec 10 01:33:23 > VERBOSE[2649]: [[1;37;40mapp_prepaid_auth_cid.so[0;37;40m] => > ([33;40m PrepaidAuthCID(Destination,Tariffplan): Returns the Tariff > rate for th) > Dec 10 01:33:23 VERBOSE[2649]: == Parsing > '/etc/asterisk/prepaid.conf': Dec 10 01:33:23 VERBOSE[2649]: => Parsing '/etc/asterisk/prepaid.conf': Found > Dec 10 01:33:23 VERBOSE[2649]: > [[1;37;40mapp_prepaid_rate.so[0;37;40m]Dec 10 01:33:23 > VERBOSE[2649]: [[1;37;40mapp_prepaid_rate.so[0;37;40m] => ([33;40m > PrepaidRate(Destination,Tariffplan): Returns the Tariff rate for the > d) > Dec 10 01:33:23 VERBOSE[2649]: == Parsing > '/etc/asterisk/prepaid.conf': Dec 10 01:33:23 VERBOSE[2649]: => Parsing '/etc/asterisk/prepaid.conf': Found > Dec 10 01:33:23 VERBOSE[2649]: > [[1;37;40mapp_prepaid_rateplan.so[0;37;40m]Dec 10 01:33:23 > VERBOSE[2649]: [[1;37;40mapp_prepaid_rateplan.so[0;37;40m] => > ([33;40m PrepaidRatePlan(User): Returns the Tariff plan for the > specified User.) > Dec 10 01:33:23 VERBOSE[2649]: == Parsing > '/etc/asterisk/prepaid.conf': Dec 10 01:33:23 VERBOSE[2649]: => Parsing '/etc/asterisk/prepaid.conf': Found > Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database > Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': > Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': > Found > Dec 10 01:33:23 VERBOSE[2649]: == Parsing > '/etc/asterisk/extconfig.conf': Dec 10 01:33:23 VERBOSE[2649]: => Parsing '/etc/asterisk/extconfig.conf': Found > Dec 10 01:33:23 VERBOSE[2649]: Asterisk Event Logger restarted > Dec 10 01:33:23 VERBOSE[2649]: == Parsing > '/etc/asterisk/manager.conf': Dec 10 01:33:23 VERBOSE[2649]: => Parsing '/etc/asterisk/manager.conf': Found > Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': > Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/enum.conf': > Found > Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/rtp.conf': > Dec 10 01:33:23 VERBOSE[2649]: == Parsing '/etc/asterisk/rtp.conf': > Found > Dec 10 01:33:23 VERBOSE[2649]: == RTP Allocating from port range > 10000 -> 20000 > Dec 10 01:33:23 VERBOSE[2649]: [1;37;40mAsterisk Ready. > [0;37;40mDec 10 01:33:39 DEBUG[2661]: Auto destroying call > '950c71b7-7fa51914@192.168.0.218' > ----------------------------------------------------------------------------------------------------------------- > Note that the 192.168.0.218' is our SIPURA > > Thanks. > > Andy > _______________________________________________ > Asterisk-Users mailing list > Asterisk-Users@lists.digium.com > http://lists.digium.com/mailman/listinfo/asterisk-users > To UNSUBSCRIBE or update options visit: > http://lists.digium.com/mailman/listinfo/asterisk-users-- Howard. LANNet Computing Associates; Your Linux people <http://www.lannetlinux.com> ------------------------------------------ "When you just want a system that works, you choose Linux; when you want a system that just works, you choose Microsoft." ------------------------------------------ "Flatter government, not fatter government; Get rid of the Australian states."
K Wong
2004-Dec-09 23:47 UTC
[Asterisk-Users] Asterisk started but doesn't register SIP client
Hi: We just setup the Asterisk and it seems to start ok. We checked the log, and beside the timer warning, there isn't other error message. However, we tried both SIPURA and XLite, but their registration is not accepted (timed out and failed). Could someone tell me what's wrong? [message] Dec 10 01:33:22 WARNING[2649]: Unable to open IAX timing interface: Permission denied Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database Dec 10 01:33:23 WARNING[2649]: Unable to open Asterisk database [debug] Dec 10 01:33:22 DEBUG[2649]: VM Review Option disabled globally Dec 10 01:33:22 DEBUG[2649]: VM Operator break disabled globally Dec 10 01:33:22 DEBUG[2649]: VM CID Info before msg disabled globally Dec 10 01:33:22 DEBUG[2649]: Send Voicemail msg disabled globally Dec 10 01:33:22 DEBUG[2649]: ENVELOPE before msg enabled globally Dec 10 01:33:22 DEBUG[2649]: We are not going to skip to the next msg after save/delete Dec 10 01:33:22 DEBUG[2649]: 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:22 DEBUG[2649]: 69.73.19.178/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:23 DEBUG[2649]: 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:23 DEBUG[2649]: 69.73.19.178/255.255.255.255/255.255.255.255 appended to acl for peer Dec 10 01:33:23 DEBUG[2649]: Scheduled a timeout # 1 Dec 10 01:33:23 DEBUG[2661]: Stopping retransmission on '366b24810a0bb91355fbb4ba7d9a27ef@127.0.0.1' of Request 102: Found Dec 10 01:33:23 DEBUG[2661]: Setting NAT on RTP to 4 Dec 10 01:33:23 DEBUG[2661]: Stopping retransmission on '366b24810a0bb91355fbb4ba7d9a27ef@127.0.0.1' of Request 103: Found Dec 10 01:33:23 DEBUG[2661]: Registration successful Dec 10 01:33:23 DEBUG[2661]: Cancelling timeout 1 Dec 10 01:33:23 DEBUG[2661]: Setting NAT on RTP to 4 Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got hostname of localhost Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got port of 3306 Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got sock file of /var/lib/mysql/mysql.sock Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got user of XXXXXXX Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got dbname of XXXXXX Dec 10 01:33:23 DEBUG[2649]: cdr_mysql: got password of XXXXXX Dec 10 01:33:23 DEBUG[2649]: Successfully connected to MySQL database. Dec 10 01:33:39 DEBUG[2661]: Auto destroying call '950c71b7-7fa51914@192.168.0.218' [full] .................... Dec 10 01:33:23 VERBOSE[2649]: [1;37;40mAsterisk Ready. [0;37;40mDec 10 01:33:39 DEBUG[2661]: Auto destroying call '950c71b7-7fa51914@192.168.0.218' ----------------------------------------------------------------------------------------------------------------- Note that the 192.168.0.218' is our SIPURA Thanks. Andy