Outgoing call issues, log attached

I’m having fits getting outbound calling working, trunk is our own sipwise softswitch that seems to be working fine, I can place calls on it with a softphone and ATA.

Freepbx box is latest freepbx distro, installed yesterday, running as a vm on xcp.

Inbound calling is working fine, I have a DID assigned to my extension, can receive calls fine. Only have one issue and that is the softswitch not passing CID data properly but I’ve verified that problem is before freepbx ever sees the call.

here is the log of an outbound call attempt to 6016385211 (local time and temp announcement).

I’ll gladly provide any additional information needed, keep in mind I’m still new to freepbx and asterisk in general, I’ve spent about 6 hours digging around trying to find my own solution.

[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [6016385211@from-internal:1] Macro(“SIP/100-00000032”, “user-callerid,LIMIT,”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/100-00000032”, “AMPUSER=100”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/100-00000032”, “0?report”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/100-00000032”, “1?Set(REALCALLERIDNUM=100)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/100-00000032”, “AMPUSER=100”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/100-00000032”, “AMPUSERCIDNAME=Stephen Donovan”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/100-00000032”, “0?report”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/100-00000032”, “AMPUSERCID=100”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/100-00000032”, “CALLERID(all)=“Stephen Donovan” <100>”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:9] GotoIf(“SIP/100-00000032”, “0?limit”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:10] ExecIf(“SIP/100-00000032”, “1?Set(GROUP(concurrency_limit)=100)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:11] ExecIf(“SIP/100-00000032”, “0?Set(CHANNEL(language)=)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:12] GosubIf(“SIP/100-00000032”, “7?sub-ccss,s,1(from-internal,6016385211)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/100-00000032”, “0?Return()”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/100-00000032”, “CCSS_SETUP=TRUE”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/100-00000032”, “0?monitor_config,1(from-internal,6016385211):monitor_default,1(from-internal,6016385211)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/100-00000032”, “0?is_exten”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [monitor_default@sub-ccss:2] StackPop(“SIP/100-00000032”, “”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [monitor_default@sub-ccss:3] Return(“SIP/100-00000032”, “FALSE”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/100-00000032”, “1?continue”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-user-callerid,s,26)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/100-00000032”, “CALLERID(number)=100”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/100-00000032”, “CALLERID(name)=Stephen Donovan”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/100-00000032”, “CHANNEL(language)=en”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [6016385211@from-internal:2] Set(“SIP/100-00000032”, “MOHCLASS=default”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [6016385211@from-internal:3] Set(“SIP/100-00000032”, “_NODEST=”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [6016385211@from-internal:4] Gosub(“SIP/100-00000032”, “sub-record-check,s,1(out,6016385211,)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/100-00000032”, “1?check”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (sub-record-check,s,6)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/100-00000032”, “__MON_FMT=wav”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:7] GotoIf(“SIP/100-00000032”, “1?next”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (sub-record-check,s,10)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:10] ExecIf(“SIP/100-00000032”, “0?Return()”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:11] GotoIf(“SIP/100-00000032”, “0?out,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/100-00000032”, “__REC_STATUS=INITIALIZED”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/100-00000032”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/100-00000032”, “NOW=1353016241”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/100-00000032”, “__DAY=15”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/100-00000032”, “__MONTH=11”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/100-00000032”, “__YEAR=2012”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/100-00000032”, “__TIMESTR=20121115-155041”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/100-00000032”, “__FROMEXTEN=100”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/100-00000032”, “__CALLFILENAME=out-6016385211-100-20121115-155041-1353016241.50”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@sub-record-check:21] Goto(“SIP/100-00000032”, “out,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (sub-record-check,out,1)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [out@sub-record-check:1] ExecIf(“SIP/100-00000032”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [out@sub-record-check:2] GosubIf(“SIP/100-00000032”, “0?record,1(exten,6016385211,100)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [out@sub-record-check:3] Return(“SIP/100-00000032”, “”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [6016385211@from-internal:5] Macro(“SIP/100-00000032”, “dialout-trunk,2,6016385211,”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/100-00000032”, “DIAL_TRUNK=2”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/100-00000032”, “0?sub-pincheck,s,1()”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/100-00000032”, “0?disabletrunk,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/100-00000032”, “DIAL_NUMBER=6016385211”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/100-00000032”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/100-00000032”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/100-00000032”, “0?nomax”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/100-00000032”, “0?chanfull”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/100-00000032”, “0?skipoutcid”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/100-00000032”, “DIAL_TRUNK_OPTIONS=”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/100-00000032”, “outbound-callerid,2”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/100-00000032”, “0?Set(CALLERPRES()=)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/100-00000032”, “0?Set(REALCALLERIDNUM=100)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/100-00000032”, “1?normcid”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-outbound-callerid,s,6)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/100-00000032”, “USEROUTCID=”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/100-00000032”, “EMERGENCYCID=”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/100-00000032”, “TRUNKOUTCID=6014560232”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/100-00000032”, “1?trunkcid”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-outbound-callerid,s,12)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/100-00000032”, “1?Set(CALLERID(all)=6014560232)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/100-00000032”, “0?Set(CALLERID(all)=)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/100-00000032”, “0?Set(CALLERID(all)=)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/100-00000032”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/100-00000032”, “0?sub-flp-2,s,1()”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/100-00000032”, “OUTNUM=6016385211”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/100-00000032”, “custom=SIP/[email protected]”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/100-00000032”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/100-00000032”, “0?Set(DIAL_TRUNK_OPTIONS=M(confirm))”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/100-00000032”, “dialout-trunk-predial-hook,”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/100-00000032”, “”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/100-00000032”, “0?bypass,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/100-00000032”, “1?Set(CONNECTEDLINE(num,i)=6016385211)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/100-00000032”, “1?Set(CONNECTEDLINE(name,i)=CID:6014560232)”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:21] GotoIf(“SIP/100-00000032”, “0?customtrunk”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:22] Dial(“SIP/100-00000032”, “SIP/[email protected]/6016385211,300,”) in new stack
[2012-11-15 15:50:41] NOTICE[4679] chan_sip.c: Conflicting extension values given. Using ‘16014560232’ and not ‘6016385211’
[2012-11-15 15:50:41] VERBOSE[4679] netsock2.c: == Using SIP RTP TOS bits 184
[2012-11-15 15:50:41] VERBOSE[4679] netsock2.c: == Using SIP RTP CoS mark 5
[2012-11-15 15:50:41] VERBOSE[4679] app_dial.c: – Called SIP/[email protected]/6016385211
[2012-11-15 15:50:41] NOTICE[1460] chan_sip.c: Failed to authenticate on INVITE to ‘“6014560232” sip:[email protected];tag=as023d6a9c’
[2012-11-15 15:50:41] VERBOSE[4679] app_dial.c: – SIP/107.7.157.250-00000033 is circuit-busy
[2012-11-15 15:50:41] VERBOSE[4679] app_dial.c: == Everyone is busy/congested at this time (1:0/1/0)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:23] NoOp(“SIP/100-00000032”, “Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 21”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-dialout-trunk:24] Goto(“SIP/100-00000032”, “s-CONGESTION,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-dialout-trunk,s-CONGESTION,1)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s-CONGESTION@macro-dialout-trunk:1] Set(“SIP/100-00000032”, “RC=21”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s-CONGESTION@macro-dialout-trunk:2] Goto(“SIP/100-00000032”, “21,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-dialout-trunk,21,1)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [21@macro-dialout-trunk:1] Goto(“SIP/100-00000032”, “continue,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-dialout-trunk,continue,1)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [continue@macro-dialout-trunk:1] GotoIf(“SIP/100-00000032”, “1?noreport”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Goto (macro-dialout-trunk,continue,3)
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [continue@macro-dialout-trunk:3] NoOp(“SIP/100-00000032”, “TRUNK Dial failed due to CONGESTION HANGUPCAUSE: 21 - failing through to other trunks”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [continue@macro-dialout-trunk:4] Set(“SIP/100-00000032”, “CALLERID(number)=100”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [6016385211@from-internal:6] Macro(“SIP/100-00000032”, “outisbusy,”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outisbusy:1] Progress(“SIP/100-00000032”, “”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outisbusy:2] GotoIf(“SIP/100-00000032”, “0?emergency,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outisbusy:3] GotoIf(“SIP/100-00000032”, “0?intracompany,1”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] pbx.c: – Executing [s@macro-outisbusy:4] Playback(“SIP/100-00000032”, “all-circuits-busy-now&pls-try-call-later, noanswer”) in new stack
[2012-11-15 15:50:41] VERBOSE[4679] file.c: – <SIP/100-00000032> Playing ‘all-circuits-busy-now.ulaw’ (language ‘en’)
[2012-11-15 15:50:42] VERBOSE[4679] app_macro.c: == Spawn extension (macro-outisbusy, s, 4) exited non-zero on ‘SIP/100-00000032’ in macro ‘outisbusy’
[2012-11-15 15:50:42] VERBOSE[4679] pbx.c: == Spawn extension (from-internal, 6016385211, 6) exited non-zero on ‘SIP/100-00000032’
[2012-11-15 15:50:42] VERBOSE[4679] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/100-00000032”, “”) in new stack
[2012-11-15 15:50:42] VERBOSE[4679] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/100-00000032’
[2012-11-15 15:50:44] NOTICE[4681] manager.c: Seems to have passed…

Did you notice:-

[2012-11-15 15:50:41] NOTICE[4679] chan_sip.c: Conflicting extension values given. Using ‘16014560232’ and not ‘6016385211’
[2012-11-15 15:50:41] VERBOSE[4679] netsock2.c: == Using SIP RTP TOS bits 184
[2012-11-15 15:50:41] VERBOSE[4679] netsock2.c: == Using SIP RTP CoS mark 5
[2012-11-15 15:50:41] VERBOSE[4679] app_dial.c: – Called SIP/[email protected]/6016385211
[2012-11-15 15:50:41] NOTICE[1460] chan_sip.c: Failed to authenticate on INVITE to ‘“6014560232” ;tag=as023d6a9c’

It’s basically saying that your authority to place a SIP call to [email protected] (The Park Residences at Bienville) is failing , you need to fix that.

I did notice that, was not sure how to read. However, I was placing a call to 6016385211, 6014560232 is the DID assigned to the extension I was calling from.

Could it be a problem with trunk settings ? if I register a cisco ATA to that account and DID, calls work fine both ways.

Stephen

Absolutely a trunk setting, your authority is therewithin. Or use IP authority to your box on your softswitch and avoid that problm.

.