manual calls OK, auto dialed campaigns drop calls at 5 sec

General and Support topics relating to ViciDialNow and GoAutoDial ISO installers

Moderators: enjay, williamconley, Op3r, Staydog, gardo, mflorell, MJCoate, mcargile, Kumba, s0lid

manual calls OK, auto dialed campaigns drop calls at 5 sec

Postby butchie3980 » Wed Jul 09, 2008 2:15 pm

Installed vicidialnow rc1. I have a trixbox PBX upstream of the dialer machine (here comes some ascii art):

[vicidialnow server]------>[trixbox]------>[sip provider]

When I run a campaign manually, the calls go through just fine.
When I run an auto campaign, the call gets connected, then disconnected 5 seconds later. I've fiddled with settings (like adding exten => 8365,1,Playback(sip-silence)), but with no success so far.

any help on how to troubleshoot this?

Thanks in advance,
butchie
butchie3980
 
Posts: 8
Joined: Tue Jul 01, 2008 4:40 pm

Postby mflorell » Wed Jul 09, 2008 5:25 pm

any Asterisk CLI output?

agiout logfile output of the transfer AGI script?
mflorell
Site Admin
 
Posts: 18384
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby butchie3980 » Thu Jul 10, 2008 12:52 pm

mflorell wrote:any Asterisk CLI output?

agiout logfile output of the transfer AGI script?


OK. Here goes:

asterisk CLI (I did a tail on /screenlog.0):

