介绍

测量游戏启动时间,用于性能优化,需要量化这个数值。

环境

  • Unity 2022.3.62f1
  • Windows 10 22H2

启动时间总览

  1. 操作系统加载应用程序
  2. 应用程序进入 main 入口
  3. Unity 初始化完成
  4. 启动游戏

从日志获取启动时间

可以将 Android Logcat 获取到日志中的绝对时间改成相对时间,以第一条日志为基准。

使用 Python 3 来编写这个小工具。convert_to_relative_time.py

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
#!/usr/bin/env python3
"""将 Android Logcat 日志的时间戳转换为相对时间"""

import re
import sys
from datetime import datetime

TIMESTAMP_PATTERN = re.compile(r'^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3}) \d+-\d+/\S+ ')
TIMESTAMP_FORMAT = '%Y-%m-%d %H:%M:%S.%f'


def parse_timestamp(ts_str):
    """解析时间戳字符串"""
    return datetime.strptime(ts_str, TIMESTAMP_FORMAT)


def format_relative_time(delta):
    """将时间差格式化为 +HH:MM:SS.mmm 格式"""
    total_seconds = delta.total_seconds()
    hours, remainder = divmod(total_seconds, 3600)
    minutes, seconds = divmod(remainder, 60)
    milliseconds = int((seconds - int(seconds)) * 1000)
    return f"+{int(hours):02d}:{int(minutes):02d}:{int(seconds):02d}.{milliseconds:03d}"


def convert_log_file(input_file, output_file=None):
    """转换日志文件中的时间戳为相对时间"""
    if output_file is None:
        output_file = input_file.rsplit('.', 1)[0] + '-relative.log'

    first_timestamp = None
    output_lines = []

    with open(input_file, 'r', encoding='utf-8') as f:
        for line in f:
            match = TIMESTAMP_PATTERN.match(line)
            if match:
                ts_str = match.group(1)
                current_ts = parse_timestamp(ts_str)

                if first_timestamp is None:
                    first_timestamp = current_ts

                delta = current_ts - first_timestamp
                relative_str = format_relative_time(delta)
                line = relative_str + ' ' + line[match.end():]

            output_lines.append(line)

    with open(output_file, 'w', encoding='utf-8') as f:
        f.writelines(output_lines)

    print(f"转换完成: {output_file}")
    return output_file


if __name__ == '__main__':
    if len(sys.argv) < 2:
        input_file = 'android-logcat.log'
    else:
        input_file = sys.argv[1]

    output_file = sys.argv[2] if len(sys.argv) > 2 else None
    convert_log_file(input_file, output_file)

游戏内测量启动时间

使用 DeepSeek 编写:

  1. Unity 中编写一个测量启动时间的脚本,使用 Time.realtimeSinceStartupAsDouble
  2. 接口为 Mark(step) PrintSummary Reset 所有时间均显示为毫秒整数
  3. 使用单例而不是MonoBehaviour,不用转换为整数而是在显示时格式化为整数
  4. 并不是第一次调用 Mark 才开始计时,所以时间计算不需要减去第一步的时间
  5. 同时输出每一步的占比,耗时与占比需要右对齐,步骤名称列的长度需要是最长步骤名称+4
  6. 同时增加一列相对上一步的耗时,最后增加一行总用时
  7. 占比与增量列交换一下,占比改为相对上一步的占比
  8. 占比改为这一步与上一步之间的用时/总用时

结果:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
using System;
using System.Collections.Generic;
using System.Linq;
using UnityEngine;

public class StartupTimer
{
    private static readonly StartupTimer instance;
    static StartupTimer() => instance = new StartupTimer();
    private StartupTimer() => steps = new List<Step>();

    public static StartupTimer Instance => instance;

    private struct Step
    {
        public string name;
        public double time; // 秒(从启动开始)
    }
    private List<Step> steps;

    public void Mark(string step) => steps.Add(new Step { name = step, time = Time.realtimeSinceStartupAsDouble });

    public void PrintSummary()
    {
        if (steps.Count == 0)
        {
            Debug.Log("没有记录任何步骤,无法生成总结。");
            return;
        }

        double totalSeconds = steps[^1].time; // 最后一个步骤的绝对时间即为总耗时
        long totalMs = (long)Math.Round(totalSeconds * 1000.0, MidpointRounding.AwayFromZero);

        Debug.Log($"=== 启动时间总结 ===");
        Debug.Log($"总启动耗时: {totalMs} ms\n");

        // 计算最大名称长度(考虑步骤名、表头“步骤名称”和汇总行“总用时”)
        int maxNameLength = steps.Max(s => s.name.Length);
        int nameWidth = Math.Max(maxNameLength, "步骤名称".Length);
        nameWidth = Math.Max(nameWidth, "总用时".Length) + 4;

        // 准备数据列表
        var rows = new List<(string name, long timeMs, long deltaMs, string ratioStr)>();
        long prevTimeMs = 0;
        for (int i = 0; i < steps.Count; i++)
        {
            long timeMs = (long)Math.Round(steps[i].time * 1000.0, MidpointRounding.AwayFromZero);
            long deltaMs = i == 0 ? 0 : timeMs - prevTimeMs;

            // 占比 = 增量 / 总耗时 * 100%
            double ratio = totalMs > 0 ? (deltaMs / (double)totalMs) * 100.0 : 0;
            string ratioStr = ratio.ToString("F1") + "%";

            rows.Add((steps[i].name, timeMs, deltaMs, ratioStr));
            prevTimeMs = timeMs;
        }

        // 表头
        string header = $"{"步骤名称",-nameWidth} {"耗时(ms)",8} {"增量(ms)",8} {"占比",6}";
        Debug.Log(header);

        // 输出每一行
        foreach (var row in rows)
        {
            string line = $"{row.name,-nameWidth} {row.timeMs,8} {row.deltaMs,8} {row.ratioStr,6}";
            Debug.Log(line);
        }

        // 汇总行(总用时)
        Debug.Log(new string('-', header.Length)); // 分隔线
        string totalLine = $"{"总用时",-nameWidth} {totalMs,8} {"",8} {"",6}";
        Debug.Log(totalLine);

        // 步骤间耗时明细(可选)
        if (steps.Count > 1)
        {
            Debug.Log("\n--- 步骤间耗时明细 ---");
            for (int i = 1; i < steps.Count; i++)
            {
                double elapsedSeconds = steps[i].time - steps[i - 1].time;
                Debug.Log($"{steps[i - 1].name} → {steps[i].name}: {FormatMilliseconds(elapsedSeconds)} ms");
            }
        }
    }

    public void Reset() => steps.Clear();

    private string FormatMilliseconds(double seconds)
    {
        long ms = (long)Math.Round(seconds * 1000.0, MidpointRounding.AwayFromZero);
        return ms.ToString();
    }

    // 静态便捷方法
    public static void Mark(string step) => Instance.Mark(step);
    public static void PrintSummary() => Instance.PrintSummary();
    public static void Reset() => Instance.Reset();
}
1
2
3
4
5
6
7
8
9
=== 启动时间总结 ===
总启动耗时: 300 ms

步骤名称                耗时(ms) 增量(ms)    占比
Awake                        50        0    0.0%
Start                       150      100   33.3%
ResourcesLoaded             300      150   50.0%
-----------------------------------------------
总用时                      300