Potential incorrect handling of SIP 404?

blanchae · February 3, 2010, 6:48am

Mikael:

It was security by obscurity as far as I can tell. The hacker attempts to break in by brute forcing the extensions, wrong extensions give a weird message. Don’t shoot me, I’m just the messenger in this.

If you read the code that originates the message “All circuits are busy”, the comment of the author is

[[from-sip-external]
;give external sip users congestion and hangup
; Yes. This is really meant to be _. - I know asterisk whinges about it, but
; I do know what I’m doing. This is correct.

I figure that he knows more about it than I do…

I’m not complaining about the changes, I’m glad that there is better error handling that will aid in troubleshooting

mickecarlsson · February 3, 2010, 7:22am

Hi blanchae,

I am not complaining to you, no way, I do like your posts and your excellent texts about PBX in a Flash and the PiaF system summary presentation.

I think that you have detected a line that should be removed a long time ago.
The text “;give external sip users congestion and hangup” was for when an anonymous peer tried to call into the system it would get the “ss-noservice”. But it is selectable in the GUI to actually make it possible to receive anonymous calls.

The rest of the text:
; Yes. This is really meant to be . - I know asterisk whinges about it, but
; I do know what I’m doing.
This is correct. It is for the ". that is a catch-all and is not related to the “;give external sip users congestion and hangup”.

And the feature is for outgoing calls only, not incoming.

I will remove that line to avoid confusion, but I need to look through the code to see when it was added so I get a grip of what it was referring to in the first place.

Take care,

curto · April 15, 2010, 6:46am

We have a TE205 Dual Channel PRI - the telco error classes are not being handled properly - we always get the All Circuits are busy message - even for incorrect numbers etc.

Does anyone know the status of this in 2.7 ?

regards

Craig

jmehl · April 16, 2010, 7:43pm

… and it looks like macro-outisbusy hasn’t changed in my extensions.conf file to reflect the HANGUPCAUSE values.

Would love to have a solution on this - we get lots of user calls saying “it’s busy” when in fact they’ve dialed a bad number, etc.

jmehl · April 16, 2010, 10:46pm

still don’t know why my 2.7.0.1 isn’t working. But I found this solution:

http://www.trixbox.org/forums/trixbox-forums/open-discussion/all-circuits-are-busy-message-when-invalid-number-dialed

plindheimer · April 17, 2010, 12:07am

what hangupcause are you receiving?

Version 2.7 has added the handling of some hangupcauses though due to the inconsistencies with all carriers, there are likely some not there.

This line should be there:

exten => 28,1,Goto(s-INVALIDNMBR,1)

which would play an ss-noservice message. I suspect we may need to add more but we need to know what you are receiving and then we can assess if it is safe to add that.

curto · April 20, 2010, 4:32am

Implemented it as described. Did an amportal stop and asterisk stop, then started all backup again - still no good

Craig

curto · April 20, 2010, 4:45am

Phillipe, Thanks firstly for taking the time to look at this

Our system is as follows (for background)

PIAF 1.4
Centos 5.2
FreePBX 2.7.0.1

We have a TE210P 3.3v Rev 2 card - we are connected to an Australian PRI (30 channels plus two signalling channels) of which we have 20 provisioned

We use LCR across this PRI trunk to direct calls to various providers based on their call rates. We have implemented this using Outbound Route pattern matching and Custom Trunks (these simple append the correct LCR code for the vendors as required)

We finding that the following conditions all seem to generate the same message to be played

1)incorrect/invalid number
2)Engaged/busy number
3)number blocked by the LCR provider

Below is the capture from the log of the call in question when the number is engaged (we had called it from a mobile phone and ensured they did not have call waiting available)

