Survey audio does not play

[apb1963]

I've read a few of the other posts of people with the same problem, however none of the ones I read seemed to have any resolution for whatever reason.

I'm able to make regular outbound calls, but the survey file simply doesn't play. The call connects, I say "hello" and after a few seconds it hangs up. Here's my CLI output. The outbound phone number has been modified to protect the innocent. Please advise. Thank you


Connected to Asterisk 1.8.23.0-1_centos5.go RPM by demian@goautodial.com currently running on vici (pid = 1138)
Verbosity is at least 4
[Dec 30 19:16:03] -- Executing [652714342213105551212@default:1] AGI("Local/652714342213105551212@default-0000000b;2", "agi://127.0.0.1:4577/call_log") in new stack
[Dec 30 19:16:03] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=39333337))
[Dec 30 19:16:03] -- <Local/652714342213105551212@default-0000000b;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Dec 30 19:16:03] -- Executing [652714342213105551212@default:2] Dial("Local/652714342213105551212@default-0000000b;2", "SIP/13105551212@1029228localpho,,tTo") in new stack
[Dec 30 19:16:03] == Using SIP RTP CoS mark 5
[Dec 30 19:16:03] -- Called SIP/13105551212@1029228localpho
[Dec 30 19:16:06] -- SIP/1029228localpho-0000000e is making progress passing it to Local/652714342213105551212@default-0000000b;2
[Dec 30 19:16:14] -- SIP/1029228localpho-0000000e answered Local/652714342213105551212@default-0000000b;2
[Dec 30 19:16:14] > Channel Local/652714342213105551212@default-0000000b;1 was answered.
[Dec 30 19:16:14] -- Executing [8373@default:1] Playback("Local/652714342213105551212@default-0000000b;1", "sip-silence") in new stack
[Dec 30 19:16:14] -- <Local/652714342213105551212@default-0000000b;1> Playing 'sip-silence.gsm' (language 'en')
[Dec 30 19:16:14] -- Executing [h@default:1] AGI("Local/652714342213105551212@default-0000000b;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----11-----0") in new stack
[Dec 30 19:16:14] -- Executing [8373@default:2] AGI("SIP/1029228localpho-0000000e", "agi://127.0.0.1:4577/call_log") in new stack
[Dec 30 19:16:14] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=39333337))
[Dec 30 19:16:14] -- <SIP/1029228localpho-0000000e>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Dec 30 19:16:14] -- Executing [8373@default:3] AMD("SIP/1029228localpho-0000000e", "2000,2000,1000,5000,120,50,4,256") in new stack
[Dec 31 19:16:14] -- AMD: SIP/1029228localpho-0000000e 5164536886 (N/A) (Fmt: slin)
[Dec 30 19:16:14] -- AMD: initialSilence [2000] greeting [2000] afterGreetingSilence [1000] totalAnalysisTime [5000] minimumWordLength [120] betweenWordsSilence [50] maximumNumberOfWords [4] silenceThreshold [256] maximumWordLength [5000]
[Dec 30 19:16:14] -- AMD: Channel [SIP/1029228localpho-0000000e]. Changed state to STATE_IN_SILENCE
[Dec 30 19:16:15] -- AMD: Channel [SIP/1029228localpho-0000000e]. Word detected. iWordsCount:1
[Dec 30 19:16:15] -- AMD: Channel [SIP/1029228localpho-0000000e]. Detected Talk, previous silence duration: 320
[Dec 30 19:16:15] -- AMD: Channel [SIP/1029228localpho-0000000e]. Changed state to STATE_IN_SILENCE
[Dec 30 19:16:15] -- <Local/652714342213105551212@default-0000000b;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --11-----0 completed, returning 0
[Dec 30 19:16:15] == Spawn extension (default, 652714342213105551212, 2) exited non-zero on 'Local/652714342213105551212@default-0000000b;2'
[Dec 30 19:16:16] -- AMD: Channel [SIP/1029228localpho-0000000e]. HUMAN: silenceDuration:1000 afterGreetingSilence:1000
[Dec 30 19:16:16] -- Executing [8373@default:4] AGI("SIP/1029228localpho-0000000e", "VD_amd.agi,8373") in new stack
[Dec 30 19:16:16] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Dec 30 19:16:17] -- <SIP/1029228localpho-0000000e>AGI Script VD_amd.agi completed, returning 0
[Dec 30 19:16:17] -- Executing [8373@default:5] AGI("SIP/1029228localpho-0000000e", "agi-VDAD_ALL_outbound.agi,SURVEYCAMP-----LB") in new stack
[Dec 30 19:16:17] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Dec 30 19:16:18] -- <SIP/1029228localpho-0000000e>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Dec 30 19:16:18] -- Executing [8373@default:6] AGI("SIP/1029228localpho-0000000e", "agi-VDAD_ALL_outbound.agi,SURVEYCAMP-----LB") in new stack
[Dec 30 19:16:18] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Dec 30 19:16:20] -- <SIP/1029228localpho-0000000e>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Dec 30 19:16:20] -- Executing [8373@default:7] Hangup("SIP/1029228localpho-0000000e", "") in new stack
[Dec 30 19:16:20] == Spawn extension (default, 8373, 7) exited non-zero on 'SIP/1029228localpho-0000000e'
[Dec 30 19:16:20] -- Executing [h@default:1] AGI("SIP/1029228localpho-0000000e", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Dec 30 19:16:20] -- <SIP/1029228localpho-0000000e>AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0

