Ring groups : offline extension causes external call attempt

paultgreen · May 7, 2016, 8:41pm

Hi there, we have a ring group set up that calls our staff out of hours. Just recently, customers have been getting a “the number you have dialed has not been recognised” message. I’ve traced this tonthr following behaviour.

There are four sip extensions, and two external numbers on the ring group. If all extensions are on line, it’s great - it works as it should. If an extension is off line (which is possible, as we have extensions on our mobile phones which we only tend to use in non-gsm areas), the system appears to attempt to dial the offline extension via the trunk, resulting in the client receiving a “the number you have dialed has not been recognised” message… I’m a rookie with freepbx, and have only worked with it enough to get it doing what we need… But I’d appreciate some advice - either to stop the behaviour all together, or to force the outbound route to only accept numbers with >4 digits (we have a second route which handles 999 calls).

We are running the latest release build of freepbx and all module updates will be under a week old. The outbound route has both analogue and sip lines included, and the behaviour is the same regardless of the trunk order (with a slightly different voice message for each provider).

lgaetz · May 7, 2016, 9:58pm

The “confirm calls” option for the ring group will fix this.

paultgreen · May 7, 2016, 11:44pm

We use confirm calls already, and if all extensions are on, it will play the voice prompt and accept input when the extension is answered as expected. I don’t understand why it would route a number that is configured as an extension to attempt an external call just because the extension is offline. I’m sure that I’ve either messed something up, or the upgrade from 2.x to 13.x has added a new setting that needs some attention, but don’t know where to start.

paultgreen · May 10, 2016, 11:38am

I’ve done some playing around, and I really don’t know enough about Asterisk to know why it’s doing what it’s doing. From what I can work out, it gets told the extension is unavailable (guessing that’s what EXTENSION_STATE: 0 (NOT_INUSE) means)… But then goes on to dial it through the trunk, where the DHADI line is (correctly) giving a “number not in service” audio announcement. The ring group is seeing this as a successful connection, and cancelling calls to those of us that are on call elsewhere.

What I need to achieve is either:

The route does not dial numbers which start with a 6
The ring group uses its own route which doesn’t include the DHADI line
or the best option : 3) It just doesn’t dial offline extensions on the PSTN network.

Any help would be greatfully appreciated - as it’s currently annoying me something crazy… No amount of Googling seems to be fixing the issue

Log file is here:

