Freepbx does not try next trunk in list

rusya_rr · September 14, 2011, 7:57am

Hi, people!
There are several SIP trunks connecting Freepbx box to my SIP provider softswitch (Mera if it does matter). Each trunk has its loginname equal to phone number (for example 2110012). When somebody calls out using the first trunk in list, nobody else can call out anymore, receiving a busy tone. Here is a log of the call:

        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [2741366@from-internal:1] Macro("SIP/243-00001194", "user-callerid,LIMIT,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:1] Set("SIP/243-00001194", "AMPUSER=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:2] GotoIf("SIP/243-00001194", "0?report") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:3] ExecIf("SIP/243-00001194", "1?Set(REALCALLERIDNUM=243)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:4] Set("SIP/243-00001194", "AMPUSER=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:5] Set("SIP/243-00001194", "AMPUSERCIDNAME=Call11") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:6] GotoIf("SIP/243-00001194", "0?report") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:7] Set("SIP/243-00001194", "AMPUSERCID=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:8] Set("SIP/243-00001194", "CALLERID(all)="Call11" <243>") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:9] GotoIf("SIP/243-00001194", "0?limit") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:10] ExecIf("SIP/243-00001194", "1?Set(GROUP(concurrency_limit)=243)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:11] GosubIf("SIP/243-00001194", "7?sub-ccss,s,1(from-internal,2741366)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@sub-ccss:1] ExecIf("SIP/243-00001194", "0?Return()") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@sub-ccss:2] Set("SIP/243-00001194", "CCSS_SETUP=TRUE") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@sub-ccss:3] GosubIf("SIP/243-00001194", "0?monitor_config,1(from-internal,2741366):monitor_default,1(from-internal,2741366)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [monitor_default@sub-ccss:1] GotoIf("SIP/243-00001194", "0?is_exten") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [monitor_default@sub-ccss:2] StackPop("SIP/243-00001194", "") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [monitor_default@sub-ccss:3] Return("SIP/243-00001194", "FALSE") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:12] ExecIf("SIP/243-00001194", "0?Set(CHANNEL(language)=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:13] GotoIf("SIP/243-00001194", "1?continue") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-user-callerid,s,26)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:26] Set("SIP/243-00001194", "CALLERID(number)=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:27] Set("SIP/243-00001194", "CALLERID(name)=Call11") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-user-callerid:28] Set("SIP/243-00001194", "CHANNEL(language)=ru") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [2741366@from-internal:2] Set("SIP/243-00001194", "MOHCLASS=default") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [2741366@from-internal:3] Set("SIP/243-00001194", "_NODEST=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [2741366@from-internal:4] Macro("SIP/243-00001194", "record-enable,243,OUT,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-record-enable:1] GotoIf("SIP/243-00001194", "1?check") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-record-enable,s,4)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-record-enable:4] ExecIf("SIP/243-00001194", "0?MacroExit()") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-record-enable:5] GotoIf("SIP/243-00001194", "0?Group:OUT") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-record-enable,s,14)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-record-enable:14] GotoIf("SIP/243-00001194", "0?IN") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-record-enable:15] ExecIf("SIP/243-00001194", "1?MacroExit()") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [2741366@from-internal:5] Macro("SIP/243-00001194", "dialout-trunk,27,2741366,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:1] Set("SIP/243-00001194", "DIAL_TRUNK=27") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/243-00001194", "0?sub-pincheck,s,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/243-00001194", "0?disabletrunk,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:4] Set("SIP/243-00001194", "DIAL_NUMBER=2741366") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:5] Set("SIP/243-00001194", "DIAL_TRUNK_OPTIONS=tr") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:6] Set("SIP/243-00001194", "OUTBOUND_GROUP=OUT_27") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/243-00001194", "1?nomax") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-dialout-trunk,s,9)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/243-00001194", "0?skipoutcid") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:10] Set("SIP/243-00001194", "DIAL_TRUNK_OPTIONS=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:11] Macro("SIP/243-00001194", "outbound-callerid,27") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/243-00001194", "0?Set(CALLERPRES()=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/243-00001194", "0?Set(REALCALLERIDNUM=243)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/243-00001194", "1?normcid") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-outbound-callerid,s,6)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:6] Set("SIP/243-00001194", "USEROUTCID=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:7] Set("SIP/243-00001194", "EMERGENCYCID=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:8] Set("SIP/243-00001194", "TRUNKOUTCID=78432113418") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/243-00001194", "1?trunkcid") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-outbound-callerid,s,12)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/243-00001194", "1?Set(CALLERID(all)=78432113418)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/243-00001194", "0?Set(CALLERID(all)=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/243-00001194", "0?Set(CALLERID(all)=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/243-00001194", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/243-00001194", "0?sub-flp-27,s,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:13] Set("SIP/243-00001194", "OUTNUM=2741366") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:14] Set("SIP/243-00001194", "custom=SIP/2113418") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/243-00001194", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/243-00001194", "0?Set(DIAL_TRUNK_OPTIONS=M(confirm))") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:17] Macro("SIP/243-00001194", "dialout-trunk-predial-hook,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/243-00001194", "") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/243-00001194", "0?bypass,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:19] GotoIf("SIP/243-00001194", "0?customtrunk") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:20] Dial("SIP/243-00001194", "SIP/2113418/2741366,300,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] netsock2.c:   == Using SIP RTP TOS bits 184
        [2011-09-12 13:47:03] VERBOSE[30951] netsock2.c:   == Using SIP RTP CoS mark 5
        [2011-09-12 13:47:03] VERBOSE[30951] app_dial.c:     -- Called SIP/2113418/2741366
        [2011-09-12 13:47:03] VERBOSE[31918] chan_sip.c:     -- Got SIP response 603 "Out of capacity" back from 88.17.46.6:5060
        [2011-09-12 13:47:03] VERBOSE[30951] app_dial.c:     -- SIP/2113418-00001195 is busy
        [2011-09-12 13:47:03] VERBOSE[30951] app_dial.c:   == Everyone is busy/congested at this time (1:1/0/0)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:21] NoOp("SIP/243-00001194", "Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 21") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s@macro-dialout-trunk:22] Goto("SIP/243-00001194", "s-BUSY,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Goto (macro-dialout-trunk,s-BUSY,1)
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s-BUSY@macro-dialout-trunk:1] NoOp("SIP/243-00001194", "Dial failed due to trunk reporting BUSY - giving up") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s-BUSY@macro-dialout-trunk:2] PlayTones("SIP/243-00001194", "busy") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [s-BUSY@macro-dialout-trunk:3] Busy("SIP/243-00001194", "20") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] app_macro.c:   == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'SIP/243-00001194' in macro 'dialout-trunk'
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:   == Spawn extension (from-internal, 2741366, 5) exited non-zero on 'SIP/243-00001194'
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [h@from-internal:1] Hangup("SIP/243-00001194", "") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:   == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/243-00001194'

