ViciDial calls agent, then hangs up immediately after answer

[kwimberl]

I turned on iax2 debug and here's the output:


Mar 5 15:07:58 VERBOSE[18874] logger.c: > Channel IAX2/200-1 was answered.
Mar 5 15:07:58 VERBOSE[18878] logger.c: == Starting IAX2/200-1 at outgoing,8600051,1 failed so falling back to exten 's'
Mar 5 15:07:58 VERBOSE[18878] logger.c: == Starting IAX2/200-1 at outgoing,s,1 still failed so falling back to context 'default'
Mar 5 15:07:58 WARNING[18878] pbx.c: Channel 'IAX2/200-1' sent into invalid extension 's' in context 'default', but no invalid handler
Mar 5 15:07:58 VERBOSE[18878] logger.c: -- Executing DeadAGI("IAX2/200-1", "agi://127.0.0.1:4577/call_log") in new stack
Mar 5 15:07:58 VERBOSE[18878] logger.c: -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
Mar 5 15:07:58 VERBOSE[18878] logger.c: -- Executing DeadAGI("IAX2/200-1", "agi://127.0.0.1:4577/VD_hangup--HVcauses--PRI-----NODEBUG-----0---------------)") in new stack
Mar 5 15:07:58 VERBOSE[18878] logger.c: -- AGI Script agi://127.0.0.1:4577/VD_hangup--HVcause ... ----------) completed, returning 0
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'ACagcW11731252750200'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '(null)'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '8600051'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'outgoing'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'IAX2/200-1'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '(null)'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'DeadAGI'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'agi://127.0.0.1:4577/VD_hangup--HVcauses--PRI-----NODEBUG-----0---------------)'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '2007-03-05 15:07:58'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '(null)'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '2007-03-05 15:07:58'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '0'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '0'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'ANSWERED'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is 'DOCUMENTATION'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '(null)'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '1173125277.1051'
Mar 5 15:07:58 DEBUG[18878] pbx.c: Function result is '(null)'
Mar 5 15:07:58 DEBUG[18878] chan_iax2.c: We're hanging up IAX2/200-1 now...

[mflorell]

can you post the Asterisk CLI output BEFORE the output you posted?

[aster1]

i got exactly the same problem and vicidial in campaign status keep on showing its dialing the numbers . My problem was the dialplan once i fixed the dialplan it went all fine . Please post ur outgoing calls dialplan below ..

Also i removed 's' extension from default context used by vicidial because if you dont keep 's' extension then it just hangs up the call or else it falls back to 's' extension's definition ( since i dont use server for incoming calls ) . However the only culprit here is ur outgoing dialplan not 's' extension .

[kwimberl]

can you post the Asterisk CLI output BEFORE the output you posted?

Here's the whole stream:

