时间分析

在本章中,我们将改进生命游戏实现的性能。我们将使用时间分析来指导我们的工作。

在继续之前,请熟悉用于时间分析 Rust 和 WebAssembly 代码的可用工具

使用 window.performance.now 函数创建每秒帧数计时器

此 FPS 计时器在我们调查生命游戏的渲染速度时将非常有用。

我们首先在 wasm-game-of-life/www/index.js 中添加一个 fps 对象

const fps = new class {
  constructor() {
    this.fps = document.getElementById("fps");
    this.frames = [];
    this.lastFrameTimeStamp = performance.now();
  }

  render() {
    // Convert the delta time since the last frame render into a measure
    // of frames per second.
    const now = performance.now();
    const delta = now - this.lastFrameTimeStamp;
    this.lastFrameTimeStamp = now;
    const fps = 1 / delta * 1000;

    // Save only the latest 100 timings.
    this.frames.push(fps);
    if (this.frames.length > 100) {
      this.frames.shift();
    }

    // Find the max, min, and mean of our 100 latest timings.
    let min = Infinity;
    let max = -Infinity;
    let sum = 0;
    for (let i = 0; i < this.frames.length; i++) {
      sum += this.frames[i];
      min = Math.min(this.frames[i], min);
      max = Math.max(this.frames[i], max);
    }
    let mean = sum / this.frames.length;

    // Render the statistics.
    this.fps.textContent = `
Frames per Second:
         latest = ${Math.round(fps)}
avg of last 100 = ${Math.round(mean)}
min of last 100 = ${Math.round(min)}
max of last 100 = ${Math.round(max)}
`.trim();
  }
};

接下来,我们在 renderLoop 的每次迭代中调用 fpsrender 函数

const renderLoop = () => {
    fps.render(); //new

    universe.tick();
    drawGrid();
    drawCells();

    animationId = requestAnimationFrame(renderLoop);
};

最后,不要忘记将 fps 元素添加到 wasm-game-of-life/www/index.html 中,位于 <canvas> 的正上方

<div id="fps"></div>

并添加 CSS 以使其格式美观

#fps {
  white-space: pre;
  font-family: monospace;
}

瞧!刷新http://localhost:8080,现在我们有了 FPS 计数器!

使用 console.timeconsole.timeEnd 对每个 Universe::tick 进行计时

为了衡量每次调用 Universe::tick 所花费的时间,我们可以使用 console.timeconsole.timeEnd,通过 web-sys 板条箱。

首先,将 web-sys 作为依赖项添加到 wasm-game-of-life/Cargo.toml

[dependencies.web-sys]
version = "0.3"
features = [
  "console",
]

由于每个 console.time 调用都应该有一个对应的 console.timeEnd 调用,因此将它们都封装在一个RAII 类型中很方便


# #![allow(unused_variables)]
#fn main() {
extern crate web_sys;
use web_sys::console;

pub struct Timer<'a> {
    name: &'a str,
}

