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