Absolutely NO audio/sound on outgoing call via SIP trunk. Incomming just fine

I am very perplexed. I installed PIAF and setup an X-Lite phone. I ordered a Vitelity SIP trunk and received incomming calls in minutes. Made a few outgoing calls and celebrated. A couple of hours later, I could make outgoing calls but hear NOTHING on my end nor could the other end hear me. I could turn right around and call inbound and everything worked flawlessly. So, I rebooted the PBX server. When it came back up I could make outgoing calls again with sound for a little while. Now, however, I can NEVER hear sound on an outgoing call. I can ALWAYS hear sound on incomming calls. I ordered another SIP trunk from Aretta. Can make outgoing calls on their trunk as well with NO SOUND EVER. This worked fine so I am not sure how it can be a router problem. I am running an Adtran router and I have since purchased an Aastra 9133i and it too has the same problem as the X-Lite soft phone. I have searched the log files and cannot see anything obvious but stil no sound on an outgoing call. I am simply at a loss for what to try next short of a reinstall (which I will do but I was hoping for some success here first). Any help would be greatly appreciated. Thank you.

FreePBX Version: 2.4.1.0
Asterisk Version: 1.4.21.1
Running on CentOS 5

Pentium 4, 3.0 GHz
Intel Motherboard
1 GB RAM
120 GB SATA Hard drive

Adtran 3120 Router

Log File:

