Freepbx does not try next trunk in list

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 [[email protected]:1] Macro("SIP/243-00001194", "user-callerid,LIMIT,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:1] Set("SIP/243-00001194", "AMPUSER=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:2] GotoIf("SIP/243-00001194", "0?report") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:3] ExecIf("SIP/243-00001194", "1?Set(REALCALLERIDNUM=243)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:4] Set("SIP/243-00001194", "AMPUSER=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:5] Set("SIP/243-00001194", "AMPUSERCIDNAME=Call11") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:6] GotoIf("SIP/243-00001194", "0?report") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:7] Set("SIP/243-00001194", "AMPUSERCID=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:8] Set("SIP/243-00001194", "CALLERID(all)="Call11" <243>") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/243-00001194", "0?limit") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]: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 [[email protected]:1] ExecIf("SIP/243-00001194", "0?Return()") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:2] Set("SIP/243-00001194", "CCSS_SETUP=TRUE") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:1] GotoIf("SIP/243-00001194", "0?is_exten") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:2] StackPop("SIP/243-00001194", "") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:3] Return("SIP/243-00001194", "FALSE") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:12] ExecIf("SIP/243-00001194", "0?Set(CHANNEL(language)=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:26] Set("SIP/243-00001194", "CALLERID(number)=243") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:27] Set("SIP/243-00001194", "CALLERID(name)=Call11") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:28] Set("SIP/243-00001194", "CHANNEL(language)=ru") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:2] Set("SIP/243-00001194", "MOHCLASS=default") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:3] Set("SIP/243-00001194", "_NODEST=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:4] Macro("SIP/243-00001194", "record-enable,243,OUT,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:4] ExecIf("SIP/243-00001194", "0?MacroExit()") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:14] GotoIf("SIP/243-00001194", "0?IN") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/243-00001194", "1?MacroExit()") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:5] Macro("SIP/243-00001194", "dialout-trunk,27,2741366,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:1] Set("SIP/243-00001194", "DIAL_TRUNK=27") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:2] GosubIf("SIP/243-00001194", "0?sub-pincheck,s,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/243-00001194", "0?disabletrunk,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:4] Set("SIP/243-00001194", "DIAL_NUMBER=2741366") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:5] Set("SIP/243-00001194", "DIAL_TRUNK_OPTIONS=tr") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:6] Set("SIP/243-00001194", "OUTBOUND_GROUP=OUT_27") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:9] GotoIf("SIP/243-00001194", "0?skipoutcid") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:10] Set("SIP/243-00001194", "DIAL_TRUNK_OPTIONS=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:11] Macro("SIP/243-00001194", "outbound-callerid,27") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/243-00001194", "0?Set(CALLERPRES()=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:2] ExecIf("SIP/243-00001194", "0?Set(REALCALLERIDNUM=243)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:6] Set("SIP/243-00001194", "USEROUTCID=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:7] Set("SIP/243-00001194", "EMERGENCYCID=") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:8] Set("SIP/243-00001194", "TRUNKOUTCID=78432113418") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]:12] ExecIf("SIP/243-00001194", "1?Set(CALLERID(all)=78432113418)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:13] ExecIf("SIP/243-00001194", "0?Set(CALLERID(all)=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:14] ExecIf("SIP/243-00001194", "0?Set(CALLERID(all)=)") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]: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 [[email protected]:13] Set("SIP/243-00001194", "OUTNUM=2741366") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:14] Set("SIP/243-00001194", "custom=SIP/2113418") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]: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 [[email protected]:17] Macro("SIP/243-00001194", "dialout-trunk-predial-hook,") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:1] MacroExit("SIP/243-00001194", "") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:18] GotoIf("SIP/243-00001194", "0?bypass,1") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]:19] GotoIf("SIP/243-00001194", "0?customtrunk") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] PlayTones("SIP/243-00001194", "busy") in new stack
        [2011-09-12 13:47:03] VERBOSE[30951] pbx.c:     -- Executing [[email protected]: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 [[email protected]: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.

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.

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.

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?

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

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.

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-

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

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