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

Matthew Rubenstein email at mattruby.com
Wed Jan 31 19:52:49 MST 2007


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

(C) Matthew Rubenstein



More information about the asterisk-users mailing list