Some profiling stuff, for debugging.

Combat tracker creation in WorldThingSpawned shouldn't need to loop through whole list. This speeds up things greatly during map load.
This commit is contained in:
Mari the Deer 2021-04-04 18:03:22 +02:00
commit a0400cb97a
8 changed files with 210 additions and 67 deletions

View file

@ -1,3 +1,3 @@
[default]
SWWM_MODVER="\chSWWM \czGZ\c- \cw0.9.11b-pre r428 \cu(Sun 4 Apr 13:54:12 CEST 2021)\c-";
SWWM_SHORTVER="\cw0.9.11b-pre r428 \cu(2021-04-04 13:54:12)\c-";
SWWM_MODVER="\chSWWM \czGZ\c- \cw0.9.11b-pre r429 \cu(Sun 4 Apr 18:03:22 CEST 2021)\c-";
SWWM_SHORTVER="\cw0.9.11b-pre r429 \cu(2021-04-04 18:03:22)\c-";

View file

@ -327,9 +327,14 @@ extend Class SWWMHandler
override void WorldThingDamaged( WorldEvent e )
{
if ( profiling ) curms = MSTime();
if ( e.Damage > 0 ) DoDamageHandling(e);
if ( e.DamageSource && (e.DamageSource != e.Thing) ) DoCombatHit(e);
if ( (e.Thing.Health > 0) || e.Thing.bKilled || e.Thing.bCorpse ) return;
if ( (e.Thing.Health > 0) || e.Thing.bKilled || e.Thing.bCorpse )
{
if ( profiling ) worldthingdamaged_ms += MSTime()-curms;
return;
}
DoGibThing(e);
// romero hax
if ( (e.Thing is 'BossBrain') && (e.DamageType == 'Telefrag') )
@ -337,7 +342,12 @@ extend Class SWWMHandler
// voodoo doll telefragging barrel hax (eviternity death exits)
if ( (e.Thing is 'ExplosiveBarrel') && (e.DamageType == 'Telefrag') && e.DamageSource.player && (e.DamageSource.player.mo != e.DamageSource) )
e.DamageSource.DamageMobj(null,null,Actor.TELEFRAG_DAMAGE,'EndLevel');
if ( !e.Thing.player && !e.Thing.bIsMonster && !e.Thing.bCountKill && !(e.Thing is 'ScriptedMarine') ) return;
if ( !e.Thing.player && !e.Thing.bIsMonster && !e.Thing.bCountKill && !(e.Thing is 'ScriptedMarine') )
{
if ( profiling ) worldthingdamaged_ms += MSTime()-curms;
return;
}
DoKillScoring(e);
if ( profiling ) worldthingdamaged_ms += MSTime()-curms;
}
}

View file

