Flag excess drops (#561)

* Make stats file interval configurable

New argument --stats_interval=<msec> controls the interval at which
statistics are written to the stats file. The default is 5000 ms (5 sec)
which matches the prior hardcoded interval.

The stats interval is triggered via signals, so an interval below ~250ms
will probably interfere with falco's behavior.

* Add ability to emit general purpose messages

A new method falco_outputs::handle_msg allows emitting generic messages
that have a "rule", message, and output fields, but aren't exactly tied
to any event and aren't passed through an event formatter.

This allows falco to emit "events" based on internal checks like kernel
buffer overflow detection.

* Clean up newline handling for logging

Log messages from falco_logger::log may or may not have trailing
newlines. Handle both by always adding a newline to stderr logs and
always removing any newline from syslog logs.

* Add method to get sequence from subkey

New variant of get_sequence that allows fetching a list of items from a
key + subkey, for example:

key:
  subkey:
    - list
    - items
    - here

Both use a shared method get_sequence_from_node().

* Monitor syscall event drops + optional actions

Start actively monitoring the kernel buffer for syscall event drops,
which are visible in scap_stats.n_drops, and add the ability
to take actions when events are dropped. The -v (verbose) and
-s (stats filename) arguments also print out information on dropped
events, but they were only printed/logged without any actions.

In falco config you can specify one or more of the following actions to
take when falco notes system call drops:

 - ignore (do nothing)
 - log a critical message
 - emit an "internal" falco alert. It looks like any other alert with a
   time, "rule", message, and output fields but is not related to any
   rule in falco_rules.yaml/other rules files.
 - exit falco (the idea being that the restart would be monitored
   elsewhere).

A new module syscall_event_drop_mgr is called for every event and
collects scap stats every second. If in the prior second there were
drops, perform_actions() handles the actions.

To prevent potential flooding in high drop rate environments, actions
are goverened by a token bucket with a rate of 1 actions per 30 seconds,
with a max burst of 10 seconds. We might tune this later based on
experience in busy environments.

This might be considered a fix for
https://github.com/falcosecurity/falco/issues/545. It doesn't
specifically flag falco rules alerts when there are drops, but does
make it easier to notice when there are drops.

* Add unit test for syscall event drop detection

Add unit tests for syscall event drop detection. First, add an optional
config option that artifically increments the drop count every
second. (This is only used for testing).

Then add test cases for each of the following:
 - No dropped events: should not see any log messages or alerts.
 - ignore action: should note the drops but not log messages or alert.
 - log action: should only see log messages for the dropped events.
 - alert action: should only see alerts for the dropped events.
 - exit action: should see log message noting the dropped event and exit
   with rc=1

A new trace file ping_sendto.scap has 10 seconds worth of events to
allow the periodic tracking of drops to kick in.

falco.yaml

@@ -63,6 +63,26 @@ priority: debug
 # buffered. Defaults to false
 buffered_outputs: false
 
+# Falco uses a shared buffer between the kernel and userspace to pass
+# system call information. When falco detects that this buffer is
+# full and system calls have been dropped, it can take one or more of
+# the following actions:
+#   - "ignore": do nothing. If an empty list is provided, ignore is assumed.
+#   - "log": log a CRITICAL message noting that the buffer was full.
+#   - "alert": emit a falco alert noting that the buffer was full.
+#   - "exit": exit falco with a non-zero rc.
+#
+# The rate at which log/alert messages are emitted is governed by a
+# token bucket. The rate corresponds to one message every 30 seconds
+# with a burst of 10 messages.
+
+syscall_event_drops:
+  actions:
+    - log
+    - alert
+  rate: .03333
+  max_burst: 10
+
 # A throttling mechanism implemented as a token bucket limits the
 # rate of falco notifications. This throttling is controlled by the following configuration
 # options:

test/confs/drops_alert.yaml

@@ -0,0 +1,11 @@
+syscall_event_drops:
+  actions:
+    - alert
+  rate: .03333
+  max_burst: 10
+  simulate_drops: true
+
+stdout_output:
+  enabled: true
+
+log_stderr: true

test/confs/drops_exit.yaml

@@ -0,0 +1,11 @@
+syscall_event_drops:
+  actions:
+    - exit
+  rate: .03333
+  max_burst: 10
+  simulate_drops: true
+
+stdout_output:
+  enabled: true
+
+log_stderr: true

test/confs/drops_ignore.yaml

@@ -0,0 +1,11 @@
+syscall_event_drops:
+  actions:
+    - ignore
+  rate: .03333
+  max_burst: 10
+  simulate_drops: true
+
+stdout_output:
+  enabled: true
+
+log_stderr: true

test/confs/drops_log.yaml

@@ -0,0 +1,11 @@
+syscall_event_drops:
+  actions:
+    - log
+  rate: .03333
+  max_burst: 10
+  simulate_drops: true
+
+stdout_output:
+  enabled: true
+
+log_stderr: true

test/confs/drops_none.yaml

@@ -0,0 +1,11 @@
+syscall_event_drops:
+  actions:
+    - log
+  rate: .03333
+  max_burst: 10
+  simulate_drops: false
+
+stdout_output:
+  enabled: true
+
+log_stderr: true

test/falco_test.py

@@ -37,7 +37,31 @@ class FalcoTest(Test):
         self.falcodir = self.params.get('falcodir', '/', default=os.path.join(self.basedir, '../build'))
 
         self.stdout_contains = self.params.get('stdout_contains', '*', default='')
+
+        if not isinstance(self.stdout_contains, list):
+            self.stdout_contains = [self.stdout_contains]
+
         self.stderr_contains = self.params.get('stderr_contains', '*', default='')
+
+        if not isinstance(self.stderr_contains, list):
+            self.stderr_contains = [self.stderr_contains]
+
+        self.stdout_not_contains = self.params.get('stdout_not_contains', '*', default='')
+
+        if not isinstance(self.stdout_not_contains, list):
+            if self.stdout_not_contains == '':
+                self.stdout_not_contains = []
+            else:
+                self.stdout_not_contains = [self.stdout_not_contains]
+
+        self.stderr_not_contains = self.params.get('stderr_not_contains', '*', default='')
+
+        if not isinstance(self.stderr_not_contains, list):
+            if self.stderr_not_contains == '':
+                self.stderr_not_contains = []
+            else:
+                self.stderr_not_contains = [self.stderr_not_contains]
+
         self.exit_status = self.params.get('exit_status', '*', default=0)
         self.should_detect = self.params.get('detect', '*', default=False)
         self.trace_file = self.params.get('trace_file', '*', default='')
@@ -389,15 +413,25 @@ class FalcoTest(Test):
 
         res = self.falco_proc.run(timeout=180, sig=9)
 
-        if self.stderr_contains != '':
-            match = re.search(self.stderr_contains, res.stderr)
+        for pattern in self.stderr_contains:
+            match = re.search(pattern, res.stderr)
             if match is None:
-                self.fail("Stderr of falco process did not contain content matching {}".format(self.stderr_contains))
+                self.fail("Stderr of falco process did not contain content matching {}".format(pattern))
 
-        if self.stdout_contains != '':
-            match = re.search(self.stdout_contains, res.stdout)
+        for pattern in self.stdout_contains:
+            match = re.search(pattern, res.stdout)
             if match is None:
-                self.fail("Stdout of falco process '{}' did not contain content matching {}".format(res.stdout, self.stdout_contains))
+                self.fail("Stdout of falco process '{}' did not contain content matching {}".format(res.stdout, pattern))
+
+        for pattern in self.stderr_not_contains:
+            match = re.search(pattern, res.stderr)
+            if match is not None:
+                self.fail("Stderr of falco process contained content matching {} when it should have not".format(pattern))
+
+        for pattern in self.stdout_not_contains:
+            match = re.search(pattern, res.stdout)
+            if match is not None:
+                self.fail("Stdout of falco process '{}' did contain content matching {} when it should have not".format(res.stdout, pattern))
 
         if res.exit_status != self.exit_status:
             self.error("Falco command \"{}\" exited with unexpected return value {} (!= {})".format(

test/falco_tests.yaml

@@ -770,4 +770,73 @@ trace_files: !mux
     stderr_contains: Rules require engine version 9999999, but engine version is
     rules_file:
       - rules/engine_version_mismatch.yaml
-    trace_file: trace_files/cat_write.scap
+    trace_file: trace_files/cat_write.scap
+
+  monitor_syscall_drops_none:
+    exit_status: 0
+    rules_file:
+      - rules/single_rule.yaml
+    conf_file: confs/drops_none.yaml
+    trace_file: trace_files/ping_sendto.scap
+    stderr_not_contains:
+      - "event drop detected: 9 occurrences"
+      - "num times actions taken: 9"
+      - "Falco internal: syscall event drop"
+    stdout_not_contains:
+      - "Falco internal: syscall event drop"
+
+  monitor_syscall_drops_ignore:
+    exit_status: 0
+    rules_file:
+      - rules/single_rule.yaml
+    conf_file: confs/drops_ignore.yaml
+    trace_file: trace_files/ping_sendto.scap
+    stderr_contains:
+      - "event drop detected: 9 occurrences"
+      - "num times actions taken: 9"
+    stderr_not_contains:
+      - "Falco internal: syscall event drop"
+    stdout_not_contains:
+      - "Falco internal: syscall event drop"
+
+  monitor_syscall_drops_log:
+    exit_status: 0
+    rules_file:
+      - rules/single_rule.yaml
+    conf_file: confs/drops_log.yaml
+    trace_file: trace_files/ping_sendto.scap
+    stderr_contains:
+      - "event drop detected: 9 occurrences"
+      - "num times actions taken: 9"
+      - "Falco internal: syscall event drop"
+    stdout_not_contains:
+      - "Falco internal: syscall event drop"
+
+  monitor_syscall_drops_alert:
+    exit_status: 0
+    rules_file:
+      - rules/single_rule.yaml
+    conf_file: confs/drops_alert.yaml
+    trace_file: trace_files/ping_sendto.scap
+    stderr_contains:
+      - "event drop detected: 9 occurrences"
+      - "num times actions taken: 9"
+    stderr_not_contains:
+      - "Falco internal: syscall event drop"
+    stdout_contains:
+      - "Falco internal: syscall event drop"
+
+  monitor_syscall_drops_exit:
+    exit_status: 1
+    rules_file:
+      - rules/single_rule.yaml
+    conf_file: confs/drops_exit.yaml
+    trace_file: trace_files/ping_sendto.scap
+    stderr_contains:
+      - "event drop detected: 1 occurrences"
+      - "num times actions taken: 1"
+      - "Falco internal: syscall event drop"
+      - "Exiting."
+    stdout_not_contains:
+      - "Falco internal: syscall event drop"
+

userspace/falco/CMakeLists.txt

@@ -36,6 +36,7 @@ add_executable(falco
 	configuration.cpp
 	logger.cpp
 	falco_outputs.cpp
+	event_drops.cpp
 	statsfilewriter.cpp
 	falco.cpp
 	"${PROJECT_SOURCE_DIR}/../sysdig/userspace/sysdig/fields_info.cpp"

userspace/falco/configuration.cpp

@@ -182,6 +182,43 @@ void falco_configuration::init(string conf_filename, list<string> &cmdline_optio
 	m_webserver_k8s_audit_endpoint = m_config->get_scalar<string>("webserver", "k8s_audit_endpoint", "/k8s_audit");
 	m_webserver_ssl_enabled = m_config->get_scalar<bool>("webserver", "ssl_enabled", false);
 	m_webserver_ssl_certificate = m_config->get_scalar<string>("webserver", "ssl_certificate","/etc/falco/falco.pem");
+
+	std::list<string> syscall_event_drop_acts;
+	m_config->get_sequence(syscall_event_drop_acts, "syscall_event_drops", "actions");
+
+	for(std::string &act : syscall_event_drop_acts)
+	{
+		if(act == "ignore")
+		{
+			m_syscall_evt_drop_actions.insert(syscall_evt_drop_mgr::ACT_IGNORE);
+		}
+		else if (act == "log")
+		{
+			m_syscall_evt_drop_actions.insert(syscall_evt_drop_mgr::ACT_LOG);
+		}
+		else if (act == "alert")
+		{
+			m_syscall_evt_drop_actions.insert(syscall_evt_drop_mgr::ACT_ALERT);
+		}
+		else if (act == "exit")
+		{
+			m_syscall_evt_drop_actions.insert(syscall_evt_drop_mgr::ACT_EXIT);
+		}
+		else
+		{
+			throw invalid_argument("Error reading config file (" + m_config_file + "): syscall event drop action " + act + " must be one of \"ignore\", \"log\", \"alert\", or \"exit\"");
+		}
+	}
+
+	if(m_syscall_evt_drop_actions.empty())
+	{
+		m_syscall_evt_drop_actions.insert(syscall_evt_drop_mgr::ACT_IGNORE);
+	}
+
+	m_syscall_evt_drop_rate = m_config->get_scalar<double>("syscall_event_drops", "rate", 0.3333);
+	m_syscall_evt_drop_max_burst = m_config->get_scalar<double>("syscall_event_drops", "max_burst", 10);
+
+	m_syscall_evt_simulate_drops = m_config->get_scalar<bool>("syscall_event_drops", "simulate_drops", false);
 }
 
 void falco_configuration::read_rules_file_directory(const string &path, list<string> &rules_filenames)

userspace/falco/configuration.h

@@ -26,8 +26,10 @@ limitations under the License.
 #include <string>
 #include <vector>
 #include <list>
+#include <set>
 #include <iostream>
 
+#include "event_drops.h"
 #include "falco_outputs.h"
 
 class yaml_configuration
@@ -133,25 +135,50 @@ public:
 
 	// called with the last variadic arg (where the sequence is expected to be found)
 	template <typename T>
-	void get_sequence(T& ret, const std::string& name)
+	void get_sequence_from_node(T& ret, const YAML::Node &node)
 	{
-		YAML::Node child_node = m_root[name];
-		if(child_node.IsDefined())
+		if(node.IsDefined())
 		{
-			if(child_node.IsSequence())
+			if(node.IsSequence())
 			{
-				for(const YAML::Node& item : child_node)
+				for(const YAML::Node& item : node)
 				{
 					ret.insert(ret.end(), item.as<typename T::value_type>());
 				}
 			}
-			else if(child_node.IsScalar())
+			else if(node.IsScalar())
 			{
-				ret.insert(ret.end(), child_node.as<typename T::value_type>());
+				ret.insert(ret.end(), node.as<typename T::value_type>());
 			}
 		}
 	}
 
+	// called with the last variadic arg (where the sequence is expected to be found)
+	template <typename T>
+	void get_sequence(T& ret, const std::string& name)
+	{
+		return get_sequence_from_node<T>(ret, m_root[name]);
+	}
+
+	// called with the last variadic arg (where the sequence is expected to be found)
+	template <typename T>
+		void get_sequence(T& ret, const std::string& key, const std::string &subkey)
+	{
+		try
+		{
+			auto node = m_root[key];
+			if (node.IsDefined())
+			{
+				return get_sequence_from_node<T>(ret, node[subkey]);
+			}
+		}
+		catch (const YAML::BadConversion& ex)
+		{
+			std::cerr << "Cannot read config file (" + m_path + "): wrong type at key " + key + "\n";
+			throw;
+		}
+	}
+
 private:
 	YAML::Node m_root;
 };
@@ -184,6 +211,13 @@ class falco_configuration
 	std::string m_webserver_k8s_audit_endpoint;
 	bool m_webserver_ssl_enabled;
 	std::string m_webserver_ssl_certificate;
+	std::set<syscall_evt_drop_mgr::action> m_syscall_evt_drop_actions;
+	double m_syscall_evt_drop_rate;
+	double m_syscall_evt_drop_max_burst;
+
+	// Only used for testing
+	bool m_syscall_evt_simulate_drops;
+
 
  private:
 	void init_cmdline_options(std::list<std::string> &cmdline_options);

userspace/falco/event_drops.cpp

@@ -0,0 +1,157 @@
+/*
+Copyright (C) 2013-2019 Draios Inc dba Sysdig.
+
+This file is part of sysdig.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+
+*/
+
+#include "event_drops.h"
+
+syscall_evt_drop_mgr::syscall_evt_drop_mgr()
+	: m_num_syscall_evt_drops(0),
+	  m_num_actions(0),
+	  m_inspector(NULL),
+	  m_outputs(NULL),
+	  m_next_check_ts(0),
+	  m_simulate_drops(false)
+{
+}
+
+syscall_evt_drop_mgr::~syscall_evt_drop_mgr()
+{
+}
+
+void syscall_evt_drop_mgr::init(sinsp *inspector,
+				falco_outputs *outputs,
+				std::set<action> &actions,
+				double rate,
+				double max_tokens,
+				bool simulate_drops)
+{
+	m_inspector = inspector;
+	m_outputs = outputs;
+	m_actions = actions;
+	m_bucket.init(rate, max_tokens);
+
+	m_inspector->get_capture_stats(&m_last_stats);
+
+	m_simulate_drops = simulate_drops;
+}
+
+bool syscall_evt_drop_mgr::process_event(sinsp_evt *evt)
+{
+	if(m_next_check_ts == 0)
+	{
+		m_next_check_ts = evt->get_ts() + ONE_SECOND_IN_NS;
+	}
+
+	if(m_next_check_ts < evt->get_ts())
+	{
+		scap_stats stats, delta;
+
+		m_next_check_ts = evt->get_ts() + ONE_SECOND_IN_NS;
+
+		m_inspector->get_capture_stats(&stats);
+
+		// NOTE: only computing delta for interesting stats (evts/drops)
+		delta.n_evts = stats.n_evts - m_last_stats.n_evts;
+		delta.n_drops = stats.n_drops - m_last_stats.n_drops;
+
+		m_last_stats = stats;
+
+		if(m_simulate_drops)
+		{
+			falco_logger::log(LOG_INFO, "Simulating syscall event drop");
+			delta.n_drops++;
+		}
+
+		if(delta.n_drops > 0)
+		{
+			m_num_syscall_evt_drops++;
+
+			// There were new drops in the last second. If
+			// the token bucket allows, perform actions.
+			if(m_bucket.claim(1, evt->get_ts()))
+			{
+				m_num_actions++;
+
+				return perform_actions(evt->get_ts(), delta);
+			}
+			else
+			{
+				falco_logger::log(LOG_DEBUG, "Syscall event drop but token bucket depleted, skipping actions");
+			}
+		}
+	}
+
+	return true;
+}
+
+void syscall_evt_drop_mgr::print_stats()
+{
+	fprintf(stderr, "Syscall event drop monitoring:\n");
+	fprintf(stderr, "   - event drop detected: %lu occurrences\n", m_num_syscall_evt_drops);
+	fprintf(stderr, "   - num times actions taken: %lu\n", m_num_actions);
+}
+
+bool syscall_evt_drop_mgr::perform_actions(uint64_t now, scap_stats &delta)
+{
+	std::string rule = "Falco internal: syscall event drop";
+	std::string msg = rule + ". " + std::to_string(delta.n_drops) + " system calls dropped in last second.";
+
+	std::map<std::string,std::string> output_fields;
+
+	output_fields["n_evts"] = std::to_string(delta.n_evts);
+	output_fields["n_drops"] = std::to_string(delta.n_drops);
+	bool should_exit = false;
+
+	for(auto &act : m_actions)
+	{
+		switch(act)
+		{
+		case ACT_IGNORE:
+			break;
+
+		case ACT_LOG:
+			falco_logger::log(LOG_ERR, msg);
+			break;
+
+		case ACT_ALERT:
+			m_outputs->handle_msg(now,
+					      falco_outputs::PRIORITY_CRITICAL,
+					      msg,
+					      rule,
+					      output_fields);
+			break;
+
+		case ACT_EXIT:
+			should_exit = true;
+			break;
+
+		default:
+			falco_logger::log(LOG_ERR, "Ignoring unknown action " + std::to_string(int(act)));
+			break;
+		}
+	}
+
+	if(should_exit)
+	{
+		falco_logger::log(LOG_CRIT, msg);
+		falco_logger::log(LOG_CRIT, "Exiting.");
+		return false;
+	}
+
+	return true;
+}

userspace/falco/event_drops.h

@@ -0,0 +1,78 @@
+/*
+Copyright (C) 2016-2019 Draios Inc dba Sysdig.
+
+This file is part of falco.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+
+*/
+#pragma once
+
+#include <set>
+
+#include <sinsp.h>
+#include <token_bucket.h>
+
+#include "logger.h"
+#include "falco_outputs.h"
+
+class syscall_evt_drop_mgr
+{
+public:
+
+	// The possible actions that this class can take upon
+	// detecting a syscall event drop.
+	enum action
+	{
+		ACT_IGNORE = 0,
+		ACT_LOG,
+		ACT_ALERT,
+		ACT_EXIT,
+	};
+
+	syscall_evt_drop_mgr();
+	virtual ~syscall_evt_drop_mgr();
+
+	void init(sinsp *inspector,
+		  falco_outputs *outputs,
+		  std::set<action> &actions,
+		  double rate,
+		  double max_tokens,
+		  bool simulate_drops);
+
+	// Call this for every event. The class will take care of
+	// periodically measuring the scap stats, looking for syscall
+	// event drops, and performing any actions.
+	//
+	// Returns whether event processing should continue or stop (with an error).
+	bool process_event(sinsp_evt *evt);
+
+	void print_stats();
+
+protected:
+
+	// Perform all configured actions.
+	bool perform_actions(uint64_t now, scap_stats &delta);
+
+	uint64_t m_num_syscall_evt_drops;
+	uint64_t m_num_actions;
+	sinsp *m_inspector;
+	falco_outputs *m_outputs;
+	std::set<action> m_actions;
+	token_bucket m_bucket;
+	uint64_t m_next_check_ts;
+	scap_stats m_last_stats;
+	bool m_simulate_drops;
+};
+
+

userspace/falco/falco.cpp

@@ -40,6 +40,7 @@ limitations under the License.
 #include "chisel.h"
 #include "sysdig.h"
 
+#include "event_drops.h"
 #include "configuration.h"
 #include "falco_engine.h"
 #include "config_falco.h"
@@ -132,6 +133,9 @@ static void usage()
            "                               from multiple files/directories.\n"
 	   " -s <stats_file>               If specified, write statistics related to falco's reading/processing of events\n"
 	   "                               to this file. (Only useful in live mode).\n"
+	   " --stats_interval <msec>       When using -s <stats_file>, write statistics every <msec> ms.\n"
+	   "                               (This uses signals, so don't recommend intervals below 200 ms)\n"
+	   "                               defaults to 5000 (5 seconds)\n"
 	   " -S <len>, --snaplen=<len>\n"
 	   "                  		   Capture the first <len> bytes of each I/O buffer.\n"
 	   "                   		   By default, the first 80 bytes are captured. Use this\n"
@@ -215,9 +219,13 @@ static std::string read_file(std::string filename)
 uint64_t do_inspect(falco_engine *engine,
 		    falco_outputs *outputs,
 		    sinsp* inspector,
+		    falco_configuration &config,
+		    syscall_evt_drop_mgr &sdropmgr,
 		    uint64_t duration_to_tot_ns,
 		    string &stats_filename,
-		    bool all_events)
+		    uint64_t stats_interval,
+		    bool all_events,
+		    int &result)
 {
 	uint64_t num_evts = 0;
 	int32_t rc;
@@ -225,11 +233,18 @@ uint64_t do_inspect(falco_engine *engine,
 	StatsFileWriter writer;
 	uint64_t duration_start = 0;
 
+	sdropmgr.init(inspector,
+		      outputs,
+		      config.m_syscall_evt_drop_actions,
+		      config.m_syscall_evt_drop_rate,
+		      config.m_syscall_evt_drop_max_burst,
+		      config.m_syscall_evt_simulate_drops);
+
 	if (stats_filename != "")
 	{
 		string errstr;
 
-		if (!writer.init(inspector, stats_filename, 5, errstr))
+		if (!writer.init(inspector, stats_filename, stats_interval, errstr))
 		{
 			throw falco_exception(errstr);
 		}
@@ -285,6 +300,12 @@ uint64_t do_inspect(falco_engine *engine,
 			}
 		}
 
+		if(!sdropmgr.process_event(ev))
+		{
+			result = EXIT_FAILURE;
+			break;
+		}
+
 		if(!ev->falco_consider() && !all_events)
 		{
 			continue;
@@ -375,6 +396,7 @@ int falco_init(int argc, char **argv)
 	sinsp_evt::param_fmt event_buffer_format = sinsp_evt::PF_NORMAL;
 	falco_engine *engine = NULL;
 	falco_outputs *outputs = NULL;
+	syscall_evt_drop_mgr sdropmgr;
 	int op;
 	int long_index = 0;
 	string trace_filename;
@@ -388,6 +410,7 @@ int falco_init(int argc, char **argv)
 	string describe_rule = "";
 	list<string> validate_rules_filenames;
 	string stats_filename = "";
+	uint64_t stats_interval = 5000;
 	bool verbose = false;
 	bool names_only = false;
 	bool all_events = false;
@@ -432,6 +455,7 @@ int falco_init(int argc, char **argv)
 		{"print", required_argument, 0, 'p' },
 		{"pidfile", required_argument, 0, 'P' },
 		{"snaplen", required_argument, 0, 'S' },
+		{"stats_interval", required_argument, 0},
 		{"support", no_argument, 0},
 		{"unbuffered", no_argument, 0, 'U' },
 		{"version", no_argument, 0, 0 },
@@ -588,6 +612,10 @@ int falco_init(int argc, char **argv)
 						list_flds_source = optarg;
 					}
 				}
+				else if (string(long_options[long_index].name) == "stats_interval")
+				{
+					stats_interval = atoi(optarg);
+				}
 				else if (string(long_options[long_index].name) == "support")
 				{
 					print_support = true;
@@ -1061,9 +1089,13 @@ int falco_init(int argc, char **argv)
 			num_evts = do_inspect(engine,
 					      outputs,
 					      inspector,
+					      config,
+					      sdropmgr,
 					      uint64_t(duration_to_tot*ONE_SECOND_IN_NS),
 					      stats_filename,
-					      all_events);
+					      stats_interval,
+					      all_events,
+					      result);
 
 			duration = ((double)clock()) / CLOCKS_PER_SEC - duration;
 
@@ -1085,6 +1117,7 @@ int falco_init(int argc, char **argv)
 
 		inspector->close();
 		engine->print_stats();
+		sdropmgr.print_stats();
 		webserver.stop();
 	}
 	catch(exception &e)

userspace/falco/falco_outputs.cpp

@@ -36,7 +36,8 @@ const static struct luaL_reg ll_falco_outputs [] =
 falco_outputs::falco_outputs(falco_engine *engine)
 	: m_falco_engine(engine),
 	  m_initialized(false),
-	  m_buffered(true)
+	  m_buffered(true),
+	  m_json_output(false)
 {
 
 }
@@ -77,6 +78,8 @@ void falco_outputs::init(bool json_output,
 		throw falco_exception("No inspector provided");
 	}
 
+	m_json_output = json_output;
+
 	falco_common::init(m_lua_main_filename.c_str(), FALCO_SOURCE_LUA_DIR);
 
 	// Note that falco_formats is added to both the lua state used
@@ -162,6 +165,81 @@ void falco_outputs::handle_event(gen_event *ev, string &rule, string &source,
 
 }
 
+void falco_outputs::handle_msg(uint64_t now,
+			       falco_common::priority_type priority,
+			       std::string &msg,
+			       std::string &rule,
+			       std::map<std::string,std::string> &output_fields)
+{
+	std::string full_msg;
+
+	if(m_json_output)
+	{
+		nlohmann::json jmsg;
+
+		// Convert the time-as-nanoseconds to a more json-friendly ISO8601.
+		time_t evttime = now/1000000000;
+		char time_sec[20]; // sizeof "YYYY-MM-DDTHH:MM:SS"
+		char time_ns[12]; // sizeof ".sssssssssZ"
+		string iso8601evttime;
+
+		strftime(time_sec, sizeof(time_sec), "%FT%T", gmtime(&evttime));
+		snprintf(time_ns, sizeof(time_ns), ".%09luZ", now % 1000000000);
+		iso8601evttime = time_sec;
+		iso8601evttime += time_ns;
+
+		jmsg["output"] = msg;
+		jmsg["priority"] = "Critical";
+		jmsg["rule"] = rule;
+		jmsg["time"] = iso8601evttime;
+		jmsg["output_fields"] = output_fields;
+
+		full_msg = jmsg.dump();
+	}
+	else
+	{
+		std::string timestr;
+		bool first = true;
+
+		sinsp_utils::ts_to_string(now, &timestr, false, true);
+		full_msg = timestr + ": " + falco_common::priority_names[LOG_CRIT] + " " + msg + "(";
+		for(auto &pair : output_fields)
+		{
+			if(first)
+			{
+				first = false;
+			}
+			else
+			{
+				full_msg += " ";
+			}
+			full_msg += pair.first + "=" + pair.second;
+		}
+		full_msg += ")";
+	}
+
+	lua_getglobal(m_ls, m_lua_output_msg.c_str());
+
+	if(lua_isfunction(m_ls, -1))
+	{
+		lua_pushstring(m_ls, full_msg.c_str());
+		lua_pushstring(m_ls, falco_common::priority_names[priority].c_str());
+		lua_pushnumber(m_ls, priority);
+
+		if(lua_pcall(m_ls, 3, 0, 0) != 0)
+		{
+			const char* lerr = lua_tostring(m_ls, -1);
+			string err = "Error invoking function output: " + string(lerr);
+			throw falco_exception(err);
+		}
+	}
+	else
+	{
+		throw falco_exception("No function " + m_lua_output_msg + " found in lua compiler module");
+	}
+
+}
+
 void falco_outputs::reopen_outputs()
 {
 	lua_getglobal(m_ls, m_lua_output_reopen.c_str());
@@ -215,4 +293,4 @@ int falco_outputs::handle_http(lua_State *ls)
   		slist1 = NULL;
 	}
 	return 1;
-}
+}

