# PROFILE The `PROFILE` command provides detailed resources usage metrics about a query. The output of this command can be visualized using [ Visual Explain](https://docs.singlestore.com/db/v9.1/query-data/query-tuning/singlestore-visual-explain.md). ## Syntax ```sql PROFILE ; ``` > **📝 Note**: Refer to [Remarks](https://docs.singlestore.com/#UUID-af4536ba-863a-2470-11d1-8c66b854bff2.md) for information about supported statements. ```sql SHOW PROFILE [JSON | UI] [PLAN ] [PROCESS ] [PIPELINE ] [INTO OUTFILE ] [ON NODE ]; ``` ## Remarks * Prior to the 8.1 release, `PROFILE` could only be utilized on a manual basis. The command was appended to the beginning of the query to be profiled as shown above. Once the query finished executing, the `SHOW PROFILE` command was run to obtain the profile results. This profiling method is called an explicit profile since the `PROFILE` command is explicitly written with the query. * Now SingleStore offers two automatic profiling (called "auto profiling" hereafter) methods: `FULL` and `LITE`. Auto profiling and explicit profiling share the same query plans, but the difference between them is the level of statistic collecting. Currently, auto profiling is not the default setting. Refer to [Query Performance Tools](https://docs.singlestore.com/db/v9.1/query-data/query-tuning/query-performance-tools.md) for more details about auto profiling. `INSERT...SELECT`, `REPLACE...SELECT` query shapes work with auto profiling. Aggregator result tables cannot be auto profiled. * When you run a `PROFILE` statement, it executes the associated statement and collects resource usage metrics about the statement. The `PROFILE` command works with `SELECT`, `UPDATE`, `INSERT ... SELECT`, and `DELETE` statements, but not `INSERT` statements. * After the query has executed, run the `SHOW PROFILE` statement to display the collected metrics. Like the [EXPLAIN](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-manipulation-language-dml/explain.md) statement, `SHOW PROFILE` displays query execution operations as a tree, where the operator at the top is the last executed before returning the result to the client, and operators below are executed before their parents; however, `SHOW PROFILE` additionally displays resource usage metrics for the operators in the execution tree. * To get more accurate resource usage metrics of a query, run the `PROFILE` statement twice followed by the `SHOW PROFILE` statement. > **📝 Note**: You must be connected to the Master Aggregator when running this command on reference tables. * The `SHOW PROFILE JSON` command returns the profile information of a query in JSON (machine readable format). To get this information, run the `PROFILE` command followed by the `SHOW PROFILE JSON` command. This information includes detailed statistics about some operators and statistics on compilation time (displayed under `compile_time_stats`). Refer to [Example: Profile Data](https://docs.singlestore.com/#UUID-7c1ff569-ecf3-d0a6-ee11-80da4ec92e59.md) for details. * If the variable `profile_for_debug` is set to `ON`, `SHOW PROFILE JSON` outputs additional data that is useful for troubleshooting query optimizer issues. Refer to [Non-Sync Variables List](https://docs.singlestore.com/db/v9.1/reference/configuration-reference/engine-variables/list-of-engine-variables/#non-sync-variables-list.md) for more information on this variable. For all possible additional data output, refer to [PROFILE JSON Metrics](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-manipulation-language-dml/profile.md). Refer to [Example: Additional Profile Data](https://docs.singlestore.com/#UUID-5d5c7ccb-0b13-e6e4-c1ee-11ef2c3118a1.md) for related information. * Run the `SHOW PROFILE PLAN` command with a specific `plan_id` to display profile information (optionally in JSON format) for any plan in the cache that was run in `PROFILE` mode. For information related to `plan_id`, refer to the [SHOW PLAN](https://docs.singlestore.com/db/v9.1/reference/sql-reference/show-commands/show-plan.md) topic. ```sql ---To display profile information for a specific plan SHOW PROFILE PLAN 4; ``` ```sql ---To display the profile information for a specific plan in JSON format SHOW PROFILE JSON PLAN 4; ``` * To write the result of a profile query to a file, use the `INTO OUTFILE file_name` clause. It creates a new file at the specified location and writes the query profile details to the file. Enter the absolute path to the file as the `file_name` parameter. The output file can be a JSON or a text file. > **📝 Note**: If the file already exists, then SingleStore throws an error. * To write the profile information of a query in JSON format to a file: ```sql SHOW PROFILE JSON INTO OUTFILE '/tmp/testprof.json'; ``` * To write the profile information of a query to a text file: ```sql SHOW PROFILE INTO OUTFILE '/tmp/testprof.txt'; ``` * To write the profile statistics of a specific plan ID to a file: ```sql SHOW PROFILE PLAN 7 INTO OUTFILE '/tmp/profile_plan7.txt'; ``` * To write the profile statistics of a specific plan ID in JSON format to a file: ```sql SHOW PROFILE JSON PLAN 7 INTO OUTFILE '/tmp/profjson_plan7.json'; ``` * To view the profile statistics of a specific pipeline in JSON format: ```sql SHOW PROFILE JSON PIPELINE pipeline1; ``` * The `SHOW PLAN [JSON] plan_id` command displays the `EXPLAIN` plan of a query. Refer to [SHOW PLAN](https://docs.singlestore.com/db/v9.1/reference/sql-reference/show-commands/show-plan.md) for details. ## Profiling a Hung Query To get information on progress of a query and to debug queries with long execution times, run the `PROFILE` statement in one connection and `SHOW PROFILE PROCESS` in another connection. For example, run the following statements in one connection: ```sql PROFILE select_statement; ``` ```sql SHOW PROFILE; ``` Simultaneously, open another connection and run the `SHOW PROFILE PROCESS` statement while the `PROFILE` statement is in progress: ```sql SHOW PROFILE PROCESS process_id; ``` You can get the process ID from the [SHOW PROCESSLIST](https://docs.singlestore.com/db/v9.1/reference/sql-reference/show-commands/show-processlist.md) command or the [CONNECTION\_ID](https://docs.singlestore.com/db/v9.1/reference/sql-reference/information-functions/connection-id.md) function as follows: ```sql SHOW PROCESSLIST; ``` ```sql SELECT CONNECTION_ID(); ``` If there is a skew between different partitions, then `SHOW PROFILE` displays additional details of the skewed metric. A skewed partition displays in the output of a `SHOW PROFILE` query in the following format: `[memory_usage: v | max:w at partition_x, average: y, std dev: z]` where, * The total across all partitions is `v`. * The partition with the largest amount is partition `x` with memory use `w`. * The average memory usage per partition is `y`. * The standard deviation is `z`. If all data is on one partition, then the `actual_rows` has the same count across all partitions as max on a single partition. The output of `SHOW PROFILE JSON` always displays these additional details, even when there is no skew. ## `PROFILE` Metrics The following table provides a brief explanation of the metrics that are gathered when executing a statement using `PROFILE`. | Metric | Description | | ----------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | `exec_time` | Time spent in running each operator. For HashJoin,`exec_time`is calculated as the time spent in probing the hash table.`build_exec_time`(specific to HashJoin operator) shows the time spent in building the hash table. | | `network_time` | Wait time spent while flushing data to the network. | | `memory_usage` | Memory used by the operator, in kilobytes (KB). | | `network_traffic` | Data sent over the network, in kilobytes (KB). | | `actual_rows` | Number of rows processed by the operator. For example, for`IndexRangeScan`,`actual_rows`is the number of rows scanned. | | `est_table_rows` | Estimated number of rows in a table. This is an attribute of a table, not of an operator. | | `est_filtered` | Estimated number of rows of a table after applying all single-table filters. | | `start_time` | Time difference between the query start and operator execution as`start_time:hh:mm:ss.SSS`. Alternatively, in`start_time: [hh:mm:ss.SSS, hh:mm:ss.SSS]`format, it shows maximum and minimum start time over all threads (partitions). | | `end_time` | Time when the operator finishes execution. | Not all of the above metrics are gathered for queries where execution performance may be hindered by gathering such metrics. ## `PROFILE` Metrics for Columnstore Queries that Use Filters The following table provides a brief explanation of the columnstore metrics that are gathered when running `PROFILE` with a columnstore query that uses filters. These metrics appear after running `SHOW PROFILE JSON`, following `PROFILE`. | Metric | Description | | ---------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | | `columnstore_filter_execution_type` | The type of filter used (full row scan, hash index, or bloom). | | `columnstore_filter_total_rows_in` | The number of rows that the filter predicate was evaluated on. | | `columnstore_filter_total_rows_out` | The number of rows that passed the filter predicate. | | `columnstore_filter_encoded_rows_in` | The number of rows that the filter predicate was evaluated on, using[operations on encoded data](https://docs.singlestore.com/db/v9.1/create-a-database/columnstore.md). | | `columnstore_filter_encoded_rows_out` | The number of rows that passed the filter predicate, using operations on encoded data. | | `columnstore_filter_avg_filters_per_row` | The number of average filtering operations performed on each row\.SingleStorecombines filtering options where possible, but outside of these cases, the following logic is true: if two columns each had a filter applied to them on every row, the`columnstore_filter_avg_per_row`would be 2.0. | | `columnstore_filter_avg_index_filters_per_row` | This is the same as`columnstore_filter_avg_filters_per_row`, but instead looking at filtering on indices, rather than all filters as a group. | | `columnstore_filter_avg_bloom_filters_per_row` | This is the same as`columnstore_filter_avg_filters_per_row`, but instead looking at how many rows are filtered out through use of a bloom filter, rather than all filters as a group. | Whether or not a filter predicate was evaluated using operations on encoded data depends on the filter predicate itself as well as the encodings of the involved columns. If `columnstore_filter_encoded_rows_in` is lower than `columnstore_filter_total_rows_in`, either the filter predicate does not support operations on encoded data or there were some segments with encodings that do not support operations on encoded data. Some filter predicates are children of other filter predicates. This is signaled by indentation levels in the text of the condition attribute. During filter evaluation, either the parent filter predicate is used, or its children are evaluated instead. The `columnstore_filter_total_rows_in` metric can be inspected to find which method of evaluation is used in what proportion. > **❗ Important**: Up-to-date `PROFILE` metrics for columnstore filters are available after the columnstore background flusher has run. The flusher runs automatically on regular intervals. You can also run it manually via [`OPTIMIZE TABLE ... FLUSH`](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-definition-language-ddl/optimize-table.md). Refer to [Example: Write Profile Data to a File](https://docs.singlestore.com/#UUID-e4881a67-1ec6-5de2-86ec-2e560d4dee3e.md) for sample resource usage metrics for a columnstore query that uses filters. ## `PROFILE` Blob Cache Metrics For columnstore tables stored in unlimited storage, there are additional metrics to provide information about the blob cache. | Metric | Description | | ------------------------------------------ | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | blobcache\_total\_blobs\_downloaded | The number of blobs downloaded from unlimited storage due to local blob cache misses. The metric sums up the number of downloaded blobs from all leaf nodes.The metric has the following sub-categories:
  • blobcache_columnar_blobs_downloaded
  • blobcache_inverted_index_blobs_downloaded
  • blobcache_cross_segment_hash_index_blobs_downloaded
  • blobcache_fts_blobs_downloaded
  • blobcache_column_group_blobs_downloaded
