Add the ability to prepend encoded log severity in the log message

Author: bwolmarans

userspace/libsinsp/logger.cpp

@@ -32,14 +32,17 @@ namespace
 
 thread_local char s_tbuf[16384];
 
+const size_t ENCODE_LEN = sizeof(uint64_t);
+
 } // end namespace
 
-const uint32_t sinsp_logger::OT_NONE     = 0;
-const uint32_t sinsp_logger::OT_STDOUT   = 1;
-const uint32_t sinsp_logger::OT_STDERR   = (OT_STDOUT   << 1);
-const uint32_t sinsp_logger::OT_FILE     = (OT_STDERR   << 1);
-const uint32_t sinsp_logger::OT_CALLBACK = (OT_FILE     << 1);
-const uint32_t sinsp_logger::OT_NOTS     = (OT_CALLBACK << 1);
+const uint32_t sinsp_logger::OT_NONE       = 0;
+const uint32_t sinsp_logger::OT_STDOUT     = 1;
+const uint32_t sinsp_logger::OT_STDERR     = (OT_STDOUT   << 1);
+const uint32_t sinsp_logger::OT_FILE       = (OT_STDERR   << 1);
+const uint32_t sinsp_logger::OT_CALLBACK   = (OT_FILE     << 1);
+const uint32_t sinsp_logger::OT_NOTS       = (OT_CALLBACK << 1);
+const uint32_t sinsp_logger::OT_ENCODE_SEV = (OT_NOTS     << 1);
 
 sinsp_logger::sinsp_logger():
 	m_file(nullptr),
@@ -101,6 +104,11 @@ void sinsp_logger::disable_timestamps()
 	m_flags |= sinsp_logger::OT_NOTS;
 }
 
+void sinsp_logger::add_encoded_severity()
+{
+	m_flags |= sinsp_logger::OT_ENCODE_SEV;
+}
+
 void sinsp_logger::add_callback_log(const sinsp_logger_callback callback)
 {
 	const sinsp_logger_callback old_cb = m_callback.exchange(callback);
@@ -165,19 +173,11 @@ void sinsp_logger::log(std::string msg, const severity sev)
 
 		if(gettimeofday(&ts, nullptr) == 0)
 		{
-			const std::string::size_type ts_length = 22;
-			char ts_buf[ts_length + 1];
+			const std::string::size_type ts_length = sizeof("31-12 23:59:59.999999 ");
+			char ts_buf[ts_length];
 			struct tm time_info = {};
 
 			gmtime_r(&ts.tv_sec, &time_info);
-
-			//
-			// This formatted string is ts_length bytes long:
-			//
-			//           1         2
-			// "1234567890123456789012
-			// "xx-xx xx:xx:xx.xxxxxx "
-			//
 			snprintf(ts_buf,
 				 sizeof(ts_buf),
 				 "%.2d-%.2d %.2d:%.2d:%.2d.%.6d ",
@@ -189,10 +189,18 @@ void sinsp_logger::log(std::string msg, const severity sev)
 				 (int)ts.tv_usec);
 
 			ts_buf[sizeof(ts_buf) - 1] = '\0';
-			msg.insert(0, ts_buf, ts_length);
+			msg.insert(0, ts_buf);
 		}
 	}
 
+	if(m_flags & sinsp_logger::OT_ENCODE_SEV)
+	{
+		char sev_buf[ENCODE_LEN + 1];
+		strncpy(sev_buf, encode_severity(sev), sizeof(sev_buf));
+		sev_buf[sizeof(sev_buf) - 1] = 0;
+		msg.insert(0, sev_buf);
+	}
+
 	if(is_callback())
 	{
 		cb = m_callback;
@@ -250,3 +258,57 @@ const char* sinsp_logger::format(const char* const fmt, ...)
 
 	return s_tbuf;
 }
+
+namespace {
+// All severity strings should be ENCODE_LEN chars long
+const char* SEV_LEVELS[] = {
+	"SEV_DEF ",
+	"SEV_FAT ",
+	"SEV_CRI ",
+	"SEV_ERR ",
+	"SEV_WAR ",
+	"SEV_NOT ",
+	"SEV_INF ",
+	"SEV_DEB ",
+	"SEV_TRA "
+};
+
+static_assert(sizeof(SEV_LEVELS) == sizeof(*SEV_LEVELS) * ((size_t)(sinsp_logger::SEV_MAX) + 1),
+	      "severity array must have SEV_MAX+1 elements");
+}
+
+const char* sinsp_logger::encode_severity(const sinsp_logger::severity sev)
+{
+	const char* ret;
+	auto sev_int = (size_t)sev;
+	if (sev_int > SEV_MAX)
+	{
+		sev_int = 0;
+	}
+
+	ret = SEV_LEVELS[sev_int];
+	assert(strlen(ret) == ENCODE_LEN);
+	return ret;
+}
+
+size_t sinsp_logger::decode_severity(const std::string &str, severity& sev)
+{
+	if(str.length() < ENCODE_LEN)
+	{
+		return 0;
+	}
+
+	const char* msg = str.c_str();
+
+	// we don't really expect "SEV_DEF " messages so skip severity 0
+	for(size_t i = SEV_MIN; i <= SEV_MAX; ++i)
+	{
+		if(!strncmp(msg, SEV_LEVELS[i], ENCODE_LEN))
+		{
+			sev = static_cast<severity>(i);
+			return ENCODE_LEN;
+		}
+	}
+
+	return 0;
+}

userspace/libsinsp/logger.h

@@ -76,6 +76,7 @@ class SINSP_PUBLIC sinsp_logger
 	const static uint32_t OT_FILE;
 	const static uint32_t OT_CALLBACK;
 	const static uint32_t OT_NOTS;
+	const static uint32_t OT_ENCODE_SEV;
 
 	/**
 	 * Initialize this sinsp_logger with no output sinks enabled.
@@ -107,6 +108,9 @@ class SINSP_PUBLIC sinsp_logger
 	/** Disables tagging logs with the current timestamp. */
 	void disable_timestamps();
 
+	/** Adds encoded severity to log messages */
+	void add_encoded_severity();
+
 	/**
 	 * Registered the given callback as the logging callback.
 	 *
@@ -154,6 +158,12 @@ class SINSP_PUBLIC sinsp_logger
 	 */
 	const char* format(const char* fmt, ...);
 
+	/** Sets `sev` to the decoded severity or SEV_MAX+1 for errors.
+	 *  Returns the length of the severity string on success
+	 *  and 0 in case of errors
+	 */
+	static size_t decode_severity(const std::string &s, severity& sev);
+
 private:
 	/** Returns true if the callback log sync is enabled, false otherwise. */
 	bool is_callback() const;
@@ -167,6 +177,9 @@ class SINSP_PUBLIC sinsp_logger
 	 */
 	static bool is_event_severity(severity sev);
 
+	/** Returns a string containing encoded severity, for OT_ENCODE_SEV. */
+	static const char* encode_severity(severity sev);
+
 	std::atomic<FILE*> m_file;
 	std::atomic<sinsp_logger_callback> m_callback;
 	std::atomic<uint32_t> m_flags;