feat(libsinsp): add logging capability to the plugin API

userspace/libsinsp/plugin.cpp

@@ -80,6 +80,13 @@ const char* sinsp_plugin::get_owner_last_error(ss_plugin_owner_t* o)
 	return t->m_last_owner_err.c_str();
 }
 
+static void plugin_log_fn(ss_plugin_owner_t* o, const char* component, const char* msg, ss_plugin_log_severity sev)
+{
+	auto t = static_cast<sinsp_plugin*>(o);
+	std::string prefix = (component == NULL) ? t->name() : std::string(component);
+	libsinsp_logger()->log(prefix + ": " + msg, (sinsp_logger::severity)sev);
+}
+
 std::shared_ptr<sinsp_plugin> sinsp_plugin::create(
 		const plugin_api* api,
 		const std::shared_ptr<libsinsp::state::table_registry>& treg,
@@ -167,6 +174,7 @@ bool sinsp_plugin::init(const std::string &config, std::string &errstr)
 	in.get_owner_last_error = sinsp_plugin::get_owner_last_error;
 	in.tables = NULL;
 	in.config = conf.c_str();
+	in.log_fn = &plugin_log_fn;
 
 	ss_plugin_init_tables_input tables_in = {};
 	ss_plugin_table_fields_vtable_ext table_fields_ext = {};

userspace/libsinsp/test/plugins.ut.cpp

@@ -640,3 +640,36 @@ TEST_F(sinsp_with_test_input, plugin_tables)
 	ASSERT_NO_THROW(table->clear_entries());
 	ASSERT_EQ(table->entries_count(), 0);
 }
+
+// Scenario: we load a plugin expecting it to log
+// when it's initialized and destroyed.
+// We use a callback attached to the logger to assert the message.
+// When the inspector goes out of scope,
+// the plugin is automatically destroyed.
+TEST(sinsp_plugin, plugin_logging)
+{
+	{
+		std::string tmp;
+		sinsp i;
+		plugin_api api;
+		get_plugin_api_sample_plugin_extract(api);
+
+		// the plugin is logging with a NULL component, so we expect the component to fallback to the plugin name
+		api.get_name = [](){ return "plugin_name"; };
+
+		libsinsp_logger()->add_callback_log([](std::string&& str, sinsp_logger::severity sev) {
+			std::string expected = "plugin_name: initializing plugin..."; 
+			ASSERT_TRUE(std::equal(expected.rbegin(), expected.rend(), str.rbegin()));
+		});
+
+		auto p = i.register_plugin(&api);
+		p->init("", tmp);
+
+		libsinsp_logger()->add_callback_log([](std::string&& str, sinsp_logger::severity sev) {
+			std::string expected = "plugin_name: destroying plugin..."; 
+			ASSERT_TRUE(std::equal(expected.rbegin(), expected.rend(), str.rbegin()));
+		});
+	}
+
+	libsinsp_logger()->remove_callback_log();
+}

userspace/libsinsp/test/plugins/plugin_extract.cpp

@@ -36,6 +36,8 @@ struct plugin_state
     std::string strstorage;
     const char* strptr;
     std::vector<uint16_t> event_types;
+    ss_plugin_owner_t* owner;
+    ss_plugin_log_fn_t log;
 };
 
 static const char* plugin_get_required_api_version()
