查询统计信息

Cloud Spanner 提供内置表,表中存储许多关于 CPU 使用率最高的查询和所有查询总计的统计信息。Google Cloud Console 使用这些 SPANNER_SYS.QUERY_STATS* 表中的数据生成其查询统计信息视图,但您也可以使用 SQL 语句从表中检索统计信息。

可用性

SPANNER_SYS 数据只能通过 SQL 接口获得(例如通过 executeQuerygcloud spanner databases execute-sql接口);Cloud Spanner 提供的其他单一读取方法不支持 SPANNER_SYS

按查询分组的 CPU 使用率

下面的表跟踪特定时间段内 CPU 使用率最高的查询:

  • SPANNER_SYS.QUERY_STATS_TOP_MINUTE:1 分钟时间段内的查询
  • SPANNER_SYS.QUERY_STATS_TOP_10MINUTE:10 分钟时间段内的查询
  • SPANNER_SYS.QUERY_STATS_TOP_HOUR:1 小时时间段内的查询

这些表具有以下属性:

  • 每个表包含表名指定的非重叠时间段长度的数据。

  • 时间段基于时钟时间。1 分钟时间段结束于整点分钟,10 分钟时间段结束于整点 10 分钟(自当前小时数开始),1 小时时间段结束于整点小时数。

    例如,在上午 11:59:30,SQL 查询可用的最近时间段为:

    • 1 分钟:上午 11:58:00–11:58:59
    • 10 分钟:上午 11:40:00–11:49:59
    • 1 小时:上午 10:00:00–10:59:59
  • Cloud Spanner 按 SQL 查询的文本对统计信息进行分组。如果是使用查询参数的查询,则 Cloud Spanner 会将该查询的所有执行结果放在一行。如果是使用字符串字面量的查询,则只有查询文本完全相同时,Cloud Spanner 才会对统计信息进行分组;当查询文本不同时,每个查询都会显示为单独的行。

  • 每行包含 Cloud Spanner 在指定时间段内捕获的特定 SQL 查询的所有执行结果的统计信息。

  • 如果 Cloud Spanner 无法存储在某时间段内运行的所有查询,则系统会优先存储在指定时间段内 CPU 使用率最高的查询。

  • 跟踪的查询包括完成、失败或被用户取消的查询。

  • 统计信息的子集专门指正在运行但未完成的查询:

    • 所有未成功的查询的执行计数和平均延迟时间(以秒为单位)。

    • 超时查询的执行计数。

    • 用户取消或因网络连接问题失败的查询的执行次数。

表架构

列名 类型 说明
INTERVAL_END TIMESTAMP 包括的查询执行时所处的时间段的结束时间。
TEXT STRING SQL 查询文本,被截断至 64KB 左右。
TEXT_TRUNCATED BOOL 查询文本是否被截断。
TEXT_FINGERPRINT INT64 查询文本的哈希值。
EXECUTION_COUNT INT64 Cloud Spanner 在时间段内查看查询的次数。
AVG_LATENCY_SECONDS FLOAT64 数据库中每个查询执行的平均时间长度(以秒为单位)。该平均值不包括结果集编码和传输时间以及开销。
AVG_ROWS FLOAT64 查询返回的平均行数。
AVG_BYTES FLOAT64 查询返回的数据字节数的平均值,不包括传输编码开销。
AVG_ROWS_SCANNED FLOAT64 查询扫描的平均行数,不包括已删除的值。
AVG_CPU_SECONDS FLOAT64 Cloud Spanner 在执行查询的所有操作上花费的平均 CPU 时间(以秒为单位)。
ALL_FAILED_EXECUTION_COUNT INT64 查询在间隔期间失败的次数。
ALL_FAILED_AVG_LATENCY_SECONDS FLOAT64 数据库中每个查询执行失败的平均时间长度(以秒为单位)。该平均值不包括结果集编码和传输时间以及开销。
CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT INT64 在该时间间隔内,查询被用户取消或由于断开的网络连接而失败的次数。
TIMED_OUT_EXECUTION_COUNT INT64 查询在时间间隔内超时的次数。

失败的查询的 EXECUTION_COUNTAVG_LATENCY_SECONDS 包括因语法不正确而失败的查询或遇到短暂错误但在重试时成功的查询。

聚合统计信息

