Files
BT411/engine/MUNGA/DROPZONE.cpp
T
Joe DiPrimaandClaude Fable 5 bf0555ccf1 #81: every MP respawn is a cross-machine round trip -- one degraded peer ghosts everyone
Two-node bench with the fixed host:local labels shows each player's drop-zone
request is answered by the OTHER machine's DropZone: A asks, B grants; B asks, A
grants.  FindGroup("DropZones") iterates replicants of remotely-mastered zones
too and takes the geometrically closest, so a respawn is
  my request -> an arbitrary peer's DropZone -> that peer's reply -> back to me.
With 5 players that is 5 round trips through arbitrary peers, and ONE degraded
peer can strand everybody else's respawn.  That finally explains the otherwise
unexplained field datum that one machine stopped processing the death-transition
stream 57% into a match and never recovered (0 explosions/wreck swaps/burials
while four other machines logged 4/4/4) -- a node in that state cannot answer
anyone's respawn.  It also explains why solo is 100% reliable (in-process) and
why a healthy 2-node bench passes.

Also fixes the instrumentation before it costs a night: every [dz] line printed
"entity 1" because a player's LOCAL entity id is 1 on every machine -- with five
players the log would have said a respawn stalled but not WHOSE.  All [dz] lines
now print host:local (including the usedBy= owner of each busy slot).

Doc: two candidate fixes recorded (prefer a locally-mastered DropZone / make the
reply path tolerant of a deathCount that is ahead of ours), neither to be guessed
at -- the [ghost] DISCARDED line's mismatch direction decides it in one line.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-30 01:20:13 -05:00

586 lines
17 KiB
C++

