FOGL-7959 Improve error handling for plugin load failure (#1142)

* Error reporting improvements Signed-off-by: Mark Riddoch <[email protected]> * Improve JSON parse error reporting Signed-off-by: Mark Riddoch <[email protected]> * FOGL-7959 Capture some of the common reasons plugins fail to load Signed-off-by: Mark Riddoch <[email protected]> * Fix typos Signed-off-by: Mark Riddoch <[email protected]> * Removing using namespace from string_utils header file Signed-off-by: Mark Riddoch <[email protected]> * Removing using namespace from string_utils header file Signed-off-by: Mark Riddoch <[email protected]> * Update test Signed-off-by: Mark Riddoch <[email protected]> * Update tests Signed-off-by: Mark Riddoch <[email protected]> * Fix unit tests Signed-off-by: Mark Riddoch <[email protected]> * Test checkin to add loggign to PR unit tester Signed-off-by: Mark Riddoch <[email protected]> * Using -j1 in RunAllTests Signed-off-by: Mark Riddoch <[email protected]> * Using -j1 in RunAllTests Signed-off-by: Mark Riddoch <[email protected]> * Include strign_utils in postgres test Signed-off-by: Mark Riddoch <[email protected]> * Use entire common library for Postgres test Signed-off-by: Mark Riddoch <[email protected]> * Add library location Signed-off-by: Mark Riddoch <[email protected]> * Add extra library requirements Signed-off-by: Mark Riddoch <[email protected]> --------- Signed-off-by: Mark Riddoch <[email protected]>
fledge-iot · Aug 18, 2023 · 1633a64 · 1633a64
1 parent 308dce9
commit 1633a64
Show file tree

Hide file tree

Showing 12 changed files with 172 additions and 30 deletions.
diff --git a/C/common/config_category.cpp b/C/common/config_category.cpp
@@ -20,6 +20,7 @@
 #include <stdlib.h>
 #include <logger.h>
 #include <stdexcept>
+#include <string_utils.h>
 
 
 using namespace std;
@@ -44,8 +45,8 @@ ConfigCategories::ConfigCategories(const std::string& json)
 	doc.Parse(json.c_str());
 	if (doc.HasParseError())
 	{
-		Logger::getLogger()->error("Configuration parse error in %s: %s at %d", json.c_str(),
-			GetParseError_En(doc.GetParseError()), (unsigned)doc.GetErrorOffset());
+		Logger::getLogger()->error("Configuration parse error in %s: %s at %d, '%s'", json.c_str(),
+			GetParseError_En(doc.GetParseError()), (unsigned)doc.GetErrorOffset(), StringAround(json, (unsigned)doc.GetErrorOffset()).c_str());
 		throw new ConfigMalformed();
 	}
 	if (doc.HasMember("categories"))
@@ -140,9 +141,10 @@ ConfigCategory::ConfigCategory(const string& name, const string& json) : m_name(
 	doc.Parse(json.c_str());
 	if (doc.HasParseError())
 	{
-		Logger::getLogger()->error("Configuration parse error in category '%s', %s: %s at %d",
+		Logger::getLogger()->error("Configuration parse error in category '%s', %s: %s at %d, '%s'",
 			name.c_str(), json.c_str(),
-			GetParseError_En(doc.GetParseError()), (unsigned)doc.GetErrorOffset());
+			GetParseError_En(doc.GetParseError()), (unsigned)doc.GetErrorOffset(),
+			StringAround(json, (unsigned)doc.GetErrorOffset()));
 		throw new ConfigMalformed();
 	}
 
@@ -1117,10 +1119,14 @@ ConfigCategory::CategoryItem::CategoryItem(const string& name,
 			check.Parse(m_value.c_str());
 			if (check.HasParseError())
 			{
+				Logger::getLogger()->error("The JSON configuration item %s has a parse error: %s",
+					m_name.c_str(), GetParseError_En(check.GetParseError()));
 				throw new runtime_error(GetParseError_En(check.GetParseError()));
 			}
 			if (!check.IsObject())
 			{
+				Logger::getLogger()->error("The JSON configuration item %s is not a valid JSON objects",
+						m_name.c_str());
 				throw new runtime_error("'value' JSON property is not an object");
 			}
 		}
@@ -1221,10 +1227,14 @@ ConfigCategory::CategoryItem::CategoryItem(const string& name,
 			check.Parse(m_default.c_str());
 			if (check.HasParseError())
 			{
+				Logger::getLogger()->error("The JSON configuration item %s has a parse error in the default value: %s",
+					m_name.c_str(), GetParseError_En(check.GetParseError()));
 				throw new runtime_error(GetParseError_En(check.GetParseError()));
 			}
 			if (!check.IsObject())
 			{
+				Logger::getLogger()->error("The JSON configuration item %s default is not a valid JSON object",
+						m_name.c_str());
 				throw new runtime_error("'default' JSON property is not an object");
 			}
 		}

diff --git a/C/common/include/string_utils.h b/C/common/include/string_utils.h
@@ -14,7 +14,6 @@
 #include <sstream>
 #include <iomanip>
 
-using namespace std;
 
 void StringReplace(std::string& StringToManage,
 		   const std::string& StringToSearch,
@@ -24,25 +23,28 @@ void StringReplaceAll(std::string& StringToManage,
 					  const std::string& StringToSearch,
 					  const std::string& StringReplacement);
 
-string StringSlashFix(const string& stringToFix);
+std::string StringSlashFix(const std::string& stringToFix);
 std::string evaluateParentPath(const std::string& path, char separator);
 std::string extractLastLevel(const std::string& path, char separator);
 
 void   StringStripCRLF(std::string& StringToManage);
-string StringStripWhiteSpacesAll(const std::string& original);
-string StringStripWhiteSpacesExtra(const  std::string& original);
+std::string StringStripWhiteSpacesAll(const std::string& original);
+std::string StringStripWhiteSpacesExtra(const  std::string& original);
 void StringStripQuotes(std::string& StringToManage);
 
-string urlEncode(const string& s);
-string urlDecode(const string& s);
-void StringEscapeQuotes(string& s);
+std::string urlEncode(const std::string& s);
+std::string urlDecode(const std::string& s);
+void StringEscapeQuotes(std::string& s);
 
 char *trim(char *str);
 std::string StringLTrim(const std::string& str);
 std::string StringRTrim(const std::string& str);
 std::string StringTrim(const std::string& str);
 
-bool IsRegex(const string &str);
+bool IsRegex(const std::string &str);
+
+std::string StringAround(const std::string& str, unsigned int pos,
+		unsigned int after = 30, unsigned int before = 10);
 
 
 #endif
diff --git a/C/common/string_utils.cpp b/C/common/string_utils.cpp
@@ -445,3 +445,20 @@ bool IsRegex(const string &str) {
 
 	return (nChar != 0);
 }
+
+/**
+ * Return a new string that extracts from the passed in string either side
+ * of a position within the string.
+ *
+ * @param str	The string to return a portion of
+ * @param pos	The position around which to extract a portion
+ * @param after	The number of characters after the position to return, defaults to 30 if omitted
+ * @param before The number of characters before the position to return, defaults to 10
+ */
+std::string StringAround(const std::string& str, unsigned int pos,
+		unsigned int after, unsigned int before)
+{
+	size_t	start = pos > before ? (pos - before) : 0;
+	size_t	len = before + after;
+	return str.substr(start, len);
+}
diff --git a/C/plugins/utils/get_plugin_info.cpp b/C/plugins/utils/get_plugin_info.cpp
@@ -41,22 +41,23 @@ int main(int argc, char *argv[])
     exit(1);
   }
 
+  openlog("Fledge PluginInfo", LOG_PID|LOG_CONS, LOG_USER);
+  setlogmask(LOG_UPTO(LOG_WARNING));
+
   if (access(argv[1], F_OK|R_OK) != 0)
   {
-    fprintf(stderr, "Unable to access library file '%s', exiting...\n", argv[1]);
+    syslog(LOG_ERR, "Unable to access library file '%s', exiting...\n", argv[1]);
     exit(2);
   }
 
-  openlog(argv[0], LOG_PID|LOG_CONS, LOG_USER);
-  setlogmask(LOG_UPTO(LOG_WARNING));
 
   if ((hndl = dlopen(argv[1], RTLD_GLOBAL|RTLD_LAZY)) != NULL)
   {
     func_t infoEntry = (func_t)dlsym(hndl, routine);
     if (infoEntry == NULL)
     {
       // Unable to find plugin_info entry point
-      fprintf(stderr, "Plugin library %s does not support %s function : %s\n", argv[1], routine, dlerror());
+      syslog(LOG_ERR, "Plugin library %s does not support %s function : %s\n", argv[1], routine, dlerror());
       dlclose(hndl);
       closelog();
       exit(3);
@@ -66,7 +67,7 @@ int main(int argc, char *argv[])
   }
   else
   {
-    fprintf(stderr, "dlopen failed: %s\n", dlerror());
+    syslog(LOG_ERR, "dlopen failed: %s\n", dlerror());
   }
   closelog();
 

diff --git a/C/services/common/include/binary_plugin_handle.h b/C/services/common/include/binary_plugin_handle.h
@@ -24,14 +24,26 @@ class BinaryPluginHandle : public PluginHandle
 	public:
 		// for the Storage plugin
 		BinaryPluginHandle(const char *name, const char *path, tPluginType type) {
+			dlerror();	// Clear the existing error
 			handle = dlopen(path, RTLD_LAZY);
+			if (!handle)
+			{
+				Logger::getLogger()->error("Unable to load storage plugin %s, %s",
+						name, dlerror());
+			}
 
 			Logger::getLogger()->debug("%s - storage plugin / RTLD_LAZY - name :%s: path :%s:", __FUNCTION__, name, path);
 		}
 
 		// for all the others plugins
 		BinaryPluginHandle(const char *name, const char *path)                   {
+			dlerror();	// Clear the existing error
 			handle = dlopen(path, RTLD_LAZY|RTLD_GLOBAL);
+			if (!handle)
+			{
+				Logger::getLogger()->error("Unable to load plugin %s, %s",
+						name, dlerror());
+			}
 
 			Logger::getLogger()->debug("%s - other plugin / RTLD_LAZY|RTLD_GLOBAL - name :%s: path :%s:", __FUNCTION__, name, path);
 		}

diff --git a/C/services/common/include/plugin_manager.h b/C/services/common/include/plugin_manager.h
@@ -58,6 +58,7 @@ class PluginManager {
 
 	private:
                 PluginManager();
+		std::string	findPlugin(std::string name, std::string _type, std::string _plugin_path, PLUGIN_TYPE type);
 
 	private:
                 std::list<PLUGIN_HANDLE>		plugins;
@@ -69,7 +70,7 @@ class PluginManager {
                 std::map<PLUGIN_HANDLE, PluginHandle*>
 							pluginHandleMap;
                 Logger*					logger;
-				tPluginType				m_pluginType;
+		tPluginType				m_pluginType;
 };
 
 #endif
diff --git a/C/services/common/plugin_manager.cpp b/C/services/common/plugin_manager.cpp
@@ -28,6 +28,7 @@
 #include "rapidjson/error/en.h"
 #include <algorithm>
 #include <config_category.h>
+#include <string_utils.h>
 
 using namespace std;
 using namespace rapidjson;
@@ -77,15 +78,19 @@ void updateJsonPluginConfig(PLUGIN_INFORMATION *info, string json_plugin_name, s
 	doc.Parse(json_plugin_defaults.c_str());
 	if (doc.HasParseError())
 	{
-		logger->error("doc JSON parsing failed");
+		logger->error("Parse error in plugin '%s' defaults: %s at %d '%s'", json_plugin_name.c_str(),
+					GetParseError_En(doc.GetParseError()), (unsigned)doc.GetErrorOffset(),
+                        StringAround(json_plugin_defaults, (unsigned)doc.GetErrorOffset()));
 		return;
 	}
 
 	Document docBase;
 	docBase.Parse(info->config);
 	if (docBase.HasParseError())
 	{
-		logger->error("docBase JSON parsing failed");
+		logger->error("Parse error in plugin '%s' information defaults: %s at %d '%s'", json_plugin_name.c_str(),
+					GetParseError_En(doc.GetParseError()), (unsigned)doc.GetErrorOffset(),
+                        			StringAround(info->config, (unsigned)doc.GetErrorOffset()));
 		return;
 	}
 
@@ -176,7 +181,9 @@ void updateJsonPluginConfig(PLUGIN_INFORMATION *info, string json_plugin_name, s
 	doc2.Parse(info->config);
 	if (doc2.HasParseError())
 	{
-		logger->error("doc2 JSON parsing failed");
+		logger->error("Parse error in information returned from plugin: %s at %d '%s'", 
+					GetParseError_En(doc2.GetParseError()), (unsigned)doc2.GetErrorOffset(),
+                        			StringAround(info->config, (unsigned)doc2.GetErrorOffset()));
 	}
 	if (doc2.HasMember("plugin"))
 	{
@@ -208,7 +215,7 @@ void updateJsonPluginConfig(PLUGIN_INFORMATION *info, string json_plugin_name, s
  * @param    type		The plugin type
  * @return   string		The absolute path of plugin
  */
-string findPlugin(string name, string _type, string _plugin_path, PLUGIN_TYPE type)
+string PluginManager::findPlugin(string name, string _type, string _plugin_path, PLUGIN_TYPE type)
 {
 	if (type != BINARY_PLUGIN && type != PYTHON_PLUGIN && type != JSON_PLUGIN)
 	{

diff --git a/python/fledge/services/core/api/utils.py b/python/fledge/services/core/api/utils.py
@@ -27,6 +27,9 @@ def get_plugin_info(name, dir):
         out, err = p.communicate()
         res = out.decode("utf-8")
         jdoc = json.loads(res)
+    except json.decoder.JSONDecodeError as err:
+        _logger.error("Failed to parse JSON data returned from the plugin information of {}, {} line {} column {}".format(name, err.msg, err.lineno, err.colno))
+        return {}
     except (OSError, ValueError) as err:
         _logger.error(err, "{} C plugin get info failed.".format(name))
         return {}

diff --git a/tests/unit/C/common/test_config_category.cpp b/tests/unit/C/common/test_config_category.cpp
@@ -324,6 +324,23 @@ const char *optionals =
 
 const char *json_quotedSpecial = R"QS({ "key" : "test \"a\"", "description" : "Test \"description\"", "value" : {"description" : { "description" : "The description of this \"Fledge\" service", "type" : "string", "value" : "The \"Fledge\" admini\\strative API", "default" : "The \"Fledge\" administra\tive API" }, "name" : { "description" : "The name of this \"Fledge\" service", "type" : "string", "value" : "\"Fledge\"", "default" : "\"Fledge\"" }, "complex" : { "description" : "A JSON configuration parameter", "type" : "json", "value" : {"first":"Fledge","second":"json"}, "default" : {"first":"Fledge","second":"json"} }} })QS";
 
+const char *json_parse_error = "{\"description\": {"
+		"\"value\": \"The Fledge administrative API\","
+		"\"type\": \"string\","
+		"\"default\": \"The Fledge administrative API\","
+		"\"description\": \"The description of this Fledge service\"},"
+	"\"name\": {"
+		"\"value\": \"Fledge\","
+		"\"type\": \"string\","
+		"\"default\": \"Fledge\","
+		"\"description\": \"The name of this Fledge service\"},"
+		"error : here,"
+        "\"complex\": {" \
+		"\"value\": { \"first\" : \"Fledge\", \"second\" : \"json\" },"
+		"\"type\": \"json\","
+		"\"default\": {\"first\" : \"Fledge\", \"second\" : \"json\" },"
+		"\"description\": \"A JSON configuration parameter\"}}";
+
 TEST(CategoriesTest, Count)
 {
 	ConfigCategories confCategories(categories);
@@ -654,3 +671,8 @@ TEST(CategoryTestQuoted, toJSONQuotedSpecial)
 	confCategory.setDescription("Test \"description\"");
 	ASSERT_EQ(0, confCategory.toJSON().compare(json_quotedSpecial));
 }
+
+TEST(Categorytest, parseError)
+{
+	EXPECT_THROW(ConfigCategory("parseTest", json_parse_error), ConfigMalformed*);
+}
diff --git a/tests/unit/C/common/test_string_utils.cpp b/tests/unit/C/common/test_string_utils.cpp
@@ -215,4 +215,15 @@ TEST(TestIsRegex, AllCases)
 
 
 
-
+TEST(TestAround, Extract)
+{
+	string longString("not shownpreamble123This part is after the location");
+	string s = StringAround(longString, 19);
+	EXPECT_STREQ(s.c_str(), "preamble123This part is after the locati");
+	s = StringAround(longString, 19, 10);
+	EXPECT_STREQ(s.c_str(), "preamble123This part");
+	s = StringAround(longString, 19, 10, 5);
+	EXPECT_STREQ(s.c_str(), "ble123This part");
+	s = StringAround(longString, 5);
+	EXPECT_STREQ(s.c_str(), "not shownpreamble123This part is after t");
+}
diff --git a/tests/unit/C/scripts/RunAllTests.sh b/tests/unit/C/scripts/RunAllTests.sh
@@ -34,8 +34,8 @@ if [ ! -d results ] ; then
 fi
 
 if [ -f "./CMakeLists.txt" ] ; then
-	echo -n "Compiling libraries..."
-	(rm -rf build && mkdir -p build && cd build && cmake -DCMAKE_BUILD_TYPE=Debug .. && make ${jobs} && cd ..) > /dev/null
+	echo "Compiling libraries..."
+	(rm -rf build && mkdir -p build && cd build && cmake -DCMAKE_BUILD_TYPE=Debug .. && make ${jobs} && cd ..) 
 	echo "done"
 fi