[Logging] Implement Player Event Logging system (#2833)

* Plumbing

* Batch processing in world

* Cleanup

* Cleanup

* Update player_event_logs.cpp

* Add player zoning event

* Use generics

* Comments

* Add events

* Add more events

* AA_GAIN, AA_PURCHASE, FORAGE_SUCCESS, FORAGE_FAILURE

* FISH_SUCCESS, FISH_FAILURE, ITEM_DESTROY

* Add charges to ITEM_DESTROY

* WENT_ONLINE, WENT_OFFLINE

* LEVEL_GAIN, LEVEL_LOSS

* LOOT_ITEM

* MERCHANT_PURCHASE

* MERCHANT_SELL

* SKILL_UP

* Add events

* Add more events

* TASK_ACCEPT, TASK_COMPLETE, and TASK_UPDATE

* GROUNDSPAWN_PICKUP

* SAY

* REZ_ACCEPTED

* COMBINE_FAILURE and COMBINE_SUCCESS

* DROPPED_ITEM

* DEATH

* SPLIT_MONEY

* TRADER_PURCHASE and TRADER_SELL

* DISCOVER_ITEM

* Convert GM_COMMAND to use new macro

* Convert ZONING event to use macro

* Revert some code changes

* Revert "Revert some code changes"

This reverts commit d53682f997e89a053a660761085913245db91e9d.

* Add cereal generation support to repositories

* TRADE

* Formatting

* Cleanup

* Relocate discord_manager to discord folder

* Discord sending plumbing

* Rename UCS's Database class to UCSDatabase to be more specific and not collide with base Database class for repository usage

* More discord sending plumbing

* More discord message formatting work

* More discord formatting work

* Discord formatting of events

* Format WENT_ONLINE, WENT_OFFLINE

* Add merchant purchase event

* Handle Discord MERCHANT_SELL formatter

* Update player_event_discord_formatter.cpp

* Tweaks

* Implement retention truncation

* Put mutex locking on batch queue, put processor on its own thread

* Process on initial bootup

* Implement optional QS processing, implement keepalive from world to QS

* Reload player event settings when logs are reloaded in game

* Set settings defaults

* Update player_event_logs.cpp

* Update player_event_logs.cpp

* Set retention days on boot

* Update player_event_logs.cpp

* Player Handin Event Testing.

Testing player handin stuff.

* Cleanup.

* Finish NPC Handin.

* set a reference to the client inside of the trade object as well for plugins to process

* Fix for windows _inline

* Bump to cpp20 default, ignore excessive warnings on windows

* Bump FMT to 6.1.2 for cpp20 compat and swap fmt::join for Strings::Join

* Windows compile fixes

* Update CMakeLists.txt

* Update CMakeLists.txt

* Update CMakeLists.txt

* Create 2022_12_19_player_events_tables.sql

* [Formatters] Work on Discord Formatters

* Handin money.

* Format header

* [Formatters] Work on Discord Formatters

* Format

* Format

* [Formatters] More Formatter work, need to test further.

* [Formatters] More Work on Formatters.

* Add missing #endif

* [Formatters] Work on Formatters, fix Bot formatting in ^create help

* NPC Handin Discord Formatter

* Update player_event_logs.cpp

* Discover Item Discord Formatter

* Dropped Item Discord Formatter

* Split Money Discord Formatter

* Trader Discord Formatters

* Cleanup.

* Trade Event Discord Formatter Groundwork

* SAY don't record GM commands

* GM_Command don't record #help

* Update player_event_logs.cpp

* Fill in more event data

* Post rebase fixes

* Post rebase fix

* Discord formatting adjustments

* Add event deprecation or unimplemented tag support

* Trade events

* Add return money and sanity checks.

* Update schema

* Update ucs.cpp

* Update client.cpp

* Update 2022_12_19_player_events_tables.sql

* Implement archive single line

* Replace hackers table and functions with PossibleHack player event

* Replace very old eventlog table since the same events are covered by player event logs

* Update bot_command.cpp

* Record NPC kill events ALL / Named / Raid

* Add BatchEventProcessIntervalSeconds rule

* Naming

* Update CMakeLists.txt

* Update database_schema.h

* Remove logging function and methods

* DB version

* Cleanup SendPlayerHandinEvent

---------

Co-authored-by: Kinglykrab <kinglykrab@gmail.com>
Co-authored-by: Aeadoin <109764533+Aeadoin@users.noreply.github.com>

world/cli/test.cpp

@@ -1,4 +1,6 @@
-#include "../../common/zone_store.h"
+#include <cereal/archives/json.hpp>
+#include <cereal/types/vector.hpp>
+#include "../../common/events/player_events.h"
 
 void WorldserverCLI::TestCommand(int argc, char **argv, argh::parser &cmd, std::string &description)
 {
@@ -8,14 +10,5 @@ void WorldserverCLI::TestCommand(int argc, char **argv, argh::parser &cmd, std::
 		return;
 	}
 
-	zone_store.LoadZones(database);
-
-	const char* zonename = ZoneName(0);
-	if (zonename == 0) {
-		LogInfo("Zone name is 0");
-	}
-	if (zonename == nullptr) {
-		LogInfo("Zone name is nullptr");
-	}
-
+	
 }

world/client.cpp

@@ -49,6 +49,8 @@
 #include "sof_char_create_data.h"
 #include "../common/zone_store.h"
 #include "../common/repositories/account_repository.h"
+#include "../common/repositories/player_event_logs_repository.h"
+#include "../common/events/player_event_logs.h"
 
 #include <iostream>
 #include <iomanip>
@@ -818,7 +820,8 @@ bool Client::HandleEnterWorldPacket(const EQApplicationPacket *app) {
 				zone_id = database.MoveCharacterToBind(charid, 4);
 			} else {
 				LogInfo("[{}] is trying to go home before they're able.", char_name);
-				database.SetHackerFlag(GetAccountName(), char_name, "MQGoHome: player tried to go home before they were able.");
+				RecordPossibleHack("[MQGoHome] player tried to go home before they were able");
+
 				eqs->Close();
 				return true;
 			}
@@ -844,7 +847,8 @@ bool Client::HandleEnterWorldPacket(const EQApplicationPacket *app) {
 				database.MoveCharacterToZone(charid, zone_id);
 			} else {
 				LogInfo("[{}] is trying to go to the Tutorial but they are not allowed.", char_name);
-				database.SetHackerFlag(GetAccountName(), char_name, "MQTutorial: player tried to enter the tutorial without having tutorial enabled for this character.");
+				RecordPossibleHack("[MQTutorial] player tried to enter the tutorial without having tutorial enabled for this character");
+
 				eqs->Close();
 				return true;
 			}
@@ -2360,3 +2364,24 @@ bool Client::StoreCharacter(
 
 	return true;
 }
+
+void Client::RecordPossibleHack(const std::string& message)
+{
+	if (player_event_logs.IsEventEnabled(PlayerEvent::POSSIBLE_HACK)) {
+		auto event = PlayerEvent::PossibleHackEvent{.message = message};
+		std::stringstream ss;
+		{
+			cereal::JSONOutputArchiveSingleLine ar(ss);
+			event.serialize(ar);
+		}
+
+		auto e = PlayerEventLogsRepository::NewEntity();
+		e.character_id    = charid;
+		e.account_id      = GetCLE() ? GetAccountID() : 0;
+		e.event_type_id   = PlayerEvent::POSSIBLE_HACK;
+		e.event_type_name = PlayerEvent::EventName[PlayerEvent::POSSIBLE_HACK];
+		e.event_data      = ss.str();
+		e.created_at      = std::time(nullptr);
+		PlayerEventLogsRepository::InsertOne(database, e);
+	}
+}

world/client.h

@@ -121,6 +121,7 @@ private:
 
 	EQStreamInterface* eqs;
 	bool CanTradeFVNoDropItem();
+	void RecordPossibleHack(const std::string& message);
 };
 
 bool CheckCharCreateInfoSoF(CharCreate_Struct *cc);

