test/Documentation/FLASHMOVE_SKILL_DEBUG_SUMMARY.md

Flashmove Skill Casting Issue - Debug Summary

Problem Description

Issue: After casting a flashmove skill in C#, when attempting to cast another skill immediately after, the client receives error message ID 20 (FIXMSG_NEEDITEM - "Need item"), preventing skill casting. This issue does NOT occur in the C++ version.

Error Code 20: Returned by CheckSkillCastCondition() when a skill requires an item but the player doesn't have it.

Investigation Status

What We've Done

1. Added comprehensive logging to C# (CECHostPlayer.Skill.cs and CECHostPlayer.Combat.cs)

   • Entry logging in ApplySkillShortcut() with full state information
   • Detailed logging in CastSkill() for network commands and m_pPrepSkill state changes
   • Detailed logging in CheckSkillCastCondition() for item requirements
   • Server response logging in OnMsgPlayerCastSkill()
   • Enhanced logging to track m_pPrepSkill state transitions (set/clear operations)

2. Added matching logging to C++ (EC_HostPlayer.cpp and EC_HostMsg.cpp)

   • Same comprehensive logging to enable direct comparison

3. Removed non-C++ code (2026-03-09)

   • Removed safeguard code that cleared stale m_pPrepSkill at start of ApplySkillShortcut()
   • This code didn't exist in C++ and was causing divergence from original behavior
   • C# code now matches C++ behavior exactly for m_pPrepSkill handling

Key Files Modified

C# Files:

• e:\Projects\perfect-world-unity\Assets\Scripts\CECHostPlayer.Skill.cs

  • ApplySkillShortcut() - Lines ~445-744
  • CastSkill() - Lines ~751-1002
  • CheckSkillCastCondition() - Lines ~1208-1222

• e:\Projects\perfect-world-unity\Assets\Scripts\CECHostPlayer.Combat.cs

  • OnMsgPlayerCastSkill() - Lines ~208-660
    • OBJECT_CAST_SKILL handler - Lines ~219-285
    • OBJECT_CAST_POS_SKILL handler - Lines ~414-538
    • SKILL_PERFORM handler - Lines ~287-305

C++ Files:

• perfect-world-source/perfect-world-source/CElement/CElementClient/EC_HostPlayer.cpp

  • ApplySkillShortcut() - Lines ~2468-2800
  • CastSkill() - Lines ~6037-6250
  • CheckSkillCastCondition() - Lines ~5779-5851

• perfect-world-source/perfect-world-source/CElement/CElementClient/EC_HostMsg.cpp

  • OnMsgPlayerCastSkill() - Lines ~5865-6151
    • OBJECT_CAST_SKILL handler - Lines ~5878-5932
    • OBJECT_CAST_POS_SKILL handler - Lines ~6038-6151
    • SKILL_PERFORM handler - Lines ~5933-5941

Key Differences Found

Flashmove Skill Handling

C++ Behavior:

• When OBJECT_CAST_POS_SKILL is received, creates WORK_FLASHMOVE work
• m_pPrepSkill is cleared in SKILL_PERFORM message (after skill execution)
• Flashmove skills use c2s_CmdCastPosSkill() network command

C# Behavior:

• Same as C++ for most parts
• Potential Issue: m_pPrepSkill might not be cleared properly when OBJECT_CAST_POS_SKILL is received

Network Commands

Flashmove Skills:

• Self-target flashmove: c2s_CmdCastPosSkill(skillID, position, byPVPMask, 0, NULL)
• Target flashmove: c2s_CmdCastPosSkill(skillID, position, byPVPMask, 1, &idTarget)

Regular Skills:

• c2s_CmdCastSkill(skillID, byPVPMask, targetCount, targets[])

Instant Skills:

• c2s_CmdCastInstantSkill(skillID, byPVPMask, targetCount, targets[])

Logging Format

All logs use the prefix [SKILL_CAST_DEBUG] for easy filtering.