[Jul 21 14:32:00] WARNING[2683] rtp.c: Unable to set TOS to 184
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [9725551212@from-internal:1] Macro(“SIP/406-08e12300”, “user-callerid|SKIPTTL|”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:1] NoOp(“SIP/406-08e12300”, “user-callerid: device 406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:2] Set(“SIP/406-08e12300”, “AMPUSER=406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/406-08e12300”, “0?report”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/406-08e12300”, “1|Set|REALCALLERIDNUM=406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: ExecIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:5] NoOp(“SIP/406-08e12300”, “REALCALLERIDNUM is 406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:6] Set(“SIP/406-08e12300”, “AMPUSER=406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/406-08e12300”, “AMPUSERCIDNAME=John Doe”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/406-08e12300”, “0?report”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:9] Set(“SIP/406-08e12300”, “AMPUSERCID=406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:10] Set(“SIP/406-08e12300”, “CALLERID(all)=“John Doe” <406>”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:11] Set(“SIP/406-08e12300”, “REALCALLERIDNUM=406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: AMPUSER/406/language not found in database.
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: AMPUSER/406/language not found in database.
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:12] ExecIf(“SIP/406-08e12300”, “0|Set|CHANNEL(language)=”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: ExecIf
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: AMPUSER/406/language not found in database.
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: AMPUSER/406/language not found in database.
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:13] NoOp(“SIP/406-08e12300”, “TTL: ARG1: SKIPTTL”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:14] GotoIf(“SIP/406-08e12300”, “1?continue”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-user-callerid,s,23)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-user-callerid:23] NoOp(“SIP/406-08e12300”, “Using CallerID “John Doe” <406>”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [9725551212@from-internal:2] Set(“SIP/406-08e12300”, “_NODEST=”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [9725551212@from-internal:3] Macro(“SIP/406-08e12300”, “record-enable|406|OUT|”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/406-08e12300”, “0?2:4”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-record-enable,s,4)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/406-08e12300”, “recordingcheck|20080721-143200|1216668720.39”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Jul 21 14:32:00] VERBOSE[4114] logger.c: recordingcheck|20080721-143200|1216668720.39: Outbound recording not enabled
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – AGI Script recordingcheck completed, returning 0
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: AGI
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-record-enable:5] NoOp(“SIP/406-08e12300”, “No recording needed”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [9725551212@from-internal:4] Macro(“SIP/406-08e12300”, “dialout-trunk|1|9725551212||”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/406-08e12300”, “DIAL_TRUNK=1”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: AMPUSER/406/pinless not found in database.
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:2] ExecIf(“SIP/406-08e12300”, “0|Authenticate|”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: ExecIf
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: AMPUSER/406/pinless not found in database.
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/406-08e12300”, “0?disabletrunk|1”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/406-08e12300”, “DIAL_NUMBER=9725551212”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/406-08e12300”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/406-08e12300”, “GROUP()=OUT_1”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/406-08e12300”, “1?nomax”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-dialout-trunk,s,9)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/406-08e12300”, “0?skipoutcid”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/406-08e12300”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/406-08e12300”, “outbound-callerid|1”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/406-08e12300”, “0|SetCallerPres|”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: ExecIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:2] GotoIf(“SIP/406-08e12300”, “1?start”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-outbound-callerid,s,4)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:4] NoOp(“SIP/406-08e12300”, “REALCALLERIDNUM is 406”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:5] GotoIf(“SIP/406-08e12300”, “1?normcid”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-outbound-callerid,s,10)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:10] Set(“SIP/406-08e12300”, “USEROUTCID=“John Doe Inc” <5555555555>”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] DEBUG[4114] func_db.c: DB: DEVICE/406/emergency_cid not found in database.
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:11] Set(“SIP/406-08e12300”, “EMERGENCYCID=”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:12] Set(“SIP/406-08e12300”, “TRUNKOUTCID=”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:13] GotoIf(“SIP/406-08e12300”, “1?trunkcid”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-outbound-callerid,s,17)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:17] GotoIf(“SIP/406-08e12300”, “1?usercid”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-outbound-callerid,s,19)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:19] GotoIf(“SIP/406-08e12300”, “0?report”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:20] Set(“SIP/406-08e12300”, “CALLERID(all)=John Doe Inc <5555555555>”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:21] GotoIf(“SIP/406-08e12300”, “1?report:hidecid”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-outbound-callerid,s,23)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-outbound-callerid:23] NoOp(“SIP/406-08e12300”, “CallerID set to “John Doe Inc” <5555555555>”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Noop
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Macro
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:12] AGI(“SIP/406-08e12300”, “fixlocalprefix”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Jul 21 14:32:00] VERBOSE[4114] logger.c: == fixlocalprefix: Dialpattern 1+NXXNXXXXXX matched. 9725551212 -> 19725551212
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – AGI Script fixlocalprefix completed, returning 0
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: AGI
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/406-08e12300”, “OUTNUM=19725551212”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/406-08e12300”, “custom=SIP/arettasip”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Set
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:15] GotoIf(“SIP/406-08e12300”, “1?gocall”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Goto (macro-dialout-trunk,s,17)
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/406-08e12300”, “dialout-trunk-predial-hook|”) in new stack
[Jul 21 14:32:00] WARNING[4114] app_macro.c: Context ‘macro-dialout-trunk-predial-hook’ for macro ‘dialout-trunk-predial-hook’ lacks ‘s’ extension, priority 1
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: Macro
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/406-08e12300”, “0?bypass|1”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:19] GotoIf(“SIP/406-08e12300”, “0?customtrunk”) in new stack
[Jul 21 14:32:00] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [s@macro-dialout-trunk:20] Dial(“SIP/406-08e12300”, “SIP/arettasip/19725551212|300|”) in new stack
[Jul 21 14:32:00] WARNING[4114] rtp.c: Unable to set TOS to 184
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Called arettasip/19725551212
[Jul 21 14:32:08] DEBUG[2683] sched.c: Request to schedule in the past?!?!
[Jul 21 14:32:11] VERBOSE[4114] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on ‘SIP/406-08e12300’ in macro ‘dialout-trunk’
[Jul 21 14:32:11] VERBOSE[4114] logger.c: == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on ‘SIP/406-08e12300’
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/406-08e12300”, “hangupcall|”) in new stack
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/406-08e12300”, “w”) in new stack
[Jul 21 14:32:11] DEBUG[4114] app_macro.c: Executed application: ResetCDR
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/406-08e12300”, “”) in new stack
[Jul 21 14:32:11] DEBUG[4114] app_macro.c: Executed application: NoCDR
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/406-08e12300”, “1?skiprg”) in new stack
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Goto (macro-hangupcall,s,6)
[Jul 21 14:32:11] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/406-08e12300”, “1?skipblkvm”) in new stack
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Goto (macro-hangupcall,s,9)
[Jul 21 14:32:11] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/406-08e12300”, “1?theend”) in new stack
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Goto (macro-hangupcall,s,11)
[Jul 21 14:32:11] DEBUG[4114] app_macro.c: Executed application: GotoIf
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/406-08e12300”, “”) in new stack
[Jul 21 14:32:11] VERBOSE[4114] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/406-08e12300’ in macro ‘hangupcall’
[Jul 21 14:32:11] VERBOSE[4114] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/406-08e12300’
[Jul 21 14:32:13] VERBOSE[4117] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Jul 21 14:32:13] VERBOSE[4117] logger.c: Found
[Jul 21 14:32:13] VERBOSE[4117] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Jul 21 14:32:13] VERBOSE[4117] logger.c: Found
[Jul 21 14:32:13] VERBOSE[4117] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Jul 21 14:32:13] VERBOSE[4117] logger.c: Found
[Jul 21 14:32:13] VERBOSE[4117] logger.c: == Manager ‘admin’ logged on from 127.0.0.1

I reconfigured my Vitelity trunk to be IAX instead of SIP. Now I can call out fine on that IAX trunk but not on ANY SIP trunk. Therefore, that SCREAMS router but this is an OUTBOUND call. So, I am throwing my Linksys router in place temporarily and if this fixes it, I will call Adtran and have them help me figure out the router issue. Will keep this updated.

If you are using an Adtran 3120 (or other router with the same operating system) they have a bug in their GUI where the setting to enable ALG traffic is not accessible. You must access it through the command line. I am not familiar enough with the command line of the Adtran to accomplish this, but their support walked me through it (free of course) and everything is solved.