FPS / 性能剖析(profiling/ + AsprofRecorder)

基本信息

属性 值
包 com.gtnewhorizons.angelica.profiling(5 个)+ debug/profiling/AsprofRecorder.java(1 个)
本条目覆盖 6 个文件
总行数 318 + 206 + 96 + 87 + 45 + 39 = 791
上游 one.profiler.AsyncProfiler(async-profiler,第三方)
观测后端 Tracy(GLSM 子项目,见 Subprojects)
# 文件 行数 位置
1 TracyFramePlots.java 318 profiling/
2 AsprofRecorder.java 206 debug/profiling/
3 RenderClassTimings.java 96 profiling/
4 BailClassCounts.java 87 profiling/
5 GpuFrameLagMeter.java 45 profiling/
6 TracyUiSections.java 39 profiling/

TracyFramePlots:每帧往 Tracy 推的数值通道(318 行)

profiling/TracyFramePlots.java 是本包里最大的类,是 profiling/ 中唯一「每帧运行」的组件。其静态入口只有一个:

方法 行 说明
onFrame(Minecraft mc) :153 每帧调用;if (!Tracy.ENABLED) return; 后按 CaptureGate.markersThisFrame 分档推送

其数据出口是类加载时一次性申请的 plot 句柄,形如 P_PACER_PRESENT_INTERVAL_US = Tracy.plotHandle("pacer.presentIntervalUs")(:150-151)。

调用点是 mixin,不是主代码:src/mixin/.../early/angelica/tracy/MixinMinecraft_Tracy.java:21 → TracyFramePlots.onFrame((Minecraft) (Object) this);。因此它是否运行取决于 enableTracy 配置,而不是任何主代码里的显式调用 —— 只 grep src/main/java 会误判它是死代码。私有构造器在 :140。

⚠️ debug/profiling/ 里另 1 个文件 TracyCaptureNotifier.java 已被 KeyBinding 注册总表 覆盖(它有 1 个 KeyBinding),本条目不重复覆盖。

两个「按类统计」的工具:结构完全对称

BailClassCounts 与 RenderClassTimings 是同一模板的两个实例化,只差 3 点:

维度 BailClassCounts RenderClassTimings
计什么 次数(int) 纳秒(long)
add 签名 add(Class<?> cls) add(Class<?> cls, long ns)
阈值 无(有值就 plot) PLOT_THRESHOLD_NS = 20_000L
null 处理 cls == null ? Object.class : cls 无 null 处理
迭代器 Reference2IntMaps.fastIterator Reference2LongMaps.fastIterator

3 个实例(各自独立的计数表):

类的实例 常量 plot 前缀 label 行
BailClassCounts.MATERIAL new BailClassCounts("tesr.bailCls.mat.", "BailMat") tesr.bailCls.mat. BailMat :11
BailClassCounts.TEMPLATE ...("tesr.bailCls.tmpl.", "BailTmpl") tesr.bailCls.tmpl. BailTmpl :12
BailClassCounts.PARTICLE_SPILL ...("particles.spillCls.", "PartSpill") particles.spillCls. PartSpill :13
RenderClassTimings.ENTITY new RenderClassTimings("entity.cls.", "Entity") entity.cls. Entity :10
RenderClassTimings.SHADOW_ENTITY ...("shadow.entity.cls.", "ShadowEntity") shadow.entity.cls. ShadowEntity :11
RenderClassTimings.TESR ...("tesr.cls.", "TESR") tesr.cls. TESR :12

共 6 个实例,plotPrefix 全部以 . 结尾 —— 类名直接拼在后面(plotName(entry.getKey()) 生成完整 plot 名)。

⚠️ BailClassCounts.PARTICLE_SPILL 的唯一生产调用点是 ParticleInstancer(ParticleInstancer.java:157 BailClassCounts.PARTICLE_SPILL.add(fx.getClass()))—— 见 粒子实例化。

⚠️ 命名不对齐:RenderClassTimings 的三个 label 是 Entity / ShadowEntity / TESR(无分隔符),而 BailClassCounts 的是 BailMat / BailTmpl / PartSpill。两套命名风格混在同一目录。 前者的 label 只用于 F3 调试行显示。

三张弱引用 map(两者各 3 张)

BailClassCounts(:15-17):

字段 类型 用途
counts Reference2IntOpenHashMap<Class<?>> 计数
plotNames Reference2ObjectOpenHashMap<Class<?>, String> plot 句柄缓存
debugLine String F3 显示行