Key Log Points to Compare

1. ApplySkillShortcut Entry:

   [SKILL_CAST_DEBUG] ApplySkillShortcut: Entry, skillID=X, IsSpellingMagic=Y, m_pPrepSkill=Z, m_pCurSkill=W, IsFlashMoving=V
   

2. CheckSkillCastCondition:

   [SKILL_CAST_DEBUG] CheckSkillCastCondition: Entry, skillID=X
   [SKILL_CAST_DEBUG] CheckSkillCastCondition: Item check, skillID=X, idItem=Y, itemTotalNum=Z
   [SKILL_CAST_DEBUG] CheckSkillCastCondition: ERROR 20 - Need item, skillID=X, requiredItem=Y, have=Z
   

3. CastSkill Network Commands:

   [SKILL_CAST_DEBUG] CastSkill: Sending c2s_CmdCastPosSkill (flashmove self), skillID=X, pos=(x,y,z), byPVPMask=Y
   [SKILL_CAST_DEBUG] CastSkill: Sending c2s_CmdCastSkill (regular), skillID=X, target=Y, byPVPMask=Z
   

4. Server Responses:

   [SKILL_CAST_DEBUG] OnMsgPlayerCastSkill: Received OBJECT_CAST_POS_SKILL, skillID=X, m_pPrepSkill=Y, m_pCurSkill=Z
   [SKILL_CAST_DEBUG] OnMsgPlayerCastSkill: Received SKILL_PERFORM, m_pPrepSkill=X (clearing)
   

What to Check When Testing

After Flashmove, Before Next Skill:

1. State Variables:

   • Is m_pPrepSkill still set? (Should be NULL)
   • Is IsSpellingMagic() returning true? (Should be false)
   • Is IsFlashMoving() returning true? (Should be false)
   • Is m_pCurSkill set? (May or may not be set)

2. Server Response:

   • Did OBJECT_CAST_POS_SKILL arrive?
   • Was WORK_FLASHMOVE created?
   • Was m_pPrepSkill cleared when it should be?

3. Next Skill Cast:

   • What does CheckSkillCastCondition() return? (Should be 0, not 20)
   • If error 20: What item is required? What's the current count?
   • Are network command parameters correct?

Potential Root Causes

1. m_pPrepSkill Not Cleared:

   • In C++, m_pPrepSkill is cleared in SKILL_PERFORM message
   • In C#, might not be cleared properly after flashmove
   • This could cause the next skill to check conditions with wrong skill reference

2. Work State Issue:

   • WORK_FLASHMOVE might not be finishing properly
   • IsSpellingMagic() or IsFlashMoving() might return true when they shouldn't
   • This could block the next skill cast

3. Item Requirement Check:

   • CheckSkillCastCondition() might be checking item requirements incorrectly
   • The flashmove skill's item requirement might be incorrectly applied to the next skill

4. Network Command Timing:

   • Client might be sending the next skill command before server confirms flashmove
   • Server might reject it due to state mismatch

Next Steps

1. Run Test:

   • Cast flashmove skill
   • Immediately cast another skill
   • Collect logs from both C++ and C# versions
   • Note: Logs from SessionLog_2026-03-09_10-48-05.txt show error 20 still occurs

