sql: collect additional runtime query statistics

[dianasaur323]

This is a stepping stone towards more reporting and query analysis tooling, but for now, it would also provide a lot of value when it comes to helping us debug the performance of queries. We do need to set the stage to build better debugging tools going into 2.1.

The information below will be added to SHOW TRACE

• Memory usage per processor
• Amount of data moved through each stream or processor (# of rows)
• Total time spent on each processor
• Stall time on each processor
• Amount of data moved by each processor to external storage (# rows)

cc @RaduBerinde @andreimatei @knz @vivekmenezes

[dianasaur323]

@knz things number of rows, total processing time, and amount of memory, and disk space are possible. If any of these stats are hard to collect, let's punt.

If at all possible, I would also love to capture time spent waiting for a given query.

cc @asubiotto

[vivekmenezes]

I believe we want to return these statistics in SHOW TRACING

[RaduBerinde]

Returning the statistics in SHOW TRACE is a good start. We can also consider adding a SHOW QUERY STATISTICS that is a version of SHOW TRACE that prints out just the stats.

In terms of prioritization, I'd say the most important one is the amount of rows (and/or bytes) moved to external storage, followed by memory used and the amount of data processed, and then the total+stall time.

[andreimatei]

I think this list of information to be collected is good. I would add:

• [ ] Data moved over network streams, measures in #bytes (as opposed to rows)

I'd clarify what we want out of "Total time spent on each processor". The time when a processor started running and when it finished we already have - it corresponds to the processor's span. But that's not very interesting; most of them will live as long as the whole query. What would be very interesting, I think, is some measure of how much CPU it used. But that may be hard to collect; I guess we need some sampling of stacks. Similarly with "stall time" - I'm not sure how we'd measure this cheaply. Perhaps for stalls we should start by instrumenting the lowest level of SQL - i.e. kvFetcher - and measure explicitly its ScanRequests; we could aggregate these stats just for the TableReader processor, which seems more tractable to me.

As for presentations, I agree that SHOW TRACE is a good start; namely, I think we should log these stats as regular log messages, and they'll make it to the trace that way. Separately, we should also output them as distsql metadata, even if initially we don't do anything with the metadata.

[knz]

@asubiotto to answer your offline question - how to structure this information and eventually present it.

The place we need to get at eventually is to attach each of these metrics to the specific stage in the query plan that they are measuring. Eventually we'll want at least to present an EXPLAIN(STATISTICS) that looks and feels like pg's, and we'll want to annotate the distsql plan with collected execution statistics.

Now the question is really how to get there.

What I have in mind is the following:

• during logical planning, number each node in the logical plan -- give each node a unique number (identifier) within the query.
• during physical planning, copy the logical node identifier to the processors that implement the operation. If multiple processors implement a single logical plan node, then copy the same identifier over to all of them, but perhaps generate separate processor IDs too.
• collect the information during execution,
• at the end, dump it in the trace (like suggested above)
• extend the EXPLAIN logic (both EXPLAIN(PLAN) for logical plans and EXPLAIN(DISTSQL) for physical plans -- btw I hate the keywords "PLAN" and "DISTSQL" but that's irrelevant here --) with a new mode that builds the plan, runs the query, then analyzes the trace to extract the statistics per node, then shows the plan (eithe rlogical or physical) with the statistics in each node.

The heart of the "presentation" stage here is an algorithm that scans/parses/analyzes a trace and constructs a dictionary, from plan node ID to stats. Initially (in scope for you) we'll showcase stats collection with EXPLAIN, but soon after that' we'll also collect this information in memory so as to show it in the admin UI, etc. (That's out of scope for you now.)

[asubiotto]

Thanks everyone!

[asubiotto]

Here is how I think I'm going to proceed with this work:

• [x] Add basic stat collection code and add to tableReader, outputting to trace:
  • PR: #24529
• [x] Add collected stats to span tags:
  • Issue: #25299
  • PR: #25296
• [x] Add processor identifiers
  • Issue: #25301
  • PR: #25513
• [x] Overlay stats in EXPLAIN (DISTSQL)
  • PR: #25849
• [x] Add to all other processors
  • Issue: #25743
• [x] Collect remaining stats
  • Issues: #26647, #26646