[Solved] Sort of Urgent

Yesterday we upgraded our FreePBX 2.11.0.x distro using yum update to 2.11.0.10. Now our phone system is down. I see these warnings, which I do not recall encountering before:

-- Registered extension context 'macro-get-vmcontext'; registrar: pbx_config
-- Added extension 's' priority 1 to macro-get-vmcontext
-- Added extension 's' priority 2 to macro-get-vmcontext
-- Added extension 's' priority 200 to macro-get-vmcontext
-- Added extension 's' priority 300 to macro-get-vmcontext

[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 1 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 1 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 2 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 2 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 3 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 3 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 4 in ‘macro-outisbusy’, already in use
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:9619 add_priority: Unable to register extension ‘s’ priority 4 in ‘macro-outisbusy’, already in use

and most strangely:

[2013-09-11 08:48:09] WARNING[2835]: pbx.c:11998 ast_context_verify_includes: Context ‘from-internal-noxfer’ tries to include nonexistent context ‘from-internal-noxfer-custom’
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:11998 ast_context_verify_includes: Context ‘from-internal-noxfer’ tries to include nonexistent context ‘from-internal-noxfer-custom’
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:11998 ast_context_verify_includes: Context ‘from-pstn’ tries to include nonexistent context ‘from-pstn-custom’
[2013-09-11 08:48:09] WARNING[2835]: pbx.c:11998 ast_context_verify_includes: Context ‘from-pstn’ tries to include nonexistent context ‘from-pstn-custom’

and

[2013-09-11 09:04:26] WARNING[5122][C-00000010]: func_channel.c:482 func_channel_read: Unknown or unavailable item requested: ‘caller_dialeddigits’
[2013-09-11 09:04:26] WARNING[5122][C-00000010]: func_channel.c:482 func_channel_read: Unknown or unavailable item requested: ‘caller_dialeddigits’

But the error I see is this:
– Executing [[email protected]:5] Return(“SIP/41712-00000017”, “”) in new stack
[2013-09-11 09:04:26] ERROR[5122][C-00000010]: app_stack.c:366 return_exec: Return without Gosub: stack is unallocated
[2013-09-11 09:04:26] ERROR[5122][C-00000010]: app_stack.c:366 return_exec: Return without Gosub: stack is unallocated
== Spawn extension (from-internal-original-override, 41720, 5) exited non-zero on ‘SIP/41712-00000017’
– Executing [[email protected]:1] Hangup(“SIP/41712-00000017”, “”) in new stack
== Spawn extension (from-internal-original-override, h, 1) exited non-zero on ‘SIP/41712-00000017’

and

[2013-09-11 09:17:01] NOTICE[5781][C-00000013]: chan_sip.c:25288 handle_request_invite: Call from ‘41712’ (192.168.6.112:3072) to extension ‘41713’ rejected because extension not found in context ‘from-internal’.
[2013-09-11 09:17:01] NOTICE[5781][C-00000013]: chan_sip.c:25288 handle_request_invite: Call from ‘41712’ (192.168.6.112:3072) to extension ‘41713’ rejected because extension not found in context ‘from-internal’.

We had an extension override conf to allow for distinctive rings from outside calls and I have renamed that to get it out of the way. The errors persist even after running amportal a reload.

I have several options, one of which is to rollback the most recent update but I would rather know what is going on first. However, the phone system is malfunctioning and I need it up.

It was not the update but the reboot. There was a corrupted extensions_custom.conf file in /etc/asterisk.

So it was not the update or the reboot. It was reloading asterisk which the reboot did. Assume you added some custom dialplan as FreePBX does not write anything to custom.conf files.

Yes, there was an extraneous command in the extensions_custom.conf which was left in from some earlier (and forgotten) testing (mea culpa) and which went unnoticed as the system was not rebooted for some time. It was strictly a co-incidence that updating the system revealed the error. Any reboot would have had the same outcome. Which was why rolling back the update did not solve it either.

On the other hand, being told by FreePBX paid support to reload the entire system to bare metal to solve this situation seemed to me a little excessive. So I reapplied the suspect updates (having nothing to lose at that point) and tried to figure out where the problem was on my own. Which, after some poking around using asterisk -rvvvvvv. . ., succeeded in revealing the point where the dial plan was failing; after which it was fairly simple to remove the offending context reference. Live and learn.

Fortunately a complete system reinstall a la Microsoft proved unnecessary.

Regards,