@ -152,7 +152,7 @@ extend Class SWWMHandler
while ( a = Actor(ti.Next()) )
{
if ( (!a.bSHOOTABLE && !a.bISMONSTER) || (a is 'LampMoth') || (a is 'CompanionLamp') ) continue;
let trk = SWWMCombatTracker.Spawn(a);
let trk = SWWMCombatTracker.Spawn(a,true);
if ( !a.player ) trk.maxhealth = max(a.health,a.GetSpawnHealth());
}
n = (trackers_cnt-n);
@ -189,58 +189,79 @@ extend Class SWWMHandler
}
// dump the values of all mod RNGs (might help someday to track down what desyncs)
Console.Printf("\cxSWWM GZ RNG dump for player %d (\c-%s\cx):\c-",consoleplayer,players[consoleplayer].GetUserName());
Console.Printf("bdscreen: %d",Random2[bdscreen]());
Console.Printf("Blood: %d",Random2[Blood]());
Console.Printf("Boolet: %d",Random2[Boolet]());
Console.Printf("BrainExplode: %d",Random2[BrainExplode]());
Console.Printf("Bundle: %d",Random2[Bundle]());
Console.Printf("Candy: %d",Random2[Candy]());
Console.Printf("Chancebox: %d",Random2[Chancebox]());
Console.Printf("ClientSparkles: %d",Random2[ClientSparkles]());
Console.Printf("Corrode: %d",Random2[Corrode]());
Console.Printf("DemoLines: %d",Random2[DemoLines]());
Console.Printf("DoBlast: %d",Random2[DoBlast]());
Console.Printf("Eviscerator: %d",Random2[Eviscerator]());
Console.Printf("Explodium: %d",Random2[Explodium]());
Console.Printf("Explos: %d",Random2[Explos]());
Console.Printf("ExtraMissiles: %d",Random2[ExtraMissiles]());
Console.Printf("FInTheChat: %d",Random2[FInTheChat]());
Console.Printf("FlameT: %d",Random2[FlameT]());
Console.Printf("Flicker: %d",Random2[Flicker]());
Console.Printf("FunTags: %d",Random2[FunTags]());
Console.Printf("Gesture: %d",Random2[Gesture]());
Console.Printf("Gibs: %d",Random2[Gibs]());
Console.Printf("GoldDrop: %d",Random2[GoldDrop]());
Console.Printf("Goldy: %d",Random2[Goldy]());
Console.Printf("GunFlash: %d",Random2[GunFlash]());
Console.Printf("hdscreen: %d",Random2[hdscreen]());
Console.Printf("Hellblazer: %d",Random2[Hellblazer]());
Console.Printf("HudStuff: %d",Random2[HudStuff]());
Console.Printf("Impact: %d",Random2[Impact]());
Console.Printf("InterArt: %d",Random2[InterArt]());
Console.Printf("Invinciball: %d",Random2[Invinciball]());
Console.Printf("Junk: %d",Random2[Junk]());
Console.Printf("Moth: %d",Random2[Moth]());
Console.Printf("Nugget: %d",Random2[Nugget]());
Console.Printf("Parry: %d",Random2[Parry]());
Console.Printf("Ponch: %d",Random2[Ponch]());
Console.Printf("Puff: %d",Random2[Puff]());
Console.Printf("Pusher: %d",Random2[Pusher]());
Console.Printf("Rage: %d",Random2[Rage]());
Console.Printf("Replacements: %d",Random2[Replacements]());
Console.Printf("ScoreBits: %d",Random2[ScoreBits]());
Console.Printf("ShellDrop: %d",Random2[ShellDrop]());
Console.Printf("Shivers: %d",Random2[Shivers]());
Console.Printf("Silverbullet: %d",Random2[Silverbullet]());
Console.Printf("SpareShells: %d",Random2[SpareShells]());
Console.Printf("Sparkster: %d",Random2[Sparkster]());
Console.Printf("Spread: %d",Random2[Spread]());
Console.Printf("Spreadgun: %d",Random2[Spreadgun]());
Console.Printf("TUID: %d",Random2[TUID]());
Console.Printf("UIStuff %d",Random2[UIStuff]());
Console.Printf("Wallbuster: %d",Random2[Wallbuster]());
Console.Printf("WallbusterMenu: %d",Random2[WallbusterMenu]());
Console.Printf("Ynykron: %d",Random2[Ynykron]());
Console.Printf("bdscreen: %08x",Random2[bdscreen]());
Console.Printf("Blood: %08x",Random2[Blood]());
Console.Printf("Boolet: %08x",Random2[Boolet]());
Console.Printf("BrainExplode: %08x",Random2[BrainExplode]());
Console.Printf("Bundle: %08x",Random2[Bundle]());
Console.Printf("Candy: %08x",Random2[Candy]());
Console.Printf("Chancebox: %08x",Random2[Chancebox]());
Console.Printf("ClientSparkles: %08x",Random2[ClientSparkles]());
Console.Printf("Corrode: %08x",Random2[Corrode]());
Console.Printf("DemoLines: %08x",Random2[DemoLines]());
Console.Printf("DoBlast: %08x",Random2[DoBlast]());
Console.Printf("Eviscerator: %08x",Random2[Eviscerator]());
Console.Printf("Explodium: %08x",Random2[Explodium]());
Console.Printf("ExploS: %08x",Random2[ExploS]());
Console.Printf("ExtraMissiles: %08x",Random2[ExtraMissiles]());
Console.Printf("FInTheChat: %08x",Random2[FInTheChat]());
Console.Printf("FlameT: %08x",Random2[FlameT]());
Console.Printf("Flicker: %08x",Random2[Flicker]());
Console.Printf("FunTags: %08x",Random2[FunTags]());
Console.Printf("Gesture: %08x",Random2[Gesture]());
Console.Printf("Gibs: %08x",Random2[Gibs]());
Console.Printf("GoldDrop: %08x",Random2[GoldDrop]());
Console.Printf("Goldy: %08x",Random2[Goldy]());
Console.Printf("GunFlash: %08x",Random2[GunFlash]());
Console.Printf("hdscreen: %08x",Random2[hdscreen]());
Console.Printf("Hellblazer: %08x",Random2[Hellblazer]());
Console.Printf("HudStuff: %08x",Random2[HudStuff]());
Console.Printf("Impact: %08x",Random2[Impact]());
Console.Printf("InterArt: %08x",Random2[InterArt]());
Console.Printf("Invinciball: %08x",Random2[Invinciball]());
Console.Printf("Junk: %08x",Random2[Junk]());
Console.Printf("Moth: %08x",Random2[Moth]());
Console.Printf("Nugget: %08x",Random2[Nugget]());
Console.Printf("Parry: %08x",Random2[Parry]());
Console.Printf("Ponch: %08x",Random2[Ponch]());
Console.Printf("Puff: %08x",Random2[Puff]());
Console.Printf("Pusher: %08x",Random2[Pusher]());
Console.Printf("Rage: %08x",Random2[Rage]());
Console.Printf("Replacements: %08x",Random2[Replacements]());
Console.Printf("ScoreBits: %08x",Random2[ScoreBits]());
Console.Printf("ShellDrop: %08x",Random2[ShellDrop]());
Console.Printf("Shivers: %08x",Random2[Shivers]());
Console.Printf("Silverbullet: %08x",Random2[Silverbullet]());
Console.Printf("SpareShells: %08x",Random2[SpareShells]());
Console.Printf("Sparkster: %08x",Random2[Sparkster]());
Console.Printf("Spread: %08x",Random2[Spread]());
Console.Printf("Spreadgun: %08x",Random2[Spreadgun]());
Console.Printf("TUID: %08x",Random2[TUID]());
Console.Printf("UIStuff: %08x",Random2[UIStuff]());
Console.Printf("Wallbuster: %08x",Random2[Wallbuster]());
Console.Printf("WallbusterMenu: %08x",Random2[WallbusterMenu]());
Console.Printf("Ynykron: %08x",Random2[Ynykron]());
return;
}
else if ( e.Name ~== "swwmprofilehandler" )
{
if ( multiplayer && (e.player != Net_Arbitrator) )
{
if ( e.player == consoleplayer )
Console.Printf("Only the net arbitrator can call this event.");
return;
}
bprofiletics = profiletics = (e.Args[0]<=0)?10:e.Args[0];
profiling = true;
worldtick_ms = 0;
worldthingspawned_ms = 0;
worldthingdestroyed_ms = 0;
worldthingdied_ms = 0;
worldthingdamaged_ms = 0;
worldthingrevived_ms = 0;
checkreplacement_ms = 0;
checkreplacee_ms = 0;
Console.Printf("Gathering data for %d tic(s)...",bprofiletics);
return;
}
if ( e.IsManual ) return;

