Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Create views over transaction_contention_events to help users troubleshoot locking contention #81466

Open
kevin-v-ngo opened this issue May 18, 2022 · 3 comments
Labels
A-sql-cli-observability Issues related to surfacing SQL observability in SHOW, CRDB_INTERNAL, SYSTEM, etc. C-enhancement Solution expected to add code/behavior + preserve backward-compat (pg compat issues are exception) T-observability

Comments

@kevin-v-ngo
Copy link

kevin-v-ngo commented May 18, 2022

In 22.1, we released transaction_contention_events to help users troubleshooting locking contention. This is the base table surfacing raw information on specific transaction conflicts. We should create a view that joins this table with transaction_statistics, statement_statistics, and tables to quickly surface the following information for users:

  • The blocked transaction fingerprint (including its statements)
  • The blocking transaction fingerprint (including its statements)
  • Where the blocking occurred, specifically the table, index, and rows (keys)

Jira issue: CRDB-15169

@kevin-v-ngo kevin-v-ngo added C-enhancement Solution expected to add code/behavior + preserve backward-compat (pg compat issues are exception) A-sql-cli-observability Issues related to surfacing SQL observability in SHOW, CRDB_INTERNAL, SYSTEM, etc. labels May 18, 2022
@kevin-v-ngo kevin-v-ngo added this to Triage in Cluster Observability via automation May 18, 2022
@jlinder jlinder added sync-me and removed sync-me labels May 20, 2022
@kevin-v-ngo kevin-v-ngo moved this from Triage to Quick Win in Cluster Observability Jun 6, 2022
@ericharmeling ericharmeling self-assigned this Jun 27, 2022
@ericharmeling
Copy link
Contributor

So I've come up with a query that I believe surfaces all of the requested information... but it's a little unwieldy, since the information is located across several tables:

  • blocking and waiting transaction fingerprint IDs and keys in crdb_internal.transaction_contention_events
  • table IDs, index IDs, and keys in crdb_internal.cluster_contention_events
  • queries, transaction fingerprint IDs in crdb_internal.statement_statistics
  • index names, index IDs in crdb_internal.table_indexes
  • database names, schema names, table names, table IDs in crdb_internal.tables

To get all of this information in a single view requires a lot of joins:

CREATE VIEW cluster_contended_transactions (
  blocking_txn_fingerprint_id, blocking_queries, 
  waiting_txn_fingerprint_id, waiting_queries, 
  database_name, schema_name, table_name, 
  index_name, key
) AS 
SELECT 
  blocking_txn_fingerprint_id, 
  blocking_queries, 
  waiting_txn_fingerprint_id, 
  waiting_queries, 
  contending_key, 
  database_name, 
  schema_name, 
  name,
  index_name 
FROM 
  crdb_internal.transaction_contention_events AS tce 
  JOIN crdb_internal.cluster_contention_events AS cce ON tce.contending_key = cce.key 
  JOIN crdb_internal.tables AS t ON t.table_id = cce.table_id
  JOIN crdb_internal.table_indexes AS i ON i.index_id = cce.index_id  
  JOIN (
    SELECT 
      transaction_fingerprint_id, 
      array_agg(metadata ->> 'query') AS waiting_queries 
    FROM 
      crdb_internal.statement_statistics 
    GROUP BY 
      transaction_fingerprint_id
  ) AS wqs ON wqs.transaction_fingerprint_id = tce.waiting_txn_fingerprint_id 
  JOIN (
    SELECT 
      transaction_fingerprint_id, 
      array_agg(metadata ->> 'query') AS blocking_queries 
    FROM 
      crdb_internal.statement_statistics 
    GROUP BY 
      transaction_fingerprint_id
  ) AS bqs ON bqs.transaction_fingerprint_id = tce.blocking_txn_fingerprint_id;

Here's some output from the console, after creating the view and running multiple workloads against a demo cluster:

