From a198171c92fe70d7d9956c153182a78969bc885b Mon Sep 17 00:00:00 2001
From: Mark Stemm <mark.stemm@gmail.com>
Date: Wed, 13 Feb 2019 09:18:58 -0800
Subject: [PATCH] Add option to display times in ISO 8601 UTC

ISO 8601 time is useful when, say, running falco in a container, which
may have a different /etc/localtime than the host system.

A new config option time_format_iso_8601 controls whether log message
and event times are displayed in ISO 8601 in UTC or in local time. The
default is false (display times in local time).

This option is passed to logger init as well as outputs. For outputs it
eventually changes the time format field from %evt.time/%jevt.time to
%evt.time.iso8601/%jevt.time.iso8601.

Adding this field changes the falco engine version so increment it.

This depends on https://github.com/draios/sysdig/pull/1317.
---
 falco.yaml                              |  5 +++++
 userspace/engine/falco_engine_version.h |  4 ++--
 userspace/engine/json_evt.cpp           | 14 ++++++++++++++
 userspace/engine/json_evt.h             |  1 +
 userspace/falco/configuration.cpp       |  2 ++
 userspace/falco/configuration.h         |  1 +
 userspace/falco/falco.cpp               |  6 +++++-
 userspace/falco/falco_outputs.cpp       | 10 +++++++---
 userspace/falco/falco_outputs.h         |  4 +++-
 userspace/falco/logger.cpp              | 22 +++++++++++++++++++---
 userspace/falco/logger.h                |  3 +++
 userspace/falco/lua/output.lua          | 23 ++++++++++++++++++++---
 12 files changed, 82 insertions(+), 13 deletions(-)

diff --git a/falco.yaml b/falco.yaml
index c01a8f0de6e..f7c1d2e5fd8 100644
--- a/falco.yaml
+++ b/falco.yaml
@@ -34,6 +34,11 @@ rules_file:
  - /etc/falco/k8s_audit_rules.yaml
  - /etc/falco/rules.d
 
+# If true, the times displayed in log messages and output messages
+# will be in ISO 8601. By default, times are displayed in the local
+# time zone, as governed by /etc/localtime.
+time_format_iso_8601: false
+
 # Whether to output events in json or text
 json_output: false
 
diff --git a/userspace/engine/falco_engine_version.h b/userspace/engine/falco_engine_version.h
index 7d45d3a60a7..c7745f72b3a 100644
--- a/userspace/engine/falco_engine_version.h
+++ b/userspace/engine/falco_engine_version.h
@@ -19,9 +19,9 @@ limitations under the License.
 
 // The version of rules/filter fields/etc supported by this falco
 // engine.
-#define FALCO_ENGINE_VERSION (2)
+#define FALCO_ENGINE_VERSION (3)
 
 // This is the result of running "falco --list -N | sha256sum" and
 // represents the fields supported by this version of falco. It's used
 // at build time to detect a changed set of fields.
-#define FALCO_FIELDS_CHECKSUM "32a91c003ab34f198dcb4c3100fbfb22bf402ad36549f193afa43d73f1f2eba3"
+#define FALCO_FIELDS_CHECKSUM "b1bf297373fd08c91ffc978dbff5b349ec9338e25b54f70f23e40a609d47924b"
diff --git a/userspace/engine/json_evt.cpp b/userspace/engine/json_evt.cpp
index 8d8bad2e696..5229fe40c7e 100644
--- a/userspace/engine/json_evt.cpp
+++ b/userspace/engine/json_evt.cpp
@@ -278,6 +278,7 @@ std::string json_event_filter_check::extract(json_event *evt)
 }
 
 std::string jevt_filter_check::s_jevt_time_field = "jevt.time";
+std::string jevt_filter_check::s_jevt_time_iso_8601_field = "jevt.time.iso8601";
 std::string jevt_filter_check::s_jevt_rawtime_field = "jevt.rawtime";
 std::string jevt_filter_check::s_jevt_value_field = "jevt.value";
 std::string jevt_filter_check::s_jevt_obj_field = "jevt.obj";