[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:10] Set("SIP/6001-0000002f", "__DIAL_OPTIONS=trwW") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:11] Set("SIP/6001-0000002f", "CALLERID(all)="Paul" <6001>") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:12] GotoIf("SIP/6001-0000002f", "0?limit") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:13] ExecIf("SIP/6001-0000002f", "0?Set(GROUP(concurrency_limit)=6001)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:14] ExecIf("SIP/6001-0000002f", "0?Set(CHANNEL(language)=)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:15] GotoIf("SIP/6001-0000002f", "0?continue") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:16] ExecIf("SIP/6001-0000002f", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:17] Set("SIP/6001-0000002f", "__TTL=64") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:18] GotoIf("SIP/6001-0000002f", "1?continue") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Goto (macro-user-callerid,s,29)
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:29] Set("SIP/6001-0000002f", "CALLERID(number)=6001") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:30] Set("SIP/6001-0000002f", "CALLERID(name)=Paul") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:31] Set("SIP/6001-0000002f", "CDR(cnum)=6001") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:32] Set("SIP/6001-0000002f", "CDR(cnam)=Paul") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-user-callerid:33] Set("SIP/6001-0000002f", "CHANNEL(language)=en") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:4] Macro("SIP/6001-0000002f", "blkvm-setifempty,") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-blkvm-setifempty:1] GotoIf("SIP/6001-0000002f", "1?init") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Goto (macro-blkvm-setifempty,s,4)
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-blkvm-setifempty:4] Set("SIP/6001-0000002f", "__BLKVM_CHANNEL=SIP/6001-0000002f") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-blkvm-setifempty:5] Set("SIP/6001-0000002f", "SHARED(BLKVM,SIP/6001-0000002f)=TRUE") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-blkvm-setifempty:6] Set("SIP/6001-0000002f", "GOSUB_RETVAL=TRUE") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-blkvm-setifempty:7] MacroExit("SIP/6001-0000002f", "") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:5] GotoIf("SIP/6001-0000002f", "1?skipov") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Goto (from-internal,6091,8)
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:8] Set("SIP/6001-0000002f", "RRNODEST=") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:9] Set("SIP/6001-0000002f", "__NODEST=6091") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:10] GosubIf("SIP/6001-0000002f", "0?sub-rgsetcid,s,1()") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:11] Set("SIP/6001-0000002f", "__CWIGNORE=TRUE") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:12] Set("SIP/6001-0000002f", "_CFIGNORE=TRUE") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:13] Set("SIP/6001-0000002f", "_FORWARD_CONTEXT=block-cf") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:14] Gosub("SIP/6001-0000002f", "sub-record-check,s,1(rg,6091,force)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/6001-0000002f", "0?initialized") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:2] Set("SIP/6001-0000002f", "__REC_STATUS=INITIALIZED") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:3] Set("SIP/6001-0000002f", "NOW=1462879250") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:4] Set("SIP/6001-0000002f", "__DAY=10") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:5] Set("SIP/6001-0000002f", "__MONTH=05") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/6001-0000002f", "__YEAR=2016") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:7] Set("SIP/6001-0000002f", "__TIMESTR=20160510-122050") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:8] Set("SIP/6001-0000002f", "__FROMEXTEN=6001") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:9] Set("SIP/6001-0000002f", "__MON_FMT=wav") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/6001-0000002f", "Recordings initialized") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/6001-0000002f", "0?Set(ARG3=dontcare)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/6001-0000002f", "REC_POLICY_MODE_SAVE=") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/6001-0000002f", "0?Set(REC_STATUS=NO)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/6001-0000002f", "2?checkaction") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Goto (sub-record-check,s,17)
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/6001-0000002f", "0?sub-record-check,rg,1") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:18] NoOp("SIP/6001-0000002f", "Generic rg Recording Check - 6001 6091") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:19] Gosub("SIP/6001-0000002f", "recordcheck,1(force,rg,6091)") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/6001-0000002f", "Starting recording check against force") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/6001-0000002f", "force") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Goto (sub-record-check,recordcheck,5)
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:5] Set("SIP/6001-0000002f", "__REC_POLICY_MODE=FORCE") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:6] GotoIf("SIP/6001-0000002f", "1?startrec") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Goto (sub-record-check,recordcheck,16)
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:16] NoOp("SIP/6001-0000002f", "Starting recording: rg, 6091") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:17] Set("SIP/6001-0000002f", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:18] Set("SIP/6001-0000002f", "__CALLFILENAME=rg-6091-6001-20160510-122050-1462879250.96") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:19] MixMonitor("SIP/6001-0000002f", "2016/05/10/rg-6091-6001-20160510-122050-1462879250.96.wav,ai(LOCAL_MIXMON_ID),/usr/local/sbin/postrecord.sh ^{TIMESTR} ^{FROMEXTEN} ^{CALLFILENAME} ^{UNIQUEID} ^{ARG3}") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:20] Set("SIP/6001-0000002f", "__MIXMON_ID=0x7f23640ffaa0") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:21] Set("SIP/6001-0000002f", "__RECORD_ID=SIP/6001-0000002f") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:22] Set("SIP/6001-0000002f", "__REC_STATUS=RECORDING") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:23] Set("SIP/6001-0000002f", "CDR(recordingfile)=rg-6091-6001-20160510-122050-1462879250.96.wav") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [recordcheck@sub-record-check:24] Return("SIP/6001-0000002f", "") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@sub-record-check:20] Return("SIP/6001-0000002f", "") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:15] Set("SIP/6001-0000002f", "RingGroupMethod=ringall") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:16] GotoIf("SIP/6001-0000002f", "0?DIALGRP") in new stack
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:17] Answer("SIP/6001-0000002f", "") in new stack
[2016-05-10 12:20:50] VERBOSE[19967][C-0000005b] app_mixmonitor.c: == Begin MixMonitor Recording SIP/6001-0000002f
[2016-05-10 12:20:50] WARNING[19963][C-0000005b] res_rtp_asterisk.c: PJ ICE Rx error status code: 370400 'Bad Request'.
[2016-05-10 12:20:50] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:18] Wait("SIP/6001-0000002f", "1") in new stack
[2016-05-10 12:20:51] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:19] Playback("SIP/6001-0000002f", "custom/Calls_Recorded_Being_connected") in new stack
[2016-05-10 12:20:51] VERBOSE[19963][C-0000005b] file.c: -- <SIP/6001-0000002f> Playing 'custom/Calls_Recorded_Being_connected.slin' (language 'en')
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [6091@from-internal:20] Macro("SIP/6001-0000002f", "dial-confirm,25,m(default)twW,6011,6091") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:1] Set("SIP/6001-0000002f", "DB(RG/6091/SIP/6001-0000002f)=RINGING") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:2] Set("SIP/6001-0000002f", "__UNIQCHAN=SIP/6001-0000002f") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:3] Set("SIP/6001-0000002f", "USE_CONFIRMATION=TRUE") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:4] Set("SIP/6001-0000002f", "RINGGROUP_INDEX=6091") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:5] Set("SIP/6001-0000002f", "FORCE_CONFIRM=") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:6] Set("SIP/6001-0000002f", "ARG4=") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-confirm:7] Macro("SIP/6001-0000002f", "dial,25,m(default)twW,6011") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:1] NoOp("SIP/6001-0000002f", "Blind Transfer: , Attended Transfer: , User: 6001, Alert Info: ") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:2] ExecIf("SIP/6001-0000002f", "1?Set(ALERT_INFO=)") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:3] ExecIf("SIP/6001-0000002f", "0?Set(ALERT_INFO=)") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:4] ExecIf("SIP/6001-0000002f", "0?Set(ALERT_INFO=)") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:5] ExecIf("SIP/6001-0000002f", "0?Set(CHANNEL(musicclass)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:6] AGI("SIP/6001-0000002f", "dialparties.agi") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: dialparties.agi: Caller ID name is 'Paul' number is '6001'
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- dialparties.agi: Added extension 6011 to extension map
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- dialparties.agi: Extension 6011 cf is disabled
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- dialparties.agi: Extension 6011 do not disturb is disabled
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: dialparties.agi: Extension 6011 has ExtensionState: 0
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- dialparties.agi: Checking CW and CFB status for extension 6011
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- dialparties.agi: dbset CALLTRACE/6011 to 6001
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- dialparties.agi: Filtered ARG3: 6011
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_agi.c: -- <SIP/6001-0000002f>AGI Script dialparties.agi completed, returning 0
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:9] NoOp("SIP/6001-0000002f", "Returned from dialparties with groups to dial") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:10] Set("SIP/6001-0000002f", "LOOPCNT=1") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:11] Set("SIP/6001-0000002f", "ITER=1") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:12] Set("SIP/6001-0000002f", "EXTTOCALL=6011") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:13] NoOp("SIP/6001-0000002f", "Working with 6011") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:14] Set("SIP/6001-0000002f", "ITER=2") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:15] GotoIf("SIP/6001-0000002f", "0?ndloopbegin") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:16] Macro("SIP/6001-0000002f", "dial-ringall-predial-hook,") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial-ringall-predial-hook:1] MacroExit("SIP/6001-0000002f", "") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-dial:17] Dial("SIP/6001-0000002f", "Local/LC-6011@from-internal,25,m(default)twWb(func-apply-sipheaders^s^1),") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] app_stack.c: -- Local/LC-6011@from-internal-00000014;1 Internal Gosub(func-apply-sipheaders,s,1) start
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@func-apply-sipheaders:1] NoOp("Local/LC-6011@from-internal-00000014;1", "Applying SIP Headers to channel") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@func-apply-sipheaders:2] Set("Local/LC-6011@from-internal-00000014;1", "SIPHEADERKEYS=") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@func-apply-sipheaders:3] While("Local/LC-6011@from-internal-00000014;1", "0") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] app_while.c: -- Jumping to priority 7
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@func-apply-sipheaders:8] Return("Local/LC-6011@from-internal-00000014;1", "") in new stack
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] app_stack.c: == Spawn extension (from-internal, 6091, 1) exited non-zero on 'Local/LC-6011@from-internal-00000014;1'
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] app_stack.c: -- Local/LC-6011@from-internal-00000014;1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] app_dial.c: -- Called Local/LC-6011@from-internal
[2016-05-10 12:21:01] VERBOSE[19963][C-0000005b] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/6001-0000002f
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [LC-6011@from-internal:1] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(DIAL_OPTIONS=trwWI)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [LC-6011@from-internal:2] Dial("Local/LC-6011@from-internal-00000014;2", "SIP/6011,25,trwWM(auto-confirm^6091)b(func-apply-sipheaders^s^1)") in new stack
[2016-05-10 12:21:01] WARNING[20123][C-0000005b] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [LC-6011@from-internal:3] ExecIf("Local/LC-6011@from-internal-00000014;2", "0 ?Set(CDR(accountcode)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [LC-6011@from-internal:4] Set("Local/LC-6011@from-internal-00000014;2", "MOHCLASS=default") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [LC-6011@from-internal:5] Set("Local/LC-6011@from-internal-00000014;2", "_NODEST=") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [LC-6011@from-internal:6] Macro("Local/LC-6011@from-internal-00000014;2", "dialout-trunk,2,LC-6011,,on") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("Local/LC-6011@from-internal-00000014;2", "DIAL_TRUNK=2") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("Local/LC-6011@from-internal-00000014;2", "0?sub-pincheck,s,1()") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?disabletrunk,1") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("Local/LC-6011@from-internal-00000014;2", "DIAL_NUMBER=LC-6011") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("Local/LC-6011@from-internal-00000014;2", "DIAL_TRUNK_OPTIONS=trwW") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("Local/LC-6011@from-internal-00000014;2", "OUTBOUND_GROUP=OUT_2") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?nomax") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:8] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?chanfull") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?skipoutcid") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:10] Set("Local/LC-6011@from-internal-00000014;2", "DIAL_TRUNK_OPTIONS=TtwW") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:11] Macro("Local/LC-6011@from-internal-00000014;2", "outbound-callerid,2") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:3] ExecIf("Local/LC-6011@from-internal-00000014;2", "1?Set(REALCALLERIDNUM=6001)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:4] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?normcid") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:5] Set("Local/LC-6011@from-internal-00000014;2", "USEROUTCID=6001") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:6] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?bypass") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:7] Set("Local/LC-6011@from-internal-00000014;2", "USEROUTCID=") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:8] Set("Local/LC-6011@from-internal-00000014;2", "EMERGENCYCID=") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:9] Set("Local/LC-6011@from-internal-00000014;2", "TRUNKOUTCID=") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:10] GotoIf("Local/LC-6011@from-internal-00000014;2", "1?trunkcid") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Goto (macro-outbound-callerid,s,15)
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:15] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERID(all)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:16] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERID(all)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:17] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERID(all)=)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:18] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:19] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:20] Set("Local/LC-6011@from-internal-00000014;2", "CDR(outbound_cnum)=6001") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-outbound-callerid:21] Set("Local/LC-6011@from-internal-00000014;2", "CDR(outbound_cnam)=Paul") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:12] GosubIf("Local/LC-6011@from-internal-00000014;2", "0?sub-flp-2,s,1()") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("Local/LC-6011@from-internal-00000014;2", "OUTNUM=LC-6011") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("Local/LC-6011@from-internal-00000014;2", "custom=DAHDI/1") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)TtwW)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:16] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(DIAL_TRUNK_OPTIONS=TtwWM(confirm))") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:17] Macro("Local/LC-6011@from-internal-00000014;2", "dialout-trunk-predial-hook,") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("Local/LC-6011@from-internal-00000014;2", "") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?bypass,1") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:19] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CONNECTEDLINE(num,i)=LC-6011)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:20] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CONNECTEDLINE(name,i)=CID:6001)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:21] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)6001)") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:22] GotoIf("Local/LC-6011@from-internal-00000014;2", "0?customtrunk") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-dialout-trunk:23] Dial("Local/LC-6011@from-internal-00000014;2", "DAHDI/1/LC-6011,300,TtwW") in new stack
[2016-05-10 12:21:01] VERBOSE[20123][C-0000005b] app_dial.c: -- Called DAHDI/1/LC-6011
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] app_dial.c: -- DAHDI/1-1 answered Local/LC-6011@from-internal-00000014;2
[2016-05-10 12:21:04] VERBOSE[19963][C-0000005b] app_dial.c: -- Local/LC-6011@from-internal-00000014;1 answered SIP/6001-0000002f
[2016-05-10 12:21:04] VERBOSE[19963][C-0000005b] res_musiconhold.c: -- Stopped music on hold on SIP/6001-0000002f
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [h@macro-dialout-trunk:1] Macro("Local/LC-6011@from-internal-00000014;2", "hangupcall,") in new stack
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("Local/LC-6011@from-internal-00000014;2", "1?Set(CDR(recordingfile)=rg-6091-6001-20160510-122050-1462879250.96.wav)") in new stack
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("Local/LC-6011@from-internal-00000014;2", "1?theend") in new stack
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: -- Goto (macro-hangupcall,s,4)
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:4] ExecIf("Local/LC-6011@from-internal-00000014;2", "0?Set(CDR(recordingfile)=)") in new stack
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:5] Hangup("Local/LC-6011@from-internal-00000014;2", "") in new stack
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on 'Local/LC-6011@from-internal-00000014;2' in macro 'hangupcall'
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'Local/LC-6011@from-internal-00000014;2'
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 23) exited non-zero on 'Local/LC-6011@from-internal-00000014;2' in macro 'dialout-trunk'
[2016-05-10 12:21:04] VERBOSE[20123][C-0000005b] pbx.c: == Spawn extension (from-internal, LC-6011, 6) exited non-zero on 'Local/LC-6011@from-internal-00000014;2'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [h@macro-dial:1] Macro("SIP/6001-0000002f", "hangupcall,") in new stack
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("SIP/6001-0000002f", "0?Set(CDR(recordingfile)=rg-6091-6001-20160510-122050-1462879250.96.wav)") in new stack
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("SIP/6001-0000002f", "0?theend") in new stack
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:3] NoOp("SIP/6001-0000002f", "Deleting: RG/6091/SIP/6001-0000002f RINGING") in new stack
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:4] ExecIf("SIP/6001-0000002f", "0?Set(CDR(recordingfile)=)") in new stack
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: -- Executing [s@macro-hangupcall:5] Hangup("SIP/6001-0000002f", "") in new stack
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on 'SIP/6001-0000002f' in macro 'hangupcall'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: == Spawn extension (macro-dial, h, 1) exited non-zero on 'SIP/6001-0000002f'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] sig_analog.c: -- Hanging up on 'DAHDI/1-1'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] chan_dahdi.c: -- Hungup 'DAHDI/1-1'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] app_macro.c: == Spawn extension (macro-dial, s, 17) exited non-zero on 'SIP/6001-0000002f' in macro 'dial'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] app_macro.c: == Spawn extension (macro-dial-confirm, s, 7) exited non-zero on 'SIP/6001-0000002f' in macro 'dial-confirm'
[2016-05-10 12:21:10] VERBOSE[19963][C-0000005b] pbx.c: == Spawn extension (from-internal, 6091, 20) exited non-zero on 'SIP/6001-0000002f'

tm1000 · May 10, 2016, 6:08pm

Asterisk is unable to get the states of DAHDi devices the same way as it gets SIP/IAX devices. Therefore when it queries a DAHDi device for state nothing useful is really returned (it probably should ask DAHDi however…)

We looked into this recently in paging but there’s no good way to ask Asterisk if DAHDi can get calls. (@xrobau)

I think removing that from the ringgroup would help you.

xrobau · May 10, 2016, 6:55pm

This is a technical issue with DAHDI, specifically analog DAHDI lines, or, PRIs that ‘Answer’ when they shouldn’t. Basically, it’s exactly the same to the phone system when a call is answered by someone saying ‘Hello?’ as it is answered by the Telco saying ‘This number is not in service’.

This is why ‘Confirm Call’ exists, so there is a way to tell if a DAHDI line was answered by a person (or, a normal line by Voicemail).