Defer BodyExpression activation to first agent speech, demote spammy logs to Verbose

- BodyExpressionComponent: don't activate on OnConversationConnected, wait for
  OnSpeakingStarted (prevents body anims while NPC still walking)
- Demote recurring logs to Verbose: UpdateThreat per-tick, FindAndFollowSpline
  debug, FindCover distance check, perception target scoring

Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
This commit is contained in:
j.foucher 2026-04-02 16:38:41 +02:00
parent c32aba9902
commit b473fcda22
5 changed files with 21 additions and 16 deletions

View File

@ -74,7 +74,7 @@ void UPS_AI_Behavior_BTService_UpdateThreat::TickNode(
BB->SetValueAsFloat(PS_AI_Behavior_BB::ThreatLevel, FinalThreat); BB->SetValueAsFloat(PS_AI_Behavior_BB::ThreatLevel, FinalThreat);
UE_LOG(LogPS_AI_Behavior, Log, TEXT("[%s] UpdateThreat: raw=%.2f, stored=%.2f, final=%.2f"), UE_LOG(LogPS_AI_Behavior, Verbose, TEXT("[%s] UpdateThreat: raw=%.2f, stored=%.2f, final=%.2f"),
*AIC->GetName(), RawThreat, StoredThreat, FinalThreat); *AIC->GetName(), RawThreat, StoredThreat, FinalThreat);
// ─── Update threat actor and location with LOS tracking ───────── // ─── Update threat actor and location with LOS tracking ─────────

View File

@ -32,7 +32,7 @@ EBTNodeResult::Type UPS_AI_Behavior_BTTask_FindAndFollowSpline::ExecuteTask(
} }
// Debug: log state on entry // Debug: log state on entry
UE_LOG(LogPS_AI_Behavior, Log, TEXT("[%s] FindAndFollowSpline: bIsFollowing=%d CurrentSpline=%s"), UE_LOG(LogPS_AI_Behavior, Verbose, TEXT("[%s] FindAndFollowSpline: bIsFollowing=%d CurrentSpline=%s"),
*AIC->GetName(), *AIC->GetName(),
(int32)Follower->bIsFollowing, (int32)Follower->bIsFollowing,
Follower->CurrentSpline ? *Follower->CurrentSpline->GetName() : TEXT("null")); Follower->CurrentSpline ? *Follower->CurrentSpline->GetName() : TEXT("null"));
@ -59,7 +59,7 @@ EBTNodeResult::Type UPS_AI_Behavior_BTTask_FindAndFollowSpline::ExecuteTask(
const FVector SplineDir = Follower->CurrentSpline->GetWorldDirectionAtDistance(ClosestDist); const FVector SplineDir = Follower->CurrentSpline->GetWorldDirectionAtDistance(ClosestDist);
const bool bForward = FVector::DotProduct(PawnFwd, SplineDir) >= 0.0f; const bool bForward = FVector::DotProduct(PawnFwd, SplineDir) >= 0.0f;
UE_LOG(LogPS_AI_Behavior, Log, UE_LOG(LogPS_AI_Behavior, Verbose,
TEXT("[%s] FindAndFollowSpline: resuming spline '%s' at closest point (gap=%.0fcm, dist=%.0f, bWalkToSpline=%d, AcceptanceRadius=%.0f)"), TEXT("[%s] FindAndFollowSpline: resuming spline '%s' at closest point (gap=%.0fcm, dist=%.0f, bWalkToSpline=%d, AcceptanceRadius=%.0f)"),
*AIC->GetName(), *Follower->CurrentSpline->GetName(), GapToSpline, ClosestDist, *AIC->GetName(), *Follower->CurrentSpline->GetName(), GapToSpline, ClosestDist,
(int32)bWalkToSpline, AcceptanceRadius); (int32)bWalkToSpline, AcceptanceRadius);
@ -73,7 +73,7 @@ EBTNodeResult::Type UPS_AI_Behavior_BTTask_FindAndFollowSpline::ExecuteTask(
/*bUsePathfinding=*/true, /*bProjectDestinationToNavigation=*/true, /*bUsePathfinding=*/true, /*bProjectDestinationToNavigation=*/true,
/*bCanStrafe=*/false); /*bCanStrafe=*/false);
UE_LOG(LogPS_AI_Behavior, Log, UE_LOG(LogPS_AI_Behavior, Verbose,
TEXT("[%s] FindAndFollowSpline: MoveToLocation result=%d (0=Failed, 1=AlreadyAtGoal, 2=RequestSuccessful)"), TEXT("[%s] FindAndFollowSpline: MoveToLocation result=%d (0=Failed, 1=AlreadyAtGoal, 2=RequestSuccessful)"),
*AIC->GetName(), (int32)Result); *AIC->GetName(), (int32)Result);
@ -98,7 +98,7 @@ EBTNodeResult::Type UPS_AI_Behavior_BTTask_FindAndFollowSpline::ExecuteTask(
{ {
// Close enough — clear any residual movement request and start following // Close enough — clear any residual movement request and start following
AIC->StopMovement(); AIC->StopMovement();
UE_LOG(LogPS_AI_Behavior, Log, UE_LOG(LogPS_AI_Behavior, Verbose,
TEXT("[%s] FindAndFollowSpline: close enough, StartFollowingAtDistance(dist=%.0f, fwd=%d)"), TEXT("[%s] FindAndFollowSpline: close enough, StartFollowingAtDistance(dist=%.0f, fwd=%d)"),
*AIC->GetName(), ClosestDist, (int32)bForward); *AIC->GetName(), ClosestDist, (int32)bForward);
Follower->StartFollowingAtDistance(Follower->CurrentSpline, ClosestDist, bForward); Follower->StartFollowingAtDistance(Follower->CurrentSpline, ClosestDist, bForward);

View File

@ -215,7 +215,7 @@ void UPS_AI_Behavior_BTTask_FindCover::TickTask(
const FVector CoverLoc = BB->GetValueAsVector(PS_AI_Behavior_BB::CoverLocation); const FVector CoverLoc = BB->GetValueAsVector(PS_AI_Behavior_BB::CoverLocation);
const float DistToCover = FVector::Dist2D(Pawn->GetActorLocation(), CoverLoc); const float DistToCover = FVector::Dist2D(Pawn->GetActorLocation(), CoverLoc);
UE_LOG(LogPS_AI_Behavior, Log, UE_LOG(LogPS_AI_Behavior, Verbose,
TEXT("[%s] FindCover: MoveStatus=Idle, dist2D=%.0fcm, acceptance=%.0fcm, coverLoc=%s, pawnLoc=%s"), TEXT("[%s] FindCover: MoveStatus=Idle, dist2D=%.0fcm, acceptance=%.0fcm, coverLoc=%s, pawnLoc=%s"),
*AIC->GetName(), DistToCover, AcceptanceRadius, *AIC->GetName(), DistToCover, AcceptanceRadius,
*CoverLoc.ToString(), *Pawn->GetActorLocation().ToString()); *CoverLoc.ToString(), *Pawn->GetActorLocation().ToString());

View File

@ -325,7 +325,7 @@ AActor* UPS_AI_Behavior_PerceptionComponent::GetHighestThreatActor(
if (MappedType == TopPriority) if (MappedType == TopPriority)
{ {
PerceivedActors.Add(CandidatePawn); PerceivedActors.Add(CandidatePawn);
UE_LOG(LogPS_AI_Behavior, Log, UE_LOG(LogPS_AI_Behavior, Verbose,
TEXT("[%s] Omniscient awareness: added '%s' (type=%d, dist=%.0f) — top priority target"), TEXT("[%s] Omniscient awareness: added '%s' (type=%d, dist=%.0f) — top priority target"),
*OwnerPawn->GetName(), *CandidatePawn->GetName(), *OwnerPawn->GetName(), *CandidatePawn->GetName(),
static_cast<int32>(CandidateType), Dist); static_cast<int32>(CandidateType), Dist);
@ -407,7 +407,7 @@ AActor* UPS_AI_Behavior_PerceptionComponent::GetHighestThreatActor(
// Allied teams (Civilian ↔ Protector) → allow gunfire through // Allied teams (Civilian ↔ Protector) → allow gunfire through
if (AIC->GetGenericTeamId().GetId() == GetActorTeamId(OwningPawn)) if (AIC->GetGenericTeamId().GetId() == GetActorTeamId(OwningPawn))
{ {
UE_LOG(LogPS_AI_Behavior, Log, TEXT("[%s] Target '%s': SKIPPED (same team 0x%02X)"), UE_LOG(LogPS_AI_Behavior, Verbose, TEXT("[%s] Target '%s': SKIPPED (same team 0x%02X)"),
*Owner->GetName(), *OwningPawn->GetName(), GetActorTeamId(OwningPawn)); *Owner->GetName(), *OwningPawn->GetName(), GetActorTeamId(OwningPawn));
continue; continue;
} }
@ -430,7 +430,7 @@ AActor* UPS_AI_Behavior_PerceptionComponent::GetHighestThreatActor(
if (!bActorHasGunshot) if (!bActorHasGunshot)
{ {
UE_LOG(LogPS_AI_Behavior, Log, TEXT("[%s] Target '%s': SKIPPED (attitude=%d, not hostile, no gunshot, theirTeam=0x%02X, myTeam=0x%02X)"), UE_LOG(LogPS_AI_Behavior, Verbose, TEXT("[%s] Target '%s': SKIPPED (attitude=%d, not hostile, no gunshot, theirTeam=0x%02X, myTeam=0x%02X)"),
*Owner->GetName(), *OwningPawn->GetName(), static_cast<int32>(Attitude), *Owner->GetName(), *OwningPawn->GetName(), static_cast<int32>(Attitude),
GetActorTeamId(OwningPawn), AIC->GetGenericTeamId().GetId()); GetActorTeamId(OwningPawn), AIC->GetGenericTeamId().GetId());
continue; // Not hostile, no gunshot — skip continue; // Not hostile, no gunshot — skip
@ -522,7 +522,7 @@ AActor* UPS_AI_Behavior_PerceptionComponent::GetHighestThreatActor(
{ {
const FActorScore& Entry = Pair.Value; const FActorScore& Entry = Pair.Value;
UE_LOG(LogPS_AI_Behavior, Log, TEXT("[%s] Target '%s' (pawn='%s'): type=%d, hostile=%d, score=%.0f"), UE_LOG(LogPS_AI_Behavior, Verbose, TEXT("[%s] Target '%s' (pawn='%s'): type=%d, hostile=%d, score=%.0f"),
*Owner->GetName(), *Entry.Actor->GetName(), *Pair.Key->GetName(), *Owner->GetName(), *Entry.Actor->GetName(), *Pair.Key->GetName(),
static_cast<int32>(Entry.ActorType), Entry.bIsHostile ? 1 : 0, Entry.Score); static_cast<int32>(Entry.ActorType), Entry.bIsHostile ? 1 : 0, Entry.Score);

View File

@ -232,18 +232,17 @@ void UPS_AI_ConvAgent_BodyExpressionComponent::PickAndSwitchAnim()
void UPS_AI_ConvAgent_BodyExpressionComponent::OnConversationConnected( void UPS_AI_ConvAgent_BodyExpressionComponent::OnConversationConnected(
const FPS_AI_ConvAgent_ConversationInfo_ElevenLabs& Info) const FPS_AI_ConvAgent_ConversationInfo_ElevenLabs& Info)
{ {
bActive = true; // Don't activate yet — wait for the agent to actually speak (OnSpeakingStarted).
// This prevents body expressions from playing while the NPC is still walking
// and the user hasn't said anything yet.
bIsSpeaking = false; bIsSpeaking = false;
LastEventName = TEXT("Connected"); LastEventName = TEXT("Connected");
LastEventWorldTime = GetWorld() ? GetWorld()->GetTimeSeconds() : 0.0f; LastEventWorldTime = GetWorld() ? GetWorld()->GetTimeSeconds() : 0.0f;
// Start with an idle anim
PickAndSwitchAnim();
if (bDebug) if (bDebug)
{ {
UE_LOG(LogPS_AI_ConvAgent_BodyExpr, Log, UE_LOG(LogPS_AI_ConvAgent_BodyExpr, Log,
TEXT("Conversation connected — body expression activating (idle).")); TEXT("Conversation connected — waiting for agent speech to activate body expressions."));
} }
} }
@ -268,6 +267,12 @@ void UPS_AI_ConvAgent_BodyExpressionComponent::OnConversationDisconnected(
void UPS_AI_ConvAgent_BodyExpressionComponent::OnSpeakingStarted() void UPS_AI_ConvAgent_BodyExpressionComponent::OnSpeakingStarted()
{ {
// Activate on first speech if not already active (deferred from OnConversationConnected)
if (!bActive)
{
bActive = true;
}
bIsSpeaking = true; bIsSpeaking = true;
LastEventName = TEXT("SpeakStart"); LastEventName = TEXT("SpeakStart");
LastEventWorldTime = GetWorld() ? GetWorld()->GetTimeSeconds() : 0.0f; LastEventWorldTime = GetWorld() ? GetWorld()->GetTimeSeconds() : 0.0f;
@ -278,7 +283,7 @@ void UPS_AI_ConvAgent_BodyExpressionComponent::OnSpeakingStarted()
if (bDebug) if (bDebug)
{ {
UE_LOG(LogPS_AI_ConvAgent_BodyExpr, Log, UE_LOG(LogPS_AI_ConvAgent_BodyExpr, Log,
TEXT("Agent started speaking — switching to speaking body anim.")); TEXT("Agent started speaking — body expression activating + speaking anim."));
} }
} }