Outgoing calls randomly routing to internal default Ring Group

Ducktour · December 1, 2017, 7:57pm

Please can anyone help?
My System has two FXS analogue telephone lines and one FXO port to an analogue portable telephone. When dialling out, usual display on Cisco 7940 phones is Proceeding (in 100) however, outbound calls randomly route to the only FXO extension and display says Ringing Destination (in 180).
The only changes I have made apart from normal updates is to purchase and install the Sys Admin Pro and the Extension Routing Module. I have uninstalled the latter as a troubleshoot but made no difference.
I deleted the analogue extension (4000) and made an outbound call and it routed to the SIP ring group, so issue not specific to the FXO port.
(Asterisk Version: FreePBX 14.0.1.20, Distro Version: 12.7.4-1710-2.sng7)

lgaetz · December 2, 2017, 10:58pm

https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs

dicko · December 2, 2017, 11:00pm

You would have to paste a call trace of a good and a bad one for comparison, unless you tell them to , computer systems never acting randomly.

Ducktour · December 4, 2017, 12:52am

Thank you both, I will append a trace on Monday, the frequency of the fault has increased so it won’t be hard to replicate.

Ducktour · December 4, 2017, 7:31pm

[2017-12-04 11:28:16] VERBOSE[21687][C-000000bf] netsock2.c: Using SIP RTP TOS bits 184
[2017-12-04 11:28:16] VERBOSE[21687][C-000000bf] netsock2.c: Using SIP RTP CoS mark 5
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [250nnnnnnn@from-internal:1] Macro("SIP/3160-0000014f", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:1] Set("SIP/3160-0000014f", "TOUCH_MONITOR=1512415696.608") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/3160-0000014f", "AMPUSER=3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/3160-0000014f", "0?report") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("SIP/3160-0000014f", "1?Set(REALCALLERIDNUM=3160)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:5] Set("SIP/3160-0000014f", "AMPUSER=3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("SIP/3160-0000014f", "0?limit") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/3160-0000014f", "AMPUSERCIDNAME=Edwin") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("SIP/3160-0000014f", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("SIP/3160-0000014f", "0?report") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:10] Set("SIP/3160-0000014f", "AMPUSERCID=3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:11] Set("SIP/3160-0000014f", "__DIAL_OPTIONS=Ttr") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:12] Set("SIP/3160-0000014f", "CALLERID(all)="Edwin" <3160>") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("SIP/3160-0000014f", "0?limit") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("SIP/3160-0000014f", "1?Set(GROUP(concurrency_limit)=3160)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("SIP/3160-0000014f", "0?Set(CHANNEL(language)=)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:16] NoOp("SIP/3160-0000014f", "Macro Depth is 1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("SIP/3160-0000014f", "1?report2:macroerror") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (macro-user-callerid,s,19)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("SIP/3160-0000014f", "1?continue") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:37] Set("SIP/3160-0000014f", "CALLERID(number)=3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:38] Set("SIP/3160-0000014f", "CALLERID(name)=Edwin") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("SIP/3160-0000014f", "0?cnum") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:40] Set("SIP/3160-0000014f", "CDR(cnam)=Edwin") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:41] Set("SIP/3160-0000014f", "CDR(cnum)=3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-user-callerid:42] Set("SIP/3160-0000014f", "CHANNEL(language)=en") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [250nnnnnnn@from-internal:2] Gosub("SIP/3160-0000014f", "sub-record-check,s,1(out,250nnnnnnn,dontcare)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/3160-0000014f", "0?initialized") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:2] Set("SIP/3160-0000014f", "__REC_STATUS=INITIALIZED") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:3] Set("SIP/3160-0000014f", "NOW=1512415696") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:4] Set("SIP/3160-0000014f", "__DAY=04") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:5] Set("SIP/3160-0000014f", "__MONTH=12") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:6] Set("SIP/3160-0000014f", "__YEAR=2017") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:7] Set("SIP/3160-0000014f", "__TIMESTR=20171204-112816") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:8] Set("SIP/3160-0000014f", "__FROMEXTEN=3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:9] Set("SIP/3160-0000014f", "__MON_FMT=wav") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/3160-0000014f", "Recordings initialized") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/3160-0000014f", "0?Set(ARG3=dontcare)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:12] Set("SIP/3160-0000014f", "REC_POLICY_MODE_SAVE=") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/3160-0000014f", "0?Set(REC_STATUS=NO)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/3160-0000014f", "3?checkaction") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/3160-0000014f", "1?sub-record-check,out,1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (sub-record-check,out,1)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [out@sub-record-check:1] NoOp("SIP/3160-0000014f", "Outbound Recording Check from 3160 to 250nnnnnnn") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [out@sub-record-check:2] Set("SIP/3160-0000014f", "RECMODE=dontcare") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [out@sub-record-check:3] ExecIf("SIP/3160-0000014f", "1?Goto(routewins)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (sub-record-check,out,7)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [out@sub-record-check:7] Gosub("SIP/3160-0000014f", "recordcheck,1(dontcare,out,250nnnnnnn)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/3160-0000014f", "Starting recording check against dontcare") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/3160-0000014f", "dontcare") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/3160-0000014f", "") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [out@sub-record-check:8] Return("SIP/3160-0000014f", "") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [250nnnnnnn@from-internal:3] ExecIf("SIP/3160-0000014f", "0 ?Set(CDR(accountcode)=)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [250nnnnnnn@from-internal:4] Set("SIP/3160-0000014f", "MOHCLASS=default") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [250nnnnnnn@from-internal:5] Set("SIP/3160-0000014f", "_NODEST=") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [250nnnnnnn@from-internal:6] Macro("SIP/3160-0000014f", "dialout-trunk,1,1250nnnnnnn,,on") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:1] Set("SIP/3160-0000014f", "DIAL_TRUNK=1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:2] GosubIf("SIP/3160-0000014f", "0?sub-pincheck,s,1()") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:3] ExecIf("SIP/3160-0000014f", "0?Set(CALLERID(num)=3160)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:4] GotoIf("SIP/3160-0000014f", "0?disabletrunk,1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:5] Set("SIP/3160-0000014f", "DIAL_NUMBER=1250nnnnnnn") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:6] Set("SIP/3160-0000014f", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:7] Set("SIP/3160-0000014f", "OUTBOUND_GROUP=OUT_1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:8] Set("SIP/3160-0000014f", "DIAL_TRUNK_OPTIONS=T") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:9] GotoIf("SIP/3160-0000014f", "1?nomax") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (macro-dialout-trunk,s,11)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:11] GotoIf("SIP/3160-0000014f", "0?skipoutcid") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:12] Macro("SIP/3160-0000014f", "outbound-callerid,1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("SIP/3160-0000014f", "3160") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("SIP/3160-0000014f", "") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("SIP/3160-0000014f", "off") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("SIP/3160-0000014f", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("SIP/3160-0000014f", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:6] ExecIf("SIP/3160-0000014f", "0?Set(REALCALLERIDNUM=3160)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:7] GotoIf("SIP/3160-0000014f", "1?normcid") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (macro-outbound-callerid,s,11)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:11] Set("SIP/3160-0000014f", "USEROUTCID=") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:12] Set("SIP/3160-0000014f", "EMERGENCYCID=") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:13] Set("SIP/3160-0000014f", "TRUNKOUTCID="NelsonBoxOffice"") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:14] GotoIf("SIP/3160-0000014f", "1?trunkcid") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (macro-outbound-callerid,s,19)
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:19] ExecIf("SIP/3160-0000014f", "1?Set(CALLERID(all)="NelsonBoxOffice")") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:20] ExecIf("SIP/3160-0000014f", "0?Set(CALLERID(all)=)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:21] ExecIf("SIP/3160-0000014f", "0?Set(CALLERID(all)=)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("SIP/3160-0000014f", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:23] ExecIf("SIP/3160-0000014f", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:24] Set("SIP/3160-0000014f", "CDR(outbound_cnum)=") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-outbound-callerid:25] Set("SIP/3160-0000014f", "CDR(outbound_cnam)=NelsonBoxOffice") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:13] GosubIf("SIP/3160-0000014f", "0?sub-flp-1,s,1()") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:14] Set("SIP/3160-0000014f", "OUTNUM=1250nnnnnnn") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:15] Set("SIP/3160-0000014f", "custom=DAHDI/R0") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:16] ExecIf("SIP/3160-0000014f", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("SIP/3160-0000014f", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:18] Macro("SIP/3160-0000014f", "dialout-trunk-predial-hook,") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/3160-0000014f", "") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:19] GotoIf("SIP/3160-0000014f", "0?bypass,1") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:20] ExecIf("SIP/3160-0000014f", "1?Set(CONNECTEDLINE(num,i)=1250nnnnnnn)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:21] ExecIf("SIP/3160-0000014f", "1?Set(CONNECTEDLINE(name,i)=CID:)") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:22] ExecIf("SIP/3160-0000014f", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden))") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:23] GotoIf("SIP/3160-0000014f", "0?customtrunk") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-dialout-trunk:24] Dial("SIP/3160-0000014f", "DAHDI/R0/1250nnnnnnn,300,T") in new stack
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] app_dial.c: Called DAHDI/R0/1250nnnnnnn
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] app_dial.c: DAHDI/4-1 is ringing
[2017-12-04 11:28:18] VERBOSE[10088][C-000000bf] app_dial.c: DAHDI/4-1 is ringing
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] sig_analog.c: Hanging up on 'DAHDI/4-1'
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] chan_dahdi.c: Hungup 'DAHDI/4-1'
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] app_macro.c: Spawn extension (macro-dialout-trunk, s, 24) exited non-zero on 'SIP/3160-0000014f' in macro 'dialout-trunk'
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx.c: Spawn extension (from-internal, 250nnnnnnn, 6) exited non-zero on 'SIP/3160-0000014f'
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx.c: Executing [h@from-internal:1] Macro("SIP/3160-0000014f", "hangupcall") in new stack
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/3160-0000014f", "1?theend") in new stack
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/3160-0000014f", "0?Set(CDR(recordingfile)=)") in new stack
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/3160-0000014f", "DAHDI/4-1 monior file= ") in new stack
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-hangupcall:5] AGI("SIP/3160-0000014f", "attendedtransfer-rec-restart.php,DAHDI/4-1,") in new stack
[2017-12-04 11:28:20] VERBOSE[10088][C-000000bf] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2017-12-04 11:28:21] VERBOSE[10088][C-000000bf] res_agi.c: <SIP/3160-0000014f>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2017-12-04 11:28:21] VERBOSE[10088][C-000000bf] pbx.c: Executing [s@macro-hangupcall:6] Hangup("SIP/3160-0000014f", "") in new stack
[2017-12-04 11:28:21] VERBOSE[10088][C-000000bf] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'SIP/3160-0000014f' in macro 'hangupcall'
[2017-12-04 11:28:21] VERBOSE[10088][C-000000bf] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/3160-0000014f'
[2017-12-04 11:28:36] WARNING[21687] chan_sip.c: Retransmission timeout reached on transmission [email protected] for seqno 102 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 16127ms with no response

