FreePBX 13 fails to start Asterisk 13

Hi all!

I’m testing FreePBX 13 with Asterisk 13 in a LXC container. I used to install this [1] guide. The only difference is that in my case I did not install the dependencies for Google Voice, I installed the Pjproject bundle from Asterisk 13.10 (whose code was obtained from the Git repository) and I install Jansson from Debian packages.

Although Asterisk gets up and running using service asterisk start, fwconsole gives the following error:

[email protected]:~# fwconsole start
Running FreePBX startup...
Taking too long? Customize the chown command, See http://wiki.freepbx.org/display/FOP/FreePBX+Chown+Conf
Setting Permissions...
        Collecting Files...Done
 44558/44558 [============================] 100%
Finished setting permissions
Starting Asterisk...
[--------------->------------] 12 secs

                                                
  [Exception]                                   
  Unable to connect to Asterisk. Did it start?


start [--pre] [--post] [--skipchown] [args1] ... [argsN]

Examining /var/log/asterisk/full, it does not show any record when run fwconsole.

Any recommendations to fix this issue?

Thanks in advance.

Kind regards,
Daniel

[1] http://wiki.freepbx.org/display/FOP/Installing+FreePBX+13+on+Debian+8.1

Any recommendations to fix this issue?

I would appreciate if someone could give some advice to solve this problem. If more information is needed, please let me know.

Thanks in advance.

Kind regards,
Daniel

It’s a little hard to diagnose from the fwconsiole, , essentially I belive it calls asterisk but safe asterisk watches /etc/init.d/asterisk with options (basically the pid of asterisk) and will restart on failure.

so , make sure safe_asterisk is NOT in ps -aux

(killall -9 safe_asterisk)

then begin with

asterisk -vvvc

which will attempt to start asterisk in the current console with a verbosity of three and in the foreground, if it fails you get your first clue. . . …

you probably need also to explore /etc/default/asterisk in Debian for how asterisk will be called by default and absolutely “man asterisk” to see tho options you have for starting asterisk.

Hi, dicko.

First, I thank you for your interest.

There is no safe_asterisk processes running:

[email protected]:~# ps aux | grep safe_asterisk | grep -v grep [email protected]:~#

This seems to start Asterisk CLI without problem:

`[email protected]:~# asterisk -vvvc
Asterisk 13.10.0, Copyright © 1999 - 2014, Digium, Inc. and others.
Created by Mark Spencer [email protected]
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core show warranty’ for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type ‘core show license’ for details.

[ Initializing Custom Configuration Options ]
== Registered ‘audio’ codec ‘g723’ at sample rate ‘8000’ with id ‘1’
== Created cached format with name ‘g723’
== Registered ‘audio’ codec ‘ulaw’ at sample rate ‘8000’ with id ‘2’
== Created cached format with name ‘ulaw’
== Registered ‘audio’ codec ‘alaw’ at sample rate ‘8000’ with id ‘3’
== Created cached format with name ‘alaw’
== Registered ‘audio’ codec ‘gsm’ at sample rate ‘8000’ with id ‘4’
== Created cached format with name ‘gsm’
(…)
== Registered custom function ‘QUEUE_VARIABLES’
== Registered custom function ‘QUEUE_EXISTS’
== Registered custom function ‘QUEUE_MEMBER’
== Registered custom function ‘QUEUE_MEMBER_COUNT’
== Registered custom function ‘QUEUE_MEMBER_LIST’
== Registered custom function ‘QUEUE_WAITING_COUNT’
== Registered custom function ‘QUEUE_MEMBER_PENALTY’
== app_queue.so => (True Call Queueing)
Loading res_manager_devicestate.so.
== Manager registered action DeviceStateList
== res_manager_devicestate.so => (Manager Device State Topic Forwarder)
Loading res_manager_presencestate.so.
== Manager registered action PresenceStateList
== res_manager_presencestate.so => (Manager Presence State Topic Forwarder)
Asterisk Ready.
*CLI> core show version
Asterisk 13.10.0 built by root @ pbxtest on a x86_64 running Linux on 2016-07-25 00:06:18 UTC
*CLI>`

