Files
test/Documentation/SKILL_CAST_BLOCKING_DEBUG_SESSION.md
2026-03-13 16:03:47 +07:00

14 KiB

Skill Cast Blocking During Flash Move - Debug Session Summary

Date: 2026-03-04
Status: Logging added to C++ code to trace skill casting blocking during flash move
Goal: Understand where and why skill casting is blocked when flash move is active


Problem Description

In C++, when a character is performing a flash move (瞬移技能) and the player tries to cast another skill, the skill casting is silently blocked (nothing happens). In C#, the same scenario allows skill casting but the server sends an error message. We want to match C++ behavior and understand the blocking mechanism.

Key Observation:

  • C++: Skill casting is blocked during flash move (no error, just doesn't work)
  • C#: Skill casting works but server rejects it with error
  • Goal: Make C# match C++ behavior and understand the blocking mechanism

Root Cause Hypothesis

The blocking happens through the work system's priority mechanism:

  • Flash move work runs at PRIORITY_2
  • CanCastSkillImmediately() checks: !IsSpellingMagic() && !HasWorkRunningOnPriority(PRIORITY_2)
  • When flash move is active, HasWorkRunningOnPriority(PRIORITY_2) returns true
  • This causes CanCastSkillImmediately() to return false, blocking skill casting

Files Modified

C++ Files

1. EC_HostPlayer.cpp

Location: perfect-world-source/perfect-world-source/CElement/CElementClient/EC_HostPlayer.cpp

Changes Made:

  • Added logging in ApplySkillShortcut() method (starting at line ~2468)
  • Added logging in CastSkill() method (starting at line ~6039)
  • All logs use prefix [SKILL_CAST_DEBUG] for easy filtering
  • Uses a_LogOutput(1, ...) function

Key Logging Points in ApplySkillShortcut():

  • Line ~2485: CanDo(CANDO_SPELLMAGIC) check
  • Line ~2491: InSlidingState() check
  • Line ~2506: Skill not found
  • Line ~2524: CheckSkillCastCondition() check
  • Line ~2669: Entry to main casting path (with state values)
  • Line ~2673: ReadyToCast() check
  • Line ~2681: CanCastSkillImmediately() check (KEY BLOCKING POINT)
  • Line ~2692: NaturallyStopMoving() check
  • Line ~2700: CanDo(CANDO_FLASHMOVE) check
  • Line ~2705: Success - setting prep skill
  • Line ~2712: IsSpellingMagic() && same skill check
  • Line ~2717: Entry to trace object path
  • Line ~2721: ReadyToCast() in trace path
  • Line ~2737: CanCastSkillImmediately() in trace path (KEY BLOCKING POINT)

Key Logging Points in CastSkill():

  • Line ~6041: Entry with skill ID, target, and IsSpellingMagic state
  • Line ~6045: Blocked when prep skill invalid or not ready

2. EC_HPWork.cpp

Location: perfect-world-source/perfect-world-source/CElement/CElementClient/EC_HPWork.cpp

Changes Made:

  • Added logging in CanCastSkillImmediately() method (line ~243)
  • Added logging in HasWorkRunningOnPriority() method (line ~668)
  • Added headers: #include <string.h> and #include <stdio.h>

Key Implementation Details:

  • CanCastSkillImmediately() calls HasWorkOnPriority() directly (not HasWorkRunningOnPriority()) to avoid infinite recursion
  • HasWorkRunningOnPriority() logs work IDs at the specified priority
  • Buffer management: Uses function-scope workInfoBuffer[256] to avoid scope issues

CanCastSkillImmediately() Logging:

bool CECHPWorkMan::CanCastSkillImmediately(int idSkill)const{
	bool isSpellingMagic = IsSpellingMagic();
	// Call HasWorkOnPriority directly to avoid infinite recursion from logging
	bool hasWorkOnPriority2 = HasWorkOnPriority(PRIORITY_2);
	bool result = !isSpellingMagic && !hasWorkOnPriority2;
	
	// Log what work is running at PRIORITY_2 if any
	const char* workInfo = "";
	if (hasWorkOnPriority2 && ValidatePriority(PRIORITY_2))
	{
		const WorkList& workList = m_WorkStack[PRIORITY_2];
		if (!workList.empty())
		{
			workInfo = workList[0]->GetWorkName();
		}
	}
	
	a_LogOutput(1, "[SKILL_CAST_DEBUG] CanCastSkillImmediately: skillID=%d, IsSpellingMagic=%d, HasWorkOnPriority2=%d, WorkAtPriority2=[%s], result=%d", 
		idSkill, isSpellingMagic ? 1 : 0, hasWorkOnPriority2 ? 1 : 0, workInfo, result ? 1 : 0);
	return result;
}

HasWorkRunningOnPriority() Logging:

bool CECHPWorkMan::HasWorkRunningOnPriority(int iPriority)const{
	bool result = HasWorkOnPriority(iPriority);
	
	// Log what work IDs are at this priority if any
	char workInfoBuffer[256] = {0};
	const char* workInfo = "";
	if (result && ValidatePriority(iPriority))
	{
		const WorkList& workList = m_WorkStack[iPriority];
		if (!workList.empty())
		{
			for (size_t i = 0; i < workList.size() && i < 5; ++i)  // Limit to 5 works
			{
				if (i > 0) strcat(workInfoBuffer, ", ");
				char workStr[64];
				sprintf(workStr, "%s(ID:%d)", workList[i]->GetWorkName(), workList[i]->GetWorkID());
				strcat(workInfoBuffer, workStr);
			}
			workInfo = workInfoBuffer;
		}
	}
	
	a_LogOutput(1, "[SKILL_CAST_DEBUG] HasWorkRunningOnPriority: priority=%d, result=%d, currentPriority=%d, WorkIDs=[%s]", 
		iPriority, result ? 1 : 0, m_iCurPriority, workInfo);
	return result;
}

C# Files (Previous Attempt - Rejected)

Note: The user rejected C# logging changes, wanting C++ logging instead. However, the C# code structure is documented here for reference.

CECHostPlayer.Skill.cs

Location: perfect-world-unity/Assets/Scripts/CECHostPlayer.Skill.cs

Key Methods:

  • ApplySkillShortcut() - Entry point for skill casting
  • CastSkill() - Actual skill casting logic

Current State:

  • Line ~646: Has CanCastSkillImmediately() check added (but user wants to understand C++ first)
  • The check uses: m_pWorkMan.CanCastSkillImmediately(pSkill.GetSkillID())

EC_HPWork.cs

Location: perfect-world-unity/Assets/PerfectWorld/Scripts/Managers/EC_HPWork.cs

Key Methods:

  • CanCastSkillImmediately() - Line ~344: return !IsSpellingMagic() && !HasWorkRunningOnPriority(Work_priority.PRIORITY_2);
  • HasWorkRunningOnPriority() - Line ~701: Returns work status at specified priority

Work System Architecture

Priority Levels

  • PRIORITY_0 (0): Stand, dead, etc.
  • PRIORITY_1 (1): Move, trace, hack, spell, etc.
  • PRIORITY_2 (2): Flash move runs here

Flash Move Work

  • Work ID: WORK_FLASHMOVE (14)
  • Priority: PRIORITY_2
  • Class: CECHPWorkFMove (in EC_HPWorkFly.cpp)

Blocking Mechanism

bool CECHPWorkMan::CanCastSkillImmediately(int idSkill)const{
	return !IsSpellingMagic() && !HasWorkRunningOnPriority(PRIORITY_2);
}

Logic:

  1. If IsSpellingMagic() is true → block
  2. If any work is running at PRIORITY_2 → block
  3. Flash move runs at PRIORITY_2, so when active, it blocks skill casting

Expected Log Flow

When trying to cast a skill during flash move, you should see:

[SKILL_CAST_DEBUG] ApplySkillShortcut: Entering main casting path, skillID=XXX, IsMeleeing=0, IsSpellingMagic=0, iTargetType=0, idCastTarget=XXX
[SKILL_CAST_DEBUG] ApplySkillShortcut: Entering main casting path, skillID=XXX, ReadyToCast=1
[SKILL_CAST_DEBUG] HasWorkRunningOnPriority: priority=2, result=1, currentPriority=2, WorkIDs=[WORK_FLASHMOVE(ID:14)]
[SKILL_CAST_DEBUG] CanCastSkillImmediately: skillID=XXX, IsSpellingMagic=0, HasWorkOnPriority2=1, WorkAtPriority2=[WORK_FLASHMOVE], result=0
[SKILL_CAST_DEBUG] ApplySkillShortcut: BLOCKED - CanCastSkillImmediately returned false, skillID=XXX, IsSpellingMagic=0, HasWorkOnPriority2=1

Key Code Locations

C++ Code

File Method Line Purpose
EC_HostPlayer.cpp ApplySkillShortcut() ~2468 Entry point for skill casting
EC_HostPlayer.cpp CastSkill() ~6039 Actual skill casting execution
EC_HPWork.cpp CanCastSkillImmediately() ~243 Checks if skill can be cast (BLOCKING LOGIC)
EC_HPWork.cpp HasWorkRunningOnPriority() ~668 Checks if work exists at priority
EC_HPWork.cpp HasWorkOnPriority() ~664 Internal check (no logging)

C# Code (Reference)

File Method Line Purpose
CECHostPlayer.Skill.cs ApplySkillShortcut() ~445 Entry point for skill casting
CECHostPlayer.Skill.cs CastSkill() ~742 Actual skill casting execution
EC_HPWork.cs CanCastSkillImmediately() ~344 Checks if skill can be cast
EC_HPWork.cs HasWorkRunningOnPriority() ~701 Checks if work exists at priority

Important Constants

Work IDs

WORK_FLASHMOVE = 14
WORK_SPELLOBJECT = 4
WORK_TRACEOBJECT = 2

Priorities

PRIORITY_0 = 0
PRIORITY_1 = 1
PRIORITY_2 = 2  // Flash move runs here

How to Use the Logs

  1. Run the game and perform a flash move
  2. While flash move is active, try to cast another skill
  3. Filter logs by searching for [SKILL_CAST_DEBUG]
  4. Trace the execution path:
    • Entry to ApplySkillShortcut
    • Which path is taken (main casting path vs trace object path)
    • CanCastSkillImmediately result and why it's false
    • HasWorkRunningOnPriority showing WORK_FLASHMOVE at PRIORITY_2

Next Steps

  1. Test the C++ logging:

    • Compile and run the C++ client
    • Cast a flash move skill
    • Try to cast another skill during flash move
    • Collect logs with [SKILL_CAST_DEBUG] prefix
  2. Analyze the logs:

    • Verify that CanCastSkillImmediately returns false
    • Verify that HasWorkRunningOnPriority(PRIORITY_2) returns true
    • Verify that WORK_FLASHMOVE is shown in the work list
  3. Apply to C# (if needed):

    • Once C++ behavior is confirmed, ensure C# has the same check
    • The check should be: if (!m_pWorkMan.CanCastSkillImmediately(pSkill.GetSkillID())) return false;
    • This should be in ApplySkillShortcut() main casting path (around line 646)

Flash Move Distance Issue (Previously Fixed)

  • Problem: Server sending wrong position (current pos instead of destination)
  • Fix: Increased distance threshold from 0.01f to 0.5f in EC_HPWorkFly.cs::PrepareMove()
  • Status: Fixed

Current Issue: Skill Casting During Flash Move

  • Problem: C# allows skill casting during flash move, server rejects it
  • Goal: Match C++ behavior (block skill casting during flash move)
  • Status: 🔍 Investigating with C++ logging

Technical Notes

Logging Function

  • C++: a_LogOutput(int iLevel, const char* szMsg, ...)
  • Header: Included via EC_Global.hALog.h
  • Usage: a_LogOutput(1, "format string", args...)

String Formatting

  • Uses C-style sprintf() and strcat()
  • Buffer size: 256 bytes for work info
  • Limits to 5 works to avoid overflow

Recursion Prevention

  • CanCastSkillImmediately() calls HasWorkOnPriority() directly (not HasWorkRunningOnPriority()) to avoid infinite recursion when logging

Code Snippets for Reference

C++ ApplySkillShortcut Main Path

if (!IsMeleeing() && !IsSpellingMagic() &&
    (!iTargetType || idCastTarget == m_PlayerInfo.cid))
{
    a_LogOutput(1, "[SKILL_CAST_DEBUG] ApplySkillShortcut: Entering main casting path, skillID=%d, IsMeleeing=%d, IsSpellingMagic=%d, iTargetType=%d, idCastTarget=%d", 
        idSkill, IsMeleeing() ? 1 : 0, IsSpellingMagic() ? 1 : 0, iTargetType, idCastTarget);
    if (!pSkill->ReadyToCast())
    {
        a_LogOutput(1, "[SKILL_CAST_DEBUG] ApplySkillShortcut: BLOCKED - ReadyToCast() returned false, skillID=%d", idSkill);
        return false;
    }

    // Check if skill can be cast immediately (blocks casting during flash move at PRIORITY_2)
    if (!m_pWorkMan->CanCastSkillImmediately(pSkill->GetSkillID()))
    {
        bool hasWorkOnPriority2 = m_pWorkMan->HasWorkRunningOnPriority(CECHPWorkMan::PRIORITY_2);
        a_LogOutput(1, "[SKILL_CAST_DEBUG] ApplySkillShortcut: BLOCKED - CanCastSkillImmediately returned false, skillID=%d, IsSpellingMagic=%d, HasWorkOnPriority2=%d", 
            idSkill, IsSpellingMagic() ? 1 : 0, hasWorkOnPriority2 ? 1 : 0);
        return false;
    }
    // ... rest of casting logic
}

C++ CanCastSkillImmediately

bool CECHPWorkMan::CanCastSkillImmediately(int idSkill)const{
	bool isSpellingMagic = IsSpellingMagic();
	// Call HasWorkOnPriority directly to avoid infinite recursion from logging
	bool hasWorkOnPriority2 = HasWorkOnPriority(PRIORITY_2);
	bool result = !isSpellingMagic && !hasWorkOnPriority2;
	
	const char* workInfo = "";
	if (hasWorkOnPriority2 && ValidatePriority(PRIORITY_2))
	{
		const WorkList& workList = m_WorkStack[PRIORITY_2];
		if (!workList.empty())
		{
			workInfo = workList[0]->GetWorkName();
		}
	}
	
	a_LogOutput(1, "[SKILL_CAST_DEBUG] CanCastSkillImmediately: skillID=%d, IsSpellingMagic=%d, HasWorkOnPriority2=%d, WorkAtPriority2=[%s], result=%d", 
		idSkill, isSpellingMagic ? 1 : 0, hasWorkOnPriority2 ? 1 : 0, workInfo, result ? 1 : 0);
	return result;
}

Questions to Answer

  1. Where is skill casting blocked in C++? → CanCastSkillImmediately() check
  2. Why is it blocked? → Flash move work at PRIORITY_2 blocks it
  3. 🔍 Does the logging confirm the blocking mechanism? → Need to test
  4. 🔍 Should C# have the same check? → Yes, if C++ behavior is confirmed

Session Summary

What We Did:

  1. Added comprehensive logging to C++ ApplySkillShortcut() method
  2. Added logging to C++ CastSkill() method
  3. Added logging to C++ CanCastSkillImmediately() method
  4. Added logging to C++ HasWorkRunningOnPriority() method
  5. Fixed recursion issue in CanCastSkillImmediately()
  6. Fixed buffer scope issues in logging code

What's Next:

  1. Test the C++ logging to confirm blocking mechanism
  2. Verify logs show WORK_FLASHMOVE at PRIORITY_2 when blocking occurs
  3. Apply same blocking logic to C# if confirmed

Key Insight: The blocking happens naturally through the work system's priority mechanism - no explicit flash move check needed. The CanCastSkillImmediately() method already checks for any work at PRIORITY_2, which includes flash move.