| | blobcache\_total\_blobs\_downloaded\_bytes | The number of blob bytes downloaded from unlimited storage due to local blob cache misses. The metric sums up the downloaded blob bytes from all leaf nodes.The metric has the following sub-categories:
  • blobcache_columnar_blobs_downloaded_bytes
  • blobcache_inverted_index_blobs_downloaded_bytes
  • blobcache_cross_segment_hash_index_blobs_downloaded_bytes
  • blobcache_fts_blobs_downloaded_bytes
  • blobcache_column_group_blobs_downloaded_bytes
| | blobcache\_total\_blobs\_accessed | The number of blobs accessed by the query. A blob is "accessed" when the query reads some data from it, regardless of how much data there is. The metric sums up the number of accessed blobs from all leaf nodes. The metric includes blob files that were both initially in the blob cache (cache hit) and downloaded from unlimited storage (cache miss)."Accessed” means the query has read some data from the blob.The metric has the following sub-categories:
  • blobcache_columnar_blobs_accessed
  • blobcache_inverted_index_blobs_accessed
  • blobcache_cross_segment_hash_index_blobs_accessed
  • blobcache_fts_blobs_accessed
  • blobcache_column_group_blobs_accessed
| | blobcache\_total\_blobs\_accessed\_bytes | The number of blob bytes accessed by the query. The metric sums up the number of accessed blob bytes from all leaf nodes.The metric has the following sub-categories:
  • blobcache_columnar_blobs_accessed_bytes
  • blobcache_inverted_index_blobs_accessed_bytes
  • blobcache_cross_segment_hash_index_blobs_accessed_bytes
  • blobcache_fts_blobs_accessed_bytes
  • blobcache_column_group_blobs_accessed_bytes
