在上一篇文章中，我们介绍了 sBPF 虚拟机架构、寄存器约定以及指令集。现在，我们将使用 agave-ledger-tool（Solana 工具链附带的 CLI 工具）来分析实际的字节码执行，生成执行追踪并手动计算程序消耗的计算单元。
尽管手动追踪操作码具有挑战性，但我们可以自动生成每个寄存器在每次操作码执行时如何更新的可视化追踪记录。这让我们能够准确看到运行了哪些指令以及计算单元是如何累加的。
分析一个简单的程序
让我们分析一个简单 Anchor 程序的字节码，看看每一部分是如何变成 SBF 指令以及它们如何使用寄存器的。这也将使我们能够手动计算出计算单元的成本。
项目设置
首先，初始化一个新项目：
anchor init compute_unit
cd compute_unit
将 programs/compute_unit/src/lib.rs 中的代码替换为以下最简程序。我们使用一个空的 initialize 函数，以便我们可以专注于测量基准计算成本，而无需包含任何业务逻辑：
use anchor_lang::prelude::*;
declare_id!("CR33kP6d39mBZv1ryjufVXoRm6djnWW8uKoQXwU5kgDV");
#[program]
pub mod compute_unit {
use super::*;
pub fn initialize(ctx: Context<Initialize>) -> Result<()> {
Ok(())
}
}
#[derive(Accounts)]
pub struct Initialize {}
我们将在本地验证者（local validator）上运行 initialize 函数（我们将在后续步骤中看到如何操作），并使用 solana logs 查看它所消耗的计算单元。然后我们将反汇编该程序并生成执行追踪，以观察运行了哪些 SBF 操作码。通过这种方式，我们可以手动计算出每条指令是如何累加成总计算单元成本的。
构建并启动本地验证者：
anchor keys sync
anchor build
然后在一个新的终端中：
solana-test-validator
这会启动一个本地验证者并创建一个 test-ledger/ 目录——agave-ledger-tool 在生成程序追踪记录时会使用该目录来加载账本状态。
在另一个终端中运行 solana logs，然后在单独的终端中运行 anchor test --skip-local-validator，以准确查看 initialize 函数使用了多少个计算单元。如果我们这样做，会得到 272 个计算单元。我们稍后会回到这个问题。
反汇编程序
Solana 字节码分析的第一步是将可执行的 Solana 程序二进制文件（通常存储在 target/deploy/<project_name>.so 文件中）转换为我们能更好理解的字节码助记符。助记符只是二进制/十六进制操作码的人类可读表示形式，例如在 EVM 中，0x60 = PUSH1，0x52 = MSTORE 等等。
我们需要在项目根目录下有一个包含 genesis.bin 文件的 test-ledger 文件夹。我们之前运行的 solana-test-validator 会自动生成这些文件。agave-ledger-tool（Solana 工具链的一部分）在反汇编程序时使用此文件来加载账本状态。
现在我们可以使用以下命令反汇编我们的程序：
agave-ledger-tool program --ledger test-ledger disassemble target/deploy/compute_unit.so --output json > output.txt
这会将汇编助记符导出到 output.txt 中。你会看到类似下面的内容：
function_0:
mov64 r0, r2
and64 r0, 1
jeq r0, 0, lbb_32
mov64 r0, 0
jslt r5, 0, lbb_34
stxdw [r10-0x8], r3
jeq r5, 0, lbb_41
...
...
像 function_0: 这样的标签是字节码中的跳转目标，其他指令可以使用 call 指令跳转到这里。Rust 函数会被编译成一系列指令，编译器生成这些标签来标记函数入口或内部代码块。因此，当你看到类似 call function_11561 的内容时，表示执行跳转到字节码中的该偏移量，并运行那里的指令。
这是我们的 Solana 程序的助记符。然而，我们光凭这个做不了什么，它非常庞大且手动分析极具挑战性。
生成执行追踪
要生成执行追踪，我们需要告诉 agave-ledger-tool 要调用程序中的哪个函数。我们通过创建一个 instructions.json 文件来实现这一点，稍后你将看到我们会把这个文件传递给该工具。
现在，在我们的项目根目录中创建一个 instructions.json 文件，并粘贴以下代码：
{
"accounts": [],
"program_id": <program_id>,
"instruction_data": [175, 175, 109, 31, 13, 152, 155, 237]
}
上述参数表示：accounts 列表（此处为空，因为我们的 initialize 函数不需要任何账户），要调用的 program_id（将 <program_id> 替换为你的真实程序 ID），以及指令数据。
instruction_data 字段仅包含 initialize 函数的 8 字节鉴别器（因为我们的函数不接受任何参数，所以没有附加参数）。Anchor 通过提取 sha256("<namespace>:<function_name>") 的前 8 个字节来 生成这些鉴别器。在我们的例子中，即 sha256("global:initialize")。命名空间是 global 的，因为我们的程序包含在代码库的最外层作用域中。
现在让我们生成执行追踪：
agave-ledger-tool program run target/deploy/compute_unit.so --limit 200000 --trace trace.txt --ledger test-ledger --input instructions.json
这将使用我们的指令数据（initialize 函数）运行程序，并将执行追踪输出到 trace.txt.0。--limit 标志设置了计算单元的限制。它不是必需的，但对测试很有用。
注意：如果你遇到提示 Err(JitNotCompiled) 的错误（例如，在使用 ARM MacBook 时），请在命令中添加 --mode interpreter，以使用解释器模式代替默认的 JIT 编译模式。
阅读执行追踪
trace.txt.0 文件看起来像这样。为了清晰起见，我们对各个部分进行了标注，并且只展示了前 6 条指令：
这为我们分析和理解程序及其消耗的计算单元提供了足够的信息。
让我们来看看每一列显示的内容：
- Execution count 列（第一列）：执行计数器。
- 带 r 前缀的列（第 2-12 列）：显示其上方的指令执行后，Solana 虚拟机的 11 个寄存器（r0 - r10）各自的状态/值。
- Program counter 列（第 13 列）：程序计数器（PC），或给定指令/操作码在程序二进制文件中的索引。
- Instruction 列（第 14 列）：接下来要执行的指令/操作码及其操作数。
现在让我们过一遍追踪输出的前 6 条指令，以熟悉执行期间寄存器中的值是如何变化的。让我们将图像分割开，以使寄存器的值更加清晰可见：
- 第一条指令（
mov64 r2, r1）将寄存器 1 中的 64 位值复制到寄存器 2 中。在下一行中，r1 和 r2 都持有相同的值。 - 第二条指令（
mov64 r1, r10）将寄存器 10 中的值复制到寄存器 1 中。 - 第三条指令（
add64 r1, -72）从 r1 的值中减去 72，并将结果存回 r1 中。 - 第四条指令（
call function_11561）跳转到另一个函数；在该函数返回后，执行将在调用之后恢复。 - 第五条指令（
mov64 r8, r1）将寄存器 1 的值复制到寄存器 8（在被调用的函数内部，如 PC 的变化所示。因为这次函数调用，PC 从 3443 变为了 11561）。 - 第六条指令（
stxdw [r10-0x30], r2）将寄存器 2 中的 64 位数据存储到 r10 中的地址减去内存偏移量 0x30 后的内存地址处。考虑到在第 6 次执行时，寄存器 2 持有的值为0x0000000400000000，而寄存器 10 持有的值为0x0000000200003000，这意味着该指令会将 64 位值0x0000000400000000存储在内存地址0x0000000200002FF0（即r10 - 0x30，其中 r10 基于其存储的地址减去指定的偏移量计算出了一个新地址）。
计算计算单元
既然我们已经看到了执行追踪是如何显示的，以及每一列代表什么，下一个问题是，计算单元在这里是如何发挥作用的？
每条 sBPF 指令消耗 1 个计算单元。然而，syscall 指令会产生额外的费用，且随类型而异。总计算单元 = 指令数量 + syscall 指令费用。
让我们在实际操作中看看。在同一个程序中，如果向下滚动到执行追踪的末尾（在 trace.txt.0 文件中），我们可以看到最后一个 execution count/索引为 171，这意味着该程序执行了 172 条指令（索引 0-171）。同一个调用的验证者日志（如下所示）报告消耗了 272 个计算单元。
差异（100）来自于打印指令名称（“Program log: Instruction: Initialize”）的日志记录 syscall。
那个 syscall 是 sol_log_，它收取一个 syscall_base_cost（即 100 个计算单元）（截至撰写本文时）。现在，如果我们将其加到 172 的指令计数中，我们得到 172 + 100 = 272 的总计算单元。
我们可以通过在 trace.txt.0 文件中搜索 syscall 操作码来验证这一点。它出现了一次 —— 在 execution count 157 处的 syscall sol_log_。
为什么 PC 不从 0 开始？
与执行从第一个 PC 开始的 EVM 字节码不同，在 Solana 字节码中，执行从 entrypoint 跳转标签所在的任何位置开始（我们将在下一篇教程中讨论这个问题，但你可以在我们之前生成的 output.txt 文件中搜索 <entrypoint> 来查看它）。在调用你的程序时，Solana 运行时会直接跳转到此标签。如果你查看上面显示我们执行追踪的图像，你会看到第一条指令 mov64 r2, r1 位于非零 PC 处（此追踪记录中为 3440），而不是 PC 0。这意味着从 PC 0 到 PC 3439 的字节码存在于编译后的程序中，但除非被明确跳转，否则不会执行。
那个跳过的部分里有什么？它包含了其他带标签的代码块（如辅助函数、错误处理例程或 Anchor 生成的代码），这些代码块只有在从主执行路径跳转时才会执行。如果你在 output.txt（完整的字节码转储）中搜索 <entrypoint> 标签，你会看到它定义在偏移量 3440 处，而像 function_0、function_11561 等其他标签则定义在其之前的早期偏移量处。运行时从 <entrypoint> 开始执行，然后根据需要跳转到这些其他标签（你可以在上面的追踪中看到 call function_11561）。同样，我们将在下一篇教程中讨论 entrypoint。
如果程序在代码中没有任何日志输出，那么日志是从哪里来的？
我们已经看到，我们的程序从指令执行和 syscall 成本两方面消耗计算单元。为了更好地理解这一点，我们首先要找出追踪中的日志是从哪里来的，然后添加显式日志记录，看看不同的 syscall 是如何影响总计算单元计数的。这将让我们能够用具体数字验证我们的公式（指令数 + syscall 成本 = 总计算单元）。
程序试图通过 sol_log_ syscall 输出什么日志？为了找出答案，让我们在保持 Solana 日志运行的情况下针对测试验证者运行一个测试。（如果你已经运行了该服务，可以跳过这一步）：
# start up a test validator
solana-test-validator
# get solana logs running in a separate terminal
solana logs
在一个单独的终端中运行 anchor test --skip-local-validator。我们应该能在 Solana logs 终端中看到输出了一些内容，而最后一条日志给了我们答案。来自程序的日志可以通过在该交易的 Log Messages: 下带有 Program log: 的前缀来识别。
在上面的例子中，严格涉及调用 initialize 的交易的输出如下：
观察发现，它具有三个属性：
- Signature：签名者的签名
- Status：交易是否成功
- Log Messages：该特定调用的日志
我们感兴趣的是上述日志输出的 Log Messages 部分。它也有一些属性：
- 第一行告诉我们被调用的程序 ID 及其调用深度（从 1 开始）。
- 倒数第二行告诉我们程序消耗了多少计算单元，以及为该交易设置的最大计算单元限制。
- 最后一行告诉我们调用是否成功。
- 中间的所有内容（在当前情况下，只有一行）是实际的程序日志。这些日志很容易识别，因为它们总是以
Program xxx:开头，其中xxx可能会根据用于输出日志的 syscall 而变化。
在我们上面的例子中，有一条日志，它只是告诉我们程序中指令的名称，或者换句话说，也就是我们调用的函数名称。该日志由 Anchor 自动插入。我们的程序代码没有显式调用任何日志函数，但 Anchor 的宏展开添加了一个 sol_log_ syscall，在函数运行时打印 “Instruction: Initialize”。如果你在没有 Anchor 的情况下用原生 Rust 编写相同的程序，除非你显式添加，否则你不会看到此日志。
鉴于 Anchor 会自动记录每次函数调用的指令名称，因此每次 Anchor 程序调用都将至少包含一行日志（即指令名称）。
添加显式日志记录以查看 syscall 成本
现在让我们添加自己的日志调用，以查看多个 syscall 如何影响计数。将 solana-program = "1.18.17" 添加到 programs/compute_unit/Cargo.toml 作为依赖项，并将我们的程序代码更新为：
use anchor_lang::prelude::*;
use solana_program::log::sol_log_compute_units;
declare_id!("CR33kP6d39mBZv1ryjufVXoRm6djnWW8uKoQXwU5kgDV"); // Run anchor sync to update your program ID
#[program]
pub mod compute_unit {
use super::*;
pub fn initialize(ctx: Context<Initialize>) -> Result<()> {
sol_log_compute_units();
Ok(())
}
}
#[derive(Accounts)]
pub struct Initialize {}
运行测试，我们可以看到针对我们交易的 solana log 输出如下：
我们可以看到现在有两个 Program xxx: 日志。第一个是我们常见的 Instruction: Initialize 日志，第二个显示了在调用 sol_log_compute_units() 时剩余了多少计算单元。
从日志中，我们还看到当执行 sol_log_compute_units() 时剩余 199,641 个计算单元。当我们用计算单元限制（200,000）减去此值时，得到在到达那一点时消耗了 359 个计算单元。我们将对其进行分解，并验证这 359 个单元去哪了。
注意：在记录剩余计算单元时，格式总是 Program consumption: X units remaining。
拆解计算单元计算过程
在将 sol_log_compute_units() 添加到我们的程序并生成新的追踪之后（你可以像我们之前那样操作）。从 trace.txt.0 中可以看出：
- Execution count 为 0-172（共执行了 173 条指令，比我们之前没有日志记录的追踪中的 172 条有所增加）
- Execution count 157 处有
syscall sol_log_（此处记录了 “Instruction: Initialize”） - Execution count 158 处有
syscall sol_log_compute_units_（此处记录了剩余的计算单元）
你可以在 trace.txt.0 中自行搜索这些内容（sol_log_ 和 sol_log_compute_units_），以确认它们在追踪输出中出现的位置。
现在有趣的地方来了。每个 syscall 都有运行时费用。Syscall 必须有这些费用，以防止程序永远运行下去（如果 syscall 是免费的，程序可能会造成无限循环的 syscall，从而堵塞网络）：
sol_log_消耗 100 CU（由syscall_base_cost在此处 定义）sol_log_compute_units_也消耗 100 CU（由get_remaining_compute_units_cost在此处 定义）
因此消耗的总计算单元为：
Instructions executed: 173
Runtime syscall charges: 200 (100 + 100)
---
Total compute units: 373
这与验证者日志中显示的结果相符：“consumed 373 of 200000 compute units”
验证日志记录点处的计算单元
请记住，在执行 sol_log_compute_units() 时，日志显示了 “199641 units remaining”。这意味着到那时为止已消耗了 359 个计算单元（200,000 - 199,641 = 359）。
让我们验证一下这是否合理。查看追踪记录，sol_log_compute_units_ 出现在 execution count 158 处，这意味着：
- 到目前为止执行了 159 条指令（execution count 0-158）
- 第一个
sol_log_syscall 产生了 100 CU 费用（在 execution count 157 处） sol_log_compute_units_自身产生 100 CU 费用（在它执行时应用）- 总计：159 + 100 + 100 = 359 CU
完美！这确认了我们的追踪可以确切地向我们显示每次 syscall 发生的时间，以及计算单元在整个执行过程中是如何累加的。
在追踪中观察参数处理
让我们将当前程序中的 solana_program::log::sol_log_compute_units(); 替换为 solana_program::log::sol_log_64(1, 2, 3, 4, 5);。在这里，我们改用 syscall 来记录五个 64 位数字。
现在运行测试，我们可以看到相关的日志为：
确实，我们有 2 条日志。我们常见的 Instruction 名称日志，以及如预期输出的那 5 个数字日志。
如果运行我们的执行追踪命令并在 trace.txt.0 中搜索 syscall，我们会找到两个条目。第二个是对 sol_log_64_ 的 syscall，这与我们刚才的操作相符。
Solana 计算单元的 代码库 显示 log_64_units 消耗 100 个单元，与 get_remaining_compute_units_cost 相同。但请注意，这会额外消耗 5 个计算单元（不再是之前的 373，而是 378）。这很容易解释，因为就在对 sol_log_64_ 的 syscall 之前，我们有了 5 条新指令。我们在下面展示了这一点。
再次说明，为了使寄存器的值更加清晰可见，图像被分割开了：
这不言自明。从图像中，我们看到了五条 mov 指令，它们将五个数字存储在寄存器 r1-r5 中。这些数字正是我们记录的内容。
本文是 Solana development 教程系列的一部分