world/dynamic_zone_manager.cpp

@@ -28,9 +28,9 @@ void DynamicZoneManager::PurgeExpiredDynamicZones()
 		LogDynamicZones("Purging [{}] dynamic zone(s)", dz_ids.size());
 
 		DynamicZoneMembersRepository::DeleteWhere(database,
-			fmt::format("dynamic_zone_id IN ({})", fmt::join(dz_ids, ",")));
+			fmt::format("dynamic_zone_id IN ({})", Strings::Join(dz_ids, ",")));
 		DynamicZonesRepository::DeleteWhere(database,
-			fmt::format("id IN ({})", fmt::join(dz_ids, ",")));
+			fmt::format("id IN ({})", Strings::Join(dz_ids, ",")));
 	}
 }
 
@@ -145,7 +145,7 @@ void DynamicZoneManager::Process()
 		// need to look up expedition ids until lockouts are moved to dynamic zones
 		std::vector<uint32_t> expedition_ids;
 		auto expeditions = ExpeditionsRepository::GetWhere(database,
-			fmt::format("dynamic_zone_id IN ({})", fmt::join(dynamic_zone_ids, ",")));
+			fmt::format("dynamic_zone_id IN ({})", Strings::Join(dynamic_zone_ids, ",")));
 
 		if (!expeditions.empty())
 		{
@@ -154,14 +154,14 @@ void DynamicZoneManager::Process()
 				expedition_ids.emplace_back(expedition.id);
 			}
 			ExpeditionLockoutsRepository::DeleteWhere(database,
-				fmt::format("expedition_id IN ({})", fmt::join(expedition_ids, ",")));
+				fmt::format("expedition_id IN ({})", Strings::Join(expedition_ids, ",")));
 		}
 
 		ExpeditionsRepository::DeleteWhere(database,
-			fmt::format("dynamic_zone_id IN ({})", fmt::join(dynamic_zone_ids, ",")));
+			fmt::format("dynamic_zone_id IN ({})", Strings::Join(dynamic_zone_ids, ",")));
 		DynamicZoneMembersRepository::RemoveAllMembers(database, dynamic_zone_ids);
 		DynamicZonesRepository::DeleteWhere(database,
-			fmt::format("id IN ({})", fmt::join(dynamic_zone_ids, ",")));
+			fmt::format("id IN ({})", Strings::Join(dynamic_zone_ids, ",")));
 	}
 }
 