View file

@ -269,12 +269,18 @@ extend Class SWWMHandler
override void CheckReplacee( ReplacedEvent e )
{
if ( profiling ) curms = MSTime();
if ( e.Replacement is 'DSparilHax' )
e.Replacee = 'Sorcerer2';
// drla stuff, needed so boss deaths work
if ( !hasdrlamonsters ) return;
if ( !hasdrlamonsters )
{
if ( profiling ) checkreplacee_ms += MSTime()-curms;
return;
}
let rep = GetDRLAReplacee(e.Replacement);
if ( rep ) e.Replacee = rep;
if ( profiling ) checkreplacee_ms += MSTime()-curms;
}
private Class<Actor> GetDRLAReplacement( Class<Actor> a )
@ -542,8 +548,13 @@ extend Class SWWMHandler
override void CheckReplacement( ReplaceEvent e )
{
if ( profiling ) curms = MSTime();
// respect final replacements
if ( e.IsFinal ) return;
if ( e.IsFinal )
{
if ( profiling ) checkreplacement_ms += MSTime()-curms;
return;
}
// shell types (sorted by rarity
static const Class<Actor> redpool[] = {"RedShell","RedShell2","RedShell4"};
static const Class<Actor> greenpool[] = {"GreenShell","GreenShell2","GreenShell4"};
@ -559,6 +570,7 @@ extend Class SWWMHandler
{
e.Replacement = rep;
e.IsFinal = true;
if ( profiling ) checkreplacement_ms += MSTime()-curms;
return;
}
}
@ -576,7 +588,11 @@ extend Class SWWMHandler
// keep checking until we hit a loop, just in case
if ( s.NextState && (s.DistanceTo(s.NextState) <= 0) ) break;
}
if ( dehackery ) return;
if ( dehackery )
{
if ( profiling ) checkreplacement_ms += MSTime()-curms;
return;
}
e.Replacement = 'SWWMHangingKeen';
}
else if ( (e.Replacee is 'BossBrain') && (!e.Replacement || (e.Replacement == 'BossBrain')) )
@ -589,13 +605,20 @@ extend Class SWWMHandler
// keep checking until we hit a loop, just in case
if ( s.NextState && (s.DistanceTo(s.NextState) <= 0) ) break;
}
if ( dehackery ) return;
if ( dehackery )
{
if ( profiling ) checkreplacement_ms += MSTime()-curms;
return;
}
e.Replacement = 'SWWMBossBrain';
}
else if ( e.Replacee is 'RedCard' )
{
if ( level.GetChecksum() ~== "3805A661D5C4523AFF7BF86991071043" )
{
if ( profiling ) checkreplacement_ms += MSTime()-curms;
return; // don't replace red key in Equinox MAP13
}
e.Replacement = 'SWWMRedCard';
}
else if ( e.Replacee is 'BlueCard' ) e.Replacement = 'SWWMBlueCard';
@ -795,9 +818,14 @@ extend Class SWWMHandler
else if ( (e.Replacee is 'BlueArmor') || (e.Replacee is 'EnchantedShield') || (e.Replacee is 'MeshArmor') || (e.Replacee is 'FalconShield') ) e.Replacement = 'WarArmorItem';
else if ( (e.Replacee is 'ArtiDarkServant') || (e.Replacee == 'ArtiTeleportOther') ) e.Replacement = 'ChanceboxSpawner';
else if ( e.Replacee is 'ArtiTeleport' ) e.Replacement = (gameinfo.GameType&GAME_Hexen)?'ChanceboxSpawner':'SWWMNothing';
else return;
else
{
if ( profiling ) checkreplacement_ms += MSTime()-curms;
return;
}
// this last part is kind of ugly, but it works
// guarantees that OUR replacements are all final
e.IsFinal = true;
if ( profiling ) checkreplacement_ms += MSTime()-curms;
}
}

