[asterisk-users] FreePBX/Debian Aborts Call While Connecting

Thu Feb 1 00:28:52 MST 2007

Yeah, your waittime parameter in your call file is set to 45 seconds.

db

On Wed, 2007-01-31 at 21:52 -0500, Matthew Rubenstein wrote:
> 	I used the "FreePBX on Debian" HowTo at
> http://powerontech.com/freepbx-on-debian.htm to install. I use callfiles
> to initiate calls to my SIP carrier. They get my registration, but they
> see that my call is interrupted before they can complete the connection.
> My Asterisk log shows that the call times out after the time (45s)
> specified in my dialplan Dial() command. What is wrong?
> 
> [from /var/log/asterisk/full]:
> Jan 30 23:40:35 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '24154c0d430e550821bda73c155cf573 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:40:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:40:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: Scheduled a registration timeout
> for 66.153.22.16 id  #17818 
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 606: Found
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 606: Match
> Found
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 607: Found
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 607: Match
> Found
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: Registration successful
> Jan 30 23:40:44 DEBUG[6245] chan_sip.c: Cancelling timeout 17818
> Jan 30 23:41:16 DEBUG[6245] chan_sip.c: Auto destroying call
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196'
> Jan 30 23:41:30 VERBOSE[17267] logger.c:     -- Attempting call on
> Local/callFrom at ext-jjp-out/n for callTo at ext-jjp-out:1 (Retry 1)
> Jan 30 23:41:30 VERBOSE[17269] logger.c:     -- Executing
> NoOp("Local/callFrom at ext-jjp-out-5c02,2", "Calling
> SIP/16467508273 at tu3961") in new stack
> Jan 30 23:41:30 VERBOSE[17269] logger.c:     -- Executing
> Dial("Local/callFrom at ext-jjp-out-5c02,2", "SIP/16467508273 at tu3961|45|
> M(say-call-2-digits^17182335097)g") in new stack
> Jan 30 23:41:30 DEBUG[17269] chan_sip.c: Setting NAT on RTP to 0
> Jan 30 23:41:30 DEBUG[17269] chan_sip.c: Outgoing Call for 16467508273
> Jan 30 23:41:30 VERBOSE[17269] logger.c:     -- Called
> 16467508273 at tu3961
> Jan 30 23:41:30 DEBUG[6245] chan_sip.c: Acked pending invite 102
> Jan 30 23:41:30 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '508201545ea2763679ff481e5e3312de at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:41:30 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '508201545ea2763679ff481e5e3312de at 82.165.187.196' Request 103: Found
> Jan 30 23:41:35 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '3a82c93e1b4f83542067e66d1ce44d99 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:42:15 VERBOSE[17269] logger.c:     -- Nobody picked up in
> 45000 ms
> Jan 30 23:42:15 DEBUG[17269] chan_sip.c:
> update_call_counter(16467508273) - decrement call limit counter
> Jan 30 23:42:15 DEBUG[17269] chan_sip.c: Acked pending invite 103
> Jan 30 23:42:15 DEBUG[17269] chan_sip.c: Stopping retransmission on
> '508201545ea2763679ff481e5e3312de at 82.165.187.196' of Request 103: Match
> Found
> Jan 30 23:42:15 DEBUG[17269] app_dial.c: Exiting with
> DIALSTATUS=NOANSWER.
> Jan 30 23:42:15 VERBOSE[17269] logger.c:     -- Executing
> NoOp("Local/callFrom at ext-jjp-out-5c02,2", "Done dialing from") in new
> stack
> Jan 30 23:42:15 DEBUG[17267] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Jan 30 23:42:15 DEBUG[17267] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-01-30 23:42:15','16467508273','16467508273','callTo','ext-jjp-out', 'Local/callFrom at ext-jjp-out-5c02,1','','Dial','Local/callFrom at ext-jjp-out/n',0,0,'FAILED',3,'','1170196890.32')
> Jan 30 23:42:15 DEBUG[17267] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Jan 30 23:42:15 DEBUG[17267] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-01-30 23:42:15','','','s','default', '**Unknown**','','','',0,0,'FAILED',3,'','1170196935.35')
> Jan 30 23:42:15 NOTICE[17267] pbx_spool.c: Call failed to go through,
> reason 0
> Jan 30 23:42:15 DEBUG[17269] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Jan 30 23:42:15 DEBUG[17269] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-01-30 23:41:30','16467508273','16467508273','callFrom','ext-jjp-out', 'Local/callFrom at ext-jjp-out-5c02,2','SIP/tu3961-08196340','NoOp','Done dialing from',45,0,'NO ANSWER',3,'','1170196890.33')
> Jan 30 23:42:15 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '508201545ea2763679ff481e5e3312de at 82.165.187.196' of Request 103: Match
> Not Found
> Jan 30 23:42:15 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '508201545ea2763679ff481e5e3312de at 82.165.187.196' of Request 103: Match
> Found
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: Scheduled a registration timeout
> for 66.153.22.16 id  #17831 
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 608: Found
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 608: Match
> Found
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 609: Found
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 609: Match
> Found
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: Registration successful
> Jan 30 23:42:29 DEBUG[6245] chan_sip.c: Cancelling timeout 17831
> Jan 30 23:42:35 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7cad49c820c295d563d0eade058e921a at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:42:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:42:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:42:47 DEBUG[6245] chan_sip.c: Auto destroying call
> '508201545ea2763679ff481e5e3312de at 82.165.187.196'
> Jan 30 23:43:01 DEBUG[6245] chan_sip.c: Auto destroying call
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196'
> Jan 30 23:43:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '79c8030b4ca3a93d23d1053f3db4d43d at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: Scheduled a registration timeout
> for 66.153.22.16 id  #17842 
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 610: Found
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 610: Match
> Found
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 611: Found
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 611: Match
> Found
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: Registration successful
> Jan 30 23:44:14 DEBUG[6245] chan_sip.c: Cancelling timeout 17842
> Jan 30 23:44:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '1b9a800d5a61fcbe2aa6721c1483e190 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:44:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:44:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:44:46 DEBUG[6245] chan_sip.c: Auto destroying call
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196'
> Jan 30 23:45:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '4bbf61f037fc67773c326db57b0e24f7 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: Scheduled a registration timeout
> for 66.153.22.16 id  #17853 
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 612: Found
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 612: Match
> Found
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 613: Found
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 613: Match
> Found
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: Registration successful
> Jan 30 23:45:59 DEBUG[6245] chan_sip.c: Cancelling timeout 17853
> Jan 30 23:46:31 DEBUG[6245] chan_sip.c: Auto destroying call
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196'
> Jan 30 23:46:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '640079ef7eec017d1cbc5020117abc9d at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:46:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:46:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:47:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '513ea44e1c43748f306e93cb17fcb16c at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: Scheduled a registration timeout
> for 66.153.22.16 id  #17864 
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 614: Found
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 614: Match
> Found
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 615: Found
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 615: Match
> Found
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: Registration successful
> Jan 30 23:47:44 DEBUG[6245] chan_sip.c: Cancelling timeout 17864
> Jan 30 23:48:16 DEBUG[6245] chan_sip.c: Auto destroying call
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196'
> Jan 30 23:48:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '66e68ffe3d92ea582adc6aa752a8b435 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:48:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:48:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: Scheduled a registration timeout
> for 66.153.22.16 id  #17872 
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 616: Found
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 616: Match
> Found
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' Request 617: Found
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196' of Request 617: Match
> Found
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: Registration successful
> Jan 30 23:49:29 DEBUG[6245] chan_sip.c: Cancelling timeout 17872
> Jan 30 23:49:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '5c28a2110cf2888e740593cf1cbc7547 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:50:01 DEBUG[6245] chan_sip.c: Auto destroying call
> '7c2631854f167c817c1479d454825c1c at 82.165.187.196'
> Jan 30 23:50:36 DEBUG[6245] chan_sip.c: Stopping retransmission on
> '2b3150cc1aa23bb31264551c07655122 at 82.165.187.196' of Request 102: Match
> Found
> Jan 30 23:50:44 DEBUG[6268] manager.c: Manager received command
> 'Command'
> Jan 30 23:50:44 DEBUG[6268] manager.c: Manager received command
> 'Command'