[Home]

Summary:ASTERISK-15443: [regression] pbx_config does not load when it should
Reporter:Mark Murawski (kobaz)Labels:
Date Opened:2010-01-15 16:20:14.000-0600Date Closed:2011-06-07 14:00:46
Priority:MajorRegression?Yes
Status:Closed/CompleteComponents:PBX/pbx_config
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) log
( 1) mod.log
( 2) std.log
Description:When using extconfig for extensions.conf, pbx_config does not load to get dialplan config.

I have an extensions.ael file in use as well as extconfig.conf for database extensions.conf (static-realtime)

extconfig.conf
---------------
[settings]
extensions.conf => odbc,pbx,asterisk.v_asterisk_ext_config
---------------

Asterisk is started... pbx_config.so is nowhere to be found in the startup log. 'dialplan reload' is not available.


I can then forcefully: module load pbx_config.so
And then extensions.conf is pulled via odbc, but clobbers my extensions.ael

'dialplan show' will still show the diaplan code from my extensions.ael, but it's not reachable.


****** ADDITIONAL INFORMATION ******

--- Start up asterisk.
--- Dial from a sip device:
[Jan 15 17:07:14] NOTICE[29859]: chan_sip.c:21052 handle_request_invite: Call from '201' to extension '261110' rejected because extension not found.
--- module load pbx_config.so
--- dial from a sip device

    -- Executing [261110@cos_internal+local+ld+intl:1] Goto("SIP/201-00000001", "_cos_internal+local+ld+intl,261110,1") in new stack
   -- Goto (_cos_internal+local+ld+intl,261110,1)
   -- Sent into invalid extension '261110' in context '_cos_internal+local+ld+intl' on SIP/201-00000001
   -- Executing [i@_cos_internal+local+ld+intl:1] Gosub("SIP/201-00000001", "invalidHandler,s,1(cos,internal+local+ld+intl,i)") in new stack
[Jan 15 17:07:55] ERROR[29880]: app_stack.c:406 gosub_exec: Attempt to reach a non-existent destination for gosub: (Context:invalidHandler, Extension:s, Priority:0)


*CLI> dialplan show invalidHandler
[ Context 'invalidHandler' created by 'pbx_ael' ]
 's' (CID match '') =>  1. Set(LOCAL(srcContext)=${ARG1})             [pbx_ael]
                   2. Set(LOCAL(exten)=${ARG2})                  [pbx_ael]
                   3. GotoIf($["${NoInvalidHandler}" = "1"]?4:6) [pbx_ael]
                   4. NoOp(InvalidHandler disabled for this channel) [pbx_ael]
                   5. Return()                                   [pbx_ael]
                   6. NoOp(Finish if-invalidHandler-80)          [pbx_ael]
                   7. Gosub(noSuchNumber,s,1)                    [pbx_ael]
                   8. Return()                                   [pbx_ael]

dialplan show, reports invalidHandler existing, but it's not reachable from the extensions.conf dialplan.

If this issue can't be reproduced by a dev easily, I have a box someone can play on, this is a pretty big blocker.
Comments:By: Leif Madsen (lmadsen) 2010-01-18 10:08:10.000-0600

This sounds like a module load order issue -- in the past people have use the preload directive in modules.conf to get around this. Could this possibly be a solution for you? Thought I'd throw that out there.
By: Mark Murawski (kobaz) 2010-01-18 13:38:21.000-0600

Putting pbx_config.so in modules.conf will force it to load... but it still clobbers extensions.ael in the dialplan merge.

This is also a regression, since this works as expected in 1.6.0/1.6.1/1.6.2
By: Mark Murawski (kobaz) 2010-01-18 13:39:41.000-0600

So really there's two issues:

pbx_config.so not loading
ael/extensions.conf merge not being done properly
By: Mark Murawski (kobaz) 2010-01-18 13:57:26.000-0600