View file

@ -10,6 +10,7 @@ extend Class SWWMHandler
override void WorldThingRevived( WorldEvent e )
{
if ( profiling ) curms = MSTime();
// reattach combat tracker
if ( !swwm_notrack && (e.Thing.bSHOOTABLE || e.Thing.bISMONSTER) && !(e.Thing is 'LampMoth') && !(e.Thing is 'CompanionLamp') )
SWWMCombatTracker.Spawn(e.Thing);
@ -21,7 +22,11 @@ extend Class SWWMHandler
let hp = Actor.Spawn("HeadpatTracker",e.Thing.pos);
hp.target = e.Thing;
}
if ( !(e.Thing is 'PlayerPawn') ) return;
if ( !(e.Thing is 'PlayerPawn') )
{
if ( profiling ) worldthingrevived_ms += MSTime()-curms;
return;
}
// reset some vars
if ( e.Thing.playernumber() != -1 )
{
@ -33,6 +38,7 @@ extend Class SWWMHandler
// reset uptime since player had just died
SWWMStats s = SWWMStats.Find(e.Thing.player);
if ( s ) s.lastspawn = level.totaltime;
if ( profiling ) worldthingrevived_ms += MSTime()-curms;
}
private bool HexenMap40()
@ -67,6 +73,7 @@ extend Class SWWMHandler
override void WorldThingDied( WorldEvent e )
{
if ( profiling ) curms = MSTime();
if ( e.Thing.default.bISMONSTER && ((e.Thing.default.bBOSS) || (e.Thing.GetSpawnHealth() >= 1000)) && (alreadygold.Find(e.Thing) == alreadygold.Size()) )
{
// make sure we can't farm drops from revivable enemies
@ -118,7 +125,11 @@ extend Class SWWMHandler
// force insert gib animations on some vanilla Doom monsters
int gibhealth = e.Thing.GetGibHealth();
bool gotgibbed = (!e.Thing.bDONTGIB && ((e.Inflictor && e.Inflictor.bEXTREMEDEATH) || (e.DamageSource && e.DamageSource.bEXTREMEDEATH) || (e.DamageType == 'Extreme') || (e.Thing.Health < gibhealth)) && (!e.Inflictor || !e.Inflictor.bNOEXTREMEDEATH) && (!e.DamageSource || !e.DamageSource.bNOEXTREMEDEATH));
if ( !gotgibbed ) return;
if ( !gotgibbed )
{
if ( profiling ) worldthingdied_ms += MSTime()-curms;
return;
}
if ( (e.Thing.GetClass() == "Demon") || (e.Thing.GetClass() == "Spectre") )
ExtraGibDeaths.GibThis(e.Thing,"DemonXDeath");
else if ( e.Thing.GetClass() == "HellKnight" )
@ -131,6 +142,7 @@ extend Class SWWMHandler
ExtraGibDeaths.GibThis(e.Thing,"BonerXDeath");
else if ( e.Thing.GetClass() == "Archvile" )
ExtraGibDeaths.GibThis(e.Thing,"VileXDeath");
if ( profiling ) worldthingdied_ms += MSTime()-curms;
}
private void DoKeyTagFix( Actor a )
@ -197,18 +209,31 @@ extend Class SWWMHandler
override void WorldThingDestroyed( WorldEvent e )
{
if ( profiling ) curms = MSTime();
if ( !e.Thing.default.bSHOOTABLE && !e.Thing.default.bMISSILE && !(e.Thing is 'Inventory') )
{
if ( profiling ) worldthingdestroyed_ms += MSTime()-curms;
return;
}
// remove from suckables
int pos = suckableactors.Find(e.Thing);
if ( pos >= suckableactors.Size() ) return;
if ( pos >= suckableactors.Size() )
{
if ( profiling ) worldthingdestroyed_ms += MSTime()-curms;
return;
}
suckableactors.Delete(pos);
if ( profiling ) worldthingdestroyed_ms += MSTime()-curms;
}
override void WorldThingSpawned( WorldEvent e )
{
if ( profiling ) curms = MSTime();
if ( SuppressMultiItem(e) )
{
if ( profiling ) worldthingspawned_ms += MSTime()-curms;
return;
}
IWantDieSpawn(e);
if ( (e.Thing is 'TeleportDest') || (e.Thing is 'BossTarget') )
{
@ -373,5 +398,6 @@ extend Class SWWMHandler
trk.maxhealth = trk.lasthealth = e.Thing.Health;
trk.intp.Reset(trk.lasthealth);
}
if ( profiling ) worldthingspawned_ms += MSTime()-curms;
}
}