[apb1963]

Here is the agiout log. I will point out that this shows an LRERR 5 & 6. (There are no references anywhere I can find as to what these errors mean, other than the vague reference to "carrier issues" in the error message.) If in fact there is a problem with the carrier, then the question becomes - what does the carrier need to do to fix it on their end?

I would like to reiterate the fact that there are no problems with a normal campaign. i.e. With an agent logged in, calls go out and are transferred to the agent, sound works both ways. It's only on surveys that the sound file fails to play and the call is terminated within maybe 1-3 seconds. The sound file was created with audacity, 16 bits, 8000 Hz, mono, PCM WAV. Or more precisely: go_TestSurvey.wav: RIFF (little-endian) data, WAVE audio, Microsoft PCM, 16 bit, mono 8000 Hz
Also I believe it's in the proper place: -rwxrwxrwx 1 apache apache 256742 Dec 19 13:51 /var/lib/asterisk/sounds/go_TestSurvey.wav
The only anomaly is the fact that the other sound files in that dir are owned by root.root with permissions 755 but I doubt that's the issue.

Once again relevant numbers and such have been changed to protect the innocent.

Thank you in advance.

2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|0|SURVEYCAMP-----LB
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|callerID changed: V2301916030000008003
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- accountcode =
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- arg_1 = SURVEYCAMP-----LB
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- callerid = 5164536886
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- calleridname = V2301916030000008003
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- callington = 0
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- channel = SIP/1029228localpho-0000000e
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- context = default
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- extension = 8373
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- language = en
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- priority = 5
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- threadid = 47953936972096
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- type = SIP
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- uniqueid = vici.mydomain.com-1419984963.41
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi| -- version = 1.8.23.0-1_centos5.go RPM by demian@goautodial.com
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|AGI Variables: |vici.mydomain.com-1419984963.41|SIP/1029228localpho-0000000e|8373|SIP|V2301916030000008003|V2301916030000008003|5|
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |8003|2014-12-30 19:16:17|1.8.23.0|5|
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 5
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|LLLLLLLLL LOCAL CHANNEL PRIORITY 4 LOGGING: (this is usually caused by carrier issues) LRERR 5
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='LRERR' where lead_id='8003' and status NOT IN('CBHOLD','CALLBK','QCFAIL');|
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|-- LRERR vicidial_list LRERR update: |1|vici.mydomain.com-1419984963.41|8003|
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi||INSERT INTO vicidial_log (uniqueid,lead_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,processed,alt_dial,list_id,called_count) values('vici.mydomain.com-1419984963.41','8003','39333337','2014-12-30 19:16:17','1419984977','LRERR','1','3105551212','VDAD','N','NONE','1001','2')|
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|-- LRERR : |8003|8003|insert to vicidial_log: vici.mydomain.com-1419984963.41
2014-12-30 19:16:17|agi-VDAD_ALL_outbound.agi|-- LRERR VLE insert: |1|
|INSERT INTO vicidial_log_extended set uniqueid='vici.mydomain.com-1419984963.41',server_ip='127.0.0.1',call_date='2014-12-30 19:16:17',lead_id = '8003',caller_code='V2301916030000008003',custom_call_id='';|
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|0|SURVEYCAMP-----LB
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|callerID changed: V2301916030000008003
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- accountcode =
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- arg_1 = SURVEYCAMP-----LB
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- callerid = unknown
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- calleridname = V2301916030000008003
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- callington = 0
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- channel = SIP/1029228localpho-0000000e
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- context = default
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- extension = 8373
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- language = en
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- priority = 6
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- threadid = 47953936972096
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- type = SIP
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- uniqueid = vici.mydomain.com-1419984963.41
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi| -- version = 1.8.23.0-1_centos5.go RPM by demian@goautodial.com
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|AGI Variables: |vici.mydomain.com-1419984963.41|SIP/1029228localpho-0000000e|8373|SIP|V2301916030000008003|V2301916030000008003|6|
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |8003|2014-12-30 19:16:19|1.8.23.0|6|
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 6
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|LLLLLLLLL LOCAL CHANNEL PRIORITY 4 LOGGING: (this is usually caused by carrier issues) LRERR 6
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='LRERR' where lead_id='8003' and status NOT IN('CBHOLD','CALLBK','QCFAIL');|
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|-- LRERR vicidial_list LRERR update: |1|vici.mydomain.com-1419984963.41|8003|
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi||INSERT INTO vicidial_log (uniqueid,lead_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,processed,alt_dial,list_id,called_count) values('vici.mydomain.com-1419984963.41','8003','39333337','2014-12-30 19:16:19','1419984979','LRERR','1','3105551212','VDAD','N','NONE','1001','2')|
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|-- LRERR : |8003|8003|insert to vicidial_log: vici.mydomain.com-1419984963.41
2014-12-30 19:16:19|agi-VDAD_ALL_outbound.agi|-- LRERR VLE insert: ||
|INSERT INTO vicidial_log_extended set uniqueid='vici.mydomain.com-1419984963.41',server_ip='127.0.0.1',call_date='2014-12-30 19:16:19',lead_id = '8003',caller_code='V2301916030000008003',custom_call_id='';|