modules.conf:
--------------------------------
[modules]
autoload=yes
noload => pbx_gtkconsole.so
noload => pbx_kdeconsole.so
noload => app_intercom.so
noload => chan_modem.so
noload => chan_modem_aopen.so
noload => chan_modem_bestdata.so
noload => chan_modem_i4l.so
noload => chan_alsa.so
noload => chan_phone.so
noload => res_jabber.so

noload => res_timing_timerfd.so

load => res_odbc.so
load => res_musiconhold.so
load => cdr_csv.so
--------------------------------


extensions.conf:
--------------------------------
[cos_internal+local+ld+intl]
exten => _!,1,Goto(services,${EXTEN},1)
--------------------------------

extensions.ael
--------------------------------
context services {
 201 => {
   Dial(SIP/201);
 }
}
--------------------------------


CLI> sip show peer 201
--------------------------------
 * Name       : 201
 Secret       : <Set>
 MD5Secret    : <Not set>
 Remote Secret: <Not set>
 Context      : cos_internal+local+ld+intl
 Subscr.Cont. : <Not set>
--------------------------------

CLI> dialplan show
--------------------------------
[ Context 'app_dial_gosub_virtual_context' created by 'app_dial' ]
 's' =>            1. NoOp()                                     [app_dial]

[ Context 'services' created by 'pbx_ael' ]
 '201' (CID match '') =>  1. Dial(SIP/201)                              [pbx_ael]

[ Context 'app_queue_gosub_virtual_context' created by 'app_queue' ]
 's' (CID match '') =>  1. NoOp()                                     [app_queue]

[ Context 'parkedcalls' created by 'features' ]
 '2620' (CID match '') =>  1. Park()                                     [features]

[ Context 'demo' created by 'pbx_lua' ]
 Alt. Switch =>    'Lua/'                                        [pbx_lua]

[ Context 'cos_internal+local+ld+intl' created by 'pbx_config' ]
 '_!' =>           1. Goto(services,${EXTEN},1)                  [pbx_config]
--------------------------------


========================
SIP/201 dials 201
*CLI>     -- Executing [201@cos_internal+local+ld+intl:1] Goto("SIP/201-00000000", "services,201,1") in new stack
   -- Goto (services,201,1)
[Jan 18 14:48:41] WARNING[3972]: pbx.c:4708 __ast_pbx_run: Channel 'SIP/201-00000000' sent into invalid extension '201' in context 'services', but no invalid handler


services does indeed exist in extensions.ael, and does have priority one.. and it even shows up in 'dialplan show'


CLI> ael reload
--------------------------------
*CLI> [Jan 18 14:52:20] NOTICE[4057]: pbx_ael.c:122 pbx_load_module: Starting AEL load process.
[Jan 18 14:52:20] NOTICE[4057]: pbx_ael.c:135 pbx_load_module: AEL load process: parsed config file name '/etc/asterisk/extensions.ael'.
[Jan 18 14:52:20] NOTICE[4057]: pbx_ael.c:138 pbx_load_module: AEL load process: checked config file name '/etc/asterisk/extensions.ael'.
   -- Registered extension context 'services' (0x87a9250) in local table 0x854f668; registrar: pbx_ael
   -- Added extension '201' priority 1 to services (0x87a9250)
