mflorell wrote:Did you reload Asterisk after you made the changes?
This is almost always an 'h' exten omission problem.
I know... yes I did reload, I have two servers and a script to sync and reload them
when I change something.... and DeadAgi seems to be running... (several times, I think I have too many)
Here is the relevant lines from messages for one of the stuck calls:
Apr 25 09:33:33 VERBOSE[2718] logger.c: -- Accepting call from '412204000' to '1021249' on channel 0/22, span 1
Apr 25 09:33:33 DEBUG[2718] chan_zap.c: Enabled echo cancellation on channel 22
Apr 25 09:33:33 VERBOSE[1295] logger.c: -- Executing Wait("Zap/22-1", "1") in new stack
Apr 25 09:33:33 DEBUG[30405] manager.c: Manager received command 'Command'
Apr 25 09:33:34 DEBUG[30405] manager.c: Manager received command 'Command'
Apr 25 09:33:34 VERBOSE[1295] logger.c: -- Executing Answer("Zap/22-1", "") in new stack
Apr 25 09:33:34 VERBOSE[1295] logger.c: -- Executing SetCDRUserField("Zap/22-1", "in-telmex") in new stack
Apr 25 09:33:34 VERBOSE[1295] logger.c: -- Executing AGI("Zap/22-1", "agi-VDAD_ALL_inbound.agi|CIDLOOKUPRC-----LB-----TelmexCom-----1021249-----Closer-----park----------8000-----56-----TelmexIN") in new stack
Apr 25 09:33:34 VERBOSE[1295] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi
Apr 25 09:33:38 VERBOSE[1295] logger.c: -- Started music on hold, class 'dmt', on Zap/22-1
Apr 25 09:33:51 VERBOSE[1295] logger.c: -- Stopped music on hold on Zap/22-1
Apr 25 09:33:52 VERBOSE[1378] logger.c: -- Executing MeetMe("Local/78603011@default-8026,2", "8603011|q") in new stack
Apr 25 09:33:52 DEBUG[2630] channel.c: Avoiding initial deadlock for 'Local/78603011@default-8026,2'
Apr 25 09:33:52 DEBUG[1378] app_meetme.c: Placed channel Local/78603011@default-8026,2 in ZAP conf 1013
Apr 25 09:33:52 VERBOSE[1379] logger.c: -- Executing Answer("Local/78603011@default-8026,1", "") in new stack
Apr 25 09:33:52 VERBOSE[1379] logger.c: -- Executing Monitor("Local/78603011@default-8026,1", "gsm|/var/spool/asterisk/
monitor/vicidial/TELMEXIN-20080425-093350-412204000") in new stack
Apr 25 09:33:52 VERBOSE[1379] logger.c: -- Executing Wait("Local/78603011@default-8026,1", "3600") in new stack
Apr 25 09:33:52 DEBUG[30405] manager.c: Manager received command 'Command'
Apr 25 09:33:52 VERBOSE[1295] logger.c: -- AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0
Apr 25 09:33:52 VERBOSE[1295] logger.c: -- Executing Goto("Zap/22-1", "vicidial|8603011|1") in new stack
Apr 25 09:33:52 VERBOSE[1295] logger.c: -- Goto (vicidial,8603011,1)
Apr 25 09:33:52 VERBOSE[1295] logger.c: -- Executing MeetMe("Zap/22-1", "8603011") in new stack
Apr 25 09:33:52 DEBUG[1295] chan_zap.c: Requested indication -1 on channel Zap/22-1
Apr 25 09:33:52 DEBUG[1295] app_meetme.c: Placed channel Zap/22-1 in ZAP conf 1013
Apr 25 09:37:19 VERBOSE[1295] logger.c: == Spawn extension (vicidial, 8603011, 1) exited non-zero on 'Zap/22-1'
Apr 25 09:37:19 VERBOSE[1295] logger.c: -- Executing DeadAGI("Zap/22-1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-
----NODEBUG-----0---------------)") in new stack
Apr 25 09:37:19 VERBOSE[1378] logger.c: == Spawn extension (default, 78603011, 1) exited non-zero on 'Local/78603011@defa
ult-8026,2'
Apr 25 09:37:19 VERBOSE[1378] logger.c: -- Executing DeadAGI("Local/78603011@default-8026,2", "agi://127.0.0.1:4577/cal
l_log--HVcauses--PRI-----NODEBUG-----0---------------)") in new stack
Apr 25 09:37:19 VERBOSE[1378] logger.c: -- AGI Script
agi://127.0.0.1:4577/call_log--HVcauses ... G-----0---
------------) completed, returning 0
Apr 25 09:37:19 VERBOSE[1379] logger.c: == Spawn extension (default, 8310, 3) exited non-zero on 'Local/78603011@default-
8026,1'
Apr 25 09:37:19 VERBOSE[1379] logger.c: -- Executing DeadAGI("Local/78603011@default-8026,1", "agi://127.0.0.1:4577/cal
l_log--HVcauses--PRI-----NODEBUG-----0---------------)") in new stack
Apr 25 09:37:19 DEBUG[1378] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Apr 25 09:37:19 DEBUG[1378] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dc
ontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2008-04-25
09:33:52','TELMEXIN-20080425-093350-412204000','','78603011','default', 'Local/78603011@default-8026,2','','MeetMe','86030
11|q',207,207,'ANSWERED',3,'','')
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is 'TELMEXIN-20080425-093350-412204000'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '78603011'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is 'default'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is 'Local/78603011@default-8026,2'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is 'MeetMe'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '8603011|q'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '2008-04-25 09:33:52'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '2008-04-25 09:33:52'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '2008-04-25 09:37:19'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '207'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '207'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is 'ANSWERED'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is 'DOCUMENTATION'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '1209130432.564192'
Apr 25 09:37:19 DEBUG[1378] pbx.c: Function result is '(null)'
Apr 25 09:37:19 VERBOSE[1295] logger.c: -- AGI Script
agi://127.0.0.1:4577/call_log--HVcauses ... G-----0---
------------) completed, returning 0
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/22-1
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: Hangup: channel: 22 index = 0, normal = 38, callwait = -1, thirdcall = -1
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: disabled echo cancellation on channel 22
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/22-1
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: Updated conferencing on 22, with 0 conference users
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/22-1
Apr 25 09:37:19 DEBUG[1295] chan_zap.c: disabled echo cancellation on channel 22
Apr 25 09:37:19 VERBOSE[1295] logger.c: -- Hungup 'Zap/22-1'
Apr 25 09:37:19 DEBUG[1295] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Apr 25 09:37:19 DEBUG[1295] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dc
ontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2008-04-25
09:33:33','"Y042593334004333289" <412204000>','412204000','8603011','vicidial', 'Zap/22-1','','MeetMe','8603011',226,225
,'ANSWERED',3,'','in-telmex')
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '"Y042593334004333289" <412204000>'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '412204000'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '8603011'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is 'vicidial'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is 'Zap/22-1'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is 'MeetMe'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '8603011'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '2008-04-25 09:33:33'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '2008-04-25 09:33:34'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '2008-04-25 09:37:19'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '226'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '225'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is 'ANSWERED'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is 'DOCUMENTATION'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is '1209130413.564179'
Apr 25 09:37:19 DEBUG[1295] pbx.c: Function result is 'in-telmex'
Apr 25 09:37:19 VERBOSE[1379] logger.c: -- AGI Script
agi://127.0.0.1:4577/call_log--HVcauses ... G-----0---
------------) completed, returning 0
Apr 25 09:37:19 DEBUG[1379] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Apr 25 09:37:19 DEBUG[1379] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dc
ontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2008-04-25
09:33:52','TELMEXIN-20080425-093350-412204000','','8310','default', 'Local/78603011@default-8026,1','','Wait','3600',207,2
07,'ANSWERED',3,'','')
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is 'TELMEXIN-20080425-093350-412204000'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '8310'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is 'default'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is 'Local/78603011@default-8026,1'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is 'Wait'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '3600'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '2008-04-25 09:33:52'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '2008-04-25 09:33:52'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '2008-04-25 09:37:19'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '207'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '207'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is 'ANSWERED'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is 'DOCUMENTATION'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '(null)'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '1209130432.564191'
Apr 25 09:37:19 DEBUG[1379] pbx.c: Function result is '(null)'