From bcc5ae916d9bcdaf5c3c94e18ff85c2f82b8633a Mon Sep 17 00:00:00 2001 From: Richard Fortier Date: Sat, 29 Nov 2025 20:22:35 -0500 Subject: [PATCH 1/2] Fix multiple starts of quests when in-party Raise logging level and fix logs of quest progression. Previously, multi-execution of quest stage entry was suppressed. But multi quest starts weren't. This is a problem when a quest start has side effects that advance quest stage; as the party members started their quests, the stage-rewind would reflect back to the leader, allowing quest stage side effects to happen again. Also added fix to debugger to force setStage. This is needed so leader can set the stage to the stage they are at, and not have it suppressed so it is sent to party. Regularized quest logging so you can import into a spreadsheet, break fields on colon and comma (:,) --- Code/client/Games/Skyrim/Forms/TESQuest.cpp | 4 +- Code/client/Games/Skyrim/Forms/TESQuest.h | 2 +- .../Services/Debug/Views/QuestDebugView.cpp | 2 +- Code/client/Services/Generic/QuestService.cpp | 58 ++++++++++++++----- Code/server/Services/QuestService.cpp | 10 ++-- 5 files changed, 52 insertions(+), 24 deletions(-) diff --git a/Code/client/Games/Skyrim/Forms/TESQuest.cpp b/Code/client/Games/Skyrim/Forms/TESQuest.cpp index 6f4feeb4b..7191fdac3 100644 --- a/Code/client/Games/Skyrim/Forms/TESQuest.cpp +++ b/Code/client/Games/Skyrim/Forms/TESQuest.cpp @@ -97,9 +97,9 @@ bool TESQuest::SetStage(uint16_t newStage) return SetStage(this, newStage); } -void TESQuest::ScriptSetStage(uint16_t stageIndex) +void TESQuest::ScriptSetStage(uint16_t stageIndex, boolean bForce) { - if (currentStage == stageIndex || IsStageDone(stageIndex)) + if ((currentStage == stageIndex || IsStageDone(stageIndex)) && !bForce) return; using Quest = TESQuest; diff --git a/Code/client/Games/Skyrim/Forms/TESQuest.h b/Code/client/Games/Skyrim/Forms/TESQuest.h index 6c121e202..4e664ff6c 100644 --- a/Code/client/Games/Skyrim/Forms/TESQuest.h +++ b/Code/client/Games/Skyrim/Forms/TESQuest.h @@ -127,7 +127,7 @@ struct TESQuest : BGSStoryManagerTreeForm bool EnsureQuestStarted(bool& succeded, bool force); bool SetStage(uint16_t stage); - void ScriptSetStage(uint16_t stage); + void ScriptSetStage(uint16_t stage, boolean bForce = false); void SetStopped(); }; diff --git a/Code/client/Services/Debug/Views/QuestDebugView.cpp b/Code/client/Services/Debug/Views/QuestDebugView.cpp index 383f6e30a..61c43d40e 100644 --- a/Code/client/Services/Debug/Views/QuestDebugView.cpp +++ b/Code/client/Services/Debug/Views/QuestDebugView.cpp @@ -61,7 +61,7 @@ void DebugService::DrawQuestDebugView() sprintf_s(setStage, std::size(setStage), "Set stage (%d)", pStage->stageIndex); if (ImGui::Button(setStage)) - pQuest->ScriptSetStage(pStage->stageIndex); + pQuest->ScriptSetStage(pStage->stageIndex, true); } } diff --git a/Code/client/Services/Generic/QuestService.cpp b/Code/client/Services/Generic/QuestService.cpp index b32f501be..f01a01cf8 100644 --- a/Code/client/Services/Generic/QuestService.cpp +++ b/Code/client/Services/Generic/QuestService.cpp @@ -57,7 +57,7 @@ BSTEventResult QuestService::OnEvent(const TESQuestStartStopEvent* apEvent, cons if (ScopedQuestOverride::IsOverriden() || !m_world.Get().GetPartyService().IsInParty()) return BSTEventResult::kOk; - spdlog::info("Quest start/stop event: {:X}", apEvent->formId); + spdlog::info(__FUNCTION__ ": quest start/stop event formId: {:X}", apEvent->formId); if (TESQuest* pQuest = Cast(TESForm::GetById(apEvent->formId))) { @@ -105,7 +105,7 @@ BSTEventResult QuestService::OnEvent(const TESQuestStageEvent* apEvent, const Ev if (ScopedQuestOverride::IsOverriden() || !m_world.Get().GetPartyService().IsInParty()) return BSTEventResult::kOk; - spdlog::info("Quest stage event: {:X}, stage: {}", apEvent->formId, apEvent->stageId); + spdlog::info(__FUNCTION__ ": quest stage formId: {:X}, stage: {}", apEvent->formId, apEvent->stageId); // there is no reason to even fetch the quest object, since the event provides everything already.... if (TESQuest* pQuest = Cast(TESForm::GetById(apEvent->formId))) @@ -157,13 +157,13 @@ void QuestService::OnQuestUpdate(const NotifyQuestUpdate& aUpdate) noexcept TESQuest* pQuest = Cast(TESForm::GetById(formId)); if (!pQuest) { - spdlog::error("Failed to find quest, base id: {:X}, mod id: {:X}", aUpdate.Id.BaseId, aUpdate.Id.ModId); + spdlog::error(__FUNCTION__ ": failed to find quest, gameId: {:X}, stage: {}", aUpdate.Id.LogFormat(), aUpdate.Stage); return; } if (pQuest->type == TESQuest::Type::None || pQuest->type == TESQuest::Type::Miscellaneous) { - spdlog::info(__FUNCTION__ ": receiving type none/misc quest update gameId {:X} questStage {} questStatus {} questType {} formId {:X} name {}", + spdlog::info(__FUNCTION__ ": receiving type none/misc quest update gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); } @@ -172,27 +172,46 @@ void QuestService::OnQuestUpdate(const NotifyQuestUpdate& aUpdate) noexcept switch (aUpdate.Status) { case NotifyQuestUpdate::Started: - { - pQuest->ScriptSetStage(aUpdate.Stage); - pQuest->SetActive(true); + if (pQuest->getState() == TESQuest::State::Running) // Supress duplicate or loopback quest starts + { + spdlog::info(__FUNCTION__ ": suppressing duplicate quest start gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", + aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); + } + else + { + pQuest->ScriptSetStage(aUpdate.Stage); + pQuest->SetActive(true); + spdlog::info(__FUNCTION__ ": remote quest started gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", + aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); + } bResult = true; - spdlog::info("Remote quest started: {:X}, stage: {}", formId, aUpdate.Stage); break; - } case NotifyQuestUpdate::StageUpdate: pQuest->ScriptSetStage(aUpdate.Stage); bResult = true; - spdlog::info("Remote quest updated: {:X}, stage: {}", formId, aUpdate.Stage); + spdlog::info(__FUNCTION__ ": remote quest updated gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", + aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); break; case NotifyQuestUpdate::Stopped: - bResult = StopQuest(formId); - spdlog::info("Remote quest stopped: {:X}, stage: {}", formId, aUpdate.Stage); + if (pQuest->getState() == TESQuest::State::Stopped) // Supress duplicate or loopback quest stop + { + spdlog::info(__FUNCTION__ ": suppressing duplicate quest stop gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", + aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); + } + else + { + bResult = StopQuest(formId); + spdlog::info(__FUNCTION__ ": remote quest stopped gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", + aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); + } + bResult = true; break; default: break; } if (!bResult) - spdlog::error("Failed to update the client quest state, quest: {:X}, stage: {}, status: {}", formId, aUpdate.Stage, aUpdate.Status); + spdlog::error(__FUNCTION__ ": failed to update the client quest state gameId: {:X}, questStage: {}, questStatus: {}, questType: {}, formId: {:X}, name: {}", + aUpdate.Id.LogFormat(), aUpdate.Stage, aUpdate.Status, aUpdate.ClientQuestType, formId, pQuest->fullName.value.AsAscii()); } bool QuestService::StopQuest(uint32_t aformId) @@ -200,8 +219,17 @@ bool QuestService::StopQuest(uint32_t aformId) TESQuest* pQuest = Cast(TESForm::GetById(aformId)); if (pQuest) { - pQuest->SetActive(false); - pQuest->SetStopped(); + if (pQuest->getState() == TESQuest::State::Stopped) // Supress duplicate or loopback quest stop + { + spdlog::info(__FUNCTION__ ": suppressing duplicate quest stop formId: {:X}, questStage: {}, questFlags: {:X}, questType: {}, formId: {:X}, name: {}", + aformId, pQuest->currentStage, static_cast(pQuest->flags), static_cast(pQuest->type), aformId, pQuest->fullName.value.AsAscii()); + } + else + { + pQuest->SetActive(false); + pQuest->SetStopped(); + } + return true; } diff --git a/Code/server/Services/QuestService.cpp b/Code/server/Services/QuestService.cpp index 52133e74c..f1476bf54 100644 --- a/Code/server/Services/QuestService.cpp +++ b/Code/server/Services/QuestService.cpp @@ -41,7 +41,7 @@ void QuestService::OnQuestChanges(const PacketEvent& acMessa { if (!bEnableMiscQuestSync) return; - spdlog::info("{}: syncing type none/misc quest to party, gameId {:X} questStage {} questStatus {} questType {}", + spdlog::info("{}: syncing type none/misc quest to party, gameId: {:X}, questStage: {}, questStatus: {}; questType: {}", __FUNCTION__, notify.Id.LogFormat(), notify.Stage, notify.Status, notify.ClientQuestType); } @@ -58,7 +58,7 @@ void QuestService::OnQuestChanges(const PacketEvent& acMessa if (message.Status == RequestQuestUpdate::Started) { - spdlog::debug("Started quest: {:X} stage: {}", message.Id.LogFormat(), message.Stage); + spdlog::info("{}: started quest: {:X}, stage: {}", __FUNCTION__, message.Id.LogFormat(), message.Stage); notify.Status = NotifyQuestUpdate::Started; } @@ -69,7 +69,7 @@ void QuestService::OnQuestChanges(const PacketEvent& acMessa } else { - spdlog::debug("Updated quest: {:X}, stage: {}", message.Id.LogFormat(), message.Id.BaseId, message.Stage); + spdlog::info("{}: updated quest: {:X}, stage: {}", __FUNCTION__, message.Id.LogFormat(), message.Stage); auto& record = *questIt; record.Id = message.Id; @@ -80,12 +80,12 @@ void QuestService::OnQuestChanges(const PacketEvent& acMessa } else if (message.Status == RequestQuestUpdate::Stopped) { - spdlog::debug("Stopped quest: {:X}, stage: {}", message.Id.LogFormat(), message.Id.BaseId, message.Stage); + spdlog::info("{}: stopped quest: {:X}, stage: {}", __FUNCTION__, message.Id.LogFormat(), message.Stage); if (questIt != entries.end()) entries.erase(questIt); else - spdlog::warn("Unable to delete quest object {:X}", message.Id.LogFormat(), message.Id.BaseId); + spdlog::warn("{}: unable to delete quest object {:X}", __FUNCTION__, message.Id.LogFormat()); notify.Status = NotifyQuestUpdate::Stopped; } From 236fe5f09cebafb393980fcc1bc28b9c3e60a606 Mon Sep 17 00:00:00 2001 From: Richard Fortier Date: Wed, 10 Dec 2025 17:40:56 -0500 Subject: [PATCH 2/2] Fix declaration to use built-in instead of typedef --- Code/client/Games/Skyrim/Forms/TESQuest.cpp | 2 +- Code/client/Games/Skyrim/Forms/TESQuest.h | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/Code/client/Games/Skyrim/Forms/TESQuest.cpp b/Code/client/Games/Skyrim/Forms/TESQuest.cpp index 7191fdac3..b91a734a4 100644 --- a/Code/client/Games/Skyrim/Forms/TESQuest.cpp +++ b/Code/client/Games/Skyrim/Forms/TESQuest.cpp @@ -97,7 +97,7 @@ bool TESQuest::SetStage(uint16_t newStage) return SetStage(this, newStage); } -void TESQuest::ScriptSetStage(uint16_t stageIndex, boolean bForce) +void TESQuest::ScriptSetStage(uint16_t stageIndex, bool bForce) { if ((currentStage == stageIndex || IsStageDone(stageIndex)) && !bForce) return; diff --git a/Code/client/Games/Skyrim/Forms/TESQuest.h b/Code/client/Games/Skyrim/Forms/TESQuest.h index 4e664ff6c..b2950318e 100644 --- a/Code/client/Games/Skyrim/Forms/TESQuest.h +++ b/Code/client/Games/Skyrim/Forms/TESQuest.h @@ -127,7 +127,7 @@ struct TESQuest : BGSStoryManagerTreeForm bool EnsureQuestStarted(bool& succeded, bool force); bool SetStage(uint16_t stage); - void ScriptSetStage(uint16_t stage, boolean bForce = false); + void ScriptSetStage(uint16_t stage, bool bForce = false); void SetStopped(); };