Explaining Slow Plan Phase

Hello,

I’m trying to debug a slow UPDATE statement that seems to put most of its time into the Plan phase of execution.

The statement tries to do a conditional update as follows:
UPDATE resources SET version_id = CASE WHEN (resources.json = $5) AND (resources.version_type = $6) THEN resources.version_id ELSE gen_random_uuid() END, operation = CASE WHEN $4 = _ THEN _ WHEN resources.operation = _ THEN _ WHEN (resources.json = $5) AND (resources.version_type = $6) THEN _ ELSE _ END, updated_at = CASE WHEN (resources.json = $5) AND (resources.version_type = $6) THEN resources.updated_at ELSE greatest(statement_timestamp(), resources.updated_at + _::INTERVAL) END, json = $5, version_type = $6 WHERE (((tenant = $1) AND (id = $2)) AND (resource_type = $3)) AND (version_id = $7) RETURNING operation, updated_at, version_id.

The timings CockroachDB reports are as follows:
Parse: 0ns
Plan: 120.7ms avg latency (73ms std dev)
Run: 2.0ms
Overhead: 166.7us

I can’t quite figure out why it would take so long to plan the query. Is it the many CASEs, the greatest check for strict monotonicity, the gen_random_uuid() latency, or something else?

Thanks!

Hi there,

You can look at the logical plan on the statements page on the admin UI.

Alternatively you can run EXPLAIN in front of the query to see the plan.

See: https://www.cockroachlabs.com/docs/stable/explain.html

Best,
Matt

Hi Matt,

The explain looks pretty reasonable, but I’m trying to understand why it’s explicitly the “Plan” phase that takes most of the time. If the query plan generated by the EXPLAIN was not efficient, wouldn’t that time show up in the “Run” phase?

The Logical Plan:
⚬ Render
render = [operation, updated_at, version_id]
⚬ Render
render = [version_id, updated_at, operation]
⚬ Run
⚬ Update
table = resources
set = version_id, updated_at, json, operation, version_type
strategy = updater
⚬ Render
render = [tenant, id, resource_type, version_id, updated_at, json, operation, owner, version_type, CASE WHEN (json = _) AND (version_type = _) THEN version_id ELSE gen_random_uuid() END, CASE WHEN (json = _) AND (version_type = _) THEN updated_at ELSE greatest(statement_timestamp(), updated_at + _) END, _, CASE WHEN operation = _ THEN _ WHEN (json = _) AND (version_type = _) THEN _ ELSE _ END, _]
⚬ Scan
table = resources@primary
filter = version_id = _
spans = 1 span

(It should be ok that we filter on version_id because there should only be one run to filter after using the primary index.)

Hey, yes you are correct.

It may be the case that the gen_random_uuid() is causing the latency, are you able to test that query without it?

Additionally, name resolution can cause latency the irst tie a table is used in a transaction.

Replacing gen_random_uuid with a UUID we generate outside Cockroach appears to have reduced the latency. Thanks for the help, Matt!