[Zoning] Fix zoning logic issues (#2412)

* [Zoning] Fix various zoning issues, flag logic, #zone etc

* Enforce character restrictions later in the connection process so we don't end up in a loop race condition in world

common/zone_store.cpp

@@ -59,6 +59,8 @@ uint32 ZoneStore::GetZoneID(std::string zone_name)
 		}
 	}
 
+	LogInfo("[GetZoneID] Failed to get zone_name [{}]", zone_name);
+
 	return 0;
 }
 
@@ -79,6 +81,12 @@ const char *ZoneStore::GetZoneName(uint32 zone_id, bool error_unknown)
 		return "UNKNOWN";
 	}
 
+	LogInfo(
+		"[GetZoneName] Failed to get zone name by zone_id [{}] error_unknown [{}]",
+		zone_id,
+		(error_unknown ? "true" : "false")
+	);
+
 	return nullptr;
 }
 
@@ -99,6 +107,12 @@ const char *ZoneStore::GetZoneLongName(uint32 zone_id, bool error_unknown)
 		return "UNKNOWN";
 	}
 
+	LogInfo(
+		"[GetZoneLongName] Failed to get zone long name by zone_id [{}] error_unknown [{}]",
+		zone_id,
+		(error_unknown ? "true" : "false")
+	);
+
 	return nullptr;
 }
 
@@ -114,6 +128,8 @@ std::string ZoneStore::GetZoneName(uint32 zone_id)
 		}
 	}
 
+	LogInfo("[GetZoneName] Failed to get zone long name by zone_id [{}]", zone_id);
+
 	return {};
 }
 
@@ -129,6 +145,8 @@ std::string ZoneStore::GetZoneLongName(uint32 zone_id)
 		}
 	}
 
+	LogInfo("[GetZoneLongName] Failed to get zone long name by zone_id [{}]", zone_id);
+
 	return {};
 }
 
@@ -145,6 +163,8 @@ ZoneRepository::Zone *ZoneStore::GetZone(uint32 zone_id, int version)
 		}
 	}
 
+	LogInfo("[GetZone] Failed to get zone by zone_id [{}] version [{}]", zone_id, version);
+
 	return nullptr;
 }
 
@@ -160,6 +180,8 @@ ZoneRepository::Zone *ZoneStore::GetZone(const char *in_zone_name)
 		}
 	}
 
+	LogInfo("[GetZone] Failed to get zone by zone_name [{}]", in_zone_name);
+
 	return nullptr;
 }
 
@@ -184,5 +206,7 @@ ZoneRepository::Zone *ZoneStore::GetZoneWithFallback(uint32 zone_id, int version
 		}
 	}
 
+	LogInfo("[GetZoneWithFallback] Failed to get zone by zone_id [{}] version [{}]", zone_id, version);
+
 	return nullptr;
 }

world/zoneserver.cpp

@@ -819,7 +819,12 @@ void ZoneServer::HandleMessage(uint16 opcode, const EQ::Net::Packet &p) {
 					ingress_server->SendPacket(pack);	// inform target server
 				}
 			} else {
-				LogInfo("Processing ZTZ for ingress to zone for client [{}]", ztz->name);
+				LogInfo(
+					"Processing ZTZ for ingress to zone for client [{}] instance_id [{}] zone_id [{}]",
+					ztz->name,
+					ztz->current_instance_id,
+					ztz->current_zone_id
+				);
 				auto egress_server = (
 					ztz->current_instance_id ?
 					zoneserver_list.FindByInstanceID(ztz->current_instance_id) :
@@ -827,6 +832,7 @@ void ZoneServer::HandleMessage(uint16 opcode, const EQ::Net::Packet &p) {
 				);
 
 				if (egress_server) {
+					LogInfo("Found egress server, forwarding client");
 					egress_server->SendPacket(pack);
 				}
 			}

zone/client_packet.cpp

@@ -780,13 +780,6 @@ void Client::CompleteConnect()
 
 	conn_state = ClientConnectFinished;
 
-	//enforce some rules..
-	if (!CanBeInZone()) {
-		LogDebug("[CLIENT] Kicking char from zone, not allowed here");
-		GoToSafeCoords(ZoneID("arena"), 0);
-		return;
-	}
-
 	if (zone)
 		zone->weatherSend(this);
 
@@ -918,6 +911,13 @@ void Client::CompleteConnect()
 	}
 
 	heroforge_wearchange_timer.Start(250);