root@127.0.0.1:26257/movr> show columns from cluster_contended_transactions;
          column_name         | data_type | is_nullable | column_default | generation_expression | indices | is_hidden
------------------------------+-----------+-------------+----------------+-----------------------+---------+------------
  blocking_txn_fingerprint_id | BYTES     |    true     | NULL           |                       | {}      |   false
  blocking_queries            | STRING[]  |    true     | NULL           |                       | {}      |   false
  waiting_txn_fingerprint_id  | BYTES     |    true     | NULL           |                       | {}      |   false
  waiting_queries             | STRING[]  |    true     | NULL           |                       | {}      |   false
  database_name               | BYTES     |    true     | NULL           |                       | {}      |   false
  schema_name                 | STRING    |    true     | NULL           |                       | {}      |   false
  table_name                  | STRING    |    true     | NULL           |                       | {}      |   false
  index_name                  | STRING    |    true     | NULL           |                       | {}      |   false
  key                         | STRING    |    true     | NULL           |                       | {}      |   false
(9 rows)


Time: 38ms total (execution 38ms / network 0ms)

root@127.0.0.1:26257/movr> select blocking_queries, waiting_queries from cluster_contended_transactions;
                   blocking_queries                   |                  waiting_queries
------------------------------------------------------+----------------------------------------------------
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
  {"INSERT INTO vehicles VALUES ($1, $2, __more6__)"} | {"SELECT city, id FROM vehicles WHERE city = $1"}
(26 rows)


Time: 28ms total (execution 27ms / network 1ms)

The EXPLAIN ANALYZE output:

root@127.0.0.1:26257/movr> explain analyze(SELECT                                                                                                                                                                                                    blocking_txn_fingerprint_id,                                                                                                                                                                                                                       blocking_queries,                                                                                                                                                                                                                                  waiting_txn_fingerprint_id,                                                                                                                                                                                                                        waiting_queries,                                                                                                                                                                                                                                   contending_key,                                                                                                                                                                                                                                    database_name,                                                                                                                                                                                                                                     schema_name,                                                                                                                                                                                                                                       name,                                                                                                                                                                                                                                              index_name                                                                                                                                                                                                                                       FROM                                                                                                                                                                                                                                                 crdb_internal.transaction_contention_events AS tce                                                                                                                                                                                                 JOIN crdb_internal.cluster_contention_events AS cce ON tce.contending_key = cce.key                                                                                                                                                                JOIN crdb_internal.tables AS t ON t.table_id = cce.table_id                                                                                                                                                                                        JOIN crdb_internal.table_indexes AS i ON i.index_id = cce.index_id                                                                                                                                                                                 JOIN (                                                                                                                                                                                                                                               SELECT                                                                                                                                                                                                                                               transaction_fingerprint_id,                                                                                                                                                                                                                        array_agg(metadata ->> 'query') AS waiting_queries                                                                                                                                                                                               FROM                                                                                                                                                                                                                                                 crdb_internal.statement_statistics                                                                                                                                                                                                               GROUP BY                                                                                                                                                                                                                                             transaction_fingerprint_id                                                                                                                                                                                                                     ) AS wqs ON wqs.transaction_fingerprint_id = tce.waiting_txn_fingerprint_id                                                                                                                                                                        JOIN (                                                                                                                                                                                                                                               SELECT                                                                                                                                                                                                                                               transaction_fingerprint_id,                                                                                                                                                                                                                        array_agg(metadata ->> 'query') AS blocking_queries                                                                                                                                                                                              FROM                                                                                                                                                                                                                                                 crdb_internal.statement_statistics                                                                                                                                                                                                               GROUP BY                                                                                                                                                                                                                                             transaction_fingerprint_id                                                                                                                                                                                                                     ) AS bqs ON bqs.transaction_fingerprint_id = tce.blocking_txn_fingerprint_id);
                                                                  info