还有一些表跟踪 Cloud Spanner 在特定时间段内为其捕获统计信息的所有查询的聚合数据:

  • SPANNER_SYS.QUERY_STATS_TOTAL_MINUTE:1 分钟时间段内的查询
  • SPANNER_SYS.QUERY_STATS_TOTAL_10MINUTE:10 分钟时间段内的查询
  • SPANNER_SYS.QUERY_STATS_TOTAL_HOUR:1 小时时间段内的查询

这些表具有以下属性:

  • 每个表包含表名指定的非重叠时间段长度的数据。

  • 时间段基于时钟时间。1 分钟时间段结束于整点分钟,10 分钟时间段结束于整点 10 分钟(自当前小时数开始),1 小时时间段结束于整点小时数。

    例如,在上午 11:59:30,SQL 查询可用的最近时间段为:

    • 1 分钟:上午 11:58:00–11:58:59
    • 10 分钟:上午 11:40:00–11:49:59
    • 1 小时:上午 10:00:00–10:59:59
  • 每行包含在指定时间段内通过数据库执行的所有查询的聚合统计信息。每个时间间隔只能有一行,包括已完成的查询、失败的查询和用户取消的查询。

  • TOTAL 表中捕获的统计信息可能包含 Cloud Spanner 在 TOP 表中未捕获的查询。

表架构

列名 类型 说明
INTERVAL_END TIMESTAMP 包括的查询执行时所处的时间段的结束时间。
EXECUTION_COUNT INT64 Cloud Spanner 在时间间隔内发现查询的次数。
AVG_LATENCY_SECONDS FLOAT64 数据库中每个查询执行的平均时间长度(以秒为单位)。该平均值不包括结果集编码和传输时间以及开销。
AVG_ROWS FLOAT64 查询返回的平均行数。
AVG_BYTES FLOAT64 查询返回的数据字节数的平均值,不包括传输编码开销。
AVG_ROWS_SCANNED FLOAT64 查询扫描的平均行数,不包括已删除的值。
AVG_CPU_SECONDS FLOAT64 Cloud Spanner 在执行查询的所有操作上花费的平均 CPU 时间(以秒为单位)。
ALL_FAILED_EXECUTION_COUNT INT64 查询在间隔期间失败的次数。
ALL_FAILED_AVG_LATENCY_SECONDS FLOAT64 数据库中每个查询执行失败的平均时间长度(以秒为单位)。该平均值不包括结果集编码和传输时间以及开销。
CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT INT64 在该时间间隔内,查询被用户取消或由于断开的网络连接而失败的次数。
TIMED_OUT_EXECUTION_COUNT INT64 查询在时间间隔内超时的次数。

数据保留

Cloud Spanner 至少为每个表保留以下时间段内的数据:

  • SPANNER_SYS.QUERY_STATS_TOP_MINUTESPANNER_SYS.QUERY_STATS_TOTAL_MINUTE:前 6 个小时中的时间段。

  • SPANNER_SYS.QUERY_STATS_TOP_10MINUTESPANNER_SYS.QUERY_STATS_TOTAL_10MINUTE:前 4 天中的时间段。

  • SPANNER_SYS.QUERY_STATS_TOP_HOURSPANNER_SYS.QUERY_STATS_TOTAL_HOUR:前 30 天中的时间段。

示例查询

本部分提供了几个可检索查询统计信息的示例 SQL 语句。您可以使用客户端库gcloud 命令行工具或 Cloud Console 运行这些 SQL 语句。

列出指定时间段内每个查询的基本统计信息

以下查询可返回前一分钟内顶级查询的原始数据:

SELECT text,
       interval_end,
       execution_count,
       avg_latency_seconds,
       avg_rows,
       avg_bytes,
       avg_rows_scanned,
       avg_cpu_seconds
FROM spanner_sys.query_stats_top_minute
ORDER BY interval_end DESC;

列出 CPU 使用率最高的查询

以下查询可返回前一小时 CPU 使用率最高的查询:

SELECT text,
       execution_count AS count,
       avg_latency_seconds AS latency,
       avg_cpu_seconds AS cpu,
       execution_count * avg_cpu_seconds AS total_cpu
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY total_cpu DESC;

查找指定时间段内的总执行次数

以下查询可返回在前一个整 1 分钟时间段内执行的查询总数:

SELECT interval_end,
       execution_count
FROM spanner_sys.query_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_minute);

查找查询的平均延迟

以下查询可返回特定查询的平均延迟时间信息:

SELECT avg_latency_seconds
FROM spanner_sys.query_stats_top_hour
WHERE text LIKE "SELECT x FROM table WHERE x=@foo;";

查找扫描最多数据的查询

要衡量某查询扫描的数据量,您可以使用该查询扫描的行数作为统计方式。以下查询可返回前一小时执行的查询所扫描的行数:

SELECT text,
       execution_count,
       avg_rows_scanned
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY avg_rows_scanned DESC;

所有查询的 CPU 总使用时间

以下查询可返回前一小时使用的 CPU 小时数:

SELECT (avg_cpu_seconds * execution_count / 60 / 60)
  AS total_cpu_hours
FROM spanner_sys.query_stats_total_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_total_hour);

列出在给定时间段内失败的查询

以下查询返回原始数据,包括过去一分钟内顶级查询的失败查询次数和平均延迟时间:

SELECT text,
       interval_end,
       execution_count,
       all_failed_execution_count,
       all_failed_avg_latency_seconds,
       avg_latency_seconds,
       avg_rows,
       avg_bytes,
       avg_rows_scanned,
       avg_cpu_seconds
FROM spanner_sys.query_stats_top_minute
WHERE all_failed_execution_count > 0
ORDER BY interval_end;

查找指定时间段内的总错误次数

以下查询返回在最近 1 分钟间隔内未能执行的查询总数。

SELECT interval_end,
       all_failed_execution_count
FROM spanner_sys.query_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_minute)
ORDER BY interval_end;

列出超时最多的查询

以下查询可返回前一小时内超时数量最高的查询。

SELECT text,
       execution_count AS count,
       timed_out_execution_count AS timeout_count,
       avg_latency_seconds AS latency,
       avg_cpu_seconds AS cpu,
       execution_count * avg_cpu_seconds AS total_cpu
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY timed_out_execution_count DESC;

查找查询成功执行和失败执行的平均延迟时间

以下查询返回特定查询的组合平均等待时间,成功执行的平均等待时间和失败执行的平均等待时间。

SELECT avg_latency_seconds AS combined_avg_latency,
       all_failed_avg_latency_seconds AS failed_execution_latency,
       ( avg_latency_seconds * execution_count -
         all_failed_avg_latency_seconds * all_failed_execution_count
       ) / (
       execution_count - all_failed_execution_count ) AS success_execution_latency
FROM   spanner_sys.query_stats_top_hour
WHERE  text LIKE "select x from table where x=@foo;";

使用查询统计信息排查 CPU 使用率高或查询延迟较长的问题

当您需要调查 Cloud Spanner 数据库上的高 CPU 使用率,或者您只是尝试了解数据库中 CPU 密集型查询形状时,查询统计信息非常有用。检查使用大量数据库资源的查询可让 Cloud Spanner 用户有机会降低运营费用,并可能缩短常规系统延迟时间。通过以下步骤,我们将向您展示如何使用查询统计信息来调查数据库中 CPU 使用率高的情况。

以下示例侧重于 CPU 使用率,不过您可按照类似的步骤来排查高查询延迟问题,并查找具有最高延迟时间的查询。只需按延迟时间(而非 CPU 使用率)即可选择时间间隔和查询。

选择要调查的时间段

调查之初是查找您的应用开始出现高 CPU 使用率的时间。例如,假设问题是于 2020 年 7 月 24 日下午 5:00 (世界协调时间)开始。

收集所选时间段内的查询统计信息

选择开始调查的时间段后,我们将查看在约该时间的 QUERY_STATS_TOTAL_10MINUTE 表中收集的统计信息。此查询的结果可能会显示在该时间段内 CPU 和其他查询统计信息在该时间段内的变化情况

以下查询可返回从 16:3017:30 (世界协调时间)(含)之间的聚合查询统计信息。我们在查询中使用 ROUND 来限制显示小数位数。

SELECT interval_end,
       execution_count AS count,
       ROUND(avg_latency_seconds,2) AS latency,
       ROUND(avg_rows,2) AS rows_returned,
       ROUND(avg_bytes,2) AS bytes,
       ROUND(avg_rows_scanned,2) AS rows_scanned,
       ROUND(avg_cpu_seconds,3) AS avg_cpu
