fix(keywords): some KID items were breaking certain active effects (#119

) Thanks to Ashen and PO3 on the skyrimmods discord, who directed me to the KID file as a possible cause for this. I narrowed it down to a handful of lines that cause this side effect with active effects, and disabled anything that looks like those. I'd rather give some items generic icons than cause gameplay bugs. The rest of this PR is cleanup I did while investigating the bug. This fixes #117 and very likely also fixes #81 .
ceejbot · Jan 20, 2024 · 130b1de · 130b1de
1 parent 503f80b
commit 130b1de
Show file tree

Hide file tree

Showing 10 changed files with 520 additions and 524 deletions.
diff --git a/installer/core/SoulsyHUD_KID.ini b/installer/core/SoulsyHUD_KID.ini
diff --git a/src/data/item_cache.rs b/src/data/item_cache.rs
@@ -106,8 +106,7 @@ impl ItemCache {
     /// Set the count of a cached item to the passed-in value.
     pub fn set_count(&mut self, form_spec: &str, new_count: u32) -> Option<&HudItem> {
         if !self.contains(form_spec) {
-            let fetched = fetch_game_item(form_spec);
-            self.record(fetched);
+            return None;
         }
 
         let Some(item) = self.lru.get_mut(form_spec) else {
@@ -121,8 +120,7 @@ impl ItemCache {
     /// cache, no action is taken.
     pub fn update_count(&mut self, form_spec: &str, new_count: u32) -> Option<&HudItem> {
         if !self.contains(form_spec) {
-            let fetched = fetch_game_item(form_spec);
-            self.record(fetched);
+            return None;
         }
         let Some(item) = self.lru.get_mut(form_spec) else {
             return None;

diff --git a/src/data/power.rs b/src/data/power.rs
@@ -13,7 +13,7 @@ pub struct PowerType {
 
 impl PowerType {
     pub fn new(name: &str, tags: Vec<String>) -> Self {
-        log::info!("{tags:?}");
+        // log::trace!("{tags:?}");
         let kywds = strings_to_enumset::<SpellKeywords>(&tags);
 
         let icon = if let Some(found) = icon_for_tagset(&kywds) {

diff --git a/src/game/gear.cpp b/src/game/gear.cpp
@@ -134,9 +134,9 @@ namespace gear
 
 		if (!foundObject) { return 0; }
 
-		rlog::debug("boundObjectForWornItem(constraint={}) found formid='{}';",
+		rlog::debug("boundObjectForWornItem(constraint={}) found formid='{:#08x}';",
 			static_cast<std::underlying_type_t<WornWhere>>(constraint),
-			rlog::formatAsHex(foundObject->formID));
+			foundObject->formID);
 
 		if (extraDataCopy.size() > 0) { outextra = extraDataCopy.back(); }
 		outobj = foundObject;
@@ -189,8 +189,7 @@ namespace gear
 
 		if (!foundObject) { return 0; }
 
-		rlog::debug(
-			"boundObjectMatchName '{}'; found formID={};"sv, nameToMatch, rlog::formatAsHex(foundObject->formID));
+		rlog::debug("boundObjectMatchName '{}'; found formID={:#08x};"sv, nameToMatch, foundObject->formID);
 		if (extraDataCopy.size() > 0) { outextra = extraDataCopy.back(); }
 		outobj = foundObject;
 		return equipData.count;
@@ -226,10 +225,10 @@ namespace gear
 
 		if (!foundObject) { return 0; }
 
-		rlog::trace("found {} instance(s) for bound object; name='{}'; formID={};"sv,
+		rlog::trace("found {} instance(s) for bound object; name='{}'; formID={:#08x};"sv,
 			count,
 			helpers::nameAsUtf8(form),
-			rlog::formatAsHex(form->formID));
+			form->formID);
 
 		if (extraDataCopy.size() > 0) { outextra = extraDataCopy.back(); }
 		outobj = foundObject;
@@ -520,10 +519,10 @@ namespace gear
 			return;
 		}
 
-		rlog::debug("queuing task to equip '{}'; left={}; formID={};"sv,
+		rlog::debug("queuing task to equip '{}'; left={}; formID={:#08x};"sv,
 			helpers::nameAsUtf8(form),
 			slot_is_left,
-			rlog::formatAsHex(equipObject->formID));
+			equipObject->formID);
 		auto* task = SKSE::GetTaskInterface();
 		if (task)
 		{
@@ -572,10 +571,10 @@ namespace gear
 			return;
 		}
 
-		rlog::debug("queued task to equip '{}'; left={}; formID={};"sv,
+		rlog::debug("queued task to equip '{}'; left={}; formID={:#08x};"sv,
 			helpers::nameAsUtf8(form),
 			slot_is_left,
-			rlog::formatAsHex(form->formID));
+			form->formID);
 	}
 
 	void unequipHand(RE::PlayerCharacter*& player, Action which)

diff --git a/src/game/shouts.cpp b/src/game/shouts.cpp
@@ -43,7 +43,7 @@ namespace shouts
 		{
 			auto* task = SKSE::GetTaskInterface();
 			if (!task) return;
-			rlog::trace("unequipping shout/power formID={};"sv, rlog::formatAsHex(selected_power->formID));
+			rlog::trace("unequipping shout/power formID={:#08x};"sv, selected_power->formID);
 			if (selected_power->Is(RE::FormType::Shout))
 			{
 				task->AddTask(

diff --git a/src/game/utility.cpp b/src/game/utility.cpp
@@ -29,13 +29,12 @@ namespace utility
 
 		if (const auto* current_ammo = thePlayer->GetCurrentAmmo(); current_ammo && current_ammo->formID == obj->formID)
 		{
-			// rlog::trace("ammo is already equipped; bound formID={}"sv, rlog::formatAsHex(obj->formID));
+			// rlog::trace("ammo is already equipped; bound formID={:#08x}"sv, obj->formID);
 			return;
 		}
 
-		rlog::debug("queuing task to equip ammo; name='{}'; bound formID={}"sv,
-			helpers::nameAsUtf8(obj),
-			rlog::formatAsHex(obj->formID));
+		rlog::debug(
+			"queuing task to equip ammo; name='{}'; bound formID={:#08x};"sv, helpers::nameAsUtf8(obj), obj->formID);
 		auto* task = SKSE::GetTaskInterface();
 		if (task)
 		{
@@ -59,8 +58,7 @@ namespace utility
 			{
 				task->AddTask([=]() { RE::ActorEquipManager::GetSingleton()->UnequipObject(thePlayer, ammo); });
 			}
-			rlog::debug(
-				"ammo unequipped; name='{}'; formID={}"sv, helpers::nameAsUtf8(ammo), rlog::formatAsHex(ammo->formID));
+			rlog::debug("ammo unequipped; name='{}'; formID={:#08x};"sv, helpers::nameAsUtf8(ammo), ammo->formID);
 		}
 	}
 
@@ -133,8 +131,8 @@ namespace utility
 
 	void consumePotion(const RE::TESForm* potionForm, RE::PlayerCharacter*& thePlayer)
 	{
-		rlog::trace("consumePotion called; form_id={}; potion='{}';"sv,
-			rlog::formatAsHex(potionForm->formID),
+		rlog::trace("consumePotion called; form_id={:#08x}; potion='{}';"sv,
+			potionForm->formID,
 			helpers::nameAsUtf8(potionForm));
 
 		RE::TESBoundObject* obj      = nullptr;
@@ -151,9 +149,9 @@ namespace utility
 		if (!obj->Is(RE::FormType::AlchemyItem))
 		{
 			helpers::honk();
-			rlog::warn("bound object is not an alchemy item? name='{}'; formID={};"sv,
+			rlog::warn("bound object is not an alchemy item? name='{}'; formID={:#08x};"sv,
 				helpers::nameAsUtf8(obj),
-				rlog::formatAsHex(obj->formID));
+				obj->formID);
 			return;
 		}
 
@@ -325,7 +323,7 @@ namespace utility
 		const auto* entry_point = static_cast<RE::BGSEntryPointPerkEntry*>(perk_entry);
 		const auto* perk        = entry_point->perk;
 
-		rlog::trace("perk formID={}; name='{}';"sv, rlog::formatAsHex(perk->formID), helpers::nameAsUtf8(perk));
+		rlog::trace("perk formID={:#08x}; name='{}';"sv, perk->formID, helpers::nameAsUtf8(perk));
 
 		// This was originally intended to handle many variations of the poison
 		// dose perk-- it should calculate the correct value from vanilla,

diff --git a/src/plugin/inventory.cpp b/src/plugin/inventory.cpp
@@ -61,19 +61,19 @@ RE::ObjectRefHandle PlayerHook::itemRemoved(RE::Actor* actor,
 	const RE::NiPoint3* a_drop_loc,
 	const RE::NiPoint3* a_rotate)
 {
-	auto retval = remove_item_(actor, object, delta, a_reason, extraDataList, a_move_to_ref, a_drop_loc, a_rotate);
 	if (object->IsInventoryObject())
 	{
 		auto* item_form = RE::TESForm::LookupByID(object->formID);
 		notifyInventoryChanged(item_form);
 	}
-	return retval;
+	return remove_item_(actor, object, delta, a_reason, extraDataList, a_move_to_ref, a_drop_loc, a_rotate);
 }
 
 void PlayerHook::add_item_functor(RE::TESObjectREFR* a_this, RE::TESObjectREFR* object, int32_t delta, bool a4, bool a5)
 {
 	add_item_functor_(a_this, object, delta, a4, a5);
 	auto item_form = RE::TESForm::LookupByID(object->GetBaseObject()->formID);
+	rlog::info("add_item_functor; {};", object->GetBaseObject()->formID);
 	notifyInventoryChanged(item_form);
 }
 

diff --git a/src/plugin/menus.cpp b/src/plugin/menus.cpp
@@ -75,8 +75,8 @@ RE::BSEventNotifyControl MenuHook::process_event(RE::InputEvent** eventPtr,
 					auto menu_form           = MenuSelection::getSelectionFromMenu(ui, selection);
 					if (!menu_form) continue;
 
-					rlog::debug("Got toggled favorite: form_id={}; form_type={}; is-favorited={};"sv,
-						rlog::formatAsHex(selection->form_id),
+					rlog::debug("Got toggled favorite: form_id={:#08x}; form_type={}; is-favorited={};"sv,
+						selection->form_id,
 						selection->formType,
 						selection->favorite);
 
@@ -156,7 +156,7 @@ uint32_t MenuSelection::makeFromFavoritesMenu(RE::FavoritesMenu* menu, MenuSelec
 	if (result.GetType() == RE::GFxValue::ValueType::kNumber)
 	{
 		form_id = static_cast<std::uint32_t>(result.GetNumber());
-		// rlog::debug("favorites menu selection has formid {}"sv, rlog::formatAsHex(form_id));
+		// rlog::debug("favorites menu selection has formid {:#08x}"sv, form_id);
 	}
 	if (form_id == 0) { return 0; }
 
@@ -218,7 +218,7 @@ void MenuSelection::makeFromInventoryMenu(RE::InventoryMenu* menu, MenuSelection
 	if (result.GetType() == RE::GFxValue::ValueType::kNumber)
 	{
 		RE::FormID form_id = static_cast<std::uint32_t>(result.GetNumber());
-		rlog::trace("formid {}"sv, rlog::formatAsHex(form_id));
+		rlog::trace("formid {:#08x}"sv, form_id);
 		auto* item_form = RE::TESForm::LookupByID(form_id);
 		if (!item_form) return;
 
@@ -261,7 +261,7 @@ void MenuSelection::makeFromMagicMenu(RE::MagicMenu* menu, MenuSelection*& outSe
 
 	for (auto* form : mfaves->spells)
 	{
-		rlog::debug("mfave form: id={}; name='{}'"sv, rlog::formatAsHex(form->GetFormID()), helpers::nameAsUtf8(form));
+		rlog::debug("mfave form: id={:#08x}; name='{}'"sv, form->GetFormID(), helpers::nameAsUtf8(form));
 		if (form->GetFormID() == form_id)
 		{
 			// match time

diff --git a/src/plugin/sinks.cpp b/src/plugin/sinks.cpp
@@ -32,9 +32,9 @@ void registerAllListeners()
 	auto okay    = player->AddAnimationGraphEventSink(listener);
 	if (okay) { rlog::info("    animation graph events to get grip changes."); }
 
-	// scriptEventSourceHolder->GetEventSource<RE::TESMagicEffectApplyEvent>()->AddEventSink(listener);
-	// scriptEventSourceHolder->GetEventSource<RE::TESActiveEffectApplyRemoveEvent>()->AddEventSink(listener);
-	// rlog::info("    magic effects come and go, talking of Michelangelo."sv);
+	//scriptEventSourceHolder->GetEventSource<RE::TESMagicEffectApplyEvent>()->AddEventSink(listener);
+	//scriptEventSourceHolder->GetEventSource<RE::TESActiveEffectApplyRemoveEvent>()->AddEventSink(listener);
+	//rlog::info("    magic effects come and go, talking of Michelangelo."sv);
 }
 
 TheListener* TheListener::singleton()
@@ -198,8 +198,6 @@ RE::BSEventNotifyControl TheListener::ProcessEvent(const RE::TESMagicEffectApply
 		return RE::BSEventNotifyControl::kContinue;
 	}
 
-	// We are specifically looking for VampireLordEffect on the player.
-
 	rlog::info("Effect status change: '{}' {} put \"{}\" ({}) on '{}' {}",
 		casterName,
 		event->caster ? rlog::formatAsHex(event->caster->GetFormID()) : "<none>",
@@ -215,11 +213,16 @@ RE::BSEventNotifyControl TheListener::ProcessEvent(const RE::TESActiveEffectAppl
 	[[maybe_unused]] RE::BSTEventSource<RE::TESActiveEffectApplyRemoveEvent>* source)
 {
 	// TODO; just logging for now
-	auto caster     = event->caster->GetBaseObject();
-	auto casterName = helpers::displayNameAsUtf8(caster);
+	auto caster     = event->caster ? event->caster->GetBaseObject() : nullptr;
+	auto casterName = caster ? helpers::displayNameAsUtf8(caster) : "<unknown>";
 
-	auto target     = event->target->GetBaseObject();
-	auto targetName = helpers::displayNameAsUtf8(target);
+	auto target     = event->target ? event->target->GetBaseObject() : nullptr;
+	auto targetName = target ? helpers::displayNameAsUtf8(target) : "<unknown>";
+
+	rlog::info(
+		"effect unique id={:#04x}; verb: {}", event->activeEffectUniqueID, event->isApplied ? "applied" : "removed");
+
+	if (!caster || !target) { return RE::BSEventNotifyControl::kContinue; }
 
 	const auto playerID = RE::PlayerCharacter::GetSingleton()->GetFormID();
 	if (caster->GetFormID() != playerID && target->GetFormID() != playerID)

diff --git a/src/util/helpers.cpp b/src/util/helpers.cpp
@@ -179,8 +179,7 @@ namespace helpers
 		if (form->IsDynamicForm())
 		{
 			// rlog::trace("it is dynamic"sv);
-			form_string =
-				fmt::format("{}{}{}", util::dynamic_name, util::delimiter, rlog::formatAsHex(form->GetFormID()));
+			form_string = fmt::format("{}{}{:#08x}", util::dynamic_name, util::delimiter, form->GetFormID());
 		}
 		else
 		{