07782a2b13
- JSON output format has changed to move the rows to under a `rows` property, with timing information under the `metadata` property - Update timing display to show rows returned and rows fetched, as well as adding verbose mode which lists all scans - Use enums for output mode and timing mode - timing is now either `on`, `off` or `verbose` - Bugfix: ensure error is returned from ExecuteSystemClientCall. Closes #4246
6.3 KiB
Steampipe CLI .timing output
CLI Implementation
When the --timing flag is enabled, the Steampipe CLI outputs the row count, number of hydrate calls and the time taken to execute the query.
The timing data is stored by the FDW in the foreign table steampipe_internal.steampipe_scan_metadata.
> select * from steampipe_internal.steampipe_scan_metadata
+-----+------------------+-----------+--------------+---------------+---------------------------+----------+--------------------------------------+-------+---------------------------------------+
| id | table | cache_hit | rows_fetched | hydrate_calls | start_time | duration | columns | limit | quals |
+-----+------------------+-----------+--------------+---------------+---------------------------+----------+--------------------------------------+-------+---------------------------------------+
| 191 | aws_ec2_instance | false | 1 | 0 | 2024-04-04T09:29:52+01:00 | 439 | ["instance_id","vpc_id","subnet_id"] | 0 | [ |
| | | | | | | | | | { |
| | | | | | | | | | "column": "subnet_id", |
| | | | | | | | | | "operator": "=", |
| | | | | | | | | | "value": "subnet-0a2c499fc37a6c1fe" |
| | | | | | | | | | } |
| | | | | | | | | | ] |
| | | | | | | | | | |
| 192 | aws_ec2_instance | false | 0 | 0 | 2024-04-04T09:29:53+01:00 | 433 | ["instance_id","vpc_id","subnet_id"] | 0 | [ |
| | | | | | | | | | { |
| | | | | | | | | | "column": "subnet_id", |
| | | | | | | | | | "operator": "=", |
| | | | | | | | | | "value": "subnet-0b8060c3ee31f4ba7" |
| | | | | | | | | | } |
| | | | | | | | | | ] |
| | | | | | | | | | |etc
etc.
Every scan which executes results in a row written to this table, with an incrementing id
The CLI DB client keeps track of the id of previous scan metadata which was read from the steampipe_internal.steampipe_scan_metadata.
Every time the client executes a query, it fetches data from the table with an id greater than the last id read.
A single query may consist of multiple scans so there may be multiple rows written to this table for a single query.
The DB client reads all these rows and combines them to display the timing data for the query.
Populating the steampipe_internal.steampipe_scan_metadata table
For every scan which the FDW executes, it stores ScanMetadata in the Hub struct.
type ScanMetadata struct {
Id int
Table string
CacheHit bool
RowsFetched int64
HydrateCalls int64
Columns []string
Quals map[string]*proto.Quals
Limit int64
StartTime time.Time
Duration time.Duration
}
This is then used to populate steampipe_internal.steampipe_scan_metadata foreign table.:
// AsResultRow returns the ScanMetadata as a map[string]interface which can be returned as a query result
func (m ScanMetadata) AsResultRow() map[string]interface{} {
res := map[string]interface{}{
"id": m.Id,
"table": m.Table,
"cache_hit": m.CacheHit,
"rows_fetched": m.RowsFetched,
"hydrate_calls": m.HydrateCalls,
"start_time": m.StartTime,
"duration": m.Duration.Milliseconds(),
"columns": m.Columns,
}
if m.Limit != -1 {
res["limit"] = m.Limit
}
if len(m.Quals) > 0 {
// ignore error
res["quals"], _ = grpc.QualMapToJSONString(m.Quals)
}
return res
}
Receiving the ScanMetadata from the plugin
The Hub ScanMetadata is populated by the scan iterator which executed the scan.
NOTE: if the query is for an aggregator connection, the scan iterator will have multiple ScanMetadata entries,
one per connection. These are summed when populating scan metadata on the Hub.
Every result row which the plugin streams to the FDW also contains QueryMetadata (the protobuf representation of ScanMetadata).
The iterator has a map of scan metadata, keyed by connection (to support aggregators).
When a row is received from the result stream, the metadata for that connection is replaced.