world/expedition_database.cpp

@@ -50,11 +50,11 @@ void ExpeditionDatabase::PurgeExpiredExpeditions()
 	auto results = database.QueryDatabase(query);
 	if (results.Success())
 	{
-		std::vector<uint32_t> expedition_ids;
+		std::vector<std::string> expedition_ids;
 		std::vector<uint32_t> dynamic_zone_ids;
 		for (auto row = results.begin(); row != results.end(); ++row)
 		{
-			expedition_ids.emplace_back(static_cast<uint32_t>(strtoul(row[0], nullptr, 10)));
+			expedition_ids.emplace_back(row[0]);
 			dynamic_zone_ids.emplace_back(static_cast<uint32_t>(strtoul(row[1], nullptr, 10)));
 		}
 

world/main.cpp

@@ -58,6 +58,7 @@
 
 #include "../common/unix.h"
 #include <sys/sem.h>
+#include <thread>
 
 #if not defined (FREEBSD) && not defined (DARWIN)
 union semun {
@@ -96,6 +97,7 @@ union semun {
 #include "shared_task_manager.h"
 #include "world_boot.h"
 #include "../common/path_manager.h"
+#include "../common/events/player_event_logs.h"
 
 
 ZoneStore           zone_store;
@@ -118,6 +120,7 @@ EQEmuLogSys         LogSys;
 WorldContentService content_service;
 WebInterfaceList    web_interface;
 PathManager         path;
+PlayerEventLogs     player_event_logs;
 
 void CatchSignal(int sig_num);
 
@@ -128,6 +131,13 @@ inline void UpdateWindowTitle(std::string new_title)
 #endif
 }
 
+void PlayerEventQueueListener() {
+	while (RunLoops) {
+		player_event_logs.Process();
+		Sleep(1000);
+	}
+}
+
 /**
  * World process entrypoint
  *
@@ -371,6 +381,13 @@ int main(int argc, char **argv)
 		}
 	);
 
+	player_event_logs.SetDatabase(&database)->Init();
+
+	if (!RuleB(Logging, PlayerEventsQSProcess)) {
+		LogInfo("[PlayerEventQueueListener] Booting queue processor");
+		std::thread(PlayerEventQueueListener).detach();
+	}
+
 	auto loop_fn = [&](EQ::Timer* t) {
 		Timer::SetCurrentTime();
 

world/queryserv.cpp

@@ -22,6 +22,7 @@ void QueryServConnection::AddConnection(std::shared_ptr<EQ::Net::ServertalkServe
 	connection->OnMessage(ServerOP_QueryServGeneric, std::bind(&QueryServConnection::HandleGenericMessage, this, std::placeholders::_1, std::placeholders::_2));
 	connection->OnMessage(ServerOP_LFGuildUpdate, std::bind(&QueryServConnection::HandleLFGuildUpdateMessage, this, std::placeholders::_1, std::placeholders::_2));
 	m_streams.insert(std::make_pair(connection->GetUUID(), connection));
+	m_keepalive = std::make_unique<EQ::Timer>(1000, true, std::bind(&QueryServConnection::OnKeepAlive, this, std::placeholders::_1));
 }
 
 void QueryServConnection::RemoveConnection(std::shared_ptr<EQ::Net::ServertalkServerConnection> connection)
@@ -51,4 +52,10 @@ bool QueryServConnection::SendPacket(ServerPacket* pack)
 	}
 
 	return true;
-}
+}
+
+void QueryServConnection::OnKeepAlive(EQ::Timer *t)
+{
+	ServerPacket pack(ServerOP_KeepAlive, 0);
+	SendPacket(&pack);
+}

world/queryserv.h

@@ -4,6 +4,7 @@
 #include "../common/types.h"
 #include "../common/net/servertalk_server.h"
 #include "../common/servertalk.h"
+#include "../common/event/timer.h"
 
 class QueryServConnection
 {
@@ -14,8 +15,10 @@ public:
 	void HandleGenericMessage(uint16_t opcode, EQ::Net::Packet &p);
 	void HandleLFGuildUpdateMessage(uint16_t opcode, EQ::Net::Packet &p);
 	bool SendPacket(ServerPacket* pack);
+	void OnKeepAlive(EQ::Timer *t);
 private:
 	std::map<std::string, std::shared_ptr<EQ::Net::ServertalkServerConnection>> m_streams;
+	std::unique_ptr<EQ::Timer> m_keepalive;
 };
 
 #endif /*QueryServ_H_*/

world/shared_task_manager.cpp

@@ -312,7 +312,7 @@ void SharedTaskManager::LoadSharedTaskState()
 
 		shared_task_character_data = CharacterDataRepository::GetWhere(
 			*m_database,
-			fmt::format("id IN ({})", fmt::join(character_ids, ","))
+			fmt::format("id IN ({})", Strings::Join(character_ids, ","))
 		);
 	}
 
@@ -1294,7 +1294,7 @@ std::vector<CharacterTaskTimersRepository::CharacterTaskTimers> SharedTaskManage
 				OR (timer_group > 0 AND timer_type = {} AND timer_group = {}))
 			AND expire_time > NOW() ORDER BY timer_type ASC LIMIT 1
 		),