[Jan 18 14:52:20] NOTICE[4057]: pbx_ael.c:141 pbx_load_module: AEL load process: compiled config file name '/etc/asterisk/extensions.ael'.
   -- Registered extension context 'app_dial_gosub_virtual_context' (0x8804468) in local table 0x854f668; registrar: app_dial
   -- merging incls/swits/igpats from old(app_dial_gosub_virtual_context) to new(app_dial_gosub_virtual_context) context, registrar = pbx_ael
   -- Added extension 's' priority 1 (CID match '') to app_dial_gosub_virtual_context (0x8804468)
   -- Registered extension context 'app_queue_gosub_virtual_context' (0x88054a0) in local table 0x854f668; registrar: app_queue
   -- merging incls/swits/igpats from old(app_queue_gosub_virtual_context) to new(app_queue_gosub_virtual_context) context, registrar = pbx_ael
   -- Added extension 's' priority 1 (CID match '') to app_queue_gosub_virtual_context (0x88054a0)
   -- Registered extension context 'parkedcalls' (0x880ad98) in local table 0x854f668; registrar: features
   -- merging incls/swits/igpats from old(parkedcalls) to new(parkedcalls) context, registrar = pbx_ael
   -- Added extension '2620' priority 1 (CID match '') to parkedcalls (0x880ad98)
   -- Registered extension context 'demo' (0x880e9e8) in local table 0x854f668; registrar: pbx_lua
   -- merging incls/swits/igpats from old(demo) to new(demo) context, registrar = pbx_ael
   -- Including switch 'Lua/' in context 'demo'
   -- Registered extension context 'cos_internal+local+ld+intl' (0x88121c8) in local table 0x854f668; registrar: pbx_config
   -- merging incls/swits/igpats from old(cos_internal+local+ld+intl) to new(cos_internal+local+ld+intl) context, registrar = pbx_ael
   -- Added extension '_!' priority 1 (CID match '') to cos_internal+local+ld+intl (0x88121c8)
   -- Time to scan old dialplan and merge leftovers back into the new: 0.000431 sec
   -- Time to restore hints and swap in new dialplan: 0.000001 sec
   -- Time to delete the old dialplan: 0.000080 sec
   -- Total time merge_contexts_delete: 0.000512 sec
[Jan 18 14:52:20] NOTICE[4057]: pbx_ael.c:146 pbx_load_module: AEL load process: merged config file name '/etc/asterisk/extensions.ael'.
[Jan 18 14:52:20] NOTICE[4057]: pbx_ael.c:149 pbx_load_module: AEL load process: verified config file name '/etc/asterisk/extensions.ael'.
--------------------------------

And now we retry that SIP/201 dialing 201

[Jan 18 14:52:22] NOTICE[4074]: chan_sip.c:21052 handle_request_invite: Call from '201' to extension '201' rejected because extension not found.

the context 'cos_internal+local+ld+intl' is now unreachable in the dialplan.
even though we have....

CLI> dialplan show
--------------------------------
[ Context 'cos_internal+local+ld+intl' created by 'pbx_config' ]
 '_!' (CID match '') =>  1. Goto(services,${EXTEN},1)                  [pbx_config]

[ Context 'demo' created by 'pbx_lua' ]
 Alt. Switch =>    'Lua/'                                        [pbx_lua]

[ Context 'parkedcalls' created by 'features' ]
 '2620' (CID match '') =>  1. Park()                                     [features]

[ Context 'app_queue_gosub_virtual_context' created by 'app_queue' ]
 's' (CID match '') =>  1. NoOp()                                     [app_queue]

[ Context 'app_dial_gosub_virtual_context' created by 'app_dial' ]
 's' (CID match '') =>  1. NoOp()                                     [app_dial]

[ Context 'services' created by 'pbx_ael' ]
 '201' =>          1. Dial(SIP/201)                              [pbx_ael]
--------------------------------


Now lets add our context to extensions.ael
--------------------------------
context cos_internal+local+ld+intl {
 201 => {
   goto services, 201, 1;
 }
}
--------------------------------

CLI> ael reload

And Now let's retry that SIP/201 dialing 201

   -- Executing [201@cos_internal+local+ld+intl:1] Goto("SIP/201-00000003", "services,201,1") in new stack
   -- Goto (services,201,1)
   -- Executing [201@services:1] Dial("SIP/201-00000003", "SIP/201") in new stack
   -- Called 201
   -- SIP/201-00000004 is ringing



So it's clear that the dialplan merge is not done correctly.  We have either extensions.conf, or extensions.ael
In 1.6.X, ael and extensions.conf are merged into one dialplan
By: Jason Parker (jparker) 2010-02-05 13:02:15.000-0600

I'm not able to reproduce this, even using the simple dialplan you provided, and the svn trunk revision you specified.