DAHDI/4-1 is my FXS port to an analogue phone. I deleted the phone profile last week and the fault just called the default Ring Group so I reinstated the extension.

lgaetz · December 4, 2017, 8:11pm

[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] app_dial.c: Called DAHDI/R0/1250nnnnnnn
[2017-12-04 11:28:16] VERBOSE[10088][C-000000bf] app_dial.c: DAHDI/4-1 is ringing
[2017-12-04 11:28:18] VERBOSE[10088][C-000000bf] app_dial.c: DAHDI/4-1 is ringing

Your trunk is defined as DAHDI group 0, and presumably group 0 includes DAHDI/4, but if it’s an FXS port, it is not appropriate to include it in a trunk group. You only want FXO ports in group 0.

dicko · December 4, 2017, 8:16pm

Further, you are calling the group as R0 which is why you are getting random results, my guess would be about a 25% failure rate.

Ducktour · December 4, 2017, 8:58pm

Thank you very much Lorne, you are correct in the 25% failure.
So I have set the FXS to Group 1, am I correct?

dicko · December 4, 2017, 9:04pm

That should work, if your FXO’s are in ‘hunt’ then you should use G0 not R0 to reduce the chance of ‘glare’.

Ducktour · December 4, 2017, 9:29pm

Thank you Dicko, much appreciated. Yes they do hunt. Where is that setting?

dicko · December 4, 2017, 10:29pm

in your outbound route definition

Ducktour · December 5, 2017, 2:10am

thank you for your time Dicko, can you explain ‘glare’ and the difference between G0 and R0 please?
I cannot find any reference via the GUI Outbound Routes.

lgaetz · December 5, 2017, 2:29am

“Glare” in this context refers to the PBX seizing an analog line for an outbound call at the exact same instant of an incoming call. Instead of a normal hello, your inbound caller hears dtmf tones as the system tries to call out. It can’t be eliminated, but it can be mitigated in some circumstances. If your inbound calls are in a hunt group and arrive on your analog channels in sequence 1-2-3-4, then you would configure your DAHDI trunk to use “Group 0 Descending” so that outbound calls go out in sequence 4-3-2-1.

Ducktour · December 5, 2017, 2:45am

Many thanks Lorne, that explains it fully. I appreciate your time.

Edwin

dicko · December 5, 2017, 3:02am

and R0 is the same trunks in “round robin Descending” hence the 25% failure rate

Ducktour · December 5, 2017, 11:00pm

All makes sense now, thank you both for your help. System working fine now.