[Quests] Improve Quest Error Handling (#2635)

* Improve Quest Error handling

* Update embperl.cpp

* Bench test (temp)

* Swap log category for benchmark

* Swap external process invocation for native Perl eval throw

common/eqemu_logsys.cpp

@@ -140,6 +140,8 @@ EQEmuLogSys *EQEmuLogSys::LoadLogSettingsDefaults()
 	log_settings[Logs::ChecksumVerification].log_to_gmsay   = static_cast<uint8>(Logs::General);
 	log_settings[Logs::CombatRecord].log_to_gmsay           = static_cast<uint8>(Logs::General);
 	log_settings[Logs::Discord].log_to_console              = static_cast<uint8>(Logs::General);
+	log_settings[Logs::QuestErrors].log_to_gmsay            = static_cast<uint8>(Logs::General);
+	log_settings[Logs::QuestErrors].log_to_console          = static_cast<uint8>(Logs::General);
 
 	/**
 	 * RFC 5424
@@ -254,6 +256,7 @@ uint16 EQEmuLogSys::GetWindowsConsoleColorFromCategory(uint16 log_category)
 			return Console::Color::Yellow;
 		case Logs::MySQLError:
 		case Logs::Error:
+		case Logs::QuestErrors:
 			return Console::Color::LightRed;
 		case Logs::MySQLQuery:
 		case Logs::Debug:
@@ -281,6 +284,7 @@ std::string EQEmuLogSys::GetLinuxConsoleColorFromCategory(uint16 log_category)
 		case Logs::Normal:
 			return LC_YELLOW;
 		case Logs::MySQLError:
+		case Logs::QuestErrors:
 		case Logs::Warning:
 		case Logs::Critical:
 		case Logs::Error:
@@ -311,6 +315,7 @@ uint16 EQEmuLogSys::GetGMSayColorFromCategory(uint16 log_category)
 		case Logs::Normal:
 			return Chat::Yellow;
 		case Logs::MySQLError:
+		case Logs::QuestErrors:
 		case Logs::Error:
 			return Chat::Red;
 		case Logs::MySQLQuery:
@@ -625,7 +630,11 @@ EQEmuLogSys *EQEmuLogSys::LoadLogDatabaseSettings()
 		bool is_missing_in_database = std::find(db_categories.begin(), db_categories.end(), i) == db_categories.end();
 		bool is_deprecated_category = Strings::Contains(fmt::format("{}", Logs::LogCategoryName[i]), "Deprecated");
 		if (!is_missing_in_database && is_deprecated_category) {
-			LogInfo("Logging category [{}] ({}) is now deprecated, deleting from database", Logs::LogCategoryName[i], i);
+			LogInfo(
+				"Logging category [{}] ({}) is now deprecated, deleting from database",
+				Logs::LogCategoryName[i],
+				i
+			);
 			LogsysCategoriesRepository::DeleteOne(*m_database, i);
 		}
 
@@ -754,7 +763,7 @@ const std::string &EQEmuLogSys::GetLogPath() const
 	return m_log_path;
 }
 
-EQEmuLogSys * EQEmuLogSys::SetLogPath(const std::string &log_path)
+EQEmuLogSys *EQEmuLogSys::SetLogPath(const std::string &log_path)
 {
 	EQEmuLogSys::m_log_path = log_path;
 

common/eqemu_logsys.h

@@ -136,6 +136,7 @@ namespace Logs {
 		PacketClientServer,
 		PacketServerToServer,
 		Bugs,
+		QuestErrors,
 		MaxCategoryID /* Don't Remove this */
 	};
 
@@ -229,7 +230,8 @@ namespace Logs {
 		"Packet-S->C",
 		"Packet-C->S",
 		"Packet-S->S",
-		"Bugs"
+		"Bugs",
+		"QuestErrors"
 	};
 }
 

common/eqemu_logsys_log_aliases.h

@@ -861,6 +861,16 @@
         OutF(LogSys, Logs::Detail, Logs::Bugs, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
 } while (0)
 