asterisk*CLI>
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 00031ms SCall: 23368 DCall: 00001 [10.0.0.12:4569]
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW
Timestamp: 00016ms SCall: 00003 DCall: 00000 [10.0.0.12:4569]
VERSION : 2
CALLED NUMBER : s
CODEC_PREFS : (ulaw)
CALLING PRESNTN : 0
CALLING TYPEOFN : 0
CALLING TRANSIT : 0
CALLING NAME : S0703061020508600051
LANGUAGE : en
USERNAME : 200
FORMAT : 4
CAPABILITY : 63492
ADSICPE : 0
DATE TIME : 2007-03-06 10:20:50

Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00016ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACCEPT
Timestamp: 00062ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
FORMAT : 4
asterisk*CLI>
-- Call accepted by 10.0.0.12 (format ulaw)
-- Format for call is ulaw
Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00062ms SCall: 00003 DCall: 23369 [10.0.0.12:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: CONTROL Subclass: RINGING
Timestamp: 00003ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
Tx-Frame Retry[-01] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 00003ms SCall: 00003 DCall: 23369 [10.0.0.12:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 001 Type: IAX Subclass: PING
Timestamp: 02014ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 003 Type: IAX Subclass: PONG
Timestamp: 02014ms SCall: 00003 DCall: 23369 [10.0.0.12:4569]
RR_JITTER : 0
RR_LOSS : 0
RR_PKTS : 1
RR_DELAY : 40
RR_DROPPED : 0
RR_OUTOFORDER : 0

Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 02014ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ
Timestamp: 00003ms SCall: 00004 DCall: 00000 [208.101.3.2:4569]
USERNAME : 328104119
REFRESH : 60

Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
Timestamp: 00003ms SCall: 00058 DCall: 00004 [208.101.3.2:4569]
Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: REGAUTH
Timestamp: 00009ms SCall: 00058 DCall: 00004 [208.101.3.2:4569]
AUTHMETHODS : 3
CHALLENGE : 159711198
USERNAME : 328104119

Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: REGREQ
Timestamp: 00034ms SCall: 00004 DCall: 00058 [208.101.3.2:4569]
USERNAME : 328104119
REFRESH : 60
MD5 RESULT : 64448a62c53f4ec8a4c0339b359cc9aa

Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 00034ms SCall: 00058 DCall: 00004 [208.101.3.2:4569]
Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: REGACK
Timestamp: 00040ms SCall: 00058 DCall: 00004 [208.101.3.2:4569]
USERNAME : 328104119
DATE TIME : 2007-03-06 07:20:54
REFRESH : 60
APPARENT ADDRES : IPV4 67.79.158.190:4569
asterisk*CLI>
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK
Timestamp: 00040ms SCall: 00004 DCall: 00058 [208.101.3.2:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass: ANSWER
Timestamp: 04716ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK
Timestamp: 04716ms SCall: 00003 DCall: 23369 [10.0.0.12:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 002 Type: VOICE Subclass: 4
Timestamp: 04740ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 005 Type: IAX Subclass: ACK
Timestamp: 04740ms SCall: 00003 DCall: 23369 [10.0.0.12:4569]
> Channel IAX2/200-3 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
== Starting IAX2/200-3 at outgoing,8600051,1 failed so falling back to exten 's'
== Starting IAX2/200-3 at outgoing,s,1 still failed so falling back to context 'default'
Mar 6 10:20:55 WARNING[3944]: pbx.c:2357 __ast_pbx_run: Channel 'IAX2/200-3' sent into invalid extension 's' in context 'default', but no invalid handler
-- Executing DeadAGI("IAX2/200-3", "agi://127.0.0.1:4577/call_log") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
-- Executing DeadAGI("IAX2/200-3", "agi://127.0.0.1:4577/VD_hangup--HVcauses--PRI-----NODEBUG-----0---------------)") in new stack
-- AGI Script agi://127.0.0.1:4577/VD_hangup--HVcause ... ----------) completed, returning 0
Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 005 Type: IAX Subclass: HANGUP
Timestamp: 04923ms SCall: 00003 DCall: 23369 [10.0.0.12:4569]
CAUSE CODE : 0

-- Hungup 'IAX2/200-3'
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 003 Type: IAX Subclass: ACK
Timestamp: 04923ms SCall: 23369 DCall: 00003 [10.0.0.12:4569]
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
== Manager 'sendcron' logged off from 127.0.0.1
== Manager 'sendcron' logged off from 127.0.0.1

[kwimberl]

i got exactly the same problem and vicidial in campaign status keep on showing its dialing the numbers . My problem was the dialplan once i fixed the dialplan it went all fine . Please post ur outgoing calls dialplan below ..

Also i removed 's' extension from default context used by vicidial because if you dont keep 's' extension then it just hangs up the call or else it falls back to 's' extension's definition ( since i dont use server for incoming calls :P ) . However the only culprit here is ur outgoing dialplan not 's' extension :) .

[outgoing]
;exten => h,1,DeadAGI(agi://127.0.0.1:4577/call_log)
;exten => h,2,DeadAGI(agi://127.0.0.1:4577/VD_hangup--HVcause ... EBUG-----${HANGUPCAUSE}-----${DIALSTATUS}-----${DIALEDTIME}-----${ANSWEREDTIME}))
exten => _1NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _1NXXNXXXXXX,n,dial(${IAX2trunk}/${EXTEN:0},60,Tto)
exten => _1NXXNXXXXXX,n,congestion
exten => _NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _NXXNXXXXXX,n,Dial(SIP/viatalk4630/${EXTEN},60,Tto)
exten => _NXXNXXXXXX,n,Dial(SIP/viatalk1957/${EXTEN},60,Tto)
exten => _NXXNXXXXXX,n,Dial(SIP/SR0380/${EXTEN},60,Tto)
exten => _NXXNXXXXXX,n,Hangup
exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,n,dial(${IAX2trunk}/${EXTEN:1},60,Tto)
exten => _91NXXNXXXXXX,n,congestion


The relevant part is the last three lines

[kwimberl]

can you post the Asterisk CLI output BEFORE the output you posted?

Without debug on, it looks like this:

== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
-- Call accepted by 10.0.0.12 (format ulaw)
-- Format for call is ulaw
> Channel IAX2/200-4 was answered.
== Starting IAX2/200-4 at outgoing,8600051,1 failed so falling back to exten 's'
== Starting IAX2/200-4 at outgoing,s,1 still failed so falling back to context 'default'
Mar 6 10:31:27 WARNING[4733]: pbx.c:2357 __ast_pbx_run: Channel 'IAX2/200-4' sent into invalid extension 's' in context 'default', but no invalid handler
-- Executing DeadAGI("IAX2/200-4", "agi://127.0.0.1:4577/call_log") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
-- Executing DeadAGI("IAX2/200-4", "agi://127.0.0.1:4577/VD_hangup--HVcauses--PRI-----NODEBUG-----0---------------)") in new stack
-- AGI Script agi://127.0.0.1:4577/VD_hangup--HVcause ... ----------) completed, returning 0
-- Hungup 'IAX2/200-4'
== Manager 'sendcron' logged off from 127.0.0.1
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
== Manager 'sendcron' logged off from 127.0.0.1

[mflorell]

Do you have 8600051 in your extensions.conf and meetme.conf?

[aster1]

== Starting IAX2/200-4 at outgoing,8600051,1 failed so falling back to exten 's'
== Starting IAX2/200-4 at outgoing,s,1 still failed so falling back to context 'default'


ur outgoing context doesnt have meetme entries it seems .

[kwimberl]

ur outgoing context doesnt have meetme entries it seems .

Sheesh -- you were correct. A quick include => default did the trick.

Thanks!