It displays that Freepbx does make no attempts to use another trunk.
Some of my russian friends explained me that " 603 “Out of capacity” message is interpreted by Freepbx as if the person called is busy and that is why making another trial according to a human logic does not make sense.
Any help would be appreciated. Thank u.

magpye · September 23, 2011, 5:22am

You’ve given information about your trunk, but nothing about the outbound route configuration.
If the outbound route does not have a secondary trunk listed, then the call will fail.

I’m not sure what logic your Russian friends are using, because one person getting a busy signal should not bring outbound calling to a screeching halt.

obelisk · September 23, 2011, 7:11am

Your friends are correct.
The workaround is to limit the number of concurrent calls through the trunk.
Set Maximum Channels to 1 for your trunks.

rusya_rr · September 24, 2011, 5:24pm

u’r right, obelisk. U’r trick resolved the issue. But just a half a problem. I’ve got the same sip response “603 - out of capacity” when there is incoming call in the route. When trying to call out via the trunk in the moment it receives this error. But when there is an outcoming call in the trunk an attempt to place another outcoming call into the trunk results in choosing the next one - works like a charm.
This error must be handled in a custom way but I don’t know how yet. Anybody knows?

obelisk · September 24, 2011, 9:12pm

You need to move your mouse over “Maximum Channels” and read the hint

rusya_rr · September 28, 2011, 4:49pm

Obelisk, u’r right twice. It’d help me if my VSP authenticated with username and password, but it authenticates only when sees the fist found peer with its ip address and even doesn’t try to look for a username section. No matter whether or not username and secret defined. No incoming calls without insecure=invite,port. Thus all incoming calls have the same channel(the first peer found), so I can’t use those autocreated contexts for each trunk. Sad.

obelisk · September 26, 2011, 10:05pm

You need to create a custom context for your trunks e.g. [from-myvsp] and jump to these autogenerated contexts based on DID.
E.g.


[from-myvsp]
exten => DID1,1,Goto(from-trunk-sip-trunk1,${EXTEN},1)
exten => DID2,1,Goto(from-trunk-sip-trunk2,${EXTEN},1)
...........

I hope your VSP is sending you DIDs, if not you will need to read
http://www.freepbx.org/support/documentation/howtos/how-to-get-the-did-of-a-sip-trunk-when-the-provider-doesnt-send-it-and-

rusya_rr · October 21, 2011, 1:49pm

Ok, tx u very much for ur answers. U helped me.
And u know what? I resolved it like here :). Tx u once again.

rusya_rr · October 21, 2011, 1:52pm

1.Copy [macro-dialout-trunk] from the file extensions_additional.conf into extensions_override_freepbx.conf
2. Put

exten => s,n,NoOp(SIP return code : ${HASH(SIP_CAUSE,${CDR(dstchannel)})})
;"SIP 603 Out of capacity"
exten => s,n,GotoIf($["${HASH(SIP_CAUSE,${CDR(dstchannel)})}" = "SIP 603 Out of capacity"]?continue,1)

right after the string

exten => s,n,Dial(${OUT_${DIAL_TRUNK}}/${OUTNUM},300,${DIAL_TRUNK_OPTIONS})

, where 603 Out of capacity - a specific error got from a VSP.
3. run CLI asterisk: asterisk -r
4. execute dialplan reload within the CLI

Special tx to abw1oim for the clue