[mflorell]

LRERR usually means that no audio was received from the carrier, so the channel pointer never resolved and the call cannot be routed properly.

To resolve this problem you should check your firewall and test another carrier.

[apb1963]

Thank you for responding.

What I don't understand is 1) Why normal outbound calls would work fine, but not the survey. What is the difference between the two modes? The firewall hasn't changed between modes, why would the firewall have an effect in survey mode but not in regular outbound mode? 2) assuming the carrier is the problem, once again I have to ask why this carrier works fine in one mode, but not the other mode? They're both outbound calls, I answer the phone in both cases with "Hello". If in fact there is a problem with the carrier, what is it they're doing - or not doing - that causes this problem? It feels to me that the sound file is not being played on this end, rather than the carrier not providing audio. So what would cause the sound file not to play? I would be more than happy to add any debug statements or whatever else is needed to nail this down. While switching carriers may or may not resolve the issue, it still begs the question of "why" or "what is the difference between carrier A and carrier B". As carrier B is more expensive than carrier A, it sure would be nice not to have to switch.

Thank you

[mflorell]

For auto-dialed calls the channel must resolve within 1 second. If it does not then the LRERR happens. For manual dialed calls there is no similar limit because the call does not have to be routed anywhere, it is already at it's destination in the agent's session.

[apb1963]

OK, that makes sense - except that ALL of these calls are auto-dialed. There is no manual dialing at all, at any time.