gcm_daemon: Use lock file to prevent parallel execution
[gnucomo.git] / src / gcm_daemon / gcm_daemon.php
index 7003d95..3e46356 100755 (executable)
@@ -1,4 +1,4 @@
-#!/usr/bin/php
+#!/usr/bin/php -e
 <?PHP
 /**********************************************************************************
 **  (c) Copyright 2002, Brenno J.S.A.A.F. de Winter, De Winter Information Solutions
    Gnucomo-0.0.8: September 4th 2003
 
  $Log: gcm_daemon.php,v $
- Revision 1.21  2007-01-11 13:47:41  arjen
+ Revision 1.26  2011-03-24 09:46:36  arjen
+ Resolve a hostname before adding to the abuses.
+
+ Revision 1.25  2007/12/12 09:06:21  arjen
+ Added a new script gcm_maintenance.php to cleanup the database
+ and check referential integrity. Purging old log entries is
+ removed from the gcm_daemon script.
+
+ Revision 1.24  2007/11/17 09:34:07  arjen
+ Cleaned up some leftovers
+
+ Revision 1.23  2007/11/03 10:31:12  arjen
+ Added the class definition for a filesystem parameter.
+ New issue type: 'property out of range'.
+
+ Revision 1.22  2007/10/23 11:23:52  arjen
+ Record the date when adding the number of abuses for an IP address
+ in the abuse list.
+
+ Revision 1.21  2007/01/11 13:47:41  arjen
  Log_adv and derived tables removed.
  Create notifications from log entries with pattern matching.
 
 
 */
 
-// $Id: gcm_daemon.php,v 1.21 2007-01-11 13:47:41 arjen Exp $
+// $Id: gcm_daemon.php,v 1.26 2011-03-24 09:46:36 arjen Exp $
 
 ini_set('include_path', '.:./classes:../phpclasses');
 ini_set('html_errors', 'false');
 
-define("BATCHSIZE", 2000);
-
-//Tell the log that we're up.
-define_syslog_variables();
+define("BATCHSIZE", 20000);
 
 require_once "gnucomo_config.php";
 require_once "db.class.php";
-require_once "gnucomo.process_log.php";
 
 // Set the standard variables //
 
-$purge_date     ="";            // Purge log entries until this date. Default: no purging
 $project_name   = "gnucomo";    // name of the entire project
 $app_name       = "gcm_daemon"; // name of the application running
 $developrelease = "FALSE";      // Indicates if special debug settings are needed
-$db_version     = 51;           // The db_version indicates what the level of
+$db_version     = 54;           // The db_version indicates what the level of
                                 // the database should be. If the database is
                                 // old an update will be generated.
 $gcmd_version   = 5;            // This value indicates the active version of
@@ -116,13 +130,8 @@ for ($argi = 1; $argi < $argc; $argi++)
       $project_name = $argv[$argi];
       break;
 
-   case "-p":
-      $argi++;
-      $purge_date = $argv[$argi];
-      break;
-
    default:
-      echo "Usage: gcm_daemon [-c configname] [-p purgedate]\n";
+      echo "Usage: gcm_daemon [-c configname]\n";
       exit();
       break;
    }
@@ -136,6 +145,22 @@ if (!$class_settings->read($project_name))
    exit();
 }
 
+$lockfilename = "/var/lock/gcm_daemon";   // The default lock file
+
+$config_lockfilename = $class_settings->find_parameter("gcm_daemon", "lockfile");
+if ($config_lockfilename != "")
+{
+   $lockfilename = $config_lockfilename;
+}
+
+$lockfile = fopen($lockfilename, "w");
+
+if (!flock($lockfile, LOCK_EX | LOCK_NB))
+{
+    echo "Unable to obtain lock for $lockfilename.\n";
+    exit(-1);
+}
+
 openlog("gnucomo", LOG_PID, LOG_DAEMON);
 syslog(LOG_INFO, "gcm_daemon started");
 
@@ -186,9 +211,8 @@ else
   die ("Couldn't initialize database version.\n");
 }
 
-// If there is a new gcm_daemon_version the logrecords that couldn't be
-// understood can be reprocessed. For this reason processed is now changed
-// to false again for not recognized records.
+// The gcm_daemon version is maintained in the database to enable
+// automatic update actions.
 
 $local_sql = "SELECT setting_value FROM db_value
               WHERE setting = 'gcm_daemon_version'";