> Channel SIP/cc100-08eeaf40 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
-- Executing MeetMe("SIP/cc100-08eeaf40", "8600051|F") in new stack
== Parsing '/etc/asterisk/meetme.conf': Found
-- Created MeetMe conference 1023 for conference '8600051'
-- Playing 'conf-onlyperson' (language 'en')
-- Executing AGI("Local/917025551111@default-1410,2", "agi://127.0.0.1:4577/call_log") in new stack
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
-- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
-- Executing Dial("Local/917025551111@default-1410,2", "SIP/SIPtrunk/17025552222||To") in new stack
-- Called SIPtrunk/17025552222
-- Executing AGI("Local/914125553333@default-e63a,2", "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 Dial("Local/914125553333@default-e63a,2", "SIP/SIPtrunk/14125553333||To") in new stack
-- Called SIPtrunk/14125553333
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
-- Executing AGI("Local/917025554444@default-5bb7,2", "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 Dial("Local/917025554444@default-5bb7,2", "SIP/SIPtrunk/17025554444||To") in new stack
-- Called SIPtrunk/17025554444
-- SIP/SIPtrunk-08ef8968 is making progress passing it to Local/917025551111@default-1410,2
-- SIP/SIPtrunk-08f09360 is making progress passing it to Local/914125553333@default-e63a,2
-- SIP/SIPtrunk-08f14c90 is making progress passing it to Local/917025554444@default-5bb7,2
-- SIP/SIPtrunk-08f14c90 answered Local/917025554444@default-5bb7,2
> Channel Local/917025554444@default-5bb7,1 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
-- Executing Playback("Local/917025554444@default-5bb7,1", "sip-silence") in new stack
-- Playing 'sip-silence' (language 'en')
-- Executing AGI("Local/917025554444@default-5bb7,1", "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 AGI("Local/917025554444@default-5bb7,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/917025554444@default-5bb7,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/917025554444@default-5bb7,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- SIP/SIPtrunk-08ef8968 answered Local/917025551111@default-1410,2
> Channel Local/917025551111@default-1410,1 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
-- Executing Playback("Local/917025551111@default-1410,1", "sip-silence") in new stack
-- Playing 'sip-silence' (language 'en')
-- Executing AGI("Local/917025551111@default-1410,1", "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 AGI("Local/917025551111@default-1410,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing Hangup("Local/917025554444@default-5bb7,1", "") in new stack
== Spawn extension (default, 8365, 6) exited non-zero on 'Local/917025554444@default-5bb7,1'
-- Executing DeadAGI("Local/917025554444@default-5bb7,1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
== Spawn extension (default, 917025554444, 2) exited non-zero on 'Local/917025554444@default-5bb7,2'
-- Executing DeadAGI("Local/917025554444@default-5bb7,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----15-----4") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --15-----4 completed, returning 0
-- SIP/SIPtrunk-08f09360 answered Local/914125553333@default-e63a,2
> Channel Local/914125553333@default-e63a,1 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
-- Executing Playback("Local/914125553333@default-e63a,1", "sip-silence") in new stack
-- Playing 'sip-silence' (language 'en')
-- Executing AGI("Local/914125553333@default-e63a,1", "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 AGI("Local/914125553333@default-e63a,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/917025551111@default-1410,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/914125553333@default-e63a,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/917025551111@default-1410,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/914125553333@default-e63a,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing Hangup("Local/917025551111@default-1410,1", "") in new stack
== Spawn extension (default, 8365, 6) exited non-zero on 'Local/917025551111@default-1410,1'
-- Executing DeadAGI("Local/917025551111@default-1410,1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
== Spawn extension (default, 917025551111, 2) exited non-zero on 'Local/917025551111@default-1410,2'
-- Executing DeadAGI("Local/917025551111@default-1410,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----19-----4") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --19-----4 completed, returning 0
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing Hangup("Local/914125553333@default-e63a,1", "") in new stack
== Spawn extension (default, 8365, 6) exited non-zero on 'Local/914125553333@default-e63a,1'
-- Executing DeadAGI("Local/914125553333@default-e63a,1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
== Spawn extension (default, 914125553333, 2) exited non-zero on 'Local/914125553333@default-e63a,2'
-- Executing DeadAGI("Local/914125553333@default-e63a,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----20-----4") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --20-----4 completed, returning 0
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
-- Executing AGI("Local/917025556666@default-73e1,2", "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 Dial("Local/917025556666@default-73e1,2", "SIP/SIPtrunk/17025556666||To") in new stack
-- Called SIPtrunk/17025556666
-- SIP/SIPtrunk-08ef8968 is making progress passing it to Local/917025556666@default-73e1,2
-- SIP/SIPtrunk-08ef8968 answered Local/917025556666@default-73e1,2
> Channel Local/917025556666@default-73e1,1 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
-- Executing Playback("Local/917025556666@default-73e1,1", "sip-silence") in new stack
-- Playing 'sip-silence' (language 'en')
-- Executing AGI("Local/917025556666@default-73e1,1", "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 AGI("Local/917025556666@default-73e1,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/917025556666@default-73e1,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing AGI("Local/917025556666@default-73e1,1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script agi-VDADtransfer.agi completed, returning 0
-- Executing Hangup("Local/917025556666@default-73e1,1", "") in new stack
== Spawn extension (default, 8365, 6) exited non-zero on 'Local/917025556666@default-73e1,1'
-- Executing DeadAGI("Local/917025556666@default-73e1,1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
== Spawn extension (default, 917025556666, 2) exited non-zero on 'Local/917025556666@default-73e1,2'
-- Executing DeadAGI("Local/917025556666@default-73e1,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----11-----4") in new stack
-- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --11-----4 completed, returning 0



And here is a tail on agiout.2008-07-10:
2008-07-10 10:25:31|agi-VDADtransfer.agi|+++++ VDAD START : |167|2008-07-10 10:25:31|1.2.27|3|
2008-07-10 10:25:31|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 3
2008-07-10 10:25:31|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:31|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:31|agi-VDADtransfer.agi|callerID changed: V0710102514000000166
2008-07-10 10:25:31|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- callerid = unknown
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- calleridname = V0710102514000000166
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- channel = Local/917025551111@default-1410,1
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- priority = 4
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:31|agi-VDADtransfer.agi| -- uniqueid = 1215710714.140
2008-07-10 10:25:31|agi-VDADtransfer.agi|AGI Variables: |1215710714.140|Local/917025551111@default-1410,1|8365|Local|V0710102514000000166|V0710102514000000166|4|
2008-07-10 10:25:31|agi-VDADtransfer.agi|+++++ VDAD START : |166|2008-07-10 10:25:31|1.2.27|4|
2008-07-10 10:25:31|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 4
2008-07-10 10:25:32|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:32|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:32|agi-VDADtransfer.agi|callerID changed: V0710102514000000167
2008-07-10 10:25:32|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callerid = unknown
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- calleridname = V0710102514000000167
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- channel = Local/914125553333@default-e63a,1
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- priority = 4
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- uniqueid = 1215710714.143
2008-07-10 10:25:32|agi-VDADtransfer.agi|AGI Variables: |1215710714.143|Local/914125553333@default-e63a,1|8365|Local|V0710102514000000167|V0710102514000000167|4|
2008-07-10 10:25:32|agi-VDADtransfer.agi|+++++ VDAD START : |167|2008-07-10 10:25:32|1.2.27|4|
2008-07-10 10:25:32|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 4
2008-07-10 10:25:32|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:32|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:32|agi-VDADtransfer.agi|callerID changed: V0710102514000000166
2008-07-10 10:25:32|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callerid = unknown
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- calleridname = V0710102514000000166
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- channel = Local/917025551111@default-1410,1
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- priority = 5
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:32|agi-VDADtransfer.agi| -- uniqueid = 1215710714.140
2008-07-10 10:25:32|agi-VDADtransfer.agi|AGI Variables: |1215710714.140|Local/917025551111@default-1410,1|8365|Local|V0710102514000000166|V0710102514000000166|5|
2008-07-10 10:25:32|agi-VDADtransfer.agi|+++++ VDAD START : |166|2008-07-10 10:25:32|1.2.27|5|
2008-07-10 10:25:32|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 5
2008-07-10 10:25:33|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:33|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:33|agi-VDADtransfer.agi|callerID changed: V0710102514000000167
2008-07-10 10:25:33|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- callerid = unknown
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- calleridname = V0710102514000000167
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- channel = Local/914125553333@default-e63a,1
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- priority = 5
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:33|agi-VDADtransfer.agi| -- uniqueid = 1215710714.143
2008-07-10 10:25:33|agi-VDADtransfer.agi|AGI Variables: |1215710714.143|Local/914125553333@default-e63a,1|8365|Local|V0710102514000000167|V0710102514000000167|5|
2008-07-10 10:25:33|agi-VDADtransfer.agi|+++++ VDAD START : |167|2008-07-10 10:25:33|1.2.27|5|
2008-07-10 10:25:33|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 5
2008-07-10 10:25:42|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:42|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:42|agi-VDADtransfer.agi|callerID changed: V0710102534000000169
2008-07-10 10:25:42|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- callerid = 0000000000
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- calleridname = V0710102534000000169
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- channel = Local/917025556666@default-73e1,1
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- priority = 3
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:42|agi-VDADtransfer.agi| -- uniqueid = 1215710735.149
2008-07-10 10:25:42|agi-VDADtransfer.agi|AGI Variables: |1215710735.149|Local/917025556666@default-73e1,1|8365|Local|V0710102534000000169|V0710102534000000169|3|
2008-07-10 10:25:42|agi-VDADtransfer.agi|+++++ VDAD START : |169|2008-07-10 10:25:42|1.2.27|3|
2008-07-10 10:25:42|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 3
2008-07-10 10:25:44|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:44|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:44|agi-VDADtransfer.agi|callerID changed: V0710102534000000169
2008-07-10 10:25:44|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- callerid = unknown
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- calleridname = V0710102534000000169
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- channel = Local/917025556666@default-73e1,1
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- priority = 4
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:44|agi-VDADtransfer.agi| -- uniqueid = 1215710735.149
2008-07-10 10:25:44|agi-VDADtransfer.agi|AGI Variables: |1215710735.149|Local/917025556666@default-73e1,1|8365|Local|V0710102534000000169|V0710102534000000169|4|
2008-07-10 10:25:44|agi-VDADtransfer.agi|+++++ VDAD START : |169|2008-07-10 10:25:44|1.2.27|4|
2008-07-10 10:25:44|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 4
2008-07-10 10:25:45|agi-VDADtransfer.agi|Perl Environment Dump:
2008-07-10 10:25:45|agi-VDADtransfer.agi|0|8365
2008-07-10 10:25:45|agi-VDADtransfer.agi|callerID changed: V0710102534000000169
2008-07-10 10:25:45|agi-VDADtransfer.agi|AGI Environment Dump:
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- accountcode =
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- callerid = unknown
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- calleridname = V0710102534000000169
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- callingani2 = 0
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- callingpres = 0
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- callingtns = 0
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- callington = 0
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- channel = Local/917025556666@default-73e1,1
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- context = default
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- dnid = unknown
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- enhanced = 0.0
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- extension = 8365
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- language = en
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- priority = 5
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- rdnis = unknown
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- type = Local
2008-07-10 10:25:45|agi-VDADtransfer.agi| -- uniqueid = 1215710735.149
2008-07-10 10:25:45|agi-VDADtransfer.agi|AGI Variables: |1215710735.149|Local/917025556666@default-73e1,1|8365|Local|V0710102534000000169|V0710102534000000169|5|
2008-07-10 10:25:45|agi-VDADtransfer.agi|+++++ VDAD START : |169|2008-07-10 10:25:45|1.2.27|5|
2008-07-10 10:25:45|agi-VDADtransfer.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 5
butchie3980
 
Posts: 8
Joined: Tue Jul 01, 2008 4:40 pm

Postby mflorell » Fri Jul 11, 2008 2:41 am

What is the loadavg on the Trixbox server?

Have you tried IAX trunk instead?
mflorell
Site Admin
 
Posts: 18384
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby butchie3980 » Fri Jul 11, 2008 12:17 pm

mflorell wrote:What is the loadavg on the Trixbox server?

Have you tried IAX trunk instead?


OK, ran the test while running top.
Load average when Idle hovers around 0.07.
Load average when making the calls (one agent test run against 5 phone numbers) is around 0.26 to 0.35.

I thought about an IAX trunk a few days ago and took a swipe at it. My first attempt wasn't successful, so we decided to stay with the SIP. I guess i should go back and try again. My gut tells me an IAX trunk would do better.

Any helpful hints on setting up an IAX trunk between a vicidial server and a trixbox?

Thanks,
Butchie
butchie3980
 
Posts: 8
Joined: Tue Jul 01, 2008 4:40 pm

Postby mflorell » Sat Jul 12, 2008 8:56 am

I have not set up a trunk using the Trixbox FreePBX interface, I just put the account into the iax.conf file directly.
mflorell
Site Admin
 
Posts: 18384
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby butchie3980 » Sat Jul 12, 2008 1:39 pm

mflorell wrote:I have not set up a trunk using the Trixbox FreePBX interface, I just put the account into the iax.conf file directly.


OK. put the iax2 trunk online (it was about time I learned how to do that). tested with a manual dial out, which worked. Did an auto dial campaign and got the same "5 seconds, then drop" behavior.

I set iax2 debug on, and saw something that I haven't seen before
This caught my attention, but I'm not sure what it means:

Jul 12 11:08:48 DEBUG[8076] channel.c: Didn't get a frame from channel: Local/91702239xxxx@default-2e08,2
Jul 12 11:08:48 DEBUG[8076] channel.c: Bridge stops bridging channels Local/91702239xxxx@default-2e08,2 and IAX2/ToECPBX-16387

Here's a full copy/paste from the call log:
Jul 12 11:08:44 VERBOSE[8075] logger.c: > Channel Local/91702239xxxx@default-2e08,1 was answered.
Jul 12 11:08:44 DEBUG[8075] manager.c: Manager received command 'Logoff'
Jul 12 11:08:44 VERBOSE[8075] logger.c: == Manager 'sendcron' logged off from 127.0.0.1
Jul 12 11:08:44 VERBOSE[8150] logger.c: -- Executing Playback("Local/91702239xxxx@default-2e08,1", "sip-silence") in new stack
Jul 12 11:08:44 DEBUG[8150] channel.c: Scheduling timer at 160 sample intervals
Jul 12 11:08:44 VERBOSE[8150] logger.c: -- Playing 'sip-silence' (language 'en')
Jul 12 11:08:44 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:44 DEBUG[8150] channel.c: Scheduling timer at 0 sample intervals
Jul 12 11:08:44 DEBUG[8150] channel.c: Scheduling timer at 0 sample intervals
Jul 12 11:08:44 VERBOSE[8150] logger.c: -- Executing AGI("Local/91702239xxxx@default-2e08,1", "agi://127.0.0.1:4577/call_log") in new stack
Jul 12 11:08:44 VERBOSE[8150] logger.c: -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
Jul 12 11:08:44 VERBOSE[8150] logger.c: -- Executing AGI("Local/91702239xxxx@default-2e08,1", "agi-VDADtransfer.agi|8365") in new stack
Jul 12 11:08:44 VERBOSE[8150] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
Jul 12 11:08:44 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:45 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:45 VERBOSE[8150] logger.c: -- AGI Script agi-VDADtransfer.agi completed, returning 0
Jul 12 11:08:45 VERBOSE[8150] logger.c: -- Executing AGI("Local/91702239xxxx@default-2e08,1", "agi-VDADtransfer.agi|8365") in new stack
Jul 12 11:08:45 VERBOSE[8150] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
Jul 12 11:08:45 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:46 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:46 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:47 VERBOSE[8150] logger.c: -- AGI Script agi-VDADtransfer.agi completed, returning 0
Jul 12 11:08:47 VERBOSE[8150] logger.c: -- Executing AGI("Local/91702239xxxx@default-2e08,1", "agi-VDADtransfer.agi|8365") in new stack
Jul 12 11:08:47 VERBOSE[8150] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
Jul 12 11:08:47 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:47 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:48 DEBUG[2746] manager.c: Manager received command 'Command'
Jul 12 11:08:48 VERBOSE[8150] logger.c: -- AGI Script agi-VDADtransfer.agi completed, returning 0
Jul 12 11:08:48 VERBOSE[8150] logger.c: -- Executing Hangup("Local/91702239xxxx@default-2e08,1", "") in new stack
Jul 12 11:08:48 VERBOSE[8150] logger.c: == Spawn extension (default, 8365, 6) exited non-zero on 'Local/91702239xxxx@default-2e08,1'
Jul 12 11:08:48 VERBOSE[8150] logger.c: -- Executing DeadAGI("Local/91702239xxxx@default-2e08,1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
Jul 12 11:08:48 VERBOSE[8150] logger.c: -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '"V0712110831000000202" <0000000000>'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '0000000000'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '8365'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is 'default'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is 'Local/91702239xxxx@default-2e08,1'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '(null)'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is 'DeadAGI'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is 'agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '2008-07-12 11:08:44'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '(null)'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '2008-07-12 11:08:48'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '4'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '0'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is 'ANSWERED'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is 'DOCUMENTATION'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '(null)'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '1215886111.309'
Jul 12 11:08:48 DEBUG[8150] pbx.c: Function result is '(null)'
Jul 12 11:08:48 DEBUG[8076] channel.c: Didn't get a frame from channel: Local/91702239xxxx@default-2e08,2
Jul 12 11:08:48 DEBUG[8076] channel.c: Bridge stops bridging channels Local/91702239xxxx@default-2e08,2 and IAX2/ToECPBX-16387
Jul 12 11:08:48 DEBUG[8076] chan_iax2.c: We're hanging up IAX2/ToECPBX-16387 now...
Jul 12 11:08:48 VERBOSE[8076] logger.c: -- Hungup 'IAX2/ToECPBX-16387'
Jul 12 11:08:48 DEBUG[8076] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jul 12 11:08:48 VERBOSE[8076] logger.c: == Spawn extension (default, 91702239xxxx, 2) exited non-zero on 'Local/91702239xxxx@default-2e08,2'
Jul 12 11:08:48 VERBOSE[8076] logger.c: -- Executing DeadAGI("Local/91702239xxxx@default-2e08,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----17-----4") in new stack
Jul 12 11:08:48 VERBOSE[8076] logger.c: -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --17-----4 completed, returning 0
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '"V0712110831000000202" <0000000000>'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '0000000000'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '91702239xxxx'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'default'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'Local/91702239xxxx@default-2e08,2'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'IAX2/ToECPBX-16387'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'Dial'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'IAX2/ToECPBX/1702239xxxx||To'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '2008-07-12 11:08:31'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '2008-07-12 11:08:44'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '2008-07-12 11:08:48'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '17'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '4'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'ANSWERED'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is 'DOCUMENTATION'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '(null)'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '1215886111.310'
Jul 12 11:08:48 DEBUG[8076] pbx.c: Function result is '(null)'
butchie3980
 
Posts: 8
Joined: Tue Jul 01, 2008 4:40 pm

Postby mflorell » Sat Jul 12, 2008 5:26 pm

I don't know that I've seen that error before, do you have any kind of firewall installed on either machine or between them?
mflorell
Site Admin
 
Posts: 18384
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida

Postby butchie3980 » Mon Jul 14, 2008 12:21 am

mflorell wrote:I don't know that I've seen that error before, do you have any kind of firewall installed on either machine or between them?


No firewall between them. I was fixated on the "Didn't get a frame from channel" in the debug output, but I realized that the lines above it might be what I should focus on. Would the trixbox be munging our caller ID or something like it, that would break the bridging of the calls? Maybe if I understood the difference between a manual dialout and the auto-dial, since the manual works just fine, but auto-dial kicks the bucket at approx 5 seconds.

Is there a chance I could retain your services? Or could you point me to someone that would log in to our servers and help? Hopefully at a reasonable rate?
butchie3980
 
Posts: 8
Joined: Tue Jul 01, 2008 4:40 pm

Postby mflorell » Mon Jul 14, 2008 7:36 am

Our rates start at $200/hour and we can pretty much fix anything VICIDIAL-related. But if you want some other offers, just post in the request for quote forum:
http://www.eflo.net/VICIDIALforum/viewforum.php?f=6
mflorell
Site Admin
 
Posts: 18384
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida


Return to ViciDialNow - GoAutoDial

Who is online

Users browsing this forum: No registered users and 103 guests