perf(server): hold 20 TPS at 50-player scale

This commit is contained in:
itsRevela
2026-04-25 13:42:29 -05:00
parent 18a08ec693
commit ce9ffefba6
11 changed files with 487 additions and 32 deletions

View File

@@ -85,6 +85,9 @@ vector<INetworkPlayer *> MinecraftServer::s_sentTo;
int MinecraftServer::s_slowQueuePlayerIndex = 0;
int MinecraftServer::s_slowQueueLastTime = 0;
bool MinecraftServer::s_slowQueuePacketSent = false;
#ifdef MINECRAFT_SERVER_BUILD
int MinecraftServer::s_dedicatedChunkSendsThisTick = 0;
#endif
#endif
unordered_map<wstring, int> MinecraftServer::ironTimers;
@@ -1770,6 +1773,12 @@ void MinecraftServer::run(int64_t seed, void *lpParameter)
int64_t unprocessedTime = 0;
while (running && !s_bServerHalted)
{
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
// Full wall-clock cost of one run loop iteration (catch-up ticks
// + setTime handlers + XUI delayed actions + Sleep).
int64_t outerIterStart = getCurrentTimeMillis();
int64_t outerIterTickWork = 0;
#endif
int64_t now = getCurrentTimeMillis();
// 4J Stu - When we pause the server, we don't want to count that as time passed
@@ -1807,15 +1816,39 @@ void MinecraftServer::run(int64_t seed, void *lpParameter)
while (unprocessedTime > MS_PER_TICK)
{
unprocessedTime -= MS_PER_TICK;
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
// Per-iteration pre/tick/post timing.
int64_t iter_t0 = System::currentTimeMillis();
#endif
chunkPacketManagement_PreTick();
// int64_t before = System::currentTimeMillis();
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
int64_t iter_t1 = System::currentTimeMillis();
#endif
tick();
// int64_t after = System::currentTimeMillis();
// PIXReportCounter(L"Server time",(float)(after-before));
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
int64_t iter_t2 = System::currentTimeMillis();
#endif
chunkPacketManagement_PostTick();
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
int64_t iter_t3 = System::currentTimeMillis();
int64_t iter_total = iter_t3 - iter_t0;
outerIterTickWork += iter_total;
if (iter_total > 60)
{
ServerRuntime::LogInfof("perf",
"iter total=%lldms pre=%lld tick=%lld post=%lld",
(long long)iter_total,
(long long)(iter_t1 - iter_t0),
(long long)(iter_t2 - iter_t1),
(long long)(iter_t3 - iter_t2));
}
#endif
}
lastTime = getCurrentTimeMillis();
// Do NOT reset lastTime here. Resetting discards the wall
// time spent in the catch-up so passedTime restarts from
// post-tick, capping effective TPS at 1000 / (MS_PER_TICK
// + avgTickBody). Runaway after a real freeze is bounded
// by the passedTime > MS_PER_TICK * 40 cap above.
// int64_t afterall = System::currentTimeMillis();
// PIXReportCounter(L"Server time all",(float)(afterall-beforeall));
// PIXReportCounter(L"Server ticks",(float)tickcount);
@@ -2101,6 +2134,73 @@ void MinecraftServer::run(int64_t seed, void *lpParameter)
}
Sleep(1);
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
int64_t outerIterTotal = getCurrentTimeMillis() - outerIterStart;
// Distribution histogram (gated). Buckets every outer iter, dumps
// the bucket counts + a self-computed TPS every ~10 seconds.
if (ServerRuntime::g_serverPerfTrace)
{
static const int kBucketCount = 14;
static int64_t s_bucketEdges[kBucketCount] = {
2, 5, 10, 20, 30, 40, 50, 60, 80, 100, 200, 500, 1000, INT64_MAX
};
static unsigned int s_buckets[kBucketCount] = {0};
static int64_t s_histWindowStartMs = 0;
static int s_histWindowStartTick = 0;
static int64_t s_histTotalIterMs = 0;
static unsigned int s_histTotalIters = 0;
static unsigned int s_histTickIters = 0;
int64_t nowMsForHist = getCurrentTimeMillis();
if (s_histWindowStartMs == 0)
{
s_histWindowStartMs = nowMsForHist;
s_histWindowStartTick = (int)tickCount;
}
for (int b = 0; b < kBucketCount; b++)
{
if (outerIterTotal <= s_bucketEdges[b])
{
s_buckets[b]++;
break;
}
}
s_histTotalIterMs += outerIterTotal;
s_histTotalIters++;
if (outerIterTickWork > 0) s_histTickIters++;
int ticksThisWindow = (int)tickCount - s_histWindowStartTick;
if (ticksThisWindow >= 200)
{
int64_t windowMs = nowMsForHist - s_histWindowStartMs;
double calcTps = windowMs > 0 ? (ticksThisWindow * 1000.0) / windowMs : 0.0;
double avgIterMs = s_histTotalIters > 0 ? (double)s_histTotalIterMs / s_histTotalIters : 0.0;
ServerRuntime::LogInfof("perf",
"histogram window: %d ticks in %lldms calcTps=%.2f iters=%u tickIters=%u avgIter=%.2fms | "
"<=2:%u <=5:%u <=10:%u <=20:%u <=30:%u <=40:%u <=50:%u <=60:%u <=80:%u <=100:%u <=200:%u <=500:%u <=1000:%u >1000:%u",
ticksThisWindow, (long long)windowMs, calcTps,
s_histTotalIters, s_histTickIters, avgIterMs,
s_buckets[0], s_buckets[1], s_buckets[2], s_buckets[3],
s_buckets[4], s_buckets[5], s_buckets[6], s_buckets[7],
s_buckets[8], s_buckets[9], s_buckets[10], s_buckets[11],
s_buckets[12], s_buckets[13]);
for (int b = 0; b < kBucketCount; b++) s_buckets[b] = 0;
s_histWindowStartMs = nowMsForHist;
s_histWindowStartTick = (int)tickCount;
s_histTotalIterMs = 0;
s_histTotalIters = 0;
s_histTickIters = 0;
}
}
if (outerIterTotal > 60)
{
ServerRuntime::LogInfof("perf",
"outerIter total=%lldms tickWork=%lld postTickOverhead=%lld",
(long long)outerIterTotal,
(long long)outerIterTickWork,
(long long)(outerIterTotal - outerIterTickWork));
}
#endif
}
}
//else
@@ -2155,6 +2255,17 @@ void MinecraftServer::broadcastStopSavingPacket()
void MinecraftServer::tick()
{
// Per-substep wall-clock timing. Logs one summary line when total tick
// exceeds TICK_SLOW_THRESHOLD_MS.
const int64_t TICK_SLOW_THRESHOLD_MS = 60;
const int kMaxLevelsRecorded = 8;
int64_t tickStart = System::currentTimeMillis();
int64_t lvlTickMs[kMaxLevelsRecorded] = {0};
int64_t lvlEntMs[kMaxLevelsRecorded] = {0};
int64_t lvlTrkMs[kMaxLevelsRecorded] = {0};
int lvlDimId[kMaxLevelsRecorded] = {0};
unsigned int recordedLevels = 0;
vector<wstring> toRemove;
for ( auto& it : ironTimers )
{
@@ -2206,11 +2317,21 @@ void MinecraftServer::tick()
{
players->broadcastAll(std::make_shared<SetTimePacket>(level->getGameTime(), level->getDayTime(), level->getGameRules()->getBoolean(GameRules::RULE_DAYLIGHT)), level->dimension->id);
}
// Gate the per-level tick body on dimension activity. Empty
// dimensions skip Level::tick / tickEntities / tracker tick so
// stale chunks loaded by a prior visit do not consume budget.
// Gametime and weather pause for empty dimensions until a
// player returns.
bool dimensionActive = (players->getPlayerCount(level) > 0) || level->hasEntitiesToRemove();
// #ifndef __PS3__
static int64_t stc = 0;
int64_t st0 = System::currentTimeMillis();
PIXBeginNamedEvent(0,"Level tick %d",i);
static_cast<Level *>(level)->tick();
if (dimensionActive)
{
static_cast<Level *>(level)->tick();
}
int64_t st1 = System::currentTimeMillis();
PIXEndNamedEvent();
PIXBeginNamedEvent(0,"Update lights %d",i);
@@ -2218,11 +2339,7 @@ void MinecraftServer::tick()
int64_t st2 = System::currentTimeMillis();
PIXEndNamedEvent();
PIXBeginNamedEvent(0,"Entity tick %d",i);
// 4J added to stop ticking entities in levels when players are not in those levels.
// Note: now changed so that we also tick if there are entities to be removed, as this also happens as a result of calling tickEntities. If we don't do this, then the
// entities get removed at the first point that there is a player count in the level - this has been causing a problem when going from normal dimension -> nether -> normal,
// as the player is getting flagged as to be removed (from the normal dimension) when going to the nether, but Actually gets removed only when it returns
if( ( players->getPlayerCount(level) > 0) || ( level->hasEntitiesToRemove() ) )
if (dimensionActive)
{
#ifdef __PSVITA__
// AP - the PlayerList->viewDistance initially starts out at 3 to make starting a level speedy
@@ -2239,17 +2356,34 @@ void MinecraftServer::tick()
}
PIXEndNamedEvent();
int64_t stEntDone = System::currentTimeMillis();
PIXBeginNamedEvent(0,"Entity tracker tick");
level->getTracker()->tick();
if (dimensionActive)
{
level->getTracker()->tick();
}
PIXEndNamedEvent();
int64_t st3 = System::currentTimeMillis();
// printf(">>>>>>>>>>>>>>>>>>>>>> Tick %d %d %d : %d\n", st1 - st0, st2 - st1, st3 - st2, st0 - stc );
stc = st0;
// #endif// __PS3__
// Record per-level breakdown for the slow-tick summary.
if (i < kMaxLevelsRecorded)
{
lvlTickMs[i] = st1 - st0; // Level::tick (mob spawner, chunk source, tile ticks, etc.)
lvlEntMs[i] = stEntDone - st2; // tickEntities (per-entity AI/physics)
lvlTrkMs[i] = st3 - stEntDone; // EntityTracker::tick (visibility & broadcasts)
lvlDimId[i] = level->dimension->id;
recordedLevels = i + 1;
}
}
}
int64_t afterLevels = System::currentTimeMillis();
Entity::tickExtraWandering(); // 4J added
int64_t afterExtraW = System::currentTimeMillis();
// Process player disconnect/kick queue BEFORE ticking connections.
// PendingConnection::handleLogin rejects duplicate XUIDs, so the old
@@ -2258,9 +2392,11 @@ void MinecraftServer::tick()
PIXBeginNamedEvent(0,"Players tick");
players->tick();
PIXEndNamedEvent();
int64_t afterPlayers = System::currentTimeMillis();
PIXBeginNamedEvent(0,"Connection tick");
connection->tick();
PIXEndNamedEvent();
int64_t afterConn = System::currentTimeMillis();
// 4J - removed
#if 0
@@ -2274,6 +2410,35 @@ void MinecraftServer::tick()
// } catch (Exception e) {
// logger.log(Level.WARNING, "Unexpected exception while parsing console command", e);
// }
int64_t totalMs = System::currentTimeMillis() - tickStart;
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
if (totalMs > TICK_SLOW_THRESHOLD_MS)
{
// Build a single one-line breakdown so it greps cleanly. Per-level:
// Level::tick / tickEntities / tracker tick. Then global subsystems.
char buf[512];
int n = 0;
for (unsigned int i = 0; i < recordedLevels && n >= 0 && n < (int)sizeof(buf); i++)
{
n += snprintf(buf + n, sizeof(buf) - n,
" L%d:tick=%lld ent=%lld trk=%lld",
lvlDimId[i],
(long long)lvlTickMs[i],
(long long)lvlEntMs[i],
(long long)lvlTrkMs[i]);
}
ServerRuntime::LogInfof("perf",
"slow tick total=%lldms%s | extraW=%lld players=%lld conn=%lld",
(long long)totalMs,
buf,
(long long)(afterExtraW - afterLevels),
(long long)(afterPlayers - afterExtraW),
(long long)(afterConn - afterPlayers));
}
#else
(void)totalMs;
#endif
}
void MinecraftServer::handleConsoleInput(const wstring& msg, ConsoleInputSource *source)
@@ -2417,7 +2582,9 @@ bool MinecraftServer::chunkPacketManagement_CanSendTo(INetworkPlayer *player)
if( player == nullptr ) return false;
#ifdef MINECRAFT_SERVER_BUILD
return true;
// Cap chunk-data sends per tick. Other players are served on later ticks
// via the per-tick rotation in ServerConnection::tick.
return s_dedicatedChunkSendsThisTick < DEDICATED_MAX_CHUNK_SENDS_PER_TICK;
#else
int time = GetTickCount();
DWORD currentPlayerCount = g_NetworkManager.GetPlayerCount();
@@ -2436,10 +2603,16 @@ bool MinecraftServer::chunkPacketManagement_CanSendTo(INetworkPlayer *player)
void MinecraftServer::chunkPacketManagement_DidSendTo(INetworkPlayer *player)
{
s_slowQueuePacketSent = true;
#ifdef MINECRAFT_SERVER_BUILD
s_dedicatedChunkSendsThisTick++;
#endif
}
void MinecraftServer::chunkPacketManagement_PreTick()
{
#ifdef MINECRAFT_SERVER_BUILD
s_dedicatedChunkSendsThisTick = 0;
#endif
}
void MinecraftServer::chunkPacketManagement_PostTick()