@@ -94,6 +96,12 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
 {
     plugin_state *ret = new plugin_state();
 
+    //save logger and owner in the state
+    ret->log = in->log_fn;
+    ret->owner = in->owner;
+
+    ret->log(ret->owner, NULL, "initializing plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     // init config may indicate the comma-separated, event-types to filter
     std::string cfg = in->config;
     if (!cfg.empty())
@@ -122,6 +130,9 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
 
 static void plugin_destroy(ss_plugin_t* s)
 {
+    plugin_state *ps = (plugin_state *) s;
+    ps->log(ps->owner, NULL, "destroying plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     delete ((plugin_state *) s);
 }
 

userspace/libsinsp/test/plugins/plugin_source.cpp

@@ -34,6 +34,8 @@ static constexpr const char* s_evt_data = "hello world";
 struct plugin_state
 {
     std::string lasterr;
+    ss_plugin_owner_t* owner;
+    ss_plugin_log_fn_t log;
 };
 
 struct instance_state
@@ -85,12 +87,23 @@ static const char* plugin_get_last_error(ss_plugin_t* s)
 
 static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc)
 {
+    plugin_state *ret = new plugin_state();
+
+    //save logger and owner in the state
+    ret->log = in->log_fn;
+    ret->owner = in->owner;
+
+    ret->log(ret->owner, NULL, "initializing plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     *rc = SS_PLUGIN_SUCCESS;
-    return new plugin_state();
+    return ret;
 }
 
 static void plugin_destroy(ss_plugin_t* s)
 {
+    plugin_state *ps = (plugin_state *) s;
+    ps->log(ps->owner, NULL, "destroying plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     delete ((plugin_state *) s);
 }
 

userspace/libsinsp/test/plugins/syscall_async.cpp

@@ -41,6 +41,8 @@ struct plugin_state
     std::atomic<bool> async_thread_run;
     uint8_t async_evt_buf[2048];
     ss_plugin_event* async_evt;
+    ss_plugin_owner_t* owner;
+    ss_plugin_log_fn_t log;
 };
 
 static const char* plugin_get_required_api_version()
@@ -82,6 +84,13 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
 {
     *rc = SS_PLUGIN_SUCCESS;
     plugin_state *ret = new plugin_state();
+
+    //save logger and owner in the state
+    ret->log = in->log_fn;
+    ret->owner = in->owner;
+
+    ret->log(ret->owner, NULL, "initializing plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     ret->async_evt = (ss_plugin_event*) &ret->async_evt_buf;
     ret->async_thread_run = false;
     if (2 != sscanf(in->config, "%ld:%ld", &ret->async_maxevts, &ret->async_period))
@@ -95,6 +104,8 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
 static void plugin_destroy(ss_plugin_t* s)
 {
     plugin_state *ps = (plugin_state *) s;
+    ps->log(ps->owner, NULL, "destroying plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     // stop the async thread if it's running
     if (ps->async_thread_run)
     {

userspace/libsinsp/test/plugins/syscall_extract.cpp

@@ -43,6 +43,8 @@ struct plugin_state
     ss_plugin_table_field_t* thread_opencount_field;
     ss_plugin_table_t* evtcount_table;
     ss_plugin_table_field_t* evtcount_count_field;
+    ss_plugin_owner_t* owner;
+    ss_plugin_log_fn_t log;
 };
 
 static inline bool evt_type_is_open(uint16_t type)
@@ -155,6 +157,12 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
     *rc = SS_PLUGIN_SUCCESS;
     plugin_state *ret = new plugin_state();
 
+    //save logger and owner in the state
+    ret->log = in->log_fn;
+    ret->owner = in->owner;
+
+    ret->log(ret->owner, NULL, "initializing plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
 	// we have the extraction capability so the `in->tables` field should be != NULL
     if (!in || !in->tables)
     {
@@ -224,6 +232,9 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
 
 static void plugin_destroy(ss_plugin_t* s)
 {
+    plugin_state *ps = (plugin_state *) s;
+    ps->log(ps->owner, NULL, "destroying plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     delete ((plugin_state *) s);
 }
 

userspace/libsinsp/test/plugins/syscall_parse.cpp

@@ -40,6 +40,8 @@ struct plugin_state
     ss_plugin_table_field_t* thread_opencount_field;
     sample_table::ptr_t event_count_table;
     ss_plugin_table_field_t* event_count_table_count_field;
+    ss_plugin_owner_t* owner;
+    ss_plugin_log_fn_t log;
 };
 
 static inline bool evt_type_is_open(uint16_t type)
@@ -110,6 +112,12 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
     *rc = SS_PLUGIN_SUCCESS;
     plugin_state *ret = new plugin_state();
 
+    //save logger and owner in the state
+    ret->log = in->log_fn;
+    ret->owner = in->owner;
+
+    ret->log(ret->owner, NULL, "initializing plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     if (!in || !in->tables)
     {
         *rc = SS_PLUGIN_FAILURE;
@@ -164,6 +172,9 @@ static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc
 
 static void plugin_destroy(ss_plugin_t* s)
 {
+    plugin_state *ps = (plugin_state *) s;
+    ps->log(ps->owner, NULL, "destroying plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     delete ((plugin_state *) s);
 }
 

userspace/libsinsp/test/plugins/syscall_source.cpp

@@ -32,6 +32,8 @@ limitations under the License.
 struct plugin_state
 {
     std::string lasterr;
+    ss_plugin_owner_t* owner;
+    ss_plugin_log_fn_t log;
 };
 
 struct instance_state
@@ -73,12 +75,23 @@ static const char* plugin_get_last_error(ss_plugin_t* s)
 
 static ss_plugin_t* plugin_init(const ss_plugin_init_input* in, ss_plugin_rc* rc)
 {
+    plugin_state *ret = new plugin_state();
+
+    //save logger and owner in the state
+    ret->log = in->log_fn;
+    ret->owner = in->owner;
+
+    ret->log(ret->owner, NULL, "initializing plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     *rc = SS_PLUGIN_SUCCESS;
-    return new plugin_state();
+    return ret;
 }
 
 static void plugin_destroy(ss_plugin_t* s)
 {
+    plugin_state *ps = (plugin_state *) s;
+    ps->log(ps->owner, NULL, "destroying plugin...", SS_PLUGIN_LOG_SEV_INFO);
+
     delete ((plugin_state *) s);
 }
 

userspace/plugin/plugin_api.h

@@ -30,7 +30,7 @@ extern "C" {
 //
 // todo(jasondellaluce): when/if major changes to v4, check and solve all todos
 #define PLUGIN_API_VERSION_MAJOR 3
-#define PLUGIN_API_VERSION_MINOR 2
+#define PLUGIN_API_VERSION_MINOR 3
 #define PLUGIN_API_VERSION_PATCH 0
 
 //
@@ -267,6 +267,15 @@ typedef struct
 	ss_plugin_table_fields_vtable_ext* fields_ext;
 } ss_plugin_init_tables_input;
 
+// Function used by plugin for sending messages to the framework-provided logger
+// Arguments:
+//  - component: name of the component that is logging
+//			(if set to NULL automatically falls back to the plugin name in the log)
+//  - msg: message to log 
+//			(it doesn't have to be '\n' terminated)
+//  - sev: message severity as defined in ss_plugin_log_severity
+typedef void (*ss_plugin_log_fn_t)(ss_plugin_owner_t* o, const char* component, const char* msg, ss_plugin_log_severity sev);
+
 // Input passed at the plugin through plugin_init(). This contain information
 // common to any plugin, and also information useful only in case the plugin
 // implements a given capability. If a certain capability is not implemented
@@ -279,6 +288,7 @@ typedef struct ss_plugin_init_input
 	//
 	// The plugin's owner. Can be passed by the plugin to the callbacks available
 	// in this struct in order to invoke functions of its owner.
+	// It doesn't change during the whole plugin's lifecycle, it's safe to store it in the state
 	ss_plugin_owner_t* owner;
 	//
 	// Return a string with the error that was last generated by the plugin's
@@ -291,6 +301,10 @@ typedef struct ss_plugin_init_input
 	// capabilities. The callbacks available in this input take the plugin's owner
 	// as a parameter.
 	const ss_plugin_init_tables_input* tables;
+	//
+	// Log function passed to the plugin through the init input
+	// It doesn't change during the whole plugin's lifecycle, it's safe to store it in the state
+	ss_plugin_log_fn_t log_fn;
 } ss_plugin_init_input;
 
 // Input passed to the plugin when extracting a field from an event for

userspace/plugin/plugin_types.h

@@ -279,6 +279,20 @@ typedef void ss_plugin_t;
 //
 typedef void ss_instance_t;
 
+//
+// Severity available in the logging facility provided by the framework
+typedef enum ss_plugin_log_severity
+{
+	SS_PLUGIN_LOG_SEV_FATAL = 1,
+	SS_PLUGIN_LOG_SEV_CRITICAL = 2,
+	SS_PLUGIN_LOG_SEV_ERROR = 3,
+	SS_PLUGIN_LOG_SEV_WARNING = 4,
+	SS_PLUGIN_LOG_SEV_NOTICE = 5,
+	SS_PLUGIN_LOG_SEV_INFO = 6,
+	SS_PLUGIN_LOG_SEV_DEBUG = 7,
+	SS_PLUGIN_LOG_SEV_TRACE = 8,
+} ss_plugin_log_severity;
+
 #ifdef __cplusplus
 }
 #endif