用日志算 p95,结果和 p50 是同一个数
目标
亲手发出 LogQL 的两种指标查询把日志变成数字,重现提取出来的标签把时间序列拆开、让分位数失去意义的现象,然后修复它。
为什么重要
需要紧急了解一个没有指标的服务的延迟或错误率时,日志已经在那里了。LogQL 的指标查询能把这些日志变成数字,但有一个陷阱——决定时间序列身份的标签里,连该查询中解析器生成的标签也算在内。只要提取出一个每行取值都不同的字段,时间序列就会被拆成与行数一样多,每条序列只有一个样本,问哪个分位数都得到同一个值。没有错误也没有警告,图却画得好好的,所以会好几个月不被发现。而且基于日志的指标每次查询都要读取原始数据,放到仪表板上之前,要养成先测一下读取量的习惯。
步骤
- 在
/root/lk-metrics中启动 Loki,把date +%s写入/root/lk-metrics/anchor.txt,然后用python3 /opt/lab/d5/gen.py metrics "$(cat anchor.txt)"放入数据。接着把基准时刻作为time给出,发出sum by (app) (count_over_time({app=~"checkout|search"}[1h])),把两个服务的行数以checkout=<정수>和search=<정수>(占位符为整数)两行写入/root/lk-metrics/01-boot.txt。 - 求出
checkout服务中status为 500 的行在一小时区间内的每秒发生率。查询写入/root/lk-metrics/02-rate.logql,值以rate=<소수 여섯째 자리>(占位符为保留到小数点后第六位的数)一行写入/root/lk-metrics/02-rate.txt。要让结果只有一条时间序列,在外面用sum(...)包起来。 - 求出
checkout一小时的错误比例(500 的行 ÷ 全部行),以ratio=<소수 여섯째 자리>(占位符为保留到小数点后第六位的数)一行写入/root/lk-metrics/03-ratio.txt。查询写在/root/lk-metrics/03-ratio.logql中。分子和分母要分别用sum(...)包起来再相除,时间序列才对得上。 - 把
quantile_over_time(0.50, ...)和quantile_over_time(0.95, ...)分别套在{app="checkout"} | logfmt | unwrap dur_ms [1h]上发出。把两个查询返回的时间序列数和第一条序列的值,写成四行存入/root/lk-metrics/04-trap.txt——series=<정수>、p50_first=<숫자>、p95_first=<숫자>、lines=<그 구간의 전체 줄 수>(占位符依次为整数、数字、数字、该区间内的总行数)。 - 把同样的两个分位数改成只出一条时间序列再发出。查询分别写入
/root/lk-metrics/05-p50.logql和/root/lk-metrics/05-p95.logql,值以p50=<숫자>、p95=<숫자>、series=<정수>(占位符依次为数字、数字、整数)三行写入/root/lk-metrics/05-fix.txt。两个值必须明显分开。 - 创建
/root/lk-metrics/compare.tsv。不要表头,共两行,每行是用制表符分隔的四列<서비스><탭><줄수><탭><오류비율><탭><p95>(占位符依次为服务、制表符、行数、制表符、错误比例、制表符、p95)。服务依次为checkout、search,错误比例保留到小数点后第六位,p95 四舍五入为不带小数的整数。 - 把第 5 步的 p95 查询用
query_range对一小时区间发出,测量响应统计中读取的字节数,写成三行存入/root/lk-metrics/07-cost.txt——bytes_per_query=<정수>、refresh_sec=30、bytes_per_day=<정수>(占位符为整数)。一天的量按每 30 秒运行一次来算,即bytes_per_query × 2880。 - 在
/root/lk-metrics/08-decide.txt中写三行。choice=后面写log或metric之一,evidence=后面写一行,其中包含前面步骤测得的两个以上数字,reason=后面写为什么这样选择(去掉空格后至少 60 个字)。正确答案不止一个,但依据必须是前面步骤的实测值。
参考
- 工作目录是
/root/lk-metrics。Loki 要在第 1 步里亲手启动。 - 数据生成器是
/opt/lab/d5/gen.py,使用metrics数据。评分器不读这个文件。 - 指标查询给出
time发送到/loki/api/v1/query,需要按区间取值时,给出step发送到/loki/api/v1/query_range。由正确答案生成的mq.sh是方便使用的辅助工具。 - 常见错误:用
since=1h或当前时刻来测量。要把anchor.txt的基准时刻作为time给出。 - 常见错误:分子和分母的标签集不同,导致除法得出空结果。两边都用
sum(...)包起来,标签就全被抹掉,自然对得上。 - 指标查询 · 日志查询 · LogQL 概述 · HTTP API
放入两个服务的日志,先数行数
在 /root/lk-metrics 中启动 Loki,把 date +%s 写入 /root/lk-metrics/anchor.txt,然后用 python3 /opt/lab/d5/gen.py metrics "$(cat anchor.txt)" 放入数据。接着把基准时刻作为 time 给出,发出 sum by (app) (count_over_time({app=~"checkout|search"}[1h])),把两个服务的行数以 checkout=<정수> 和 search=<정수>(占位符为整数)两行写入 /root/lk-metrics/01-boot.txt。
指标查询不是发到 query_range,而是发到 /loki/api/v1/query,time 以纳秒给出。也看一看响应的 resultType 与日志查询有什么不同。sum by (app) 会把时间序列按服务合并。
数行的查询——每秒错误数
求出 checkout 服务中 status 为 500 的行在一小时区间内的每秒发生率。查询写入 /root/lk-metrics/02-rate.logql,值以 rate=<소수 여섯째 자리>(占位符为保留到小数点后第六位的数)一行写入 /root/lk-metrics/02-rate.txt。要让结果只有一条时间序列,在外面用 sum(...) 包起来。
rate 是区间内的行数除以区间的秒数。只数 500 的话,要用解析器取出状态码,再套标签过滤器。值算出来很小是正常的——一小时才几条。
比例是两个指标查询相除
求出 checkout 一小时的错误比例(500 的行 ÷ 全部行),以 ratio=<소수 여섯째 자리>(占位符为保留到小数点后第六位的数)一行写入 /root/lk-metrics/03-ratio.txt。查询写在 /root/lk-metrics/03-ratio.logql 中。分子和分母要分别用 sum(...) 包起来再相除,时间序列才对得上。
分母不需要解析器——数全部行就行。分子和分母的标签集不同,除法就会得出空结果,所以两边都用 sum(...) 包起来、把标签全部抹掉是最简单的办法。
p50 和 p95 一模一样
把 quantile_over_time(0.50, ...) 和 quantile_over_time(0.95, ...) 分别套在 {app="checkout"} | logfmt | unwrap dur_ms [1h] 上发出。把两个查询返回的时间序列数和第一条序列的值,写成四行存入 /root/lk-metrics/04-trap.txt——series=<정수>、p50_first=<숫자>、p95_first=<숫자>、lines=<그 구간의 전체 줄 수>(占位符依次为整数、数字、数字、该区间内的总行数)。
时间序列数就是响应 data.result 数组的长度。把这个数字与第 1 步数出的行数比较一下。为什么两个分位数得出相同的值,从这个比较里马上就能看出来。logfmt 在这份日志里生成了哪些标签,也在结果的 metric 里确认。
整理标签,分位数就分开了
把同样的两个分位数改成只出一条时间序列再发出。查询分别写入 /root/lk-metrics/05-p50.logql 和 /root/lk-metrics/05-p95.logql,值以 p50=<숫자>、p95=<숫자>、series=<정수>(占位符依次为数字、数字、整数)三行写入 /root/lk-metrics/05-fix.txt。两个值必须明显分开。
去掉每行取值都不同的标签,或者只留下要用的标签,或者在外面套聚合,都行。三种方法用哪个都可以——只是时间序列必须变成一条。哪个标签是元凶,看第 4 步结果里的 metric 就知道。
把两个服务放进一张表比较
创建 /root/lk-metrics/compare.tsv。不要表头,共两行,每行是用制表符分隔的四列 <서비스><탭><줄수><탭><오류비율><탭><p95>(占位符依次为服务、制表符、行数、制表符、错误比例、制表符、p95)。服务依次为 checkout、search,错误比例保留到小数点后第六位,p95 四舍五入为不带小数的整数。
把第 3 步和第 5 步的查询里的服务名称换掉就行。在表里确认,即使是同样的数据,两个服务的长尾形状也不同——只有看 p95 而不是平均值,才看得出这个差别。
应用 ① ——把这个查询设成面板,会读多少
把第 5 步的 p95 查询用 query_range 对一小时区间发出,测量响应统计中读取的字节数,写成三行存入 /root/lk-metrics/07-cost.txt——bytes_per_query=<정수>、refresh_sec=30、bytes_per_day=<정수>(占位符为整数)。一天的量按每 30 秒运行一次来算,即 bytes_per_query × 2880。
指标查询也可以用 query_range 发出,此时要给出 step。统计和日志查询在同一个位置(data.stats.summary)。一天 2880 次,是 30 秒周期下一天的次数——这意味着一个仪表板面板的查询次数远多于人。
应用 ② ——继续用日志测量,还是改为输出指标
在 /root/lk-metrics/08-decide.txt 中写三行。choice= 后面写 log 或 metric 之一,evidence= 后面写一行,其中包含前面步骤测得的两个以上数字,reason= 后面写为什么这样选择(去掉空格后至少 60 个字)。正确答案不止一个,但依据必须是前面步骤的实测值。
两条路的价值不同。基于日志的,不用修改埋点,还能回顾过去,但每次查询都要读取原始数据。基于指标的,便宜又快,但要事先输出,且没有过去。用第 7 步的一天读取量,和在第 4、5 步里遇到的陷阱作依据,就有说服力。