#include "munga.h"
#pragma hdrstop
#include "dropzone.h"
#include "random.h"
#include "app.h"
#include "hostmgr.h"
#include "nttmgr.h"
#include "notation.h"
#include "namelist.h"
#include "player.h"
#define DOWN_TIME 5.0f
//#############################################################################
//############################### DropZone #################################
//#############################################################################
//#############################################################################
// Shared Data Support
//
Derivation* DropZone::GetClassDerivations()
{
static Derivation classDerivations(Entity::GetClassDerivations(),"DropZone");
return &classDerivations;
}
DropZone::SharedData
DropZone::DefaultData(
DropZone::GetClassDerivations(),
DropZone::GetMessageHandlers(),
DropZone::GetAttributeIndex(),
DropZone::StateCount,
(Entity::MakeHandler)DropZone::Make
);
//#############################################################################
// Message Support
//
const Receiver::HandlerEntry
DropZone::MessageHandlerEntries[]=
{
MESSAGE_ENTRY(DropZone, AssignDropZone)
};
Receiver::MessageHandlerSet& DropZone::GetMessageHandlers()
{
static Receiver::MessageHandlerSet messageHandlers(ELEMENTS(DropZone::MessageHandlerEntries), DropZone::MessageHandlerEntries, Entity::GetMessageHandlers());
return messageHandlers;
}
//#############################################################################
// Construction and Destruction
//
//~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
//
DropZone::DropZone(
DropZone::MakeMessage *creation_message,
DropZone::SharedData &virtual_data
):
Entity(creation_message, virtual_data)
{
Check_Pointer(this);
Check_Pointer(creation_message);
SetValidFlag();
dropZoneCount = 0;
dropZones = NULL;
//
//--------------------------------------------------------------
// Name the drop zone, and enter the zone in the drop zone group
//--------------------------------------------------------------
//
Str_Copy(dropZoneName, creation_message->dropZoneName, sizeof(dropZoneName));
EntityManager *entity_manager = application->GetEntityManager();
Check(entity_manager);
EntityGroup* drop_zones = entity_manager->UseGroup("DropZones");
Check(drop_zones);
drop_zones->Add(this);
//
//-----------------------------------------------------------------------
// Now, interpret the data to create the appropriate number of drop zones
//-----------------------------------------------------------------------
//
MemoryStream
stream(
creation_message,
creation_message->messageLength,
sizeof(*creation_message)
);
dropZoneCount = creation_message->dropZoneCount;
Verify(dropZoneCount > 0);
dropZones = new Origin[dropZoneCount];
Register_Pointer(dropZones);
lastUsageTime = new Time[dropZoneCount];
Register_Pointer(lastUsageTime);
lastUsedBy = new EntityID[dropZoneCount];
Register_Pointer(lastUsedBy);
lastDeathCount = new int[dropZoneCount];
Register_Pointer(lastDeathCount);
for (int i=0; i<dropZoneCount; ++i)
{
dropZones[i] = *(Origin*)stream.GetPointer();
lastUsageTime[i] = Time::Null;
lastUsedBy[i] = EntityID::Null;
lastDeathCount[i] = -3;
stream.AdvancePointer(sizeof(Origin));
}
}
//~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
//
DropZone*
DropZone::Make(DropZone::MakeMessage *creation_message)
{
return new DropZone(creation_message);
}
//~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
//
DropZone::~DropZone()
{
if (dropZones)
{
Unregister_Pointer(dropZones);
delete[] dropZones;
Unregister_Pointer(lastUsageTime);
delete[] lastUsageTime;
Unregister_Pointer(lastUsedBy);
delete[] lastUsedBy;
Unregister_Pointer(lastDeathCount);
delete[] lastDeathCount;
}
}
// #81: print an EntityID as host:local. A player's LOCAL id is 1 on every
// machine, so printing only the local part made every one of five players read
// "entity 1" -- useless for telling WHO stalled. GetHostID() is non-const.
static inline int DZHost(const EntityID &id) { EntityID c(id); return (int)c.GetHostID(); }
static inline int DZLocal(const EntityID &id) { return (int)id; }
//#############################################################################
// Dropzone assignment
//
//~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
//
Logical
DropZone::IsAvailable(int index)
{
Check(this);
Verify(index >= 0 && index < dropZoneCount);
Check(application);
return
!lastUsageTime[index].ticks
|| Now() - lastUsageTime[index] > DOWN_TIME
&& application->GetApplicationState() == Application::RunningMission;
}
//~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
//
void
DropZone::AssignDropZoneMessageHandler(AssignDropZoneMessage* message)
{
Check(this);
Check_Pointer(message);
Check(application);
HostManager *host = application->GetHostManager();
Check(host);
Entity *entity = host->GetEntityPointer(message->requestingEntity);
Check(entity);
// ---- BT_DROPZONE_LOG (2026-07-30) -------------------------------------
// The GHOST MECH investigation: a respawn strands forever when no slot is
// available, because the no-zone path below reposts this message to itself
// every 0.1 s at MaxEventPriority and NEVER replies -- so the player's
// deathPending latch is never cleared (Gitea #57/#81). This whole
// subsystem was previously DARK: not one log line about drop zones in a
// full night of field logs, which is why it hid. Log the pool state on
// every request, and the outcome, so saturation is measurable.
// Rate-limited: reposts are logged for the first few then once a second,
// because a single stranded player generates 10 reposts/second forever.
// The POOL CENSUS and the STALL WATCHDOG below are ALWAYS ON (no env gate):
// a respawn stall is rare, catastrophic and field-only, exactly like the
// Gitea #57/#59 guards. Volume is bounded -- one census line per mission,
// one line per grant (i.e. per respawn), and stall lines are rate-limited
// per waiting player. BT_DROPZONE_LOG adds the verbose per-request dump
// for bench work.
const Logical dzLog = (getenv("BT_DROPZONE_LOG") != 0);
static Logical s_census = False;
if (!s_census)
{
s_census = True;
DEBUG_STREAM << "[dz] POOL name='" << GetDropZoneName()
<< "' slots=" << dropZoneCount << " downTime=" << DOWN_TIME
<< "s proximityBlock=2m\n" << std::flush;
}
//
// Track how long THIS (requester, death) pair has been waiting. The engine
// reposts the same message to itself every 0.1 s while no slot is free, so
// the first sighting is the start of the stall.
//
enum { DZ_WAITERS = 8 };
static EntityID s_waitWho[DZ_WAITERS];
static int s_waitDeath[DZ_WAITERS];
static Time s_waitSince[DZ_WAITERS];
static Time s_waitLastLog[DZ_WAITERS];
static int s_waitUsed = 0;
int wslot = -1;
for (int w = 0; w < s_waitUsed; ++w)
if (s_waitWho[w] == message->requestingEntity
&& s_waitDeath[w] == message->deathCount)
{ wslot = w; break; }
if (wslot < 0 && s_waitUsed < DZ_WAITERS)
{
wslot = s_waitUsed++;
s_waitWho[wslot] = message->requestingEntity;
s_waitDeath[wslot] = message->deathCount;
s_waitSince[wslot] = Now();
s_waitLastLog[wslot].ticks = 0;
}
const Scalar waited = (wslot >= 0) ? (Scalar)(Now() - s_waitSince[wslot]) : 0.0f;
if (dzLog)
{
DEBUG_STREAM << "[dz] REQUEST from "
<< DZHost(message->requestingEntity) << ":"
<< DZLocal(message->requestingEntity)
<< " deathCount=" << message->deathCount
<< " waited=" << waited << "s slots[";
for (int d = 0; d < dropZoneCount; ++d)
DEBUG_STREAM << (d ? " " : "") << d << (IsAvailable(d) ? ":free" : ":BUSY");
DEBUG_STREAM << "]\n" << std::flush;
}
//
//---------------------------------------------------------------------
// If we have allocated a dropzone within the last ten seconds for this
// player, resend the data
//---------------------------------------------------------------------
//
Origin *drop_zone = NULL;
int
lowest, highest, remaining, i;
for (i=0; i<dropZoneCount; ++i)
{
if (
!IsAvailable(i)
&& lastUsedBy[i] == message->requestingEntity
&& lastDeathCount[i] == message->deathCount
)
{
lastUsageTime[i] = Now();
drop_zone = &dropZones[i];
goto Found_One;
}
}
//
//------------------------------------------------------------------------
// Figure out how many drop zones are available. If none are, repost this
// message to ourself
//------------------------------------------------------------------------
//
lowest = dropZoneCount;
highest = -1;
remaining = 0;
for (i=0; i<dropZoneCount; ++i)
{
if (IsAvailable(i))
{
++remaining;
if (i < lowest)
{
lowest = i;
}
if (i > highest)
{
highest = i;
}
}
}
//
//-----------------------------------------------------
// Now, randomly look about until we find one available
//-----------------------------------------------------
//
highest = highest - lowest + 1;
while (remaining)
{
i = lowest + Random(highest);
Verify(i < dropZoneCount && i >= 0);
if (IsAvailable(i))
{
//
//-------------------------------------------------------------------
// Check to see if vehicle attached to a player is within 2 meters of
// this drop zone. If so, mark it unavailable for 3 seconds
//-------------------------------------------------------------------
//
EntityManager *entity_mgr = application->GetEntityManager();
Check(entity_mgr);
EntityGroup *player_group = entity_mgr->FindGroup("Players");
if (
player_group
&& application->GetApplicationState()
== Application::RunningMission
)
{
Player *player;
ChainIteratorOf<Node*> iterator(player_group->groupMembers);
while ((player = (Player*)iterator.ReadAndNext()) != NULL)
{
Check(player);
Entity *vehicle = player->GetPlayerVehicle();
if (vehicle && player != entity)
{
Check(vehicle);
Vector3D distance;
distance.Subtract(
vehicle->localOrigin.linearPosition,
dropZones[i].linearPosition
);
if (distance.LengthSquared() <= 4.0f)
{
lastUsedBy[i] = NULL;
lastUsageTime[i] = Now();
lastUsageTime[i] -= DOWN_TIME - 1.0f;
--remaining;
if (i == lowest)
{
++lowest;
--highest;
}
else if (i == lowest + highest - 1)
{
--highest;
}
break;
}
}
}
//
//----------------------------------------------------------
// If someone was in this spot, keep looking for another one
//----------------------------------------------------------
//
if (player)
{
continue;
}
}
lastUsageTime[i] = Now();
drop_zone = &dropZones[i];
lastUsedBy[i] = message->requestingEntity;
lastDeathCount[i] = message->deathCount;
remaining = 0;
}
}
//
//----------------------------------------------------------------
// If no drop_zone could be found, repost the message to ourselves
//----------------------------------------------------------------
//
if (!drop_zone)
{
// NO SLOT: repost to ourselves in 0.1 s and reply to nobody. The
// requester's respawn is stalled until this eventually succeeds -- if it
// never does, that player is a permanent GHOST (dead, un-reset, still
// simulated and driveable, wearing the wreck on every peer).
// ALWAYS-ON STALL WATCHDOG. Escalating, rate-limited (first sighting,
// then every 5 s per waiting player), and it names WHY each slot is
// busy -- seconds since last use and who used it -- which is the
// actionable half: cooldown saturation (pool too small for the death
// rate) looks different from proximity blocking (mechs parked on the
// pad). After 15 s a stalled respawn is a confirmed GHOST: the player
// is dead, un-reset, still driveable, and a wreck on every peer.
if (wslot >= 0
&& (!s_waitLastLog[wslot].ticks || (Now() - s_waitLastLog[wslot]) > 5.0f))
{
s_waitLastLog[wslot] = Now();
DEBUG_STREAM << (waited >= 15.0f ? "[dz] GHOST LIKELY -- " : "[dz] STALL -- ")
<< DZHost(message->requestingEntity) << ":"
<< DZLocal(message->requestingEntity)
<< " death#" << message->deathCount
<< " has waited " << waited << "s for a slot; all "
<< dropZoneCount << " busy [";
for (int d = 0; d < dropZoneCount; ++d)
{
Scalar age = lastUsageTime[d].ticks ? (Scalar)(Now() - lastUsageTime[d]) : -1.0f;
DEBUG_STREAM << (d ? " " : "") << d << ":usedBy="
<< DZHost(lastUsedBy[d]) << ":" << DZLocal(lastUsedBy[d])
<< ",age=" << age << "s";
}
DEBUG_STREAM << "]\n" << std::flush;
}
if (dzLog)
{
static int s_rp = 0;
if (++s_rp <= 5)
DEBUG_STREAM << "[dz] repost #" << s_rp << " ("
<< DZHost(message->requestingEntity) << ":"
<< DZLocal(message->requestingEntity) << ")\n" << std::flush;
}
Time when=Now();
when += 0.1f;
application->Post(MaxEventPriority, this, message, when);
return;
}
//
//--------------------------------------------------------------------
// Send a message back to the requesting object what sent this message
//--------------------------------------------------------------------
//
Found_One:
// ALWAYS ON -- one line per respawn. `waited` is the headline number: 0 is
// healthy, anything seconds-long means the pool is saturating, and a grant
// after a long wait is a ghost that RECOVERED (which is what testers see as
// "it fixed itself after a while").
{
static int s_grants = 0, s_stalledGrants = 0;
int slot = (int)(drop_zone - dropZones);
if (waited > 0.5f) ++s_stalledGrants;
++s_grants;
DEBUG_STREAM << "[dz] GRANTED slot " << slot << " to "
<< DZHost(message->requestingEntity) << ":"
<< DZLocal(message->requestingEntity)
<< " death#" << message->deathCount
<< " waited=" << waited << "s"
<< (waited >= 15.0f ? " (GHOST RECOVERED)" : "")
<< " [grants=" << s_grants << " stalled=" << s_stalledGrants << "]"
<< "\n" << std::flush;
// retire this waiter slot so the table does not fill up over a match
if (wslot >= 0)
{
for (int w = wslot; w + 1 < s_waitUsed; ++w)
{
s_waitWho[w] = s_waitWho[w+1];
s_waitDeath[w] = s_waitDeath[w+1];
s_waitSince[w] = s_waitSince[w+1];
s_waitLastLog[w] = s_waitLastLog[w+1];
}
--s_waitUsed;
}
}
ReplyMessage
reply(
message->replyMessageID,
sizeof(ReplyMessage),
*drop_zone,
message->deathCount
);
entity->Dispatch(&reply);
}
//~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
//
Logical
DropZone::CreateMakeMessage(
MakeMessage *creation_message,
const char* model_name,
const char* resource_name,
NotationFile *map_file
)
{
Check(creation_message);
Check(map_file);
Check_Pointer(model_name);
Check_Pointer(resource_name);
if (!Entity::CreateMakeMessage(creation_message, map_file, NULL))
{
return False;
}
creation_message->classToCreate = RegisteredClass::DropZoneClassID;
creation_message->instanceFlags = MapFlag|TrappedFlag;
//
//-----------------------------------------------
// Count up the number of drop zones in our model
//-----------------------------------------------
//
Enumeration save_modes = map_file->GetModes();
map_file->SetMode(NotationFile::CleanListMode);
NameList *zone_list =
map_file->MakeEntryList(model_name, "dropzone");
Register_Object(zone_list);
creation_message->dropZoneCount = zone_list->EntryCount();
creation_message->messageLength =
sizeof(*creation_message)
+ creation_message->dropZoneCount*sizeof(Origin);
if (!creation_message->dropZoneCount)
{
std::cout << "Error: " << model_name << " hasn't specified any drop zones!\n";
Dump_And_Die:
Unregister_Object(zone_list);
delete zone_list;
map_file->PutModes(save_modes);
return False;
}
//
//---------------------------------------------
// Allocate a buffer to hold the drop zone data
//---------------------------------------------
//
MemoryStream
stream(
creation_message,
creation_message->messageLength,
sizeof(*creation_message)
);
//
//----------------------------
// zero out the drop zone name
//----------------------------
//
for (int ii=0; ii<sizeof(creation_message->dropZoneName); ii++)
{
creation_message->dropZoneName[ii] = '\0';
}
Str_Copy(
creation_message->dropZoneName,
resource_name,
sizeof(creation_message->dropZoneName)
);
//
//-----------------
// Read in the data
//-----------------
//
NameList::Entry *drop_zone = zone_list->GetFirstEntry();
while (drop_zone)
{
Point3D translation;
EulerAngles tmp_rotation;
const char* zone_data = drop_zone->GetChar();
sscanf(
zone_data,
"%f %f %f %f %f %f",
&translation.x,
&translation.y,
&translation.z,
&tmp_rotation.pitch,
&tmp_rotation.yaw,
&tmp_rotation.roll
);
((Origin*)stream.GetPointer())->linearPosition = translation;
((Origin*)stream.GetPointer())->angularPosition = tmp_rotation;
stream.AdvancePointer(sizeof(Origin));
drop_zone = drop_zone->GetNextEntry();
}
Unregister_Object(zone_list);
delete zone_list;
map_file->PutModes(save_modes);
return True;
}
Logical
DropZone::TestInstance() const
{
return IsDerivedFrom(*GetClassDerivations());
}