Query History

Overview

A high-frequency event-tracing feature has been introduced in SingleStore 8.5 that offers a robust infrastructure and method for tracing events that are expected to occur frequently. Additional trace events will be added over time.

Query event tracing, the first of this event-tracing feature, is designed to help identify which queries take the longest or that fail so they can be isolated and optimized. This feature is at the core of Query History which displays these query trace events over time.

For query execution reporting, Query_completion is the initial event type to be implemented, where each query execution and its details can be traced and viewed in near real-time.

Query event traces are configurable, where a query execution may only be traced if it takes longer than, for example, 1,000 milliseconds (1 second) to run, where the query text may be set to either be included or omitted.

Event Type	`Query_completion`
Engine Variable	`trace_events_queue_size` Set the value of this engine variable to `0` to turn off query event tracing
Parameter	Value(s)
Capture query text?	`Query_text = on` `Query_text = off`
Record queries that take x amount of time to complete, in milliseconds	`Duration_threshold_ms` = x While `Duration_threshold_ms` can be set to any millisecond value, setting its value to `0` will negatively impact the usefulness of this feature and impair the workspace's performance.
Trace all queries that have failed	`Trace_all_failed_executions= on` `Trace_all_failed_executions= off`

Prerequisites

A workspace running SingleStore version 8.5 or later
Access to Query History in the Cloud portal

The MV_TRACE_EVENTS Information Schema

The MV_TRACE_EVENTS information schema is a ring buffer with a size defined by the value of the trace_events_queue_size engine variable. When this limit is reached, the oldest events are overwritten as the buffer wraps around.

While MV_TRACE_EVENTS can be used to view the most recent events that meet a specified criteria, the information displayed is only temporary. As such, the Query History feature in the Cloud portal is recommended for viewing query trace events over time.

View MV_TRACE_EVENTS

The following examples can be used to record those queries that take longer than 1,000 milliseconds, or one second, to run, which can be used to create a collection of all of the expensive events that have occurred over a specified period of time. The results can provide insight into which workloads are the most demanding on a cluster, and can be used for workload and application tuning and debugging.

Successful Queries

Run the following to display those SQL statements that have been executed successfully.

Note that the following steps are provided to demonstrate how the query events are traced, and only provide a glimpse into which queries are captured. To see the list of successful queries over time, you may filter for “successful queries” in Query History.

Note that the trace_events_queue_size value is s set to 16,000,000 bytes by default and can be updated with a new value via the following SQL statement.
SQL
```
SET GLOBAL trace_events_queue_size = 16000000;
```

Enable the Query_completion event type.

SQL

CREATE EVENT TRACE Query_completion WITH (Query_text = on, Duration_threshold_ms = 1000);

Display the traced query events.

SQL

SELECT * FROM information_schema.MV_TRACE_EVENTS;

NODE_ID,NODE_IP,NODE_TYPE,NODE_START_EPOCH_S,EVENT_ID,EVENT_TYPE,TIME,DETAILS
1,127.0.0.1,MA,1698096978,1,Query_completion,2023-10-25 16:39:51.747556,"{""activity_name"":""Select_MV_PROCESS_PERMISSIONS__et_al_453a6b42e2c4cc91"",""connection_id"":44,""context_database"":"""",""duration_ms"":76,""plan_id"":55,""query_text"":""select * from information_schema.mv_trace_events"",""resource_pool_name"":""default_pool"",""start_time"":""2023-10-25 16:39:51.671264"",""success"":1,""user_name"":""root""}"
1,127.0.0.1,MA,1698096978,2,Query_completion,2023-10-25 16:40:17.988318,"{""activity_name"":""Select_MV_PROCESS_PERMISSIONS__et_al_453a6b42e2c4cc91"",""connection_id"":44,""context_database"":"""",""duration_ms"":2,""plan_id"":55,""query_text"":""select * from information_schema.mv_trace_events"",""resource_pool_name"":""default_pool"",""start_time"":""2023-10-25 16:40:17.986134"",""success"":1,""user_name"":""root""}"