impl<'a> Timer<'a> {
    pub fn new(name: &'a str) -> Timer<'a> {
        console::time_with_label(name);
        Timer { name }
    }
}

impl<'a> Drop for Timer<'a> {
    fn drop(&mut self) {
        console::time_end_with_label(self.name);
    }
}
#}

然后,我们可以通过在方法顶部添加此代码段来计时每次 Universe::tick 所花费的时间


# #![allow(unused_variables)]
#fn main() {
let _timer = Timer::new("Universe::tick");
#}

每次调用 Universe::tick 所花费的时间现在已记录在控制台中

Screenshot of console.time logs

此外,console.timeconsole.timeEnd 对将在浏览器的分析器中的“时间线”或“瀑布”视图中显示

Screenshot of console.time logs

扩展我们的生命游戏宇宙

⚠️ 本节使用 Firefox 中的示例屏幕截图。虽然所有现代浏览器都具有类似的工具,但在使用不同的开发者工具时可能存在细微差别。您提取的配置文件信息本质上是相同的,但在您看到的视图和不同工具的命名方面,您的体验可能会有所不同。

如果我们使生命游戏宇宙更大,会发生什么?将 64x64 宇宙替换为 128x128 宇宙(通过修改 wasm-game-of-life/src/lib.rs 中的 Universe::new),在我的机器上,FPS 从流畅的 60 帧下降到卡顿的 40 帧左右。

如果我们记录一个配置文件并查看瀑布视图,我们会发现每个动画帧都花费了超过 20 毫秒。回想一下,每秒 60 帧为整个渲染帧的过程留下了 16 毫秒。这不仅包括我们的 JavaScript 和 WebAssembly,还包括浏览器正在执行的所有其他操作,例如绘制。

Screenshot of a waterfall view of rendering a frame

如果我们查看单个动画帧中发生的事情,我们会发现 CanvasRenderingContext2D.fillStyle 设置器非常昂贵!

⚠️ 在 Firefox 中,如果您看到一条只显示“DOM”而不是上面提到的 CanvasRenderingContext2D.fillStyle 的行,您可能需要在性能开发者工具选项中启用“显示 Gecko 平台数据”选项

Turning on Show Gecko Platform Data

Screenshot of a flamegraph view of rendering a frame

我们可以通过查看调用树对多个帧的聚合来确认这不是异常

Screenshot of a flamegraph view of rendering a frame

我们近 40% 的时间都花在这个设置器上!

⚡ 我们可能期望 tick 方法中的某些内容是性能瓶颈,但事实并非如此。始终让分析指导您的重点,因为时间可能花在您意想不到的地方。

wasm-game-of-life/www/index.js 中的 drawCells 函数中,fillStyle 属性在每个动画帧上为宇宙中的每个单元格设置一次

for (let row = 0; row < height; row++) {
  for (let col = 0; col < width; col++) {
    const idx = getIndex(row, col);

    ctx.fillStyle = cells[idx] === DEAD
      ? DEAD_COLOR
      : ALIVE_COLOR;

    ctx.fillRect(
      col * (CELL_SIZE + 1) + 1,
      row * (CELL_SIZE + 1) + 1,
      CELL_SIZE,
      CELL_SIZE
    );
  }
}

现在我们已经发现设置 fillStyle 非常昂贵,我们该怎么做才能避免频繁设置它?我们需要根据单元格是存活还是死亡来更改 fillStyle。如果我们设置 fillStyle = ALIVE_COLOR,然后在一次遍历中绘制所有存活的单元格,然后设置 fillStyle = DEAD_COLOR,并在另一次遍历中绘制所有死亡的单元格,那么我们只需要设置 fillStyle 两次,而不是为每个单元格设置一次。

// Alive cells.
ctx.fillStyle = ALIVE_COLOR;
for (let row = 0; row < height; row++) {
  for (let col = 0; col < width; col++) {
    const idx = getIndex(row, col);
    if (cells[idx] !== Cell.Alive) {
      continue;
    }

    ctx.fillRect(
      col * (CELL_SIZE + 1) + 1,
      row * (CELL_SIZE + 1) + 1,
      CELL_SIZE,
      CELL_SIZE
    );
  }
}

// Dead cells.
ctx.fillStyle = DEAD_COLOR;
for (let row = 0; row < height; row++) {
  for (let col = 0; col < width; col++) {
    const idx = getIndex(row, col);
    if (cells[idx] !== Cell.Dead) {
      continue;
    }

    ctx.fillRect(
      col * (CELL_SIZE + 1) + 1,
      row * (CELL_SIZE + 1) + 1,
      CELL_SIZE,
      CELL_SIZE
    );
  }
}

保存这些更改并刷新http://localhost:8080/ 后,渲染又恢复到流畅的每秒 60 帧。

如果我们再进行一次分析,我们会发现现在每个动画帧只花费了大约 10 毫秒。

Screenshot of a waterfall view of rendering a frame after the drawCells changes

分解单个帧,我们会发现 fillStyle 成本消失了,我们帧的大部分时间都花在了 fillRect 中,绘制每个单元格的矩形。

Screenshot of a flamegraph view of rendering a frame after the drawCells changes

让时间飞逝

有些人不喜欢等待,他们更希望宇宙每动画帧执行 9 次 tick,而不是 1 次。我们可以很容易地修改 wasm-game-of-life/www/index.js 中的 renderLoop 函数来实现这一点

for (let i = 0; i < 9; i++) {
  universe.tick();
}

在我的机器上,这使我们的帧速率降至每秒 35 帧。不好。我们想要那种流畅的 60 帧!

现在我们知道时间花在了 Universe::tick 中,所以让我们添加一些 Timer 来将 console.timeconsole.timeEnd 调用封装在它的各个部分中,看看会发生什么。我的假设是,在每次 tick 时分配一个新的单元格向量并释放旧向量是昂贵的,并且占用了我们时间预算的很大一部分。


# #![allow(unused_variables)]
#fn main() {
pub fn tick(&mut self) {
    let _timer = Timer::new("Universe::tick");

    let mut next = {
        let _timer = Timer::new("allocate next cells");
        self.cells.clone()
    };

    {
        let _timer = Timer::new("new generation");
        for row in 0..self.height {
            for col in 0..self.width {
                let idx = self.get_index(row, col);
                let cell = self.cells[idx];
                let live_neighbors = self.live_neighbor_count(row, col);

                let next_cell = match (cell, live_neighbors) {
                    // Rule 1: Any live cell with fewer than two live neighbours
                    // dies, as if caused by underpopulation.
                    (Cell::Alive, x) if x < 2 => Cell::Dead,
                    // Rule 2: Any live cell with two or three live neighbours
                    // lives on to the next generation.
                    (Cell::Alive, 2) | (Cell::Alive, 3) => Cell::Alive,
                    // Rule 3: Any live cell with more than three live
                    // neighbours dies, as if by overpopulation.
                    (Cell::Alive, x) if x > 3 => Cell::Dead,
                    // Rule 4: Any dead cell with exactly three live neighbours
                    // becomes a live cell, as if by reproduction.
                    (Cell::Dead, 3) => Cell::Alive,
                    // All other cells remain in the same state.
                    (otherwise, _) => otherwise,
                };

                next[idx] = next_cell;
            }
        }
    }

    let _timer = Timer::new("free old cells");
    self.cells = next;
}
#}

查看计时结果,很明显我的假设是错误的:绝大多数时间都花在了实际计算下一代单元格上。令人惊讶的是,在每次 tick 时分配和释放向量似乎成本微不足道。另一个提醒,始终让分析指导我们的工作!

Screenshot of a Universe::tick timer results

下一节需要 nightly 编译器。这是因为我们将要使用的test 特性门。我们将安装的另一个工具是cargo benchcmp。它是一个用于比较 cargo bench 生成的微基准测试的小型实用程序。

让我们编写一个本地代码 #[bench],它执行与我们的 WebAssembly 相同的操作,但我们可以使用更成熟的分析工具。这是新的 wasm-game-of-life/benches/bench.rs


# #![allow(unused_variables)]
#![feature(test)]

#fn main() {
extern crate test;
extern crate wasm_game_of_life;

#[bench]
fn universe_ticks(b: &mut test::Bencher) {
    let mut universe = wasm_game_of_life::Universe::new();

    b.iter(|| {
        universe.tick();
    });
}
#}

我们还必须注释掉所有 #[wasm_bindgen] 注释以及 Cargo.toml 中的 "cdylib" 部分,否则构建本地代码将失败并出现链接错误。

有了这些,我们可以运行 cargo bench | tee before.txt 来编译并运行我们的基准测试!| tee before.txt 部分将获取 cargo bench 的输出并将其放入名为 before.txt 的文件中。

$ cargo bench | tee before.txt
    Finished release [optimized + debuginfo] target(s) in 0.0 secs
     Running target/release/deps/wasm_game_of_life-91574dfbe2b5a124

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out