FROM spanner_sys.query_stats_total_10minute
WHERE
  interval_end >= "2020-07-24T16:30:00Z"
  AND interval_end <= "2020-07-20T17:30:00Z"
ORDER BY interval_end;

运行该查询会产生以下结果。

interval_end 计数 延时 rows_returned 字节 rows_scanned avg_cpu
2020-07-24T16:30:00Z 6 0.06 5.00 536.00 16.67 0.035
2020-07-24T16:40:00Z 55 0.02 0.22 25.29 0.22 0.004
2020-07-24T16:50:00Z 102 0.02 0.30 33.35 0.30 0.004
2020-07-24T17:00:00Z 154 1.06 4.42 486.33 7792208.12 4.633
2020-07-24T17:10:00Z 94 0.02 1.68 106.84 1.68 0.006
2020-07-24T17:20:00Z 110 0.02 0.38 34.60 0.38 0.005
2020-07-24T17:30:00Z 47 0.02 0.23 24.96 0.23 0.004

在上表中,我们看到平均 CPU 时间(结果表中的 avg_cpu 列)在高亮显示的时间间隔(截止17:00)中是最高的。我们还发现平均扫描的行数更高这表示从 16:50 到 17:00 运行的查询价格更高。让我们选择这个时间间隔,以便在下一步中进一步研究。

查找哪些查询导致 CPU 使用率高

选择要调查的时间间隔后,我们现在查询 QUERY_STATS_TOP_10MINUTE 表。此查询的结果有助于确定哪些查询会导致 CPU 使用率高。

SELECT text_fingerprint AS fingerprint,
       execution_count AS count,
       ROUND(avg_latency_seconds,2) AS latency,
       ROUND(avg_cpu_seconds,3) AS cpu,
       ROUND(execution_count * avg_cpu_seconds,3) AS total_cpu
FROM spanner_sys.query_stats_top_10MINUTE
WHERE
  interval_end = "2020-07-20T17:00:00Z"
ORDER BY total_cpu DESC;

运行此查询会生成以下结果。

指纹 计数 延时 CPU total_cpu
5505124206529314852 30 3.88 17.635 529.039
1697951036096498470 10 4.49 18.388 183.882
2295109096748351518 1 0.33 0.048 0.048
11618299167612903606 1 0.25 0.021 0.021
10302798842433860499 1 0.04 0.006 0.006
123771704548746223 1 0.04 0.006 0.006
4216063638051261350 1 0.04 0.006 0.006
3654744714919476398 1 0.04 0.006 0.006
2999453161628434990 1 0.04 0.006 0.006
823179738756093706 1 0.02 0.005 0.0056

结果表中突出显示的前 2 个查询是平均 CPU 和延迟时间的离群值,以及执行次数和总 CPU 数。我们来调查这些结果中列出的第一个查询。

比较查询随时间的变化

通过缩小调查范围,我们可以将注意力集中到 QUERY_STATS_TOP_MINUTE 表。通过比较特定查询随时间的运行情况,我们可以查找返回的行数或字节数,扫描的行数与 CPU 或延迟时间增加之间的相关性。偏差可能表明数据中的非均匀性。持续扫描的大量行可能表明缺乏适当的索引或次优连接顺序。

让我们通过运行以下过滤该查询的 text_fingerprint 的语句,来研究表现出最高平均 CPU 使用率和最高延迟的查询。

SELECT interval_end,
       ROUND(avg_latency_seconds,2) AS latency,
       avg_rows AS rows_returned,
       avg_bytes AS bytes_returned,
       avg_rows_scanned AS rows_scanned,
       ROUND(avg_cpu_seconds,3) AS cpu,
FROM spanner_sys.query_stats_top_minute
WHERE text_fingerprint = 5505124206529314852
ORDER BY interval_end DESC;

运行此查询会返回以下结果。