+#define LogQuestErrors(message, ...) do {\
+    if (LogSys.IsLogEnabled(Logs::General, Logs::QuestErrors))\
+        OutF(LogSys, Logs::General, Logs::QuestErrors, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
+} while (0)
+
+#define LogQuestErrorsDetail(message, ...) do {\
+    if (LogSys.IsLogEnabled(Logs::Detail, Logs::QuestErrors))\
+        OutF(LogSys, Logs::Detail, Logs::QuestErrors, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
+} while (0)
+
 #define Log(debug_level, log_category, message, ...) do {\
     if (LogSys.IsLogEnabled(debug_level, log_category))\
         LogSys.Out(debug_level, log_category, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\

zone/embperl.cpp

@@ -19,6 +19,9 @@ Eglin
 #include "embxs.h"
 #include "../common/features.h"
 #include "../common/path_manager.h"
+#include "../common/process/process.h"
+#include "../common/file.h"
+#include "../common/timer.h"
 
 #ifndef GvCV_set
 #define GvCV_set(gv,cv)   (GvCV(gv) = (cv))
@@ -211,6 +214,7 @@ void Embperl::init_eval_file(void)
 			"} else {"
 			// we 'my' $filename,$mtime,$package,$sub to prevent them from changing our state up here.
 			"	eval(\"package $package; my(\\$filename,\\$mtime,\\$package,\\$sub); \\$isloaded = 1; require './$filename'; \");"
+			"	die $@ if ($@ && $@ !~ /did not return a true value/); "
 			//  " print $@ if $@;"
 /*				"local *FH;open FH, $filename or die \"open '$filename' $!\";"
 				"local($/) = undef;my $sub = <FH>;close FH;"
@@ -229,21 +233,21 @@ int Embperl::eval_file(const char * packagename, const char * filename)
 	std::vector<std::string> args;
 	args.push_back(packagename);
 	args.push_back(filename);
+
 	return dosub("main::eval_file", &args);
 }
 
 int Embperl::dosub(const char * subname, const std::vector<std::string> * args, int mode)
 {
 	dSP;
-	int ret_value = 0;
+	int         ret_value = 0;
-	int count;
+	int         count;
 	std::string error;
 
 	ENTER;
 	SAVETMPS;
 	PUSHMARK(SP);
-	if(args && !args->empty())
+	if (args && !args->empty()) {
-	{
 		for (auto i = args->begin(); i != args->end(); ++i) {
 			XPUSHs(sv_2mortal(newSVpv(i->c_str(), i->length())));
 		}
@@ -253,16 +257,14 @@ int Embperl::dosub(const char * subname, const std::vector<std::string> * args,
 	count = call_pv(subname, mode);
 	SPAGAIN;
 
-	if(SvTRUE(ERRSV))
+	if (SvTRUE(ERRSV)) {
-	{
 		error = SvPV_nolen(ERRSV);
 		POPs;
 	}
-	else
+	else {
-	{
+		if (count == 1) {
-		if(count == 1) {
 			SV *ret = POPs;
-			if(SvTYPE(ret) == SVt_IV) {
+			if (SvTYPE(ret) == SVt_IV) {
 				IV v = SvIV(ret);
 				ret_value = v;
 			}
@@ -273,8 +275,7 @@ int Embperl::dosub(const char * subname, const std::vector<std::string> * args,
 	FREETMPS;
 	LEAVE;
 
-	if(error.length() > 0)
+	if (error.length() > 0) {
-	{
 		std::string errmsg = "Perl runtime error: ";
 		errmsg += SvPVX(ERRSV);
 		throw errmsg;

zone/quest_interface.h

@@ -71,7 +71,7 @@ public:
 		return 0;
 	}
 #endif
-	
+
 	virtual bool HasQuestSub(uint32 npcid, QuestEventID evt) { return false; }
 	virtual bool HasGlobalQuestSub(QuestEventID evt) { return false; }
 	virtual bool PlayerHasQuestSub(QuestEventID evt) { return false; }
@@ -120,14 +120,14 @@ public:
 		return 0;
 	}
 #endif
-	
+
 	virtual void AddVar(std::string name, std::string val) { }
 	virtual std::string GetVar(std::string name) { return std::string(); }
 	virtual void Init() { }
 	virtual void ReloadQuests() { }
 	virtual uint32 GetIdentifier() = 0;
 	virtual void RemoveEncounter(const std::string &name) { }
-	
+
 	//TODO: Set maximum quest errors instead of hard coding it
 	virtual void GetErrors(std::list<std::string> &quest_errors) {
 		quest_errors.insert(quest_errors.end(), errors_.begin(), errors_.end());
@@ -135,13 +135,14 @@ public:
 
 	virtual void AddError(std::string error) {
 		LogQuests("{}", error);
+		LogQuestErrors("{}", Strings::Trim(error));
 
 		errors_.push_back(error);
 		if(errors_.size() > 30) {
 			errors_.pop_front();
 		}
 	}
-	
+
 protected:
 	std::list<std::string> errors_;
 };