All circuits are busy after upgrade to 2.7.0.5

Hi,

After upgrading the core to 2.7.0.5 I have a problem with the oubound route - all circuits are busy problem.

All trunks are registered properly and used to work fine before the 2.7.0.5 core update (from 2.7.0.4).

I use g729 codes and have 5 licenses installed.

Now I am not sure if this is a bug or not.

Tips and tricks are welcome!

Richard

Log output of outbound call:

[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [00###########@from-internal:1] Macro("SIP/1003-082269c0", "user-callerid|SKIPTTL|") in new stack
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:1] Set("SIP/1003-082269c0", "AMPUSER=1003") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Set
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:2] GotoIf("SIP/1003-082269c0", "0?report") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: GotoIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:3] ExecIf("SIP/1003-082269c0", "1|Set|REALCALLERIDNUM=1003") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: ExecIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:4] Set("SIP/1003-082269c0", "AMPUSER=1003") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Set
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:5] Set("SIP/1003-082269c0", "AMPUSERCIDNAME=Richard") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Set
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:6] GotoIf("SIP/1003-082269c0", "0?report") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: GotoIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:7] Set("SIP/1003-082269c0", "AMPUSERCID=1003") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Set
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:8] Set("SIP/1003-082269c0", "CALLERID(all)="Richard" <1003>") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Set
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:9] ExecIf("SIP/1003-082269c0", "0|Set|CHANNEL(language)=") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: ExecIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:10] GotoIf("SIP/1003-082269c0", "1?continue") in new stack
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Goto (macro-user-callerid,s,19)
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: GotoIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:19] NoOp("SIP/1003-082269c0", "Using CallerID "Richard" <1003>") in new stack
*** STRIPPED ***
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Noop
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [00###########@from-internal:6] Macro("SIP/1003-082269c0", "outisbusy|") in new stack
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:1] Progress("SIP/1003-082269c0", "") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: Progress
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:2] GotoIf("SIP/1003-082269c0", "0?emergency|1") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: GotoIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:3] GotoIf("SIP/1003-082269c0", "0?intracompany|1") in new stack
[Apr 11 15:28:58] DEBUG[4128] app_macro.c: Executed application: GotoIf
[Apr 11 15:28:58] VERBOSE[4128] logger.c:     -- Executing [[email protected]:4] Playback("SIP/1003-082269c0", "all-circuits-busy-now&pls-try-call-later| noanswer") in new stack

This looks wrong:

Executing [00###########@from-internal:1] Macro("SIP/1003-082269c0", "user-callerid|SKIPTTL|") in new stack
Executing [00###########@from-internal:2] Macro("SIP/1003-082269c0", "user-callerid|SKIPTTL|") in new stack
Executing [00###########@from-internal:3] Macro("SIP/1003-082269c0", "user-callerid|SKIPTTL|") in new stack
Executing [00###########@from-internal:4] Macro("SIP/1003-082269c0", "user-callerid|SKIPTTL|") in new stack
Executing [00###########@from-internal:5] Macro("SIP/1003-082269c0", "user-callerid|SKIPTTL|") in new stack

Type dialplan show 00###########@from-internal from an asterisk cli and post the outcome here (replacing 00########### with your real number and then masking it again)

inchmarlow*CLI> dialplan show 00###########@from-internal
[ Included context 'outrt-001-0_outside' created by 'pbx_config' ]
  '_0.' =>          1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|5|${EXTEN:1}||)        [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_0.' =>          1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|5|${EXTEN:1}||)        [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_0.' =>          1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|5|${EXTEN:1}||)        [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_0.' =>          1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|5|${EXTEN:1}||)        [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_0.' =>          1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|5|${EXTEN:1}||)        [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_0.' =>          1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    3. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    4. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    5. Macro(user-callerid|SKIPTTL|)              [pbx_config]

[ Included context 'outrt-006-lamse_int_1' created by 'pbx_config' ]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(dialout-trunk|3|${EXTEN}||)          [pbx_config]
                    6. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    3. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    4. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    5. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    6. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    7. Macro(user-callerid|SKIPTTL|)              [pbx_config]

[ Included context 'bad-number' created by 'pbx_config' ]
  '_X.' =>          1. ResetCDR()                                 [pbx_config]
                    2. NoCDR()                                    [pbx_config]
                    3. Wait(1)                                    [pbx_config]
                    4. Playback(silence/1&cannot-complete-as-dialed&check-number-dial-again|noanswer) [pbx_config]
                    5. Wait(1)                                    [pbx_config]
                    6. Congestion(20)                             [pbx_config]
                    7. Hangup()                                   [pbx_config]

-= 15 extensions (86 priorities) in 3 contexts. =-

It should match: outrt-006-lamse_int_1

My dialplan is as follow:
00./1003
etc…

something looks corrupted.

can you just delete that route completely and then re-create it and see if the section that looks like:

'_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    3. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    4. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    5. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    6. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    7. Macro(user-callerid|SKIPTTL|)              [pbx_config]

goes away?

It looks like after the upgrade, dial patterns with / are not working anymore. See below results with various dial patterns:

Result show dialplan 1 outbount route with dial pattern: 00.

[ Included context 'outrt-001-rlamse_int_1' created by 'pbx_config' ]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]

[ Included context 'bad-number' created by 'pbx_config' ]
  '_X.' =>          1. ResetCDR()                                 [pbx_config]
                    2. NoCDR()                                    [pbx_config]
                    3. Wait(1)                                    [pbx_config]
                    4. Playback(silence/1&cannot-complete-as-dialed&check-number-dial-again|noanswer) [pbx_config]
                    5. Wait(1)                                    [pbx_config]
                    6. Congestion(20)                             [pbx_config]
                    7. Hangup()                                   [pbx_config]

-= 2 extensions (12 priorities) in 2 contexts. =-

Result show dialplan 1 outbound route (rlamse_int_1) with dial pattern: 00./1003

[ Included context 'outrt-001-rlamse_int_1' created by 'pbx_config' ]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]

[ Included context 'bad-number' created by 'pbx_config' ]
  '_X.' =>          1. ResetCDR()                                 [pbx_config]
                    2. NoCDR()                                    [pbx_config]
                    3. Wait(1)                                    [pbx_config]
                    4. Playback(silence/1&cannot-complete-as-dialed&check-number-dial-again|noanswer) [pbx_config]
                    5. Wait(1)                                    [pbx_config]
                    6. Congestion(20)                             [pbx_config]
                    7. Hangup()                                   [pbx_config]

-= 3 extensions (13 priorities) in 2 contexts. =-

Result show dialplan 1 outbound route (rlamse_int_1) with dial pattern: 00./1003, 00./1013, etc (7 in total)

[ Included context 'outrt-001-rlamse_int_1' created by 'pbx_config' ]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Set(_NODEST=)                              [pbx_config]
                    3. Macro(record-enable|${AMPUSER}|OUT|)       [pbx_config]
                    4. Macro(dialout-trunk|2|${EXTEN}||)          [pbx_config]
                    5. Macro(outisbusy|)                          [pbx_config]
  '_00.' =>         1. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    2. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    3. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    4. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    5. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    6. Macro(user-callerid|SKIPTTL|)              [pbx_config]
                    7. Macro(user-callerid|SKIPTTL|)              [pbx_config]

[ Included context 'bad-number' created by 'pbx_config' ]
  '_X.' =>          1. ResetCDR()                                 [pbx_config]
                    2. NoCDR()                                    [pbx_config]
                    3. Wait(1)                                    [pbx_config]
                    4. Playback(silence/1&cannot-complete-as-dialed&check-number-dial-again|noanswer) [pbx_config]
                    5. Wait(1)                                    [pbx_config]
                    6. Congestion(20)                             [pbx_config]
                    7. Hangup()                                   [pbx_config]

-= 9 extensions (49 priorities) in 2 contexts. =-

Is this a bug in 2.7.0.5 (Core)?

it actually looks like most of them are right except one but unfortunately “dialplan show” does not do well when showing CID enabled dialplan.

Can you copy the route “outrt-001-rlamse_int_1” from extensions_additional.conf to see what is generated and see which one is an issue?

It still feels like there is some corruption in the database that is not being removed with the deletion of the routes.

got on a 2.7 system, confirmed it is a bug so don’t bother digging any further

After removing all dial patterns except: 00./1003

[outrt-001-rlamse_int_1]
include => outrt-001-rlamse_int_1-custom
exten => _00.,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1003,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1003,n,Set(_NODEST=)
exten => _00./1003,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1003,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1003,n,Macro(outisbusy,)

; end of [outrt-001-rlamse_int_1]

Originals outbound route with its dial patterns:

[outrt-001-rlamse_int_1]
include => outrt-001-rlamse_int_1-custom
exten => _00.,1,Macro(user-callerid,SKIPTTL,)
exten => _00.,n,Macro(user-callerid,SKIPTTL,)
exten => _00.,n,Macro(user-callerid,SKIPTTL,)
exten => _00.,n,Macro(user-callerid,SKIPTTL,)
exten => _00.,n,Macro(user-callerid,SKIPTTL,)
exten => _00.,n,Macro(user-callerid,SKIPTTL,)
exten => _00.,n,Macro(user-callerid,SKIPTTL,)
exten => _00./1003,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1003,n,Set(_NODEST=)
exten => _00./1003,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1003,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1003,n,Macro(outisbusy,)
exten => _00./1013,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1013,n,Set(_NODEST=)
exten => _00./1013,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1013,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1013,n,Macro(outisbusy,)
exten => _00./1014,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1014,n,Set(_NODEST=)
exten => _00./1014,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1014,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1014,n,Macro(outisbusy,)
exten => _00./1017,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1017,n,Set(_NODEST=)
exten => _00./1017,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1017,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1017,n,Macro(outisbusy,)
exten => _00./1060,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1060,n,Set(_NODEST=)
exten => _00./1060,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1060,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1060,n,Macro(outisbusy,)
exten => _00./1061,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1061,n,Set(_NODEST=)
exten => _00./1061,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1061,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1061,n,Macro(outisbusy,)
exten => _00./1065,1,Macro(user-callerid,SKIPTTL,)
exten => _00./1065,n,Set(_NODEST=)
exten => _00./1065,n,Macro(record-enable,${AMPUSER},OUT,)
exten => _00./1065,n,Macro(dialout-trunk,2,${EXTEN},,)
exten => _00./1065,n,Macro(outisbusy,)

; end of [outrt-001-rlamse_int_1]

#4202 reported, fixed and published

Thanks for the support and quick fix! All routes are working now.

I think I had the same problem. A couple of weeks ago I set up some routes for pattern matching in routes with the / option. It seemed that whenever I placed more than four dial patterns, I got the behavior described above, so I simply broke it down in to multiple routes each with no more than four matches. Was planning to look at it later, but looks like Philippe found the problem and resolved it. I installed the fix and put all of my dial patterns in a single route and all seems to work.

Thanks again Philippe!

Bill/W5WAF