The contents of /etc/default/asterisk is the following (I remember to have changed AST_USER and AST_GROUP after having compiled Asterisk):

[email protected]:~# grep ^[^#] /etc/default/asterisk AST_USER="asterisk" AST_GROUP="asterisk" COLOR=yes

I have also executed fwconsole in debug mode with the intention of getting some more information that would suggest the cause of the problem:

[email protected]:~# fwconsole -vvv start
(...)
Finished setting permissions
Starting Asterisk...
[--------------->------------] 11 secs

                                            
  [Exception]                                   
  Unable to connect to Asterisk. Did it start?  
                                            


Exception trace:
() at /var/www/html/admin/libraries/Console/Start.class.php:166
FreePBX\Console\Command\Start->startAsterisk() at /var/www/html/admin/libraries/Console/Start.class.php:118
FreePBX\Console\Command\Start->execute() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Command/Command.php:257
Symfony\Component\Console\Command\Command->run() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:874
Symfony\Component\Console\Application->doRunCommand() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:195
Symfony\Component\Console\Application->doRun() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:126
Symfony\Component\Console\Application->run() at /var/lib/asterisk/bin/fwconsole:139

/var/www/html/admin/libraries/Console/Start.class.php:166:

161                 while(!$this->asteriskIsReady()) {
162                         $astman->reconnect('on');
163                         usleep(100000);
164                         $i++;
165                         if($i >= 100) {
166                                 throw new \Exception("Unable to connect to Asterisk. Did it start?");
167                         }
168                         $progress->setProgress($i);
169                 }

/var/www/html/admin/libraries/Console/Start.class.php:118:

117                 if ($startasterisk) {
118                         if ($this->startAsterisk($output)) {
119                                 $output->writeln('');
120                                 $output->writeln(_("Asterisk Started"));
121                         } else {
122                                 $output->writeln('');
123                                 $output->writeln(_("Unable to start Asterisk!"));
124                         }
125                 }`

/var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Command/Command.php:257:

254         if ($this->code) {
255             $statusCode = call_user_func($this->code, $input, $output);
256         } else {
257             $statusCode = $this->execute($input, $output);
258         }

/var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:874:

873         if (null === $this->dispatcher) {
874             return $command->run($input, $output);
875         }`

/var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:195:

191         // the command name MUST be the first element of the input
192         $command = $this->find($name);
193 
194         $this->runningCommand = $command;
195         $exitCode = $this->doRunCommand($command, $input, $output);
196         $this->runningCommand = null;
197 
198         return $exitCode;`

/var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:126:

125         try {
126             $exitCode = $this->doRun($input, $output);
127         } catch (\Exception $e) {
128             if (!$this->catchExceptions) {
129                 throw $e;
130             }

/var/lib/asterisk/bin/fwconsole:139:

138         }
139         $fbc->run();
140 } catch(Exception $e) {
141         echo $e->getMessage()."\n";
142 }

It seems that /var/www/html/admin/libraries/Console/Start.class.php fails for connect to Asterisk Manager in the line 166 because FreePBX is unable to starts Asterisk. But I’m not sure why FreePBX is unable to do so.

Any idea?

Thanks in advance.

Kind regards,
Daniel

Yep, again it points to cxpanel and isymphony as being rogue, I suggest you delete those modules.

Hi, dicko.

Thanks for your reply.

Yep, again it points to cxpanel and isymphony as being rogue, I suggest you delete those modules.

I’m not sure, but it seems I do not have installed those modules. Please tell me if I would make a different verification.

 [email protected]:~# fwconsole ma list
 No repos specified, using: [standard] from last GUI settings

+------------------+-----------+---------+
| Module           | Version   | Status  |
+------------------+-----------+---------+
| builtin          |           | Enabled |
| callrecording    | 13.0.11   | Enabled |
| cdr              | 13.0.29.4 | Enabled |
| cel              | 13.0.23   | Enabled |
| core             | 13.0.99   | Enabled |
| customappsreg    | 13.0.5    | Enabled |
| dashboard        | 13.0.24   | Enabled |
| featurecodeadmin | 13.0.6    | Enabled |
| framework        | 13.0.163  | Enabled |
| infoservices     | 13.0.1    | Enabled |
| logfiles         | 13.0.10   | Enabled |
| music            | 13.0.21   | Enabled |
| sipsettings      | 13.0.23.6 | Enabled |
| ucp              | 13.0.37   | Enabled |
| userman          | 13.0.69   | Enabled |
| voicemail        | 13.0.51   | Enabled |
+------------------+-----------+---------+

Thanks for your time.

Kind regards,
Daniel

That doesn’t jive, enable all the commercial stuff, then delete what you don’t use

This has nothing to do with cxpanel. All information provided here by dicko is completely inaccurate.

Symfony is a library we use for php. It is not to be confused with iSymphony. Not only are they spelled different they have nothing in common.

If you removed symfony you’d completely break freepbx. It would be unusable.

There’s no point in looking at the stack trace. There is a bigger problem with the particular installation and it not being able to communicate with asterisk over AMI.

I would like to second that.

The problem is that asterisk is being started and run by the ‘root’ user, not the correct user (which should be the user that is running the web server). Make sure that asterisk is NOT running with asterisk -rx 'core stop now' and then run ‘fwconsole start’. That will start asterisk as the correct user.

Hi, Andrew/Rob. Thanks for your interest.

I think FreePBX is not able to communicate with asterisk over AMI because, in a previous step, FreePBX is not able to start Asterisk.

As you can see below, Asterisk is not running:

[email protected]:~# ps auxf | grep asterisk
root      1256  0.0  0.1  13968  2236 pts/0    S+   08:11   0:00                      \_ grep asterisk
asterisk 30035  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30036  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30037  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30038  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30039  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start

We can also see that Apache is running with the asterisk user, which was a necessary requirement.

I also made sure to set the user and group asterisk in /etc/default/asterisk, but this would only be useful if FreePBX uses the init script to start Asterisk.

[email protected]:~# grep ^[^#] /etc/default/asterisk 
AST_USER="asterisk"
AST_GROUP="asterisk"
COLOR=yes

Below we can see that when start Asterisk, it is effectively executed with the asterisk user.

[email protected]:~# service asterisk start
[email protected]:~# ps auxf | grep asterisk
root      1663  0.0  0.1  13968  2168 pts/0    S+   08:21   0:00                      \_ grep asterisk
asterisk 30035  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30036  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30037  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30038  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30039  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk  1580 27.5  3.1 1329552 64644 ?       Ssl  08:21   0:08 /usr/sbin/asterisk -U asterisk -G asterisk

But as I said, I’m not sure if FreePBX uses the init script of Asterisk.

Then I stop Asterisk and verify that the process is not running:

[email protected]:~# ps auxf | grep asterisk
root      1752  0.0  0.1  13968  2236 pts/0    S+   08:24   0:00                      \_ grep asterisk
asterisk 30035  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30036  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30037  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30038  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30039  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start

However fwconsole fails:

[email protected]:~# fwconsole -vvv start
Running FreePBX startup...
Taking too long? Customize the chown command, See http://wiki.freepbx.org/display/FOP/FreePBX+Chown+Conf
Setting Permissions...
        Collecting Files...Done
(...)
Finished setting permissions
Starting Asterisk...
[--------------->------------] 12 secs

                                                
  [Exception]                                   
  Unable to connect to Asterisk. Did it start?  
                                            


Exception trace:
 () at /var/www/html/admin/libraries/Console/Start.class.php:166
 FreePBX\Console\Command\Start->startAsterisk() at /var/www/html/admin/libraries/Console/Start.class.php:118
 FreePBX\Console\Command\Start->execute() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Command/Command.php:257
 Symfony\Component\Console\Command\Command->run() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:874
 Symfony\Component\Console\Application->doRunCommand() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:195
 Symfony\Component\Console\Application->doRun() at /var/www/html/admin/libraries/Composer/vendor/symfony/console/Symfony/Component/Console/Application.php:126
 Symfony\Component\Console\Application->run() at /var/lib/asterisk/bin/fwconsole:139


start [--pre] [--post] [--skipchown] [args1] ... [argsN]

I wonder if fwconsole is using a procedure outside the init script to start Asterisk. Maybe that’s what we have to be check.

Thanks for your time.

Kind regards,
Daniel

Is the line 149 in /var/www/html/admin/libraries/Console/Start.class.php the responsible for starting Asterisk?

147         private function startAsterisk($output){
148                 $output->writeln(_('Starting Asterisk...'));
149                 $astbin = '/usr/bin/env safe_asterisk -U '.\FreePBX::Config()->get('AMPASTERISKUSER').' -G '.\FreePBX::Config()->get('AMPASTERISKGROUP')    .' > /dev/null 2>&1 &';
150                 $process = new Process($astbin);

Assuming FreePBX::Config()->get(...) gets these values:

[email protected]:~# egrep "AMPASTERISKUSER|AMPASTERISKGROUP" /etc/amportal.conf
AMPASTERISKGROUP=asterisk
AMPASTERISKUSER=asterisk

In this case, I guess that Asterisk would be initiated by FreePBX as follows:

[email protected]:~# /usr/bin/env safe_asterisk -U asterisk -G asterisk

But when running this command, nothing happens:

[email protected]:~# ps auxf | grep asterisk
root      8758  0.0  0.1  13968  2164 pts/2    S+   11:44   0:00                                  \_ grep asterisk
asterisk 30035  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30036  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30037  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30038  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30039  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start

Is this analysis correct?

Kind regards,
Daniel

Why don’t you try running that command. If when you run it manually nothing happens then something is misconfigured on your system. That’s what you need to figure out.

Hi, Andrew.

I did it. The ps shown in the previous message was after running this command where it seems that after running the safe_asterisk command did not appear any Asterisk process running.

I’m testing this version of FreePBX in a LXC container. Do you think that in this case I would have to have some particular consideration to run FreePBX?

Thanks for your reply.

Kind regards,
Daniel

On looking the script /usr/sbin/safe_asterisk, I uncomment on the LOGFILE variable to see if when I run the script manually, I can find in /var/log/asterisk/safe_asterisk.log something which give a little more light on this problem. And this was what I found:

safe_asterisk[12727] Cannot find specified TTY (9)

So I checked again the script /usr/sbin/safe_asterisk and found this line:

TTY=9                          # TTY (if you want one) for Asterisk to run on

Then I’ve commented this line and try again manually by running the script with the syntax used by FreePBX. This time the log does not show any new entry. Then I check the output of ps:

[email protected]:~# /usr/bin/env safe_asterisk -U asterisk -G asterisk
[email protected]:~# ps auxf | grep asterisk
root     14094  0.0  0.0   7064   696 pts/1    S+   14:10   0:00                              |   \_ tail -F safe_asterisk.log
root     14203  0.0  0.1  13968  2112 pts/2    S+   14:11   0:00                                  \_ grep asterisk
asterisk 30035  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30036  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30037  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30038  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30039  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
root     14107  0.0  0.0   4336   128 pts/2    S    14:10   0:00 /bin/sh /usr/sbin/safe_asterisk -U asterisk -G asterisk
asterisk 14108 25.0  3.1 1329556 65184 pts/2   Sl   14:10   0:08  \_ /usr/sbin/asterisk -f -U asterisk -G  asterisk

All right! This time it seems that the script has run smoothly.

Then I stop all Asterisk processes:

[email protected]:~# kill -9 14277
[email protected]:~# kill -9 14278
[email protected]:~# ps auxf | grep asterisk
root     14094  0.0  0.0   7064   696 pts/1    S+   14:10   0:00                              |   \_ tail -F safe_asterisk.log
root     14527  0.0  0.1  13968  2052 pts/2    S+   14:19   0:00                                  \_ grep asterisk
asterisk 30035  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30036  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30037  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30038  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start
asterisk 30039  0.0  0.4 316284 10028 ?        S    06:25   0:00  \_ /usr/sbin/apache2 -k start

Curiously, after making this change, when trying to run fwconsole I got a Permission denied. The strange thing is that /var/lib/asterisk/bin/fwconsole did not have execution permission. This caught my attention because I do not remember having changed it. So I changed the permissions and tried again:

[email protected]:~# chmod u+x /var/lib/asterisk/bin/fwconsole
[email protected]:~# fwconsole -vvv start
(...)
Finished setting permissions
Starting Asterisk...
[============================] 5 secs
Asterisk Started

Great! This time seems to run smoothly. I guess the problem with the TTY would be linked to the configuration of the LXC container (or perhaps some limitation of LXC).

On the other hand, the systemd startup script [1] seems to work well:

[email protected]:/etc/systemd/system# systemctl start freepbx
[email protected]:/etc/systemd/system# systemctl status freepbx
● freepbx.service - FreePBX VoIP Server
   Loaded: loaded (/etc/systemd/system/freepbx.service; enabled)
   Active: active (exited) since lun 2016-08-01 14:46:15 ART; 6s ago
  Process: 15773 ExecStart=/usr/sbin/fwconsole start (code=exited, status=0/SUCCESS)
 Main PID: 15773 (code=exited, status=0/SUCCESS)

ago 01 14:46:11 pbxtest fwconsole[15773]: [-------->-------------------] 1 sec
ago 01 14:46:11 pbxtest fwconsole[15773]: [--------->------------------] 1 sec
ago 01 14:46:11 pbxtest fwconsole[15773]: [---------->-----------------] 1 sec
ago 01 14:46:12 pbxtest fwconsole[15773]: [----------->----------------] 1 sec
ago 01 14:46:12 pbxtest fwconsole[15773]: [------------>---------------] 2 secs
ago 01 14:46:12 pbxtest fwconsole[15773]: [------------->--------------] 2 secs
ago 01 14:46:15 pbxtest fwconsole[15773]: [-------------->-------------] 2 secs
ago 01 14:46:15 pbxtest fwconsole[15773]: [--------------->------------] 5 secs
ago 01 14:46:15 pbxtest fwconsole[15773]: Asterisk Started
ago 01 14:46:15 pbxtest systemd[1]: Started FreePBX VoIP Server.

[email protected]:/etc/systemd/system# systemctl stop freepbx
[email protected]:/etc/systemd/system# systemctl status freepbx
● freepbx.service - FreePBX VoIP Server
   Loaded: loaded (/etc/systemd/system/freepbx.service; enabled)
   Active: inactive (dead) since lun 2016-08-01 14:48:41 ART; 30s ago
  Process: 16005 ExecStop=/usr/sbin/fwconsole stop (code=exited, status=0/SUCCESS)
  Process: 15773 ExecStart=/usr/sbin/fwconsole start (code=exited, status=0/SUCCESS)
 Main PID: 15773 (code=exited, status=0/SUCCESS)

ago 01 14:48:38 pbxtest systemd[1]: Stopping FreePBX VoIP Server...
ago 01 14:48:39 pbxtest fwconsole[16005]: Running FreePBX shutdown...
ago 01 14:48:39 pbxtest fwconsole[16005]: Shutting down Asterisk Gracefully. Will forcefully kill after 30 seconds.
ago 01 14:48:39 pbxtest fwconsole[16005]: Press C to Cancel
ago 01 14:48:39 pbxtest fwconsole[16005]: Press N to shut down NOW
ago 01 14:48:39 pbxtest fwconsole[16005]: stty: standard input: Inappropriate ioctl for device
ago 01 14:48:39 pbxtest fwconsole[16005]: stty: standard input: Inappropriate ioctl for device
ago 01 14:48:41 pbxtest fwconsole[16005]: [>---------------------------] 1 sec
ago 01 14:48:41 pbxtest fwconsole[16005]: [------>---------------------] 1 sec
ago 01 14:48:41 pbxtest fwconsole[16005]: [---------------->-----------] 1 secstty: standard input: Inappropriate ioctl for device
ago 01 14:48:41 pbxtest systemd[1]: Stopped FreePBX VoIP Server.

Do you thing the message Inappropriate ioctl for device may be due to some configuration of the container or is independent of it?

Kind regards,
Daniel

[1] http://wiki.freepbx.org/display/HTGS/Example+systemd+startup+script+for+FreePBX