| | blobcache\_wait\_time\_ms | The time that was spent on waiting for blob cache data. The metric is the maximum waiting time (in milliseconds) from all query threads. To be more specific, query threads run concurrently with blob-downloading threads. This metric measures the time that query threads spend waiting for blob cache data. This metric does not measure the time that download worker threads spend downloading from the network. | ## `PROFILE JSON` Fields When unlimited is enabled, `PROFILE JSON` provides information about the segments and blobs retrieved from unlimited storage to the blob cache (on local disk) under the ColumnStoreScan executor. This information includes segment statistics covering timing and size information of blobs. | Field | Description | | -------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | | `segments_scanned` | The number of segments that were scanned. | | `segments_skipped` | The number of segments that were not scanned due to segment elimination. | | `segments_fully_contained` | The number of segments that were not scanned, because they are fully contained. | | `segments_in_blob_cache` | Represents the number of segments in the blob cache, which did not need retrieval from unlimited storage. | | `number_of_blocks_tested_for_block_elim` | The number of blocks on which sub-segment elimination was run. | | `number_of_blocks_eliminated_for_block_elim` | The number of blocks that were eliminated by sub-segment elimination. | | `column_group_project_rows` | The number of rows scanned using the row index (COLUMN GROUP). | | `column_segment_project_rows` | The number of rows scanned when scanning the individual column segments. | | `blob_fetch_network_time` | The total time spent waiting for blobs to be retrieved over the network. | | `total_blobs_fetched_size` | The total size of blobs retrieved from unlimited storage and stored in the blob cache. | | `blobs_fetched_stats` | Provides detail about various blob sizes and types retrieved. Includes the following fields:
  • columnar_blobs_fetched_size - provides the size of the columnar blobs retrieved.
  • inverted_index_blobs_fetched_size - provides the size of the index blobs within segments.
  • cross_segment_hash_index_blobs_fetched_size - provides the size of index blobs across segments.
  • fts_blobs_fetched_size - provides the size of the full- text search index blobs.
  • column_group_xxxx - provides the size of the row index (COLUMN GROUP) blobs retrieved.