2. Compare Logs:

   • Filter by [SKILL_CAST_DEBUG]
   • Compare state variables at each step
   • Identify where C# behavior diverges from C++
   • Key: Check if [SKILL_CAST_DEBUG] logs are appearing (they weren't in the test log)

3. Focus Areas:

   • When is m_pPrepSkill cleared in C# vs C++? (Should be immediately after sending flashmove command)
   • What is the state when CheckSkillCastCondition() returns error 20?
   • Are network commands sent with correct parameters?
   • NEW: Verify that debug logs are actually being written (may need to check Unity console or log file location)

4. Server-Side Investigation:

   • Error 20 comes from server, not client CheckSkillCastCondition()
   • Server might be checking wrong skill's item requirement
   • Server might be receiving incorrect skill ID in network command
   • Need to verify what skill ID the server receives vs what client sends

Code References

CheckSkillCastCondition Error 20:

// C++: EC_HostPlayer.cpp line ~5781-5785
int idItem = pSkill->GetRequiredItem();
if (idItem > 0 && GetPack()->GetItemTotalNum(idItem) <= 0)
{
    return 20; // Need item
}

// C#: CECHostPlayer.Skill.cs line ~1161-1165
int idItem = pSkill.SkillCore.GetItemCost();
if (idItem > 0 && GetPack().GetItemTotalNum(idItem) <= 0)
{
    return 20; // Need item
}

Flashmove Skill Casting:

// C++: EC_HostPlayer.cpp line ~6106-6130
else if (m_pPrepSkill->GetType() == CECSkill::TYPE_FLASHMOVE)
{
    // ... flashmove logic ...
    g_pGame->GetGameSession()->c2s_CmdCastPosSkill(...);
    m_pPrepSkill = NULL;
}

// C#: CECHostPlayer.Skill.cs line ~831-860
else if (m_pPrepSkill.GetType() == (int)CECSkill.SkillType.TYPE_FLASHMOVE)
{
    // ... flashmove logic ...
    UnityGameSession.c2s_CmdCastPosSkill(...);
    m_pPrepSkill = null;
}

Server Response Handling:

// C++: EC_HostMsg.cpp line ~6038-6147
case OBJECT_CAST_POS_SKILL:
{
    // Creates WORK_FLASHMOVE
    CECHPWorkFMove* pWork = (CECHPWorkFMove*)m_pWorkMan->CreateWork(CECHPWork::WORK_FLASHMOVE);
    // ...
}

// C#: CECHostPlayer.Combat.cs line ~414-534
case CommandID.OBJECT_CAST_POS_SKILL:
{
    // Creates WORK_FLASHMOVE
    CECHPWorkFMove pWork = (CECHPWorkFMove)m_pWorkMan.CreateWork(CECHPWork.Host_work_ID.WORK_FLASHMOVE);
    // ...
}

Important Notes

• All logging uses [SKILL_CAST_DEBUG] prefix for easy filtering
• Error 20 = FIXMSG_NEEDITEM = "Need item" error
• Flashmove skills are TYPE_FLASHMOVE skill type
• m_pPrepSkill should be cleared after sending network command (for instant/flashmove) or on server response (for regular skills)
• m_pCurSkill is set when server responds with OBJECT_CAST_SKILL or OBJECT_CAST_POS_SKILL

Questions to Answer

1. When exactly does error 20 occur? (Which skill triggers it?)
2. What item is required? (Check the logs for requiredItem value)
3. Does the player actually have the item? (Check itemTotalNum in logs)
4. Is m_pPrepSkill still set to the flashmove skill when checking the next skill?
5. Is CheckSkillCastCondition() being called with the correct skill object?
6. NEW: Why are [SKILL_CAST_DEBUG] logs not appearing in SessionLog_2026-03-09_10-48-05.txt?
7. NEW: Is the error coming from client-side CheckSkillCastCondition() or server-side validation?

Recent Changes (2026-03-09)

Removed Non-C++ Code

• File: Assets/Scripts/CECHostPlayer.Skill.cs
• Lines removed: 453-459 (safeguard code that cleared stale m_pPrepSkill)
• Reason: This code didn't exist in C++ and was causing divergence from original behavior
• Status: ✅ Removed - C# now matches C++ behavior

Enhanced Logging

• File: Assets/Scripts/CECHostPlayer.Skill.cs
• Added detailed logging for m_pPrepSkill state transitions:
  • When m_pPrepSkill is set in ApplySkillShortcut()
  • When m_pPrepSkill is cleared in CastSkill() for flashmove skills
  • Which skill ID is being checked in CheckSkillCastCondition()
• File: Assets/Scripts/CECHostPlayer.Combat.cs
• Added logging in SKILL_PERFORM handler to track when m_pPrepSkill is cleared

Current Status

• ✅ Code now matches C++ behavior for m_pPrepSkill handling
• ❌ Bug still exists (error 20 when casting skill after flashmove)
• ⚠️ Debug logs not appearing in test session log (need to verify log output location)
• 🔍 Next: Compare C++ and C# logs side-by-side to find root cause

Root Cause Analysis (2026-03-09)

Key Finding: Error 20 is Server-Side, Not Client-Side

Critical Discovery: The error 20 (FIXMSG_NEEDITEM) is coming from the SERVER, not from client-side CheckSkillCastCondition().

Evidence from logs:

• Unity log (SessionLog_2026-03-09_11-16-28.txt):

  • Line 535: CAST_SKILL sent
  • Line 536: ### GameDataSend: ERROR_MESSAGE: 20 ← Server response
  • Line 537: ### GameDataSend: ERROR_MESSAGE parsed iMessage=20

• C++ log (EC.log):

  • Line 5448: Flashmove skill (skillID=58) cast
  • Line 5472: Server responds with OBJECT_CAST_POS_SKILL and SKILL_PERFORM (almost immediately)
  • Line 6208: Next skill (skillID=1) cast successfully - NO ERROR

The Problem

Timing Issue: In the Unity version, the next skill is being cast before the server has fully processed the flashmove skill.

Sequence in Unity:

1. 11:16:57.856 - CAST_POS_SKILL sent (flashmove)
2. 11:17:00.858 - CAST_SKILL sent (next skill) ← 3 seconds later
3. 11:17:00.972 - Server returns ERROR_MESSAGE: 20

Sequence in C++ (working):

1. 10:35:21.207 - Flashmove skill cast
2. 10:35:21.276 - Server responds with OBJECT_CAST_POS_SKILL and SKILL_PERFORM ← Immediate response
3. 10:35:24.438 - Next skill cast successfully ← 3+ seconds later, but AFTER server confirmed flashmove

Why This Happens

The server needs to:

1. Process the flashmove skill
2. Send OBJECT_CAST_POS_SKILL back to client
3. Send SKILL_PERFORM to clear the skill state
4. Only then is it ready for the next skill

If the next skill is sent before the server has sent SKILL_PERFORM, the server may still be in a state where it thinks the flashmove skill is active, causing it to check the wrong skill's item requirements.

Missing Server Response in Unity Log

Critical Observation: The Unity log shows:

• CAST_POS_SKILL sent at 11:16:57.856
• But NO OBJECT_CAST_POS_SKILL or SKILL_PERFORM response from server before the next skill is cast

This suggests either:

1. The server response is not being received/logged
2. The server response handler is not being called
3. There's a network timing issue

Solution

Option 1: Wait for Server Confirmation

• Don't allow casting the next skill until SKILL_PERFORM is received for the flashmove skill
• This matches C++ behavior where the client waits for server confirmation

Option 2: Check Server State

• Before casting the next skill, verify that m_pPrepSkill is null (which should be set after SKILL_PERFORM)
• If m_pPrepSkill is still set, wait for SKILL_PERFORM before allowing next skill

Option 3: Server-Side Fix

• If the error is truly server-side, the server should handle the case where a new skill is sent while a flashmove is still processing
• However, since C++ works fine, this is likely a client-side timing issue

Recommended Fix

Immediate Fix: Add a check in ApplySkillShortcut() or CastSkill() to prevent casting a new skill if:

• m_pPrepSkill is still set (waiting for server confirmation)
• OR IsFlashMoving() returns true (flashmove work is still active)

This will ensure the client waits for server confirmation before allowing the next skill cast, matching C++ behavior.

Root Cause Found (2026-03-09)

The Missing Check

Problem: The C# code was missing the CanCastSkillImmediately() check that exists in C++.

C++ Code (EC_HostPlayer.cpp, line 2688-2694):

// 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;
}