View file

@ -57,6 +57,7 @@ Class SWWMStatusBar : BaseStatusBar
int midtic, midtype;
bool koraxhack;
int ignoremsg;
double minimapzoom, oldminimapzoom;
// minimap constants
@ -172,6 +173,18 @@ Class SWWMStatusBar : BaseStatusBar
override bool ProcessNotify( EPrintLevel printlevel, String outline )
{
if ( ignoremsg )
{
ignoremsg--;
return true;
}
if ( outline.Left(21) == "SWWMHandler profiling" )
return true;
if ( outline.left(18) == "\cxSWWM GZ RNG dump" )
{
ignoremsg = 51;
return true;
}
if ( koraxhack )
{
// treat as chat message

View file

@ -24,8 +24,20 @@ Class SWWMHandler : EventHandler
// for checkreplacement
bool hasdrlamonsters;
// profiling data
bool profiling;
int bprofiletics, profiletics; // how many tics to aggregate data for
uint worldtick_ms;
uint worldthingspawned_ms, worldthingdestroyed_ms,
worldthingdied_ms, worldthingdamaged_ms,
worldthingrevived_ms;
uint checkreplacement_ms, checkreplacee_ms;
uint curms;
override void OnRegister()
{
profiling = true;
bprofiletics = profiletics = 35;
// oneliner RNG must be relative to consoleplayer
SetRandomSeed[DemoLines](Random[DemoLines]()+consoleplayer+MSTime());
// "uninitialize" some vars
@ -43,6 +55,7 @@ Class SWWMHandler : EventHandler
override void WorldTick()
{
if ( profiling ) curms = MSTime();
LangRefresh();
QueueMaintenance();
if ( !mnotify && (level.maptime >= 5) )
@ -79,6 +92,36 @@ Class SWWMHandler : EventHandler
OneHundredPercentCheck();
SimpleTracking();
VanillaBossTick();
if ( profiling )
{
worldtick_ms += MSTime()-curms;
Console.Printf("%d...",profiletics);
profiletics--;
if ( profiletics <= 0 )
{
profiling = false;
Console.Printf("Done!");
Console.Printf("SWWMHandler profiling info for "..bprofiletics.." tic(s):\n"
" event | total | avg\n"
"---------------------|--------|--------\n"
" WorldTick | %-6d | %g\n"
" WorldThingSpawned | %-6d | %g\n"
" WorldThingDestroyed | %-6d | %g\n"
" WorldThingDied | %-6d | %g\n"
" WorldThingDamaged | %-6d | %g\n"
" WorldThingRevived | %-6d | %g\n"
" CheckReplacement | %-6d | %g\n"
" CheckReplacee | %-6d | %g",
worldtick_ms,double(worldtick_ms)/bprofiletics,
worldthingspawned_ms,double(worldthingspawned_ms)/bprofiletics,
worldthingdestroyed_ms,double(worldthingdestroyed_ms)/bprofiletics,
worldthingdied_ms,double(worldthingdied_ms)/bprofiletics,
worldthingdamaged_ms,double(worldthingdamaged_ms)/bprofiletics,
worldthingrevived_ms,double(worldthingrevived_ms)/bprofiletics,
checkreplacement_ms,double(checkreplacement_ms)/bprofiletics,
checkreplacee_ms,double(checkreplacee_ms)/bprofiletics);
}
}
}
override void PostUiTick()

View file

@ -292,12 +292,14 @@ Class SWWMCombatTracker : Thinker
else mytag = "";
}
static SWWMCombatTracker Spawn( Actor target )
static SWWMCombatTracker Spawn( Actor target, bool update = false )
{
let hnd = SWWMHandler(EventHandler.Find("SWWMHandler"));
if ( !hnd ) return null;
// NOTE: These are only ever called once a thing spawns, so we don't need to "check" if entries already exist
// this check will only be performed in "update mode", i.e. when called from the swwmupdatetrackers netevent
SWWMCombatTracker t;
for ( t=hnd.trackers; t; t=t.next )
if ( update ) for ( t=hnd.trackers; t; t=t.next )
{
if ( t.mytarget != target ) continue;
return t;