RenderClassTimings(:20-22)多一张 nanos(Reference2LongOpenHashMap<Class<?>>)。

⚠️ 全是弱引用键(Reference2IntOpenHashMap)—— 渲染器类被卸载后条目可回收。⚠️ 但 plotNames 里的 plot 句柄是 String(Tracy plot 名)不是数值句柄 —— Tracy.plotInt(plotName(...), v) 每帧用字符串调 plot,而 GpuFrameLagMeter 用的是预先取好的数值句柄 Tracy.plotHandle("gpuLagNs")(GpuFrameLagMeter.java:14,在静态初始化时取一次)。两种 plot 用法并存 —— 字符串版每帧走名字查找,数值版直接用句柄。性能与稳定性不同。

⚠️ plotNames 是弱引用键的 map,但 Tracy 的 plot 句柄是全局注册的 —— 类被回收后条目消失,下次同名的另一个类会重新注册同名 plot。若 Tracy 侧同名 plot 已存在,行为取决于 Tracy.plotInt(String, ...) 的实现(GLSM 子项目,本条目不可判定)。

flushFrame 的早退条件

BailClassCounts.flushFrame(boolean plot)(:30-~46):

if (counts.isEmpty()) { debugLine = ""; return; }                                   // :31
final boolean debugScreen = Minecraft.getMinecraft().gameSettings.showDebugInfo;      // :35
if (!plot && !debugScreen) { debugLine = ""; counts.clear(); return; }                // :36-38

⚠️ 早退时 counts.clear() 但 plotNames 不清(:38)—— plotNames 跨帧累积(弱引用键,被回收的类条目会消失)。内存不会无界增长,但也不完全对称。

⚠️ Minecraft.getMinecraft() 在 flush 里被调用(:35)—— 每帧一次。若 flush 在非客户端线程,会拿到不同实例或 NPE。

⚠️ !plot && !debugScreen 的语义:plot 通常是 Tracy.ENABLED。即 Tracy 关 + F3 关 → 完全跳过(只清缓存);任一开 → 继续。这是正确的性能门控。

Top-3 维护(两处完全相同的手写代码)

BailClassCounts.java:41-58(RenderClassTimings 同构):

if (v > an) { c = b; cn = bn; b = a; bn = an; a = entry.getKey(); an = v; }      // 1st
else if (v > bn) { c = b; cn = bn; b = entry.getKey(); bn = v; }                  // 2nd
else if (v > cn) { c = entry.getKey(); cn = v; }                                   // 3rd

手写的三槽插入排序。⚠️ v > an 严格大于,所以并列时保留先遇到的(迭代顺序 = Reference2IntMap 的哈希序,不确定)—— Top-3 在并列时不稳定。

⚠️ 两处代码逐字重复(BailClassCounts 与 RenderClassTimings 各一份,逻辑完全相同,只有 int/long 之差)。没有抽成共用方法。 这是明确的重复代码。

⚠️ plot 判定在 Top-3 之前(BailClassCounts.java:47 if (plot) Tracy.plotInt(...))—— 即使不显示 F3,只要有 plot 就会对每个类调一次 plot。类多了会有几百次 plotInt 调用/帧。

⚠️ RenderClassTimings 的阈值判定在 plot 之前(:53 if (plot && v >= PLOT_THRESHOLD_NS))—— 低于 20 µs 的类不 plot,但仍参与 Top-3。BailClassCounts 无阈值(任何次数都 plot)—— 两类的 Tracy 噪声量不同。

GpuFrameLagMeter:GPU 帧延迟计量

45 行,public final。用 OpenGL fence sync 测量 GPU 侧延迟。

常量 值 行
RING 8 :9
P_GPU_LAG_NS Tracy.plotHandle("gpuLagNs") :14

2 个环形数组(:10-11):long[] syncs、long[] submitNs,各 8 槽。索引 head / tail(:12-13)。

onFrame 的两阶段(:18-44)

第一阶段:收割已完成的 fence(:21-35)

