UCS / Raid / Zone Fixes (#1033)

* Cache EntityList::GetRaidByClient

* Adjustments [skip ci]

* Update entity [skip ci]

* More cleanup [skip ci]

* More tweaks [skip ci]

* Cleanup [skip ci]

* Fix bugs with UCS reconnection on crash / exit, not adding soft deleted characters, put main loop on UV lib

* Reduce log spam that should be debugging; send keepalives to clients so that they properly prune from the connection list

* Shutdown the eventloop to properly shutdown the zone versus calling a hard exit

ucs/chatchannel.cpp

@@ -47,8 +47,13 @@ ChatChannel::ChatChannel(std::string inName, std::string inOwner, std::string in
 
 	Moderated = false;
 
-	LogInfo("New ChatChannel created: Name: [[{}]], Owner: [[{}]], Password: [[{}]], MinStatus: [{}]",
-		Name.c_str(), Owner.c_str(), Password.c_str(), MinimumStatus);
+	LogDebug(
+		"New ChatChannel created: Name: [[{}]], Owner: [[{}]], Password: [[{}]], MinStatus: [{}]",
+		Name.c_str(),
+		Owner.c_str(),
+		Password.c_str(),
+		MinimumStatus
+	);
 
 }
 
@@ -154,7 +159,7 @@ void ChatChannelList::SendAllChannels(Client *c) {
 
 void ChatChannelList::RemoveChannel(ChatChannel *Channel) {
 
-	LogInfo("RemoveChannel([{}])", Channel->GetName().c_str());
+	LogDebug("RemoveChannel ([{}])", Channel->GetName().c_str());
 
 	LinkedListIterator<ChatChannel*> iterator(ChatChannels);
 
@@ -175,7 +180,7 @@ void ChatChannelList::RemoveChannel(ChatChannel *Channel) {
 
 void ChatChannelList::RemoveAllChannels() {
 
-	LogInfo("RemoveAllChannels");
+	LogDebug("RemoveAllChannels");
 
 	LinkedListIterator<ChatChannel*> iterator(ChatChannels);
 
@@ -242,7 +247,7 @@ void ChatChannel::AddClient(Client *c) {
 
 	int AccountStatus = c->GetAccountStatus();
 
-	LogInfo("Adding [{}] to channel [{}]", c->GetName().c_str(), Name.c_str());
+	LogDebug("Adding [{}] to channel [{}]", c->GetName().c_str(), Name.c_str());
 
 	LinkedListIterator<Client*> iterator(ClientsInChannel);
 
@@ -267,7 +272,7 @@ bool ChatChannel::RemoveClient(Client *c) {
 
 	if(!c) return false;
 
-	LogInfo("RemoveClient [{}] from channel [{}]", c->GetName().c_str(), GetName().c_str());
+	LogDebug("RemoveClient [{}] from channel [{}]", c->GetName().c_str(), GetName().c_str());
 
 	bool HideMe = c->GetHideMe();
 
@@ -304,7 +309,7 @@ bool ChatChannel::RemoveClient(Client *c) {
 		if((Password.length() == 0) || (RuleI(Channels, DeleteTimer) == 0))
 			return false;
 
-		LogInfo("Starting delete timer for empty password protected channel [{}]", Name.c_str());
+		LogDebug("Starting delete timer for empty password protected channel [{}]", Name.c_str());
 
 		DeleteTimer.Start(RuleI(Channels, DeleteTimer) * 60000);
 	}
@@ -402,7 +407,7 @@ void ChatChannel::SendMessageToChannel(std::string Message, Client* Sender) {
 
 		if(ChannelClient)
 		{
-			LogInfo("Sending message to [{}] from [{}]",
+			LogDebug("Sending message to [{}] from [{}]",
 				ChannelClient->GetName().c_str(), Sender->GetName().c_str());
 
 			if (cv_messages[static_cast<uint32>(ChannelClient->GetClientVersion())].length() == 0) {
@@ -505,7 +510,7 @@ ChatChannel *ChatChannelList::AddClientToChannel(std::string ChannelName, Client
 		return nullptr;
 	}
 
-	LogInfo("AddClient to channel [[{}]] with password [[{}]]", NormalisedName.c_str(), Password.c_str());
+	LogDebug("AddClient to channel [[{}]] with password [[{}]]", NormalisedName.c_str(), Password.c_str());
 
 	ChatChannel *RequiredChannel = FindChannel(NormalisedName);
 
@@ -581,7 +586,7 @@ void ChatChannelList::Process() {
 
 		if(CurrentChannel && CurrentChannel->ReadyToDelete()) {
 
-			LogInfo("Empty temporary password protected channel [{}] being destroyed",
+			LogDebug("Empty temporary password protected channel [{}] being destroyed",
 				CurrentChannel->GetName().c_str());
 
 			RemoveChannel(CurrentChannel);
@@ -597,7 +602,7 @@ void ChatChannel::AddInvitee(const std::string &Invitee)
 	if (!IsInvitee(Invitee)) {
 		Invitees.push_back(Invitee);
 
-		LogInfo("Added [{}] as invitee to channel [{}]", Invitee.c_str(), Name.c_str());
+		LogDebug("Added [{}] as invitee to channel [{}]", Invitee.c_str(), Name.c_str());
 	}
 
 }
@@ -608,7 +613,7 @@ void ChatChannel::RemoveInvitee(std::string Invitee)
 
 	if(it != std::end(Invitees)) {
 		Invitees.erase(it);
-		LogInfo("Removed [{}] as invitee to channel [{}]", Invitee.c_str(), Name.c_str());
+		LogDebug("Removed [{}] as invitee to channel [{}]", Invitee.c_str(), Name.c_str());
 	}
 }
 

ucs/clientlist.cpp

@@ -235,7 +235,7 @@ std::vector<std::string> ParseRecipients(std::string RecipientString) {
 
 static void ProcessMailTo(Client *c, std::string MailMessage) {
 
-	LogInfo("MAILTO: From [{}], [{}]", c->MailBoxName().c_str(), MailMessage.c_str());
+	LogDebug("MAILTO: From [{}], [{}]", c->MailBoxName().c_str(), MailMessage.c_str());
 
 	std::vector<std::string> Recipients;
 
@@ -304,7 +304,7 @@ static void ProcessMailTo(Client *c, std::string MailMessage) {
 
 		if (!database.SendMail(Recipient, c->MailBoxName(), Subject, Body, RecipientsString)) {
 
-			LogInfo("Failed in SendMail([{}], [{}], [{}], [{}])", Recipient.c_str(),
+			LogError("Failed in SendMail([{}], [{}], [{}], [{}])", Recipient.c_str(),
 				c->MailBoxName().c_str(), Subject.c_str(), RecipientsString.c_str());
 
 			int PacketLength = 10 + Recipient.length() + Subject.length();
@@ -556,6 +556,17 @@ void Client::CloseConnection() {
 	ClientStream->ReleaseFromUse();
 }
 
+void Clientlist::CheckForStaleConnectionsAll()
+{
+	LogDebug("Checking for stale connections");
+
+	auto it = ClientChatConnections.begin();
+	while (it != ClientChatConnections.end()) {
+		(*it)->SendKeepAlive();
+		++it;
+	}
+}
+
 void Clientlist::CheckForStaleConnections(Client *c) {
 
 	if (!c) return;
@@ -634,10 +645,12 @@ void Clientlist::Process()
 				//
 				std::string::size_type LastPeriod = MailBoxString.find_last_of(".");
 
-				if (LastPeriod == std::string::npos)
+				if (LastPeriod == std::string::npos) {
 					CharacterName = MailBoxString;
-				else
+				}
+				else {
 					CharacterName = MailBoxString.substr(LastPeriod + 1);
+				}
 
 				LogInfo("Received login for user [{}] with key [{}]",
 					MailBox, Key);
@@ -652,8 +665,9 @@ void Clientlist::Process()
 
 				database.GetAccountStatus((*it));
 
-				if ((*it)->GetConnectionType() == ConnectionTypeCombined)
+				if ((*it)->GetConnectionType() == ConnectionTypeCombined) {
 					(*it)->SendFriends();
+				}
 
 				(*it)->SendMailBoxes();
 
@@ -865,7 +879,9 @@ void Clientlist::CloseAllConnections() {
 void Client::AddCharacter(int CharID, const char *CharacterName, int Level) {
 
 	if (!CharacterName) return;
-	LogInfo("Adding character [{}] with ID [{}] for [{}]", CharacterName, CharID, GetName().c_str());
+
+	LogDebug("Adding character [{}] with ID [{}] for [{}]", CharacterName, CharID, GetName().c_str());
+
 	CharacterEntry NewCharacter;
 	NewCharacter.CharID = CharID;
 	NewCharacter.Name = CharacterName;
@@ -874,6 +890,10 @@ void Client::AddCharacter(int CharID, const char *CharacterName, int Level) {
 	Characters.push_back(NewCharacter);
 }
 
+void Client::SendKeepAlive() {
+	QueuePacket(new EQApplicationPacket(OP_SessionReady, 0));
+}
+
 void Client::SendMailBoxes() {
 
 	int Count = Characters.size();
@@ -930,7 +950,7 @@ void Client::AddToChannelList(ChatChannel *JoinedChannel) {
 	for (int i = 0; i < MAX_JOINED_CHANNELS; i++)
 		if (JoinedChannels[i] == nullptr) {
 			JoinedChannels[i] = JoinedChannel;
-			LogInfo("Added Channel [{}] to slot [{}] for [{}]", JoinedChannel->GetName().c_str(), i + 1, GetName().c_str());
+			LogDebug("Added Channel [{}] to slot [{}] for [{}]", JoinedChannel->GetName().c_str(), i + 1, GetName().c_str());
 			return;
 		}
 }
@@ -2346,18 +2366,17 @@ void Client::SendFriends() {
 	}
 }
 
-std::string Client::MailBoxName() {
+std::string Client::MailBoxName()
+{
+	if ((Characters.empty()) || (CurrentMailBox > (Characters.size() - 1))) {
+		LogDebug("MailBoxName() called with CurrentMailBox set to [{}] and Characters.size() is [{}]",
+				 CurrentMailBox, Characters.size());
 
-	if ((Characters.empty()) || (CurrentMailBox > (Characters.size() - 1)))
-	{
-		LogInfo("MailBoxName() called with CurrentMailBox set to [{}] and Characters.size() is [{}]",
-			CurrentMailBox, Characters.size());
-
-		return "";
+		return std::string();
 	}
 
-	LogInfo("MailBoxName() called with CurrentMailBox set to [{}] and Characters.size() is [{}]",
-		CurrentMailBox, Characters.size());
+	LogDebug("MailBoxName() called with CurrentMailBox set to [{}] and Characters.size() is [{}]",
+			 CurrentMailBox, Characters.size());
 
 	return Characters[CurrentMailBox].Name;
 

ucs/clientlist.h

@@ -143,7 +143,7 @@ public:
 	void SetConnectionType(char c);
 	ConnectionType GetConnectionType() { return TypeOfConnection; }
 	EQEmu::versions::ClientVersion GetClientVersion() { return ClientVersion_; }
-	
+
 	inline bool IsMailConnection() { return (TypeOfConnection == ConnectionTypeMail) || (TypeOfConnection == ConnectionTypeCombined); }
 	void SendNotification(int MailBoxNumber, std::string From, std::string Subject, int MessageID);
 	void ChangeMailBox(int NewMailBox);
@@ -151,6 +151,7 @@ public:
 	void SendFriends();
 	int GetCharID();
 	void SendUptime();
+	void SendKeepAlive();
 
 private:
 	unsigned int CurrentMailBox;
@@ -183,6 +184,7 @@ public:
 	void	Process();
 	void	CloseAllConnections();
 	Client *FindCharacter(std::string CharacterName);
+	void	CheckForStaleConnectionsAll();
 	void	CheckForStaleConnections(Client *c);
 	Client *IsCharacterOnline(std::string CharacterName);
 	void ProcessOPMailCommand(Client *c, std::string CommandString);

ucs/database.cpp

@@ -108,7 +108,7 @@ void Database::GetAccountStatus(Client *client)
 {
 
 	std::string query = StringFormat(
-		"SELECT `status`, `hideme`, `karma`, `revoked` FROM `account` WHERE `id` = '%i' LIMIT 1",
+		"SELECT `status`, `hideme`, `karma`, `revoked` FROM `account` WHERE `id` = %i LIMIT 1",
 		client->GetAccountID()
 	);
 
@@ -173,7 +173,7 @@ int Database::FindAccount(const char *characterName, Client *client)
 
 	query = StringFormat(
 		"SELECT `id`, `name`, `level` FROM `character_data` "
-		"WHERE `account_id` = %i AND `name` != '%s'",
+		"WHERE `account_id` = %i AND `name` != '%s' AND deleted_at is NULL",
 		accountID, characterName
 	);
 
@@ -320,7 +320,7 @@ void Database::SendHeaders(Client *client)
 	int unknownField3 = 1;
 	int characterID   = FindCharacter(client->MailBoxName().c_str());
 
-	LogInfo("Sendheaders for [{}], CharID is [{}]", client->MailBoxName().c_str(), characterID);
+	LogDebug("Sendheaders for [{}], CharID is [{}]", client->MailBoxName().c_str(), characterID);
 
 	if (characterID <= 0) {
 		return;

ucs/ucs.cpp

@@ -70,17 +70,18 @@ int main() {
 	// Check every minute for unused channels we can delete
 	//
 	Timer ChannelListProcessTimer(60000);
+	Timer ClientConnectionPruneTimer(60000);
 
 	Timer InterserverTimer(INTERSERVER_TIMER); // does auto-reconnect
 
 	LogInfo("Starting EQEmu Universal Chat Server");
 
-	if (!ucsconfig::LoadConfig()) { 
-		LogInfo("Loading server configuration failed"); 
+	if (!ucsconfig::LoadConfig()) {
+		LogInfo("Loading server configuration failed");
 		return 1;
 	}
 
-	Config = ucsconfig::get(); 
+	Config = ucsconfig::get();
 
 	WorldShortName = Config->ShortName;
 
@@ -144,19 +145,26 @@ int main() {
 
 	worldserver = new WorldServer;
 
-	while(RunLoops) {
+	auto loop_fn = [&](EQ::Timer* t) {
 
 		Timer::SetCurrentTime();
 
 		g_Clientlist->Process();
 
-		if(ChannelListProcessTimer.Check())
+		if (ChannelListProcessTimer.Check()) {
 			ChannelList->Process();
+		}
 
-		EQ::EventLoop::Get().Process();
+		if (ClientConnectionPruneTimer.Check()) {
+			g_Clientlist->CheckForStaleConnectionsAll();
+		}
 
-		Sleep(5);
-	}
+	};
+
+	EQ::Timer process_timer(loop_fn);
+	process_timer.Start(32, true);
+
+	EQ::EventLoop::Get().Run();
 
 	ChannelList->RemoveAllChannels();
 

ucs/worldserver.cpp

@@ -61,7 +61,7 @@ void WorldServer::ProcessMessage(uint16 opcode, EQ::Net::Packet &p)
 	ServerPacket tpack(opcode, p);
 	ServerPacket *pack = &tpack;
 
-	LogInfo("Received Opcode: {:#04x}", opcode);
+	LogNetcode("Received Opcode: {:#04x}", opcode);
 
 	switch (opcode)
 	{