初步了解 Databend 怎么实现全链路追踪。
Tracing 是由 Tokio 团队维护的 Rust 应用跟踪框架,用来收集结构化的、基于事件的诊断信息。
项目地址:https://github.com/tokio-rs/tracing
示例:
use tracing::{info, Level};
use tracing_subscriber;
fn main() {
let collector = tracing_subscriber::fmt()
// filter spans/events with level TRACE or higher.
.with_max_level(Level::TRACE)
// build but do not install the subscriber.
.finish();
tracing::collect::with_default(collector, || {
info!("This will be logged to stdout");
});
info!("This will _not_ be logged to stdout");
}
Databend 的 tracing-subscriber 被统一整合在 common/tracing,由 query 和 meta 共用。
// Use env RUST_LOG to initialize log if present.
// Otherwise use the specified level.
let directives = env::var(EnvFilter::DEFAULT_ENV).unwrap_or_else(|_x| level.to_string());
let env_filter = EnvFilter::new(directives);
let subscriber = Registry::default()
.with(env_filter) # 根据环境变量过滤
.with(JsonStorageLayer) # 利用 tracing-bunyan-formatter 格式化为 json
.with(stdout_logging_layer) # 标准输出
.with(file_logging_layer) # 输出到文件,默认位于 `_logs` 目录下
.with(jaeger_layer); # opentelemetry-jaeger
#[cfg(feature = "console")]
let subscriber = subscriber.with(console_subscriber::spawn()); # tokio console
tracing::subscriber::set_global_default(subscriber)
.expect("error setting global tracing subscriber");
具体到内部的 tracing 记录,大致有两类:
普通:与其他 log 方式一样,利用 info!、debug! 来收集信息。
use common_tracing::tracing;
tracing::info!("{:?}", conf);
tracing::info!("DatabendQuery {}", *databend_query::DATABEND_COMMIT_VERSION);
Instruments:在调用函数时创建并进入 tracing span(跨度),span 表示程序在特定上下文中执行的时间段。
use common_tracing::tracing::debug_span;
#[tracing::instrument(level = "debug", skip_all)]
async fn read(&mut self) -> Result<Option<DataBlock>> {
...
fetched_metadata = read_metadata_async(&mut self.reader)
.instrument(debug_span!("parquet_source_read_meta"))
.await
.map_err(|e| ErrorCode::ParquetError(e.to_string()))?;
...
}
{
"v": 0,
"name": "databend-query-test_cluster@0.0.0.0:3307",
"msg": "Shutdown server.",
"level": 30,
"hostname": "dataslime",
"pid": 53341,
"time": "2022-05-11T00:51:56.374807359Z",
"target": "databend_query",
"line": 153,
"file": "query/src/bin/databend-query.rs"
}
构建二进制程式:cargo build(可以使用 --bin 指定)
将日志级别设定为 DEBUG ,运行需要调试的应用程式。例如,LOG_LEVEL=DEBUG ./databend-query
运行 jaeger :docker run -d -p6831:6831/udp -p6832:6832/udp -p16686:16686 jaegertracing/all-in- one:latest
打开 http://127.0.0.1:16686/ 以查看 jaeger 收集的信息
CREATE TABLE t1(a INT);
INSERT INTO t1 VALUES(1);
INSERT INTO t1 SELECT * FROM t1;
Timeline
下图是点击最大的圆点得到的追踪情况:
使用 timeline 模式来展现 tracing 的各个跨度之间的关系。以时间为主线进行分析,方便使用者观看在某个时间点观看程序信息。
点开第一个跨度,可以看到这是执行 INSERT INTO t1 SELECT *FROM t1 查询时的情况。
Graph
通过这个视图使用者很容易知道系统瓶颈,快速定位问题。
Compare
连起来的各个部分形成整个 trace 的调用链。因为比较时一般会比较两个相同类型的调用,所以看到的会是重合后的视图。
对于颜色的一个说明:
深绿色,表示这个 span 只存在于 trace-B 中,A 没有这个 span
深红色,表示这个 span 只存在于 trace-A 中,B 没有这个 span
浅绿色,表示这个 span 在 trace-B(右边这个)的数量多
浅红色,表示这个 span 在 trace-A(左边这个)的数量多
tokio-rs 团队出品的诊断和调试工具,可以帮助我们诊断与 tokio 运行时相关的问题。
使用特定的 rustflags 和 features 来构建:RUSTFLAGS="--cfg tokio_unstable" cargo build --features tokio-console ,也可以只构建单个二进制程式,使用 --bin 进行指定。
将日志级别设定为 TRACE ,运行需要调试的应用程式 LOG_LEVEL=TRACE databend-query 或者 databend-meta --single --log-level=TRACE。可以使用 TOKIO_CONSOLE_BIND 指定端口,以避免潜在的端口抢占问题。
运行 tokio-console,默认连接到 http://127.0.0.1:6669
通过左右切换,可以得到总忙时间或轮询次数等指标对任务进行排序。控制台通过高亮来提示较大差异,比如从毫秒到秒的切换。
控制台还实现了一个“警告”系统。通过监视应用程序中任务的运行时操作,控制台可以检测可能提示 bug 或性能问题的行为模式,并突出显示这些行为模式供用户分析。比如已经运行了很长时间而没有让步的任务,唤醒的次数比被其他任务唤醒的次数还要多的任务。
任务视图
上下切换选中任务,enter 查看关于每个任务的翔实数据,比如轮询持续时间的直方图。
不仅列出任务。console 还会插入异步互斥和信号量等资源。Tokio Console 的资源详细信息视图显示了哪些任务已经进入临界区,哪些任务正在等待获得访问权限。
Databend 文档:https://databend.rs/
Twitter:https://twitter.com/Datafuse_Labs
Slack:https://datafusecloud.slack.com/
Wechat:Databend
GitHub :https://github.com/datafuselabs/databend