while (tail != head) {
    final int slot = tail % RING;
    final int status = rb.clientWaitSync(syncs[slot], 0, 0);      // timeout=0, flush=0
    if (status != GL_ALREADY_SIGNALED && status != GL_CONDITION_SATISFIED) {
        if (status == GL_WAIT_FAILED) { rb.deleteSync(syncs[slot]); tail++; continue; }
        break;                                                     // 未完成 → 停
    }
    Tracy.plotInt(P_GPU_LAG_NS, System.nanoTime() - submitNs[slot]);   // :32
    rb.deleteSync(syncs[slot]);
    tail++;
}

三个 clientWaitSync 返回值:

返回值 处理 行
GL_ALREADY_SIGNALED 收割 :24 条件假
GL_CONDITION_SATISFIED 收割 :24 条件假
GL_WAIT_FAILED 删 fence、推进 tail、continue :25-29
其它(GL_TIMEOUT_EXPIRED) break 停在本槽 :30

⚠️ 用 timeout = 0 的非阻塞查询(:23)—— 不等待。GPU 未完成时 GL_TIMEOUT_EXPIRED → break,本槽留到下一帧再试。这是正确的非阻塞设计。

⚠️ 实测值是 System.nanoTime() - submitNs[slot](:32)—— CPU 时间差,不是 GPU 时间。它测量的是「从提交 fence 到观察到 fence 已完成」的墙钟时间,包含 GPU 排队 + 执行 + CPU 发现延迟。不是纯 GPU 执行时间。

⚠️ deleteSync 在两处调用(:26、:33),都是无条件删。若 plotInt 抛异常(:32),fence 泄漏(未 delete 也未推进 tail,下一帧重复处理)。无 try/finally。

第二阶段:提交新 fence(:36-43)

if (head - tail < RING) {                                    // :36  环未满
    final long sync = rb.fenceSync(GL_SYNC_GPU_COMMANDS_COMPLETE, 0);   // :37
    if (sync != 0) { syncs[head % RING] = sync; submitNs[head % RING] = System.nanoTime(); head++; }   // :38-42
}

⚠️ fenceSync(...) == 0 表示创建失败(:38)—— 静默跳过(不 push、不计数)。无日志。 持续失败时 gpuLagNs 恒无数据且无任何提示。

⚠️ 环只有 8 槽 —— GPU 延迟超过 8 帧时新 fence 无法提交(:36 的 head - tail < RING 不满足),静默停止测量。8 帧在 20 TPS 下是 400 ms —— 对极卡场景可能不够。

⚠️ onFrame 开头 if (!Tracy.ENABLED) return;(:19)—— Tracy 关时整个环不维护。P_GPU_LAG_NS 在静态初始化时取(:14),Tracy 关时该句柄的值未定义(GLSM 侧行为,本条目不可判定)。

rb 是 BackendManager.RENDER_BACKEND(:20) —— GLSM 的后端抽象,clientWaitSync / fenceSync / deleteSync 是 GLSM 扩展的方法(标准 GL 没有 deleteSync)。

TracyUiSections:GUI 段落的 Tracy 标注

39 行,public final。极简的「当前屏幕 → Tracy section」映射。

字段 行 说明
LABELS :13 Map<Class<?>, String>(普通 HashMap,非 fastutil)
current :14 Class<?>,初值 TracyUiSections.class
section :15 long(Tracy section 句柄)

poll(:19-26)

public static void poll(GuiScreen screen) {
    if (!Tracy.ENABLED) return;                                    // :20
    final Class<?> screenClass = screen == null ? null : screen.getClass();
    if (screenClass == current) return;                             // :22
    current = screenClass;                                          // :23
    Tracy.sectionLeave(section);                                    // :24
    section = Tracy.sectionEnter(Tracy.SECTION_UI, label(screenClass));   // :25
}

4 条语义:

  1. screen == null → screenClass = null(:21)—— 代表「在世界里,没有 GUI」(见 label)。
  2. 同 class 直接返回(:22)—— 只在切到不同 GUI 类时换 section,同一类的不同实例不重置。
  3. current 初值是 TracyUiSections.class(:14) —— 一个不存在的 screen 类,确保首次 poll 一定走完整路径(不会误判为「没变」)。
  4. sectionLeave(section) 在 section 为 0(未 enter 过)时也被调(:24)—— 首次 poll 时 section 初值 0。Tracy.sectionLeave(0) 的行为本条目不可判定(GLSM 侧)。

⚠️ 先 current = screenClass 再 sectionLeave(:23-24) —— 若 sectionLeave 抛异常,current 已更新但 section 未换,下次同 class 会直接 return,section 永久错位。无 try/finally。