----------------------------------------------------------------------------------------------------------------------------------------
  planning time: 1ms
  execution time: 68ms
  distribution: local
  vectorized: true
  rows read from KV: 376 (652 KiB)
  cumulative time spent in KV: 33ms
  maximum memory usage: 5.6 MiB
  network usage: 0 B (0 messages)
  regions: us-east1

  • hash join
  │ nodes: n1
  │ regions: us-east1
  │ actual row count: 58
  │ estimated max memory allocated: 270 KiB
  │ estimated max sql temp disk usage: 0 B
  │ equality: (key) = (contending_key)
  │
  ├── • hash join
  │   │ nodes: n1
  │   │ regions: us-east1
  │   │ actual row count: 58
  │   │ estimated max memory allocated: 220 KiB
  │   │ estimated max sql temp disk usage: 0 B
  │   │ equality: (table_id) = (table_id)
  │   │
  │   ├── • hash join
  │   │   │ nodes: n1
  │   │   │ regions: us-east1
  │   │   │ actual row count: 58
  │   │   │ estimated max memory allocated: 100 KiB
  │   │   │ estimated max sql temp disk usage: 0 B
  │   │   │ equality: (index_id) = (index_id)
  │   │   │
  │   │   ├── • virtual table
  │   │   │     nodes: n1
  │   │   │     regions: us-east1
  │   │   │     actual row count: 27
  │   │   │     table: cluster_contention_events@primary
  │   │   │
  │   │   └── • virtual table
  │   │         nodes: n1
  │   │         regions: us-east1
  │   │         actual row count: 10
  │   │         table: table_indexes@primary
  │   │
  │   └── • virtual table
  │         nodes: n1
  │         regions: us-east1
  │         actual row count: 330
  │         table: tables@primary
  │
  └── • hash join
      │ nodes: n1
      │ regions: us-east1
      │ actual row count: 27
      │ estimated max memory allocated: 100 KiB
      │ estimated max sql temp disk usage: 0 B
      │ equality: (waiting_txn_fingerprint_id) = (transaction_fingerprint_id)
      │ right cols are key
      │
      ├── • hash join
      │   │ nodes: n1
      │   │ regions: us-east1
      │   │ actual row count: 27
      │   │ estimated max memory allocated: 100 KiB
      │   │ estimated max sql temp disk usage: 0 B
      │   │ equality: (blocking_txn_fingerprint_id) = (transaction_fingerprint_id)
      │   │ right cols are key
      │   │
      │   ├── • virtual table
      │   │     nodes: n1
      │   │     regions: us-east1
      │   │     actual row count: 27
      │   │     table: transaction_contention_events@primary
      │   │
      │   └── • group (hash)
      │       │ nodes: n1
      │       │ regions: us-east1
      │       │ actual row count: 124
      │       │ estimated max memory allocated: 260 KiB
      │       │ estimated max sql temp disk usage: 0 B
      │       │ group by: transaction_fingerprint_id
      │       │
      │       └── • render
      │           │ nodes: n1
      │           │ regions: us-east1
      │           │ actual row count: 188
      │           │ estimated max memory allocated: 750 KiB
      │           │ estimated max sql temp disk usage: 0 B
      │           │
      │           └── • group (hash)
      │               │ nodes: n1
      │               │ regions: us-east1
      │               │ actual row count: 188
      │               │ estimated max memory allocated: 750 KiB
      │               │ estimated max sql temp disk usage: 0 B
      │               │ group by: aggregated_ts, fingerprint_id, transaction_fingerprint_id, plan_hash, app_name, aggregation_interval
      │               │
      │               └── • union all
      │                   │ nodes: n1
      │                   │ regions: us-east1
      │                   │ actual row count: 200
      │                   │
      │                   ├── • virtual table
      │                   │     nodes: n1
      │                   │     regions: us-east1
      │                   │     actual row count: 12
      │                   │     table: cluster_statement_statistics@primary
      │                   │
      │                   └── • scan
      │                         nodes: n1
      │                         regions: us-east1
      │                         actual row count: 188
      │                         KV time: 15ms
      │                         KV contention time: 0µs
      │                         KV rows read: 188
      │                         KV bytes read: 326 KiB
      │                         estimated max memory allocated: 390 KiB
      │                         missing stats
      │                         table: statement_statistics@primary
      │                         spans: FULL SCAN
      │
      └── • group (hash)
          │ nodes: n1
          │ regions: us-east1
          │ actual row count: 124
          │ estimated max memory allocated: 260 KiB
          │ estimated max sql temp disk usage: 0 B
          │ group by: transaction_fingerprint_id
          │
          └── • render
              │ nodes: n1
              │ regions: us-east1
              │ actual row count: 188
              │ estimated max memory allocated: 750 KiB
              │ estimated max sql temp disk usage: 0 B
              │
              └── • group (hash)
                  │ nodes: n1
                  │ regions: us-east1
                  │ actual row count: 188
                  │ estimated max memory allocated: 750 KiB
                  │ estimated max sql temp disk usage: 0 B
                  │ group by: aggregated_ts, fingerprint_id, transaction_fingerprint_id, plan_hash, app_name, aggregation_interval
                  │
                  └── • union all
                      │ nodes: n1
                      │ regions: us-east1
                      │ actual row count: 200
                      │
                      ├── • virtual table
                      │     nodes: n1
                      │     regions: us-east1
                      │     actual row count: 12
                      │     table: cluster_statement_statistics@primary
                      │
                      └── • scan
                            nodes: n1
                            regions: us-east1
                            actual row count: 188
                            KV time: 18ms
                            KV contention time: 0µs
                            KV rows read: 188
                            KV bytes read: 326 KiB
                            estimated max memory allocated: 390 KiB
                            missing stats
                            table: statement_statistics@primary
                            spans: FULL SCAN
