Product DocumentationAppearance
sys.log_query
This view records the history of SQL operations and bulk loads performed over the past seven days (by default).
Note: The statistical values recorded in this view are also available via the Query Details tabs in the SMC.
User accounts only see the queries they submit. Superuser accounts see all queries. (Commands executed by internal superusers, such as yellowbrick, are not logged.)
| Column Name | Data Type | Description |
|---|---|---|
| query_id | bigint | Unique query ID. This view contains entries for ybload operations as well as SQL queries. |
| parent_id | bigint | ID of the parent query when a query has subqueries. (This column is always null in sys.query.) |
| prior_id | bigint | The previous query ID if the query was restarted in another resource pool. You may see a sequence of IDs for the same query if it is restarted more than once. |
| original_id | bigint | The original query ID of a query that was restarted. |
| transaction_id | bigint | Unique transaction ID. |
| plan_id | varchar(64) | Unique query plan ID. |
| status | varchar(255) | The final state of the query. A status code of 00000 means that the query completed successfully. Other error codes are returned for failure conditions, such as out-of-memory errors. (See sys.query for a list of state values.) |
| requeue_status | varchar(255) | The status of the query if it was restarted or moved. |
| user_name | varchar(255) | User who ran the query. |
| application_name | varchar(255) | Name of the application that ran the query, such as ybsql, yb-smc, or ybload. The application name for replication operations is replication service. |
| database_name | varchar(255) | Name of the database where the query was run. |
| session_id | bigint | Unique ID of the session. |
| tags | varchar(255) | Query tags in the system, as defined with a SET YBD_QUERY_TAGS command. Tags may be logged based on WLM rule processing. |
| type | varchar(255) | Type of query, such as select, insert, update, delete, load, create, drop. |
| submit_time | timestamptz | When the front-end database received the query. |
| start_time | timestamptz | When the query entered a workload management (WLM) queue. |
| execution_time | timestamptz | When the query started execution on the worker nodes. This timestamp is logged when the query reaches a worker node and starts spending worker time. This column contains NULL if the query did not start (see the status column). |
| end_time | timestamptz | When the query completed execution. |
| planning_ms | decimal(18,3) | Query planning interval, in milliseconds: how much time was spent between the submit_time and when query planning completed. |
| lock_ms | decimal(18,3) | Total time (in milliseconds) spent waiting for locks on tables during query execution. |
| wait_admission_ms | decimal(18,3) | How long, in milliseconds, a query waited for admission to the system because the maximum number of concurrent connections was reached (this limit defaults to 500). This wait time has an impact on total query execution time. |
| wait_concurrency_ms | decimal(18,3) | How long the query waited because a "throttle" rule prevented the query from being run (different from time spent waiting in a queue). See Throttling Concurrency. |
| queue_ms | decimal(18,3) | How long the query waited in a workload management (WLM) queue before being executed (in milliseconds). |
| prepare_ms | decimal(18,3) | How much time was spent on query compilation (in milliseconds). |
| runtime_ms | decimal(18,3) | Total wall clock time between start_time and end_time (or current time), in milliseconds. |
| runtime_execution_ms | decimal(18,3) | How long the query spent executing on the worker nodes (in milliseconds). |
| spool_ms | decimal(18,3) | Time, in milliseconds, required to spool rows from the worker nodes to the manager node (usually a small number), combined with the time spent by the client application to fetch all the results. If the query result set is less than 8MB, spool_ms shows 0, regardless of how long the client application takes to fetch the results. |
| total_ms | decimal(18,3) | Total time (in milliseconds) from either submission to completion or submission to the current time. |
| io_read_bytes | bigint | Number of bytes read by the query. |
| io_write_bytes | bigint | Number of bytes written by the query. |
| io_spill_read_bytes | bigint | Number of bytes the query has read back from temporary storage on disk. This number may be lower than io_spill_write_bytes (for example, if the query has a LIMIT clause). This column returns 0 for queries that run on the worker nodes without spilling. For queries that did not reach the worker nodes, this column returns null. |
| io_spill_write_bytes | bigint | Number of bytes the query has written (spilled) to disk, using temporary storage. This column returns 0 for queries that run on the worker nodes without spilling. For queries that did not reach the worker nodes, this column returns null. |
| io_spill_space_bytes | bigint | The maximum temporary space used at any given time on any worker. This value is very useful when you are setting up spill space allocation for WLM resource pools. |
| io_network_bytes | bigint | Number of bytes moved internally over the network on the cluster (manager node to workers and vice versa). This number does not include data being returned to the client. |
| avg_cpu_percent | decimal(9,2) | Average CPU usage for the query (a percentage). |
| rows_inserted | bigint | Number of rows inserted by the query. |
| rows_deleted | bigint | Number of rows deleted by the query. For UPDATE statements, both rows_deleted and rows_inserted are both >0. |
| rows_returned | bigint | Number of rows the query returned to the client. |
| memory_bytes | bigint | Maximum amount of memory consumed on a worker that ran this query. |
| memory_total_bytes | bigint | Total amount of memory consumed by the query on the whole cluster. |
| memory_estimated_bytes | bigint | Estimated amount of memory expected to be consumed by the query. |
| memory_required_bytes | bigint | Amount of memory minimally required to run the query. |
| memory_granted_bytes | bigint | Amount of memory actually given to the query in its assigned resource pool and execution slot. |
| memory_estimate_confidence | varchar(16) | None (no confidence), Low, High, or Unknown. These values describe the degree to which the estimated memory is thought to be reliable. |
| cost | real | The estimated cost of running the query, determined by the planner; 0 is logged for some operations, such as DROP TABLE and ybload. |
| priority | varchar(255) | WLM query priority: normal, low, high, or critical. |
| query_text | varchar(63488) | SQL text of the query. For readability the text is broken into multiple lines, with each line separated by a plus sign (+). This is the SQL text of the original query, not of any subplans currently running. |
| pool_id | varchar(128) | Resource pool that the query was assigned to. |
| slot | integer | Execution slot number for the query, within its resource pool. Each pool has a fixed maximum and minimum number of slots. |
Examples
Return the total running time for a series of PREPARE statements:
premdb=# select query_id, end_time-submit_time total, trim(query_text)
from sys.log_query where type='insert' and query_text like 'prepare%' order by query_id;
query_id | total | btrim
----------+--------------+-----------------------------------------------------------------------------------------------------------
871315 | 00:00:00.966 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871337 | 00:00:00.886 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871353 | 00:00:00.887 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871369 | 00:00:00.865 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871385 | 00:00:00.957 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871401 | 00:00:00.957 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871417 | 00:00:00.086 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871426 | 00:00:00.085 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871435 | 00:00:00.066 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871444 | 00:00:00.047 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871453 | 00:00:00.067 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
871462 | 00:00:00.056 | prepare moment(varchar(5)) as insert into newmatchstats select seasonid,matchday,htid,atid,$1 from match;
...Return runtime statistics and the SQL text for a single query.
yellowbrick=# select query_id, type, submit_time, start_time, execution_time, end_time, end_time-submit_time total, trim(query_text)
from sys.log_query where query_id=19213;
query_id | type | submit_time | start_time | execution_time | end_time | total | btrim
----------+--------+---------------------------+----------------------------+----------------------------+----------------------------+--------------+--------------------------------------------------
19213 | insert | 2017-02-17 15:15:36.46-08 | 2017-02-17 15:15:36.809-08 | 2017-02-17 15:15:37.893-08 | 2017-02-17 15:15:37.993-08 | 00:00:01.533 | insert into awayteam select atid,name from team;
(1 row)Join the sys.log_query, sys.log_query_analyze, and sys.log_query_explain views to return statistics and plan information for a single query.
premdb=# select a.*, e.query_plan
from sys.log_query_analyze a join sys.log_query q on q.query_id = a.query_id
join sys.log_query_explain e on e.plan_id = q.plan_id and e.node_id = a.node_id
where q.query_id = 44864;
-[ RECORD 1 ]--------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
query_id | 44864
node_id | 0
rows_planned | 1
rows_actual | 20
memory_planned_bytes | 8388848
memory_actual_bytes | 524528
io_read_bytes | 0
io_write_bytes | 0
io_network_bytes | 859
io_network_count | 5
runtime_ms | 0.000
skew | 0
detail | [NULL]
query_plan | SELECT +
| (t1.name, SUM(SUM(SUBSTRING(m1.ftscore, 1, 1)::INT4::INT8)), SUM(SUM(SUBSTRING(m1.ftscore, 3, 1)::INT4::INT8)), (SUM(SUM(SUBSTRING(m1.ftscore, 1, 1)::INT4::INT8)) + SUM(SUM(SUBSTRING(m1.ftscore, 3, 1)::INT4::INT8))))+
| distribute single
-[ RECORD 2 ]--------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
query_id | 44864
node_id | 2
rows_planned | 1
rows_actual | 20
memory_planned_bytes | 17825792
memory_actual_bytes | 524288
io_read_bytes | 0
io_write_bytes | 0
io_network_bytes | 0
io_network_count | 0
runtime_ms | 0.155
skew | 0
detail | [NULL]
query_plan | DISTRIBUTE SORT +
| (t1.name, SUM(SUM(SUBSTRING(m1.ftscore, 1, 1)::INT4::INT8)), SUM(SUM(SUBSTRING(m1.ftscore, 3, 1)::INT4::INT8)), (SUM(SUM(SUBSTRING(m1.ftscore, 1, 1)::INT4::INT8)) + SUM(SUM(SUBSTRING(m1.ftscore, 3, 1)::INT4::INT8))))+
| distribute single
-[ RECORD 3 ]--------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
query_id | 44864
...Return the 10 longest-running operations in terms of total running time:
premdb=# select query_id, type, submit_time, end_time, total_ms, rank() over(order by total_ms desc) from sys.log_query limit 10;
query_id | type | submit_time | end_time | total_ms | rank
----------+---------+----------------------------+-------------------------------+----------+------
20127 | create | 2017-11-28 11:36:03.121-08 | 2017-11-28 11:36:04.550437-08 | 1429.437 | 1
20136 | analyze | 2017-11-28 11:36:03.121-08 | 2017-11-28 11:36:04.548579-08 | 1427.579 | 2
19176 | insert | 2017-11-28 11:32:00.854-08 | 2017-11-28 11:32:02.214419-08 | 1360.419 | 3
19204 | select | 2017-11-28 11:32:02.326-08 | 2017-11-28 11:32:03.641269-08 | 1315.269 | 4
20139 | session | 2017-11-28 11:36:04.554-08 | 2017-11-28 11:36:05.841143-08 | 1287.143 | 5
20081 | select | 2017-11-28 11:35:59.25-08 | 2017-11-28 11:36:00.427285-08 | 1177.285 | 6
20216 | insert | 2017-11-28 11:36:10.716-08 | 2017-11-28 11:36:11.744655-08 | 1028.655 | 7
20179 | insert | 2017-11-28 11:36:07.801-08 | 2017-11-28 11:36:08.794765-08 | 993.765 | 8
20169 | insert | 2017-11-28 11:36:06.811-08 | 2017-11-28 11:36:07.799361-08 | 988.361 | 9
20189 | insert | 2017-11-28 11:36:08.796-08 | 2017-11-28 11:36:09.771835-08 | 975.835 | 10
(10 rows)Return the five longest-running database replication restore operations that started on a specific date:
premdb=# select query_id, transaction_id, user_name, application_name, database_name, type, total_ms, start_time from sys.log_query
where application_name='replication service' and type='restore' and start_time::date='2020-04-03'
order by total_ms desc limit 5;
query_id | transaction_id | user_name | application_name | database_name | type | total_ms | start_time
----------+----------------+--------------------+---------------------+-------------------+---------+-----------+----------------------------
98093 | 17980 | sys_ybd_replicator | replication service | premdb_replicated | restore | 15140.243 | 2020-04-03 13:20:20.704-07
40248 | 5492 | sys_ybd_replicator | replication service | premdb_replicated | restore | 11287.063 | 2020-04-03 12:34:20.885-07
38158 | 4998 | sys_ybd_replicator | replication service | premdb_replicated | restore | 3855.906 | 2020-04-03 12:33:21.077-07
33489 | 3829 | sys_ybd_replicator | replication service | premdb_replicated | restore | 3304.325 | 2020-04-03 12:30:36.281-07
33167 | 3829 | sys_ybd_replicator | replication service | premdb_replicated | restore | 1919.030 | 2020-04-03 12:30:32.753-07
(5 rows)Parent topic:System Views