C# Code (BEFORE FIX):

• Missing this check in the main casting path
• Only checked ReadyToCast() but not CanCastSkillImmediately()
• This allowed casting a new skill while flashmove work (PRIORITY_2) was still active

Why This Causes Error 20:

1. Flashmove skill is cast → WORK_FLASHMOVE created at PRIORITY_2
2. m_pPrepSkill is cleared immediately after sending network command (correct)
3. User tries to cast next skill → CanCastSkillImmediately() should return false (blocking it)
4. BUT the check was missing, so the skill is sent to server
5. Server receives the skill while flashmove is still processing
6. Server checks the wrong skill's item requirement → returns ERROR 20

Fix Applied

File: Assets/Scripts/CECHostPlayer.Skill.cs
Location: Line ~683 (after ReadyToCast() check, before setting m_pPrepSkill)

Added:

// Check if skill can be cast immediately (blocks casting during flash move at PRIORITY_2)
// 检查技能是否可以立即施放（阻止在PRIORITY_2的闪移工作期间施放）
if (!m_pWorkMan.CanCastSkillImmediately(pSkill.GetSkillID()))
{
    bool hasWorkOnPriority2 = m_pWorkMan.HasWorkRunningOnPriority(CECHPWorkMan.Priority.PRIORITY_2);
    Debug.Log($"[SKILL_CAST_DEBUG] ApplySkillShortcut: BLOCKED - CanCastSkillImmediately returned false, skillID={idSkill}, " +
        $"IsSpellingMagic={IsSpellingMagic()}, HasWorkOnPriority2={hasWorkOnPriority2}");
    return false;
}