Both get loaded and merged, and the goto works just fine.  What am I doing wrong?

The original problem you mentioned would likely be solved by added a preload of res_odbc and res_config_odbc to modules.conf.
By: Mark Murawski (kobaz) 2010-02-09 09:28:00.000-0600

I pasted my configs, converted from static-realtime into config files, but I agree, this problem doesn't actually exist with using regular config files.  It's specifically to do with using extconfig odbc for pulling configs.

I'll build a new test case.
By: Mark Murawski (kobaz) 2010-02-09 09:49:38.000-0600

----------------
extensions data:
----------------

  Column   |  Type   | Modifiers
------------+---------+-----------
cat_metric | integer |
var_metric | integer |
commented  | integer |
filename   | text    |
category   | text    |
var_name   | text    |
var_val    | text    |


INSERT INTO asterisk_extensions
(cat_metric,var_metric,commented,filename,category,var_name,var_val)
VALUES
(0,1,0,'extensions.conf','cos_internal+local+ld+intl','exten','_.,1,Goto(services,${EXTEN},1')

---------------
extconfig.conf
---------------
[settings]
extensions.conf => odbc,pbx,asterisk_extensions

--------------
res_odbc.conf
--------------
[pbx]
enabled=>yes
dsn=>pbx
pre-connect=>yes
idlecheck=>3600

--------------
/etc/odbc.ini
--------------
[pbx]
Description      = PostgreSQL PBX DB
Driver           = /usr/lib/odbc/psqlodbca.so
Setup            = /usr/lib/odbc/libodbcpsqlS.so
Trace            = Yes
TraceFile        = /tmp/extodbc.log
Debugging        = Yes
DebugFile        = /tmp/odbcdebug.log
Database         = pbx
Servername       = localhost
UserName         = root
Password         = admin
Port             = 5432
Protocol         = 6.4
ReadOnly         = No
RowVersioning    = No
ShowSystemTables = No
ShowOidColumn    = No
FakeOidIndex     = No
ConnSettings     =


With these settings, the command 'dialplan reload' is not available, and the extensions table is not loaded into the dialplan.


If I do a
module reload pbx_config.so
*CLI> [Feb  9 10:47:58] NOTICE[1465]: loader.c:698 ast_module_reload: The module 'pbx_config.so' was not properly initialized.  Before reloading the module, you must run "module load pbx_config.so" and fix whatever is preventing the module from being initialized.

From the logs... pbx_config.so looks like it's never loaded.  If i do a module load pbx_config.so... it loads, merges the dialplan, and everything works nicely.

If i put a load => pbx_config.so, in modules.conf, it seems to fix this.

So it appears that pbx_config.so isn't being loaded if extconfig is set up to load extensions.conf via odbc.
By: Jason Parker (jparker) 2010-02-10 17:32:49.000-0600

See my previous comment about adding preload => lines for odbc modules.

Does adding those change anything?
By: Mark Murawski (kobaz) 2010-02-10 17:47:31.000-0600

Oh... sorry.... No that doesn't change anything.

The only thing that fixes the problem that I've found so far is adding load => pbx_config.so in modules.conf
By: Jason Parker (jparker) 2010-03-01 16:21:59.000-0600

Can you show a full Asterisk startup (verbose/debug enabled), both with and without the preload lines?

There should be no reason that the merge is failing only when using ODBC.
By: Mark Murawski (kobaz) 2010-03-11 10:56:49.000-0600

Uploaded two log files... one without any forced module loading (log.std)
and one with the following modules in modules.conf (log.mod)

load => pbx_config.so
load => res_odbc.so
By: Mark Murawski (kobaz) 2010-03-11 10:58:21.000-0600

You'll notice that the cos_ contexts (which are only loaded from odbc)... will only load with the modules being forcefully loaded early.
By: Jason Parker (jparker) 2010-03-11 11:09:14.000-0600

Module load order issue.  Setting modules.conf correctly avoids this issue.