IVR Transfer Choppy

I have a box with Asterisk (1.4.22) on Trixbox running CentOS release 5.3, on a Intel® Atom™ CPU D410 @ 1.66GHz.
There are only 3 phones registered and I am testing on a private LAN with no other traffic.

If I call in directly to a phone from the PSTN the voice quality is great in both directions.
If I call in from the PSTN to the IVR the quality is not as great and is really bad when you choose an option (such as ext 2001 or any other). The ring back you hear on the PSTN side while it’s ringing the extension is all choppy. The voice quality seems ok once the phone is picked up, but sometimes the call simply drops for no reason?

Here is the capture from the * box when this happens. This one includes the call dropping after so many seconds.

trixbox1CLI>
– Executing [4035551234@from-sip-external:1] NoOp(“SIP/10.10.10.1-b7600468”, “Received incoming SIP connection from unknown peer to 4035551234”) in new stack
– Executing [4035551234@from-sip-external:2] Set(“SIP/10.10.10.1-b7600468”, “DID=4035551234”) in new stack
– Executing [4035551234@from-sip-external:3] Goto(“SIP/10.10.10.1-b7600468”, “s|1”) in new stack
– Goto (from-sip-external,s,1)
– Executing [s@from-sip-external:1] GotoIf(“SIP/10.10.10.1-b7600468”, “1?from-trunk|4035551234|1”) in new stack
– Goto (from-trunk,4035551234,1)
– Executing [4035551234@from-trunk:1] Set(“SIP/10.10.10.1-b7600468”, “__FROM_DID=4035551234”) in new stack
– Executing [4035551234@from-trunk:2] Gosub(“SIP/10.10.10.1-b7600468”, “app-blacklist-check|s|1”) in new stack
– Executing [s@app-blacklist-check:1] LookupBlacklist(“SIP/10.10.10.1-b7600468”, “”) in new stack
– Executing [s@app-blacklist-check:2] GotoIf(“SIP/10.10.10.1-b7600468”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/10.10.10.1-b7600468”, “”) in new stack
– Executing [4035551234@from-trunk:3] ExecIf(“SIP/10.10.10.1-b7600468”, “1 |Set|CALLERID(name)=4032224444”) in new stack
– Executing [4035551234@from-trunk:4] Set(“SIP/10.10.10.1-b7600468”, “FAX_RX=disabled”) in new stack
– Executing [4035551234@from-trunk:5] Set(“SIP/10.10.10.1-b7600468”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
– Executing [4035551234@from-trunk:6] SetCallerPres(“SIP/10.10.10.1-b7600468”, “allowed_not_screened”) in new stack
– Executing [4035551234@from-trunk:7] Goto(“SIP/10.10.10.1-b7600468”, “ivr-2|s|1”) in new stack
– Goto (ivr-2,s,1)
– Executing [s@ivr-2:1] Set(“SIP/10.10.10.1-b7600468”, “MSG=custom/Welcome-to-Infosat”) in new stack
– Executing [s@ivr-2:2] Set(“SIP/10.10.10.1-b7600468”, “LOOPCOUNT=0”) in new stack
– Executing [s@ivr-2:3] Set(“SIP/10.10.10.1-b7600468”, “__DIR-CONTEXT=default”) in new stack
– Executing [s@ivr-2:4] Set(“SIP/10.10.10.1-b7600468”, “_IVR_CONTEXT_ivr-2=”) in new stack
– Executing [s@ivr-2:5] Set(“SIP/10.10.10.1-b7600468”, “_IVR_CONTEXT=ivr-2”) in new stack
– Executing [s@ivr-2:6] GotoIf(“SIP/10.10.10.1-b7600468”, “0?begin”) in new stack
– Executing [s@ivr-2:7] Answer(“SIP/10.10.10.1-b7600468”, “”) in new stack
– Executing [s@ivr-2:8] Wait(“SIP/10.10.10.1-b7600468”, “1”) in new stack
– Executing [s@ivr-2:9] Set(“SIP/10.10.10.1-b7600468”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3
– Executing [s@ivr-2:10] Set(“SIP/10.10.10.1-b7600468”, “TIMEOUT(response)=10”) in new stack
– Response timeout set to 10
– Executing [s@ivr-2:11] Set(“SIP/10.10.10.1-b7600468”, “__IVR_RETVM=”) in new stack
– Executing [s@ivr-2:12] ExecIf(“SIP/10.10.10.1-b7600468”, “1|Background|custom/Welcome-to-Infosat”) in new stack
– <SIP/10.10.10.1-b7600468> Playing ‘custom/Welcome-to-Infosat’ (language ‘en’)
== CDR updated on SIP/10.10.10.1-b7600468
– Executing [2001@ivr-2:1] ExecIf(“SIP/10.10.10.1-b7600468”, “0|dbDel|”) in new stack
– Executing [2001@ivr-2:2] Set(“SIP/10.10.10.1-b7600468”, “__NODEST=”) in new stack
– Executing [2001@ivr-2:3] Goto(“SIP/10.10.10.1-b7600468”, “from-did-direct|2001|1”) in new stack
– Goto (from-did-direct,2001,1)
– Executing [2001@from-did-direct:1] Macro(“SIP/10.10.10.1-b7600468”, “exten-vm|2001|2001”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“SIP/10.10.10.1-b7600468”, “user-callerid”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/10.10.10.1-b7600468”, “AMPUSER=4032224444”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/10.10.10.1-b7600468”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/10.10.10.1-b7600468”, “1|Set|REALCALLERIDNUM=4032224444”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/10.10.10.1-b7600468”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/10.10.10.1-b7600468”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/10.10.10.1-b7600468”, “1?report”) in new stack
– Goto (macro-user-callerid,s,10)
– Executing [s@macro-user-callerid:10] GotoIf(“SIP/10.10.10.1-b7600468”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/10.10.10.1-b7600468”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/10.10.10.1-b7600468”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] NoOp(“SIP/10.10.10.1-b7600468”, “Using CallerID “4032224444” <4032224444>”) in new stack
– Executing [s@macro-exten-vm:2] Set(“SIP/10.10.10.1-b7600468”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“SIP/10.10.10.1-b7600468”, “VMBOX=2001”) in new stack
– Executing [s@macro-exten-vm:4] Set(“SIP/10.10.10.1-b7600468”, “EXTTOCALL=2001”) in new stack
– Executing [s@macro-exten-vm:5] Set(“SIP/10.10.10.1-b7600468”, “CFUEXT=”) in new stack
– Executing [s@macro-exten-vm:6] Set(“SIP/10.10.10.1-b7600468”, “CFBEXT=”) in new stack
– Executing [s@macro-exten-vm:7] Set(“SIP/10.10.10.1-b7600468”, “RT=15”) in new stack
– Executing [s@macro-exten-vm:8] Macro(“SIP/10.10.10.1-b7600468”, “record-enable|2001|IN”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“SIP/10.10.10.1-b7600468”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] AGI(“SIP/10.10.10.1-b7600468”, “recordingcheck|20110207-165934|1297115968.10”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20110207-165934|1297115968.10: Inbound recording not enabled
– AGI Script recordingcheck completed, returning 0
– Executing [s@macro-record-enable:5] MacroExit(“SIP/10.10.10.1-b7600468”, “”) in new stack
– Executing [s@macro-exten-vm:9] Macro(“SIP/10.10.10.1-b7600468”, “dial|15|tr|2001”) in new stack
– Executing [s@macro-dial:1] GotoIf(“SIP/10.10.10.1-b7600468”, “1?dial”) in new stack
– Goto (macro-dial,s,3)
– Executing [s@macro-dial:3] AGI(“SIP/10.10.10.1-b7600468”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
== Parsing ‘/etc/asterisk/manager.conf’: Found
== Parsing ‘/etc/asterisk/manager_additional.conf’: Found
== Parsing ‘/etc/asterisk/manager_custom.conf’: Found
== Manager ‘admin’ logged on from 127.0.0.1
dialparties.agi: Caller ID name is ‘4032224444’ number is '4032224444’
dialparties.agi: Methodology of ring is ‘none’
– dialparties.agi: Added extension 2001 to extension map
– dialparties.agi: Extension 2001 cf is disabled
– dialparties.agi: Extension 2001 do not disturb is disabled
dialparties.agi: ExtensionState: 0
– dialparties.agi: dbset CALLTRACE/2001 to 4032224444
– dialparties.agi: Filtered ARG3: 2001
== Manager ‘admin’ logged off from 127.0.0.1
– AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:7] Dial(“SIP/10.10.10.1-b7600468”, “SIP/2001|15|tr”) in new stack
– Called 2001
– SIP/2001-08e53a78 is ringing
– SIP/2001-08e53a78 answered SIP/10.10.10.1-b7600468
trixbox1
CLI>
trixbox1CLI>
trixbox1
CLI>
trixbox1CLI>
trixbox1
CLI>
trixbox1*CLI> <>
== Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/10.10.10.1-b7600468’ in macro ‘dial’
== Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/10.10.10.1-b7600468’ in macro ‘exten-vm’
== Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/10.10.10.1-b7600468’
– Executing [h@macro-dial:1] Macro(“SIP/10.10.10.1-b7600468”, “hangupcall”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/10.10.10.1-b7600468”, “1?skiprg”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [s@macro-hangupcall:4] GotoIf(“SIP/10.10.10.1-b7600468”, “1?skipblkvm”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [s@macro-hangupcall:7] GotoIf(“SIP/10.10.10.1-b7600468”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,9)
– Executing [s@macro-hangupcall:9] Hangup(“SIP/10.10.10.1-b7600468”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/10.10.10.1-b7600468’ in macro ‘hangupcall’
== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/10.10.10.1-b7600468’

Any help would be great.

Cheers!
Dave

Typical causes are:

  • failing to provide Asterisk with an internal timing source (asterisk.conf, plus at least some dahdi driver);
  • trying to run Asterisk on a general use virtual machine host (I would advise real hardware, but it can be run on a virtual machine, if you give it enough priority).