[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [0296051135@from-internal:1] Macro(“SIP/519-b67e5018”, “user-callerid|SKIPTTL|”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/519-b67e5018”, “AMPUSER=519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/519-b67e5018”, “0?report”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/519-b67e5018”, “1|Set|REALCALLERIDNUM=519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/519-b67e5018”, “AMPUSER=519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/519-b67e5018”, “AMPUSERCIDNAME=Michele Martinez”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/519-b67e5018”, “0?report”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/519-b67e5018”, “AMPUSERCID=519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/519-b67e5018”, “CALLERID(all)=“Michele Martinez” <519>”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/519-b67e5018”, “0|Set|CHANNEL(language)=”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/519-b67e5018”, “1?continue”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Goto (macro-user-callerid,s,19)
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“SIP/519-b67e5018”, “Using CallerID “Michele Martinez” <519>”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Noop
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [0296051135@from-internal:2] Set(“SIP/519-b67e5018”, “_NODEST=”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [0296051135@from-internal:3] Macro(“SIP/519-b67e5018”, “record-enable|519|OUT|”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/519-b67e5018”, “1?check”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Goto (macro-record-enable,s,4)
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/519-b67e5018”, “0|MacroExit|”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/519-b67e5018”, “0?Group:OUT”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Goto (macro-record-enable,s,15)
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/519-b67e5018”, “0?IN”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/519-b67e5018”, “1|MacroExit|”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [0296051135@from-internal:4] Macro(“SIP/519-b67e5018”, “dialout-trunk|2|0296051135||”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/519-b67e5018”, “DIAL_TRUNK=2”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] DEBUG[15134] func_db.c: DB: AMPUSER/519/pinless not found in database.
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/519-b67e5018”, “0?sub-pincheck|s|1”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GosubIf
[2010-04-20 13:58:57] DEBUG[15134] func_db.c: DB: AMPUSER/519/pinless not found in database.
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/519-b67e5018”, “0?disabletrunk|1”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/519-b67e5018”, “DIAL_NUMBER=0296051135”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/519-b67e5018”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/519-b67e5018”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/519-b67e5018”, “0?nomax”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/519-b67e5018”, “0?chanfull”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/519-b67e5018”, “0?skipoutcid”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/519-b67e5018”, “DIAL_TRUNK_OPTIONS=”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/519-b67e5018”, “outbound-callerid|2”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/519-b67e5018”, “0|SetCallerPres|”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/519-b67e5018”, “0|Set|REALCALLERIDNUM=519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/519-b67e5018”, “1?normcid”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Goto (macro-outbound-callerid,s,6)
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/519-b67e5018”, “USEROUTCID=292557519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] DEBUG[15134] func_db.c: DB: DEVICE/519/emergency_cid not found in database.
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/519-b67e5018”, “EMERGENCYCID=”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/519-b67e5018”, “TRUNKOUTCID=”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/519-b67e5018”, “1?trunkcid”) in new stack
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Goto (macro-outbound-callerid,s,12)
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/519-b67e5018”, “0|Set|CALLERID(all)=”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/519-b67e5018”, “1|Set|CALLERID(all)=292557519”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Last app: Set|CALLERID(all)=292557519
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/519-b67e5018”, “0|Set|CALLERID(all)=”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/519-b67e5018”, “0|SetCallerPres|prohib_passed_screen”) in new stack
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:57] DEBUG[15134] app_macro.c: Executed application: Macro
[2010-04-20 13:58:57] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:12] ExecIf(“SIP/519-b67e5018”, “1|AGI|fixlocalprefix”) in new stack
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: == fixlocalprefix: Dialpattern 1434+. matched. 0296051135 -> 14340296051135
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – AGI Script fixlocalprefix completed, returning 0
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Last app: AGI|fixlocalprefix
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/519-b67e5018”, “OUTNUM=14340296051135”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/519-b67e5018”, “custom=AMP”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/519-b67e5018”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: ExecIf
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/519-b67e5018”, “dialout-trunk-predial-hook|”) in new stack
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/519-b67e5018”, “”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Macro
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/519-b67e5018”, “0?bypass|1”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/519-b67e5018”, “1?customtrunk”) in new stack
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Goto (macro-dialout-trunk,s,22)
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:22] Set(“SIP/519-b67e5018”, “pre_num=AMP:Local/”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:23] Set(“SIP/519-b67e5018”, “the_num=OUTNUM”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:24] Set(“SIP/519-b67e5018”, “post_num=@LCR-Gotalk”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:25] GotoIf(“SIP/519-b67e5018”, “1?outnum:skipoutnum”) in new stack
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Goto (macro-dialout-trunk,s,26)
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:26] Set(“SIP/519-b67e5018”, “the_num=14340296051135”) in new stack
[2010-04-20 13:58:58] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:27] Dial(“SIP/519-b67e5018”, “Local/14340296051135@LCR-Gotalk|300|”) in new stack
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Called 14340296051135@LCR-Gotalk
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Local/14340296051135@LCR-Gotalk-3a09,1 is ringing
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Local/14340296051135@LCR-Gotalk-3a09,1 stopped sounds
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Dial
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:28] NoOp(“SIP/519-b67e5018”, “Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 0”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Noop
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s@macro-dialout-trunk:29] Goto(“SIP/519-b67e5018”, “s-CHANUNAVAIL|1”) in new stack
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Goto
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set(“SIP/519-b67e5018”, “RC=0”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto(“SIP/519-b67e5018”, “0|1”) in new stack
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Goto (macro-dialout-trunk,0,1)
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Goto
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [0@macro-dialout-trunk:1] Goto(“SIP/519-b67e5018”, “continue|1”) in new stack
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Goto (macro-dialout-trunk,continue,1)
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Goto
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [continue@macro-dialout-trunk:1] GotoIf(“SIP/519-b67e5018”, “1?noreport”) in new stack
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Goto (macro-dialout-trunk,continue,3)
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [continue@macro-dialout-trunk:3] NoOp(“SIP/519-b67e5018”, “TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 0 - failing through to other trunks”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Noop
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [continue@macro-dialout-trunk:4] Set(“SIP/519-b67e5018”, “CALLERID(number)=519”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Set
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [0296051135@from-internal:5] Macro(“SIP/519-b67e5018”, “outisbusy|”) in new stack
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s@macro-outisbusy:1] Progress(“SIP/519-b67e5018”, “”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: Progress
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s@macro-outisbusy:2] GotoIf(“SIP/519-b67e5018”, “0?emergency|1”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s@macro-outisbusy:3] GotoIf(“SIP/519-b67e5018”, “0?intracompany|1”) in new stack
[2010-04-20 13:58:59] DEBUG[15134] app_macro.c: Executed application: GotoIf
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Executing [s@macro-outisbusy:4] Playback(“SIP/519-b67e5018”, “all-circuits-busy-now&pls-try-call-later| noanswer”) in new stack
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – <SIP/519-b67e5018> Playing ‘all-circuits-busy-now’ (language ‘au’)
[2010-04-20 13:59:01] VERBOSE[15134] logger.c: – <SIP/519-b67e5018> Playing ‘pls-try-call-later’ (language ‘au’)
[2010-04-20 13:59:03] DEBUG[15134] app_macro.c: Executed application: Playback
[2010-04-20 13:59:03] VERBOSE[15134] logger.c: – Executing [s@macro-outisbusy:5] Congestion(“SIP/519-b67e5018”, “20”) in new stack
[2010-04-20 13:59:03] VERBOSE[15134] logger.c: == Spawn extension (macro-outisbusy, s, 5) exited non-zero on ‘SIP/519-b67e5018’ in macro ‘outisbusy’
[2010-04-20 13:59:03] VERBOSE[15134] logger.c: == Spawn extension (macro-outisbusy, s, 5) exited non-zero on ‘SIP/519-b67e5018’

regards

Craig

mickecarlsson · April 20, 2010, 5:02am

This is in your log file:
"Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 0"
It seems that your provider does not report back anything useful or that your PRI card is not detecting it.

curto · April 20, 2010, 11:20am

This system has been implemented as a replacement for an Asterisk 1.4 system (commandline driven), it is running on the same hardware (PRI card etc) to the same providers and we did not have this issue then.

I will bypass our LCR routing and see what the call logs tell us from there.

regards

Craig

plindheimer · April 20, 2010, 3:45pm

you are running this through a custom trunk and thus some custom dialplan.

That equates to spawning a new Local channel which is similar to calling a function in programming terms.

I suspect that the HANGUPCAUSE, if being set, may very likely not be ‘passed back’ to the initiating channel just like a local variable would not be since it occurs within the new spawned channel and a failure would end up back here where it was called.

However … from the looks of the trace, it appears that the failure is that there is no such Local channel which is resulting in the CHANUNAVAIL. So check your dialplan. If it were hitting your custom trunk code, you would see it executed in the log above.

curto · April 20, 2010, 11:18pm

Phillipe, You can see where the 1434 is appended to the outgoing number - this is the function of the custom trunk

All of our normal calls are working and going out the way we expect it is only when we hit an incorrect number or engaged etc that we are getting this issue

[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Called 14340296051135@LCR-Gotalk
[2010-04-20 13:58:58] VERBOSE[15134] logger.c: – Local/14340296051135@LCR-Gotalk-3a09,1 is ringing
[2010-04-20 13:58:59] VERBOSE[15134] logger.c: – Local/14340296051135@LCR-Gotalk-3a09,1 stopped

So we dial the number 0296051135, our outbound route matches this and sends it to our custom trunk, which appends the 1434 at the front and then pumps it out through the ZAP group on the Pri (single group only)

Our Custom trunk code is pretty straight forward

;Use this section for Least Cost Routing
[LCR-Gotalk]
exten => _X.,1,Dial(ZAP/g0/${EXTEN},120,tr)
exten => _X.,2,Hangup

[LCR-International]
exten => _X.,1,Dial(ZAP/g0/${EXTEN},120,tr)
exten => _X.,2,Hangup

[LCR-Primus]
exten => _X.,1,Dial(ZAP/g0/${EXTEN},120,tr)
exten => _X.,2,Hangup

[LCR-Bypass]
exten => _X.,1,Dial(ZAP/g0/${EXTEN},120,tr)
exten => _X.,2,Hangup

This is included in the extensions_custom.conf file

and in the outbound trunk all we have in the string is

Local/$OUTNUM$@LCR-Gotalk

regards

Craig

curto · April 21, 2010, 7:28am

I have changed around the custom trunks and outbound routes for testing today and have received the correct error codes as per the log below

l-4477,2", “0?customtrunk”) in new stack
[2010-04-21 17:20:51] VERBOSE[26785] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“Local/98826559@from-internal-
4477,2”, “ZAP/g0/143498826559|300|”) in new stack
[2010-04-21 17:20:51] VERBOSE[26785] logger.c: – Called g0/143498826559
[2010-04-21 17:20:51] VERBOSE[26785] logger.c: – Zap/1-1 is proceeding passing it to Local/98826559@from-internal-4477,2
[2010-04-21 17:20:51] VERBOSE[26784] logger.c: – Local/98826559@from-internal-4477,1 is proceeding passing it to Zap/10-1
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s@macro-dialout-trunk:20] NoOp(“Local/98826559@from-internal-
4477,2”, “Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s@macro-dialout-trunk:21] Goto(“Local/98826559@from-internal-
4477,2”, “s-BUSY|1”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s-BUSY@macro-dialout-trunk:1] NoOp(“Local/98826559@from-inter
nal-4477,2”, “Dial failed due to trunk reporting BUSY - giving up”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s-BUSY@macro-dialout-trunk:2] PlayTones(“Local/98826559@from-
internal-4477,2”, “busy”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s-BUSY@macro-dialout-trunk:3] Busy(“Local/98826559@from-inter
nal-4477,2”, “20”) in new stack
[2010-04-21 17:20:54] VERBOSE[26784] logger.c: – Local/98826559@from-internal-4477,1 is busy
[2010-04-21 17:20:54] VERBOSE[26784] logger.c: – Executing [98826559@disa-dial:3] Gosub(“Zap/10-1”, “s-BUSY|1”) in new st
ack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on ‘Local
/98826559@from-internal-4477,2’ in macro ‘dialout-trunk’
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on ‘Local
/98826559@from-internal-4477,2’
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“Local/98826559@from-internal-
4477,2”, “hangupcall|”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s@macro-hangupcall:1] GotoIf(“Local/98826559@from-internal-44
77,2”, “1?skiprg”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s@macro-hangupcall:4] GotoIf(“Local/98826559@from-internal-44
77,2”, “1?skipblkvm”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s@macro-hangupcall:7] GotoIf(“Local/98826559@from-internal-44
77,2”, “1?theend”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: – Executing [s@macro-hangupcall:9] Hangup(“Local/98826559@from-internal-44
77,2”, “”) in new stack
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘Local/9882655
9@from-internal-4477,2’ in macro ‘hangupcall’
[2010-04-21 17:20:54] VERBOSE[26785] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/9882655
9@from-internal-4477,2’
root@asterisk2:/var/log/asterisk $

So it seems that FreePBX is doing what it is meant to do as is our PRI and Service provider.

The issue we have now is that we need to be able to have the following

Multiple Outbound Routes going out the same physical trunk (Zap/g0) but with different codes appended to the front to perform Least Cost Routing

We were using the code in the previous posts to do this but obviously this appears to be interfering with the ISDN return codes to FreepBX in some fashion through the use of Custom Trunks.

Can anyone see a way for us to do this and still keep the ISDN status codes flowing through correctly ?

regards

Craig

plindheimer · April 21, 2010, 2:23pm

Version 2.8 will let you prepend digits at the route level. You could have multiple routes prepending as needed but all sending to the same trunk.

Version 2.8 is in beta right now so that may not be an option. Otherwise you can write some dialplan that hooks the predial macro in dialout-trunk to change the number being dialed.

curto · April 21, 2010, 3:38pm

We would have to go through a heap of testing as we use UNISTIM extensively.

We have contracted support with you guys, i will raise a ticket to get the custom diaplan stuff written as i would not know where to start on that.

regards
Craig

plindheimer · April 21, 2010, 4:01pm

I can understand needing to test.

As far as UNISTIM is concerned though, it should not make a difference given that any UNISTIM stuff is all custom anyhow and FreePBX should not be messing with it or doing anything that was change what you may have done.

jaisingh · April 22, 2010, 4:34pm

I have a similar issue, it seems that if channel 1 is being used on the pri freepbx does not know that there are channels 2-23 available and gives me back a channel unavailable message.

plindheimer · April 22, 2010, 4:39pm

jaisingh,

sounds like a mis-configuration.

Make sure you have a proper zap/dahdi group configured that includes all the channels you want as part of that group (usually 1-23) and then use that as your trunk. And leave the max calls blank since it is automatic in the case of zap/dahdi.

jaisingh · April 22, 2010, 5:06pm

the pri is setup as -

chan_dahdi_custom.conf :

signalling=pri_cpe
callerid=asreceived
context=from-pstn
channel => 1-23
group=1

in FreePBX trunk config :

from extensions_additonal.conf

OUT_1 = DAHDI/g1

the UI shows zap/g1

I can receive multiple in bound calls, but can only make 1 outbound calls on the PRI (this issues does not exist on sip trunks for me)

thanks

Jai

plindheimer · April 22, 2010, 5:43pm

I would suggest that you may want to open a new ticket to seek help as this had diverted from the original thread and you may end up getting many people not reading it as a result.