The payload that describes an event is stored in the DETAILS JSON field that contains the following fields:

JSON

{
    "user_name": string,              (empty string if the user has been dropped)
    "connection_id": integer,
    "activity_name": string,
    "plan_id": integer,
    "query_text": string,             (on by default; can be sizeable as comments are included)
    "resource_pool_name": string      (empty if no resource pool)
    "success": bool,
    [ "error_code": string, ]	      (field only present if success = false)
    [ "error_message": string, ]      (field only present if success = false)
    "start_time": string (datetime(6)),
    "duration_ms": bigint,
    "context_database": string
}

Note: Currently, when a multi-insert query is traced, a plan_id of -1 is reflected without an associated activity_name.

The following is an example of the DETAILS column JSON output. The query_text contains literals (sanitized via the SECRET function), and includes comments.

JSON

{
    "activity_name":"Select_MV_PROCESS_PERMISSIONS__et_al_453a6b42e2c4cc91",
    "connection_id":44,
    "context_database":"",
    "duration_ms":76,
    "plan_id":55,
    "query_text":"select * from information_schema.mv_trace_events",
    "resource_pool_name":"default_pool",
    "start_time":"2023-10-25 16:39:51.671264",
    "success":1,
    "user_name":"root"
}

Failed Queries

Run the following to display those SQL statements that have failed to execute and the associated reason.

Note that the following steps are provided to demonstrate how the query events are traced, and they only provide a glimpse into which queries are captured. To see the list of failed queries over time, you may filter for “failed queries” in Query History.

Note that the trace_events_queue_size value is s set to 16,000,000 bytes by default and can be updated with a new value via the following SQL statement.
SQL
```
SET GLOBAL trace_events_queue_size = 16000000;
```

Enable the Query_completion event type to capture failed queries.

SQL

CREATE EVENT TRACE Query_completion WITH (Query_text = on, Duration_threshold_ms = 1000, Trace_all_failed_executions= on);

Run the following to display the query events.

SQL

SELECT * FROM information_schema.MV_TRACE_EVENTS;

NODE_ID,NODE_IP,NODE_TYPE,NODE_START_EPOCH_S,EVENT_ID,EVENT_TYPE,TIME,DETAILS
1,127.0.0.1,MA,1698096978,1,Query_completion,2023-10-25 16:39:51.747556,"{""activity_name"":""Select_MV_PROCESS_PERMISSIONS__et_al_453a6b42e2c4cc91"",""connection_id"":44,""context_database"":"""",""duration_ms"":76,""plan_id"":55,""query_text"":""select * from information_schema.mv_trace_events"",""resource_pool_name"":""default_pool"",""start_time"":""2023-10-25 16:39:51.671264"",""success"":1,""user_name"":""root""}"
1,127.0.0.1,MA,1698096978,2,Query_completion,2023-10-25 16:40:17.988318,"{""activity_name"":""Select_MV_PROCESS_PERMISSIONS__et_al_453a6b42e2c4cc91"",""connection_id"":44,""context_database"":"""",""duration_ms"":2,""plan_id"":55,""query_text"":""select * from information_schema.mv_trace_events"",""resource_pool_name"":""default_pool"",""start_time"":""2023-10-25 16:40:17.986134"",""success"":1,""user_name"":""root""}"

Time-Bound Queries

Run the following to display those SQL statements that are time-bound.

Note that the following steps are provided to demonstrate how the query events are traced, and only provide a glimpse into which queries are captured. To see the list of time-bound queries over time, you may filter for “time-bound queries” in Query History.

Note that the trace_events_queue_size value is s set to 16,000,000 bytes by default and can be updated with a new value via the following SQL statement.
SQL
```
SET GLOBAL trace_events_queue_size = 16000000;
```
Run the following to display just those query events that were created since a specified time @t.
SQL
```
SET @t = NOW(6);        /* Or use a desired time instead of the current time */
```