+
+	// enforce some rules..
+	if (!CanBeInZone()) {
+		LogInfo("Kicking character [{}] from zone, not allowed here (missing requirements)", GetCleanName());
+		GoToSafeCoords(ZoneID("arena"), 0);
+		return;
+	}
 }
 
 // connecting opcode handlers
@@ -6621,7 +6621,7 @@ void Client::Handle_OP_GMZoneRequest(const EQApplicationPacket *app)
 		return;
 	}
 
-	GMZoneRequest_Struct* gmzr = (GMZoneRequest_Struct*)app->pBuffer;
+	auto* gmzr = (GMZoneRequest_Struct*)app->pBuffer;
 	float target_x = -1, target_y = -1, target_z = -1, target_heading;
 
 	int16 min_status = AccountStatus::Player;
@@ -6640,15 +6640,16 @@ void Client::Handle_OP_GMZoneRequest(const EQApplicationPacket *app)
 	// this both loads the safe points and does a sanity check on zone name
 	auto z = GetZone(target_zone, 0);
 	if (z) {
-		target_zone[0] = 0;
 		target_x       = z->safe_x;
 		target_y       = z->safe_y;
 		target_z       = z->safe_z;
 		target_heading = z->safe_heading;
+	} else {
+		target_zone[0] = 0;
 	}
 
 	auto outapp = new EQApplicationPacket(OP_GMZoneRequest, sizeof(GMZoneRequest_Struct));
-	GMZoneRequest_Struct* gmzr2 = (GMZoneRequest_Struct*)outapp->pBuffer;
+	auto* gmzr2 = (GMZoneRequest_Struct*)outapp->pBuffer;
 	strcpy(gmzr2->charname, GetName());
 	gmzr2->zone_id = gmzr->zone_id;
 	gmzr2->x = target_x;

zone/zoning.cpp

