(this is unfortunately not an answer but system would not let me post my bug confirmation with more than 2000 characters otherwise)
Hi everyone
We experienced some random editor crashes when testing our multiplayer game with more than 1 player in PIE where PlayerState
on a clients locally controlled pawn suddenly was NULL
even though it was successfully received in OnRep_PlayerState
before.
Turns out that in some cases PlayerState
on the APawn
can get replicated before SpectatorClass
in AGameState
gets replicated. In that case, AGameState
then calls ReceivedSpectatorClass
which then goes on to put all local player controllers into spectator mode. Controllers entering spectator mode will UnPossess pawn and that in turn sets PlayerState
back to NULL
.
I have made a tiny test project which implements a custom AGameMode, AGameState and APawn which just logs out when relevant steps are called during initialization. Then during bad late call to AMyPawn::UnPossessed and during AMyPawn::Tick it prints a message that things are going badly.
It is seems very much a race condition in that it happens very randomly. Sometimes it doesn’t happen at all between editor starts and sometimes it happens every second time. Sometimes it happens more often when testing with 4 or more PIE players instead of just 2.
Here is me running project in PIE 4 times with 2 players. First and fourth time ended up with client pawn having no PlayerState. I set log output to just print info from client (HasAuthority() == false) and only included lines regarding controlled pawn here.
[0.00] AMyGameMode::OnConstruction
[0.00] AMyGameMode::RestartPlayer
[0.28] AMyGameMode::RestartPlayer
[0.34] AMyPawn OnConstruction - PlayerState: 0x0 - State: Has No Controller
[0.37] AMyPawn OnRep_PlayerState - PlayerState: 0x4674e400 - State: Spectating
[0.37] AMyGameState OnConstruction
[0.37] AMyGameState ReceivedSpectatorClass
[0.37] AMyPawn UnPossessed - PlayerState: 0x4674e400 - State: Spectating
[0.37] AMyPawn UnPossessed due to ReceivedSpectatorClass during init after receiving PlayerState will remove PlayerState again
[0.37] AMyPawn BeginPlay - PlayerState: 0x0 - State: Has No Controller
[0.37] AMyGameState BeginPlay
[0.59] AMyPawn Restart - PlayerState: 0x0 - State: Spectating
[0.60] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[0.72] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[0.84] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[0.96] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.08] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.20] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.33] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.45] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.57] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.69] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.82] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.94] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.06] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.19] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.31] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.43] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.56] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.68] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.81] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.94] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[3.07] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[3.07] AMyPawn EndPlay - PlayerState: 0x0 - State: Playing
[3.07] AMyPawn UnPossessed - PlayerState: 0x0 - State: Playing
[3.07] AMyGameState EndPlay
[3.07] AMyGameMode::EndPlay
[0.00] AMyGameMode::OnConstruction
[0.00] AMyGameMode::RestartPlayer
[0.24] AMyGameMode::RestartPlayer
[0.27] AMyPawn OnConstruction - PlayerState: 0x0 - State: Has No Controller
[0.29] AMyGameState OnConstruction
[0.29] AMyGameState ReceivedSpectatorClass
[0.29] AMyPawn UnPossessed - PlayerState: 0x0 - State: Spectating
[0.29] AMyPawn BeginPlay - PlayerState: 0x0 - State: Has No Controller
[0.29] AMyGameState BeginPlay
[0.33] AMyPawn OnRep_PlayerState - PlayerState: 0x427c4800 - State: Has No Controller
[0.53] AMyPawn Restart - PlayerState: 0x427c4800 - State: Spectating
[1.12] AMyPawn EndPlay - PlayerState: 0x427c4800 - State: Playing
[1.12] AMyPawn UnPossessed - PlayerState: 0x427c4800 - State: Playing
[1.12] AMyGameState EndPlay
[1.13] AMyGameMode::EndPlay
[0.00] AMyGameMode::OnConstruction
[0.00] AMyGameMode::RestartPlayer
[0.23] AMyGameMode::RestartPlayer
[0.28] AMyPawn OnConstruction - PlayerState: 0x0 - State: Has No Controller
[0.30] AMyGameState OnConstruction
[0.30] AMyGameState ReceivedSpectatorClass
[0.30] AMyPawn UnPossessed - PlayerState: 0x0 - State: Spectating
[0.30] AMyPawn BeginPlay - PlayerState: 0x0 - State: Has No Controller
[0.30] AMyGameState BeginPlay
[0.33] AMyPawn OnRep_PlayerState - PlayerState: 0x59365600 - State: Has No Controller
[0.53] AMyPawn Restart - PlayerState: 0x59365600 - State: Spectating
[0.96] AMyPawn EndPlay - PlayerState: 0x59365600 - State: Playing
[0.96] AMyPawn UnPossessed - PlayerState: 0x59365600 - State: Playing
[0.96] AMyGameState EndPlay
[0.96] AMyGameMode::EndPlay
[0.00] AMyGameMode::OnConstruction
[0.00] AMyGameMode::RestartPlayer
[0.27] AMyGameMode::RestartPlayer
[0.32] AMyPawn OnConstruction - PlayerState: 0x0 - State: Has No Controller
[0.34] AMyPawn OnRep_PlayerState - PlayerState: 0x33dc9600 - State: Spectating
[0.34] AMyGameState OnConstruction
[0.34] AMyGameState ReceivedSpectatorClass
[0.34] AMyPawn UnPossessed - PlayerState: 0x33dc9600 - State: Spectating
[0.34] AMyPawn UnPossessed due to ReceivedSpectatorClass during init after receiving PlayerState will remove PlayerState again
[0.34] AMyPawn BeginPlay - PlayerState: 0x0 - State: Has No Controller
[0.34] AMyGameState BeginPlay
[0.57] AMyPawn Restart - PlayerState: 0x0 - State: Spectating
[0.58] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[0.70] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[0.82] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[0.94] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.06] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.18] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.31] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.43] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.55] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.68] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.80] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[1.92] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.04] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.17] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.29] AMyPawn Tick on bad pawn! - PlayerState: 0x0 - State: Playing
[2.29] AMyPawn EndPlay - PlayerState: 0x0 - State: Playing
[2.29] AMyPawn UnPossessed - PlayerState: 0x0 - State: Playing
[2.29] AMyGameState EndPlay
[2.30] AMyGameMode::EndPlay
As one can see on bad first and fourth attempt, AMyPawn
gets constructed and then gets OnRep_PlayerState
right away even before AMyGameState
gets constructed (all happening seemingly on same tick, same time stamp). On second and third correct run ReceivedSpectatorClass
happens what seems a tick before OnRep_PlayerState
.
We confirmed this on two machines with 4.10.2, 4.10.3 and 4.11.0 preview 5.
test project is attached.
Thanks for looking into this,