From 357af800a3019999c1e03917ff18099ee50ebaa1 Mon Sep 17 00:00:00 2001
From: Arjen Baart <arjen@andromeda.nl>
Date: Sat, 31 Oct 2020 11:15:40 +0100
Subject: [PATCH] gcm_daemon: Use lock file to prevent parallel execution

---
 src/gcm_daemon/gcm_daemon.php     | 106 +++++++++++++++++++++++++++++++++++---
 src/gcm_input/gcm_input.cpp       |   3 ++
 src/gnucomo.conf                  |   1 +
 test/gnucomo_test.conf            |   4 ++
 test/read_bad_messages            |  15 ++++--
 test/read_bad_messages.log.expect |   6 ---
 test/read_without_hostname        |   7 ++-
 7 files changed, 120 insertions(+), 22 deletions(-)
 delete mode 100644 test/read_bad_messages.log.expect

diff --git a/src/gcm_daemon/gcm_daemon.php b/src/gcm_daemon/gcm_daemon.php
index 38e0d3a..3e46356 100755
--- a/src/gcm_daemon/gcm_daemon.php
+++ b/src/gcm_daemon/gcm_daemon.php
@@ -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
@@ -97,7 +97,7 @@
 ini_set('include_path', '.:./classes:../phpclasses');
 ini_set('html_errors', 'false');
 
-define("BATCHSIZE", 50000);
+define("BATCHSIZE", 20000);
 
 require_once "gnucomo_config.php";
 require_once "db.class.php";
@@ -145,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");
 
@@ -243,6 +259,9 @@ do
 
 //Tell the log that we're ending our efforts in a nice way
 
+flock($lockfile, LOCK_UN);    // release the lock
+fclose($lockfile);
+
 syslog (LOG_INFO, "gcm_daemon ended nicely");
 
 function process_log ()
@@ -260,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.
@@ -337,6 +358,8 @@ function process_log ()
      }
   }
 