@@ -198,11 +222,6 @@ if ($dbms->fetch_row() == "TRUE")
 {
    if ($dbms->db_result_row[0] < $gcmd_version)
    {
-      //Reactive log-records that weren't understood earlier.
-
-      $local_sql = "UPDATE log SET processed = false
-                    WHERE logid NOT IN (SELECT DISTINCT logid FROM log_adv)";
-      $dbms->query($local_sql);
 
       //Update de gcm_daemon version in the database
       $local_sql = "UPDATE db_value SET setting_value = '".$gcmd_version;
@@ -219,15 +238,9 @@ if ($dbms->fetch_row() == "TRUE")
 do
 {
 
-   if ($purge_date != "")
-   {
-      purge_old_logs($purge_date);
-   }
-
-   echo "Processing logs...\n";
+   //echo "Processing logs...\n";
    process_log ();
    service_check();
-   find_notifications();
    //mail_notifications();
 
    //  Gather the statistics for each object
@@ -236,7 +249,7 @@ do
    for ($obj = 0; $obj < $dbms->num_rows($obj_result); $obj++)
    {
       $object = $dbms->fetch_object($obj_result, $obj);
-      echo "Gathering statistics for object " . $object->objectid . "\n";
+      // echo "Gathering statistics for object " . $object->objectid . "\n";
       GatherStatistics($object->objectid);
    }
 
@@ -246,54 +259,10 @@ do
 
 //Tell the log that we're ending our efforts in a nice way
 
-syslog (LOG_INFO, "gcm_daemon ended nicely");
-
-function purge_old_logs($purge_date)
-{
-   global $dbms;
-
-   /*
-    *   Make a temporary table with the logids of the old log entries
-    *   We don't want to repeat a selection on the large log table itself.
-    */
-
-   echo "Purging log entries before $purge_date\n";
-
-   $dbms->query("CREATE TABLE gcm_deamon_old_log AS SELECT logid FROM log WHERE logid < $purge_date");
-   $dbms->query("SELECT logid FROM gcm_deamon_old_log");
-   echo $dbms->num_rows() . " log entries found.\n";
-   $r = $dbms->query("select notificationid from log_notification where logid in
-                         (select logid from gcm_deamon_old_log) group by notificationid");
-   echo "Notifications that may be affected:\n";
-   $notifications = array();
-   for ($i=0; $i < $dbms->num_rows(); $i++)
-   {
-      $notif = $dbms->fetch_object($r, $i);
-      $notifications[] = $notif->notificationid;
-      echo $notif->notificationid . "\n";
-   }
-   $dbms->query("delete from log_notification where logid in
-                         (select logid from gcm_deamon_old_log)");
-
-   //  Clean up any notifications that have no more logs left
-   foreach ($notifications as $notif)
-   {
-      $c = $dbms->fetch_object($dbms->query("select count(*) from log_notification where notificationid=$notif"), 0);
-      echo "Notification $notif has " . $c->count . " log entries left.\n";
-      if ($c->count == 0)
-      {
-         echo "Cleaning up notification $notif.\n";
-         $dbms->query("delete from action_user where notificationid=$notif");
-         $dbms->query("delete from notification where notificationid=$notif");
-      }
-   }
-
-   $dbms->query("delete from log where logid in
-                         (select logid from gcm_deamon_old_log)");
-
-   $dbms->query("drop table gcm_deamon_old_log");
-}
+flock($lockfile, LOCK_UN);    // release the lock
+fclose($lockfile);
 
+syslog (LOG_INFO, "gcm_daemon ended nicely");
 
 function process_log ()
 {
@@ -310,6 +279,8 @@ function process_log ()
   global $dbms_working;
   global $class_settings;
 
+  $start_time = time();
+
   $last_log = 0;
 
   // Find records in log that still have to be processed.
@@ -322,7 +293,7 @@ function process_log ()
      $last_log = $dbms->db_result_row[0];
   }
 
-  echo "Last processed logid = $last_log \n";
+  //echo "Last processed logid = $last_log \n";
 
   //Query the log-table
   $log_limit = $last_log + BATCHSIZE;
@@ -367,66 +338,6 @@ function process_log ()
        $local_object_os         = "";
        $local_object_os_version = "";
 
-/*
-       while ($local_counter < $dbms->num_rows())
-       {
-
-         $local_return_row = $dbms->fetch_row();
-         if ($local_return_row == 'TRUE')
-         {
-            // Work on active rows
-            $local_log_id = $dbms->db_result_row[0];
-
-            $local_sql_findobject = "SELECT os, os_version FROM object
-                                WHERE objectid = '".$dbms->db_result_row[1]."'";
-            $local_findobject_db->query($local_sql_findobject);
-            $local_findobject_result = $local_findobject_db->fetch_row();
-            if ($local_findobject_result == 'TRUE')
-            {
-
-                // Now work on the OS again
-                $local_object_os = $local_findobject_db->db_result_row[0];
-                if  ($local_object_os == "")
-                {
-                    $local_object_os = "Linux";
-                    $local_object_os_version = "Unknown assuming Linux";
-                }
-                else
-                {
-                  $local_object_os_version = $local_findobject_db->db_result_row[1];
-                }
-             }
-
-            switch (strtolower($local_object_os))
-            {
-            case "linux":
-                $local_process_return = linux_log ();
-                break;
-            default:
-                syslog (LOG_INFO, "Couldn't find suitable OS for processing the logline");
-                break;
-            }
-
-            if ($local_process_return != 'TRUE')
-            {
-              $local_process_return = 'FALSE';
-            }
-
-         }
-         else
-         {
-
-           break;
-
-         }
-         $local_counter++;
-       }
-*/
-
-       //  Check for spam and other abuses.
-
-       // abuse_check($last_log);
-
        match_log_patterns($last_log);
 
        // Register that the logrecords have been processed.
@@ -434,7 +345,7 @@ function process_log ()
        $local_sql = "UPDATE db_value SET setting_value = '"
                    . $local_upper_row ."' where setting = 'log_processing'";
        $dbms->query($local_sql);
-
+   
 
        // Update the statistics for the object-table
 
@@ -447,6 +358,8 @@ function process_log ()
      }
   }
 
+   $end_time = time();
+   //echo "Processing logs took " . ($end_time - $start_time) . " seconds.\n";
 }
 
 /*
@@ -533,88 +446,43 @@ function GatherStatistics($objectid)
    UpdateStatistic($objectid, 'logs', $cnt->count);
 }
 
-//  Check for spam and other abuses in the log_adv tables.
-
-function abuse_check($logstart)
+class profiler
 {
-return;   //  This function is obsolete
-   global  $dbms;
+   var $time_spent;
+   var $nr_occurs;
 
-  // notification: 'abuses exceeded'.
+   var $start_time;
 
-   $noqueue_res = $dbms->query("select logid, source_ip from log_adv_daemon_email
-                                where event='NOQUEUE' and logid > " . $logstart);
-   echo "NOQUEUE abuses:\n\n";
-   for ($row = 0; $row < $dbms->num_rows($noqueue_res); $row++)
+   function profiler()
    {
-      $noqueue = $dbms->fetch_object($noqueue_res, $row);
-      if ($noqueue->source_ip != '')
-      {
-         $obj = $dbms->fetch_object(
-                       $dbms->query("SELECT objectid FROM log WHERE logid = '" . $noqueue->logid . "'"),0);
-         record_abuse(0, $obj->objectid, $noqueue->source_ip, 2);
+      $this->time_spent = 0;
+      $this->nr_occurs  = 0;
 
-         // TODO: Create notification
-      }
-   } 
-   $dbms->Free($noqueue_res);
+      $this->start_time = 0;
+   }
 
-   $noqueue_res = $dbms->query("select logid, source_ip, relay from log_adv_daemon_email
-                                where event='SPAM' and logid > " . $logstart);
-   echo "SPAM abuses:\n\n";
-   for ($row = 0; $row < $dbms->num_rows($noqueue_res); $row++)
+   function start()
    {
-      $noqueue = $dbms->fetch_object($noqueue_res, $row);
-      $source = $noqueue->source_ip;
-      if ($source == '')
-      {
-         $source = $noqueue->relay;
-      }
-      if ($source != '')
-      {
-         $obj = $dbms->fetch_object(
-                       $dbms->query("SELECT objectid FROM log WHERE logid = '" . $noqueue->logid . "'"),0);
-         record_abuse(0, $obj->objectid, $source, 1);
-
-         // TODO: Create notification
-      }
-   } 
-   $dbms->Free($noqueue_res);
+      $this->start_time = microtime(true);
+   }
 
-   echo "HTTP abuses:\n\n";
-   $abuse_res = $dbms->query("select logid, objectid, rawdata from log
-                              where servicecode='httpd' and logid > " . $logstart);
-   for ($row = 0; $row < $dbms->num_rows($abuse_res); $row++)
+   function stop()
    {
-      $source = '';
-      $abuse = $dbms->fetch_object($abuse_res, $row);
-      if (ereg("\[error\] \[client ([0-9.]+)\] request failed: URI too long", $abuse->rawdata, $parts))
-      {
-         echo $abuse->rawdata . "\n";
-         echo "Abuse on object " . $abuse->objectid . " from IP address " . $parts[1] . "\n";
-         $source = $parts[1];
-      }
-      if (ereg("\[error\] \[client ([0-9.]+)\] File does not exist: .+/MSADC",
-               $abuse->rawdata, $parts))
-      {
-         echo $abuse->rawdata . "\n";
-         echo "Abuse on object " . $abuse->objectid . " from IP address " . $parts[1] . "\n";
-         $source = $parts[1];
-      }
-      if ($source != '')
-      {
-         record_abuse(0, $abuse->objectid, $source, 2);
-
-         // TODO: Create notification
-      }
+      $stop_time = microtime(true);
+      $this->time_spent += $stop_time - $this->start_time;
+      $this->nr_occurs++;
    }
-   $dbms->Free($abuse_res);
 }
 
 function match_log_patterns($logstart)
 {
    global  $dbms;
 
+   $start_time = microtime(true);
+   $notify_perf = new profiler();
+   $abuse_perf  = new profiler();
+   $record_perf  = new profiler();
+
    $notifications = array();
 
    $log_limit = $logstart + BATCHSIZE;
@@ -633,15 +501,14 @@ function match_log_patterns($logstart)
       for ($patnr = 0; !$match_found && $patnr < $dbms->num_rows($pattern_res); $patnr++)
       {
          $srv_pat = $dbms->fetch_object($pattern_res, $patnr);
+         //echo "  Checking with pattern " . $srv_pat->pattern . "\n";
          if (ereg($srv_pat->pattern, $logentry->rawdata, $matches))
          {
+            $match_found = true;
+
             //  Scan the argument for '$n' expressions and expand
 
             $srv_pat->argument = expand_arguments($srv_pat->argument, $matches);
-            //echo "   " . $srv_pat->pattern . " matches.\n";
-            //echo "   Matched string: " . $matches[0] . "\n";
-            //echo "   Action = " . $srv_pat->action . "(" . $srv_pat->argument . ")\n\n";
-            $match_found = true;
 
             switch ($srv_pat->action)
             {
@@ -649,6 +516,7 @@ function match_log_patterns($logstart)
                break;
 
             case "notify":
+               $notify_perf->start();
                $notif = $srv_pat->argument;
                if (!isset($notifications[$logentry->objectid][$notif]))
                {
@@ -665,23 +533,45 @@ function match_log_patterns($logstart)
                   $insertion .= $logentry->logid . "')";
                   $dbms->query($insertion);
                }
+               $notify_perf->stop();
                break;
 
             case "abuse":
-               if (record_abuse($logentry->logid, $logentry->objectid, $srv_pat->argument, 1) >= 6)
+               $abuse_perf->start();
+               //echo "Recording abuse for address ", $srv_pat->argument, "\n  Log entry:\n  ";
+               //echo $logentry->rawdata, "\n  Pattern:\n  ", $srv_pat->pattern, "\n\n";
+
+                $record_perf->start();
+               $nr_abuses = record_abuse($logentry->logid, $logentry->objectid, $srv_pat->argument, 1);
+                $record_perf->stop();
+
+               if ($nr_abuses < 0)
+               {
+                  echo "ERROR in recording abuse for address ", $srv_pat->argument, "\n  Log entry:\n  ";
+                  echo $logentry->rawdata, "\n  Pattern:\n  ", $srv_pat->pattern, "\n\n";
+               }
+               if ($nr_abuses >= 32)
                {
-                  $source_ip = $srv_pat->argument;
+                  if (preg_match("/[0-9.]+/", $srv_pat->argument))
+                  {
+                     $source_ip = $srv_pat->argument;
+                  }
+                  else
+                  {
+                     $source_ip = gethostbyname($srv_pat->argument);
+                  }
+
                   $notif = 'abuses exceeded';
                   if (!isset($notifications[$logentry->objectid][$notif][$source_ip]))
                   {
-                     echo "Creating notification $notif for object " . $logentry->objectid . ".\n";
+                     //echo "Creating notification $notif for object " . $logentry->objectid . ".\n";
                      $remark = "Abuses from IP address $source_ip exceeded the limit.";
                      $notifid = $dbms->new_notification($logentry->objectid, $notif, $remark);
                      $notifications[$logentry->objectid][$notif][$source_ip] = $notifid;
 
                      //  Add log entries from previously detected abuses
 
-                     echo " Add log entries from previously detected abuses";
+                     //echo " Add log entries from previously detected abuses\n";
                      $abuses = $dbms->query("SELECT logid FROM log_abuse WHERE objectid = '" .
                                     $logentry->objectid . "' AND source = '$source_ip'");
                      for ($abusenr = 0; $abusenr < $dbms->num_rows($abuses); $abusenr++)
@@ -698,14 +588,16 @@ function match_log_patterns($logstart)
                   }
                   if (isset($notifications[$logentry->objectid][$notif][$source_ip]))
                   {
-                     echo "Notification $notif for object " . $logentry->objectid . " already created.\n";
+                     //echo "Notification $notif for object " . $logentry->objectid . " already created.\n";
                      $insertion = "INSERT INTO log_notification (notificationid, logid) VALUES ('";
                      $insertion .= $notifications[$logentry->objectid][$notif][$source_ip] . "', '";
                      $insertion .= $logentry->logid . "')";
                      $dbms->query($insertion);
                   }
                }
+               $abuse_perf->stop();
                break;
+
             case "forgive":
                record_abuse($logentry->logid, $logentry->objectid, $srv_pat->argument, -4);
                break;
@@ -721,6 +613,28 @@ function match_log_patterns($logstart)
       }
 
    }
+   $stop_time = microtime(true);
+   $elapsed_time = $stop_time - $start_time;
+
+  /*   Performance report is disabled
+
+   echo $row . " log entries processed in " . $elapsed_time . " seconds.\n";
+   echo "Abuse: " . $abuse_perf->nr_occurs . " in " . $abuse_perf->time_spent . " seconds.\n";
+   if ($abuse_perf->time_spent > 0)
+   {
+      echo "Handled " . $abuse_perf->nr_occurs / $abuse_perf->time_spent . " abuses per second.\n";
+   }
+   echo "Record Abuse: " . $record_perf->nr_occurs . " in " . $record_perf->time_spent . " seconds.\n";
+   if ($record_perf->time_spent > 0)
+   {
+      echo "Handled " . $record_perf->nr_occurs / $record_perf->time_spent . " recording abuses per second.\n";
+   }
+   echo "Notify: " . $notify_perf->nr_occurs . " in " . $notify_perf->time_spent . " seconds.\n";
+   if ($notify_perf->time_spent > 0)
+   {
+      echo "Handled " . $notify_perf->nr_occurs / $notify_perf->time_spent . " notifies per second.\n";
+   }
+  */
 }
 
 /*
@@ -740,35 +654,43 @@ function record_abuse($logid, $objectid, $sourceip, $points)
 
    $abres = $dbms->query("SELECT * FROM object_abuse WHERE objectid='$objectid' AND source='$sourceip'");
 
-   if (pg_numrows($abres) == 0 && $points > 0)
+   if ($abres == false)
    {
-      //echo "$sourceip is new.\n";
-      $dbms->query("INSERT INTO object_abuse VALUES ('$objectid', '$sourceip', '$points')");
+      $abuse_points = -1;   // return an error
    }
-   else if (pg_numrows($abres) != 0)
+   else
    {
-      $abuse = $dbms->fetch_object($abres, 0);
-      if ($abuse->status == '' || $abuse->status == 'dropped')
+      if (pg_numrows($abres) == 0 && $points > 0)
       {
-         $abuse_points = $abuse->nr_abuses + $points;
-         if ($abuse_points < 0)
+         //echo "$sourceip is new.\n";
+         $dbms->query("INSERT INTO object_abuse VALUES ('$objectid', '$sourceip', '$points', '', NOW())");
+         $dbms->query("INSERT INTO log_abuse VALUES ('$logid', '$objectid', '$sourceip')");
+      }
+      else if (pg_numrows($abres) != 0)
+      {
+         $abuse = $dbms->fetch_object($abres, 0);
+         if ($abuse->status == '' || $abuse->status == 'dropped')
          {
-            $abuse_points = 0;
-         }
-         //echo $sourceip . " will get " . $abuse_points . " abuse points, ";
-         //echo "Status was " . $abuse->status . "\n";
-         $dbms->query("UPDATE object_abuse SET nr_abuses='$abuse_points'" .
-                     " WHERE objectid='$objectid' AND source='$sourceip'");
+            $abuse_points = $abuse->nr_abuses + $points;
+            if ($abuse_points < 0)
+            {
+               $abuse_points = 0;
+            }
+            //echo $sourceip . " will get " . $abuse_points . " abuse points, ";
+            //echo "Status was " . $abuse->status . "\n";
+            $dbms->query("UPDATE object_abuse SET nr_abuses='$abuse_points'" .
+                        ", last_change=NOW() WHERE objectid='$objectid' AND source='$sourceip'");
 
-         if ($points > 0)
-         {
-            $dbms->query("INSERT INTO log_abuse VALUES ('$logid', '$objectid', '$sourceip')");
-         }
-         if ($abuse_points >= 6)
-         {
-            //echo "      BLOCK IP adrress $sourceip on the firewall.\n";
-            $dbms->query("UPDATE object_abuse SET status='dropped'" .
-                     " WHERE objectid='$objectid' AND source='$sourceip'");
+            if ($points > 0)
+            {
+               $dbms->query("INSERT INTO log_abuse VALUES ('$logid', '$objectid', '$sourceip')");
+            }
+            if ($abuse_points >= 32)
+            {
+               //echo "      BLOCK IP adrress $sourceip on the firewall.\n";
+               $dbms->query("UPDATE object_abuse SET status='dropped'" .
+                        " WHERE objectid='$objectid' AND source='$sourceip'");
+            }
          }
       }
    }
@@ -805,7 +727,7 @@ function service_check()
                             VALUES ('log_servicecheck', '0')");
    }
 
-   echo "Running service check from log id $last_log.\n";
+   //echo "Running service check from log id $last_log.\n";
    // Query the log-table
 
    $log_limit = $last_log + BATCHSIZE;
@@ -875,30 +797,6 @@ function service_check()
    $dbms->query($qry);
 }
 
-function find_notifications ()
-{
-
-/*
- *  Do something with notification checks.
- *
- * INPUT  : NONE
- * OUTPUT : NONE
- */
-
-   global $dbms;
-
-   // Find checks that have to be executed.
-   $local_sql = "select * from notification_check where
-                    age(last_execution) > time_between_executions";
-   $dbms->query($local_sql);
-
-   for ($i=0; $i<$dbms->num_rows(); $i++)
-   {
-      // A check has been found that has to be executed
-      $dbms->fetch_row();
-   }
-}
-
 /*
  *  find open notifications and send an email to the object's users.
  */
@@ -960,5 +858,18 @@ function expand_arguments($command, $args)
    return $command;
 }
 
-?>
+// ereg function are removed from PHP since version 7.0
+// These wrappers use the alternative preg functions.
+
+function ereg($pattern, $string, &$matches)
+{
+   $pattern = "#" . $pattern . "#";
+   return preg_match($pattern, $string, $matches);
+}
 
+function ereg_replace($pattern, $replacement, $string)
+{
+   $pattern = "#" . $pattern . "#";
+   return preg_replace($pattern, $replacement, $string);
+}
+?>