-		fmt::join(character_ids, ","),
+		Strings::Join(character_ids, ","),
 		task.id,
 		static_cast<int>(TaskTimerType::Replay),
 		task.replay_timer_group,
@@ -1632,7 +1632,7 @@ void SharedTaskManager::AddReplayTimers(SharedTask *s)
 				s->GetTaskData().id,
 				s->GetTaskData().replay_timer_group,
 				static_cast<int>(TaskTimerType::Replay),
-				fmt::join(s->member_id_history, ",")
+				Strings::Join(s->member_id_history, ",")
 			));
 
 			CharacterTaskTimersRepository::InsertMany(*m_database, task_timers);

world/shared_task_world_messaging.cpp

@@ -323,7 +323,7 @@ void SharedTaskWorldMessaging::HandleZoneMessage(ServerPacket *pack)
 					}
 				}
 
-				std::string player_list = fmt::format("{}", fmt::join(player_names, ", "));
+				std::string player_list = fmt::format("{}", Strings::Join(player_names, ", "));
 				client_list.SendCharacterMessageID(buf->source_character_id, Chat::Yellow, TaskStr::MEMBERS_PRINT, {player_list});
 			}
 

world/zoneserver.cpp

@@ -43,6 +43,8 @@ Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
 #include "../common/shared_tasks.h"
 #include "shared_task_manager.h"
 #include "../common/content/world_content_service.h"
+#include "../common/repositories/player_event_logs_repository.h"
+#include "../common/events/player_event_logs.h"
 
 extern ClientList client_list;
 extern GroupLFPList LFPGroupList;
@@ -369,6 +371,30 @@ void ZoneServer::HandleMessage(uint16 opcode, const EQ::Net::Packet &p) {
 			zoneserver_list.SendPacket(pack);
 			break;
 		}
+		case ServerOP_PlayerEvent: {
+			auto                         n = PlayerEvent::PlayerEventContainer{};
+			auto                         s = (ServerSendPlayerEvent_Struct *) pack->pBuffer;
+			EQ::Util::MemoryStreamReader ss(s->cereal_data, s->cereal_size);
+			cereal::BinaryInputArchive   archive(ss);
+			archive(n);
+
+			// by default process events in world
+			// if set, process events in queryserver
+			// if you want to offload event recording to a dedicated QS instance
+			if (!RuleB(Logging, PlayerEventsQSProcess)) {
+				player_event_logs.AddToQueue(n.player_event_log);
+			}
+			else {
+				QSLink.SendPacket(pack);
+			}
+
+			// if discord enabled for event, ship to UCS to process
+			if (player_event_logs.IsEventDiscordEnabled(n.player_event_log.event_type_id)) {
+				UCSLink.SendPacket(pack);
+			}
+
+			break;
+		}
 		case ServerOP_DetailsChange: {
 			if (pack->size != sizeof(ServerRaidGeneralAction_Struct)) {
 				break;
@@ -1356,6 +1382,7 @@ void ZoneServer::HandleMessage(uint16 opcode, const EQ::Net::Packet &p) {
 			zoneserver_list.SendPacket(pack);
 			UCSLink.SendPacket(pack);
 			LogSys.LoadLogDatabaseSettings();
+			player_event_logs.ReloadSettings();
 			break;
 		}
 		case ServerOP_ReloadTasks: {