+   $end_time = time();
+   //echo "Processing logs took " . ($end_time - $start_time) . " seconds.\n";
 }
 
 /*
@@ -423,10 +446,43 @@ function GatherStatistics($objectid)
    UpdateStatistic($objectid, 'logs', $cnt->count);
 }
 
+class profiler
+{
+   var $time_spent;
+   var $nr_occurs;
+
+   var $start_time;
+
+   function profiler()
+   {
+      $this->time_spent = 0;
+      $this->nr_occurs  = 0;
+
+      $this->start_time = 0;
+   }
+
+   function start()
+   {
+      $this->start_time = microtime(true);
+   }
+
+   function stop()
+   {
+      $stop_time = microtime(true);
+      $this->time_spent += $stop_time - $this->start_time;
+      $this->nr_occurs++;
+   }
+}
+
 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;
@@ -448,13 +504,11 @@ function match_log_patterns($logstart)
          //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)
             {
@@ -462,6 +516,7 @@ function match_log_patterns($logstart)
                break;
 
             case "notify":
+               $notify_perf->start();
                $notif = $srv_pat->argument;
                if (!isset($notifications[$logentry->objectid][$notif]))
                {
@@ -478,13 +533,18 @@ function match_log_patterns($logstart)
                   $insertion .= $logentry->logid . "')";
                   $dbms->query($insertion);
                }
+               $notify_perf->stop();
                break;
 
             case "abuse":
+               $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  ";
@@ -492,7 +552,15 @@ function match_log_patterns($logstart)
                }
                if ($nr_abuses >= 32)
                {
-                  $source_ip = gethostbyname($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]))
                   {
@@ -527,7 +595,9 @@ function match_log_patterns($logstart)
                      $dbms->query($insertion);
                   }
                }
+               $abuse_perf->stop();
                break;
+
             case "forgive":
                record_abuse($logentry->logid, $logentry->objectid, $srv_pat->argument, -4);
                break;
@@ -543,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";
+   }
+  */
 }
 
 /*
diff --git a/src/gcm_input/gcm_input.cpp b/src/gcm_input/gcm_input.cpp
index f9e30d9..112290f 100644
--- a/src/gcm_input/gcm_input.cpp
+++ b/src/gcm_input/gcm_input.cpp
@@ -263,6 +263,8 @@ int main(int argc, char *argv[])
    }
    verbose = verbose || level > 0;
 
+   *Log << Now() << " gcm_input starting.\n";
+
    if (verbose)
    {
       *Log << "Hostname = " << hostname;
@@ -330,6 +332,7 @@ int main(int argc, char *argv[])
 
             gcm_input_result = 1;
          }
+         *Log << Now() << " gcm_input finished successfully.\n";
       }
       catch (std::exception &e)
       {
diff --git a/src/gnucomo.conf b/src/gnucomo.conf
index 21cb7d1..cbc9c5c 100644
--- a/src/gnucomo.conf
+++ b/src/gnucomo.conf
@@ -24,6 +24,7 @@
    <gcm_daemon>
       <user>arjen</user>
       <password>test</password>
+      <lockfile>/var/lock/gnucomo</lockfile>
    </gcm_daemon>
 </gnucomo>
 
diff --git a/test/gnucomo_test.conf b/test/gnucomo_test.conf
index dc1fb75..6aab3c4 100644
--- a/test/gnucomo_test.conf
+++ b/test/gnucomo_test.conf
@@ -15,9 +15,13 @@
       <destination>./gcm_input.log</destination>
       <level>0</level>
    </logging>
+   <spool>
+      <directory>.</directory>
+   </spool>
    <gcm_daemon>
       <user>arjen</user>
       <password>test</password>
+      <lockfile>./gnucomo.lock</lockfile>
    </gcm_daemon>
 </gnucomo_test>
 
diff --git a/test/read_bad_messages b/test/read_bad_messages
index 0abb454..8b58112 100755
--- a/test/read_bad_messages
+++ b/test/read_bad_messages
@@ -9,18 +9,23 @@ rm -f gcm_input.log
 
 createdb gnucomo_test
 
+result=0
+
 if psql gnucomo_test -q <../src/database/create.sql >/dev/null
 then
    psql gnucomo_test -q -c "insert into object (objectname) values ('example1.gnucomo.test')"
    ../src/gcm_input/gcm_input -c gnucomo_test -h example1.gnucomo.test -d 'Jun 9 2002 20:30:45' <messages.bad
    psql gnucomo_test -q -t -c "select * from log" -o log.tbl
-   diff read_bad_messages.log.expect gcm_input.log
+   result=2
+   if grep "WARNING: Not a valid line: nearly empty line" gcm_input.log && grep "Can not insert log element" gcm_input.log
+   then
+      result=0
+   fi
    result=$?
    psql gnucomo_test -f ../src/database/destroy.sql -q
-   dropdb gnucomo_test
-   exit $result
 else
    echo Can not create test database
-   dropdb gnucomo_test
-   exit 1
+   result=1
 fi
+dropdb gnucomo_test
+exit $result
diff --git a/test/read_bad_messages.log.expect b/test/read_bad_messages.log.expect
deleted file mode 100644
index 29d4643..0000000
--- a/test/read_bad_messages.log.expect
+++ /dev/null
@@ -1,6 +0,0 @@
-gcm_input WARNING: Not a valid line: nearly empty line
-Can not insert log element .
-gcm_input WARNING: Not a valid line: Jun  5 04:02:16 example1 
-Can not insert log element .
-Can not insert log element .
-Can not insert log element .
diff --git a/test/read_without_hostname b/test/read_without_hostname
index de8cb28..8e25f96 100755
--- a/test/read_without_hostname
+++ b/test/read_without_hostname
@@ -22,11 +22,10 @@ then
    fi
    if [[ $result -eq 0 ]]
    then
-      GCM_LOG=`cat gcm_input.log`
-      echo $GCM_LOG
-      if [[ $GCM_LOG != "Can not determine the hostname where the message came from." ]]
+      result=2
+      if grep "Can not determine the hostname where the message came from." gcm_input.log
       then
-         result=2
+         result=0
       fi
    fi
    psql gnucomo_test -f ../src/database/destroy.sql -q
-- 
2.11.0