Rust Tokio异步场景下序列化性能下降原因及排查方法问询

问题背景 #

计划用Rust开发高吞吐、低延迟的交易平台，在序列化性能测试中发现单例序列化耗时达0.05ms，且带有await的函数中代码运行速度明显慢于无await的版本。测试数据显示，带await的序列化耗时约为无await版本的5倍。

1. 性能差异的可能原因 #

• Tokio调度器上下文切换开销：每次执行sleep(Duration::from_millis(1)).await会让当前任务主动让出线程，当任务被唤醒时，Tokio调度器需要重新分配线程资源，这个过程会导致CPU缓存失效，后续序列化代码的缓存命中率下降，直接拖慢执行速度。
• 任务唤醒的调度延迟被误统计：当前计时逻辑是从sleep结束后开始，但任务从被唤醒到真正开始执行序列化代码之间，存在调度器分配线程的等待时间，这部分延迟被错误计入了序列化的耗时中，导致结果偏高。
• 编译器优化程度差异：无await的函数是纯同步循环，编译器可以进行循环展开、常量传播等深度优化；而带await的异步函数因为存在调度断点，编译器的优化空间被限制，序列化代码无法得到充分优化。

2. 除perf和hotspot外的代码追踪方法 #

• Tokio异步追踪：引入tokio-tracing crate，为异步任务、序列化代码添加追踪Span，通过控制台或本地可视化工具输出追踪数据，可直观区分调度延迟与序列化本身的耗时，定位性能瓶颈点。
• Cargo火焰图：使用cargo flamegraph生成函数调用栈火焰图，对比同步、异步版本的火焰图，能快速发现两者在执行路径、耗时分布上的差异，精准定位慢函数。
• 细粒度手动插桩：拆分计时节点，比如单独统计sleep唤醒到序列化开始的间隔、序列化本身的耗时，明确是调度延迟还是序列化逻辑的问题；同时用std::hint::black_box包裹序列化结果，避免编译器因优化省略关键操作，保证计时准确性。
• 内存分析：用valgrind massif工具分析内存分配情况，异步场景下可能因任务堆分配频繁、内存碎片问题，导致序列化时内存访问效率降低。
• 编译阶段分析：使用rustc -Z time-passes参数查看编译各阶段耗时，判断是否因异步代码的编译优化差异导致性能问题。

测试结果 #

with_await 0.04643426799999998
without_await 0.009190136999999998
without_await 0.009858687000000007
with_await 0.050352950999999944

测试代码 #

use std::time::{Duration, SystemTime, UNIX_EPOCH};
use serde_json::Value;
use tokio::time::sleep;

static JSON_BLOB: &str = "{\"arg\":{\"channel\":\"basket_orders\",\"order_name\":\"socks\"},\"data\":[{\"prices\":[[\"15.15\",\"22.22\",\"12.5\",\"22.0\"]],\"amounts\":[[\"10\",\"20\",\"10\",\"15\"]],\"ts\":\"1680917016349\"}]}";

pub fn utcnow() -> Duration {
    SystemTime::now().duration_since(UNIX_EPOCH).unwrap()
}

async fn with_await() {
    let mut diff_sum = 0_f64;
    for count in 1..=1000 {
        sleep(Duration::from_millis(1)).await;
        let blah: &str = JSON_BLOB.as_ref();
        let received_time = utcnow().as_nanos();
        let value: Value = serde_json::from_str(blah).unwrap();
        let millis_diff = (utcnow().as_nanos() - received_time) as f64 / 1_000_000.0;
        diff_sum += millis_diff;
    }
    println!("with_await {}", diff_sum / 1000_f64);
}

async fn without_await() {
    let mut diff_sum = 0_f64;
    for count in 1..=1000 {
        let blah: &str = JSON_BLOB.as_ref();
        let received_time = utcnow().as_nanos();
        let value: Value = serde_json::from_str(blah).unwrap();
        let millis_diff = (utcnow().as_nanos() - received_time) as f64 / 1_000_000.0;
        diff_sum += millis_diff;
    }
    println!("without_await {}", diff_sum / 1000_f64);
}

#[tokio::main]
async fn main() {
    with_await().await;
    without_await().await;

    let mut handles = vec![];
    handles.push(tokio::spawn(with_await()));
    handles.push(tokio::spawn(without_await()));
    futures::future::join_all(handles).await;
}

依赖项 #

[dependencies]
futures = "0.3.28"
serde = "1.0.159"
serde_json = "1.0.95"
tokio = { version = "1.27.0", features = ["full"] }

内容的提问来源于stack exchange，提问作者Henry B