0

To Generation D:

This is a new problem with build secast-1.0.4.0-x86_64-ub12 that didn't happen with the previous build, secast-1.0.1.0-x86_64-ub12.

When secast is run as a service (service secast start) or launched from the command line in daemon mode (/usr/local/secast/secast), it exits just a few seconds later without any apparent reason. When launching the previous version of secast, it stays running as expected until it is explicitly shutdown by user action.

When running the lastest build of secast in the foreground (/usr/local/secast/secast –f), this problem is not apparent.

Here are the contents of the /var/log/secast file (note the line "General, Received shutdown request via HUP") indicating the problem when running in daemon mode:

    2014-06-25T15:14:43, 00000100, S, General, SecAst starting as daemon under process ID 2059
    2014-06-25T15:14:43, 00001700, D, Database, Database manager thread started
    2014-06-25T15:14:43, 00000100, D, General, SecAst version 1.0.4.0; build date Monday; June 23; 2014 11:44:00 PM EDT; Ubuntu 12 LTS; Intel 64-bit
    2014-06-25T15:14:43, 00000108, D, General, SecAst state changing to starting
    2014-06-25T15:14:43, 00000810, D, Controller, firewall (iptables) not flushed on start
    2014-06-25T15:14:43, 00000504, I, Asterisk, Existing Asterisk log file (/var/log/asterisk/messages) open for monitoring
    2014-06-25T15:14:43, 00000600, D, EventQueue, Security event queue starting
    2014-06-25T15:14:43, 00000300, I, Controller, Telnet server listening on 0.0.0.0:3000
    2014-06-25T15:14:43, 00001600, I, Controller, Pipe server listening
    2014-06-25T15:14:43, 00001010, I, License, License file not present.  Defaulting to free edition
    2014-06-25T15:14:43, 00001300, D, GeoIp, Found GeoIP database version 2.0.1394137568 updated Thursday; March 6; 2014 3:26:08 PM EDT
    2014-06-25T15:14:43, 00001302, I, GeoIp, Opened GeoIP database
    2014-06-25T15:14:44, 00001705, D, Database, Opened database [secast] on host [localhost]
    2014-06-25T15:14:44, 00001705, I, Database, Database open for archiving
    2014-06-25T15:14:44, 00000800, D, Alert, Sent email: SecAst Incomplete Start
    2014-06-25T15:14:44, 00000106, I, General, SecAst state changing to standby
    2014-06-25T15:14:45, 00000800, D, Alert, Sent email: Entering standby state
    2014-06-25T15:14:45, 00000102, I, General, Received shutdown request via HUP signal
    2014-06-25T15:14:45, 00000601, D, EventQueue, Security event queue stopping
    2014-06-25T15:14:45, 00000604, D, EventQueue, Flushed 0 event(s) from queue
    2014-06-25T15:14:45, 00001706, I, Database, Database closed
    2014-06-25T15:14:45, 00001701, D, Database, Database Manager stopped
    2014-06-25T15:14:45, 00000110, D, General, SecAst state changing to stopping
    2014-06-25T15:14:45, 00001211, D, Asterisk, Flushed 0 message(s) from received message queue
    2014-06-25T15:14:45, 00001210, D, Asterisk, Flushed 0 message(s) from sent message queue
    2014-06-25T15:14:45, 00001500, D, Controller, Flushed 0 user(s) from user watch list
    2014-06-25T15:14:45, 00001303, I, GeoIp, Closed GeoIP database
    2014-06-25T15:14:45, 00001307, D, GeoIp, Flushed 0 location(s) from geoIP cache
    2014-06-25T15:14:46, 00000800, D, Alert, Sent email: SecAst Stopping
    2014-06-25T15:14:46, 00001602, I, Controller, Pipe server stopping
    2014-06-25T15:14:46, 00000506, I, Asterisk, Asterisk log file closing
    2014-06-25T15:14:46, 00000201, I, Controller, Telnet server stopping
    2014-06-25T15:14:46, 00000808, D, Controller, firewall (iptables) not flushed on shutdown
    2014-06-25T15:14:46, 00001400, D, Controller, Flushed 0 IP('s) from IP watch list
    2014-06-25T15:14:46, 00000903, D, ThreatInfo, Flushed 0 IP('s) from internal blocked list
    2014-06-25T15:14:46, 00000101, S, General, SecAst terminating with exit code 0 (Normal termination) after running for 3 second(s)

Note: /usr/local/secast/secast did manage to stay open on one attempt during one session, but the issue came back upon rebooting the computer.

Is this something that requires a code fix, given that the previous build seemed to work as expected in this regard?

Elyod
  • 25
  • 4

1 Answers1

1

SecAst is stopping because it is receiving the HUP signal from Linux, note the line in your log:

2014-06-25T15:14:45, 00000102, I, General, Received shutdown request via HUP signal

Apps must shutdown when receiving the HUP signal. So the question is why is SecAst receiving a HUP signal.

Most likely, SecAst received a shutdown request from the secast init.d service script (it uses the HUP signal to tell the SecAst executable to shutdown properly). Any chance you / someone / cron / etc. issued a 'service secast stop' ? Check your syslog - any entries from SecAst's init script?

TSG
  • 1,674
  • 7
  • 32
  • 51
  • I am the only one with access to the server, and it is only running Asterisk and secast, using the unmodified sample scripts/secast.initd.ub12 file for /etc/init.d/secast. I have not set up any cron jobs or otherwise directly caused the HUP signal to be sent for secast during these tests. The daemon was exiting just 3 seconds after it launched, with no secast entry in /var/log/syslog. Note that the problem occurred when launched from the command line in demon mode (/usr/local/secast/secast), not just as a service through the init.d script (continued...) – Elyod Jun 26 '14 at 20:08
  • The good news is that with the new build, secast-1.0.6.0-x86_64-ub12, I have not experienced any of these premature exits so far. I had noticed that in the files for the new build, in addition to the secast executable, the scripts/secast.initd.ub12 had also changed, which I used to also update the /etc/init.d/secast script. (continued...) – Elyod Jun 26 '14 at 20:08
  • With the new build, when I reboot the computer, it seems that it now successfully makes a connection to the mysql database. With the previous build this failed, and I was concerned that the services started in the wrong order, where secast service uses the /etc/init.d/secast and the mysql service uses the /etc/init/mysql.conf configuration file (i.e., upstart, not 'init.d'). Hopefully, this is now resolved, too. I'll keep you posted... Thanks. – Elyod Jun 26 '14 at 20:10
  • The only change to the ubuntu initd script is adding a message to the syslog on start/stop request. That should help you diagnose the cause of the stop if the problem resurfaces. Look at the documents/changelog file for more details. – TSG Jun 26 '14 at 20:23
  • If you have a MySQL connection problem please start a new topic and provide log details. The service start order shouldn't matter since the MySQL connection is retried every few minutes. – TSG Jun 26 '14 at 20:24
  • OK, if I see that happening again, I'll report it as a new issue. Thanks. – Elyod Jun 26 '14 at 22:09