@@ -193,11 +193,8 @@ void Client::Handle_OP_ZoneChange(const EQApplicationPacket *app) {
 	float safe_x, safe_y, safe_z, safe_heading;
 	int16 min_status = AccountStatus::Player;
 	uint8 min_level  = 0;
-	char  flag_needed[128];
 
-	if (!zone_data->flag_needed.empty()) {
+	LogInfo("[Handle_OP_ZoneChange] Loaded zone flag [{}]", zone_data->flag_needed);
-		strcpy(flag_needed, zone_data->flag_needed.c_str());
-	}
 
 	safe_x       = zone_data->safe_x;
 	safe_y       = zone_data->safe_y;
@@ -327,10 +324,15 @@ void Client::Handle_OP_ZoneChange(const EQApplicationPacket *app) {
 		myerror = ZONE_ERROR_NOEXPERIENCE;
 	}
 
-	if(!ignore_restrictions && flag_needed[0] != '\0') {
+	if (!ignore_restrictions && !zone_data->flag_needed.empty()) {
 		//the flag needed string is not empty, meaning a flag is required.
-		if(Admin() < minStatusToIgnoreZoneFlags && !HasZoneFlag(target_zone_id))
+		if (Admin() < minStatusToIgnoreZoneFlags && !HasZoneFlag(target_zone_id)) {
-		{
+			LogInfo(
+				"Client [{}] does not have the proper flag to enter [{}] ({})",
+				GetCleanName(),
+				ZoneName(target_zone_id),
+				target_zone_id
+			);
 			Message(Chat::Red, "You do not have the flag to enter %s.", target_zone_name);
 			myerror = ZONE_ERROR_NOEXPERIENCE;
 		}
@@ -342,36 +344,11 @@ void Client::Handle_OP_ZoneChange(const EQApplicationPacket *app) {
 	 * Expansion check
 	 */
 	if (content_service.GetCurrentExpansion() >= Expansion::Classic && !GetGM()) {
-
-		/**
-		 * Hit the zone cache first so we're not hitting the database every time someone attempts to zone
-		 */
 		bool meets_zone_expansion_check = false;
-		bool      found_zone                 = false;
+
-		for (auto &z: zone_store.GetZones()) {
+		auto z = zone_store.GetZoneWithFallback(ZoneID(target_zone_name), 0);
-			if (z.short_name == target_zone_name && z.version == 0) {
+		if (z->expansion <= content_service.GetCurrentExpansion() || z->bypass_expansion_check) {
-				found_zone = true;
-				if (z.expansion <= content_service.GetCurrentExpansion() || z.bypass_expansion_check) {
 			meets_zone_expansion_check = true;
-					break;
-				}
-			}
-		}
-
-		/**
-		 * If we fail to find a cached zone lookup because someone just so happened to change some data, second attempt
-		 * In 99% of cases we would never get here and this would be fallback
-		 */
-		if (!found_zone) {
-			auto zones = ZoneRepository::GetWhere(content_db,
-				fmt::format(
-					"expansion <= {} AND short_name = '{}' and version = 0",
-					(content_service.GetCurrentExpansion()),
-					target_zone_name
-				)
-			);
-
-			meets_zone_expansion_check = !zones.empty();
 		}
 
 		LogInfo(
@@ -466,7 +443,16 @@ void Client::DoZoneSuccess(ZoneChange_Struct *zc, uint16 zone_id, uint32 instanc
 		}
 	}
 
-	LogInfo("Zoning [{}] to: [{}] ([{}]) - ([{}]) x [{}] y [{}] z [{}]", m_pp.name, ZoneName(zone_id), zone_id, instance_id, dest_x, dest_y, dest_z);
+	LogInfo(
+		"Zoning [{}] to: [{}] ([{}]) - ([{}]) x [{}] y [{}] z [{}]",
+		m_pp.name,
+		ZoneName(zone_id),
+		zone_id,
+		instance_id,
+		dest_x,
+		dest_y,
+		dest_z
+	);
 
 	//set the player's coordinates in the new zone so they have them
 	//when they zone into it
@@ -674,6 +660,18 @@ void Client::ZonePC(uint32 zoneID, uint32 instance_id, float x, float y, float z
 		pZoneName = strcpy(new char[strlen(zd->long_name.c_str()) + 1], zd->long_name.c_str());
 	}
 
+	LogInfo(
+		"[ZonePC] Client [{}] zone_id [{}] x [{}] y [{}] x [{}] heading [{}] ignorerestrictions [{}] zone_mode [{}]",
+		GetCleanName(),
+		zoneID,
+		x,
+		y,
+		z,
+		heading,
+		ignorerestrictions,
+		zm
+	);
+
 	cheat_manager.SetExemptStatus(Port, true);
 
 	if(!pZoneName) {
@@ -881,9 +879,11 @@ void Client::ZonePC(uint32 zoneID, uint32 instance_id, float x, float y, float z
 	safe_delete_array(pZoneName);
 }
 
-void Client::GoToSafeCoords(uint16 zone_id, uint16 instance_id) {
+void Client::GoToSafeCoords(uint16 zone_id, uint16 instance_id)
-	if(zone_id == 0)
+{
+	if (zone_id == 0) {
 		zone_id = zone->GetZoneID();
+	}
 
 	MovePC(zone_id, instance_id, 0.0f, 0.0f, 0.0f, 0.0f, 0, ZoneToSafeCoords);
 }
@@ -1240,15 +1240,12 @@ bool Client::CanBeInZone() {
 	float safe_x, safe_y, safe_z, safe_heading;
 	int16 min_status = AccountStatus::Player;
 	uint8 min_level = 0;
-	char flag_needed[128];
 
 	auto z = GetZoneVersionWithFallback(
 		ZoneID(zone->GetShortName()),
 		zone->GetInstanceVersion()
 	);
 	if (!z) {
-		//this should not happen...
-		LogDebug("[CLIENT] Unable to query zone info for ourself [{}]", zone->GetShortName());
 		return false;
 	}
 
@@ -1259,10 +1256,6 @@ bool Client::CanBeInZone() {
 	min_status   = z->min_status;
 	min_level    = z->min_level;
 
-	if (!z->flag_needed.empty()) {
-		strcpy(flag_needed, z->flag_needed.c_str());
-	}
-
 	if (GetLevel() < min_level) {
 		LogDebug("[CLIENT] Character does not meet min level requirement ([{}] < [{}])!", GetLevel(), min_level);
 		return (false);
@@ -1272,13 +1265,13 @@ bool Client::CanBeInZone() {
 		return (false);
 	}
 
-	if (flag_needed[0] != '\0') {
+	if (!z->flag_needed.empty()) {
 		//the flag needed string is not empty, meaning a flag is required.
 		if (Admin() < minStatusToIgnoreZoneFlags && !HasZoneFlag(zone->GetZoneID())) {
-			LogDebug("[CLIENT] Character does not have the flag to be in this zone ([{}])!", flag_needed);
+			LogInfo("Character [{}] does not have the flag to be in this zone [{}]!", GetCleanName(), z->flag_needed);
-			return (false);
+			return false;
 		}
 	}
 
-	return(true);
+	return true;
 }