userspace/falco/falco_outputs.h

@@ -20,6 +20,7 @@ limitations under the License.
 #pragma once
 
 #include <memory>
+#include <map>
 
 extern "C" {
 #include "lua.h"
@@ -66,6 +67,13 @@ public:
 	void handle_event(gen_event *ev, std::string &rule, std::string &source,
 			  falco_common::priority_type priority, std::string &format);
 
+	// Send a generic message to all outputs. Not necessarily associated with any event.
+	void handle_msg(uint64_t now,
+			falco_common::priority_type priority,
+			std::string &msg,
+			std::string &rule,
+			std::map<std::string,std::string> &output_fields);
+
 	void reopen_outputs();
 
 	static int handle_http(lua_State *ls);
@@ -81,8 +89,11 @@ private:
 
 	bool m_buffered;
 
+	bool m_json_output;
+
 	std::string m_lua_add_output = "add_output";
 	std::string m_lua_output_event = "output_event";
+	std::string m_lua_output_msg = "output_msg";
 	std::string m_lua_output_cleanup = "output_cleanup";
 	std::string m_lua_output_reopen = "output_reopen";
 	std::string m_lua_main_filename = "output.lua";

userspace/falco/logger.cpp

@@ -93,22 +93,39 @@ int falco_logger::syslog(lua_State *ls) {
 bool falco_logger::log_stderr = true;
 bool falco_logger::log_syslog = true;
 
-void falco_logger::log(int priority, const string msg) {
+void falco_logger::log(int priority, const string msg)
+{
 
 	if(priority > falco_logger::level)
 	{
 		return;
 	}
 
-	if (falco_logger::log_syslog) {
-		::syslog(priority, "%s", msg.c_str());
+	string copy = msg;
+
+	if (falco_logger::log_syslog)
+	{
+		// Syslog output should not have any trailing newline
+		if(copy.back() == '\n')
+		{
+			copy.pop_back();
+		}
+
+		::syslog(priority, "%s", copy.c_str());
 	}
 
-	if (falco_logger::log_stderr) {
+	if (falco_logger::log_stderr)
+	{
+		// log output should always have a trailing newline
+		if(copy.back() != '\n')
+		{
+			copy.push_back('\n');
+		}
+
 		std::time_t result = std::time(nullptr);
 		string tstr = std::asctime(std::localtime(&result));
 		tstr = tstr.substr(0, 24);// remove trailling newline
-		fprintf(stderr, "%s: %s", tstr.c_str(), msg.c_str());
+		fprintf(stderr, "%s: %s", tstr.c_str(), copy.c_str());
 	}
 }
 

userspace/falco/lua/output.lua

@@ -172,6 +172,12 @@ function output_event(event, rule, source, priority, priority_num, format)
    end
 end
 
+function output_msg(msg, priority, priority_num)
+   for index,o in ipairs(outputs) do
+      o.output(priority, priority_num, msg, o.options)
+   end
+end
+
 function output_cleanup()
    formats.free_formatters()
    for index,o in ipairs(outputs) do

userspace/falco/statsfilewriter.cpp

@@ -42,7 +42,7 @@ StatsFileWriter::~StatsFileWriter()
 	m_output.close();
 }
 
-bool StatsFileWriter::init(sinsp *inspector, string &filename, uint32_t interval_sec, string &errstr)
+bool StatsFileWriter::init(sinsp *inspector, string &filename, uint32_t interval_msec, string &errstr)
 {
 	struct itimerval timer;
 	struct sigaction handler;
@@ -60,8 +60,8 @@ bool StatsFileWriter::init(sinsp *inspector, string &filename, uint32_t interval
 		return false;
 	}
 
-	timer.it_value.tv_sec = interval_sec;
-	timer.it_value.tv_usec = 0;
+	timer.it_value.tv_sec = 0;
+	timer.it_value.tv_usec = interval_msec * 1000;
 	timer.it_interval = timer.it_value;
 	if (setitimer(ITIMER_REAL, &timer, NULL) == -1)
 	{

userspace/falco/statsfilewriter.h

@@ -35,7 +35,7 @@ public:
 
 	// Returns success as bool. On false fills in errstr.
 	bool init(sinsp *inspector, std::string &filename,
-		  uint32_t interval_sec,
+		  uint32_t interval_msec,
 		  string &errstr);
 
 	// Should be called often (like for each event in a sinsp