@@ -288,6 +289,7 @@ jevt_filter_check::jevt_filter_check()
 		  "generic ways to access json events",
 		  {
 			  {s_jevt_time_field, "json event timestamp as a string that includes the nanosecond part"},
+			  {s_jevt_time_iso_8601_field, "json event timestamp in ISO 8601 format, including nanoseconds and time zone offset (in UTC)"},
 			  {s_jevt_rawtime_field, "absolute event timestamp, i.e. nanoseconds from epoch."},
 			  {s_jevt_value_field, "General way to access single property from json object. The syntax is [<json pointer expression>]. The property is returned as a string"},
 			  {s_jevt_obj_field, "The entire json object, stringified"}
@@ -307,6 +309,12 @@ int32_t jevt_filter_check::parse_field_name(const char *str, bool alloc_state, b
 		return s_jevt_time_field.size();
 	}
 
+	if(strncmp(s_jevt_time_iso_8601_field.c_str(), str, s_jevt_time_iso_8601_field.size()) == 0)
+	{
+		m_field = s_jevt_time_iso_8601_field;
+		return s_jevt_time_iso_8601_field.size();
+	}
+
 	if(strncmp(s_jevt_rawtime_field.c_str(), str, s_jevt_rawtime_field.size()) == 0)
 	{
 		m_field = s_jevt_rawtime_field;
@@ -361,6 +369,12 @@ uint8_t* jevt_filter_check::extract(gen_event *evt, uint32_t* len, bool sanitize
 		*len = m_tstr.size();
 		return (uint8_t *) m_tstr.c_str();
 	}
+	else if(m_field == s_jevt_time_iso_8601_field)
+	{
+		sinsp_utils::ts_to_iso_8601(evt->get_ts(), &m_tstr);
+		*len = m_tstr.size();
+		return (uint8_t *) m_tstr.c_str();
+	}
 	else if(m_field == s_jevt_obj_field)
 	{
 		json_event *jevt = (json_event *) evt;
diff --git a/userspace/engine/json_evt.h b/userspace/engine/json_evt.h
index 29a4779ae3d..e04d73fda70 100644
--- a/userspace/engine/json_evt.h
+++ b/userspace/engine/json_evt.h
@@ -200,6 +200,7 @@ class jevt_filter_check : public json_event_filter_check
 private:
 
 	static std::string s_jevt_time_field;
+	static std::string s_jevt_time_iso_8601_field;
 	static std::string s_jevt_rawtime_field;
 	static std::string s_jevt_obj_field;
 	static std::string s_jevt_value_field;
diff --git a/userspace/falco/configuration.cpp b/userspace/falco/configuration.cpp
index a778caaf2c4..3f95823d9ce 100644
--- a/userspace/falco/configuration.cpp
+++ b/userspace/falco/configuration.cpp
@@ -31,6 +31,7 @@ using namespace std;
 
 falco_configuration::falco_configuration()
 	: m_buffered_outputs(false),
+	  m_time_format_iso_8601(false),
 	  m_webserver_enabled(false),
 	  m_webserver_listen_port(8765),
 	  m_webserver_k8s_audit_endpoint("/k8s_audit"),
@@ -157,6 +158,7 @@ void falco_configuration::init(string conf_filename, list<string> &cmdline_optio
 	m_min_priority = (falco_common::priority_type) (it - falco_common::priority_names.begin());
 
 	m_buffered_outputs = m_config->get_scalar<bool>("buffered_outputs", false);
+	m_time_format_iso_8601 = m_config->get_scalar<bool>("time_format_iso_8601", false);
 
 	falco_logger::log_stderr = m_config->get_scalar<bool>("log_stderr", false);
 	falco_logger::log_syslog = m_config->get_scalar<bool>("log_syslog", true);
diff --git a/userspace/falco/configuration.h b/userspace/falco/configuration.h
index 0fb6700a4bc..606c914fb0b 100644
--- a/userspace/falco/configuration.h
+++ b/userspace/falco/configuration.h
@@ -178,6 +178,7 @@ class falco_configuration
 	falco_common::priority_type m_min_priority;
 
 	bool m_buffered_outputs;
+	bool m_time_format_iso_8601;
 
 	bool m_webserver_enabled;
 	uint32_t m_webserver_listen_port;
diff --git a/userspace/falco/falco.cpp b/userspace/falco/falco.cpp
index 8b43937f6b3..e859d4f9a88 100644
--- a/userspace/falco/falco.cpp
+++ b/userspace/falco/falco.cpp
@@ -666,12 +666,15 @@ int falco_init(int argc, char **argv)
 		if (conf_filename.size())
 		{
 			config.init(conf_filename, cmdline_options);
+			falco_logger::set_time_format_iso_8601(config.m_time_format_iso_8601);
+
 			// log after config init because config determines where logs go
 			falco_logger::log(LOG_INFO, "Falco initialized with configuration file " + conf_filename + "\n");
 		}
 		else
 		{
 			config.init(cmdline_options);
+			falco_logger::set_time_format_iso_8601(config.m_time_format_iso_8601);
 			falco_logger::log(LOG_INFO, "Falco initialized. No configuration file found, proceeding with defaults\n");
 		}
 
@@ -741,7 +744,8 @@ int falco_init(int argc, char **argv)
 		outputs->init(config.m_json_output,
 			      config.m_json_include_output_property,
 			      config.m_notifications_rate, config.m_notifications_max_burst,
-			      config.m_buffered_outputs);
+			      config.m_buffered_outputs,
+			      config.m_time_format_iso_8601);
 
 		if(!all_events)
 		{
diff --git a/userspace/falco/falco_outputs.cpp b/userspace/falco/falco_outputs.cpp
index 97341e0b1b8..145b6980d5b 100644
--- a/userspace/falco/falco_outputs.cpp
+++ b/userspace/falco/falco_outputs.cpp
@@ -30,7 +30,8 @@ using namespace std;
 falco_outputs::falco_outputs(falco_engine *engine)
 	: m_falco_engine(engine),
 	  m_initialized(false),
-	  m_buffered(true)
+	  m_buffered(true),
+	  m_time_format_iso_8601(false)
 {
 
 }
@@ -63,7 +64,8 @@ falco_outputs::~falco_outputs()
 
 void falco_outputs::init(bool json_output,
 			 bool json_include_output_property,
-			 uint32_t rate, uint32_t max_burst, bool buffered)
+			 uint32_t rate, uint32_t max_burst, bool buffered,
+			 bool time_format_iso_8601)
 {
 	// The engine must have been given an inspector by now.
 	if(! m_inspector)
@@ -83,13 +85,14 @@ void falco_outputs::init(bool json_output,
 	m_notifications_tb.init(rate, max_burst);
 
 	m_buffered = buffered;
+	m_time_format_iso_8601 = time_format_iso_8601;
 
 	m_initialized = true;
 }
 
 void falco_outputs::add_output(output_config oc)
 {
-	uint8_t nargs = 2;
+	uint8_t nargs = 3;
 	lua_getglobal(m_ls, m_lua_add_output.c_str());
 
 	if(!lua_isfunction(m_ls, -1))
@@ -98,6 +101,7 @@ void falco_outputs::add_output(output_config oc)
 	}
 	lua_pushstring(m_ls, oc.name.c_str());
 	lua_pushnumber(m_ls, (m_buffered ? 1 : 0));
+	lua_pushnumber(m_ls, (m_time_format_iso_8601 ? 1 : 0));
 
 	// If we have options, build up a lua table containing them
 	if (oc.options.size())
diff --git a/userspace/falco/falco_outputs.h b/userspace/falco/falco_outputs.h
index 0d9cbcebdbd..b0f3761c38b 100644
--- a/userspace/falco/falco_outputs.h
+++ b/userspace/falco/falco_outputs.h
@@ -49,7 +49,8 @@ class falco_outputs : public falco_common
 
 	void init(bool json_output,
 		  bool json_include_output_property,
-		  uint32_t rate, uint32_t max_burst, bool buffered);
+		  uint32_t rate, uint32_t max_burst, bool buffered,
+		  bool time_format_iso_8601);
 
 	void add_output(output_config oc);
 
@@ -72,6 +73,7 @@ class falco_outputs : public falco_common
 	token_bucket m_notifications_tb;
 
 	bool m_buffered;
+	bool m_time_format_iso_8601;
 
 	std::string m_lua_add_output = "add_output";
 	std::string m_lua_output_event = "output_event";
diff --git a/userspace/falco/logger.cpp b/userspace/falco/logger.cpp
index 772951513f9..5db7236f870 100644
--- a/userspace/falco/logger.cpp
+++ b/userspace/falco/logger.cpp
@@ -30,12 +30,18 @@ const static struct luaL_reg ll_falco [] =
 };
 
 int falco_logger::level = LOG_INFO;
+bool falco_logger::time_format_iso_8601 = false;
 
 void falco_logger::init(lua_State *ls)
 {
 	luaL_openlib(ls, "falco", ll_falco, 0);
 }
 
+void falco_logger::set_time_format_iso_8601(bool val)
+{
+	falco_logger::time_format_iso_8601 = val;
+}
+
 void falco_logger::set_level(string &level)
 {
 	if(level == "emergency")
@@ -105,10 +111,20 @@ void falco_logger::log(int priority, const string msg) {
 	}
 
 	if (falco_logger::log_stderr) {
+
 		std::time_t result = std::time(nullptr);
-		char buf[sizeof "YYYY-MM-DDTHH:MM:SS-0000"];
-		strftime(buf, sizeof(buf), "%FT%T%z", std::localtime(&result));
-		fprintf(stderr, "%s: %s", buf, msg.c_str());
+		if(falco_logger::time_format_iso_8601)
+		{
+			char buf[sizeof "YYYY-MM-DDTHH:MM:SS-0000"];
+			strftime(buf, sizeof(buf), "%FT%T%z", std::gmtime(&result));
+			fprintf(stderr, "%s: %s", buf, msg.c_str());
+		}
+		else
+		{
+			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());
+		}
 	}
 }
 
diff --git a/userspace/falco/logger.h b/userspace/falco/logger.h
index 82cda156423..7fb78082f18 100644
--- a/userspace/falco/logger.h
+++ b/userspace/falco/logger.h
@@ -33,6 +33,8 @@ class falco_logger
  public:
 	static void init(lua_State *ls);
 
+	static void set_time_format_iso_8601(bool val);
+
 	// Will throw exception if level is unknown.
 	static void set_level(string &level);
 
@@ -44,4 +46,5 @@ class falco_logger
 	static int level;
 	static bool log_stderr;
 	static bool log_syslog;
+	static bool time_format_iso_8601;
 };