     Running target/release/deps/bench-8474091a05cfa2d9

running 1 test
test universe_ticks ... bench:     664,421 ns/iter (+/- 51,926)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured; 0 filtered out

这也告诉我们二进制文件的位置,我们可以再次运行基准测试,但这次是在我们的操作系统分析器下运行。在我的情况下,我运行的是 Linux,所以perf 是我将使用的分析器

$ perf record -g target/release/deps/bench-8474091a05cfa2d9 --bench
running 1 test
test universe_ticks ... bench:     635,061 ns/iter (+/- 38,764)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured; 0 filtered out

[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.178 MB perf.data (2349 samples) ]

使用 perf report 加载配置文件显示我们所有时间都花在了 Universe::tick 中,正如预期的那样

Screenshot of perf report

如果您按下 aperf 将注释函数中花费时间的指令

Screenshot of perf's instruction annotation

这告诉我们 26.67% 的时间花在了对相邻单元格的值求和上,23.41% 的时间花在了获取相邻单元格的列索引上,另外 15.42% 的时间花在了获取相邻单元格的行索引上。在这三个最昂贵的指令中,第二和第三都是昂贵的 div 指令。这些 div 实现 Universe::live_neighbor_count 中的模索引逻辑。

回想一下 wasm-game-of-life/src/lib.rs 中的 live_neighbor_count 定义


# #![allow(unused_variables)]
#fn main() {
fn live_neighbor_count(&self, row: u32, column: u32) -> u8 {
    let mut count = 0;
    for delta_row in [self.height - 1, 0, 1].iter().cloned() {
        for delta_col in [self.width - 1, 0, 1].iter().cloned() {
            if delta_row == 0 && delta_col == 0 {
                continue;
            }

            let neighbor_row = (row + delta_row) % self.height;
            let neighbor_col = (column + delta_col) % self.width;
            let idx = self.get_index(neighbor_row, neighbor_col);
            count += self.cells[idx] as u8;
        }
    }
    count
}
#}

我们使用模运算的原因是为了避免使用 if 分支来处理第一行或最后一行的边缘情况,从而使代码变得混乱。但即使对于最常见的情况,当 rowcolumn 都不在宇宙的边缘并且不需要模运算包装处理时,我们也需要支付 div 指令的成本。相反,如果我们使用 if 来处理边缘情况并展开此循环,那么分支应该会被 CPU 的分支预测器很好地预测。

让我们像这样重写 live_neighbor_count


# #![allow(unused_variables)]
#fn main() {
fn live_neighbor_count(&self, row: u32, column: u32) -> u8 {
    let mut count = 0;

    let north = if row == 0 {
        self.height - 1
    } else {
        row - 1
    };

    let south = if row == self.height - 1 {
        0
    } else {
        row + 1
    };

    let west = if column == 0 {
        self.width - 1
    } else {
        column - 1
    };

    let east = if column == self.width - 1 {
        0
    } else {
        column + 1
    };

    let nw = self.get_index(north, west);
    count += self.cells[nw] as u8;

    let n = self.get_index(north, column);
    count += self.cells[n] as u8;

    let ne = self.get_index(north, east);
    count += self.cells[ne] as u8;

    let w = self.get_index(row, west);
    count += self.cells[w] as u8;

    let e = self.get_index(row, east);
    count += self.cells[e] as u8;

    let sw = self.get_index(south, west);
    count += self.cells[sw] as u8;

    let s = self.get_index(south, column);
    count += self.cells[s] as u8;

    let se = self.get_index(south, east);
    count += self.cells[se] as u8;

    count
}
#}

现在让我们再次运行基准测试!这次将输出保存到 after.txt 中。

$ cargo bench | tee after.txt
   Compiling wasm_game_of_life v0.1.0 (file:///home/fitzgen/wasm_game_of_life)
    Finished release [optimized + debuginfo] target(s) in 0.82 secs
     Running target/release/deps/wasm_game_of_life-91574dfbe2b5a124

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out

     Running target/release/deps/bench-8474091a05cfa2d9

running 1 test
test universe_ticks ... bench:      87,258 ns/iter (+/- 14,632)

test result: ok. 0 passed; 0 failed; 0 ignored; 1 measured; 0 filtered out

看起来好多了!我们可以使用 benchcmp 工具和我们之前创建的两个文本文件来查看它到底好多少

$ cargo benchcmp before.txt after.txt
 name            before.txt ns/iter  after.txt ns/iter  diff ns/iter   diff %  speedup
 universe_ticks  664,421             87,258                 -577,163  -86.87%   x 7.61

哇!速度提高了 7.61 倍!

WebAssembly 故意与常见的硬件架构紧密映射,但我们需要确保这种本地代码速度提升也转化为 WebAssembly 速度提升。

让我们使用 wasm-pack build 重新构建 .wasm 并刷新http://localhost:8080/。在我的机器上,页面再次以每秒 60 帧的速度运行,使用浏览器的分析器记录另一个配置文件显示每个动画帧大约花费了 10 毫秒。

成功!

Screenshot of a waterfall view of rendering a frame after replacing modulos with branches

练习

  • 在这一点上,加速 Universe::tick 的下一个最容易实现的目标是消除分配和释放。实现单元格的双缓冲,其中 Universe 维持两个向量,从不释放其中任何一个,并且从不在 tick 中分配新的缓冲区。

  • 将“实现生命”一章中介绍的基于增量的替代设计从 Rust 代码移植到 JavaScript,使其返回一个包含状态发生变化的单元格列表。这是否会使渲染到<canvas>更快?你能否在每次计时器触发时,不分配新的增量列表的情况下实现这种设计?

  • 正如我们的性能分析所显示的那样,2D <canvas> 渲染并不快。用 WebGL 渲染器替换 2D 画布渲染器。WebGL 版本的速度提高了多少?在 WebGL 渲染成为瓶颈之前,你能将宇宙的大小扩展到多大?