label(`:28-38)—— 3 个特例 + 兜底

if (screenClass == null) return "in world";                        // :29
String label = LABELS.get(screenClass);
if (label == null) {
    if (screenClass == GuiMainMenu.class) label = "main menu";     // :32
    else if (screenClass == GuiIngameMenu.class) label = "pause";   // :33
    else label = screenClass.getSimpleName();                       // :34
    LABELS.put(screenClass, label);                                 // :35
}
return label;
输入 输出
null "in world"(硬编码英文)
GuiMainMenu "main menu"
GuiIngameMenu "pause"
其它 screenClass.getSimpleName()

⚠️ getSimpleName() 对匿名类返回空字符串 —— 某些 GUI 是匿名 GuiScreen 子类时,Tracy section 标签是空串。无法定位。

⚠️ 只有 2 个 GUI 有硬编码友好名(:32-33)—— 其它全用类名。GuiIngameMenu 的 label 是 "pause" 而不是 "ingame menu" —— 与类名不符,是有意的用户友好命名还是遗留,无注释。

⚠️ 2 个特例用 == 引用比较(:32-33)—— 只匹配精确类,不匹配子类。若某个 mod 继承 GuiIngameMenu 并实例化,label 会退化成子类名。

⚠️ LABELS 是普通 HashMap 且只增不清(:13、:35)—— 每个见过的 GUI 类一条,永不清理。GUI 类数量有界(不会动态生成几百个),实际无泄漏,但理论上无界。

⚠️ screen == null 的 label "in world" 每次都新造字符串还是常量(:29)—— 源码写的是字面量,Java 字符串池会复用,无分配。

AsprofRecorder:async-profiler 录制

206 行,public final,在 debug/profiling/ 包(不是 profiling/)。

⚠️ 它依赖第三方库 one.profiler.AsyncProfiler(:4 import,:19 的 Session(Asprof::execute) 方法引用)。async-profiler 是独立的 native profiler 库,不在本仓库。

available() 的三重门控(:32-37)

private static boolean computeAvailable() {
    if (!SystemProperties.debugTooling()) return false;                                    // :33
    final String os = System.getProperty("os.name", "").toLowerCase(Locale.ROOT);           // :34
    if (!(os.contains("mac") || os.contains("linux"))) return false;                        // :35
    return AsprofRecorder.class.getResource("/one/profiler/AsyncProfiler.class") != null;   // :36
}
# 条件 行
1 SystemProperties.debugTooling() :33
2 os.name(小写)含 "mac" 或 "linux" :34-35
3 类路径上存在 /one/profiler/AsyncProfiler.class :36

⚠️ 第 3 条用 getResource 而非 Class.forName(:36)—— 只查资源存在,不触发类加载,避免了 NoClassDefFoundError。这是正确的做法。

⚠️ 第 2 条用 contains 匹配 os.name(:35)—— "mac" 会匹配 "macos"(正确)但也匹配任何含 “mac” 的字符串。用 startsWith 更严格。Windows 明确不支持("windows 10" 不含 mac/linux)—— 这是 async-profiler 的真实限制。

⚠️ available() 是 synchronized 且用 availabilityChecked / availabilityValue 两个静态字段缓存(:16-17、:24-30)—— 但两个字段都非 volatile。因为 available() 是 synchronized,在 synchronized 块内的读写有 happens-before,所以缓存本身安全。正确。

⚠️ available() 的结果永久缓存(:26 的 availabilityChecked 一旦为 true 不再计算)—— debugTooling() 在运行期变化不会反映。

start() 的四道检查(:39-~50)

# 行 检查 失败返回
1 :40 !available() "async-profiler is not available on this platform/build"
2 :41 SESSION.recordingId() != 0 "already recording to " + SESSION.outputPath()
3 :45 file.exists() "output file already exists: " + file.getPath()
4 :44 file.getAbsoluteFile() —
5 :46-47 parent.mkdirs() 返回值未检查

⚠️ parent.mkdirs() 的返回值被丢弃(:47)—— 目录创建失败无提示,后续写文件会失败。

⚠️ 输出路径的两级来源(:43):

File file = SystemProperties.PROFILE_OUTPUT.isEmpty()
    ? new File(SystemProperties.PROFILE_DIR, fileName(tag, "jfr", System.currentTimeMillis()))
    : new File(SystemProperties.PROFILE_OUTPUT);

⚠️ PROFILE_OUTPUT 非空时 PROFILE_DIR 与 fileName(...) 都被完全忽略 —— 包括 tag 参数。即「指定了输出路径则 tag 无效」。

⚠️ 扩展名硬编码 "jfr"(:43)—— JFR 格式。async-profiler 也支持其它格式(--traces、--flat),本实现只出 JFR。

⚠️ file.exists() 检查在 getAbsoluteFile() 之后(:44-45)—— 顺序正确(相对路径要先绝对化才能判存在)。

⚠️ 命令构造会打日志(:50 LOGGER.info("async-profiler: {}", command))—— 完整命令进日志,若 opts 含敏感信息会泄漏。调试工具,可接受。

方法签名 start(String tag, String opts) 且 synchronized(:39)—— 与 available() 共享同一把锁。

⚠️ Session 内部类(:19 new Session(Asprof::execute))是 static final 单例(:19),recordingId() / outputPath() 是其方法。Session 的实现本条目未读(在 :~60 之后)—— 录制状态机、文件落盘、shutdownHook(:20 shutdownHookRegistered)的逻辑不可判定。

⚠️ shutdownHookRegistered(:20)是静态非 volatile boolean —— 若注册逻辑在 synchronized 块内则安全,本条目未读注册处。

与命令的对应

/angelica profile <start|stop|status>(见 AngelicaCommand)控制本类;/angelica tracy <...> 控制另一套(Tracy)。两套录制器完全独立。

已知问题 / 风险

  1. BailClassCounts 与 RenderClassTimings 的 Top-3 维护代码逐字重复(BailClassCounts.java:41-58 与 RenderClassTimings 同构),未抽共用方法。
  2. 两者的 null 处理不一致:BailClassCounts.add 把 null 映射为 Object.class(:26),RenderClassTimings.add 无 null 处理(:30-33)—— 传 null 会 NPE 或行为异常。
  3. Top-3 在并列时不稳定(严格 > 比较 + 哈希序迭代)。
  4. Tracy plot 有两种用法并存:字符串 plot 名(BailClassCounts / RenderClassTimings 每帧)与预取数值句柄(GpuFrameLagMeter.P_GPU_LAG_NS),性能与稳定性不同。
  5. BailClassCounts 无 plot 阈值而 RenderClassTimings 有 PLOT_THRESHOLD_NS = 20_000L —— 两类的 Tracy 噪声量不同。
  6. plotNames 跨帧累积且在早退时不清,弱引用键回收后同名 plot 会重新注册(行为取决于 GLSM 的 Tracy.plotInt(String, ...),本仓库不可判定)。
  7. GpuFrameLagMeter 的 deleteSync 无 try/finally(:26、:33),plotInt 抛异常则 fence 泄漏。
  8. GpuFrameLagMeter 的 fenceSync == 0 静默跳过(:38),无日志;环仅 8 槽,GPU 延迟超 8 帧时静默停止测量。
  9. GpuFrameLagMeter 测的是「墙钟差」而非纯 GPU 时间(:32),含 CPU 发现延迟。
  10. TracyUiSections.poll 的 current = screenClass 在 sectionLeave 之前(:23-24),异常会导致 section 永久错位。
  11. TracyUiSections.poll 首次调用时 sectionLeave(0)(:15 初值 0),GLSM 侧行为未确认。
  12. TracyUiSections.label 的 2 个特例用 == 不匹配子类(:32-33);匿名类 getSimpleName() 返回空串。
  13. TracyUiSections.LABELS 是只增不清的 HashMap(:13、:35)。
  14. AsprofRecorder.start 丢弃 mkdirs() 的返回值(:47),目录创建失败无提示。
  15. AsprofRecorder 的 PROFILE_OUTPUT 非空时 tag 完全失效(:43)。
  16. AsprofRecorder 硬编码 JFR 扩展名(:43),不支持 async-profiler 的其它输出格式。
  17. AsprofRecorder 的完整命令进日志(:50)。
  18. AsprofRecorder.available() 的结果永久缓存(:26),运行期配置变化不反映。
  19. AsprofRecorder 的 Session 内部类实现本条目未读 —— 录制状态机、落盘、shutdown hook 逻辑不可判定。
  20. 包位置不一致:AsprofRecorder 在 debug/profiling/,其余 5 个在 profiling/。同一子系统的两个包。

相关条目