diff --git a/userspace/falco/lua/output.lua b/userspace/falco/lua/output.lua
index 0314cd65bec..9a7a255a28b 100644
--- a/userspace/falco/lua/output.lua
+++ b/userspace/falco/lua/output.lua
@@ -149,10 +149,26 @@ function output_event(event, rule, source, priority, priority_num, format)
       format = format:sub(2)
    end
 
+   -- time_format_iso_8601 will be the same for all output channels
+   time_format_iso_8601 = 0
+
+   for index,o in ipairs(outputs) do
+      time_format_iso_8601 = o.options.time_format_iso_8601
+      break
+   end
+
    if source == "syscall" then
-      format = "*%evt.time: "..priority.." "..format
+      if time_format_iso_8601 == 1 then
+	 format = "*%evt.time.iso8601: "..priority.." "..format
+      else
+	 format = "*%evt.time: "..priority.." "..format
+      end
    else
-      format = "*%jevt.time: "..priority.." "..format
+      if time_format_iso_8601 == 1 then
+	 format = "*%jevt.time: "..priority.." "..format
+      else
+	 format = "*%jevt.time.iso8601: "..priority.." "..format
+      end
    end
 
    msg = formats.format_event(event, rule, source, priority, format)
@@ -175,7 +191,7 @@ function output_reopen()
    end
 end
 
-function add_output(output_name, buffered, options)
+function add_output(output_name, buffered, time_format_iso_8601, options)
    if not (type(mod[output_name]) == 'function') then
       error("rule_loader.add_output(): invalid output_name: "..output_name)
    end
@@ -191,6 +207,7 @@ function add_output(output_name, buffered, options)
    end
 
    options.buffered = buffered
+   options.time_format_iso_8601 = time_format_iso_8601
 
    table.insert(outputs, {output = mod[output_name],
 			  cleanup = mod[output_name.."_cleanup"],