interval_end 延时 rows_returned bytes_returned rows_scanned CPU
2020-07-24T17:00:00Z 4.55 21 2365 30000000 19.255
2020-07-24T16:00:00Z 3.62 21 2365 30000000 17.255
2020-07-24T15:00:00Z 4.37 21 2365 30000000 18.350
2020-07-24T14:00:00Z 4.02 21 2365 30000000 17.748
2020-07-24T13:00:00Z 3.12 21 2365 30000000 16.380
2020-07-24T12:00:00Z 3.45 21 2365 30000000 15.476
2020-07-24T11:00:00Z 4.94 21 2365 30000000 22.611
2020-07-24T10:00:00Z 6.48 21 2365 30000000 21.265
2020-07-24T09:00:00Z 0.23 21 2365 5 0.040
2020-07-24T08:00:00Z 0.04 21 2365 5 0.021
2020-07-24T07:00:00Z 0.09 21 2365 5 0.030

检查上述结果,我们发现扫描的行数,使用的 CPU 和延迟时间都在上午 9:00 左右发生了显着变化。为了了解这些数字急剧增加的原因,我们将检查查询文本,并查看架构中的任何更改是否可能影响查询。

使用以下查询来检索要调查的查询的查询文本。

SELECT text,
       text_truncated
FROM spanner_sys.query_stats_top_hour
WHERE text_fingerprint = 5505124206529314852
LIMIT 1;

这会返回以下结果。

text text_truncated
从 o_custkey = 36901 的订单中选择 *;

通过检查返回的查询文本,我们意识到该查询会在名为 o_custkey 的字段中进行过滤。这是 orders 表上的非键列。发生这种情况时,该列中的索引将在上午 9 点左右删除。这解释了此查询的费用变化。我们可以重新添加该索引,如果该查询很少运行,请确定没有索引,并接受更高的读取费用。

到目前为止,我们的调查工作重点放在了成功完成的查询中,并发现了数据库性能下降的一些原因。下一步,我们将着重介绍失败的或已取消的查询,并介绍如何检查数据以获取更多洞见。

调查失败的查询

未完成的查询仍会在超时前、被取消前或失败之前消耗资源。Cloud Spanner 跟踪失败查询和成功查询的执行计数和消耗的资源。

如需检查失败的查询是否会影响系统利用率,我们首先可以检查相关时间间隔中有多少查询失败。

SELECT interval_end,
       all_failed_execution_count AS failed_count,
       all_failed_avg_latency_seconds AS latency
FROM spanner_sys.query_stats_total_minute
WHERE
  interval_end >= "2020-07-24T16:50:00Z"
  AND interval_end <= "2020-07-24T17:00:00Z"
ORDER BY interval_end;
interval_end failed_count 延时
2020-07-24T16:52:00Z 1 15.211391
2020-07-24T16:53:00Z 3 58.312232

在进一步调查时,我们可以利用以下查询找出最有可能失败的查询。

SELECT interval_end,
       text_fingerprint,
       execution_count,
       avg_latency_seconds AS avg_latency,
       all_failed_execution_count AS failed_count,
       all_failed_avg_latency_seconds AS failed_latency,
       cancelled_or_disconnected_execution_count AS cancel_count,
       timed_out_execution_count AS to_count
FROM spanner_sys.query_stats_top_minute
WHERE all_failed_execution_count > 0
ORDER BY interval_end;
interval_end text_fingerprint execution_count failed_count cancel_count to_count
2020-07-24T16:52:00Z 5505124206529314852 3 1 1 0
2020-07-24T16:53:00Z 1697951036096498470 2 1 1 0
2020-07-24T16:53:00Z 5505124206529314852 5 2 1 1

如上表所示,使用指纹 5505124206529314852 的查询在不同时间间隔内多次失败。如果遇到此类故障,那么比较成功和失败的运行延迟时间会比较有趣。

SELECT interval_end,
       avg_latency_seconds AS combined_avg_latency,
       all_failed_avg_latency_seconds AS failed_execution_latency,
       ( avg_latency_seconds * execution_count -
         all_failed_avg_latency_seconds * all_failed_execution_count
       ) / (
       execution_count - all_failed_execution_count ) AS success_execution_latency
FROM   spanner_sys.query_stats_top_hour
WHERE  text_fingerprint = 5505124206529314852;
interval_end combined_avg_latency failed_execution_latency success_execution_latency
2020-07-24T17:00:00Z 3.880420 13.830709 2.774832

采用最佳做法

确定了要优化的候选查询后,我们接下来可以查看查询配置文件,并尝试使用 SQL 最佳做法进行优化。

后续步骤