This check prevents casting a new skill while WORK_FLASHMOVE (or any other PRIORITY_2 work) is still active, matching C++ behavior exactly.

Status

• ✅ Root cause identified: Missing CanCastSkillImmediately() check
• ✅ Fix applied: Added the check to match C++ behavior
• ✅ Enhanced fix: Added IsFlashMoving() check as additional safeguard
• ❌ Still occurring: Error 20 still happens in test (SessionLog_2026-03-09_11-43-06.txt)
• 🔍 Investigation: The check may not be sufficient - client-side flashmove work might finish before server processes it

Updated Fix (2026-03-09)

Enhanced Check: Added IsFlashMoving() check in addition to CanCastSkillImmediately():

// Check if skill can be cast immediately (blocks casting during flash move at PRIORITY_2)
// Also check IsFlashMoving() as an additional safeguard since client-side work might finish
// before server processes the flashmove
if (IsFlashMoving() || !m_pWorkMan.CanCastSkillImmediately(pSkill.GetSkillID()))
{
    // BLOCKED
    return false;
}

Why this is needed: The client-side flashmove work (WORK_FLASHMOVE) might finish before the server processes the flashmove command. When this happens:

• CanCastSkillImmediately() might return true (work is done on client)
• But server is still processing the flashmove
• Next skill sent to server → server checks wrong skill → ERROR 20

Note: Debug logs ([SKILL_CAST_DEBUG]) are not appearing in session log files. They may be going to Unity console instead. This makes it difficult to verify if the check is being executed.

Additional Issue: "Distance Too Far" Error After Flashmove (2026-03-09)

Problem

After casting a flashmove skill, normal attacks and skill casts fail with "distance too far" error (ERROR_MESSAGE: 2), even though the target should be in range.

Root Cause

The Real Issue: CanTouchTarget() and distance calculation functions were using transform.position (the visual position) instead of the server-tracked position (GetLastSevPos()).

What Happens:

1. When flashmove happens, SetHostLastPos() and SetLastSevPos() ARE updated immediately (this was already fixed)
2. BUT CanTouchTarget() uses transform.position which is NOT updated immediately - it's moved gradually by WORK_FLASHMOVE work
3. So distance checks use the OLD visual position, while server uses the tracked position (which was updated)
4. Client thinks player is still at old position → distance check fails → ERROR 2 from server