(169 rows)


Time: 71ms total (execution 70ms / network 1ms)

As-is, this query performs a lot of joins and full scans across several tables. It's quite expensive when compared to a simpler view (crdb_internal.cluster_contended_keys):

root@127.0.0.1:26257/movr> explain analyze (SELECT                                                                                                                                                                                                     database_name,                                                                                                                                                                                                                                     schema_name,                                                                                                                                                                                                                                       name,                                                                                                                                                                                                                                              index_name,                                                                                                                                                                                                                                        crdb_internal.pretty_key(key, 0),                                                                                                                                                                                                                  sum(count)                                                                                                                                                                                                                                       FROM                                                                                                                                                                                                                                                 crdb_internal.cluster_contention_events,                                                                                                                                                                                                           crdb_internal.tables,                                                                                                                                                                                                                              crdb_internal.table_indexes                                                                                                                                                                                                                      WHERE                                                                                                                                                                                                                                                crdb_internal.cluster_contention_events.index_id                                                                                                                                                                                                   = crdb_internal.table_indexes.index_id                                                                                                                                                                                                             AND crdb_internal.cluster_contention_events.table_id                                                                                                                                                                                                 = crdb_internal.table_indexes.descriptor_id                                                                                                                                                                                                      AND crdb_internal.cluster_contention_events.table_id                                                                                                                                                                                                 = crdb_internal.tables.table_id                                                                                                                                                                                                                GROUP BY                                                                                                                                                                                                                                             database_name, schema_name, name, index_name, key);
                                    info
