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.
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
}
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.