Fix Applied (2026-03-09)

File 1: Assets/Scripts/CECHostPlayer.cs
Location: Line ~1534 (CanTouchTarget overload)

Changed:

// BEFORE (WRONG):
A3DVECTOR3 vector = new A3DVECTOR3(playerTransform.position.x, playerTransform.position.y,
    playerTransform.position.z);

// AFTER (CORRECT):
// Use server-tracked position instead of visual position for distance checks
A3DVECTOR3 vector = EC_Utility.ToA3DVECTOR3(m_MoveCtrl.GetLastSevPos());

File 2: Assets/Scripts/CECHostPlayer.Combat.cs
Location: Line ~791 (NormalAttackObject)

Changed:

// BEFORE (WRONG):
A3DVECTOR3 vHostPos = EC_Utility.ToA3DVECTOR3(transform.position);

// AFTER (CORRECT):
// Use server-tracked position instead of visual position for distance checks
A3DVECTOR3 vHostPos = EC_Utility.ToA3DVECTOR3(m_MoveCtrl.GetLastSevPos());

File 3: Assets/Scripts/CECHostPlayer.Skill.cs
Location: Line ~1102 (CastSkill logging)

Changed:

// BEFORE (WRONG):
A3DVECTOR3 vHostPos = EC_Utility.ToA3DVECTOR3(transform.position);

// AFTER (CORRECT):
// Use server-tracked position instead of visual position for accurate distance checks
A3DVECTOR3 vHostPos = EC_Utility.ToA3DVECTOR3(m_MoveCtrl.GetLastSevPos());

Why this works:

• GetLastSevPos() returns the server-tracked position, which is updated immediately when flashmove happens
• transform.position is the visual position, which is moved gradually by WORK_FLASHMOVE work
• Using the tracked position ensures distance checks match what the server sees

C++ Comparison:

• C++ (EC_HostPlayer.cpp, line 4106): CanTouchTarget(GetPos(), vTargetPos, ...)
• C# (BEFORE FIX): CanTouchTarget(transform.position, ...) ❌ Wrong - uses visual position
• C# (AFTER FIX): CanTouchTarget(GetLastSevPos(), ...) ✅ Correct - uses server-tracked position

Evidence from C++ Code:

1. Flashmove Position Update (EC_HostMsg.cpp, lines 6115-6178):

   • For flashmove skills using WORK_FLASHMOVE, SetPos() is NOT called immediately
   • Only SetHostLastPos() and SetLastSevPos() are updated (via work system)
   • The work moves the player visually over time

2. Position Comparison (EC_HostPlayer.cpp, line 4162):

   if (GetPos() != m_MoveCtrl.GetLastSevPos())
   {
       m_MoveCtrl.SendMoveCmd(GetPos(), ...);
   }
   

   This shows GetPos() and GetLastSevPos() can be different, but when they differ, the code sends a move command to sync them.

3. Why C++ Works:

   • GetPos() in C++ appears to be synchronized with server position through the work system
   • OR GetPos() might return GetLastSevPos() in certain contexts
   • OR the work system updates GetPos() during flashmove execution
   • The exact mechanism is unclear, but CanTouchTarget(GetPos(), ...) works correctly in C++

4. Why C# Doesn't Work (Before Fix):

   • transform.position in Unity is the visual position, updated gradually by WORK_FLASHMOVE
   • GetPos() in C# likely returns transform.position (visual position)
   • This causes distance checks to use the old position, failing immediately after flashmove

Conclusion: Using GetLastSevPos() directly in C# matches the server-tracked position that C++ GetPos() appears to use for distance checks, ensuring consistent behavior.

Status

• ✅ Root cause identified: Distance checks using visual position instead of tracked position
• ✅ Fix applied: All distance checks now use GetLastSevPos() instead of transform.position
• ⏳ Testing needed: Verify normal attacks and skill casts work correctly after flashmove