----------------------------------------------------------------------------
  planning time: 581µs
  execution time: 17ms
  distribution: local
  vectorized: true
  maximum memory usage: 380 KiB
  network usage: 0 B (0 messages)
  regions: us-east1

  • render
  │ nodes: n1
  │ regions: us-east1
  │ actual row count: 26
  │ estimated max memory allocated: 160 KiB
  │ estimated max sql temp disk usage: 0 B
  │
  └── • group (hash)
      │ nodes: n1
      │ regions: us-east1
      │ actual row count: 26
      │ estimated max memory allocated: 160 KiB
      │ estimated max sql temp disk usage: 0 B
      │ group by: key, name, database_name, schema_name, index_name
      │
      └── • hash join
          │ nodes: n1
          │ regions: us-east1
          │ actual row count: 26
          │ estimated max memory allocated: 70 KiB
          │ estimated max sql temp disk usage: 0 B
          │ equality: (table_id) = (descriptor_id)
          │
          ├── • virtual table
          │     nodes: n1
          │     regions: us-east1
          │     actual row count: 330
          │     table: tables@primary
          │
          └── • hash join
              │ nodes: n1
              │ regions: us-east1
              │ actual row count: 26
              │ estimated max memory allocated: 60 KiB
              │ estimated max sql temp disk usage: 0 B
              │ equality: (index_id, table_id) = (index_id, descriptor_id)
              │
              ├── • virtual table
              │     nodes: n1
              │     regions: us-east1
              │     actual row count: 27
              │     table: cluster_contention_events@primary
              │
              └── • virtual table
                    nodes: n1
                    regions: us-east1
                    actual row count: 10
                    table: table_indexes@primary
(56 rows)


Time: 19ms total (execution 18ms / network 1ms)

@kevin-v-ngo Do we want to simplify the view at all, to make this query less expensive? Or should we just try to make the CREATE statement as efficient as we can while keeping the same information?

@ericharmeling
Copy link
Contributor

We can actually simplify this a bit using the crdb_internal.cluster_contended_keys view...

CREATE VIEW cluster_contended_transactions (
  blocking_txn_fingerprint_id, blocking_queries, 
  waiting_txn_fingerprint_id, waiting_queries, 
  database_name, schema_name, table_name, 
  index_name, key
) AS 
SELECT 
  blocking_txn_fingerprint_id, 
  blocking_queries, 
  waiting_txn_fingerprint_id, 
  waiting_queries, 
  database_name, 
  schema_name, 
  table_name, 
  index_name,
  contending_key
FROM 
  crdb_internal.transaction_contention_events AS tce 
  JOIN crdb_internal.cluster_contended_keys AS ctk ON ctk.key = crdb_internal.pretty_key(tce.contending_key, 0) 
  JOIN (
    SELECT 
      transaction_fingerprint_id, 
      array_agg(metadata ->> 'query') AS waiting_queries 
    FROM 
      crdb_internal.statement_statistics 
    GROUP BY 
      transaction_fingerprint_id
  ) AS wqs ON wqs.transaction_fingerprint_id = tce.waiting_txn_fingerprint_id 
  JOIN (
    SELECT 
      transaction_fingerprint_id, 
      array_agg(metadata ->> 'query') AS blocking_queries 
    FROM 
      crdb_internal.statement_statistics 
    GROUP BY 
      transaction_fingerprint_id
  ) AS bqs ON bqs.transaction_fingerprint_id = tce.blocking_txn_fingerprint_id;

@ericharmeling
Copy link
Contributor

ericharmeling commented Sep 7, 2022

@kevin-v-ngo I'm not sure this is a quick win at this point. Might be best to put it on the backlog. We should spend some time thinking about what we want the view to look like (view name, column names, data types, query, etc).

Also - the work on transaction-level execution insights might meet this need.

WDYT?

@ericharmeling ericharmeling removed their assignment Mar 29, 2023
@kevin-v-ngo kevin-v-ngo moved this from Quick Win to Backlog in Cluster Observability May 24, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-sql-cli-observability Issues related to surfacing SQL observability in SHOW, CRDB_INTERNAL, SYSTEM, etc. C-enhancement Solution expected to add code/behavior + preserve backward-compat (pg compat issues are exception) T-observability
Projects
No open projects
Development

No branches or pull requests

3 participants