native: perf telemetry, 2 frames in flight, 120 Hz pacing, GPU shadow map

- --perf-log CSV + logcat telemetry (perf_log.h, EterBase/PerfCounters.h),
  incl. display refresh rate / app vsync rate, thermal, CPU clocks;
  tools/pull_perf_logs.sh + tools/perf_summary.py
- Vulkan renderer: two frames in flight, in-frame texture uploads (no
  vkQueueWaitIdle), --fps-cap / --refresh-rate / --frames-in-flight
- Android: ANativeWindow_setFrameRate, ADPF performance hint,
  appCategory=game (ColorOS no longer drops to 60 Hz when idle)
- Character shadow map rendered on the GPU into an offscreen render target
  instead of CPU rasterization + per-frame 1 MB upload; --cpu-shadow keeps
  the old path. Device (120 Hz, 32 mobs): 75 -> ~115 fps, script thread
  8.9 -> 3.4 ms. draw_capture format v10.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
shenlei
2026-09-29 17:59:23 +09:00
co-authored by Claude Opus 5.5
parent 3e3708ef06
commit c2cc093ed0
16 changed files with 1883 additions and 261 deletions
@@ -7,6 +7,8 @@
<application android:label="@string/app_name" <application android:label="@string/app_name"
android:allowBackup="false" android:allowBackup="false"
android:appCategory="game"
android:isGame="true"
android:extractNativeLibs="true" android:extractNativeLibs="true"
android:theme="@android:style/Theme.NoTitleBar.Fullscreen" android:theme="@android:style/Theme.NoTitleBar.Fullscreen"
android:hardwareAccelerated="true" android:hardwareAccelerated="true"
@@ -1,7 +1,9 @@
package org.metin2port.client; package org.metin2port.client;
import android.content.Intent; import android.content.Intent;
import android.content.IntentFilter;
import android.content.pm.ActivityInfo; import android.content.pm.ActivityInfo;
import android.os.BatteryManager;
import android.os.Build; import android.os.Build;
import android.os.Bundle; import android.os.Bundle;
import android.util.Log; import android.util.Log;
@@ -9,7 +11,9 @@ import android.view.Display;
import android.view.DisplayCutout; import android.view.DisplayCutout;
import android.view.HapticFeedbackConstants; import android.view.HapticFeedbackConstants;
import android.view.RoundedCorner; import android.view.RoundedCorner;
import android.view.Choreographer;
import android.view.View; import android.view.View;
import android.view.WindowManager;
import android.view.WindowInsets; import android.view.WindowInsets;
import android.view.WindowInsetsController; import android.view.WindowInsetsController;
@@ -24,13 +28,124 @@ import org.libsdl.app.SDLActivity;
* without --live-server (e.g. --es args "--fake-mobs 64") run the in-process fake-server smoke flow. * without --live-server (e.g. --es args "--fake-mobs 64") run the in-process fake-server smoke flow.
*/ */
public class MainActivity extends SDLActivity { public class MainActivity extends SDLActivity {
private static final String DEFAULT_ARGS = "--live-server 192.168.21.203:11000:13000 --login-screen"; // --perf-log: native_render/perf_log.h writes perf-*.csv under files/perf (tools/pull_perf_logs.sh).
private static final String DEFAULT_ARGS =
"--live-server 192.168.21.203:11000:13000 --login-screen --perf-log --show-fps";
@Override @Override
protected void onCreate(Bundle savedInstanceState) { protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState); super.onCreate(savedInstanceState);
setRequestedOrientation(ActivityInfo.SCREEN_ORIENTATION_SENSOR_LANDSCAPE); setRequestedOrientation(ActivityInfo.SCREEN_ORIENTATION_SENSOR_LANDSCAPE);
applyImmersiveMode(); applyImmersiveMode();
chosenRefreshRate = applyRefreshRate(requestedRefreshRate(launchArgs()));
}
// The display rate picked in onCreate (0: left to the system); handed to native as --refresh-rate.
private int chosenRefreshRate = 0;
private String launchArgs() {
Intent intent = getIntent();
String args = intent != null ? intent.getStringExtra("args") : null;
return args == null || args.trim().isEmpty() ? DEFAULT_ARGS : args;
}
// --refresh-rate N (0 = system default); absent = the display's highest rate.
private static float requestedRefreshRate(String args) {
final String[] tokens = args.trim().split("\\s+");
for (int i = 0; i + 1 < tokens.length; ++i) {
if (tokens[i].equals("--refresh-rate")) {
try {
return Float.parseFloat(tokens[i + 1]);
} catch (NumberFormatException e) {
return -1;
}
}
}
return -1;
}
/**
* Asks for the display mode with the current resolution and the refresh rate closest to `wanted`
* (the highest one when wanted < 0). The vendor can still override it; currentRefreshRate() reports
* what the display actually runs at.
*/
private int applyRefreshRate(float wanted) {
if (wanted == 0 || Build.VERSION.SDK_INT < Build.VERSION_CODES.M)
return 0;
final Display display = Build.VERSION.SDK_INT >= Build.VERSION_CODES.R ? getDisplay()
: getWindowManager().getDefaultDisplay();
if (display == null)
return 0;
final Display.Mode current = display.getMode();
Display.Mode best = null;
for (Display.Mode mode : display.getSupportedModes()) {
if (mode.getPhysicalWidth() != current.getPhysicalWidth() ||
mode.getPhysicalHeight() != current.getPhysicalHeight())
continue;
if (best == null) {
best = mode;
continue;
}
final float rate = mode.getRefreshRate();
final boolean better = wanted < 0 ? rate > best.getRefreshRate()
: Math.abs(rate - wanted) < Math.abs(best.getRefreshRate() - wanted);
if (better)
best = mode;
}
if (best == null)
return 0;
final WindowManager.LayoutParams params = getWindow().getAttributes();
params.preferredDisplayModeId = best.getModeId();
getWindow().setAttributes(params);
Log.i("Metin2Args", "display mode " + best.getModeId() + " " + best.getPhysicalWidth() + "x" +
best.getPhysicalHeight() + " @ " + best.getRefreshRate() + " Hz");
return Math.round(best.getRefreshRate());
}
// The app-vsync rate, measured with a Choreographer callback. It differs from the panel's refresh rate
// when the system renders the app at a divisor of it (ColorOS drops a non-game app to 60 fps after
// 2.5 s without a touch while the panel stays at 120 Hz). Started by the first currentRenderRate().
private volatile float renderRate = -1f;
private boolean renderRateStarted = false;
// Called from native code (android_perf.h), off the UI thread.
public float currentRenderRate() {
synchronized (this) {
if (!renderRateStarted) {
renderRateStarted = true;
runOnUiThread(() -> Choreographer.getInstance().postFrameCallback(new Choreographer.FrameCallback() {
long windowStart = 0;
int frames = 0;
@Override
public void doFrame(long frameTimeNanos) {
if (windowStart == 0) {
windowStart = frameTimeNanos;
} else if (++frames >= 30) {
renderRate = frames * 1e9f / (frameTimeNanos - windowStart);
windowStart = frameTimeNanos;
frames = 0;
}
Choreographer.getInstance().postFrameCallback(this);
}
}));
}
}
return renderRate;
}
// Called from native code (android_perf.h): battery temperature in C, -1 if unknown.
public float batteryTemperature() {
final Intent battery = registerReceiver(null, new IntentFilter(Intent.ACTION_BATTERY_CHANGED));
final int tenths = battery != null ? battery.getIntExtra(BatteryManager.EXTRA_TEMPERATURE, -10) : -10;
return tenths / 10f;
}
// Called from native code (android_perf.h): the rate the display runs at now.
public float currentRefreshRate() {
final Display display = Build.VERSION.SDK_INT >= Build.VERSION_CODES.R ? getDisplay()
: getWindowManager().getDefaultDisplay();
return display != null ? display.getRefreshRate() : -1f;
} }
@Override @Override
@@ -89,6 +204,8 @@ public class MainActivity extends SDLActivity {
// Test phase: FPS readout in the top-left corner. Drop this line for release builds. // Test phase: FPS readout in the top-left corner. Drop this line for release builds.
if (!args.contains("--show-fps")) if (!args.contains("--show-fps"))
args = args.trim() + " --show-fps"; args = args.trim() + " --show-fps";
if (!args.contains("--refresh-rate") && chosenRefreshRate > 0)
args = args.trim() + " --refresh-rate " + chosenRefreshRate;
return args.trim().split("\\s+"); return args.trim().split("\\s+");
} }
@@ -0,0 +1,124 @@
#pragma once
// PORT: performance telemetry (40250 has no counterpart). The script thread adds the wall time of the
// sections of CPythonApplication::Process() and of the Python callbacks here; the native host
// (native_render/perf_log.h) reads and clears the totals every sample window. The two threads never run
// at the same time (PythonBoot hands one baton between them), so plain fields are enough.
//
// Nothing is timed until MtPerf::Enabled() is set, so a build without --perf-log pays one branch per
// section.
#include <chrono>
namespace MtPerf
{
enum ESection
{
SECTION_PROCESS, // the whole CPythonApplication::Process()
SECTION_NETWORK, // CPythonNetworkStream + CAccountConnector Process
SECTION_CAMERA, // __UpdateCamera, CResourceManager::Update, OnCameraUpdate, OnMouseUpdate
SECTION_UI_UPDATE, // OnUIUpdate (WindowManager Update -> Python OnUpdate)
SECTION_UPDATE_GAME, // app.UpdateGame, inside UI_UPDATE
SECTION_RENDER_BEGIN, // CCullingManager::Update + the command-list restarts
SECTION_UI_RENDER, // OnUIRender (Python OnRender) + OnMouseRender
SECTION_RENDER_GAME, // app.RenderGame, inside UI_RENDER
SECTION_PYTHON, // outermost C++ -> Python callbacks (includes UPDATE_GAME/RENDER_GAME)
SECTION_SHADOW_RASTER, // RecordingDevice's CPU rasterization of the shadow texture, inside RENDER_GAME
SECTION_COUNT,
};
struct SCounters
{
double ms[SECTION_COUNT] = {};
unsigned calls[SECTION_COUNT] = {};
unsigned pyMissing = 0; // callbacks whose method does not exist
int actorCount = 0; // CPythonCharacterManager alive instances, last Process()
int scriptCpu = -1; // CPU the script thread last ran on (Linux/Android), else -1
};
inline bool& Enabled()
{
static bool s_bEnabled = false;
return s_bEnabled;
}
inline SCounters& Counters()
{
static SCounters s_kCounters;
return s_kCounters;
}
inline int& PythonDepth()
{
static int s_iDepth = 0;
return s_iDepth;
}
class CScope
{
public:
explicit CScope(ESection eSection) : m_eSection(eSection), m_bActive(Enabled())
{
if (m_bActive)
m_kStart = std::chrono::steady_clock::now();
}
~CScope()
{
if (!m_bActive)
return;
SCounters& rkCounters = Counters();
rkCounters.ms[m_eSection] += std::chrono::duration<double, std::milli>(std::chrono::steady_clock::now() - m_kStart).count();
++rkCounters.calls[m_eSection];
}
private:
ESection m_eSection;
bool m_bActive;
std::chrono::steady_clock::time_point m_kStart;
};
// Times only the outermost Python callback, so nested callbacks are not counted twice.
class CPythonScope
{
public:
CPythonScope() : m_bActive(Enabled() && PythonDepth()++ == 0)
{
if (m_bActive)
m_kStart = std::chrono::steady_clock::now();
}
~CPythonScope()
{
if (!Enabled())
return;
if (PythonDepth() > 0)
--PythonDepth();
if (!m_bActive)
return;
SCounters& rkCounters = Counters();
rkCounters.ms[SECTION_PYTHON] += std::chrono::duration<double, std::milli>(std::chrono::steady_clock::now() - m_kStart).count();
++rkCounters.calls[SECTION_PYTHON];
}
private:
bool m_bActive;
std::chrono::steady_clock::time_point m_kStart;
};
inline void CountPythonMissing()
{
if (Enabled())
++Counters().pyMissing;
}
// The totals since the last call, which clears them.
inline SCounters Take()
{
SCounters kTaken = Counters();
SCounters& rkCounters = Counters();
const int iActors = rkCounters.actorCount;
const int iCpu = rkCounters.scriptCpu;
rkCounters = SCounters();
rkCounters.actorCount = iActors;
rkCounters.scriptCpu = iCpu;
return kTaken;
}
}
@@ -2,6 +2,7 @@
#include "RenderCommands3D.h" #include "RenderCommands3D.h"
#include "UIRenderCommands.h" #include "UIRenderCommands.h"
#include "CpuBuffer.h" #include "CpuBuffer.h"
#include "../EterBase/PerfCounters.h"
#include <algorithm> #include <algorithm>
#include <cmath> #include <cmath>
@@ -15,6 +16,7 @@ namespace {
std::mutex g_draws_mutex; std::mutex g_draws_mutex;
std::vector<Render3DDraw> g_draws; std::vector<Render3DDraw> g_draws;
int g_native_terrain_override = -1; int g_native_terrain_override = -1;
bool g_gpu_render_targets = false;
struct VertexLayout { struct VertexLayout {
@@ -434,7 +436,33 @@ public:
auto* surface = static_cast<CpuSurface*>(m_renderTarget); auto* surface = static_cast<CpuSurface*>(m_renderTarget);
if (!surface->parent || surface->level != 0 || surface->desc.Format != D3DFMT_R5G6B5) if (!surface->parent || surface->level != 0 || surface->desc.Format != D3DFMT_R5G6B5)
return S_OK; return S_OK;
if (g_gpu_render_targets)
{
// The whole target, as the CPU path below clears it.
Render3DDraw clear;
clear.render_target = surface->parent->id;
clear.target_width = surface->desc.Width;
clear.target_height = surface->desc.Height;
clear.clear_flags = flags & (D3DCLEAR_TARGET | D3DCLEAR_ZBUFFER);
clear.clear_color = color;
clear.clear_z = depth;
if (clear.clear_flags)
Render3DAdd(std::move(clear));
return S_OK;
}
const size_t pixels = size_t(surface->desc.Width) * surface->desc.Height; const size_t pixels = size_t(surface->desc.Width) * surface->desc.Height;
if (const char* dump = std::getenv("MT_DUMP_RT"); dump && *dump && surface->parent->levels[0].bytes.size() >= pixels * 2)
{
// Debug: the previous frame's CPU shadow map, red channel, before it is cleared.
if (FILE* out = std::fopen((std::string(dump) + "_cpu.pgm").c_str(), "wb"))
{
std::fprintf(out, "P5\n%u %u\n255\n", unsigned(surface->desc.Width), unsigned(surface->desc.Height));
const auto& bytes = surface->parent->levels[0].bytes;
for (size_t i = 0; i < pixels; ++i)
std::fputc(int(((bytes[i * 2 + 1] >> 3) & 31) * 255 / 31), out);
std::fclose(out);
}
}
if (flags & D3DCLEAR_TARGET) if (flags & D3DCLEAR_TARGET)
{ {
const std::uint16_t rgb565 = std::uint16_t((((color >> 16) & 255u) >> 3) << 11 | const std::uint16_t rgb565 = std::uint16_t((((color >> 16) & 255u) >> 3) << 11 |
@@ -593,6 +621,7 @@ private:
// the normal memory-texture path upload the result for terrain/object projection. // the normal memory-texture path upload the result for terrain/object projection.
void rasterize_shadow(const Render3DDraw& draw) void rasterize_shadow(const Render3DDraw& draw)
{ {
MtPerf::CScope kPerf(MtPerf::SECTION_SHADOW_RASTER);
auto* surface = static_cast<CpuSurface*>(m_renderTarget); auto* surface = static_cast<CpuSurface*>(m_renderTarget);
if (!surface->parent || surface->level != 0 || surface->desc.Format != D3DFMT_R5G6B5 || draw.lines) if (!surface->parent || surface->level != 0 || surface->desc.Format != D3DFMT_R5G6B5 || draw.lines)
return; return;
@@ -1048,10 +1077,47 @@ private:
} }
if (m_renderTarget == m_backBuffer) if (m_renderTarget == m_backBuffer)
Render3DAdd(std::move(draw)); Render3DAdd(std::move(draw));
else if (g_gpu_render_targets)
record_shadow(std::move(draw));
else else
rasterize_shadow(draw); rasterize_shadow(draw);
} }
// GPU counterpart of rasterize_shadow: the draw goes to the renderer's offscreen pass with the
// states rasterize_shadow implements -- a flat D3DRS_TEXTUREFACTOR fill, no culling, no texture,
// light, fog or blending, depth test LESSEQUAL with depth writes -- so both paths draw the same map.
void record_shadow(Render3DDraw draw)
{
auto* surface = static_cast<CpuSurface*>(m_renderTarget);
if (!surface->parent || surface->level != 0 || surface->desc.Format != D3DFMT_R5G6B5 || draw.lines ||
draw.pretransformed || draw.indices.size() < 3)
return;
draw.render_target = surface->parent->id;
draw.target_width = surface->desc.Width;
draw.target_height = surface->desc.Height;
draw.ui_offset_x = 0;
draw.texture0.clear();
draw.texture1.clear();
draw.texture_factor = m_renderStates[D3DRS_TEXTUREFACTOR];
draw.color_op[0] = D3DTOP_SELECTARG1;
draw.color_arg1[0] = D3DTA_TFACTOR;
draw.alpha_op[0] = D3DTOP_SELECTARG1;
draw.alpha_arg1[0] = D3DTA_TFACTOR;
draw.color_op[1] = D3DTOP_DISABLE;
draw.alpha_op[1] = D3DTOP_DISABLE;
draw.lighting = FALSE;
draw.light0 = false;
for (auto& light : draw.lights) light.type = 0;
draw.fog_enable = FALSE;
draw.alpha_blend = FALSE;
draw.alpha_test = FALSE;
draw.cull_mode = D3DCULL_NONE;
draw.z_enable = TRUE;
draw.z_write = TRUE;
draw.z_func = D3DCMP_LESSEQUAL;
Render3DAdd(std::move(draw));
}
ULONG m_refs = 1; ULONG m_refs = 1;
int m_width, m_height; int m_width, m_height;
D3DVIEWPORT8 m_viewport = {}; D3DVIEWPORT8 m_viewport = {};
@@ -1089,6 +1155,11 @@ std::string MtCpuTextureNameFromHandle(const IDirect3DBaseTexture8* handle)
std::lock_guard<std::mutex> lock(g_cpu_tex_mutex); std::lock_guard<std::mutex> lock(g_cpu_tex_mutex);
for (const auto& entry : g_cpu_textures) for (const auto& entry : g_cpu_textures)
{ {
if (entry.second != handle || entry.second->levels.empty())
continue;
const D3DSURFACE_DESC& desc = entry.second->levels[0].desc;
if (g_gpu_render_targets && (desc.Usage & D3DUSAGE_RENDERTARGET) && desc.Format == D3DFMT_R5G6B5)
return Render3DRenderTargetName(entry.first, desc.Width, desc.Height);
if (entry.second == handle && !entry.second->levels.empty()) if (entry.second == handle && !entry.second->levels.empty())
return "mem:cpu_" + std::to_string(entry.first) + "@" + std::to_string(entry.second->revision); return "mem:cpu_" + std::to_string(entry.first) + "@" + std::to_string(entry.second->revision);
} }
@@ -1168,6 +1239,14 @@ bool IsNativeTerrainRenderEnabled()
return env_on; return env_on;
} }
void SetGpuRenderTargetsEnabled(bool enabled) { g_gpu_render_targets = enabled; }
bool IsGpuRenderTargetsEnabled() { return g_gpu_render_targets; }
std::string Render3DRenderTargetName(std::uint32_t id, std::uint32_t width, std::uint32_t height)
{
return "rt:" + std::to_string(id) + ":" + std::to_string(width) + "x" + std::to_string(height);
}
void Render3DBeginFrame() void Render3DBeginFrame()
{ {
std::lock_guard<std::mutex> lock(g_draws_mutex); std::lock_guard<std::mutex> lock(g_draws_mutex);
@@ -29,6 +29,13 @@ struct Render3DDraw {
std::uint32_t clear_color = 0; // 0xAARRGGBB std::uint32_t clear_color = 0; // 0xAARRGGBB
float clear_z = 1; float clear_z = 1;
// Non-zero: the draw (or clear) targets an offscreen render-target texture instead of the back
// buffer -- the 40250 character shadow map. The renderer draws these into the texture named
// Render3DRenderTargetName(render_target, ...) ahead of the back-buffer pass, in recorded order.
// viewport is then in the target's pixels. Only emitted while GPU render targets are enabled.
std::uint32_t render_target = 0;
std::uint32_t target_width = 0, target_height = 0;
// Stage 0/1 textures, named like UIRenderTextureName: the pack path of a file texture or // Stage 0/1 textures, named like UIRenderTextureName: the pack path of a file texture or
// "mem:<id>@<revision>"; empty when the stage has no texture. // "mem:<id>@<revision>"; empty when the stage has no texture.
std::string texture0; std::string texture0;
@@ -122,6 +129,13 @@ bool LookupGpuSkinSubrange(const void* vertex_buffer_base, std::uint32_t stride,
std::uint32_t lo_vertex, std::uint32_t hi_vertex, std::uint32_t lo_vertex, std::uint32_t hi_vertex,
GpuSkinSubrangeView* out_view); GpuSkinSubrangeView* out_view);
// GPU render targets: shadow-map draws are recorded with render_target set and sampled as
// "rt:<id>:<w>x<h>" instead of being rasterized on the CPU into a "mem:cpu_<id>" texture. Off by
// default (the Godot consumer has no offscreen pass); the native Vulkan renderer turns it on.
void SetGpuRenderTargetsEnabled(bool enabled);
bool IsGpuRenderTargetsEnabled();
std::string Render3DRenderTargetName(std::uint32_t id, std::uint32_t width, std::uint32_t height);
void Render3DBeginFrame(); void Render3DBeginFrame();
void Render3DAdd(Render3DDraw draw); void Render3DAdd(Render3DDraw draw);
const std::vector<Render3DDraw>& Render3DDraws(); const std::vector<Render3DDraw>& Render3DDraws();
@@ -50,6 +50,7 @@
#include "../EterBase/LogBox.h" #include "../EterBase/LogBox.h"
#include "../UserInterface/ServerClock.h" #include "../UserInterface/ServerClock.h"
#include <atomic>
#include <condition_variable> #include <condition_variable>
#include <cstdlib> #include <cstdlib>
#include <filesystem> #include <filesystem>
@@ -61,6 +62,9 @@
#include <signal.h> #include <signal.h>
#include <unistd.h> #include <unistd.h>
#endif #endif
#if defined(__linux__) || defined(__ANDROID__)
#include <unistd.h>
#endif
namespace namespace
{ {
@@ -185,6 +189,7 @@ struct ScriptFiber
}; };
ScriptFiber g_fiber; ScriptFiber g_fiber;
thread_local bool t_on_fiber = false; thread_local bool t_on_fiber = false;
std::atomic<int> g_script_thread_id{0};
// Caller holds the GIL. Returns with the GIL held again after the script has given the baton back. // Caller holds the GIL. Returns with the GIL held again after the script has given the baton back.
void hand_to_script() void hand_to_script()
@@ -218,6 +223,9 @@ void* fiber_main(void*)
g_fiber.cv.wait(lock, [] { return g_fiber.turn == ScriptFiber::Script; }); g_fiber.cv.wait(lock, [] { return g_fiber.turn == ScriptFiber::Script; });
} }
t_on_fiber = true; t_on_fiber = true;
#if defined(__linux__) || defined(__ANDROID__)
g_script_thread_id = int(gettid());
#endif
PyGILState_STATE gil = PyGILState_Ensure(); PyGILState_STATE gil = PyGILState_Ensure();
std::string error; std::string error;
const bool ok = run_main_script_body(g_fiber.command_line.c_str(), &error); const bool ok = run_main_script_body(g_fiber.command_line.c_str(), &error);
@@ -927,6 +935,11 @@ bool RunMainScript(const char* lpCmdLine, std::string* error)
return true; return true;
} }
int ScriptThreadId()
{
return g_script_thread_id;
}
bool IsAppLooping() bool IsAppLooping()
{ {
return g_fiber.alive && g_fiber.looping && !g_fiber.finished; return g_fiber.alive && g_fiber.looping && !g_fiber.finished;
@@ -40,6 +40,9 @@ bool CursorVisible();
// CPythonApplication::Process() while the host thread waits, so the two never run concurrently. // CPythonApplication::Process() while the host thread waits, so the two never run concurrently.
bool RunMainScript(const char* lpCmdLine, std::string* error); bool RunMainScript(const char* lpCmdLine, std::string* error);
bool IsAppLooping(); bool IsAppLooping();
// The script thread's kernel thread id (Linux/Android), 0 before it starts or elsewhere. The host adds
// it to its ADPF performance-hint session.
int ScriptThreadId();
bool AppFrame(); bool AppFrame();
// Native CPythonBackground map selection, in the local coordinate frame of RenderGame. // Native CPythonBackground map selection, in the local coordinate frame of RenderGame.
std::string CurrentMapName(); std::string CurrentMapName();
@@ -22,6 +22,11 @@
#include "UserInterface/PythonSystem.h" #include "UserInterface/PythonSystem.h"
#include "../ScriptLib/PythonBoot.h" #include "../ScriptLib/PythonBoot.h"
#include "ServerClock.h" #include "ServerClock.h"
#include "../EterBase/PerfCounters.h"
#if defined(__linux__) || defined(__ANDROID__)
#include <sched.h>
#endif
// 2V0-d link surface; 2V0-f adds the application lifecycle (Create/Loop/Process/Exit) that // 2V0-d link surface; 2V0-f adds the application lifecycle (Create/Loop/Process/Exit) that
// prototype.RunApp() drives. The rest of the members still wait for the game slices (2V1-2V3). // prototype.RunApp() drives. The rest of the members still wait for the game slices (2V1-2V3).
@@ -196,6 +201,7 @@ void CPythonApplication::GetMousePosition(POINT* ppt)
// PORT: the members are reached through their singletons (see the note at the top of the file). // PORT: the members are reached through their singletons (see the note at the top of the file).
void CPythonApplication::RenderGame() void CPythonApplication::RenderGame()
{ {
MtPerf::CScope kPerf(MtPerf::SECTION_RENDER_GAME);
float fAspect=UI::CWindowManager::Instance().GetAspect(); float fAspect=UI::CWindowManager::Instance().GetAspect();
float fFarClip=CPythonBackground::Instance().GetFarClip(); float fFarClip=CPythonBackground::Instance().GetFarClip();
@@ -253,6 +259,7 @@ void CPythonApplication::RenderGame()
// calls it every frame. PORT: members through their singletons, as in RenderGame. // calls it every frame. PORT: members through their singletons, as in RenderGame.
void CPythonApplication::UpdateGame() void CPythonApplication::UpdateGame()
{ {
MtPerf::CScope kPerf(MtPerf::SECTION_UPDATE_GAME);
POINT ptMouse; POINT ptMouse;
GetMousePosition(&ptMouse); GetMousePosition(&ptMouse);
@@ -293,19 +300,42 @@ void CPythonApplication::UpdateGame()
// input instead), camera (2V3), resource GC, mouse/UI update, then the render block's interface pass. // input instead), camera (2V3), resource GC, mouse/UI update, then the render block's interface pass.
// PORT: the frame-skip bookkeeping and the game render pass are left out; the Godot frame clock // PORT: the frame-skip bookkeeping and the game render pass are left out; the Godot frame clock
// decides when this runs, and RenderGame belongs to 2V3. // decides when this runs, and RenderGame belongs to 2V3.
// PORT: telemetry for --perf-log (platform/EterBase/PerfCounters.h); 40250 has no counterpart.
static void __PerfSampleWorld()
{
if (!MtPerf::Enabled())
return;
MtPerf::SCounters& rkCounters = MtPerf::Counters();
CPythonCharacterManager& rkChrMgr = CPythonCharacterManager::Instance();
int iActors = 0;
for (CPythonCharacterManager::CharacterIterator i = rkChrMgr.CharacterInstanceBegin(); i != rkChrMgr.CharacterInstanceEnd(); ++i)
++iActors;
rkCounters.actorCount = iActors;
#if defined(__linux__) || defined(__ANDROID__)
rkCounters.scriptCpu = sched_getcpu();
#endif
}
bool CPythonApplication::Process() bool CPythonApplication::Process()
{ {
MtPerf::CScope kPerfProcess(MtPerf::SECTION_PROCESS);
__PerfSampleWorld();
ELTimer_SetFrameMSec(); ELTimer_SetFrameMSec();
CTimer& rkTimer=CTimer::Instance(); CTimer& rkTimer=CTimer::Instance();
rkTimer.Advance(); rkTimer.Advance();
// Network I/O // Network I/O
{
MtPerf::CScope kPerf(MtPerf::SECTION_NETWORK);
CPythonNetworkStream::Instance().Process(); CPythonNetworkStream::Instance().Process();
// PORT: m_kGuildMarkUploader/m_kGuildMarkDownloader.Process() follow here in 40250; the guild mark // PORT: m_kGuildMarkUploader/m_kGuildMarkDownloader.Process() follow here in 40250; the guild mark
// transfer is not ported yet (GuildMarkDownloader.cpp/GuildMarkUploader.cpp). // transfer is not ported yet (GuildMarkDownloader.cpp/GuildMarkUploader.cpp).
CAccountConnector::Instance().Process(); CAccountConnector::Instance().Process();
}
{
MtPerf::CScope kPerf(MtPerf::SECTION_CAMERA);
//!@# Alt+Tab 중 SetTransfor 에서 튕김 현상 해결을 위해 - [levites] //!@# Alt+Tab 중 SetTransfor 에서 튕김 현상 해결을 위해 - [levites]
//if (m_isActivateWnd) //if (m_isActivateWnd)
__UpdateCamera(); __UpdateCamera();
@@ -315,7 +345,11 @@ bool CPythonApplication::Process()
OnCameraUpdate(); OnCameraUpdate();
if (IsNativeTerrainRenderEnabled()) if (IsNativeTerrainRenderEnabled())
OnMouseUpdate(); OnMouseUpdate();
}
{
MtPerf::CScope kPerf(MtPerf::SECTION_UI_UPDATE);
OnUIUpdate(); OnUIUpdate();
}
if (IsNativeTerrainRenderEnabled()) if (IsNativeTerrainRenderEnabled())
CGrannyMaterial::TranslateSpecularMatrix(g_specularSpd, g_specularSpd, 0.0f); CGrannyMaterial::TranslateSpecularMatrix(g_specularSpd, g_specularSpd, 0.0f);
@@ -325,14 +359,19 @@ bool CPythonApplication::Process()
// Win32 activation (CMSWindow::IsActive is a stub). The frame's UI and 3D command lists restart here. // Win32 activation (CMSWindow::IsActive is a stub). The frame's UI and 3D command lists restart here.
// 40250 PythonApplication.cpp:681. // 40250 PythonApplication.cpp:681.
DWORD dwRenderStartTime = ELTimer_GetMSec(); DWORD dwRenderStartTime = ELTimer_GetMSec();
{
MtPerf::CScope kPerf(MtPerf::SECTION_RENDER_BEGIN);
CCullingManager::Instance().Update(); CCullingManager::Instance().Update();
UIRenderBeginFrame(); UIRenderBeginFrame();
Render3DBeginFrame(); Render3DBeginFrame();
}
CPythonGraphic& rkGraphic = CPythonGraphic::Instance(); CPythonGraphic& rkGraphic = CPythonGraphic::Instance();
if (rkGraphic.Begin()) if (rkGraphic.Begin())
{ {
rkGraphic.SetInterfaceRenderState(); rkGraphic.SetInterfaceRenderState();
{
MtPerf::CScope kPerf(MtPerf::SECTION_UI_RENDER);
OnUIRender(); OnUIRender();
if (IsNativeTerrainRenderEnabled()) if (IsNativeTerrainRenderEnabled())
{ {
@@ -342,6 +381,7 @@ bool CPythonApplication::Process()
UIRenderSetClip(0.0f, 0.0f, float(cw), float(ch)); UIRenderSetClip(0.0f, 0.0f, float(cw), float(ch));
OnMouseRender(); OnMouseRender();
} }
}
rkGraphic.End(); rkGraphic.End();
@@ -1,5 +1,6 @@
#include "StdAfx.h" #include "StdAfx.h"
#include "PythonUtils.h" #include "PythonUtils.h"
#include "../../platform/EterBase/PerfCounters.h" // PORT: --perf-log callback timing
IPythonExceptionSender * g_pkExceptionSender = NULL; IPythonExceptionSender * g_pkExceptionSender = NULL;
@@ -291,6 +292,7 @@ bool PyCallClassMemberFunc(PyObject* poClass, const char* c_szFunc, PyObject* po
*/ */
bool __PyCallClassMemberFunc_ByCString(PyObject* poClass, const char* c_szFunc, PyObject* poArgs, PyObject** ppoRet) bool __PyCallClassMemberFunc_ByCString(PyObject* poClass, const char* c_szFunc, PyObject* poArgs, PyObject** ppoRet)
{ {
MtPerf::CPythonScope kPerf;
if (!poClass) if (!poClass)
{ {
Py_XDECREF(poArgs); Py_XDECREF(poArgs);
@@ -302,6 +304,7 @@ bool __PyCallClassMemberFunc_ByCString(PyObject* poClass, const char* c_szFunc,
if (!poFunc) if (!poFunc)
{ {
PyErr_Clear(); PyErr_Clear();
MtPerf::CountPythonMissing();
Py_XDECREF(poArgs); Py_XDECREF(poArgs);
return false; return false;
} }
@@ -339,6 +342,7 @@ bool __PyCallClassMemberFunc_ByCString(PyObject* poClass, const char* c_szFunc,
bool __PyCallClassMemberFunc_ByPyString(PyObject* poClass, PyObject* poFuncName, PyObject* poArgs, PyObject** ppoRet) bool __PyCallClassMemberFunc_ByPyString(PyObject* poClass, PyObject* poFuncName, PyObject* poArgs, PyObject** ppoRet)
{ {
MtPerf::CPythonScope kPerf;
if (!poClass) if (!poClass)
{ {
Py_XDECREF(poArgs); Py_XDECREF(poArgs);
@@ -350,6 +354,7 @@ bool __PyCallClassMemberFunc_ByPyString(PyObject* poClass, PyObject* poFuncName,
if (!poFunc) if (!poFunc)
{ {
PyErr_Clear(); PyErr_Clear();
MtPerf::CountPythonMissing();
Py_XDECREF(poArgs); Py_XDECREF(poArgs);
return false; return false;
} }
@@ -387,6 +392,7 @@ bool __PyCallClassMemberFunc_ByPyString(PyObject* poClass, PyObject* poFuncName,
bool __PyCallClassMemberFunc(PyObject* poClass, PyObject * poFunc, PyObject* poArgs, PyObject** ppoRet) bool __PyCallClassMemberFunc(PyObject* poClass, PyObject * poFunc, PyObject* poArgs, PyObject** ppoRet)
{ {
MtPerf::CPythonScope kPerf;
if (!poClass) if (!poClass)
{ {
Py_XDECREF(poArgs); Py_XDECREF(poArgs);
@@ -396,6 +402,7 @@ bool __PyCallClassMemberFunc(PyObject* poClass, PyObject * poFunc, PyObject* poA
if (!poFunc) if (!poFunc)
{ {
PyErr_Clear(); PyErr_Clear();
MtPerf::CountPythonMissing();
Py_XDECREF(poArgs); Py_XDECREF(poArgs);
return false; return false;
} }
+13 -3
View File
@@ -22,7 +22,17 @@ namespace
{ {
constexpr std::uint32_t kHandshake = 0x2468ace0; constexpr std::uint32_t kHandshake = 0x2468ace0;
constexpr int kHandshakeRetryLimit = 32; // game/src/desc.h HANDSHAKE_RETRY_LIMIT constexpr int kHandshakeRetryLimit = 32; // game/src/desc.h HANDSHAKE_RETRY_LIMIT
constexpr int kIdleMs = 20000; // A client that sends nothing for this long is dropped. MT_FAKE_IDLE_MS raises it for runs that stand
// still in game (perf measurements).
int idle_ms()
{
static const int ms = [] {
const char* value = std::getenv("MT_FAKE_IDLE_MS");
const long parsed = value && *value ? std::strtol(value, nullptr, 10) : 0;
return parsed >= 1000 ? static_cast<int>(parsed) : 20000;
}();
return ms;
}
int fake_mob_count() int fake_mob_count()
{ {
@@ -127,7 +137,7 @@ struct FakeLoginServer::Connection
int ready = poll(&pfd, 1, 50); int ready = poll(&pfd, 1, 50);
if (ready == 0) if (ready == 0)
{ {
if ((waited += 50) >= kIdleMs) if ((waited += 50) >= idle_ms())
return -1; return -1;
continue; continue;
} }
@@ -222,7 +232,7 @@ bool FakeLoginServer::Accept(int listener, Connection& c)
c.fd = accept(listener, nullptr, nullptr); c.fd = accept(listener, nullptr, nullptr);
return c.fd >= 0; return c.fd >= 0;
} }
if (waited >= kIdleMs) if (waited >= idle_ms())
return Fail("no client connected"); return Fail("no client connected");
} }
return false; return false;
+140
View File
@@ -0,0 +1,140 @@
#pragma once
// Android frame-rate and CPU-clock plumbing for the live client's render loop.
//
// - display_refresh_rate(): the panel's refresh rate now (MainActivity.currentRefreshRate), and
// render_rate(): the app-vsync rate the system actually gives the app (MainActivity.currentRenderRate),
// for the perf log's refresh_hz / render_hz columns.
// - request_frame_rate(): ANativeWindow_setFrameRate (API 30), the surface's preferred rate. The display
// mode itself is chosen by MainActivity (--refresh-rate -> preferredDisplayModeId); the vendor
// (ColorOS etc.) can still cap an app it does not know.
// - PerformanceHint: ADPF APerformanceHint (API 33). The loop reports each frame's CPU work against the
// frame budget, so the governor raises the clocks before a frame misses instead of idling the CPU at
// its lowest step between short bursts (the 556-748 MHz seen in perf-20260929-153205.csv).
//
// Every NDK entry point is looked up at run time: minSdk is 24. On other platforms all of this is a no-op.
#include <SDL3/SDL.h>
#include <cstdint>
#include <vector>
#ifdef __ANDROID__
#include <android/native_window.h>
#include <dlfcn.h>
#include <jni.h>
#include <unistd.h>
#endif
namespace android_perf {
#ifdef __ANDROID__
inline void* libandroid() {
static void* lib = dlopen("libandroid.so", RTLD_NOW);
return lib;
}
inline double call_activity_float(const char* name) {
auto* env = static_cast<JNIEnv*>(SDL_GetAndroidJNIEnv());
auto activity = static_cast<jobject>(SDL_GetAndroidActivity());
if (!env || !activity) return -1.0;
double hz = -1.0;
jclass cls = env->GetObjectClass(activity);
if (jmethodID method = env->GetMethodID(cls, name, "()F"))
hz = env->CallFloatMethod(activity, method);
if (env->ExceptionCheck()) {
env->ExceptionClear();
hz = -1.0;
}
env->DeleteLocalRef(cls);
env->DeleteLocalRef(activity);
return hz;
}
inline double display_refresh_rate() { return call_activity_float("currentRefreshRate"); }
// The app-vsync rate (Choreographer); -1 until the first measurement.
inline double render_rate() { return call_activity_float("currentRenderRate"); }
inline double battery_celsius() { return call_activity_float("batteryTemperature"); }
// false when the call is unavailable (API < 30) or rejected.
inline bool request_frame_rate(SDL_Window* window, float fps) {
using SetFrameRate = int32_t (*)(ANativeWindow*, float, int8_t);
static const auto set_frame_rate =
libandroid() ? reinterpret_cast<SetFrameRate>(dlsym(libandroid(), "ANativeWindow_setFrameRate")) : nullptr;
if (!set_frame_rate || !window) return false;
auto* native = static_cast<ANativeWindow*>(SDL_GetPointerProperty(
SDL_GetWindowProperties(window), SDL_PROP_WINDOW_ANDROID_WINDOW_POINTER, nullptr));
if (!native) return false;
// ANATIVEWINDOW_FRAME_RATE_COMPATIBILITY_DEFAULT: a game, not fixed-rate video.
return set_frame_rate(native, fps, 0) == 0;
}
class PerformanceHint {
public:
// `thread_ids`: the threads that do each frame's work (render thread + script thread).
bool open(const std::vector<int32_t>& thread_ids, std::int64_t target_ns) {
void* lib = libandroid();
if (!lib || thread_ids.empty()) return false;
get_manager_ = reinterpret_cast<GetManager>(dlsym(lib, "APerformanceHint_getManager"));
create_ = reinterpret_cast<CreateSession>(dlsym(lib, "APerformanceHint_createSession"));
update_target_ = reinterpret_cast<UpdateTarget>(dlsym(lib, "APerformanceHint_updateTargetWorkDuration"));
report_ = reinterpret_cast<Report>(dlsym(lib, "APerformanceHint_reportActualWorkDuration"));
close_ = reinterpret_cast<Close>(dlsym(lib, "APerformanceHint_closeSession"));
if (!get_manager_ || !create_ || !report_ || !close_) return false;
void* manager = get_manager_();
if (!manager) return false;
session_ = create_(manager, thread_ids.data(), thread_ids.size(), target_ns);
target_ns_ = target_ns;
return session_ != nullptr;
}
~PerformanceHint() {
if (session_ && close_) close_(session_);
}
bool active() const { return session_ != nullptr; }
void set_target(std::int64_t target_ns) {
if (!session_ || !update_target_ || target_ns == target_ns_ || target_ns <= 0) return;
update_target_(session_, target_ns);
target_ns_ = target_ns;
}
void report(std::int64_t actual_ns) {
if (session_ && actual_ns > 0) report_(session_, actual_ns);
}
private:
using GetManager = void* (*)();
using CreateSession = void* (*)(void*, const int32_t*, size_t, int64_t);
using UpdateTarget = int (*)(void*, int64_t);
using Report = int (*)(void*, int64_t);
using Close = void (*)(void*);
GetManager get_manager_ = nullptr;
CreateSession create_ = nullptr;
UpdateTarget update_target_ = nullptr;
Report report_ = nullptr;
Close close_ = nullptr;
void* session_ = nullptr;
std::int64_t target_ns_ = 0;
};
inline int32_t current_thread_id() { return int32_t(gettid()); }
#else
inline double display_refresh_rate() {
const SDL_DisplayMode* mode = SDL_GetCurrentDisplayMode(SDL_GetPrimaryDisplay());
return mode ? double(mode->refresh_rate) : -1.0;
}
inline double render_rate() { return display_refresh_rate(); }
inline double battery_celsius() { return -1.0; }
inline bool request_frame_rate(SDL_Window*, float) { return false; }
class PerformanceHint {
public:
bool open(const std::vector<int32_t>&, std::int64_t) { return false; }
bool active() const { return false; }
void set_target(std::int64_t) {}
void report(std::int64_t) {}
};
inline int32_t current_thread_id() { return 0; }
#endif
} // namespace android_perf
+11 -3
View File
@@ -28,7 +28,7 @@
namespace native_draw_capture { namespace native_draw_capture {
struct Capture { struct Capture {
std::uint32_t version = 9; std::uint32_t version = 10;
std::vector<Render3DDraw> draws; std::vector<Render3DDraw> draws;
std::unordered_map<std::string, std::vector<std::uint8_t>> textures; std::unordered_map<std::string, std::vector<std::uint8_t>> textures;
std::uint32_t ui_width = 960; std::uint32_t ui_width = 960;
@@ -114,7 +114,7 @@ inline void write(
std::ofstream file(path, std::ios::binary | std::ios::trunc); std::ofstream file(path, std::ios::binary | std::ios::trunc);
if (!file) throw std::runtime_error("cannot create native draw capture: " + path); if (!file) throw std::runtime_error("cannot create native draw capture: " + path);
const std::uint32_t magic = 0x4d544452; // MTDR const std::uint32_t magic = 0x4d544452; // MTDR
const std::uint32_t version = 9; const std::uint32_t version = 10;
const auto count = static_cast<std::uint32_t>(draws.size()); const auto count = static_cast<std::uint32_t>(draws.size());
write_scalar(file, magic); write_scalar(file, version); write_scalar(file, count); write_scalar(file, magic); write_scalar(file, version); write_scalar(file, count);
for (const auto& draw : draws) { for (const auto& draw : draws) {
@@ -193,6 +193,9 @@ inline void write(
write_vector(file, draw.bone_indices); write_vector(file, draw.bone_indices);
write_vector(file, draw.bone_weights); write_vector(file, draw.bone_weights);
write_vector(file, draw.bone_matrices); write_vector(file, draw.bone_matrices);
write_scalar(file, draw.render_target);
write_scalar(file, draw.target_width);
write_scalar(file, draw.target_height);
} }
const auto texture_count = static_cast<std::uint32_t>(textures.size()); const auto texture_count = static_cast<std::uint32_t>(textures.size());
write_scalar(file, texture_count); write_scalar(file, texture_count);
@@ -239,7 +242,7 @@ inline Capture read_capture(const std::string& path) {
if (!file) throw std::runtime_error("cannot open native draw capture: " + path); if (!file) throw std::runtime_error("cannot open native draw capture: " + path);
std::uint32_t magic = 0, version = 0, count = 0; std::uint32_t magic = 0, version = 0, count = 0;
read_scalar(file, magic); read_scalar(file, version); read_scalar(file, count); read_scalar(file, magic); read_scalar(file, version); read_scalar(file, count);
if (magic != 0x4d544452 || (version < 1 || version > 9) || count > 10'000) if (magic != 0x4d544452 || (version < 1 || version > 10) || count > 10'000)
throw std::runtime_error("unsupported native draw capture format"); throw std::runtime_error("unsupported native draw capture format");
Capture capture; Capture capture;
capture.version = version; capture.version = version;
@@ -348,6 +351,11 @@ inline Capture read_capture(const std::string& path) {
read_vector(file, draw.bone_weights); read_vector(file, draw.bone_weights);
read_vector(file, draw.bone_matrices); read_vector(file, draw.bone_matrices);
} }
if (version >= 10) {
read_scalar(file, draw.render_target);
read_scalar(file, draw.target_width);
read_scalar(file, draw.target_height);
}
} }
if (version >= 3) { if (version >= 3) {
std::uint32_t texture_count = 0; std::uint32_t texture_count = 0;
+776 -254
View File
File diff suppressed because it is too large Load Diff
+419
View File
@@ -0,0 +1,419 @@
#pragma once
// Performance telemetry for the live client (--perf-log or MT_PERF_LOG=1).
//
// Every frame the host hands PerfLog the frame's wall times and the renderer's running totals; the
// script thread's section times come from platform/EterBase/PerfCounters.h. Every interval (2 s) one CSV
// row with the window's per-frame averages is appended to perf-YYYYMMDD-HHMMSS.csv and a short summary
// goes to logcat (stderr on desktop). A frame over the hitch threshold additionally writes a "# hitch"
// comment line with that frame's own breakdown.
//
// Files: Android <external files dir>/perf (/sdcard/Android/data/<package>/files/perf, pulled with
// tools/pull_perf_logs.sh), desktop $MT_PERF_DIR or ./perf. The newest kKeepFiles files are kept.
#include "platform/EterBase/PerfCounters.h"
#include <SDL3/SDL.h>
#include <algorithm>
#include <chrono>
#include <cstdint>
#include <cstdio>
#include <cstdlib>
#include <ctime>
#include <filesystem>
#include <functional>
#include <string>
#include <vector>
#if defined(__linux__) || defined(__ANDROID__)
#include <sched.h>
#include <unistd.h>
#endif
#ifdef __ANDROID__
#include <dlfcn.h>
#endif
namespace native_perf {
// Running totals the renderer keeps (VulkanWindow::Timings and its upload counters); PerfLog differences
// them itself, so they never need resetting.
struct RendererTotals {
double sync_ms = 0, fence_ms = 0, prepare_ms = 0, geometry_upload_ms = 0, texture_upload_ms = 0;
double submit_ms = 0, present_ms = 0, gpu_ms = 0;
std::uint64_t gpu_samples = 0;
std::uint64_t uploads = 0, uploaded_bytes = 0, texture_uploads = 0, texture_bytes = 0;
// The last frame's counts.
std::uint64_t draws = 0, skinned_draws = 0, ui_batches = 0, vertices = 0;
const std::string* last_texture = nullptr; // name of the texture uploaded last
};
struct FrameInput {
double frame_ms = 0; // whole loop iteration
double app_ms = 0; // PythonBoot::UIUpdate: the script thread's Process() plus the baton handoff
double host_ms = 0; // cursor sync, UIRender, audio pump
double render_ms = 0; // VulkanWindow::render
double pace_ms = 0; // sleep of the frame-rate cap (--fps-cap), outside frame_ms
RendererTotals renderer;
};
class PerfLog {
public:
static constexpr double kIntervalS = 2.0;
static constexpr double kHitchMs = 100.0;
static constexpr int kKeepFiles = 10;
static bool requested_by_env() {
const char* env = std::getenv("MT_PERF_LOG");
return env && *env && std::string(env) != "0";
}
bool enabled() const { return file_ != nullptr; }
// Display refresh rate in Hz as the OS reports it now (Android Display.getRefreshRate), sampled
// once per row; -1 when unknown.
void set_refresh_rate_source(std::function<double()> source) { refresh_rate_ = std::move(source); }
// The rate the system actually drives the app at (Android Choreographer); can be a divisor of refresh_hz.
void set_render_rate_source(std::function<double()> source) { render_rate_ = std::move(source); }
// Battery temperature in C (Android: the ACTION_BATTERY_CHANGED sticky intent; sysfs is SELinux-denied).
void set_battery_source(std::function<double()> source) { battery_ = std::move(source); }
void set_fps_cap(int cap) { fps_cap_ = cap; }
const std::string& path() const { return path_; }
// `context` goes into the file header (device, present mode, MSAA, size...).
bool open(const std::string& context) {
const std::string dir = directory();
std::error_code ec;
std::filesystem::create_directories(dir, ec);
prune(dir);
char stamp[32];
const std::time_t now = std::time(nullptr);
std::tm local{};
localtime_r(&now, &local);
std::strftime(stamp, sizeof(stamp), "%Y%m%d-%H%M%S", &local);
path_ = dir + "/perf-" + stamp + ".csv";
file_ = std::fopen(path_.c_str(), "w");
if (!file_) {
log("perf log: cannot write %s", path_.c_str());
return false;
}
std::fprintf(file_, "# mt_native_render perf log %s\n# %s\n", stamp, context.c_str());
std::fprintf(file_, "# per-frame averages over each %.0f s window; *_ms game sections run on the script thread "
"inside app_ms; py_ms includes update_game/render_game\n", kIntervalS);
std::fprintf(file_,
"t_s,map,actors,frames,fps,refresh_hz,render_hz,fps_cap,frame_ms,frame_p95_ms,frame_max_ms,jank33,jank50,"
"app_ms,process_ms,handoff_ms,net_ms,camera_ms,ui_update_ms,update_game_ms,render_begin_ms,ui_render_ms,"
"render_game_ms,shadow_raster_ms,py_ms,py_calls,py_missing,host_ms,render_ms,pace_ms,sync_ms,fence_ms,"
"prepare_ms,geo_upload_ms,tex_upload_ms,"
"submit_ms,present_ms,gpu_ms,draws,skinned_draws,ui_batches,vertices,geo_uploads,geo_kb,tex_uploads,tex_kb,"
"script_cpu,main_cpu,cpu_mhz,cpu_max_mhz,thermal,batt_c,rss_mb,last_texture\n");
std::fflush(file_);
MtPerf::Enabled() = true;
MtPerf::Take();
start_ = window_start_ = std::chrono::steady_clock::now();
log("perf log: %s", path_.c_str());
return true;
}
~PerfLog() {
if (file_) std::fclose(file_);
MtPerf::Enabled() = false;
}
// Call once per frame. `map_name` is only asked for when a row is written.
template <typename MapName>
void frame(const FrameInput& in, MapName&& map_name) {
if (!file_) return;
const MtPerf::SCounters game = MtPerf::Take();
const RendererTotals& r = in.renderer;
const RendererTotals& p = have_prev_ ? prev_ : r;
Window f;
f.frames = 1;
f.frame_ms = in.frame_ms;
f.app_ms = in.app_ms;
f.host_ms = in.host_ms;
f.render_ms = in.render_ms;
f.pace_ms = in.pace_ms;
for (int i = 0; i < MtPerf::SECTION_COUNT; ++i) f.game_ms[i] = game.ms[i];
f.py_calls = game.calls[MtPerf::SECTION_PYTHON];
f.py_missing = game.pyMissing;
f.sync_ms = r.sync_ms - p.sync_ms;
f.fence_ms = r.fence_ms - p.fence_ms;
f.prepare_ms = r.prepare_ms - p.prepare_ms;
f.geo_upload_ms = r.geometry_upload_ms - p.geometry_upload_ms;
f.tex_upload_ms = r.texture_upload_ms - p.texture_upload_ms;
f.submit_ms = r.submit_ms - p.submit_ms;
f.present_ms = r.present_ms - p.present_ms;
f.gpu_ms = r.gpu_ms - p.gpu_ms;
f.gpu_samples = r.gpu_samples - p.gpu_samples;
f.geo_uploads = r.uploads - p.uploads;
f.geo_bytes = r.uploaded_bytes - p.uploaded_bytes;
f.tex_uploads = r.texture_uploads - p.texture_uploads;
f.tex_bytes = r.texture_bytes - p.texture_bytes;
prev_ = r;
have_prev_ = true;
if (in.frame_ms >= kHitchMs) write_hitch(f, game);
window_.add(f);
frame_times_.push_back(in.frame_ms);
draws_ = r.draws;
skinned_draws_ = r.skinned_draws;
ui_batches_ = r.ui_batches;
vertices_ = r.vertices;
if (f.tex_uploads && r.last_texture) last_texture_ = *r.last_texture;
actors_ = game.actorCount;
script_cpu_ = game.scriptCpu;
const auto now = std::chrono::steady_clock::now();
const double elapsed = std::chrono::duration<double>(now - window_start_).count();
if (elapsed < kIntervalS) return;
write_row(elapsed, map_name());
window_ = {};
frame_times_.clear();
window_start_ = now;
}
private:
struct Window {
std::uint64_t frames = 0;
double frame_ms = 0, app_ms = 0, host_ms = 0, render_ms = 0, pace_ms = 0;
double game_ms[MtPerf::SECTION_COUNT] = {};
std::uint64_t py_calls = 0, py_missing = 0;
double sync_ms = 0, fence_ms = 0, prepare_ms = 0, geo_upload_ms = 0, tex_upload_ms = 0, submit_ms = 0;
double present_ms = 0, gpu_ms = 0;
std::uint64_t gpu_samples = 0;
std::uint64_t geo_uploads = 0, geo_bytes = 0, tex_uploads = 0, tex_bytes = 0;
void add(const Window& o) {
frames += o.frames;
frame_ms += o.frame_ms; app_ms += o.app_ms; host_ms += o.host_ms; render_ms += o.render_ms;
pace_ms += o.pace_ms; fence_ms += o.fence_ms;
for (int i = 0; i < MtPerf::SECTION_COUNT; ++i) game_ms[i] += o.game_ms[i];
py_calls += o.py_calls; py_missing += o.py_missing;
sync_ms += o.sync_ms; prepare_ms += o.prepare_ms; geo_upload_ms += o.geo_upload_ms;
tex_upload_ms += o.tex_upload_ms; submit_ms += o.submit_ms; present_ms += o.present_ms;
gpu_ms += o.gpu_ms; gpu_samples += o.gpu_samples;
geo_uploads += o.geo_uploads; geo_bytes += o.geo_bytes;
tex_uploads += o.tex_uploads; tex_bytes += o.tex_bytes;
}
};
static std::string directory() {
if (const char* env = std::getenv("MT_PERF_DIR"); env && *env) return env;
#ifdef __ANDROID__
if (const char* ext = SDL_GetAndroidExternalStoragePath(); ext && *ext) return std::string(ext) + "/perf";
if (const char* internal = SDL_GetAndroidInternalStoragePath(); internal && *internal)
return std::string(internal) + "/perf";
#endif
return "perf";
}
static void prune(const std::string& dir) {
std::error_code ec;
std::vector<std::filesystem::path> files;
for (const auto& entry : std::filesystem::directory_iterator(dir, ec)) {
const std::string name = entry.path().filename().string();
if (name.rfind("perf-", 0) == 0 && entry.path().extension() == ".csv") files.push_back(entry.path());
}
std::sort(files.begin(), files.end());
// Leave room for the file about to be opened.
for (std::size_t i = 0; i + kKeepFiles <= files.size(); ++i) std::filesystem::remove(files[i], ec);
}
template <typename... Args>
static void log(const char* format, Args... args) {
#ifdef __ANDROID__
SDL_Log(format, args...);
#else
std::fprintf(stderr, format, args...);
std::fputc('\n', stderr);
#endif
}
static int current_cpu() {
#if defined(__linux__) || defined(__ANDROID__)
return sched_getcpu();
#else
return -1;
#endif
}
static long read_long(const char* path) {
std::FILE* f = std::fopen(path, "r");
if (!f) return -1;
long value = -1;
if (std::fscanf(f, "%ld", &value) != 1) value = -1;
std::fclose(f);
return value;
}
// Current clock of every CPU in MHz, "cpu0/cpu1/...", or "" where sysfs is closed.
static std::string cpu_mhz() {
std::string out;
#if defined(__linux__) || defined(__ANDROID__)
for (int cpu = 0; cpu < 16; ++cpu) {
char path[96];
std::snprintf(path, sizeof(path), "/sys/devices/system/cpu/cpu%d/cpufreq/scaling_cur_freq", cpu);
const long khz = read_long(path);
if (khz < 0) {
if (cpu >= 8 || access(path, F_OK) != 0) break;
continue;
}
if (!out.empty()) out += '/';
out += std::to_string(khz / 1000);
}
#endif
return out;
}
// Each cpufreq policy's current ceiling (scaling_max_freq): the vendor's thermal throttling shows up
// here long before AThermal reports anything.
static std::string cpu_max_mhz() {
std::string out;
#if defined(__linux__) || defined(__ANDROID__)
for (int policy = 0; policy < 16; ++policy) {
char path[96];
std::snprintf(path, sizeof(path), "/sys/devices/system/cpu/cpufreq/policy%d/scaling_max_freq", policy);
const long khz = read_long(path);
if (khz < 0) continue;
if (!out.empty()) out += '/';
out += std::to_string(khz / 1000);
}
#endif
return out;
}
// AThermal_getCurrentThermalStatus (API 30+, looked up at run time since minSdk is lower):
// 0 none, 1 light, 2 moderate, 3 severe, 4 critical, 5 emergency, 6 shutdown; -1 unknown.
static int thermal_status() {
#ifdef __ANDROID__
using Acquire = void* (*)();
using Status = int (*)(void*);
static void* manager = nullptr;
static Status status = nullptr;
static bool looked_up = false;
if (!looked_up) {
looked_up = true;
if (void* lib = dlopen("libandroid.so", RTLD_NOW)) {
const auto acquire = reinterpret_cast<Acquire>(dlsym(lib, "AThermal_acquireManager"));
status = reinterpret_cast<Status>(dlsym(lib, "AThermal_getCurrentThermalStatus"));
if (acquire && status) manager = acquire();
}
}
if (manager && status) return status(manager);
#endif
return -1;
}
double battery_celsius() const {
if (battery_) return battery_();
#if defined(__linux__) || defined(__ANDROID__)
const long tenths = read_long("/sys/class/power_supply/battery/temp");
if (tenths > 0) return double(tenths) / 10.0; // -1: unreadable (SELinux on most phones)
#endif
return -1.0;
}
static double rss_mb() {
#if defined(__linux__) || defined(__ANDROID__)
std::FILE* f = std::fopen("/proc/self/statm", "r");
if (!f) return -1.0;
long pages = 0, resident = 0;
const int read = std::fscanf(f, "%ld %ld", &pages, &resident);
std::fclose(f);
if (read == 2) return double(resident) * double(sysconf(_SC_PAGESIZE)) / (1024.0 * 1024.0);
#endif
return -1.0;
}
static std::string csv_field(std::string text) {
for (char& c : text)
if (c == ',' || c == '\n' || c == '\r') c = ' ';
return text;
}
void write_row(double elapsed_s, const std::string& map) {
const Window& w = window_;
if (!w.frames) return;
const double n = double(w.frames);
std::vector<double> sorted = frame_times_;
std::sort(sorted.begin(), sorted.end());
const double p95 = sorted[std::min(sorted.size() - 1, std::size_t(0.95 * double(sorted.size())))];
int jank33 = 0, jank50 = 0;
for (double ms : frame_times_) {
jank33 += ms > 33.4;
jank50 += ms > 50.0;
}
const auto g = [&](MtPerf::ESection s) { return w.game_ms[s] / n; };
const double fps = n / elapsed_s;
const double gpu = w.gpu_samples ? w.gpu_ms / double(w.gpu_samples) : 0.0;
const double t = std::chrono::duration<double>(std::chrono::steady_clock::now() - start_).count();
const std::string mhz = cpu_mhz();
const std::string max_mhz = cpu_max_mhz();
const int thermal = thermal_status();
const double batt = battery_celsius();
const double rss = rss_mb();
const int main_cpu = current_cpu();
const double refresh = refresh_rate_ ? refresh_rate_() : -1.0;
const double render_rate = render_rate_ ? render_rate_() : -1.0;
std::fprintf(file_,
"%.1f,%s,%d,%llu,%.1f,%.1f,%.1f,%d,%.2f,%.2f,%.2f,%d,%d,"
"%.2f,%.2f,%.2f,%.3f,%.3f,%.3f,%.3f,%.3f,%.3f,"
"%.3f,%.3f,%.3f,%.1f,%.1f,%.3f,%.2f,%.2f,%.2f,%.2f,"
"%.2f,%.3f,%.3f,"
"%.3f,%.3f,%.2f,%llu,%llu,%llu,%llu,%.2f,%.1f,%.2f,%.1f,"
"%d,%d,%s,%s,%d,%.1f,%.0f,%s\n",
t, csv_field(map).c_str(), actors_, (unsigned long long)w.frames, fps, refresh, render_rate, fps_cap_, w.frame_ms / n,
p95, sorted.back(), jank33, jank50,
w.app_ms / n, g(MtPerf::SECTION_PROCESS), (w.app_ms - w.game_ms[MtPerf::SECTION_PROCESS]) / n,
g(MtPerf::SECTION_NETWORK), g(MtPerf::SECTION_CAMERA), g(MtPerf::SECTION_UI_UPDATE),
g(MtPerf::SECTION_UPDATE_GAME), g(MtPerf::SECTION_RENDER_BEGIN), g(MtPerf::SECTION_UI_RENDER),
g(MtPerf::SECTION_RENDER_GAME), g(MtPerf::SECTION_SHADOW_RASTER), g(MtPerf::SECTION_PYTHON),
double(w.py_calls) / n,
double(w.py_missing) / n, w.host_ms / n, w.render_ms / n, w.pace_ms / n, w.sync_ms / n, w.fence_ms / n,
w.prepare_ms / n, w.geo_upload_ms / n, w.tex_upload_ms / n,
w.submit_ms / n, w.present_ms / n, gpu, (unsigned long long)draws_, (unsigned long long)skinned_draws_,
(unsigned long long)ui_batches_, (unsigned long long)vertices_, double(w.geo_uploads) / n,
double(w.geo_bytes) / 1024.0 / n, double(w.tex_uploads) / n, double(w.tex_bytes) / 1024.0 / n,
script_cpu_, main_cpu, mhz.c_str(), max_mhz.c_str(), thermal, batt, rss, csv_field(last_texture_).c_str());
std::fflush(file_);
if (!w.tex_uploads) last_texture_.clear();
log("perf fps=%.1f @%.0fHz/%.0f cap=%d frame=%.1f/p95 %.1f/max %.1f jank33=%d | app=%.1f (upd=%.1f rnd=%.1f "
"shadow=%.1f py=%.1f) | render=%.1f (sync=%.1f fence=%.1f prep=%.1f up=%.1f/%.1f) pace=%.1f gpu=%.1f | "
"draws=%llu actors=%d map=%s thermal=%d batt=%.1f cpu=%s max=%s tex_uploads=%.2f last_tex=%s",
fps, refresh, render_rate, fps_cap_, w.frame_ms / n, p95, sorted.back(), jank33, w.app_ms / n,
g(MtPerf::SECTION_UPDATE_GAME), g(MtPerf::SECTION_RENDER_GAME), g(MtPerf::SECTION_SHADOW_RASTER),
g(MtPerf::SECTION_PYTHON), w.render_ms / n, w.sync_ms / n, w.fence_ms / n, w.prepare_ms / n,
w.geo_upload_ms / n, w.tex_upload_ms / n, w.pace_ms / n, gpu, (unsigned long long)draws_, actors_,
map.c_str(), thermal, batt, mhz.c_str(), max_mhz.c_str(), double(w.tex_uploads) / n, last_texture_.c_str());
}
void write_hitch(const Window& f, const MtPerf::SCounters& game) {
const double t = std::chrono::duration<double>(std::chrono::steady_clock::now() - start_).count();
std::fprintf(file_,
"# hitch t=%.2f frame=%.1f app=%.1f process=%.1f net=%.1f camera=%.1f ui_update=%.1f update_game=%.1f "
"ui_render=%.1f render_game=%.1f shadow=%.1f py=%.1f host=%.1f render=%.1f sync=%.1f prepare=%.1f geo_upload=%.1f(%llu) "
"tex_upload=%.1f(%llu, %.0f KB) submit=%.1f present=%.1f\n",
t, f.frame_ms, f.app_ms, game.ms[MtPerf::SECTION_PROCESS], game.ms[MtPerf::SECTION_NETWORK],
game.ms[MtPerf::SECTION_CAMERA], game.ms[MtPerf::SECTION_UI_UPDATE], game.ms[MtPerf::SECTION_UPDATE_GAME],
game.ms[MtPerf::SECTION_UI_RENDER], game.ms[MtPerf::SECTION_RENDER_GAME],
game.ms[MtPerf::SECTION_SHADOW_RASTER], game.ms[MtPerf::SECTION_PYTHON],
f.host_ms, f.render_ms, f.sync_ms, f.prepare_ms, f.geo_upload_ms, (unsigned long long)f.geo_uploads,
f.tex_upload_ms, (unsigned long long)f.tex_uploads, double(f.tex_bytes) / 1024.0, f.submit_ms, f.present_ms);
}
std::FILE* file_ = nullptr;
std::string path_;
std::chrono::steady_clock::time_point start_{}, window_start_{};
Window window_;
std::vector<double> frame_times_;
RendererTotals prev_;
bool have_prev_ = false;
std::uint64_t draws_ = 0, skinned_draws_ = 0, ui_batches_ = 0, vertices_ = 0;
int actors_ = 0, script_cpu_ = -1;
int fps_cap_ = 0;
std::function<double()> refresh_rate_;
std::function<double()> render_rate_;
std::function<double()> battery_;
std::string last_texture_;
};
} // namespace native_perf
+113
View File
@@ -0,0 +1,113 @@
#!/usr/bin/env python3
"""Summarises a native client --perf-log CSV (native_render/perf_log.h).
usage: perf_summary.py perf-YYYYMMDD-HHMMSS.csv [--all]
Only in-game rows (a map is loaded) are summarised unless --all is given. Prints the median of each
frame-time section so the largest cost stands out, the worst windows, thermal/clock trend and the
"# hitch" lines.
"""
import csv
import statistics
import sys
SECTIONS = [
("frame_ms", "whole frame"),
("app_ms", " script thread (AppFrame)"),
("net_ms", " network"),
("camera_ms", " camera/resource"),
("update_game_ms", " UpdateGame"),
("render_game_ms", " RenderGame"),
("shadow_raster_ms", " CPU shadow raster"),
("py_ms", " Python callbacks (incl. Update/RenderGame)"),
("handoff_ms", " baton handoff"),
("pace_ms", " fps-cap sleep (before the frame)"),
("host_ms", " host UI/audio"),
("render_ms", " renderer"),
("sync_ms", " fence wait + acquire"),
("fence_ms", " frame-slot fence wait"),
("prepare_ms", " prepare (incl. uploads)"),
("geo_upload_ms", " geometry uploads"),
("tex_upload_ms", " texture uploads"),
("submit_ms", " submit"),
("present_ms", " present"),
("gpu_ms", " GPU (timestamps)"),
]
def num(row, key):
try:
return float(row.get(key, "") or "nan")
except ValueError:
return float("nan")
def median(rows, key):
values = [num(r, key) for r in rows]
values = [v for v in values if v == v]
return statistics.median(values) if values else float("nan")
def main():
args = [a for a in sys.argv[1:] if not a.startswith("--")]
if not args:
sys.exit(__doc__)
path = args[0]
comments, lines = [], []
with open(path, encoding="utf-8", errors="replace") as f:
for line in f:
(comments if line.startswith("#") else lines).append(line)
rows = list(csv.DictReader(lines))
if "--all" not in sys.argv:
rows = [r for r in rows if r.get("map")]
print(path)
for c in comments[:2]:
print(c.rstrip())
if not rows:
print("no in-game rows (use --all to include the login/select screens)")
return
duration = num(rows[-1], "t_s") - num(rows[0], "t_s")
print("%d windows, %.0f s in game, maps: %s" % (len(rows), duration, ", ".join(sorted({r["map"] for r in rows}))))
print("display %s Hz app vsync (render_hz) median %.1f fps cap %s" % (
"/".join(sorted({r.get("refresh_hz", "?") for r in rows})), median(rows, "render_hz"),
rows[-1].get("fps_cap", "?")))
print("median fps %.1f frame p95 %.1f ms jank>33ms %d frames jank>50ms %d frames" % (
median(rows, "fps"), median(rows, "frame_p95_ms"),
sum(int(num(r, "jank33")) for r in rows), sum(int(num(r, "jank50")) for r in rows)))
print("median actors %.0f draws %.0f skinned %.0f python calls/frame %.0f (missing %.0f)" % (
median(rows, "actors"), median(rows, "draws"), median(rows, "skinned_draws"),
median(rows, "py_calls"), median(rows, "py_missing")))
print("uploads/frame: geometry %.1f (%.1f KB) texture %.2f (%.0f KB)" % (
median(rows, "geo_uploads"), median(rows, "geo_kb"), median(rows, "tex_uploads"), median(rows, "tex_kb")))
print()
print("median ms per frame")
for key, label in SECTIONS:
print(" %-48s %7.2f" % (label, median(rows, key)))
print()
print("worst windows (lowest fps)")
for r in sorted(rows, key=lambda r: num(r, "fps"))[:5]:
print(" t=%6.0fs fps=%5.1f frame=%5.1f app=%5.1f render_game=%5.1f render=%5.1f sync=%5.1f gpu=%5.1f "
"actors=%s thermal=%s cpu_mhz=%s" % (
num(r, "t_s"), num(r, "fps"), num(r, "frame_ms"), num(r, "app_ms"), num(r, "render_game_ms"),
num(r, "render_ms"), num(r, "sync_ms"), num(r, "gpu_ms"), r.get("actors"), r.get("thermal"),
r.get("cpu_mhz")))
step = max(1, len(rows) // 8)
print()
print("trend (thermal: 0 none .. 3 severe; -1 unknown)")
for r in rows[::step]:
print(" t=%6.0fs fps=%5.1f thermal=%s batt=%s C cpu_mhz=%s (max %s) rss=%s MB" % (
num(r, "t_s"), num(r, "fps"), r.get("thermal"), r.get("batt_c"), r.get("cpu_mhz"),
r.get("cpu_max_mhz", "?"), r.get("rss_mb")))
hitches = [c.rstrip() for c in comments if c.startswith("# hitch")]
if hitches:
print()
print("%d hitches >= 100 ms (first 10)" % len(hitches))
for h in hitches[:10]:
print(" " + h[2:])
if __name__ == "__main__":
main()
+11
View File
@@ -0,0 +1,11 @@
#!/bin/sh
# Copies the Android client's --perf-log files (native_render/perf_log.h) to ./perf-logs and prints a
# summary of the newest one. The phone must be connected with USB debugging; the files can also be
# taken off the phone without a PC from Android/data/org.metin2port.client/files/perf.
set -e
PKG=org.metin2port.client
OUT=${1:-perf-logs}
mkdir -p "$OUT"
adb pull "/sdcard/Android/data/$PKG/files/perf/." "$OUT"
newest=$(ls -t "$OUT"/perf-*.csv 2>/dev/null | head -1)
[ -n "$newest" ] && python3 "$(dirname "$0")/perf_summary.py" "$newest"