Merge remote-tracking branch 'origin/topic/robin/gh-1179-plugin-loading'

* origin/topic/robin/gh-1179-plugin-loading:
  Retry loading plugins on failure to resolve to dependencies.
  Fix use of deprecated functionality in test.
  When attempting to activate a plugin, load dynamic libraries first.
  Add test creating multiple plugins with load dependencies.

CHANGES

@@ -1,3 +1,9 @@
+
+3.3.0-dev.585 | 2020-12-01 14:42:54 +0000
+
+  * Retry loading plugins on failure to resolve to dependencies.
+    Closes #1179. (Robin Sommer, Corelight)
+
 3.3.0-dev.580 | 2020-11-30 14:07:39 -0700
 
   * Find correct zeek namespace in debug logger macros.

VERSION

@@ -1 +1 @@
-3.3.0-dev.580
+3.3.0-dev.585

src/plugin/Manager.cc

@@ -140,7 +140,7 @@ void Manager::SearchDynamicPlugins(const std::string& dir)
 	closedir(d);
 	}
 
-bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_not_found)
+bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_not_found, std::vector<std::string>* errors)
 	{
 	dynamic_plugin_map::iterator m = dynamic_plugins.find(util::strtolower(name));
 
@@ -160,7 +160,7 @@ bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_
 				return true;
 			}
 
-		reporter->Error("plugin %s is not available", name.c_str());
+		errors->push_back(util::fmt("plugin %s is not available", name.c_str()));
 		return false;
 		}
 
@@ -175,58 +175,6 @@ bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_
 
 	DBG_LOG(DBG_PLUGINS, "Activating plugin %s", name.c_str());
 
-	// Add the "scripts" and "bif" directories to ZEEKPATH.
-	std::string scripts = dir + "scripts";
-
-	if ( util::is_dir(scripts) )
-		{
-		DBG_LOG(DBG_PLUGINS, "  Adding %s to ZEEKPATH", scripts.c_str());
-		util::detail::add_to_zeek_path(scripts);
-		}
-
-	string init;
-
-	// First load {scripts}/__preload__.zeek automatically.
-	for (const string& ext : util::detail::script_extensions)
-		{
-		init = dir + "scripts/__preload__" + ext;
-
-		if ( util::is_file(init) )
-			{
-			DBG_LOG(DBG_PLUGINS, "  Loading %s", init.c_str());
-			util::detail::warn_if_legacy_script(init);
-			scripts_to_load.push_back(init);
-			break;
-			}
-		}
-
-	// Load {bif,scripts}/__load__.zeek automatically.
-	for (const string& ext : util::detail::script_extensions)
-		{
-		init = dir + "lib/bif/__load__" + ext;
-
-		if ( util::is_file(init) )
-			{
-			DBG_LOG(DBG_PLUGINS, "  Loading %s", init.c_str());
-			util::detail::warn_if_legacy_script(init);
-			scripts_to_load.push_back(init);
-			break;
-			}
-		}
-
-	for (const string& ext : util::detail::script_extensions)
-		{
-		init = dir + "scripts/__load__" + ext;
-
-		if ( util::is_file(init) )
-			{
-			DBG_LOG(DBG_PLUGINS, "  Loading %s", init.c_str());
-			util::detail::warn_if_legacy_script(init);
-			scripts_to_load.push_back(init);
-			break;
-			}
-		}
-
 	// Load shared libraries.
 
 	string dypattern = dir + "/lib/*." + HOST_ARCHITECTURE + DYNAMIC_PLUGIN_SUFFIX;
@@ -244,16 +192,19 @@ bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_
 			current_plugin = nullptr;
 			current_dir = dir.c_str();
 			current_sopath = path;