| ## `PROFILE JSON` Metrics with `profile_for_debug` = `ON` The following list shows all additional data included in the output of `SHOW PROFILE JSON` when it is run with the variable `set_profile_for_debug` set to `ON`. Different data is displayed, depending on what is relevant to the query being profiled. For example, in the case that tables included in a query do not have any statistics collected on them, the table statistics metadata will be empty in the output. The debugging information consists of: * DDL for all database objects relevant to the query * Global variable settings * Session variable settings * Table statistics metadata * Sampling cache for filter selectivities * Sampling cache for row counts * Autostats results cache The following commands can be used without needing to set the [profile\_for\_debug](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-manipulation-language-dml/profile/#UUID-ecb6c5eb-1ad0-7cad-5c7b-a6d8cdf6c012.md) session variable. ```sql PROFILE REPRO ; SHOW REPRODUCTION; ``` SingleStore will continue to support the [profile\_for\_debug](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-manipulation-language-dml/profile/#UUID-ecb6c5eb-1ad0-7cad-5c7b-a6d8cdf6c012.md) session variable with the `PROFILE` and `SHOW PROFILE JSON` commands for backward compatibility. Note that the `profile_for_debug` session variable can only be used on fully or partially *executed* queries. To learn how to collect troubleshooting data for queries that *fail in the compilation phase*, refer to the [SHOW REPRODUCTION](https://docs.singlestore.com/db/v9.1/reference/sql-reference/show-commands/show-reproduction.md) command reference. ## `PROFILE JSON` Metrics with `enable_spilling` = `ON` Sometimes, a `GROUP BY` query will use a hash table internally to execute the query, which is known as a HashGroupBy operation. For this operation, when node memory load is above 75% and the hash table (for the current thread) is at least 100MB, the intermediate result of the operation spills to disk in the data/spill directory. Spilling will usually reduce memory usage (can spill at most 64x physical memory), but may result in longer execution time. **Note:** SingleStore recommends to use an SSD for the spilling directory, since it can result in a tenfold increase in performance. The output of `SHOW PROFILE JSON` also includes the following metrics, when the sync variable `enable_spilling` is set to `ON` (starting with version 7.8, `ON` is the default value for this sync variable): * `spill_outputted_rows`: The number of rows spilled to disk * `spill_disk_usage` : The number of bytes spilled to disk The sync variables `spilling_node_memory_threshold_ratio`, `spilling_query_operator_memory_threshold` , and `spilling_minimal_disk_space` (starting with version 7.8) also define the threshold limit to start spilling. Refer to [Sync Variables Lists](https://docs.singlestore.com/db/v9.1/reference/configuration-reference/engine-variables/list-of-engine-variables/#sync-variables-lists.md) for details. ## Visual Profile via SHOW PROFILE UI Using `SHOW PROFILE UI` will generate a URL that loads a visual representation of the query profile. When you open the link, the [Visual Explain](https://docs.singlestore.com/db/v9.1/query-data/query-tuning/singlestore-visual-explain.md) site is loaded and the query profile is displayed. ## Examples ## Example: Profile Data The `SHOW PROFILE JSON` statement displays the compilation and optimizer statistics. This helps to troubleshoot slow query performance and compare the time spent in running versus compiling the query. In this example, the variable `profile_for_debug` is set to `OFF`. For example, run the following `PROFILE` query: ```sql PROFILE SELECT * from Emp; ``` ```output +-----------+---------+ | Name | City | +-----------+---------+ | Sam | Chicago | | Jack | Norway | | Tom | Chicago | | Neil | Chicago | +-----------+---------+ 4 rows in set (0.29 sec) ``` Now run the `SHOW PROFILE JSON` command. The following output is filtered to display only the compilation and optimization details. It has also been tab spaced to increase readability, and may differ from the actual output. ```sql SHOW PROFILE JSON; ``` ```output +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- "query_info":{ "query_text":"profile select * from Emp", "total_runtime_ms":"291", "text_profile":"Gather partitions:all alias:remote_0 actual_rows: 9 exec_time: 0ms start_time: 00:00:00.001 end_time: 00:00:00.143\nProject [Emp.Name, Emp.City] actual_rows: 9 exec_time: 0ms start_time: 00:00:00.139 network_traffic: 0.100000 KB network_time: 1ms\nTableScan trades.Emp actual_rows: 9 exec_time: 0ms start_time: 00:00:00.139\nCompile Total Time: 147ms\n", "compile_time_stats":{ "mbc_emission":"0", "create_mbc_context":"4", "expanding_views":"0", "optimizer_query_rewrites":"1", "optimizer_stats_analyze":"0", "optimizer_stats_other":"0", "optimizer_stats_sampling":"0", "optimizer_setting_up_subselect":"0", "optimizer_distributed_optimizations":"0", "optimizer_enumerate_temporary_tables":"0", "optimizer_singlebox_optimizations_agg":"0", "optimizer_rewrite_estimate_cost":"0", "optimizer_stats_autostats":"0", "ppc_check":"0", "generating_query_mpl":"1", "generating_user_function_mpl":"0", "module_cleaning":"0", "dump_clean_bitcode":"0", "llvm_optimization":"0", "dump_optimized_bitcode":"0", "machine_code_generation":"0", "llvm_printing":"0", "asm_printing":"0", "symbol_resolution":"0", "unknown":"138", "total":"147" } } } | +-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+- 1 row in set (0.00 sec) ``` If you had run `PROFILE` again prior to running `SHOW PROFILE JSON`, the results would have been more accurate. **Note**: The `PROFILE` command can be used for long running queries to analyze the query plan and search for unexpectedly expensive operators. Output the result in JSON format using the `SHOW PROFILE JSON` command to analyze the query plan visually in the [ Visual Explain UI](https://docs.singlestore.com/db/v9.1/query-data/query-tuning/singlestore-visual-explain.md). ## Example: Additional Profile Data This example shows how to run `SHOW PROFILE JSON` with the variable `profile_for_debug` set to `ON` in order to get additional data output beyond what is displayed in the first example where this variable is set to `OFF`. Different data is displayed, depending on what is relevant to the query being profiled. ```sql SET profile_for_debug = on; PROFILE SELECT * FROM t1 JOIN t2 ON t1.b = t2.b; SHOW PROFILE JSON; ``` ```output /* The following JSON output has been truncated to show only the additional data provided with set_profile_for_debug set to ON. */ "debug_info": { "ddl": [ "CREATE DATABASE `db` PARTITIONS 3", "USING `db` CREATE TABLE `t2` ( `a` bigint(11) NOT NULL AUTO_INCREMENT, `b` int(11) DEFAULT NULL, PRIMARY KEY (`a`)) AUTOSTATS_CARDINALITY_MODE=OFF AUTOSTATS_HISTOGRAM_MODE=OFF SQL_MODE=\'STRICT_ALL_TABLES\'", "USING `db` CREATE TABLE `t1` ( `a` bigint(11) NOT NULL AUTO_INCREMENT, `b` int(11) DEFAULT NULL, PRIMARY KEY (`a`)) AUTOSTATS_CARDINALITY_MODE=OFF AUTOSTATS_HISTOGRAM_MODE=OFF SQL_MODE=\'STRICT_ALL_TABLES\'" ], "optimizer_stats": [], "sampling_rowcount_cache": [ { "db": "db", "rowcount": "1", "table": "t1" }, { "db": "db", "rowcount": "4", "table": "t2" } ], "variables": { "as_aggregator": 1, "cardinality_estimation_level": 3, "client_found_rows": 0, "collation_server": 2, "comment from t.py": "t.py normalize_profile_json() is modifying this output - most variables are filtered out of this output, look at t.py for details", "data_conversion_compatibility_level": 0, "default_partitions_per_leaf": 3, "disable_sampling_estimation_with_histograms": 2, "disable_subquery_merge_with_straight_joins": 2, "distributed_optimizer_min_join_size_run_initial_heuristics": 18, "force_bushy_joins": 0, "interpreter_mode": 4, "json_extract_string_collation": 3, "materialize_ctes": 0, "max_subselect_aggregator_rowcount": 0, "resource_pool_is_auto": 0, "resource_pool_statement_selector_function": 4294967300, "sql_mode": 4194304, "sql_select_limit": 1 } }, ``` This example shows how to run `PROFILE REPRO` followed by `SHOW REPRODUCTION` commands that will replace the `SET profile_for_debug=1`; `PROFILE `; and `SHOW PROFILE JSON` series of commands. ```sql PROFILE REPRO SELECT * FROM t; SHOW REPRODUCTION; ``` ```output REPRODUCTION INFO /* The following JSON output has been truncated to show only the additional data provided with set_profile_for_debug set to ON. */     "debug_info":{         "ddl":[     "CREATE DATABASE `test1` PARTITIONS 2",     "USING `test1` CREATE TABLE `t` (\n  `id` bigint(11) NOT NULL AUTO_INCREMENT,\n  `a` int(11) DEFAULT NULL,\n  `b` int(11) DEFAULT NULL,\n  UNIQUE KEY `PRIMARY` (`id`) USING HASH,\n  SHARD KEY `__SHARDKEY` (`id`),\n  KEY `__UNORDERED` () USING CLUSTERED COLUMNSTORE\n) AUTO_INCREMENT=1000000 AUTOSTATS_CARDINALITY_MODE=INCREMENTAL AUTOSTATS_HISTOGRAM_MODE=CREATE AUTOSTATS_SAMPLING=ON SQL_MODE='STRICT_ALL_TABLES'" ],         "variables":{"as_aggregator": 1, "as_leaf": 0, "batch_external_functions": 0, "binary_serialization": 1, "client_found_rows": 1, "collation_server": 2, "datetime_precision_mode": 0, "default_columnstore_table_lock_threshold": 0, "disable_histogram_estimation": 0, "disable_sampling_estimation": 0, "disable_sampling_estimation_with_histograms": 2, "disable_subquery_merge_with_straight_joins": 2, "display_full_estimation_stats": 0, "distributed_optimizer_broadcast_mult": 0, "distributed_optimizer_estimated_restricted_search_cost_bound": 125, "distributed_optimizer_max_join_size": 22, "distributed_optimizer_min_join_size_run_initial_heuristics": 16, "distributed_optimizer_nodes": 0, "distributed_optimizer_old_selectivity_table_threshold": 22, "distributed_optimizer_run_legacy_heuristic": 0, "distributed_optimizer_selectivity_fallback_threshold": 50000000, "distributed_optimizer_unrestricted_search_threshold": 22, "enable_broadcast_left_join": 1, "enable_local_shuffle_group_by": 1, "enable_multipartition_queries": 1, "enable_skiplist_sampling_for_selectivity": 1, "force_bloom_filters": 0, "force_bushy_join_table_limit": 18, "force_bushy_joins": 0, "force_heuristic_rewrites": 0, "force_table_pushdown": 0, "hash_groupby_segment_distinct_values_threshold": 10000, "ignore_insert_into_computed_column": 0, "inlist_precision_limit": 10000, "interpreter_mode": 4, "leaf_pushdown_default": 0, "leaf_pushdown_enable_rowcount": 120000, "materialize_ctes": 1, "max_broadcast_tree_rowcount": 120000, "max_subselect_aggregator_rowcount": 120000, "old_local_join_optimizer": 0, "optimize_constants": 1, "optimize_mpl_before_printing": 0, "optimize_stmt_threshold": 50, "optimizer_beam_width": 10, "optimizer_cross_join_cost": 1.000000, "optimizer_disable_right_join": 0, "optimizer_disable_subselect_to_join": 0, "optimizer_empty_tables_limit": 0, "optimizer_hash_join_cost": 1.000000, "optimizer_merge_join_cost": 1.000000, "optimizer_nested_join_cost": 1.000000, "optimizer_num_partitions": 0, "quadratic_rewrite_size_limit": 200, "query_rewrite_loop_iterations": 1, "reshuffle_group_by_base_cost": 0, "sampling_estimates_for_complex_filters": 1, "singlebox_optimizer_cost_based_threshold": 18, "sql_mode": 4194304, "sql_select_limit": 0, "subquery_merge_with_outer_joins": 3, "cardinality_estimation_level": 3, "data_conversion_compatibility_level": 0, "debug_mode": 0, "default_partitions_per_leaf": 1, "disable_update_delete_distributed_transactions": 0, "enable_alias_space_trim": 0, "enable_spilling": 1, "explicit_defaults_for_timestamp": 1, "json_extract_string_collation": 3, "resource_pool_statement_selector_function": 4294967300, "use_avx2": 1, "use_dstree": 1, "use_joincolumnstore": 1, "node_degree_of_parallelism": 0, "resource_pool_is_auto": 0},         "optimizer_stats":[     {     "version": 2,     "databaseName": "test1",     "tables": [         {             "tableName": "t",             "rowCount": "2048",             "columns": [                 {                     "columnName": "id",                     "nullCount": "0",                     "minValue": "",                     "maxValue": "",                     "cardinality": "2048",                     "density": "0x0p+0",                     "sampleSize": "0",                     "lastUpdated": "1646329049"                 },                 {                     "columnName": "a",                     "nullCount": "0",                     "minValue": "",                     "maxValue": "",                     "cardinality": "101",                     "density": "0x0p+0",                     "sampleSize": "0",                     "lastUpdated": "1646329049"                 },                 {                     "columnName": "b",                     "nullCount": "0",                     "minValue": "",                     "maxValue": "",                     "cardinality": "101",                     "density": "0x0p+0",                     "sampleSize": "0",                     "lastUpdated": "1646329049"                 }             ]         }     ],     "stats": [         {             "tableName": "t",             "columns": [                 {                     "columnName": "id"                 },                 {                     "columnName": "a"                 },                 {                     "columnName": "b"                 }             ]         }     ] } ],         "query_after_rewrites":"SELECT `t`.`id` AS `id`, `t`.`a` AS `a`, `t`.`b` AS `b` FROM  `test1`.`t` as `t`  LIMIT @@SESSION.`sql_select_limit` \/*!90623 OPTION(CLIENT_FOUND_ROWS=1)*\/"         }     } ``` ## Example: Write Profile Data to a File The `INTO OUTFILE file_name` clause is useful to output the profile information of a query/plan to a file. In this example, the variable `profile_for_debug` is set to `OFF`. For example, run the following `PROFILE` query: ```sql PROFILE SELECT * from Emp; ``` Now, run the following command to write the JSON profile information to the `EmpProfile.json` file in the `/tmp` directory. ```sql SHOW PROFILE JSON INTO OUTFILE '/tmp/EmpProfile.json'; ``` To view the contents of the `EmpProfile.json` file, run the following command at the `root` prompt: ``` cat '/tmp/EmpProfile.json'; ``` ## Example: Diagnose Query Performance The `PROFILE` statement is particularly helpful when evaluating distributed query performance, such as a distributed join. Distributed joins that require broadcasts or repartitions are expensive, and the `PROFILE` statement can help you understand how such queries are executed so that they can be optimized. In this example, the variable `profile_for_debug` is set to `OFF`. In the following example, a distributed join is executed to return data about customers and their orders. For demonstration purposes, we loaded simulated statistics for each table. Suppose we have run the query: ```sql SELECT COUNT(*) FROM orders o JOIN customer c WHERE o.custkey = c.custkey and c.mktsegment = 'BUILDING'; ``` Now we want to diagnose why it is slower than expected. It’s best to first execute an `EXPLAIN` statement to understand the execution plan for a query. ```sql EXPLAIN SELECT COUNT(*) FROM orders o JOIN customer c WHERE o.custkey = c.custkey and c.mktsegment = 'BUILDING'; ``` ```output +------------------------------------------------------------------------------------------------------------------------------------------------+ | EXPLAIN | +------------------------------------------------------------------------------------------------------------------------------------------------+ | Project [CAST(COALESCE($0,0) AS SIGNED) AS `count(*)`] | | Aggregate [SUM(remote_0.`count(*)`) AS $0] | | Gather partitions:all est_rows:1 alias:remote_0 | | Project [`count(*)`] est_rows:1 est_select_cost:87,206,400 | | Aggregate [COUNT(*) AS `count(*)`] | | NestedLoopJoin | | |---IndexRangeScan orders AS o, KEY orders_fk1 (o_custkey) scan:[o_custkey = r1.c_custkey] est_table_rows:150,000,000 est_filtered:150,000,000 | | TableScan r1 storage:list stream:no est_table_rows:2,725,200 | | Broadcast [c.c_custkey] AS r1 distribution:direct est_rows:2,725,200 | | Filter [c.c_mktsegment = ?] | | TableScan customer AS c, PRIMARY KEY (c_custkey) est_table_rows:150,000,000 est_filtered:2,725,200 | +------------------------------------------------------------------------------------------------------------------------------------------------+ ``` From this `EXPLAIN` statement, it’s clear that a broadcast is required, and that a nested loop join will be performed. Now you can run the `PROFILE` statement with the same `SELECT` query to gather resource usage metrics. ```sql PROFILE SELECT COUNT(*) FROM orders o JOIN customer c WHERE o.custkey = c.custkey and c.mktsegment = 'BUILDING'; ``` ```output +----------+ | count(*) | +----------+ | 421 | +----------+ ``` The `PROFILE` statement will output the same results as the inner `SELECT` statement, but it has also gathered resource usage metrics. To view the metrics, you must run the `SHOW PROFILE` statement. ```sql SHOW PROFILE; ``` ```output +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | PROFILE | +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Project [CAST(COALESCE($0,0) AS SIGNED) AS `count(*)`] actual_rows: 1 exec_time: 0ms start_time: 00:00:00.584 network_traffic: 0.004000 KB | | Aggregate [SUM(remote_0.`count(*)`) AS $0] actual_rows: 3 exec_time: 0ms start_time: 00:00:00.581 | | Gather partitions:all est_rows:1 alias:remote_0 actual_rows: 3 exec_time: 0ms start_time: 00:00:00.003 end_time: 00:00:00.583 | | Project [`count(*)`] est_rows:1 est_select_cost:87,206,400 actual_rows: 3 exec_time: 0ms start_time: [00:00:00.581, 00:00:00.582] network_traffic: 0.012000 KB | | Aggregate [COUNT(*) AS `count(*)`] actual_rows: 421 exec_time: 0ms start_time: [00:00:00.053, 00:00:00.056] | | NestedLoopJoin actual_rows: 421 exec_time: 0ms | | |---IndexRangeScan orders AS o, KEY orders_fk1 (o_custkey) scan:[o_custkey = r1.c_custkey] est_table_rows:150,000,000 est_filtered:150,000,000 actual_rows: 421 exec_time: 532ms start_time: [00:00:00.053, 00:00:00.059] | | TableScan r1 storage:list stream:no est_table_rows:2,725,200 actual_rows: 122,424 exec_time: 29ms start_time: [00:00:00.004, 00:00:00.005] | | Broadcast [c.c_custkey] AS r1 distribution:direct est_rows:27,252 actual_rows: 40,808 exec_time: 19ms start_time: 00:00:00.002 network_traffic: 334.326996 KB | | Filter [c.c_mktsegment = ?] actual_rows: 40,808 exec_time: 97ms start_time: 00:00:00.002 | | TableScan customer AS c, PRIMARY KEY (c_custkey) est_table_rows:150,000 est_filtered:27,252 actual_rows: 200,000 exec_time: 68ms start_time: 00:00:00.002 | | Compile Total Time: 238ms +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ ``` After the `SHOW PROFILE` statement has been executed, notice that actual rows, network traffic, and execution time have been appended to the end of the execution operator lines. The most expensive operator is `IndexRangeScan orders`, which takes 532ms. Note that `TableScan tpch.orders` has many fewer rows now than are recorded in statistics, which suggests that our statistics are not up-to-date. Also note that the most network-consuming operator is `Broadcast [c.custkey]` and there is no memory-consuming operator (every operator uses only a constant amount of memory). After running `ANALYZE TABLE`, we can rerun the `PROFILE` query: ```sql PROFILE SELECT COUNT(*) FROM orders o JOIN customer c where o.custkey = c.custkey and c.mktsegment = 'BUILDING'; ``` ```output +----------+ | count(*) | +----------+ | 421 | +----------+ ``` Finally, we can output the profile information for it: ```sql SHOW PROFILE; ``` ```output +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | PROFILE | +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Project [CAST(COALESCE($0,0) AS SIGNED) AS `count(*)`] actual_rows: 1 exec_time: 0ms start_time: 00:00:00.237 network_traffic: 0.004000 KB | | Aggregate [SUM(remote_0.`count(*)`) AS $0] actual_rows: 3 exec_time: 0ms start_time: 00:00:00.223 | | Gather partitions:all est_rows:1 alias:remote_0 actual_rows: 3 exec_time: 0ms start_time: 00:00:00.004 end_time: 00:00:00.236 | | Project [`count(*)`] est_rows:1 est_select_cost:25,006 actual_rows: 3 exec_time: 0ms start_time: [00:00:00.221, 00:00:00.235] network_traffic: 0.012000 KB | | Aggregate [COUNT(*) AS `count(*)`] actual_rows: 421 exec_time: 0ms start_time: [00:00:00.140, 00:00:00.141] | | HashJoin [r1.o_custkey = customer.c_custkey] actual_rows: 421 exec_time: 11ms start_time: [00:00:00.140, 00:00:00.141] memory_usage: 655.359985 KB | | |---Broadcast [orders.o_custkey] AS r1 distribution:direct est_rows:12,503 actual_rows: 12,503 exec_time: 11ms start_time: 00:00:00.002 network_traffic: 78.333000 KB | | | TableScan tpch.orders, PRIMARY KEY (o_orderkey) est_table_rows:12,503 est_filtered:12,503 actual_rows: 12,503 exec_time: 13ms start_time: 00:00:00.002 | | Filter [customer.c_mktsegment = ?] actual_rows: 40,808 exec_time: 52ms start_time: [00:00:00.140, 00:00:00.141] | | TableScan tpch.customer, PRIMARY KEY (c_custkey) est_table_rows:200,000 est_filtered:40,832 actual_rows: 200,000 exec_time: 41ms start_time: [00:00:00.140, 00:00:00.141] | +---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ ``` The new plan is faster in execution time but notice that we introduced a memory-consuming operator `HashJoin`, which allocates 655.359985 KB of memory at run time in the example. That could be something to watch out for if we add more data, since it might limit the total number of queries that can run concurrently. ```sql PROFILE SELECT name FROM company WHERE name LIKE "C%"; ``` ```output +------------------------------+ | name | +------------------------------+ | Cutera, Inc. | | CVB Financial Corporation | | CVD Equipment Corporation | | Cyanotech Corporation | | ... | | Curis, Inc. | +------------------------------+ 348 rows in set (404 ms) ``` Now run the `SHOW PROFILE JSON` query to view the resource usage metrics in JSON format: ```sql SHOW PROFILE JSON; ``` ```output +------------------------------+ | PROFILE | +------------------------------+ | { "profile":[ { "executor":"Gather", "partitions":"all", "query":"SELECT `company`.`name` AS `name` FROM `trades_0`.`company` as `company` WHERE (`company`.`name` LIKE 'C%') OPTION(NO_QUERY_REWRITE=1, INTERPRETER_MODE=LLVM)", "alias":"remote_0", "actual_row_count":{ "value":348, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "actual_total_time":{ "value":0 }, "start_time":{ "value":0 }, "end_time":{ "value":5 }, ... } } 1 row in set (290 ms) ``` The `SHOW PLAN` command displays the plan information for the specified plan ID: ```sql SHOW PLAN 5; ``` ```output +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | PLAN | +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Gather partitions:all alias:remote_0 | | Project [company.symbol, company.name, company.last_sale, company.market_cap, company.IPO_year, company.sector, company.industry, company.summary_quote, company.extra] | | TableScan trades.company | +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 3 rows in set (0.00 sec) ``` Next, get the JSON plan information by running the following command: ```sql SHOW PLAN JSON 5; ``` This command produces a large amount of text as result. ## Example: Resource Usage Metrics The following example provides resource usage metrics for columnstore query that uses filters. In this example, the variable `profile_for_debug` is set to `OFF`. Run this statement: ```sql PROFILE SELECT * FROM products WHERE Color = 'Blue' and Qty = '5'; ``` Then run `SHOW PROFILE JSON`. Selected output: ```json ... "inputs":[ { "executor":"ColumnStoreFilter", "keyId":4294968019, "condition":[ "products.Color = ? AND products.Qty = ?" ], "columnstore_filter_predicates":[ { "executor":"ColumnStoreFilterPredicate", "keyId":4294968020, "condition":[ "products.Color = ? AND products.Qty = ?" ], "columnstore_filter_callback_ordinal":"2", "columnstore_filter_execution_type":"regular", "columnstore_filter_total_rows_in":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "columnstore_filter_total_rows_out":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "columnstore_filter_encoded_rows_in":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "columnstore_filter_encoded_rows_out":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "inputs":[] }, { "executor":"ColumnStoreFilterPredicate", "keyId":4294968020, "condition":[ " products.Color = ?" ], "columnstore_filter_callback_ordinal":"3", "columnstore_filter_execution_type":"regular", "columnstore_filter_total_rows_in":{ "value":6, "avg":0.750000, "stddev":1.984313, "max":6, "maxPartition":2 }, "columnstore_filter_total_rows_out":{ "value":4, "avg":0.500000, "stddev":1.322876, "max":4, "maxPartition":2 }, "columnstore_filter_encoded_rows_in":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "columnstore_filter_encoded_rows_out":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "inputs":[] }, { "executor":"ColumnStoreFilterPredicate", "keyId":4294968020, "condition":[ " AND products.Qty = ?" ], "columnstore_filter_callback_ordinal":"5", "columnstore_filter_execution_type":"regular", "columnstore_filter_total_rows_in":{ "value":4, "avg":0.500000, "stddev":1.322876, "max":4, "maxPartition":2 }, "columnstore_filter_total_rows_out":{ "value":4, "avg":0.500000, "stddev":1.322876, "max":4, "maxPartition":2 }, "columnstore_filter_encoded_rows_in":{ "value":4, "avg":0.500000, "stddev":1.322876, "max":4, "maxPartition":2 }, "columnstore_filter_encoded_rows_out":{ "value":4, "avg":0.500000, "stddev":1.322876, "max":4, "maxPartition":2 }, "inputs":[] } ], "subselects":[], "actual_row_count":{ "value":4, "avg":0.500000, "stddev":1.322876, "max":4, "maxPartition":2 }, "actual_total_time":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "start_time":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":2 }, "columnstore_filter_total_rows_in":{ "value":6, "avg":0.750000, "stddev":1.984313, "max":6, "maxPartition":2 }, "columnstore_filter_avg_filters_per_row":{ "value":0, "avg":1.666667, "stddev":0.000000, "max":0, "maxPartition":0 }, "columnstore_filter_avg_index_filters_per_row":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "columnstore_filter_avg_bloom_filters_per_row":{ "value":0, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, ... ``` ## Example: Spilling-related Metrics Here is an example of the spilling-related metrics under hash Join operators: ```json ... "inputs":[ { "executor":"HashJoin", "keyId":458753, "type":"inner", "subselects":[], "actual_row_count":{ "value":4194304, "avg":1398101.333333, "stddev":606.633516, "max":1398899, "maxPartition":0 }, "actual_total_time":{ "value":1964, "avg":1964.000000, "stddev":0.000000, "max":1964, "maxPartition":0 }, "start_time":{ "value":7074, "avg":7486.333333, "stddev":0.000000, "max":8142, "maxPartition":2 }, "inputs":[ { "executor":"HashTableProbe", "keyId":458917, "condition":[ "r1.a = r0.a" ], "spill_outputted_rows":{ "value":4194304, "avg":1398101.333333, "stddev":606.633516, "max":1398899, "maxPartition":0 }, "spill_disk_usage":{ "value":134217728, "avg":44739242.666667, "stddev":19412.272498, "max":44764768, "maxPartition":0 }, "inputs":[ { "executor":"HashTableBuild", "keyId":458916, "alias":"r1", "actual_row_count":{ "value":4194304, "avg":0.000000, "stddev":0.000000, "max":0, "maxPartition":0 }, "actual_total_time":{ "value":4, "avg":4.000000, "stddev":0.000000, "max":4, "maxPartition":0 }, "start_time":{ "value":1782, "avg":1866.666667, "stddev":0.000000, "max":1978, "maxPartition":1 }, "memory_usage":{ "value":393216, "avg":131072.000000, "stddev":0.000000, "max":131072, "maxPartition":0 }, "spill_outputted_rows":{ "value":4194304, "avg":1398101.333333, "stddev":606.633516, "max":1398899, "maxPartition":0 }, "spill_disk_usage":{ "value":100663296, "avg":33554432.000000, "stddev":14559.204374, "max":33573576, "maxPartition":0 }, ... ``` ## Related Topics * [ Visual Explain](https://docs.singlestore.com/db/v9.1/query-data/query-tuning/singlestore-visual-explain.md) * [Query Plan Operations](https://docs.singlestore.com/db/v9.1/query-data/query-plan-operations.md) * [EXPLAIN](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-manipulation-language-dml/explain.md) *** Modified at: June 12, 2026 Source: [/db/v9.1/reference/sql-reference/data-manipulation-language-dml/profile/](https://docs.singlestore.com/db/v9.1/reference/sql-reference/data-manipulation-language-dml/profile/) (An index of the documentation is available at /llms.txt)