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

threeforks · July 21, 2008, 7:30pm

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 [[email protected]:1] Macro(“SIP/406-08e12300”, “user-callerid|SKIPTTL|”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] Set(“SIP/406-08e12300”, “_NODEST=”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [[email protected]:3] Macro(“SIP/406-08e12300”, “record-enable|406|OUT|”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:4] Macro(“SIP/406-08e12300”, “dialout-trunk|1|9725551212||”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]out-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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:11] Macro(“SIP/406-08e12300”, “outbound-callerid|1”) in new stack
[Jul 21 14:32:00] VERBOSE[4114] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] Macro(“SIP/406-08e12300”, “hangupcall|”) in new stack
[Jul 21 14:32:11] VERBOSE[4114] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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

threeforks · July 21, 2008, 8:52pm

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.

threeforks · July 30, 2008, 2:44am

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.

system · June 4, 2014, 6:40pm