-			void* hdl = dlopen(path, RTLD_LAZY | RTLD_GLOBAL);
+			void* hdl = dlopen(path, RTLD_NOW | RTLD_GLOBAL);
 
 			if ( ! hdl )
 				{
 				const char* err = dlerror();
-				reporter->FatalError("cannot load plugin library %s: %s", path, err ? err : "<unknown error>");
+				errors->push_back(util::fmt("cannot load plugin library %s: %s", path, err ? err : "<unknown error>"));
+				return false;
 				}
 
-			if ( ! current_plugin )
-				reporter->FatalError("load plugin library %s did not instantiate a plugin", path);
+			if ( ! current_plugin ) {
+				errors->push_back(util::fmt("load plugin library %s did not instantiate a plugin", path));
+				return false;
+			}
 
 			current_plugin->SetDynamic(true);
 			current_plugin->DoConfigure();
@@ -269,9 +220,11 @@ bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_
 
 			// Make sure the name the plugin reports is consistent with
 			// what we expect from its magic file.
-			if ( util::strtolower(current_plugin->Name()) != util::strtolower(name) )
-				reporter->FatalError("inconsistent plugin name: %s vs %s",
-						     current_plugin->Name().c_str(), name.c_str());
+			if ( util::strtolower(current_plugin->Name()) != util::strtolower(name) ) {
+				errors->push_back(util::fmt("inconsistent plugin name: %s vs %s",
+						     current_plugin->Name().c_str(), name.c_str()));
+				return false;
+			}
 
 			current_dir = nullptr;
 			current_sopath = nullptr;
@@ -288,43 +241,124 @@ bool Manager::ActivateDynamicPluginInternal(const std::string& name, bool ok_if_
 		DBG_LOG(DBG_PLUGINS, "  No shared library found");
 		}
 
+	// Add the "scripts" and "bif" directories to ZEEKPATH.
+	std::string scripts = dir + "scripts";
+
+	if ( util::is_dir(scripts) )
+		{
+		DBG_LOG(DBG_PLUGINS, "  Adding %s to ZEEKPATH", scripts.c_str());
+		util::detail::add_to_zeek_path(scripts);
+		}
+
+	string init;
+
+	// First load {scripts}/__preload__.zeek automatically.
+	for (const string& ext : util::detail::script_extensions)
+		{
+		init = dir + "scripts/__preload__" + ext;
+
+		if ( util::is_file(init) )
+			{
+			DBG_LOG(DBG_PLUGINS, "  Loading %s", init.c_str());
+			util::detail::warn_if_legacy_script(init);
+			scripts_to_load.push_back(init);
+			break;
+			}
+		}
+
+	// Load {bif,scripts}/__load__.zeek automatically.
+	for (const string& ext : util::detail::script_extensions)
+		{
+		init = dir + "lib/bif/__load__" + ext;
+
+		if ( util::is_file(init) )
+			{
+			DBG_LOG(DBG_PLUGINS, "  Loading %s", init.c_str());
+			util::detail::warn_if_legacy_script(init);
+			scripts_to_load.push_back(init);
+			break;
+			}
+		}
+
+	for (const string& ext : util::detail::script_extensions)
+		{
+		init = dir + "scripts/__load__" + ext;
+
+		if ( util::is_file(init) )
+			{
+			DBG_LOG(DBG_PLUGINS, "  Loading %s", init.c_str());
+			util::detail::warn_if_legacy_script(init);
+			scripts_to_load.push_back(init);
+			break;
+			}
+		}
+
 	// Mark this plugin as activated by clearing the path.
 	m->second.clear();
 
 	return true;
 	}
 
-bool Manager::ActivateDynamicPlugin(const std::string& name)
+void Manager::ActivateDynamicPlugin(const std::string& name)
 	{
-	if ( ! ActivateDynamicPluginInternal(name) )
-		return false;
-
-	UpdateInputFiles();
-	return true;
+	std::vector<std::string> errors;
+	if ( ActivateDynamicPluginInternal(name, false, &errors) )
+		UpdateInputFiles();
+	else
+		// Reschedule for another attempt later.
+		requested_plugins.insert(std::move(name));
 	}
 
-bool Manager::ActivateDynamicPlugins(bool all)
-	{
+void Manager::ActivateDynamicPlugins(bool all) {
+	// Tracks plugins we need to activate as pairs of their names and booleans
+	// indicating whether an activation failure is to be deemed a fatal error.
+	std::set<std::pair<std::string, bool>> plugins_to_activate;
+
+	// Activate plugins that were specifically requested.
+	for ( const auto& x : requested_plugins )
+		plugins_to_activate.emplace(x, false);
+
 	// Activate plugins that our environment tells us to.
 	vector<string> p;
 	util::tokenize_string(util::zeek_plugin_activate(), ",", &p);
 
-	for ( size_t n = 0; n < p.size(); ++n )
-		ActivateDynamicPluginInternal(p[n], true);
+	for ( const auto& x : p )
+		plugins_to_activate.emplace(x, true);
 
 	if ( all )
 		{
-		for ( dynamic_plugin_map::const_iterator i = dynamic_plugins.begin();
-		      i != dynamic_plugins.end(); i++ )
+		// Activate all other ones we discovered.
+		for ( const auto& x : dynamic_plugins )
+			plugins_to_activate.emplace(x.first, false);
+		}
+
+	// Now we keep iterating over all the plugins, trying to load them, for as
+	// long as we're successful for at least one further of them each round.
+	// Doing so ensures that we can resolve (non-cyclic) load dependencies
+	// independent of any particular order.
+	while ( ! plugins_to_activate.empty() ) {
+		std::vector<std::string> errors;
+		auto plugins_left = plugins_to_activate;
+
+		for ( const auto& x : plugins_to_activate )
 			{
-			if ( ! ActivateDynamicPluginInternal(i->first) )
-				return false;
+			if ( ActivateDynamicPluginInternal(x.first, x.second, &errors) )
+				plugins_left.erase(x);
+			}
+
+		if ( plugins_left.size() == plugins_to_activate.size() )
+			{
+			// Could not load a single further plugin this round, that's fatal.
+			for ( const auto& msg : errors )
+				reporter->Error("%s", msg.c_str());
+
+			reporter->FatalError("aborting after plugin errors");
 			}
+
+		plugins_to_activate = std::move(plugins_left);
 		}
 
 	UpdateInputFiles();
-
-	return true;
 	}
 
 void Manager::UpdateInputFiles()

src/plugin/Manager.h

@@ -2,9 +2,10 @@
 
 #pragma once
 
-#include <utility>
 #include <map>
+#include <set>
 #include <string_view>
+#include <utility>
 
 #include "zeek/plugin/Plugin.h"
 #include "zeek/plugin/Component.h"
@@ -79,28 +80,25 @@ class Manager
 	 * Activating a plugin involves loading its dynamic module, making its
 	 * bifs available, and adding its script paths to ZEEKPATH.
 	 *
-	 * @param name The name of the plugin, as found previously by
-	 * SearchPlugin().
-	 *
-	 * @return True if the plugin has been loaded successfully.
+	 * This attempts to activate the plugin immediately. If that fails for
+	 * some reason, we schedule it to be retried later with
+	 * ActivateDynamicPlugins().
 	 *
+	 * @param name The name of the plugin, as found previously by
+	·* SearchPlugin().
 	 */
-	bool ActivateDynamicPlugin(const std::string& name);
+	void ActivateDynamicPlugin(const std::string& name);
 
 	/**
-	 * Activates plugins that SearchDynamicPlugins() has previously discovered.
-	 * The effect is the same all calling \a ActivePlugin(name) for each plugin.
+	 * Activates plugins that SearchDynamicPlugins() has previously discovered,
+	 * including any that have failed to load in prior calls to
+	 * ActivateDynamicPlugin(). Aborts if any plugins fails to activate.
 	 *
 	 * @param all If true, activates all plugins that are found. If false,
 	 * activates only those that should always be activated unconditionally,
-	 * as specified via the ZEEK_PLUGIN_ACTIVATE enviroment variable. In other
-	 * words, it's \c true in standard mode and \c false in bare mode.
-	 *
-	 * @return True if all plugins have been loaded successfully. If one
-	 * fails to load, the method stops there without loading any further ones
-	 * and returns false.
+	 * as specified via the ZEEK_PLUGIN_ACTIVATE environment variable.
 	 */
-	bool ActivateDynamicPlugins(bool all);
+	void ActivateDynamicPlugins(bool all);
 
 	/**
 	 * First-stage initializion of the manager. This is called early on
@@ -413,11 +411,15 @@ class Manager
 	static void RegisterBifFile(const char* plugin, bif_init_func c);
 
 private:
-	bool ActivateDynamicPluginInternal(const std::string& name, bool ok_if_not_found = false);
+	bool ActivateDynamicPluginInternal(const std::string& name, bool ok_if_not_found, std::vector<std::string>* errors);
 	void UpdateInputFiles();
 	void MetaHookPre(HookType hook, const HookArgumentList& args) const;
 	void MetaHookPost(HookType hook, const HookArgumentList& args, HookArgument result) const;
 
+	// Plugins that were explicitly requested to be activated, but failed to
+	// load at first.
+	std::set<std::string> requested_plugins;
+
 	 // All found dynamic plugins, mapping their names to base directory.
 	using dynamic_plugin_map = std::map<std::string, std::string>;
 	dynamic_plugin_map dynamic_plugins;

src/zeek-setup.cc

@@ -604,17 +604,8 @@ SetupResult setup(int argc, char** argv, Options* zopts)
 	file_mgr->InitPreScript();
 	zeekygen_mgr->InitPreScript();
 
-	bool missing_plugin = false;
-
-	for ( set<string>::const_iterator i = requested_plugins.begin();
-	      i != requested_plugins.end(); i++ )
-		{
-		if ( ! plugin_mgr->ActivateDynamicPlugin(*i) )
-			missing_plugin = true;
-		}
-
-	if ( missing_plugin )
-		reporter->FatalError("Failed to activate requested dynamic plugin(s).");
+	for ( const auto& x : requested_plugins )
+		plugin_mgr->ActivateDynamicPlugin(std::move(x));
 
 	plugin_mgr->ActivateDynamicPlugins(! options.bare_mode);
 

testing/btest/Baseline/plugins.plugin-load-dependency/output

@@ -0,0 +1,18 @@
+### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63.
+Testing::Plugin2 - Plugin2 provides a load dependency for Plugin1 and Plugin3 (dynamic, version 1.0.0)
+Testing::Plugin3 - Plugin3 has a load dependency on Plugin2 (dynamic, version 1.0.0)
+in Plugin2
+in Plugin3
+
+Testing::Plugin1 - Plugin1 has a load dependency on Plugin2 (dynamic, version 1.0.0)
+Testing::Plugin2 - Plugin2 provides a load dependency for Plugin1 and Plugin3 (dynamic, version 1.0.0)
+in Plugin1
+in Plugin2
+
+Testing::Plugin1 - Plugin1 has a load dependency on Plugin2 (dynamic, version 1.0.0)
+Testing::Plugin2 - Plugin2 provides a load dependency for Plugin1 and Plugin3 (dynamic, version 1.0.0)
+Testing::Plugin3 - Plugin3 has a load dependency on Plugin2 (dynamic, version 1.0.0)
+in Plugin1
+in Plugin2
+in Plugin2
+in Plugin3

testing/btest/plugins/bifs-and-scripts.sh

@@ -51,7 +51,7 @@ EOF
 cat >src/foo.bif <<EOF
 function hello_plugin_world%(%): string
         %{
-        return new StringVal("Hello from the plugin!");
+        return make_intrusive<StringVal>("Hello from the plugin!");
         %}
 
 event plugin_event%(foo: count%);