From 598fc9cf2dcac90a24103c723efff8b08980a24a Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Tue, 14 May 2024 23:41:27 +0100 Subject: [PATCH 01/25] Add system:sequences and system:all_sequences --- .../n1ql-manage/monitoring-n1ql-query.adoc | 129 ++++++++++++++++++ 1 file changed, 129 insertions(+) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 1fcf85c63..9eb54a367 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -2738,6 +2738,135 @@ __required__ Refer to xref:n1ql:n1ql-language-reference/transactions.adoc[{sqlpp} Support for Couchbase Transactions] for more information. +[#sys-sequences] +== Monitor Sequences + +The `system:sequences` catalog maintains a list of loaded sequences on any node: that is, sequences that have been accessed since the last restart. +To see the list of loaded sequences, use: + +[source,sqlpp] +---- +SELECT * FROM system:sequences; +---- + +This will result in a list similar to: + +[source,json] +---- +FIXME: +---- + +This catalog contains the following attributes: + +[options="header", cols="~a,~a,~a"] +|=== +|Name|Description|Schema + +|**bucket** + +__required__ +|The bucket containing the sequence. +|string + +|**cache** + +__required__ +|The sequence's cache size. +|integer + +|**cycle** + +__required__ +|Whether the sequence is set to cycle. +|boolean + +|**increment** + +__required__ +|The sequence step value. +|integer + +|**min** + +__required__ +|The minimum value permitted for the sequence. +|integer + +|**max** + +__required__ +|The maximum value permitted for the sequence. +|integer + +|**name** + +__required__ +|The name of the sequence. +|string + +|**namespace** + +__required__ +|Namespace to which the sequence belongs. +|string + +|**namespace_id** + +__required__ +|ID of the namespace to which the sequence belongs. +|string + +|**path** + +__required__ +|The fully qualified sequence name. +|string + +|**scope_id** + +__required__ +|ID of the scope to which the sequence belongs. +|string + +|**value** + +__required__ +|The current value of the sequence on each Query node. +| <> object +|=== + +[[value]] +**Values** + +[options="header", cols="~a,~a,~a"] +|=== +|Name|Description|Schema + +|**** + +__required__ +|The name of this property is the UUID of a Query node. + +The value of this property is the current value of the sequence on that node. +|Integer + +|**~next_block** + +__optional__ +|The starting vale of the next block of values that can be reserved for the sequence. +|Integer +|=== + +For further details, refer to xref:n1ql:n1ql-language-reference/createsequence.adoc[]. + +[#sys-all-sequences] +== Monitor All Sequences + +The `system:all_sequences` catalog maintains a list of all defined sequences. +To see the list of all defined sequences, use: + +[source,sqlpp] +---- +SELECT * FROM system:all_sequences; +---- + +This will result in a list similar to: + +[source,json] +---- +FIXME: +---- + +This catalog gives the same information as the <> catalog. + +For further details, refer to xref:n1ql:n1ql-language-reference/createsequence.adoc[]. + == Related Links * Refer to xref:n1ql:n1ql-intro/sysinfo.adoc[Getting System Information] for more information on the system namespace. From daa8b92e5ee0d916b5b14ca4a5812d9affa61b0e Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Tue, 14 May 2024 23:43:42 +0100 Subject: [PATCH 02/25] Add system:vitals --- .../n1ql-manage/monitoring-n1ql-query.adoc | 38 +++++++++++++++---- 1 file changed, 31 insertions(+), 7 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 9eb54a367..12ef27299 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -63,10 +63,7 @@ a| | Other a| -* <> - -NOTE: These are only available using REST APIs. - +* <> |=== == Authentication and Client Privileges @@ -629,15 +626,42 @@ Since Query Workbench can connect to the same node only when cbq-engine is runni To get around this block, once the Query Workbench clients connect to a query node, this internal user (cbq-engine-cbauth) will be used to do any further inter-node user verification. [#vitals] -== System Vitals +== Monitor System Vitals -The [.cmd]`Vitals` API provides data about the running state and health of the query engine, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. -This information can be very useful to assess the current workload and performance characteristics of a query engine, and hence load-balance the requests being sent to various query engines. +The `system:vitals` catalog provides data about the running state and health of the query engine, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. +This information can be very useful to assess the current workload and performance characteristics of a query engine. For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. === Get System Vitals +[tabs] +==== +REST API:: ++ +-- +To view system vitals with Admin REST API: + +[source,sh] +---- +curl -u Administrator:pword http://localhost:8093/admin/vitals +---- +-- + +{sqlpp}:: ++ +-- +To view system vitals with {sqlpp}: + +[source,sqlpp] +---- +SELECT * FROM system:vitals; +---- +-- +==== + + + [source,sh] ---- curl -u Administrator:pword http://localhost:8093/admin/vitals From 5808c1ad2ed050418b4b2d93ebd57800b4ed1a0b Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Tue, 14 May 2024 23:52:33 +0100 Subject: [PATCH 03/25] Replace profiling explanation with includes from REST API --- .../n1ql-manage/monitoring-n1ql-query.adoc | 126 +----------------- 1 file changed, 1 insertion(+), 125 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 12ef27299..665380567 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -202,138 +202,14 @@ When a query executes a user-defined function, profiling information is availabl When profiling is enabled, a query response includes the profile attribute. The attribute details are as follows: -.Attribute Details -[cols="14,8"] -|=== -| Attribute | Example - -a| -`phaseTimes` -- Cumulative execution times for various phases involved in the query execution, such as authorize, indexscan, fetch, parse, plan, run, etc. - [NOTE] ==== This value will be dynamic, depending on the documents processed by various phases up to this moment in time. A new query on `system:active_requests` will return different values. ==== -a| -[source,json] ----- -"phaseTimes": { - "authorize": "823.631µs", - "fetch": "656.873µs", - "indexScan": "29.146543ms", - "instantiate": "236.221µs", - "parse": "826.382µs", - "plan": "11.831101ms", - "run": "16.892181ms" -} ----- - -a| -`phaseCounts` -- Count of documents processed at selective phases involved in the query execution, such as authorize, indexscan, fetch, parse, plan, run, etc. - -[NOTE] -==== -This value will be dynamic, depending on the documents processed by various phases up to this moment in time. -A new query on `system:active_requests` will return different values. -==== -a| -[source,json] ----- -"phaseCounts": { - "fetch": 16, - "indexScan": 187 -} ----- - -a| -`phaseOperators` -- Indicates the number of each kind of query operators involved in different phases of the query processing. -For instance, this example, one non covering index path was taken, which involves 1 indexScan and 1 fetch operator. - -A join would have probably involved 2 fetches (1 per keyspace) - -A union select would have twice as many operator counts (1 per each branch of the union). - -This is in essence the count of all the operators in the `executionTimings` field. -a| -[source,json] ----- -"phaseOperators": { - "authorize": 1, - "fetch": 1, - "indexScan": 2 -} ----- - -a| -`executionTimings` -- The execution details such as kernel and service execution times, number of documents processed at each query operator in each phase, and number of phase switches, for various phases involved in the query execution. - -The following statistics are collected for each operator: - -`#operator`:: -Name of the operator. - -`#stats`:: -These values will be dynamic, depending on the documents processed by various phases up to this moment in time. -+ -A new query on `system:active_requests` will return different values. - -`#itemsIn`;; -Number of input documents to the operator. - -`#itemsOut`;; -Number of output documents after the operator processing. - -`#phaseSwitches`;; -Number of switches between executing, waiting for services, or waiting for the `goroutine` scheduler. - -`execTime`;; -Time spent executing the operator code inside {sqlpp} query engine. - -`kernTime`;; -Time spent waiting to be scheduled for CPU time. - -`servTime`;; -Time spent waiting for another service, such as index or data. -+ -* For index scan, it is time spent waiting for GSI/indexer. -* For fetch, it is time spent waiting on the KV store. - -a| -[source,json] ----- -"executionTimings": { - // … - [{ - "#operator": "Fetch", - "#stats": { - "#itemsIn": 187, - "#itemsOut": 16, - "#phaseSwitches": 413, - "execTime": "128.434µs", - "kernTime": "15.027879ms", - "servTime": "1.590934ms", - "state": "services" - }, - "keyspace": "travel-sample", - "namespace": "default" - }, - { - "#operator": "IntersectScan", - "#stats": { - "#itemsIn": 187, - "#itemsOut": 187, - "#phaseSwitches": 749, - "execTime": "449.944µs", - "kernTime": "14.625524ms" - } - // … - ]} ----- - -|=== +include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] These statistics (`kernTime`, `servTime`, and `execTime`) can be very helpful in troubleshooting query performance issues, such as: From ba2c88986f42e239c705d7d3f9d6cd881811470f Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Tue, 14 May 2024 23:53:31 +0100 Subject: [PATCH 04/25] Tabs for requests, prepared statements --- .../n1ql-manage/monitoring-n1ql-query.adoc | 76 +++++++++++++++++++ 1 file changed, 76 insertions(+) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 665380567..a3a6f71b3 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -584,38 +584,60 @@ The profile related attributes are described in the section < Date: Wed, 15 May 2024 00:08:29 +0100 Subject: [PATCH 05/25] Outsource prepared statement fields to the REST API docs --- .../pages/n1ql-manage/monitoring-n1ql-query.adoc | 16 ---------------- 1 file changed, 16 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index a3a6f71b3..7cb31eb05 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -825,22 +825,6 @@ For each prepared statement, this catalog provides information such as name, sta For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_statements[Statements]. The `system:prepareds` catalog returns all the properties that the {sqlpp} Admin REST API would return for a specific prepared statement. -In addition, the `system:prepareds` catalog also returns the following properties. - -[options="header", cols=".^3a,.^11a,.^4a"] -|=== -|Name|Description|Schema -|**node** + -__required__ -|The node on which the prepared statement is stored. -|string - -|**namespace** + -__required__ -|The namespace in which the prepared statement is stored. -Currently, only the `default` namespace is available. -|string -|=== A prepared statement is created and stored relative to the current xref:n1ql:n1ql-intro/queriesandresults.adoc#query-context[query context]. You can create multiple prepared statements with the same name, each stored relative to a different query context. From 5bdb7bc08b41f56e6bc8ccd12d22aac89b726395 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Thu, 16 May 2024 12:28:28 +0100 Subject: [PATCH 06/25] Delete Monitor Query Clusters section marketing bumf that says nothing --- .../n1ql-manage/monitoring-n1ql-query.adoc | 27 ------------------- 1 file changed, 27 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 7cb31eb05..b9ba8f119 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -474,33 +474,6 @@ This attribute is enabled for the following system keyspaces: For a detailed example, see <>. -== Monitor Query Clusters - -Couchbase Server allows you to monitor many aspects of an active cluster: cluster-aware operations, diagnostics, and more system keyspaces features that cover multiple nodes. -Functionalities include: - -* Ability to access active / completed / prepared requests across all Query nodes from {sqlpp}. -* Ability to list nodes by type and with status from {sqlpp}. -* Ability to list system keyspaces from `system:keyspaces`. -* Extra fields in `system:active_requests` and `system:completed_requests`. -* Counters to keep track of specific requests, such as cancelled requests. -* Killing request for CREATE INDEX. - -=== System Keyspaces - -* The `system:keyspaces` keyspace can be augmented to list system keyspaces with a static map. -The small disadvantage of this is that it has to be maintained as new system keyspaces are added. -* The `system:active_requests` and `system:completed_requests` keyspaces can report scan consistency. -* The `system:prepareds` keyspace can list min and max execution and service times, as well as average times. - -=== cbq-engine-cbauth - -`cbq-engine-cbauth` is an internal user that the query service uses to allow Query Workbench clients to query across multiple query nodes. - -Since Query Workbench can connect to the same node only when cbq-engine is running, Query Workbench cannot do any query-clustered operations. - -To get around this block, once the Query Workbench clients connect to a query node, this internal user (cbq-engine-cbauth) will be used to do any further inter-node user verification. - [#vitals] == Monitor System Vitals From b53af28ea6a2350f4f977b9365963e931522ef41 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Fri, 17 May 2024 18:56:27 +0100 Subject: [PATCH 07/25] Rework sections on query profiling --- .../n1ql-manage/monitoring-n1ql-query.adoc | 232 ++++++++++-------- 1 file changed, 132 insertions(+), 100 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index b9ba8f119..542fbd642 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -81,72 +81,83 @@ Similarly, users must have SELECT permission on the target of an index to be abl ** `system:datastores` ** `system:namespaces` -== Query Monitoring Settings +[#query-monitoring-settings] +== Query Profiling -The monitoring settings can be set for each query engine (using the REST API) or for each query statement (using the cbq command line tool). -Both settings are actually set via REST endpoints: using the xref:n1ql:n1ql-rest-api/admin.adoc[Admin REST API] (`/admin/settings` endpoint) and the xref:n1ql:n1ql-rest-api/index.adoc[Query REST API] (`/query/service` endpoint). +Query profiling enables you to obtain more detailed monitoring information and finer execution timings for any query. +You can set query profiling to the following levels: -The cbq shell and Query Workbench use the Query REST API to set monitoring at the request level. -The Query Workbench automatically enables the profiling and timings. -It can be disabled using the [.ui]*Preferences* option. -For more information refer to the xref:tools:query-workbench.adoc[Query Workbench] section. +* `off` -- query profiling is disabled. +* `phases` -- query profiling is enabled, including information about the phases of query execution. +* `timings` -- query profiling is enabled, including information about the phases of query execution, and detailed timing information. -Use the following query parameters to enable, disable, and control the monitoring capabilities, and the level of monitoring and profiling details for each query or globally at a query engine level: +You can set query profiling in the following ways: -* profile -* controls +* At the <>, so that it is enabled for all queries on that node. +* At the <>, for individual queries. -For more details and examples, see xref:n1ql:n1ql-manage/query-settings.adoc[]. +For more information about Query settings and parameters, see xref:n1ql:n1ql-manage/query-settings.adoc[]. -=== Enable Settings for a Query Engine +[#enable-settings-for-a-query-engine] +=== Enable Query Profiling for a Query Node -You can enable profile settings for each query engine. -These examples use local host IP address and default port numbers. -You need to provide correct credentials, IP address, and port details of your setup. +To activate query profiling at the node level, specify the `profile` setting using the xref:n1ql:n1ql-rest-api/admin.adoc[Admin REST API] (`/admin/settings` endpoint). -. Get the current query settings: -+ -[source,sh] ----- -include::n1ql:example$settings/save-node-level-settings.sh[tag=curl] ----- -+ +.See the current node-level query settings +==== +The following request gets the current node-level query settings. + +.Request [source,sh] ---- -cat ./query_settings.json +include::n1ql:example$settings/node-level-settings.sh[tag=curl] ---- -+ + +.Results [source,json] ---- include::n1ql:example$settings/node-level-settings.jsonc[] ---- +==== -. Set current query settings profile: - .. To set the query settings saved in a file [.path]_./query_settings.json_, enter the following query: -+ +.Save node-level query settings to a file +==== +The following request saves the current node-level query settings to the file `query_settings.json`. + +.Request [source,sh] ---- -curl http://localhost:8093/admin/settings -u user:pword \ +include::n1ql:example$settings/save-node-level-settings.sh[tag=curl] +---- +==== + +.Set node-level query settings from a file +==== +Assuming that you have edited the file `query_settings.json` to specify the query settings you want, the following request +sets the node-level query settings according to the file. + +.Request +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ -X POST \ -d@./query_settings.json ---- +==== - .. To explicitly specify the settings, enter the following query: -+ +.Set node-level query settings explicitly +==== +The following request explicitly sets query profiling at the node level. + +.Request [source,sh] ---- -curl http://localhost:8093/admin/settings -u user:pword \ +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ -H 'Content-Type: application/json' \ -d '{"profile": "phases"}' ---- -. Verify the settings are changed as specified: -+ -[source,sh] ----- -include::n1ql:example$settings/node-level-settings.sh[tag=curl] ----- -+ +.Results [source,json] ---- { @@ -160,78 +171,91 @@ include::n1ql:example$settings/node-level-settings.sh[tag=curl] "use-cbo": true } ---- +==== -=== Enable Settings per Session or per Query +[#enable-settings-per-session-or-per-query] +=== Enable Query Profiling for a Request -You can enable monitoring and profiling settings for each query statement. -To set query settings using the cbq shell, use the `\SET` command: +To activate profiling at the request level, do one of the following: -[source,sqlpp] ----- -\set -profile "timings"; -\set; ----- +* Specify the `profile` setting using the xref:n1ql:n1ql-rest-api/index.adoc[Query REST API] (`/query/service` endpoint). +* Specify the `profile` setting using the xref:n1ql:n1ql-intro/cbq.adoc[cbq] command line tool. + +[tabs] +==== +REST API:: ++ +-- +To set query settings using the REST API, specify the parameters in the request body. + +''' + +The following statement sets the profiling to phases: -[source,none] +[source,sh] ---- - Query Parameters : - Parameter name : profile - Value : ["timings"] - ... +curl $BASE_URL/query/service -u $USER:$PASSWORD \ + -d 'profile=phases&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1' ---- -To set query settings using the REST API, specify the parameters in the request body: +The following statement sets the profiling to timings: [source,sh] ---- -curl http://localhost:8093/query/service -u user:pword \ - -d 'profile=timings&statement=SELECT * FROM "world" AS hello' +curl $BASE_URL/query/service -u $USER:$PASSWORD \ + -d 'profile=timings&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1' ---- +-- -[#monitor-profile-details] -== Monitoring and Profiling Details +{sqlpp}:: ++ +-- +To set query settings using the cbq shell, use the `\SET` command. -Couchbase Server provides detailed query monitoring and profiling information. -The profiling and finer query execution timing details can be obtained for any query. +''' -When a query executes a user-defined function, profiling information is available for the {sqlpp} queries within the user-defined function as well. +The following statement sets the profiling to phases: -[[profile]] -=== Attribute Profile in Query Response +[source,sqlpp] +---- +\set -profile "phases"; +SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; +---- -When profiling is enabled, a query response includes the profile attribute. -The attribute details are as follows: +The following statement sets the profiling to timings: -[NOTE] +[source,sqlpp] +---- +\set -profile "timings"; +SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; +---- +-- ==== -This value will be dynamic, depending on the documents processed by various phases up to this moment in time. -A new query on `system:active_requests` will return different values. -==== +The Query Workbench automatically enables Query profiling, with detailed timing information. +To disable or enable Query profiling with the Query Workbench, specify the *Collect query timings* option using the xref:tools:query-workbench.adoc#query-preferences[Query Preferences]. -include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] +[#monitor-profile-details] +== Query Profiling Details -These statistics (`kernTime`, `servTime`, and `execTime`) can be very helpful in troubleshooting query performance issues, such as: +You can access the profiling information in the following ways: -* A high `servTime` for a low number of items processed is an indication that the indexer or KV store is stressed. -* A high `kernTime` means there is a downstream issue in the query plan or the query server having many requests to process (so the scheduled waiting time will be more for CPU time). +* In the <>. +* In the <>. -.Phases Profile -==== -The cbq engine must be started with authorization, for example: +When a query executes a user-defined function, profiling information is available for the {sqlpp} queries within the user-defined function as well. -[source,sh] ----- -./cbq -engine=http://localhost:8091/ -u Administrator -p pword ----- +[[profile]] +=== Profiling Details in Query Response -Using the cbq shell, show the statistics collected when the `profile` is set to `phases`: +When profiling is enabled: -[source,sqlpp] ----- -\set -profile "phases"; -SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; ----- +* If you are using the cbq shell or the Query REST API, query profiling information is returned with the query results. +* However, if you are using the Query workbench, query profiling information is not returned with the query results. + +.Phases Profile +==== +If you are using the cbq shell or the Query REST API, the following statistics are returned when `profile` is set to `phases`: [source,json] ---- @@ -289,13 +313,7 @@ SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; .Timings Profile ==== -Using the cbq shell, show the statistics collected when `profile` is set to `timings`: - -[source,sqlpp] ----- -\set -profile "timings"; -SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; ----- +If you are using the cbq shell or the Query REST API, the following statistics are returned when `profile` is set to `timings`: [source,json] ---- @@ -453,27 +471,41 @@ SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; ---- ==== -[[plan]] -=== Attribute Meta in System Keyspaces +The `profile` object contains the following attributes: -The `meta().plan` virtual attribute captures the whole query plan, and monitoring stats of various phases and involved query operators. -The `meta().plan` must be explicitly called in the SELECT query projection list. +include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] -The `meta().plan` attribute is enabled only for individual requests that are running (`active_requests`) or completed (`completed_requests`) when the profile is set to timings (`profile ="timings"`) for each individual request. -If at the engine level, the profile is set to off and individual requests have been run with `profile ="timings"`, then the system keyspaces will return the plan only for those requests. +The `kernTime`, `servTime`, and `execTime` statistics can be very helpful in troubleshooting query performance issues +For example: -Since there may be a combination of profile settings for all of the requests reported by the system keyspaces, not all requests returned will have a `meta().plan` attachment. +* A high `servTime` for a low number of items processed is an indication that the indexer or KV store is stressed. +* A high `kernTime` means there is a downstream issue in the query plan or the query server having many requests to process, so the scheduled waiting time will be more for CPU time. -NOTE: For the `system:prepareds` requests, the `meta().plan` is available at all times since the `PREPARE` statement is not dependant on the profile setting. +[[plan]] +=== Profiling Details in System Catalogs -This attribute is enabled for the following system keyspaces: +The following system catalogs support the `meta().plan` virtual attribute, which captures the whole query plan, including query profiling information. * <> * <> * <> +With the `system:active_requests` and `system:completed_requests` catalogs, not all statements have a `meta().plan` attribute. +The `meta().plan` attribute is only available for statements that run when the profile is set to `timings`. + +With the `system:prepareds` catalog, the `meta().plan` attribute is available for all statements. + +You must explicitly specify `meta().plan` in the projection list for the SELECT query. For a detailed example, see <>. +The `meta().plan` attribute contains similar properties to the `profile` object included with the query results when profiling is active. + +[NOTE] +==== +For active requests, `phaseTimes` and `phaseCounts` are dynamic, depending on the documents processed by various phases up to this moment in time. +A new query on `system:active_requests` will return different values. +==== + [#vitals] == Monitor System Vitals From 0b1c8ccf189de3835c672ca601a58c4a899abc62 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Fri, 17 May 2024 19:00:41 +0100 Subject: [PATCH 08/25] Update REST API examples with placeholders --- .../examples/settings/node-level-settings.sh | 2 +- .../settings/save-node-level-settings.sh | 2 +- .../n1ql-manage/monitoring-n1ql-query.adoc | 28 +++++++++++-------- 3 files changed, 19 insertions(+), 13 deletions(-) diff --git a/modules/n1ql/examples/settings/node-level-settings.sh b/modules/n1ql/examples/settings/node-level-settings.sh index c582ed1bd..2a42a58df 100644 --- a/modules/n1ql/examples/settings/node-level-settings.sh +++ b/modules/n1ql/examples/settings/node-level-settings.sh @@ -1,5 +1,5 @@ #!/bin/sh # tag::curl[] -curl http://localhost:8093/admin/settings -u user:pword +curl $BASE_URL/admin/settings -u $USER:$PASSWORD # end::curl[] \ No newline at end of file diff --git a/modules/n1ql/examples/settings/save-node-level-settings.sh b/modules/n1ql/examples/settings/save-node-level-settings.sh index ddbac3034..6d83ed494 100644 --- a/modules/n1ql/examples/settings/save-node-level-settings.sh +++ b/modules/n1ql/examples/settings/save-node-level-settings.sh @@ -1,5 +1,5 @@ #!/bin/sh # tag::curl[] -curl http://localhost:8093/admin/settings -u user:pword -o ./query_settings.json +curl $BASE_URL/admin/settings -u $USER:$PASSWORD -o ./query_settings.json # end::curl[] \ No newline at end of file diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 542fbd642..cfc2635a3 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -81,6 +81,14 @@ Similarly, users must have SELECT permission on the target of an index to be abl ** `system:datastores` ** `system:namespaces` +== Examples on this Page + +In the REST API examples: + +* `$BASE_URL` is the protocol, host name or IP address, and port -- for example, `+http://localhost:8093+`. +* `$USER` is the user name. +* `$PASSWORD` is the password. + [#query-monitoring-settings] == Query Profiling @@ -525,7 +533,7 @@ To view system vitals with Admin REST API: [source,sh] ---- -curl -u Administrator:pword http://localhost:8093/admin/vitals +curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ---- -- @@ -541,11 +549,9 @@ SELECT * FROM system:vitals; -- ==== - - [source,sh] ---- -curl -u Administrator:pword http://localhost:8093/admin/vitals +curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ---- [source,json] @@ -598,7 +604,7 @@ To view active requests with Admin REST API: [source,sh] ---- -curl -u Administrator:pword http://localhost:8093/admin/active_requests +curl -u $USER:$PASSWORD $BASE_URL/admin/active_requests ---- -- @@ -628,7 +634,7 @@ To terminate an active request [.var]`uuid` with the Admin REST API: [source,sh] ---- -curl -u Administrator:pword -X DELETE http://localhost:8093/admin/active_requests/uuid +curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/active_requests/uuid ---- -- @@ -849,7 +855,7 @@ REST API:: -- [source,sh] ---- -curl -u Administrator:pword http://localhost:8093/admin/prepareds +curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds ---- -- @@ -871,7 +877,7 @@ REST API:: -- [source,sh] ---- -curl -u Administrator:pword http://localhost:8093/admin/prepareds/example1 +curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds/example1 ---- -- @@ -897,7 +903,7 @@ REST API:: -- [source,sh] ---- -curl -u Administrator:pword -X DELETE http://localhost:8093/admin/prepareds/p1 +curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/prepareds/p1 ---- -- @@ -1246,7 +1252,7 @@ To get a list of all logged completed requests using the Admin REST API: [source,sh] ---- -curl -u Administrator:pword http://localhost:8093/admin/completed_requests +curl -u $USER:$PASSWORD $BASE_URL/admin/completed_requests ---- -- @@ -1282,7 +1288,7 @@ To purge a completed request [.var]`uuid` with the Admin REST API: [source,sh] ---- -curl -u Administrator:pword -X DELETE http://localhost:8093/admin/completed_requests/uuid +curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/completed_requests/uuid ---- -- From e5a6163a680224561caa573d5ef75cbbb86250b3 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Sat, 18 May 2024 00:35:10 +0100 Subject: [PATCH 09/25] Update ToC --- .../pages/n1ql-manage/monitoring-n1ql-query.adoc | 16 +++++++++------- 1 file changed, 9 insertions(+), 7 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index cfc2635a3..2164b8ed8 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -44,15 +44,10 @@ a| | Monitoring Catalogs a| +* <> * <> * <> * <> -* <> -* <> -* <> -* <> -* <> -* <> | Security Catalogs a| @@ -63,7 +58,14 @@ a| | Other a| -* <> +* <> +* <> +* <> +* <> +* <> +* <> +* <> +* <> |=== == Authentication and Client Privileges From 749586d6ce907e0c2d30392211ca6c26e6138c84 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Sat, 18 May 2024 00:35:58 +0100 Subject: [PATCH 10/25] Add sequence examples --- .../n1ql-manage/monitoring-n1ql-query.adoc | 65 ++++++++++++++++++- 1 file changed, 63 insertions(+), 2 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 2164b8ed8..f934d0283 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -2726,7 +2726,28 @@ This will result in a list similar to: [source,json] ---- -FIXME: +[ + { + "sequences": { + "bucket": "travel-sample", + "cache": 50, + "cycle": false, + "increment": 1, + "max": 9223372036854776000, + "min": -9223372036854776000, + "name": "seq1", + "namespace": "default", + "namespace_id": "default", + "path": "`default`:`travel-sample`.`inventory`.`seq1`", + "scope_id": "inventory", + "value": { + "73428daec3c68d8632ae66b09b70f14d": null, + "~next_block": 0 + } + } + }, +// ... +] ---- This catalog contains the following attributes: @@ -2833,7 +2854,47 @@ This will result in a list similar to: [source,json] ---- -FIXME: +[ + { + "sequences": { + "bucket": "travel-sample", + "cache": 50, + "cycle": false, + "increment": -1, + "max": 9223372036854776000, + "min": 0, + "name": "seq4", + "namespace": "default", + "namespace_id": "default", + "path": "`default`:`travel-sample`.`inventory`.`seq4`", + "scope_id": "inventory", + "value": { + "73428daec3c68d8632ae66b09b70f14d": 10, + "~next_block": -40 + } + } + }, + { + "sequences": { + "bucket": "travel-sample", + "cache": 50, + "cycle": true, + "increment": 5, + "max": 1000, + "min": 0, + "name": "seq3", + "namespace": "default", + "namespace_id": "default", + "path": "`default`:`travel-sample`.`inventory`.`seq3`", + "scope_id": "inventory", + "value": { + "73428daec3c68d8632ae66b09b70f14d": 5, + "~next_block": 255 + } + } + }, +// ... +] ---- This catalog gives the same information as the <> catalog. From 7a76458d5bd9b938a711c0c5c73a412d2e3715d8 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Sat, 18 May 2024 00:36:54 +0100 Subject: [PATCH 11/25] Move Configure the Completed Requests as a top-level section --- .../n1ql-manage/monitoring-n1ql-query.adoc | 262 +++++++++--------- 1 file changed, 131 insertions(+), 131 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index f934d0283..b7f2ccb65 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -1313,137 +1313,6 @@ DELETE FROM system:completed_requests WHERE requestTime LIKE "2015-09-09%"; -- ==== -[[sys-completed-config]] -=== Configure the Completed Requests - -You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API settings endpoint. - -In Couchbase Server 6.5 and later, you can specify the conditions for completed request logging using the `completed` field. - -This field takes a JSON object containing the names and values of logging qualifiers. -Completed requests that meet the defined qualifiers are logged. - -[source,sh] ----- -curl http://localhost:8093/admin/settings -u Administrator:password \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"user": "marco", "error": 12003}}' ----- - -==== Logging Qualifiers - -You can specify the following logging qualifiers. -A completed request is logged if _any_ of the qualifiers are met (logical OR). - -[horizontal] -`threshold`:: The execution time threshold in milliseconds. -`aborted`:: Whether to log requests that generate a panic. -`error`:: Log requests returning this error number. -`client`:: Log requests from this IP address. -`user`:: Log requests with this user name. -`context`:: Log requests with this client context ID. - -For full details, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_logging_parameters[Logging parameters]. - -The basic syntax adds a qualifier to the logging parameters, i.e. any existing qualifiers are not removed. -You can change the value of a logging qualifier by specifying the same qualifier again with a new value. - -To add a new instance of an existing qualifier, use a plus sign (`+`) before the qualifier name, e.g. `+user`. -To remove a qualifier, use a minus sign (`-`) before the qualifier name, e.g. `-user`. - -For example, the following request will add user `simon` to those tracked, and remove error `12003`. - -[source,sh] ----- -curl http://localhost:8093/admin/settings -u Administrator:password \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"+user": "simon", "-error": 12003}}' ----- - -Similarly, you could remove all logging by execution time with the following request, as long as the value matches the existing threshold. - -[source,sh] ----- -curl http://localhost:8093/admin/settings -u Administrator:password \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"-threshold": 1000}}' ----- - -==== Tagged Sets - -You can also specify qualifiers that have to be met as a group for the completed request to be logged (logical AND). - -To do this, specify the `tag` field along with a set of qualifiers, like so: - -[source,sh] ----- -curl http://localhost:8093/admin/settings -u Administrator:password \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"user": "marco", "error": 12003, "tag": "both_user_and_error"}}' ----- - -In this case, the request will be logged when both user and error match. - -The tag name can be any string that is meaningful and unique. -Requests that match a tagged set of conditions are logged with a field `~tag`, which is set to the name of the tag. - -To add a qualifier to a tagged set, specify the tag name again along with the new qualifier: - -[source,sh] ----- -curl http://localhost:8093/admin/settings -u Administrator:password \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"client": "172.1.2.3", "tag": "both_user_and_error"}}' ----- - -You cannot add a new instance of an existing qualifier to a tagged set using a plus sign (`+`) before the qualifier name. -For example, you cannot add a `user` qualifier to a tagged set that already contains a `user` qualifier. -If you need to track two users with the same error, create two tagged sets, one per user. - -You can remove a qualifier from a tagged set using a minus sign (`-`) before the qualifier name, e.g. `-user`. -When you remove the last qualifier from a tagged set, the tagged set is removed. - -[NOTE] --- -You can specify multiple tagged sets. -In this case, completed requests are logged if they match all of the qualifiers in any of the tagged sets. - -You can also specify a mixture of tagged sets and individual qualifiers. -In this case, completed requests are logged if they match any of the individual qualifiers, or all of the qualifiers in any of the tagged sets. --- - -==== Completed Threshold - -The [.param]`completed-threshold` field provides another way of specifying the `threshold` qualifier within the `completed` field. - -This field sets the minimum request duration after which requests are added to the `system:completed_requests` catalog. -The default value is 1000ms. -Specify [.in]`0` to log all requests and [.in]`-1` to not log any requests to the keyspace. - -To specify a different value, use: - -[source,sh] ----- -curl http://localhost:port/admin/settings -u user:pword \ - -H 'Content-Type: application/json' \ - -d '{"completed-threshold":0}' ----- - -==== Completed Limit - -The [.param]`completed-limit` field sets the number of most recent requests to be tracked in the `system:completed_requests` catalog. -The default value is 4000. -Specify [.in]`0` to not track any requests and [.in]`-1` to set no limit. - -To specify a different value, use: - -[source,sh] ----- -curl http://localhost:port/admin/settings -u user:pword \ - -H 'Content-Type: application/json' \ - -d '{"completed-limit":1000}' ----- - [[sys-completed-examples]] === Examples @@ -1715,6 +1584,137 @@ This example shows: <3> The profile attribute with all phases-related statistics for this query itself, which is querying the `system:completed_requests` keyspace. ==== +[[sys-completed-config]] +== Configure the Completed Requests + +You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API settings endpoint. + +In Couchbase Server 6.5 and later, you can specify the conditions for completed request logging using the `completed` field. + +This field takes a JSON object containing the names and values of logging qualifiers. +Completed requests that meet the defined qualifiers are logged. + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"user": "marco", "error": 12003}}' +---- + +=== Logging Qualifiers + +You can specify the following logging qualifiers. +A completed request is logged if _any_ of the qualifiers are met (logical OR). + +[horizontal] +`threshold`:: The execution time threshold in milliseconds. +`aborted`:: Whether to log requests that generate a panic. +`error`:: Log requests returning this error number. +`client`:: Log requests from this IP address. +`user`:: Log requests with this user name. +`context`:: Log requests with this client context ID. + +For full details, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_logging_parameters[Logging parameters]. + +The basic syntax adds a qualifier to the logging parameters, i.e. any existing qualifiers are not removed. +You can change the value of a logging qualifier by specifying the same qualifier again with a new value. + +To add a new instance of an existing qualifier, use a plus sign (`+`) before the qualifier name, e.g. `+user`. +To remove a qualifier, use a minus sign (`-`) before the qualifier name, e.g. `-user`. + +For example, the following request will add user `simon` to those tracked, and remove error `12003`. + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"+user": "simon", "-error": 12003}}' +---- + +Similarly, you could remove all logging by execution time with the following request, as long as the value matches the existing threshold. + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"-threshold": 1000}}' +---- + +=== Tagged Sets + +You can also specify qualifiers that have to be met as a group for the completed request to be logged (logical AND). + +To do this, specify the `tag` field along with a set of qualifiers, like so: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"user": "marco", "error": 12003, "tag": "both_user_and_error"}}' +---- + +In this case, the request will be logged when both user and error match. + +The tag name can be any string that is meaningful and unique. +Requests that match a tagged set of conditions are logged with a field `~tag`, which is set to the name of the tag. + +To add a qualifier to a tagged set, specify the tag name again along with the new qualifier: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"client": "172.1.2.3", "tag": "both_user_and_error"}}' +---- + +You cannot add a new instance of an existing qualifier to a tagged set using a plus sign (`+`) before the qualifier name. +For example, you cannot add a `user` qualifier to a tagged set that already contains a `user` qualifier. +If you need to track two users with the same error, create two tagged sets, one per user. + +You can remove a qualifier from a tagged set using a minus sign (`-`) before the qualifier name, e.g. `-user`. +When you remove the last qualifier from a tagged set, the tagged set is removed. + +[NOTE] +-- +You can specify multiple tagged sets. +In this case, completed requests are logged if they match all of the qualifiers in any of the tagged sets. + +You can also specify a mixture of tagged sets and individual qualifiers. +In this case, completed requests are logged if they match any of the individual qualifiers, or all of the qualifiers in any of the tagged sets. +-- + +=== Completed Threshold + +The [.param]`completed-threshold` field provides another way of specifying the `threshold` qualifier within the `completed` field. + +This field sets the minimum request duration after which requests are added to the `system:completed_requests` catalog. +The default value is 1000ms. +Specify [.in]`0` to log all requests and [.in]`-1` to not log any requests to the keyspace. + +To specify a different value, use: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed-threshold":0}' +---- + +=== Completed Limit + +The [.param]`completed-limit` field sets the number of most recent requests to be tracked in the `system:completed_requests` catalog. +The default value is 4000. +Specify [.in]`0` to not track any requests and [.in]`-1` to set no limit. + +To specify a different value, use: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed-limit":1000}' +---- + [#sys_my-user-info] == Monitor Your User Info From a41bb58af1fc155c69a24caaeaf8a7bcf2083a5d Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Sat, 18 May 2024 00:41:26 +0100 Subject: [PATCH 12/25] Move query profiling after manage and monitor sections --- .../n1ql-manage/monitoring-n1ql-query.adoc | 2080 ++++++++--------- 1 file changed, 1040 insertions(+), 1040 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index b7f2ccb65..16c789337 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -91,575 +91,150 @@ In the REST API examples: * `$USER` is the user name. * `$PASSWORD` is the password. -[#query-monitoring-settings] -== Query Profiling - -Query profiling enables you to obtain more detailed monitoring information and finer execution timings for any query. -You can set query profiling to the following levels: - -* `off` -- query profiling is disabled. -* `phases` -- query profiling is enabled, including information about the phases of query execution. -* `timings` -- query profiling is enabled, including information about the phases of query execution, and detailed timing information. - -You can set query profiling in the following ways: - -* At the <>, so that it is enabled for all queries on that node. -* At the <>, for individual queries. - -For more information about Query settings and parameters, see xref:n1ql:n1ql-manage/query-settings.adoc[]. - -[#enable-settings-for-a-query-engine] -=== Enable Query Profiling for a Query Node - -To activate query profiling at the node level, specify the `profile` setting using the xref:n1ql:n1ql-rest-api/admin.adoc[Admin REST API] (`/admin/settings` endpoint). +[#vitals] +== Monitor System Vitals -.See the current node-level query settings -==== -The following request gets the current node-level query settings. +The `system:vitals` catalog provides data about the running state and health of the query engine, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. +This information can be very useful to assess the current workload and performance characteristics of a query engine. -.Request -[source,sh] ----- -include::n1ql:example$settings/node-level-settings.sh[tag=curl] ----- +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. -.Results -[source,json] ----- -include::n1ql:example$settings/node-level-settings.jsonc[] ----- -==== +=== Get System Vitals -.Save node-level query settings to a file +[tabs] ==== -The following request saves the current node-level query settings to the file `query_settings.json`. +REST API:: ++ +-- +To view system vitals with Admin REST API: -.Request [source,sh] ---- -include::n1ql:example$settings/save-node-level-settings.sh[tag=curl] +curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ---- -==== +-- -.Set node-level query settings from a file -==== -Assuming that you have edited the file `query_settings.json` to specify the query settings you want, the following request -sets the node-level query settings according to the file. +{sqlpp}:: ++ +-- +To view system vitals with {sqlpp}: -.Request -[source,sh] +[source,sqlpp] ---- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -X POST \ - -d@./query_settings.json +SELECT * FROM system:vitals; ---- +-- ==== -.Set node-level query settings explicitly -==== -The following request explicitly sets query profiling at the node level. - -.Request [source,sh] ---- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"profile": "phases"}' +curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ---- -.Results [source,json] ---- { - // ... - "profile":"phases", - "request-size-cap": 67108864, - "scan-cap": 512, - "servicers": 4, - "timeout": 0, - "txtimeout": "0s", - "use-cbo": true + "uptime": "7h39m32.668577197s", + "local.time": "2021-04-30 18:42:39.517208807 +0000 UTC m=+27573.945319668", + "version": "7.0.0-N1QL", + "total.threads": 191, + "cores": 2, + "gc.num": 669810600, + "gc.pause.time": "57.586373ms", + "gc.pause.percent": 0, + "memory.usage": 247985184, + "memory.total": 11132383704, + "memory.system": 495554808, + "cpu.user.percent": 0, + "cpu.sys.percent": 0, + "request.completed.count": 140, + "request.active.count": 0, + "request.per.sec.1min": 0.0018, + "request.per.sec.5min": 0.0055, + "request.per.sec.15min": 0.0033, + "request_time.mean": "536.348163ms", + "request_time.median": "54.065567ms", + "request_time.80percentile": "981.869933ms", + "request_time.95percentile": "2.543128455s", + "request_time.99percentile": "4.627922799s", + "request.prepared.percent": 0 } ---- -==== -[#enable-settings-per-session-or-per-query] -=== Enable Query Profiling for a Request +[#sys-active-req] +== Monitor and Manage Active Requests -To activate profiling at the request level, do one of the following: +The `system:active_requests` catalog lists all currently executing active requests or queries. -* Specify the `profile` setting using the xref:n1ql:n1ql-rest-api/index.adoc[Query REST API] (`/query/service` endpoint). -* Specify the `profile` setting using the xref:n1ql:n1ql-intro/cbq.adoc[cbq] command line tool. +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. +The profile related attributes are described in the section <> + +[[sys-active-get]] +=== Get Active Requests [tabs] ==== REST API:: + -- -To set query settings using the REST API, specify the parameters in the request body. - -''' - -The following statement sets the profiling to phases: +To view active requests with Admin REST API: [source,sh] ---- -curl $BASE_URL/query/service -u $USER:$PASSWORD \ - -d 'profile=phases&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1' +curl -u $USER:$PASSWORD $BASE_URL/admin/active_requests ---- +-- -The following statement sets the profiling to timings: +{sqlpp}:: ++ +-- +To view active requests with {sqlpp}, including the query plan: -[source,sh] +[source,sqlpp] ---- -curl $BASE_URL/query/service -u $USER:$PASSWORD \ - -d 'profile=timings&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1' +SELECT *, meta().plan FROM system:active_requests; ---- -- +==== -{sqlpp}:: -+ --- -To set query settings using the cbq shell, use the `\SET` command. +[[sys-active-delete]] +=== Terminate an Active Request -''' +The DELETE command can be used to terminate an active request, for instance, a non-responding or a long-running query. -The following statement sets the profiling to phases: +[tabs] +==== +REST API:: ++ +-- +To terminate an active request [.var]`uuid` with the Admin REST API: -[source,sqlpp] +[source,sh] ---- -\set -profile "phases"; -SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; +curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/active_requests/uuid ---- +-- -The following statement sets the profiling to timings: +{sqlpp}:: ++ +-- +To terminate an active request [.var]`uuid` with {sqlpp}: [source,sqlpp] ---- -\set -profile "timings"; -SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; +DELETE FROM system:active_requests WHERE requestId = "uuid"; ---- -- ==== -The Query Workbench automatically enables Query profiling, with detailed timing information. -To disable or enable Query profiling with the Query Workbench, specify the *Collect query timings* option using the xref:tools:query-workbench.adoc#query-preferences[Query Preferences]. - -[#monitor-profile-details] -== Query Profiling Details - -You can access the profiling information in the following ways: - -* In the <>. -* In the <>. - -When a query executes a user-defined function, profiling information is available for the {sqlpp} queries within the user-defined function as well. - -[[profile]] -=== Profiling Details in Query Response - -When profiling is enabled: - -* If you are using the cbq shell or the Query REST API, query profiling information is returned with the query results. -* However, if you are using the Query workbench, query profiling information is not returned with the query results. +[[sys-active-examples]] +=== Examples -.Phases Profile +.Get Active ==== -If you are using the cbq shell or the Query REST API, the following statistics are returned when `profile` is set to `phases`: - -[source,json] +[source,sqlpp] ---- -{ - "requestID": "06d6c1c2-1a8a-4989-a856-7314f9eddee5", - "signature": { - "*": "*" - }, - "results": [ - { - "airline": { - "callsign": "MILE-AIR", - "country": "United States", - "iata": "Q5", - "icao": "MLA", - "id": 10, - "name": "40-Mile Air", - "type": "airline" - } - } - ], - "status": "success", - "metrics": { - "elapsedTime": "12.77927ms", - "executionTime": "12.570648ms", - "resultCount": 1, - "resultSize": 254, - "serviceLoad": 12 - }, - "profile": { - "phaseTimes": { - "authorize": "19.629µs", - "fetch": "401.997µs", - "instantiate": "147.686µs", - "parse": "4.545234ms", - "plan": "409.364µs", - "primaryScan": "6.103775ms", - "run": "6.699056ms" - }, - "phaseCounts": { - "fetch": 1, - "primaryScan": 1 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1 - }, - "requestTime": "2021-04-30T18:37:56.394Z", - "servicingHost": "127.0.0.1:8091" - } -} ----- -==== - -.Timings Profile -==== -If you are using the cbq shell or the Query REST API, the following statistics are returned when `profile` is set to `timings`: - -[source,json] ----- -{ - "requestID": "268a1240-6864-43a2-af13-ccb8d1e50abf", - "signature": { - "*": "*" - }, - "results": [ - { - "airline": { - "callsign": "MILE-AIR", - "country": "United States", - "iata": "Q5", - "icao": "MLA", - "id": 10, - "name": "40-Mile Air", - "type": "airline" - } - } - ], - "status": "success", - "metrics": { - "elapsedTime": "2.915245ms", - "executionTime": "2.755355ms", - "resultCount": 1, - "resultSize": 254, - "serviceLoad": 12 - }, - "profile": { - "phaseTimes": { - "authorize": "18.096µs", - "fetch": "388.122µs", - "instantiate": "31.702µs", - "parse": "646.157µs", - "plan": "120.427µs", - "primaryScan": "1.402918ms", - "run": "1.936852ms" - }, - "phaseCounts": { - "fetch": 1, - "primaryScan": 1 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1 - }, - "requestTime": "2021-04-30T18:40:13.239Z", - "servicingHost": "127.0.0.1:8091", - "executionTimings": { - "#operator": "Authorize", - "#stats": { - "#phaseSwitches": 4, - "execTime": "1.084µs", - "servTime": "17.012µs" - }, - "privileges": { - "List": [ - { - "Target": "default:travel-sample.inventory.airline", - "Priv": 7, - "Props": 0 - } - ] - }, - "~child": { - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 1, - "execTime": "2.474µs" - }, - "~children": [ - { - "#operator": "PrimaryScan3", - "#stats": { - "#itemsOut": 1, - "#phaseSwitches": 7, - "execTime": "18.584µs", - "kernTime": "8.869µs", - "servTime": "1.384334ms" - }, - "bucket": "travel-sample", - "index": "def_inventory_airline_primary", - "index_projection": { - "primary_key": true - }, - "keyspace": "airline", - "limit": "1", - "namespace": "default", - "scope": "inventory", - "using": "gsi" - }, - { - "#operator": "Fetch", - "#stats": { - "#itemsIn": 1, - "#itemsOut": 1, - "#phaseSwitches": 10, - "execTime": "25.64µs", - "kernTime": "1.427752ms", - "servTime": "362.482µs" - }, - "bucket": "travel-sample", - "keyspace": "airline", - "namespace": "default", - "scope": "inventory" - }, - { - "#operator": "InitialProject", - "#stats": { - "#itemsIn": 1, - "#itemsOut": 1, - "#phaseSwitches": 9, - "execTime": "6.006µs", - "kernTime": "1.825917ms" - }, - "result_terms": [ - { - "expr": "self", - "star": true - } - ] - }, - { - "#operator": "Limit", - "#stats": { - "#itemsIn": 1, - "#itemsOut": 1, - "#phaseSwitches": 4, - "execTime": "2.409µs", - "kernTime": "2.094µs" - }, - "expr": "1" - }, - { - "#operator": "Stream", - "#stats": { - "#itemsIn": 1, - "#itemsOut": 1, - "#phaseSwitches": 6, - "execTime": "46.964µs", - "kernTime": "1.844828ms" - } - } - ] - }, - "~versions": [ - "7.0.0-N1QL", - "7.0.0-4960-enterprise" - ] - } - } -} ----- -==== - -The `profile` object contains the following attributes: - -include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] - -The `kernTime`, `servTime`, and `execTime` statistics can be very helpful in troubleshooting query performance issues -For example: - -* A high `servTime` for a low number of items processed is an indication that the indexer or KV store is stressed. -* A high `kernTime` means there is a downstream issue in the query plan or the query server having many requests to process, so the scheduled waiting time will be more for CPU time. - -[[plan]] -=== Profiling Details in System Catalogs - -The following system catalogs support the `meta().plan` virtual attribute, which captures the whole query plan, including query profiling information. - -* <> -* <> -* <> - -With the `system:active_requests` and `system:completed_requests` catalogs, not all statements have a `meta().plan` attribute. -The `meta().plan` attribute is only available for statements that run when the profile is set to `timings`. - -With the `system:prepareds` catalog, the `meta().plan` attribute is available for all statements. - -You must explicitly specify `meta().plan` in the projection list for the SELECT query. -For a detailed example, see <>. - -The `meta().plan` attribute contains similar properties to the `profile` object included with the query results when profiling is active. - -[NOTE] -==== -For active requests, `phaseTimes` and `phaseCounts` are dynamic, depending on the documents processed by various phases up to this moment in time. -A new query on `system:active_requests` will return different values. -==== - -[#vitals] -== Monitor System Vitals - -The `system:vitals` catalog provides data about the running state and health of the query engine, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. -This information can be very useful to assess the current workload and performance characteristics of a query engine. - -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. - -=== Get System Vitals - -[tabs] -==== -REST API:: -+ --- -To view system vitals with Admin REST API: - -[source,sh] ----- -curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ----- --- - -{sqlpp}:: -+ --- -To view system vitals with {sqlpp}: - -[source,sqlpp] ----- -SELECT * FROM system:vitals; ----- --- -==== - -[source,sh] ----- -curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ----- - -[source,json] ----- -{ - "uptime": "7h39m32.668577197s", - "local.time": "2021-04-30 18:42:39.517208807 +0000 UTC m=+27573.945319668", - "version": "7.0.0-N1QL", - "total.threads": 191, - "cores": 2, - "gc.num": 669810600, - "gc.pause.time": "57.586373ms", - "gc.pause.percent": 0, - "memory.usage": 247985184, - "memory.total": 11132383704, - "memory.system": 495554808, - "cpu.user.percent": 0, - "cpu.sys.percent": 0, - "request.completed.count": 140, - "request.active.count": 0, - "request.per.sec.1min": 0.0018, - "request.per.sec.5min": 0.0055, - "request.per.sec.15min": 0.0033, - "request_time.mean": "536.348163ms", - "request_time.median": "54.065567ms", - "request_time.80percentile": "981.869933ms", - "request_time.95percentile": "2.543128455s", - "request_time.99percentile": "4.627922799s", - "request.prepared.percent": 0 -} ----- - -[#sys-active-req] -== Monitor and Manage Active Requests - -The `system:active_requests` catalog lists all currently executing active requests or queries. - -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. -The profile related attributes are described in the section <> - -[[sys-active-get]] -=== Get Active Requests - -[tabs] -==== -REST API:: -+ --- -To view active requests with Admin REST API: - -[source,sh] ----- -curl -u $USER:$PASSWORD $BASE_URL/admin/active_requests ----- --- - -{sqlpp}:: -+ --- -To view active requests with {sqlpp}, including the query plan: - -[source,sqlpp] ----- -SELECT *, meta().plan FROM system:active_requests; ----- --- -==== - -[[sys-active-delete]] -=== Terminate an Active Request - -The DELETE command can be used to terminate an active request, for instance, a non-responding or a long-running query. - -[tabs] -==== -REST API:: -+ --- -To terminate an active request [.var]`uuid` with the Admin REST API: - -[source,sh] ----- -curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/active_requests/uuid ----- --- - -{sqlpp}:: -+ --- -To terminate an active request [.var]`uuid` with {sqlpp}: - -[source,sqlpp] ----- -DELETE FROM system:active_requests WHERE requestId = "uuid"; ----- --- -==== - -[[sys-active-examples]] -=== Examples - -.Get Active -==== -[source,sqlpp] ----- -SELECT *, meta().plan FROM system:active_requests; +SELECT *, meta().plan FROM system:active_requests; ---- [source,json] @@ -1038,682 +613,1107 @@ PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = "U2"; } ---- -.Prepared statement with specified query context -- using cbq +.Prepared statement with specified query context -- using cbq +[source,sqlpp] +---- +\SET -query_context travel-sample.inventory; +PREPARE p1 AS SELECT * FROM airline WHERE iata = "U2"; +---- + +[source,json] +---- +{ + "requestID": "1c90603e-5e42-42b4-9362-4fc96bf895ac", + "signature": "json", + "results": [ + { + "encoded_plan": "H4sIAAAAAAAA/wEAAP//AAAAAAAAAAA=", + "featureControls": 76, + "indexApiVersion": 4, + "indexScanKeyspaces": { + "default:travel-sample.inventory.airline": false + }, + "name": "[127.0.0.1:8091]p1", + "namespace": "default", + "operator": { + "#operator": "Authorize", + "privileges": { + "List": [ + { + "Priv": 7, + "Props": 0, + "Target": "default:travel-sample.inventory.airline" + } + ] + }, + "~child": { + "#operator": "Sequence", + "~children": [ + { + "#operator": "Sequence", + "~children": [ + { + "#operator": "PrimaryScan3", + "bucket": "travel-sample", + "index": "def_inventory_airline_primary", + "index_projection": { + "primary_key": true + }, + "keyspace": "airline", + "namespace": "default", + "scope": "inventory", + "using": "gsi" + }, + { + "#operator": "Fetch", + "bucket": "travel-sample", + "keyspace": "airline", + "namespace": "default", + "scope": "inventory" + }, + { + "#operator": "Parallel", + "~child": { + "#operator": "Sequence", + "~children": [ + { + "#operator": "Filter", + "condition": "((`airline`.`iata`) = \"U2\")" + }, + { + "#operator": "InitialProject", + "result_terms": [ + { + "expr": "self", + "star": true + } + ] + } + ] + } + } + ] + }, + { + "#operator": "Stream" + } + ] + } + }, + "queryContext": "travel-sample.inventory", + "reqType": "SELECT", + "signature": { + "*": "*" + }, + "text": "PREPARE p1 AS SELECT * FROM airline WHERE iata = \"U2\";", + "useCBO": true + } + ], + "status": "success", + "metrics": { + "elapsedTime": "17.476424ms", + "executionTime": "17.187836ms", + "resultCount": 1, + "resultSize": 3298, + "serviceLoad": 12 + } +} +---- + +.List prepared statements +[source,sqlpp] +---- +SELECT *, meta().plan FROM system:prepareds; +---- + +[source,json] +---- +{ + "requestID": "d976e59a-d74e-4350-b0df-fa137099d594", + "signature": { + "*": "*", + "plan": "json" + }, + "results": [ + { + "plan": { + // ... + }, + "prepareds": { + "encoded_plan": "H4sIAAAAAAAA/6RTUW/TPBT9K9H5XrbJ30QBMcmIhzJ1AjG0qh3wwKbEJLedmWt71061UIXfjpxkndYhENpbYt97z7nn+GxAtnQVVbk3ykICAgtSsWY6djayMwHy6JWAthXdjr3+TBy0s5Avh7N5qewHaoJXJQXIDSpaqNpEGVmtyfwf1MobOtR2TTY6bg6VZqMtQS6UCdQKWLUiSPgR+u9uFOTdIAg4T6yi4zT+v/sfjOt45Vj/IAh41mttaNmTONUhQn7d4FzxkuL9tL/SEpiyXkMepQ/nA+Sz9rIV+FleaVPtMpjTTU22TG19AZPtcP+5aMp6pbhJcr6AwLe6vO54P+CLQfR+n3zLPh/Y576fcleXe3bfqYydYxsMt/k1NZCR66T+9eAdJO4l+L0NoXQ+nWxhIVAHbZeQWAaNVjxc6YRiefWnXZ6EvYs2VayMIYMneXWiTSSGQOlspXvhsLdXDPyKw0KrqIr97E12gU/PL7D/iMh7q6NWZtpLDwGmUJuYR+JV6ADp1qfCQGaRVouKBzsu28s2vbYd4pFJrZDuBFJOtyE8Go0EbmriJqWVbmOfYKab86aTaz45nRyfJxC9tF2skyoHkDhAKzC0TGeT6Xg2yfwoG8+zvic7yE5mZx+z4oFpxePEZF/eTWaTLMmyFeV19zLo+O3ZsNivAAAA//+q+jhuaAQAAA==", + "featuresControl": 76, + "indexApiVersion": 4, + "indexScanKeyspaces": { + "default:travel-sample.inventory.airline": false + }, + "name": "p1", // <1> + "namespace": "default", + "node": "127.0.0.1:8091", + "statement": "PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = \"U2\";", + "uses": 0 + } + }, + { + "plan": { + // ... + }, + "prepareds": { + "encoded_plan": "H4sIAAAAAAAA/6STT28TMRDFv8rqcWkrExFAVDLiEKpUIIoaJQUOtNqY3Ulq6tju2Bt1iZbPjry7TWmKQKg3/xnPvPk9zwZkC1dSmXujLCQgsCAVK6YjZyM7EyAPXwloW9LNyOvPxEE7C/myP5sVyn6gOnhVUIDcoKSFqkyUkdWazNOgVt7QQNs12ei4HijNRluCXCgTqBGwakWQ8EN06zYV5G0iCDhPrKLjlP7J3QajKl461j8IAp71WhtadiJOdIiQXzc4U7ykeJftn7IEJqzXkIdp4XyAfNZcNAI/i0ttyl0FM7quyBbpWRfAZNu6/x00Yb1SXCecLyDwrSquWt339KKH3vWTb9Xnvfrcd1lu43LP7jsVsXVsg/42v6IaMnKV6F/13kHiDsGfbQiF8+lkWxYCVdB2CYll0GjE/ZaOKRaXf+vlUbV3q00UK2PI4FFeHWsTiSFQOFvqDhz29ua9vvlgrlVU8/3sTXaOT8/Psf9AyHuro1Zm0qGHAFOoTMwj8Sq0BenGp8BAZpFai4p7Oy6aiyb9th3hkUmtkO4E0pxuh/BwOBS4rojrNK108wDy4HevmK7P6pbibHwyPjpLtfXSttOeYB1A4gCNQJ9pMh1PRtNx5ofZaJZ1b7KD7Hh6+jHreWRf3o2n4ywx2RJ53X4LOnp72nf1KwAA////9+bsZQQAAA==", + "featuresControl": 76, + "indexApiVersion": 4, + "indexScanKeyspaces": { + "default:travel-sample.inventory.airline": false + }, + "name": "p1(travel-sample.inventory)", // <2> + "namespace": "default", + "node": "127.0.0.1:8091", + "statement": "PREPARE p1 AS SELECT * FROM airline WHERE iata = \"U2\";", + "uses": 0 + } + } + ], + "status": "success", + "metrics": { + "elapsedTime": "25.323496ms", + "executionTime": "25.173646ms", + "resultCount": 2, + "resultSize": 7891, + "serviceLoad": 12 + } +} +---- + +Note that the names of the prepared statements are identical, but they are associated with different query contexts. + +<.> The name of the prepared statement for the default query context +<.> The name of the prepared statement showing the associated query context +==== + +[#sys-completed-req] +== Monitor and Manage Completed Requests + +By default, the `system:completed_requests` catalog maintains a list of the most recent completed requests that have run longer than a predefined threshold of time. +(You can also log completed requests that meet other conditions that you define.) + +For each completed request, this catalog maintains information such as requestId, statement text, prepared name (if prepared statement), request time, service time, and so on. +This information provides a general insight into the health and performance of the query engine and the cluster. + +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. +Most field names and meanings match exactly those of `system:active_requests`. + +Note that the `completed` state means that the request was started and completed by the Query service, but it does not mean that it was necessarily successful. +The request could have been successful, or completed with errors. + +To find requests that completed successfully, search for completed requests whose `state` is `completed` and whose `errorCount` field has the value `0`. + +[NOTE] +==== +Request profiling affects the `system:completed_requests` keyspace in the following ways: + +* When the feature is turned on, completed requests are stored with their execution plan. +* Profiling information is likely to use 100KB+ per entry. +* Due to the added overhead of running both profiling and logging, we recommend turning on both of them only when needed. +Running only one of them continuously has no noticeable affect on performance. +* Profiling does not carry any extra cost beyond memory for completed requests, so it's fine to run it continuously. +==== + +[[sys-completed-get]] +=== Get Completed Requests + +[tabs] +==== +REST API:: ++ +-- +To get a list of all logged completed requests using the Admin REST API: + +[source,sh] +---- +curl -u $USER:$PASSWORD $BASE_URL/admin/completed_requests +---- +-- + +{sqlpp}:: ++ +-- +To get a list of all logged completed requests using {sqlpp}, including the query plan: + [source,sqlpp] ---- -\SET -query_context travel-sample.inventory; -PREPARE p1 AS SELECT * FROM airline WHERE iata = "U2"; +SELECT *, meta().plan FROM system:completed_requests; +---- + +To get a list of all logged completed requests using {sqlpp}, including only successful requests: + +[source,sqlpp] +---- +SELECT * FROM system:completed_requests +WHERE state = "completed" AND errorCount = 0; +---- +-- +==== + +[[sys-completed-delete]] +=== Purge the Completed Requests + +[tabs] +==== +REST API:: ++ +-- +To purge a completed request [.var]`uuid` with the Admin REST API: + +[source,sh] +---- +curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/completed_requests/uuid +---- +-- + +{sqlpp}:: ++ +-- +To purge a completed request [.var]`uuid` with {sqlpp}: + +[source,sqlpp] +---- +DELETE FROM system:completed_requests WHERE requestId = "uuid"; +---- + +To purge the completed requests for a given time period, use: + +[source,sqlpp] +---- +DELETE FROM system:completed_requests WHERE requestTime LIKE "2015-09-09%"; +---- +-- +==== + +[[sys-completed-examples]] +=== Examples + +[[example-2]] +.Completed Request +==== +First, using the cbq shell, we set `profile = "timings"` and run a long query which takes at least 1000ms (the default value of the `completed-threshold` query setting) to get registered in the `system:completed_requests` keyspace: + +.Query 1 +[source,sqlpp] +---- +\set -profile "timings"; +SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport; +---- + +Now, using the cbq shell, we change the profile setting to "phases" and rerun another long query: + +.Query 2 +[source,sqlpp] +---- +\set -profile "phases"; +SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport; +---- + +Run a query `system:completed_requests` keyspace with `meta().plan`. + +.Query 3 +[source,sqlpp] +---- +SELECT meta().plan, * from system:completed_requests; ---- +.Result [source,json] ---- { - "requestID": "1c90603e-5e42-42b4-9362-4fc96bf895ac", - "signature": "json", + "requestID": "4a36e1dc-cea0-4ba2-a428-258511d50582", + "signature": { + "*": "*", + "plan": "json" + }, "results": [ - { - "encoded_plan": "H4sIAAAAAAAA/wEAAP//AAAAAAAAAAA=", - "featureControls": 76, - "indexApiVersion": 4, - "indexScanKeyspaces": { - "default:travel-sample.inventory.airline": false + // ... + { // <1> + "completed_requests": { + "elapsedTime": "15.641879295s", + "errorCount": 0, + "node": "127.0.0.1:8091", + "phaseCounts": { + "fetch": 24024, + "primaryScan": 24024, + "sort": 24024 + }, + "phaseOperators": { + "authorize": 1, + "fetch": 1, + "primaryScan": 1, + "sort": 1 + }, + "phaseTimes": { + "authorize": "51.305µs", + "fetch": "3.27276723s", + "instantiate": "60.662µs", + "parse": "66.701943ms", + "plan": "15.12951ms", + "primaryScan": "171.439769ms", + "run": "15.548781894s", + "sort": "153.767638ms" + }, + "remoteAddr": "172.17.0.1:56962", + "requestId": "08445bae-66ef-4ccd-8b2d-ea899b453a1b", + "requestTime": "2021-04-30T21:14:57.576Z", + "resultCount": 24024, + "resultSize": 81821919, + "scanConsistency": "unbounded", + "serviceTime": "15.630714144s", + "state": "completed", + "statement": "SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport;", + "useCBO": true, + "userAgent": "Go-http-client/1.1 (CBQ/2.0)", + "users": "Administrator" + } + }, + // ... + { // <2> + "completed_requests": { + "elapsedTime": "15.321128463s", + "errorCount": 0, + "node": "127.0.0.1:8091", + "phaseCounts": { + "fetch": 24024, + "primaryScan": 24024, + "sort": 24024 + }, + "phaseOperators": { + "authorize": 1, + "fetch": 1, + "primaryScan": 1, + "sort": 1 + }, + "phaseTimes": { + "authorize": "23.037µs", + "fetch": "3.092306635s", + "instantiate": "7.313569ms", + "parse": "579.368µs", + "plan": "2.449143ms", + "primaryScan": "153.686873ms", + "run": "15.29433203s", + "sort": "147.889352ms" + }, + "remoteAddr": "172.17.0.1:56900", + "requestId": "5eefc9e5-bdaa-4824-bcd7-47977eb1f08a", + "requestTime": "2021-04-30T21:13:58.707Z", + "resultCount": 24024, + "resultSize": 81821919, + "scanConsistency": "unbounded", + "serviceTime": "15.30510306s", + "state": "completed", + "statement": "SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport;", + "useCBO": true, + "userAgent": "Go-http-client/1.1 (CBQ/2.0)", + "users": "Administrator" }, - "name": "[127.0.0.1:8091]p1", - "namespace": "default", - "operator": { + "plan": { "#operator": "Authorize", + "#stats": { + "#phaseSwitches": 4, + "execTime": "1.725µs", + "servTime": "21.312µs" + }, "privileges": { "List": [ { "Priv": 7, "Props": 0, - "Target": "default:travel-sample.inventory.airline" + "Target": "default:travel-sample.inventory.route" } ] }, "~child": { "#operator": "Sequence", + "#stats": { + "#phaseSwitches": 2, + "execTime": "1.499µs" + }, "~children": [ { - "#operator": "Sequence", - "~children": [ - { - "#operator": "PrimaryScan3", - "bucket": "travel-sample", - "index": "def_inventory_airline_primary", - "index_projection": { - "primary_key": true - }, - "keyspace": "airline", - "namespace": "default", - "scope": "inventory", - "using": "gsi" - }, + "#operator": "PrimaryScan3", + "#stats": { + "#heartbeatYields": 6, + "#itemsOut": 24024, + "#phaseSwitches": 96099, + "execTime": "84.366121ms", + "kernTime": "3.021901421s", + "servTime": "69.320752ms" + }, + "bucket": "travel-sample", + "index": "def_inventory_route_primary", + "index_projection": { + "primary_key": true + }, + "keyspace": "route", + "namespace": "default", + "scope": "inventory", + "using": "gsi" + }, + { + "#operator": "Fetch", + "#stats": { + "#heartbeatYields": 7258, + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 99104, + "execTime": "70.34694ms", + "kernTime": "142.630196ms", + "servTime": "3.021959695s" + }, + "bucket": "travel-sample", + "keyspace": "route", + "namespace": "default", + "scope": "inventory" + }, + { + "#operator": "InitialProject", + "#stats": { + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 96100, + "execTime": "15.331951ms", + "kernTime": "3.219612458s" + }, + "result_terms": [ { - "#operator": "Fetch", - "bucket": "travel-sample", - "keyspace": "airline", - "namespace": "default", - "scope": "inventory" - }, + "expr": "self", + "star": true + } + ] + }, + { + "#operator": "Order", + "#stats": { + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 72078, + "execTime": "147.889352ms", + "kernTime": "3.229055752s" + }, + "sort_terms": [ { - "#operator": "Parallel", - "~child": { - "#operator": "Sequence", - "~children": [ - { - "#operator": "Filter", - "condition": "((`airline`.`iata`) = \"U2\")" - }, - { - "#operator": "InitialProject", - "result_terms": [ - { - "expr": "self", - "star": true - } - ] - } - ] - } + "expr": "(`route`.`sourceairport`)" } ] }, { - "#operator": "Stream" + "#operator": "Stream", + "#stats": { + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 24025, + "execTime": "11.851634134s" + } } ] - } - }, - "queryContext": "travel-sample.inventory", - "reqType": "SELECT", - "signature": { - "*": "*" - }, - "text": "PREPARE p1 AS SELECT * FROM airline WHERE iata = \"U2\";", - "useCBO": true + }, + "~versions": [ + "7.0.0-N1QL", + "7.0.0-4960-enterprise" + ] + } } ], "status": "success", "metrics": { - "elapsedTime": "17.476424ms", - "executionTime": "17.187836ms", - "resultCount": 1, - "resultSize": 3298, + "elapsedTime": "172.831251ms", + "executionTime": "172.586836ms", + "resultCount": 40, + "resultSize": 65181, "serviceLoad": 12 + }, + "profile": { // <3> + "phaseTimes": { + "authorize": "19.912µs", + "fetch": "123.022426ms", + "instantiate": "29.424µs", + "parse": "6.414711ms", + "plan": "3.19076ms", + "primaryScan": "55.521683ms", + "run": "158.514001ms" + }, + "phaseCounts": { + "fetch": 40, + "primaryScan": 40 + }, + "phaseOperators": { + "authorize": 1, + "fetch": 1, + "primaryScan": 1 + }, + "requestTime": "2021-04-30T21:15:18.104Z", + "servicingHost": "127.0.0.1:8091" } } ---- -.List prepared statements -[source,sqlpp] +This example shows: + +<1> The profile attribute with all phases-related statistics for Query 2. +<2> The `meta().plan` with all detailed statistics collected for Query 1. +<3> The profile attribute with all phases-related statistics for this query itself, which is querying the `system:completed_requests` keyspace. +==== + +[[sys-completed-config]] +== Configure the Completed Requests + +You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API settings endpoint. + +In Couchbase Server 6.5 and later, you can specify the conditions for completed request logging using the `completed` field. + +This field takes a JSON object containing the names and values of logging qualifiers. +Completed requests that meet the defined qualifiers are logged. + +[source,sh] ---- -SELECT *, meta().plan FROM system:prepareds; +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"user": "marco", "error": 12003}}' ---- -[source,json] +=== Logging Qualifiers + +You can specify the following logging qualifiers. +A completed request is logged if _any_ of the qualifiers are met (logical OR). + +[horizontal] +`threshold`:: The execution time threshold in milliseconds. +`aborted`:: Whether to log requests that generate a panic. +`error`:: Log requests returning this error number. +`client`:: Log requests from this IP address. +`user`:: Log requests with this user name. +`context`:: Log requests with this client context ID. + +For full details, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_logging_parameters[Logging parameters]. + +The basic syntax adds a qualifier to the logging parameters, i.e. any existing qualifiers are not removed. +You can change the value of a logging qualifier by specifying the same qualifier again with a new value. + +To add a new instance of an existing qualifier, use a plus sign (`+`) before the qualifier name, e.g. `+user`. +To remove a qualifier, use a minus sign (`-`) before the qualifier name, e.g. `-user`. + +For example, the following request will add user `simon` to those tracked, and remove error `12003`. + +[source,sh] ---- -{ - "requestID": "d976e59a-d74e-4350-b0df-fa137099d594", - "signature": { - "*": "*", - "plan": "json" - }, - "results": [ - { - "plan": { - // ... - }, - "prepareds": { - "encoded_plan": "H4sIAAAAAAAA/6RTUW/TPBT9K9H5XrbJ30QBMcmIhzJ1AjG0qh3wwKbEJLedmWt71061UIXfjpxkndYhENpbYt97z7nn+GxAtnQVVbk3ykICAgtSsWY6djayMwHy6JWAthXdjr3+TBy0s5Avh7N5qewHaoJXJQXIDSpaqNpEGVmtyfwf1MobOtR2TTY6bg6VZqMtQS6UCdQKWLUiSPgR+u9uFOTdIAg4T6yi4zT+v/sfjOt45Vj/IAh41mttaNmTONUhQn7d4FzxkuL9tL/SEpiyXkMepQ/nA+Sz9rIV+FleaVPtMpjTTU22TG19AZPtcP+5aMp6pbhJcr6AwLe6vO54P+CLQfR+n3zLPh/Y576fcleXe3bfqYydYxsMt/k1NZCR66T+9eAdJO4l+L0NoXQ+nWxhIVAHbZeQWAaNVjxc6YRiefWnXZ6EvYs2VayMIYMneXWiTSSGQOlspXvhsLdXDPyKw0KrqIr97E12gU/PL7D/iMh7q6NWZtpLDwGmUJuYR+JV6ADp1qfCQGaRVouKBzsu28s2vbYd4pFJrZDuBFJOtyE8Go0EbmriJqWVbmOfYKab86aTaz45nRyfJxC9tF2skyoHkDhAKzC0TGeT6Xg2yfwoG8+zvic7yE5mZx+z4oFpxePEZF/eTWaTLMmyFeV19zLo+O3ZsNivAAAA//+q+jhuaAQAAA==", - "featuresControl": 76, - "indexApiVersion": 4, - "indexScanKeyspaces": { - "default:travel-sample.inventory.airline": false - }, - "name": "p1", // <1> - "namespace": "default", - "node": "127.0.0.1:8091", - "statement": "PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = \"U2\";", - "uses": 0 - } - }, - { - "plan": { - // ... - }, - "prepareds": { - "encoded_plan": "H4sIAAAAAAAA/6STT28TMRDFv8rqcWkrExFAVDLiEKpUIIoaJQUOtNqY3Ulq6tju2Bt1iZbPjry7TWmKQKg3/xnPvPk9zwZkC1dSmXujLCQgsCAVK6YjZyM7EyAPXwloW9LNyOvPxEE7C/myP5sVyn6gOnhVUIDcoKSFqkyUkdWazNOgVt7QQNs12ei4HijNRluCXCgTqBGwakWQ8EN06zYV5G0iCDhPrKLjlP7J3QajKl461j8IAp71WhtadiJOdIiQXzc4U7ykeJftn7IEJqzXkIdp4XyAfNZcNAI/i0ttyl0FM7quyBbpWRfAZNu6/x00Yb1SXCecLyDwrSquWt339KKH3vWTb9Xnvfrcd1lu43LP7jsVsXVsg/42v6IaMnKV6F/13kHiDsGfbQiF8+lkWxYCVdB2CYll0GjE/ZaOKRaXf+vlUbV3q00UK2PI4FFeHWsTiSFQOFvqDhz29ua9vvlgrlVU8/3sTXaOT8/Psf9AyHuro1Zm0qGHAFOoTMwj8Sq0BenGp8BAZpFai4p7Oy6aiyb9th3hkUmtkO4E0pxuh/BwOBS4rojrNK108wDy4HevmK7P6pbibHwyPjpLtfXSttOeYB1A4gCNQJ9pMh1PRtNx5ofZaJZ1b7KD7Hh6+jHreWRf3o2n4ywx2RJ53X4LOnp72nf1KwAA////9+bsZQQAAA==", - "featuresControl": 76, - "indexApiVersion": 4, - "indexScanKeyspaces": { - "default:travel-sample.inventory.airline": false - }, - "name": "p1(travel-sample.inventory)", // <2> - "namespace": "default", - "node": "127.0.0.1:8091", - "statement": "PREPARE p1 AS SELECT * FROM airline WHERE iata = \"U2\";", - "uses": 0 - } - } - ], - "status": "success", - "metrics": { - "elapsedTime": "25.323496ms", - "executionTime": "25.173646ms", - "resultCount": 2, - "resultSize": 7891, - "serviceLoad": 12 - } -} +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"+user": "simon", "-error": 12003}}' +---- + +Similarly, you could remove all logging by execution time with the following request, as long as the value matches the existing threshold. + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"-threshold": 1000}}' +---- + +=== Tagged Sets + +You can also specify qualifiers that have to be met as a group for the completed request to be logged (logical AND). + +To do this, specify the `tag` field along with a set of qualifiers, like so: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"user": "marco", "error": 12003, "tag": "both_user_and_error"}}' +---- + +In this case, the request will be logged when both user and error match. + +The tag name can be any string that is meaningful and unique. +Requests that match a tagged set of conditions are logged with a field `~tag`, which is set to the name of the tag. + +To add a qualifier to a tagged set, specify the tag name again along with the new qualifier: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed": {"client": "172.1.2.3", "tag": "both_user_and_error"}}' +---- + +You cannot add a new instance of an existing qualifier to a tagged set using a plus sign (`+`) before the qualifier name. +For example, you cannot add a `user` qualifier to a tagged set that already contains a `user` qualifier. +If you need to track two users with the same error, create two tagged sets, one per user. + +You can remove a qualifier from a tagged set using a minus sign (`-`) before the qualifier name, e.g. `-user`. +When you remove the last qualifier from a tagged set, the tagged set is removed. + +[NOTE] +-- +You can specify multiple tagged sets. +In this case, completed requests are logged if they match all of the qualifiers in any of the tagged sets. + +You can also specify a mixture of tagged sets and individual qualifiers. +In this case, completed requests are logged if they match any of the individual qualifiers, or all of the qualifiers in any of the tagged sets. +-- + +=== Completed Threshold + +The [.param]`completed-threshold` field provides another way of specifying the `threshold` qualifier within the `completed` field. + +This field sets the minimum request duration after which requests are added to the `system:completed_requests` catalog. +The default value is 1000ms. +Specify [.in]`0` to log all requests and [.in]`-1` to not log any requests to the keyspace. + +To specify a different value, use: + +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed-threshold":0}' ---- -Note that the names of the prepared statements are identical, but they are associated with different query contexts. +=== Completed Limit -<.> The name of the prepared statement for the default query context -<.> The name of the prepared statement showing the associated query context -==== +The [.param]`completed-limit` field sets the number of most recent requests to be tracked in the `system:completed_requests` catalog. +The default value is 4000. +Specify [.in]`0` to not track any requests and [.in]`-1` to set no limit. -[#sys-completed-req] -== Monitor and Manage Completed Requests +To specify a different value, use: -By default, the `system:completed_requests` catalog maintains a list of the most recent completed requests that have run longer than a predefined threshold of time. -(You can also log completed requests that meet other conditions that you define.) +[source,sh] +---- +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"completed-limit":1000}' +---- -For each completed request, this catalog maintains information such as requestId, statement text, prepared name (if prepared statement), request time, service time, and so on. -This information provides a general insight into the health and performance of the query engine and the cluster. +[#query-monitoring-settings] +== Query Profiling -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. -Most field names and meanings match exactly those of `system:active_requests`. +Query profiling enables you to obtain more detailed monitoring information and finer execution timings for any query. +You can set query profiling to the following levels: -Note that the `completed` state means that the request was started and completed by the Query service, but it does not mean that it was necessarily successful. -The request could have been successful, or completed with errors. +* `off` -- query profiling is disabled. +* `phases` -- query profiling is enabled, including information about the phases of query execution. +* `timings` -- query profiling is enabled, including information about the phases of query execution, and detailed timing information. -To find requests that completed successfully, search for completed requests whose `state` is `completed` and whose `errorCount` field has the value `0`. +You can set query profiling in the following ways: -[NOTE] -==== -Request profiling affects the `system:completed_requests` keyspace in the following ways: +* At the <>, so that it is enabled for all queries on that node. +* At the <>, for individual queries. -* When the feature is turned on, completed requests are stored with their execution plan. -* Profiling information is likely to use 100KB+ per entry. -* Due to the added overhead of running both profiling and logging, we recommend turning on both of them only when needed. -Running only one of them continuously has no noticeable affect on performance. -* Profiling does not carry any extra cost beyond memory for completed requests, so it's fine to run it continuously. +For more information about Query settings and parameters, see xref:n1ql:n1ql-manage/query-settings.adoc[]. + +[#enable-settings-for-a-query-engine] +=== Enable Query Profiling for a Query Node + +To activate query profiling at the node level, specify the `profile` setting using the xref:n1ql:n1ql-rest-api/admin.adoc[Admin REST API] (`/admin/settings` endpoint). + +.See the current node-level query settings ==== +The following request gets the current node-level query settings. -[[sys-completed-get]] -=== Get Completed Requests +.Request +[source,sh] +---- +include::n1ql:example$settings/node-level-settings.sh[tag=curl] +---- -[tabs] +.Results +[source,json] +---- +include::n1ql:example$settings/node-level-settings.jsonc[] +---- ==== -REST API:: -+ --- -To get a list of all logged completed requests using the Admin REST API: +.Save node-level query settings to a file +==== +The following request saves the current node-level query settings to the file `query_settings.json`. + +.Request [source,sh] ---- -curl -u $USER:$PASSWORD $BASE_URL/admin/completed_requests +include::n1ql:example$settings/save-node-level-settings.sh[tag=curl] ---- --- +==== -{sqlpp}:: -+ --- -To get a list of all logged completed requests using {sqlpp}, including the query plan: +.Set node-level query settings from a file +==== +Assuming that you have edited the file `query_settings.json` to specify the query settings you want, the following request +sets the node-level query settings according to the file. -[source,sqlpp] +.Request +[source,sh] ---- -SELECT *, meta().plan FROM system:completed_requests; +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -X POST \ + -d@./query_settings.json ---- +==== -To get a list of all logged completed requests using {sqlpp}, including only successful requests: +.Set node-level query settings explicitly +==== +The following request explicitly sets query profiling at the node level. -[source,sqlpp] +.Request +[source,sh] ---- -SELECT * FROM system:completed_requests -WHERE state = "completed" AND errorCount = 0; +curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ + -H 'Content-Type: application/json' \ + -d '{"profile": "phases"}' +---- + +.Results +[source,json] +---- +{ + // ... + "profile":"phases", + "request-size-cap": 67108864, + "scan-cap": 512, + "servicers": 4, + "timeout": 0, + "txtimeout": "0s", + "use-cbo": true +} ---- --- ==== -[[sys-completed-delete]] -=== Purge the Completed Requests +[#enable-settings-per-session-or-per-query] +=== Enable Query Profiling for a Request + +To activate profiling at the request level, do one of the following: + +* Specify the `profile` setting using the xref:n1ql:n1ql-rest-api/index.adoc[Query REST API] (`/query/service` endpoint). +* Specify the `profile` setting using the xref:n1ql:n1ql-intro/cbq.adoc[cbq] command line tool. [tabs] ==== REST API:: + -- -To purge a completed request [.var]`uuid` with the Admin REST API: +To set query settings using the REST API, specify the parameters in the request body. + +''' + +The following statement sets the profiling to phases: [source,sh] ---- -curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/completed_requests/uuid +curl $BASE_URL/query/service -u $USER:$PASSWORD \ + -d 'profile=phases&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1' +---- + +The following statement sets the profiling to timings: + +[source,sh] +---- +curl $BASE_URL/query/service -u $USER:$PASSWORD \ + -d 'profile=timings&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1' ---- -- {sqlpp}:: + -- -To purge a completed request [.var]`uuid` with {sqlpp}: +To set query settings using the cbq shell, use the `\SET` command. + +''' + +The following statement sets the profiling to phases: [source,sqlpp] ---- -DELETE FROM system:completed_requests WHERE requestId = "uuid"; +\set -profile "phases"; +SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; ---- -To purge the completed requests for a given time period, use: +The following statement sets the profiling to timings: [source,sqlpp] ---- -DELETE FROM system:completed_requests WHERE requestTime LIKE "2015-09-09%"; +\set -profile "timings"; +SELECT * FROM `travel-sample`.inventory.airline LIMIT 1; ---- -- ==== -[[sys-completed-examples]] -=== Examples +The Query Workbench automatically enables Query profiling, with detailed timing information. +To disable or enable Query profiling with the Query Workbench, specify the *Collect query timings* option using the xref:tools:query-workbench.adoc#query-preferences[Query Preferences]. -[[example-2]] -.Completed Request -==== -First, using the cbq shell, we set `profile = "timings"` and run a long query which takes at least 1000ms (the default value of the `completed-threshold` query setting) to get registered in the `system:completed_requests` keyspace: +[#monitor-profile-details] +== Query Profiling Details -.Query 1 -[source,sqlpp] ----- -\set -profile "timings"; -SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport; ----- +You can access the profiling information in the following ways: -Now, using the cbq shell, we change the profile setting to "phases" and rerun another long query: +* In the <>. +* In the <>. -.Query 2 -[source,sqlpp] +When a query executes a user-defined function, profiling information is available for the {sqlpp} queries within the user-defined function as well. + +[[profile]] +=== Profiling Details in Query Response + +When profiling is enabled: + +* If you are using the cbq shell or the Query REST API, query profiling information is returned with the query results. +* However, if you are using the Query workbench, query profiling information is not returned with the query results. + +.Phases Profile +==== +If you are using the cbq shell or the Query REST API, the following statistics are returned when `profile` is set to `phases`: + +[source,json] ---- -\set -profile "phases"; -SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport; +{ + "requestID": "06d6c1c2-1a8a-4989-a856-7314f9eddee5", + "signature": { + "*": "*" + }, + "results": [ + { + "airline": { + "callsign": "MILE-AIR", + "country": "United States", + "iata": "Q5", + "icao": "MLA", + "id": 10, + "name": "40-Mile Air", + "type": "airline" + } + } + ], + "status": "success", + "metrics": { + "elapsedTime": "12.77927ms", + "executionTime": "12.570648ms", + "resultCount": 1, + "resultSize": 254, + "serviceLoad": 12 + }, + "profile": { + "phaseTimes": { + "authorize": "19.629µs", + "fetch": "401.997µs", + "instantiate": "147.686µs", + "parse": "4.545234ms", + "plan": "409.364µs", + "primaryScan": "6.103775ms", + "run": "6.699056ms" + }, + "phaseCounts": { + "fetch": 1, + "primaryScan": 1 + }, + "phaseOperators": { + "authorize": 1, + "fetch": 1, + "primaryScan": 1 + }, + "requestTime": "2021-04-30T18:37:56.394Z", + "servicingHost": "127.0.0.1:8091" + } +} ---- +==== -Run a query `system:completed_requests` keyspace with `meta().plan`. - -.Query 3 -[source,sqlpp] ----- -SELECT meta().plan, * from system:completed_requests; ----- +.Timings Profile +==== +If you are using the cbq shell or the Query REST API, the following statistics are returned when `profile` is set to `timings`: -.Result [source,json] ---- { - "requestID": "4a36e1dc-cea0-4ba2-a428-258511d50582", + "requestID": "268a1240-6864-43a2-af13-ccb8d1e50abf", "signature": { - "*": "*", - "plan": "json" + "*": "*" }, "results": [ - // ... - { // <1> - "completed_requests": { - "elapsedTime": "15.641879295s", - "errorCount": 0, - "node": "127.0.0.1:8091", - "phaseCounts": { - "fetch": 24024, - "primaryScan": 24024, - "sort": 24024 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1, - "sort": 1 - }, - "phaseTimes": { - "authorize": "51.305µs", - "fetch": "3.27276723s", - "instantiate": "60.662µs", - "parse": "66.701943ms", - "plan": "15.12951ms", - "primaryScan": "171.439769ms", - "run": "15.548781894s", - "sort": "153.767638ms" - }, - "remoteAddr": "172.17.0.1:56962", - "requestId": "08445bae-66ef-4ccd-8b2d-ea899b453a1b", - "requestTime": "2021-04-30T21:14:57.576Z", - "resultCount": 24024, - "resultSize": 81821919, - "scanConsistency": "unbounded", - "serviceTime": "15.630714144s", - "state": "completed", - "statement": "SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport;", - "useCBO": true, - "userAgent": "Go-http-client/1.1 (CBQ/2.0)", - "users": "Administrator" - } - }, - // ... - { // <2> - "completed_requests": { - "elapsedTime": "15.321128463s", - "errorCount": 0, - "node": "127.0.0.1:8091", - "phaseCounts": { - "fetch": 24024, - "primaryScan": 24024, - "sort": 24024 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1, - "sort": 1 - }, - "phaseTimes": { - "authorize": "23.037µs", - "fetch": "3.092306635s", - "instantiate": "7.313569ms", - "parse": "579.368µs", - "plan": "2.449143ms", - "primaryScan": "153.686873ms", - "run": "15.29433203s", - "sort": "147.889352ms" - }, - "remoteAddr": "172.17.0.1:56900", - "requestId": "5eefc9e5-bdaa-4824-bcd7-47977eb1f08a", - "requestTime": "2021-04-30T21:13:58.707Z", - "resultCount": 24024, - "resultSize": 81821919, - "scanConsistency": "unbounded", - "serviceTime": "15.30510306s", - "state": "completed", - "statement": "SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport;", - "useCBO": true, - "userAgent": "Go-http-client/1.1 (CBQ/2.0)", - "users": "Administrator" - }, - "plan": { - "#operator": "Authorize", - "#stats": { - "#phaseSwitches": 4, - "execTime": "1.725µs", - "servTime": "21.312µs" - }, - "privileges": { - "List": [ - { - "Priv": 7, - "Props": 0, - "Target": "default:travel-sample.inventory.route" - } - ] - }, - "~child": { - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 2, - "execTime": "1.499µs" - }, - "~children": [ - { - "#operator": "PrimaryScan3", - "#stats": { - "#heartbeatYields": 6, - "#itemsOut": 24024, - "#phaseSwitches": 96099, - "execTime": "84.366121ms", - "kernTime": "3.021901421s", - "servTime": "69.320752ms" - }, - "bucket": "travel-sample", - "index": "def_inventory_route_primary", - "index_projection": { - "primary_key": true - }, - "keyspace": "route", - "namespace": "default", - "scope": "inventory", - "using": "gsi" - }, - { - "#operator": "Fetch", - "#stats": { - "#heartbeatYields": 7258, - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 99104, - "execTime": "70.34694ms", - "kernTime": "142.630196ms", - "servTime": "3.021959695s" - }, - "bucket": "travel-sample", - "keyspace": "route", - "namespace": "default", - "scope": "inventory" - }, - { - "#operator": "InitialProject", - "#stats": { - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 96100, - "execTime": "15.331951ms", - "kernTime": "3.219612458s" - }, - "result_terms": [ - { - "expr": "self", - "star": true - } - ] - }, - { - "#operator": "Order", - "#stats": { - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 72078, - "execTime": "147.889352ms", - "kernTime": "3.229055752s" - }, - "sort_terms": [ - { - "expr": "(`route`.`sourceairport`)" - } - ] - }, - { - "#operator": "Stream", - "#stats": { - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 24025, - "execTime": "11.851634134s" - } - } - ] - }, - "~versions": [ - "7.0.0-N1QL", - "7.0.0-4960-enterprise" - ] + { + "airline": { + "callsign": "MILE-AIR", + "country": "United States", + "iata": "Q5", + "icao": "MLA", + "id": 10, + "name": "40-Mile Air", + "type": "airline" } } ], "status": "success", "metrics": { - "elapsedTime": "172.831251ms", - "executionTime": "172.586836ms", - "resultCount": 40, - "resultSize": 65181, + "elapsedTime": "2.915245ms", + "executionTime": "2.755355ms", + "resultCount": 1, + "resultSize": 254, "serviceLoad": 12 }, - "profile": { // <3> + "profile": { "phaseTimes": { - "authorize": "19.912µs", - "fetch": "123.022426ms", - "instantiate": "29.424µs", - "parse": "6.414711ms", - "plan": "3.19076ms", - "primaryScan": "55.521683ms", - "run": "158.514001ms" + "authorize": "18.096µs", + "fetch": "388.122µs", + "instantiate": "31.702µs", + "parse": "646.157µs", + "plan": "120.427µs", + "primaryScan": "1.402918ms", + "run": "1.936852ms" }, "phaseCounts": { - "fetch": 40, - "primaryScan": 40 + "fetch": 1, + "primaryScan": 1 }, "phaseOperators": { "authorize": 1, "fetch": 1, "primaryScan": 1 }, - "requestTime": "2021-04-30T21:15:18.104Z", - "servicingHost": "127.0.0.1:8091" + "requestTime": "2021-04-30T18:40:13.239Z", + "servicingHost": "127.0.0.1:8091", + "executionTimings": { + "#operator": "Authorize", + "#stats": { + "#phaseSwitches": 4, + "execTime": "1.084µs", + "servTime": "17.012µs" + }, + "privileges": { + "List": [ + { + "Target": "default:travel-sample.inventory.airline", + "Priv": 7, + "Props": 0 + } + ] + }, + "~child": { + "#operator": "Sequence", + "#stats": { + "#phaseSwitches": 1, + "execTime": "2.474µs" + }, + "~children": [ + { + "#operator": "PrimaryScan3", + "#stats": { + "#itemsOut": 1, + "#phaseSwitches": 7, + "execTime": "18.584µs", + "kernTime": "8.869µs", + "servTime": "1.384334ms" + }, + "bucket": "travel-sample", + "index": "def_inventory_airline_primary", + "index_projection": { + "primary_key": true + }, + "keyspace": "airline", + "limit": "1", + "namespace": "default", + "scope": "inventory", + "using": "gsi" + }, + { + "#operator": "Fetch", + "#stats": { + "#itemsIn": 1, + "#itemsOut": 1, + "#phaseSwitches": 10, + "execTime": "25.64µs", + "kernTime": "1.427752ms", + "servTime": "362.482µs" + }, + "bucket": "travel-sample", + "keyspace": "airline", + "namespace": "default", + "scope": "inventory" + }, + { + "#operator": "InitialProject", + "#stats": { + "#itemsIn": 1, + "#itemsOut": 1, + "#phaseSwitches": 9, + "execTime": "6.006µs", + "kernTime": "1.825917ms" + }, + "result_terms": [ + { + "expr": "self", + "star": true + } + ] + }, + { + "#operator": "Limit", + "#stats": { + "#itemsIn": 1, + "#itemsOut": 1, + "#phaseSwitches": 4, + "execTime": "2.409µs", + "kernTime": "2.094µs" + }, + "expr": "1" + }, + { + "#operator": "Stream", + "#stats": { + "#itemsIn": 1, + "#itemsOut": 1, + "#phaseSwitches": 6, + "execTime": "46.964µs", + "kernTime": "1.844828ms" + } + } + ] + }, + "~versions": [ + "7.0.0-N1QL", + "7.0.0-4960-enterprise" + ] + } } } ---- - -This example shows: - -<1> The profile attribute with all phases-related statistics for Query 2. -<2> The `meta().plan` with all detailed statistics collected for Query 1. -<3> The profile attribute with all phases-related statistics for this query itself, which is querying the `system:completed_requests` keyspace. ==== -[[sys-completed-config]] -== Configure the Completed Requests - -You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API settings endpoint. - -In Couchbase Server 6.5 and later, you can specify the conditions for completed request logging using the `completed` field. - -This field takes a JSON object containing the names and values of logging qualifiers. -Completed requests that meet the defined qualifiers are logged. - -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"user": "marco", "error": 12003}}' ----- - -=== Logging Qualifiers - -You can specify the following logging qualifiers. -A completed request is logged if _any_ of the qualifiers are met (logical OR). - -[horizontal] -`threshold`:: The execution time threshold in milliseconds. -`aborted`:: Whether to log requests that generate a panic. -`error`:: Log requests returning this error number. -`client`:: Log requests from this IP address. -`user`:: Log requests with this user name. -`context`:: Log requests with this client context ID. - -For full details, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_logging_parameters[Logging parameters]. - -The basic syntax adds a qualifier to the logging parameters, i.e. any existing qualifiers are not removed. -You can change the value of a logging qualifier by specifying the same qualifier again with a new value. - -To add a new instance of an existing qualifier, use a plus sign (`+`) before the qualifier name, e.g. `+user`. -To remove a qualifier, use a minus sign (`-`) before the qualifier name, e.g. `-user`. - -For example, the following request will add user `simon` to those tracked, and remove error `12003`. - -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"+user": "simon", "-error": 12003}}' ----- - -Similarly, you could remove all logging by execution time with the following request, as long as the value matches the existing threshold. - -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"-threshold": 1000}}' ----- +The `profile` object contains the following attributes: -=== Tagged Sets +include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] -You can also specify qualifiers that have to be met as a group for the completed request to be logged (logical AND). +The `kernTime`, `servTime`, and `execTime` statistics can be very helpful in troubleshooting query performance issues +For example: -To do this, specify the `tag` field along with a set of qualifiers, like so: +* A high `servTime` for a low number of items processed is an indication that the indexer or KV store is stressed. +* A high `kernTime` means there is a downstream issue in the query plan or the query server having many requests to process, so the scheduled waiting time will be more for CPU time. -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"user": "marco", "error": 12003, "tag": "both_user_and_error"}}' ----- +[[plan]] +=== Profiling Details in System Catalogs -In this case, the request will be logged when both user and error match. +The following system catalogs support the `meta().plan` virtual attribute, which captures the whole query plan, including query profiling information. -The tag name can be any string that is meaningful and unique. -Requests that match a tagged set of conditions are logged with a field `~tag`, which is set to the name of the tag. +* <> +* <> +* <> -To add a qualifier to a tagged set, specify the tag name again along with the new qualifier: +With the `system:active_requests` and `system:completed_requests` catalogs, not all statements have a `meta().plan` attribute. +The `meta().plan` attribute is only available for statements that run when the profile is set to `timings`. -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed": {"client": "172.1.2.3", "tag": "both_user_and_error"}}' ----- +With the `system:prepareds` catalog, the `meta().plan` attribute is available for all statements. -You cannot add a new instance of an existing qualifier to a tagged set using a plus sign (`+`) before the qualifier name. -For example, you cannot add a `user` qualifier to a tagged set that already contains a `user` qualifier. -If you need to track two users with the same error, create two tagged sets, one per user. +You must explicitly specify `meta().plan` in the projection list for the SELECT query. +For a detailed example, see <>. -You can remove a qualifier from a tagged set using a minus sign (`-`) before the qualifier name, e.g. `-user`. -When you remove the last qualifier from a tagged set, the tagged set is removed. +The `meta().plan` attribute contains similar properties to the `profile` object included with the query results when profiling is active. [NOTE] --- -You can specify multiple tagged sets. -In this case, completed requests are logged if they match all of the qualifiers in any of the tagged sets. - -You can also specify a mixture of tagged sets and individual qualifiers. -In this case, completed requests are logged if they match any of the individual qualifiers, or all of the qualifiers in any of the tagged sets. --- - -=== Completed Threshold - -The [.param]`completed-threshold` field provides another way of specifying the `threshold` qualifier within the `completed` field. - -This field sets the minimum request duration after which requests are added to the `system:completed_requests` catalog. -The default value is 1000ms. -Specify [.in]`0` to log all requests and [.in]`-1` to not log any requests to the keyspace. - -To specify a different value, use: - -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed-threshold":0}' ----- - -=== Completed Limit - -The [.param]`completed-limit` field sets the number of most recent requests to be tracked in the `system:completed_requests` catalog. -The default value is 4000. -Specify [.in]`0` to not track any requests and [.in]`-1` to set no limit. - -To specify a different value, use: - -[source,sh] ----- -curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ - -H 'Content-Type: application/json' \ - -d '{"completed-limit":1000}' ----- +==== +For active requests, `phaseTimes` and `phaseCounts` are dynamic, depending on the documents processed by various phases up to this moment in time. +A new query on `system:active_requests` will return different values. +==== [#sys_my-user-info] == Monitor Your User Info From 36943c4814e6d7c1700f5dbb47ceee5e90e5d2a1 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:37:35 +0100 Subject: [PATCH 13/25] =?UTF-8?q?Query=20engine=20=E2=86=92=20query=20node?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 16c789337..cd1c4544d 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -1,5 +1,5 @@ = Manage and Monitor Queries -:description: Monitoring and profiling {sqlpp} queries, query service engines, and corresponding system resources is very important for smoother operational performance and efficiency of the system. +:description: Monitoring and profiling {sqlpp} queries, query service nodes, and corresponding system resources is very important for smoother operational performance and efficiency of the system. :page-aliases: monitoring:monitoring-n1ql-query, manage:monitor/monitoring-n1ql-query [abstract] @@ -13,7 +13,7 @@ When running on a cluster with multiple query nodes, stats about all queries on For example, this can help identify: -* The top 10 slow or fast queries running on a particular query engine or the cluster. +* The top 10 slow or fast queries running on a particular query node or the cluster. * Resource usage statistics of the query service, or resources used for a particular query. * Details about the active, completed, and prepared queries. * Find long running queries that are running for more than 2 minutes. @@ -94,8 +94,8 @@ In the REST API examples: [#vitals] == Monitor System Vitals -The `system:vitals` catalog provides data about the running state and health of the query engine, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. -This information can be very useful to assess the current workload and performance characteristics of a query engine. +The `system:vitals` catalog provides data about the running state and health of the query node, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. +This information can be very useful to assess the current workload and performance characteristics of a query node. For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. @@ -408,7 +408,7 @@ The root operator is a Sequence, which itself has a collection of child operator [#sys-prepared] == Monitor and Manage Prepared Statements -The `system:prepareds` catalog provides data about the known prepared statements and their state in a query engine's prepared statement cache. +The `system:prepareds` catalog provides data about the known prepared statements and their state in a query node's prepared statement cache. For each prepared statement, this catalog provides information such as name, statement, query plan, last use time, number of uses, and so on. For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_statements[Statements]. From cfa7d7483e4f1cde7744a4a60a6787d7175f3fd0 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:38:31 +0100 Subject: [PATCH 14/25] Reformat ToC --- .../n1ql-manage/monitoring-n1ql-query.adoc | 54 +++++++++---------- 1 file changed, 27 insertions(+), 27 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index cd1c4544d..63fa6c8cc 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -33,39 +33,39 @@ The following diagnostics are provided: [cols="1,3"] |=== | System Catalogs -a| -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-datastores[system:datastores] -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-namespaces[system:namespaces] -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-buckets[system:buckets] -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-scopes[system:scopes] -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-keyspaces[system:keyspaces] -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-indexes[system:indexes] -* xref:n1ql:n1ql-intro/sysinfo.adoc#querying-dual[system:dual] +a| [%hardbreaks] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-datastores[system:datastores] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-namespaces[system:namespaces] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-buckets[system:buckets] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-scopes[system:scopes] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-keyspaces[system:keyspaces] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-indexes[system:indexes] +xref:n1ql:n1ql-intro/sysinfo.adoc#querying-dual[system:dual] | Monitoring Catalogs -a| -* <> -* <> -* <> -* <> +a| [%hardbreaks] +<> +<> +<> +<> | Security Catalogs -a| -* <> -* <> -* <> -* <> +a| [%hardbreaks] +<> +<> +<> +<> | Other -a| -* <> -* <> -* <> -* <> -* <> -* <> -* <> -* <> +a| [%hardbreaks] +<> +<> +<> +<> +<> +<> +<> +<> |=== == Authentication and Client Privileges From 94a39114f2a13a5fc4a88c373c8740ea22021a3e Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:39:20 +0100 Subject: [PATCH 15/25] Update system:vitals --- .../n1ql-manage/monitoring-n1ql-query.adoc | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 63fa6c8cc..f9b794dd4 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -97,10 +97,11 @@ In the REST API examples: The `system:vitals` catalog provides data about the running state and health of the query node, such as number of logical cores, active threads, queued threads, CPU utilization, memory usage, network utilization, garbage collection percentage, and so on. This information can be very useful to assess the current workload and performance characteristics of a query node. -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. - +[#sys-vitals-get] === Get System Vitals +To view system vitals, you can use the Admin REST API or a {sqlpp} query. + [tabs] ==== REST API:: @@ -126,11 +127,12 @@ SELECT * FROM system:vitals; -- ==== -[source,sh] ----- -curl -u $USER:$PASSWORD $BASE_URL/admin/vitals ----- +[[sys-vital-examples]] +=== System Vitals Details + +Getting system vitals, as described in <>, returns results similar to the following. +==== [source,json] ---- { @@ -160,6 +162,9 @@ curl -u $USER:$PASSWORD $BASE_URL/admin/vitals "request.prepared.percent": 0 } ---- +==== + +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. [#sys-active-req] == Monitor and Manage Active Requests From 848fe855ed89b25e1cb48a437291ca51aa4baa20 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:40:17 +0100 Subject: [PATCH 16/25] Update system:active_requests --- .../n1ql-manage/monitoring-n1ql-query.adoc | 213 +++++------------- 1 file changed, 56 insertions(+), 157 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index f9b794dd4..0b0ca7873 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -171,12 +171,11 @@ For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vital The `system:active_requests` catalog lists all currently executing active requests or queries. -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. -The profile related attributes are described in the section <> - [[sys-active-get]] === Get Active Requests +To view active requests, you can use the Admin REST API or a {sqlpp} query. + [tabs] ==== REST API:: @@ -190,6 +189,23 @@ curl -u $USER:$PASSWORD $BASE_URL/admin/active_requests ---- -- +{sqlpp}:: ++ +-- +To view active requests with {sqlpp}: + +[source,sqlpp] +---- +SELECT * FROM system:active_requests; +---- +-- +==== + +To get the query plan for active requests, include `meta().plan` in a {sqlpp} query. +See <>. + +[tabs] +==== {sqlpp}:: + -- @@ -233,181 +249,64 @@ DELETE FROM system:active_requests WHERE requestId = "uuid"; ==== [[sys-active-examples]] -=== Examples +=== Active Request Details -.Get Active -==== -[source,sqlpp] ----- -SELECT *, meta().plan FROM system:active_requests; ----- +Getting active requests, as described in <>, returns results similar to the following. +==== [source,json] ---- [ { "active_requests": { - "clientContextID": "81984707-a9cd-4b78-9110-d130eb580d7f", - "elapsedTime": "65.543946ms", - "executionTime": "65.507111ms", + "clientContextID": "832adfa0-e9e6-464e-b5e6-b7ec7549d511", + "cpuTime": "111.877µs", + "elapsedTime": "77.631814ms", + "executionTime": "77.517185ms", + "n1qlFeatCtrl": 76, "node": "127.0.0.1:8091", - "phaseCounts": { - "primaryScan": 1 - }, "phaseOperators": { "authorize": 1, "fetch": 1, - "primaryScan": 1 + "primaryScan": 1, + "project": 1, + "stream": 1 }, "phaseTimes": { - "authorize": "2.361862ms", - "fetch": "7.222µs", - "instantiate": "13.233µs", - "parse": "660.048µs", - "plan": "52.877µs", - "primaryScan": "41.125271ms" + "authorize": "4.998µs", + "fetch": "69.519µs", + "instantiate": "16.28µs", + "parse": "597.435µs", + "plan": "24.141851ms", + "plan.index.metadata": "24.005473ms", + "plan.keyspace.metadata": "2.022µs", + "primaryScan": "23.496033ms", + "project": "824ns", + "stream": "2.242µs" }, - "remoteAddr": "127.0.0.1:57065", - "requestId": "27e73286-c6cc-4c26-8977-ef8d68e91c8f", - "requestTime": "2019-05-06 09:08:42.431161361 -0700 PDT m=+6976.301141271", + "queryContext": "default:travel-sample.inventory", + "remoteAddr": "127.0.0.1:37506", + "requestId": "05cc1895-9986-4819-b4d3-8a4311e8f319", + "requestTime": "2024-05-21T13:29:16.864Z", "scanConsistency": "unbounded", "state": "running", - "statement": "SELECT *, meta().plan FROM system:active_requests;", - "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:66.0) Gecko/20100101 Firefox/66.0 (Couchbase Query Workbench (6.5.0-2859-enterprise))", - "users": "Administrator" - }, - "plan": { // <1> - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 1, - "execTime": "1.661µs" - }, - "~children": [ - { - "#operator": "Authorize", - "#stats": { - "#phaseSwitches": 3, - "execTime": "4.844µs", - "servTime": "2.357018ms" - }, - // ... - } - ] - }, - "plan": { - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 1, - "execTime": "1.661µs" - }, - "~children": [ - { - "#operator": "Authorize", - "#stats": { - "#phaseSwitches": 3, - "execTime": "4.844µs", - "servTime": "2.357018ms" - }, - "privileges": { - "List": [ - { - "Priv": 4, - "Target": "#system:active_requests" - } - ] - }, - "~child": { - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 1, - "execTime": "2.71µs" - }, - "~children": [ - { - "#operator": "PrimaryScan", - "#stats": { - "#itemsOut": 1, - "#phaseSwitches": 7, - "execTime": "22.314µs", - "kernTime": "2.13µs", - "servTime": "41.102957ms" - }, - "index": "#primary", - "keyspace": "active_requests", - "namespace": "#system", - "using": "system" - }, - { - "#operator": "Fetch", - "#stats": { - "#itemsIn": 1, - "#phaseSwitches": 5, - "execTime": "7.222µs", - "kernTime": "41.130913ms", - "servTime": "22.888285ms", - "state": "services" - }, - "keyspace": "active_requests", - "namespace": "#system" - }, - { - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 1, - "execTime": "1.544µs" - }, - "~children": [ - { - "#operator": "InitialProject", - "#stats": { - "#phaseSwitches": 1, - "execTime": "980ns", - "kernTime": "64.066618ms", - "state": "kernel" - }, - "result_terms": [ - { - "expr": "self", - "star": true - }, - { - "expr": "(meta(`active_requests`).`plan`)" - } - ] - }, - { - "#operator": "FinalProject", - "#stats": { - "#phaseSwitches": 1, - "execTime": "827ns" - } - } - ] - } - ] - } - }, - { - "#operator": "Stream", - "#stats": { - "#phaseSwitches": 1, - "execTime": "1.29µs", - "kernTime": "66.511806ms", - "state": "kernel" - } - } - ], - "~versions": [ - "2.0.0-N1QL", - "6.5.0-2859-enterprise" - ] + "statement": "SELECT * FROM system:active_requests;", + "statementType": "SELECT", + "useCBO": true, + "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:126.0) Gecko/20100101 Firefox/126.0", + "users": "builtin:Administrator" } } ] ---- +==== -<1> The *plan* section contains a tree of operators that combine to execute the {sqlpp} query. -The root operator is a Sequence, which itself has a collection of child operators like Authorize, PrimaryScan, Fetch, and possibly even more Sequences. +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. + +[NOTE] +==== +For active requests, `phaseTimes` and `phaseCounts` are dynamic, depending on the documents processed by various phases up to this moment in time. +A new query on `system:active_requests` may return different values. ==== [#sys-prepared] From 577bd09c7f6e903912d1b9a3df0b2a0225e9b36f Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:41:01 +0100 Subject: [PATCH 17/25] Update system:prepareds --- .../n1ql-manage/monitoring-n1ql-query.adoc | 285 ++++-------------- 1 file changed, 61 insertions(+), 224 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 0b0ca7873..bb727dd30 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -315,9 +315,6 @@ A new query on `system:active_requests` may return different values. The `system:prepareds` catalog provides data about the known prepared statements and their state in a query node's prepared statement cache. For each prepared statement, this catalog provides information such as name, statement, query plan, last use time, number of uses, and so on. -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_statements[Statements]. -The `system:prepareds` catalog returns all the properties that the {sqlpp} Admin REST API would return for a specific prepared statement. - A prepared statement is created and stored relative to the current xref:n1ql:n1ql-intro/queriesandresults.adoc#query-context[query context]. You can create multiple prepared statements with the same name, each stored relative to a different query context. This enables you to run multiple instances of the same application against different datasets. @@ -327,13 +324,15 @@ When there are multiple prepared statements with the same name in different quer [[sys-prepared-get]] === Get Prepared Statements -To get a list of all known prepared statements, you can use the Admin REST API or a {sqlpp} query: +To get a list of all known prepared statements, you can use the Admin REST API or a {sqlpp} query. [tabs] ==== REST API:: + -- +To get a list of all known prepared statements with the Admin REST API: + [source,sh] ---- curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds @@ -343,19 +342,24 @@ curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds {sqlpp}:: + -- +To get a list of all known prepared statements with a {sqlpp} query: + [source,sqlpp] ---- SELECT * FROM system:prepareds; ---- +-- ==== -To get information about a specific prepared statement [.var]`example1`, you can use the Admin REST API or a {sqlpp} query: +To get information about a specific prepared statement, you can use the Admin REST API or a {sqlpp} query. [tabs] ==== REST API:: + -- +To get information about a specific prepared statement [.var]`example1` with the Admin REST API: + [source,sh] ---- curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds/example1 @@ -365,6 +369,8 @@ curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds/example1 {sqlpp}:: + -- +To get information about a specific prepared statement [.var]`example1` with a {sqlpp} query: + [source,sqlpp] ---- SELECT * FROM system:prepareds WHERE name = "example1"; @@ -372,16 +378,35 @@ SELECT * FROM system:prepareds WHERE name = "example1"; -- ==== +To get the query plan for prepared statements, include `meta().plan` in a {sqlpp} query. +See <>. + +[tabs] +==== +{sqlpp}:: ++ +-- +To view prepared statements with {sqlpp}, including the query plan: + +[source,sqlpp] +---- +SELECT *, meta().plan FROM system:prepareds; +---- +-- +==== + [[sys-prepared-delete]] === Delete Prepared Statements -To delete a specific prepared statement [.var]`p1`, you can use the Admin REST API or a {sqlpp} query: +To delete a specific prepared statement, you can use the Admin REST API or a {sqlpp} query. [tabs] ==== REST API:: + -- +To delete a prepared statement [.var]`p1` with the Admin REST API: + [source,sh] ---- curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/prepareds/p1 @@ -391,6 +416,8 @@ curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/prepareds/p1 {sqlpp}:: + -- +To delete a prepared statement [.var]`p1` with a {sqlpp} query: + [source,sqlpp] ---- DELETE FROM system:prepareds WHERE name = "p1"; @@ -398,238 +425,52 @@ DELETE FROM system:prepareds WHERE name = "p1"; -- ==== -To delete all the known prepared statements, you must use a {sqlpp} query: +To delete all the known prepared statements, you must use a {sqlpp} query. + +[tabs] +==== +{sqlpp}:: ++ +-- +To delete all known prepared statements: [source,sqlpp] ---- DELETE FROM system:prepareds; ---- +-- +==== [[sys-prepared-examples]] -=== Examples +=== Prepared Statement Details + +To try the examples in this section, first create a couple of prepared statements. -.Get Prepared +.Create a prepared statement with default query context ==== -.Prepared statement with default query context -- using cbq +include::ROOT:partial$query-context.adoc[tag=unset] + +.Query [source,sqlpp] ---- -\UNSET -query_context; PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = "U2"; ---- +==== -[source,json] ----- -{ - "requestID": "64069886-eb17-4fa6-8cc8-e60ebe93d97c", - "signature": "json", - "results": [ - { - "encoded_plan": "H4sIAAAAAAAA/wEAAP//AAAAAAAAAAA=", - "featureControls": 76, - "indexApiVersion": 4, - "indexScanKeyspaces": { - "default:travel-sample.inventory.airline": false - }, - "name": "[127.0.0.1:8091]p1", - "namespace": "default", - "operator": { - "#operator": "Authorize", - "privileges": { - "List": [ - { - "Priv": 7, - "Props": 0, - "Target": "default:travel-sample.inventory.airline" - } - ] - }, - "~child": { - "#operator": "Sequence", - "~children": [ - { - "#operator": "Sequence", - "~children": [ - { - "#operator": "PrimaryScan3", - "bucket": "travel-sample", - "index": "def_inventory_airline_primary", - "index_projection": { - "primary_key": true - }, - "keyspace": "airline", - "namespace": "default", - "scope": "inventory", - "using": "gsi" - }, - { - "#operator": "Fetch", - "bucket": "travel-sample", - "keyspace": "airline", - "namespace": "default", - "scope": "inventory" - }, - { - "#operator": "Parallel", - "~child": { - "#operator": "Sequence", - "~children": [ - { - "#operator": "Filter", - "condition": "((`airline`.`iata`) = \"U2\")" - }, - { - "#operator": "InitialProject", - "result_terms": [ - { - "expr": "self", - "star": true - } - ] - } - ] - } - } - ] - }, - { - "#operator": "Stream" - } - ] - } - }, - "queryContext": "", - "reqType": "SELECT", - "signature": { - "*": "*" - }, - "text": "PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = \"U2\";", - "useCBO": true - } - ], - "status": "success", - "metrics": { - "elapsedTime": "105.814848ms", - "executionTime": "105.648798ms", - "resultCount": 1, - "resultSize": 3301, - "serviceLoad": 12 - } -} ----- +.Create a prepared statement with specified query context +==== +include::ROOT:partial$query-context.adoc[tag=example] -.Prepared statement with specified query context -- using cbq +.Query [source,sqlpp] ---- -\SET -query_context travel-sample.inventory; PREPARE p1 AS SELECT * FROM airline WHERE iata = "U2"; ---- +==== -[source,json] ----- -{ - "requestID": "1c90603e-5e42-42b4-9362-4fc96bf895ac", - "signature": "json", - "results": [ - { - "encoded_plan": "H4sIAAAAAAAA/wEAAP//AAAAAAAAAAA=", - "featureControls": 76, - "indexApiVersion": 4, - "indexScanKeyspaces": { - "default:travel-sample.inventory.airline": false - }, - "name": "[127.0.0.1:8091]p1", - "namespace": "default", - "operator": { - "#operator": "Authorize", - "privileges": { - "List": [ - { - "Priv": 7, - "Props": 0, - "Target": "default:travel-sample.inventory.airline" - } - ] - }, - "~child": { - "#operator": "Sequence", - "~children": [ - { - "#operator": "Sequence", - "~children": [ - { - "#operator": "PrimaryScan3", - "bucket": "travel-sample", - "index": "def_inventory_airline_primary", - "index_projection": { - "primary_key": true - }, - "keyspace": "airline", - "namespace": "default", - "scope": "inventory", - "using": "gsi" - }, - { - "#operator": "Fetch", - "bucket": "travel-sample", - "keyspace": "airline", - "namespace": "default", - "scope": "inventory" - }, - { - "#operator": "Parallel", - "~child": { - "#operator": "Sequence", - "~children": [ - { - "#operator": "Filter", - "condition": "((`airline`.`iata`) = \"U2\")" - }, - { - "#operator": "InitialProject", - "result_terms": [ - { - "expr": "self", - "star": true - } - ] - } - ] - } - } - ] - }, - { - "#operator": "Stream" - } - ] - } - }, - "queryContext": "travel-sample.inventory", - "reqType": "SELECT", - "signature": { - "*": "*" - }, - "text": "PREPARE p1 AS SELECT * FROM airline WHERE iata = \"U2\";", - "useCBO": true - } - ], - "status": "success", - "metrics": { - "elapsedTime": "17.476424ms", - "executionTime": "17.187836ms", - "resultCount": 1, - "resultSize": 3298, - "serviceLoad": 12 - } -} ----- - -.List prepared statements -[source,sqlpp] ----- -SELECT *, meta().plan FROM system:prepareds; ----- +Getting prepared statements, as described in <>, returns results similar to the following. +==== [source,json] ---- { @@ -640,9 +481,6 @@ SELECT *, meta().plan FROM system:prepareds; }, "results": [ { - "plan": { - // ... - }, "prepareds": { "encoded_plan": "H4sIAAAAAAAA/6RTUW/TPBT9K9H5XrbJ30QBMcmIhzJ1AjG0qh3wwKbEJLedmWt71061UIXfjpxkndYhENpbYt97z7nn+GxAtnQVVbk3ykICAgtSsWY6djayMwHy6JWAthXdjr3+TBy0s5Avh7N5qewHaoJXJQXIDSpaqNpEGVmtyfwf1MobOtR2TTY6bg6VZqMtQS6UCdQKWLUiSPgR+u9uFOTdIAg4T6yi4zT+v/sfjOt45Vj/IAh41mttaNmTONUhQn7d4FzxkuL9tL/SEpiyXkMepQ/nA+Sz9rIV+FleaVPtMpjTTU22TG19AZPtcP+5aMp6pbhJcr6AwLe6vO54P+CLQfR+n3zLPh/Y576fcleXe3bfqYydYxsMt/k1NZCR66T+9eAdJO4l+L0NoXQ+nWxhIVAHbZeQWAaNVjxc6YRiefWnXZ6EvYs2VayMIYMneXWiTSSGQOlspXvhsLdXDPyKw0KrqIr97E12gU/PL7D/iMh7q6NWZtpLDwGmUJuYR+JV6ADp1qfCQGaRVouKBzsu28s2vbYd4pFJrZDuBFJOtyE8Go0EbmriJqWVbmOfYKab86aTaz45nRyfJxC9tF2skyoHkDhAKzC0TGeT6Xg2yfwoG8+zvic7yE5mZx+z4oFpxePEZF/eTWaTLMmyFeV19zLo+O3ZsNivAAAA//+q+jhuaAQAAA==", "featuresControl": 76, @@ -658,9 +496,6 @@ SELECT *, meta().plan FROM system:prepareds; } }, { - "plan": { - // ... - }, "prepareds": { "encoded_plan": "H4sIAAAAAAAA/6STT28TMRDFv8rqcWkrExFAVDLiEKpUIIoaJQUOtNqY3Ulq6tju2Bt1iZbPjry7TWmKQKg3/xnPvPk9zwZkC1dSmXujLCQgsCAVK6YjZyM7EyAPXwloW9LNyOvPxEE7C/myP5sVyn6gOnhVUIDcoKSFqkyUkdWazNOgVt7QQNs12ei4HijNRluCXCgTqBGwakWQ8EN06zYV5G0iCDhPrKLjlP7J3QajKl461j8IAp71WhtadiJOdIiQXzc4U7ykeJftn7IEJqzXkIdp4XyAfNZcNAI/i0ttyl0FM7quyBbpWRfAZNu6/x00Yb1SXCecLyDwrSquWt339KKH3vWTb9Xnvfrcd1lu43LP7jsVsXVsg/42v6IaMnKV6F/13kHiDsGfbQiF8+lkWxYCVdB2CYll0GjE/ZaOKRaXf+vlUbV3q00UK2PI4FFeHWsTiSFQOFvqDhz29ua9vvlgrlVU8/3sTXaOT8/Psf9AyHuro1Zm0qGHAFOoTMwj8Sq0BenGp8BAZpFai4p7Oy6aiyb9th3hkUmtkO4E0pxuh/BwOBS4rojrNK108wDy4HevmK7P6pbibHwyPjpLtfXSttOeYB1A4gCNQJ9pMh1PRtNx5ofZaJZ1b7KD7Hh6+jHreWRf3o2n4ywx2RJ53X4LOnp72nf1KwAA////9+bsZQQAAA==", "featuresControl": 76, @@ -687,12 +522,14 @@ SELECT *, meta().plan FROM system:prepareds; } ---- -Note that the names of the prepared statements are identical, but they are associated with different query contexts. +In this example, the names of the prepared statements are identical, but they are associated with different query contexts. <.> The name of the prepared statement for the default query context <.> The name of the prepared statement showing the associated query context ==== +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_statements[Statements]. + [#sys-completed-req] == Monitor and Manage Completed Requests From 6f65814d9952f2d6ef69388861467cbaa721ed3c Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:41:47 +0100 Subject: [PATCH 18/25] Update system:completed_requests --- .../n1ql-manage/monitoring-n1ql-query.adoc | 393 +++++------------- 1 file changed, 115 insertions(+), 278 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index bb727dd30..ada7b53db 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -537,30 +537,13 @@ By default, the `system:completed_requests` catalog maintains a list of the most (You can also log completed requests that meet other conditions that you define.) For each completed request, this catalog maintains information such as requestId, statement text, prepared name (if prepared statement), request time, service time, and so on. -This information provides a general insight into the health and performance of the query engine and the cluster. - -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. -Most field names and meanings match exactly those of `system:active_requests`. - -Note that the `completed` state means that the request was started and completed by the Query service, but it does not mean that it was necessarily successful. -The request could have been successful, or completed with errors. - -To find requests that completed successfully, search for completed requests whose `state` is `completed` and whose `errorCount` field has the value `0`. - -[NOTE] -==== -Request profiling affects the `system:completed_requests` keyspace in the following ways: - -* When the feature is turned on, completed requests are stored with their execution plan. -* Profiling information is likely to use 100KB+ per entry. -* Due to the added overhead of running both profiling and logging, we recommend turning on both of them only when needed. -Running only one of them continuously has no noticeable affect on performance. -* Profiling does not carry any extra cost beyond memory for completed requests, so it's fine to run it continuously. -==== +This information provides a general insight into the health and performance of the query node and the cluster. [[sys-completed-get]] === Get Completed Requests +To get a list of all logged completed requests, you can use the Admin REST API or a {sqlpp} query. + [tabs] ==== REST API:: @@ -577,14 +560,26 @@ curl -u $USER:$PASSWORD $BASE_URL/admin/completed_requests {sqlpp}:: + -- -To get a list of all logged completed requests using {sqlpp}, including the query plan: +To get a list of all logged completed requests using {sqlpp}: [source,sqlpp] ---- -SELECT *, meta().plan FROM system:completed_requests; +SELECT * FROM system:completed_requests; ---- +-- +==== -To get a list of all logged completed requests using {sqlpp}, including only successful requests: +Note that the `completed` state means that the request was started and completed by the Query service, but it does not mean that it was necessarily successful. +The request could have been successful, or completed with errors. + +To find requests that completed successfully, search for completed requests whose `state` is `completed` and whose `errorCount` field has the value `0`. + +[tabs] +==== +{sqlpp}:: ++ +-- +To get a list of all logged completed requests, including only successful requests: [source,sqlpp] ---- @@ -594,9 +589,28 @@ WHERE state = "completed" AND errorCount = 0; -- ==== +To get the query plan for completed requests, include `meta().plan` in a {sqlpp} query. +See <>. + +[tabs] +==== +{sqlpp}:: ++ +-- +To view completed requests with {sqlpp}, including the query plan: + +[source,sqlpp] +---- +SELECT *, meta().plan FROM system:completed_requests; +---- +-- +==== + [[sys-completed-delete]] === Purge the Completed Requests +To purge a specific completed request, you can use the Admin REST API or a {sqlpp} query. + [tabs] ==== REST API:: @@ -619,8 +633,17 @@ To purge a completed request [.var]`uuid` with {sqlpp}: ---- DELETE FROM system:completed_requests WHERE requestId = "uuid"; ---- +-- +==== -To purge the completed requests for a given time period, use: +To delete purge completed requests for a given time period, you must use a {sqlpp} query. + +[tabs] +==== +{sqlpp}:: ++ +-- +To purge the completed requests for a given time period: [source,sqlpp] ---- @@ -630,276 +653,90 @@ DELETE FROM system:completed_requests WHERE requestTime LIKE "2015-09-09%"; ==== [[sys-completed-examples]] -=== Examples +=== Completed Request Details -[[example-2]] -.Completed Request -==== -First, using the cbq shell, we set `profile = "timings"` and run a long query which takes at least 1000ms (the default value of the `completed-threshold` query setting) to get registered in the `system:completed_requests` keyspace: - -.Query 1 -[source,sqlpp] ----- -\set -profile "timings"; -SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport; ----- +To try the examples in this section, first run a query which takes at least 1000ms (the default value of the `completed-threshold` query setting) to get registered in the `system:completed_requests` keyspace. -Now, using the cbq shell, we change the profile setting to "phases" and rerun another long query: +.Run a long query +==== +include::ROOT:partial$query-context.adoc[tag=example] -.Query 2 +.Query [source,sqlpp] ---- -\set -profile "phases"; -SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport; +SELECT * FROM route ORDER BY sourceairport LIMIT 5; ---- +==== -Run a query `system:completed_requests` keyspace with `meta().plan`. - -.Query 3 -[source,sqlpp] ----- -SELECT meta().plan, * from system:completed_requests; ----- +Getting completed requests, as described in <>, returns results similar to the following. -.Result +==== [source,json] ---- -{ - "requestID": "4a36e1dc-cea0-4ba2-a428-258511d50582", - "signature": { - "*": "*", - "plan": "json" - }, - "results": [ - // ... - { // <1> - "completed_requests": { - "elapsedTime": "15.641879295s", - "errorCount": 0, - "node": "127.0.0.1:8091", - "phaseCounts": { - "fetch": 24024, - "primaryScan": 24024, - "sort": 24024 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1, - "sort": 1 - }, - "phaseTimes": { - "authorize": "51.305µs", - "fetch": "3.27276723s", - "instantiate": "60.662µs", - "parse": "66.701943ms", - "plan": "15.12951ms", - "primaryScan": "171.439769ms", - "run": "15.548781894s", - "sort": "153.767638ms" - }, - "remoteAddr": "172.17.0.1:56962", - "requestId": "08445bae-66ef-4ccd-8b2d-ea899b453a1b", - "requestTime": "2021-04-30T21:14:57.576Z", - "resultCount": 24024, - "resultSize": 81821919, - "scanConsistency": "unbounded", - "serviceTime": "15.630714144s", - "state": "completed", - "statement": "SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport;", - "useCBO": true, - "userAgent": "Go-http-client/1.1 (CBQ/2.0)", - "users": "Administrator" - } - }, - // ... - { // <2> - "completed_requests": { - "elapsedTime": "15.321128463s", - "errorCount": 0, - "node": "127.0.0.1:8091", - "phaseCounts": { - "fetch": 24024, - "primaryScan": 24024, - "sort": 24024 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1, - "sort": 1 - }, - "phaseTimes": { - "authorize": "23.037µs", - "fetch": "3.092306635s", - "instantiate": "7.313569ms", - "parse": "579.368µs", - "plan": "2.449143ms", - "primaryScan": "153.686873ms", - "run": "15.29433203s", - "sort": "147.889352ms" - }, - "remoteAddr": "172.17.0.1:56900", - "requestId": "5eefc9e5-bdaa-4824-bcd7-47977eb1f08a", - "requestTime": "2021-04-30T21:13:58.707Z", - "resultCount": 24024, - "resultSize": 81821919, - "scanConsistency": "unbounded", - "serviceTime": "15.30510306s", - "state": "completed", - "statement": "SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport;", - "useCBO": true, - "userAgent": "Go-http-client/1.1 (CBQ/2.0)", - "users": "Administrator" +[ + // ... + { + "completed_requests": { + "clientContextID": "a19a61ab-cd9e-46c9-be71-92623ff85741", + "cpuTime": "912.408423ms", + "elapsedTime": "3.762926948s", + "errorCount": 0, + "errors": [], + "n1qlFeatCtrl": 76, + "node": "127.0.0.1:8091", + "phaseCounts": { + "fetch": 24023, + "primaryScan": 24023, + "primaryScan.GSI": 24023, + "sort": 24028 }, - "plan": { - "#operator": "Authorize", - "#stats": { - "#phaseSwitches": 4, - "execTime": "1.725µs", - "servTime": "21.312µs" - }, - "privileges": { - "List": [ - { - "Priv": 7, - "Props": 0, - "Target": "default:travel-sample.inventory.route" - } - ] - }, - "~child": { - "#operator": "Sequence", - "#stats": { - "#phaseSwitches": 2, - "execTime": "1.499µs" - }, - "~children": [ - { - "#operator": "PrimaryScan3", - "#stats": { - "#heartbeatYields": 6, - "#itemsOut": 24024, - "#phaseSwitches": 96099, - "execTime": "84.366121ms", - "kernTime": "3.021901421s", - "servTime": "69.320752ms" - }, - "bucket": "travel-sample", - "index": "def_inventory_route_primary", - "index_projection": { - "primary_key": true - }, - "keyspace": "route", - "namespace": "default", - "scope": "inventory", - "using": "gsi" - }, - { - "#operator": "Fetch", - "#stats": { - "#heartbeatYields": 7258, - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 99104, - "execTime": "70.34694ms", - "kernTime": "142.630196ms", - "servTime": "3.021959695s" - }, - "bucket": "travel-sample", - "keyspace": "route", - "namespace": "default", - "scope": "inventory" - }, - { - "#operator": "InitialProject", - "#stats": { - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 96100, - "execTime": "15.331951ms", - "kernTime": "3.219612458s" - }, - "result_terms": [ - { - "expr": "self", - "star": true - } - ] - }, - { - "#operator": "Order", - "#stats": { - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 72078, - "execTime": "147.889352ms", - "kernTime": "3.229055752s" - }, - "sort_terms": [ - { - "expr": "(`route`.`sourceairport`)" - } - ] - }, - { - "#operator": "Stream", - "#stats": { - "#itemsIn": 24024, - "#itemsOut": 24024, - "#phaseSwitches": 24025, - "execTime": "11.851634134s" - } - } - ] - }, - "~versions": [ - "7.0.0-N1QL", - "7.0.0-4960-enterprise" - ] - } + "phaseOperators": { + "authorize": 1, + "fetch": 1, + "primaryScan": 1, + "primaryScan.GSI": 1, + "project": 1, + "sort": 2, + "stream": 1 + }, + "phaseTimes": { + "authorize": "15.111µs", + "fetch": "3.641125449s", + "instantiate": "332.963µs", + "parse": "1.04015ms", + "plan": "602.878µs", + "plan.index.metadata": "25.849µs", + "plan.keyspace.metadata": "11.586µs", + "primaryScan": "101.118572ms", + "primaryScan.GSI": "101.118572ms", + "project": "33.273783ms", + "run": "3.760767643s", + "sort": "666.364325ms", + "stream": "1.617688ms" + }, + "queryContext": "default:travel-sample.inventory", + "remoteAddr": "127.0.0.1:37684", + "requestId": "e170bf67-d364-4ed7-9698-784bbb779d18", + "requestTime": "2024-05-21T14:31:46.882Z", + "resultCount": 5, + "resultSize": 17714, + "scanConsistency": "unbounded", + "serviceTime": "3.762768429s", + "state": "completed", + "statement": "SELECT * FROM route ORDER BY sourceairport LIMIT 5;", + "statementType": "SELECT", + "useCBO": true, + "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:126.0) Gecko/20100101 Firefox/126.0", + "users": "builtin:Administrator", + "~qualifier": "threshold" } - ], - "status": "success", - "metrics": { - "elapsedTime": "172.831251ms", - "executionTime": "172.586836ms", - "resultCount": 40, - "resultSize": 65181, - "serviceLoad": 12 - }, - "profile": { // <3> - "phaseTimes": { - "authorize": "19.912µs", - "fetch": "123.022426ms", - "instantiate": "29.424µs", - "parse": "6.414711ms", - "plan": "3.19076ms", - "primaryScan": "55.521683ms", - "run": "158.514001ms" - }, - "phaseCounts": { - "fetch": 40, - "primaryScan": 40 - }, - "phaseOperators": { - "authorize": 1, - "fetch": 1, - "primaryScan": 1 - }, - "requestTime": "2021-04-30T21:15:18.104Z", - "servicingHost": "127.0.0.1:8091" } -} +] ---- - -This example shows: - -<1> The profile attribute with all phases-related statistics for Query 2. -<2> The `meta().plan` with all detailed statistics collected for Query 1. -<3> The profile attribute with all phases-related statistics for this query itself, which is querying the `system:completed_requests` keyspace. ==== +For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. + [[sys-completed-config]] == Configure the Completed Requests From 17720f6878060262c33cd27d931de18b699d6ae3 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:42:33 +0100 Subject: [PATCH 19/25] Update query plan in system catalogs --- .../n1ql-manage/monitoring-n1ql-query.adoc | 148 ++++++++++++++++-- 1 file changed, 136 insertions(+), 12 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index ada7b53db..f02544269 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -1271,28 +1271,152 @@ For example: [[plan]] === Profiling Details in System Catalogs -The following system catalogs support the `meta().plan` virtual attribute, which captures the whole query plan, including query profiling information. +The <> and <> system catalogs always return profiling information regarding query phases: that is, phase times, phase counts, and phase operators. -* <> -* <> -* <> +The <>, <>, and <> system catalogs also support the `meta().plan` virtual attribute. +This captures the whole query plan, and includes profiling information regarding execution timings. -With the `system:active_requests` and `system:completed_requests` catalogs, not all statements have a `meta().plan` attribute. -The `meta().plan` attribute is only available for statements that run when the profile is set to `timings`. +To get execution timing information from these system catalogs, you must explicitly specify `meta().plan` in the projection list for the SELECT query. -With the `system:prepareds` catalog, the `meta().plan` attribute is available for all statements. +Within these system catalogs, not all statements have a `meta().plan` attribute. -You must explicitly specify `meta().plan` in the projection list for the SELECT query. -For a detailed example, see <>. +* With <> and <>, the `meta().plan` attribute is only available for statements that you run when profile is set to `timings`. -The `meta().plan` attribute contains similar properties to the `profile` object included with the query results when profiling is active. +* With <>, the `meta().plan` attribute is available for all statements. [NOTE] ==== -For active requests, `phaseTimes` and `phaseCounts` are dynamic, depending on the documents processed by various phases up to this moment in time. -A new query on `system:active_requests` will return different values. +When request profiling is set to `timings`, profiling information is likely to use 100KB+ per entry in the `system:completed_requests` keyspace. + +* Due to the added overhead of running both profiling and logging, we recommend turning on both of them only when needed. +Running only one of them continuously has no noticeable affect on performance. +* Profiling does not carry any extra cost beyond memory for completed requests, so it's fine to run it continuously. +==== + + +[[example-2]] +.Plan Details +==== +Getting the plan for a statement that was run when profile was set to `timings` returns results similar to the following. + +[source,json] +---- +[ + { + // ... + "plan": { + "#operator": "Authorize", + "#stats": { + "#phaseSwitches": 4, + "execTime": "1.725µs", + "servTime": "21.312µs" + }, + "privileges": { + "List": [ + { + "Priv": 7, + "Props": 0, + "Target": "default:travel-sample.inventory.route" + } + ] + }, + "~child": { + "#operator": "Sequence", + "#stats": { + "#phaseSwitches": 2, + "execTime": "1.499µs" + }, + "~children": [ + { + "#operator": "PrimaryScan3", + "#stats": { + "#heartbeatYields": 6, + "#itemsOut": 24024, + "#phaseSwitches": 96099, + "execTime": "84.366121ms", + "kernTime": "3.021901421s", + "servTime": "69.320752ms" + }, + "bucket": "travel-sample", + "index": "def_inventory_route_primary", + "index_projection": { + "primary_key": true + }, + "keyspace": "route", + "namespace": "default", + "scope": "inventory", + "using": "gsi" + }, + { + "#operator": "Fetch", + "#stats": { + "#heartbeatYields": 7258, + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 99104, + "execTime": "70.34694ms", + "kernTime": "142.630196ms", + "servTime": "3.021959695s" + }, + "bucket": "travel-sample", + "keyspace": "route", + "namespace": "default", + "scope": "inventory" + }, + { + "#operator": "InitialProject", + "#stats": { + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 96100, + "execTime": "15.331951ms", + "kernTime": "3.219612458s" + }, + "result_terms": [ + { + "expr": "self", + "star": true + } + ] + }, + { + "#operator": "Order", + "#stats": { + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 72078, + "execTime": "147.889352ms", + "kernTime": "3.229055752s" + }, + "sort_terms": [ + { + "expr": "(`route`.`sourceairport`)" + } + ] + }, + { + "#operator": "Stream", + "#stats": { + "#itemsIn": 24024, + "#itemsOut": 24024, + "#phaseSwitches": 24025, + "execTime": "11.851634134s" + } + } + ] + }, + "~versions": [ + "7.0.0-N1QL", + "7.0.0-4960-enterprise" + ] + } + } +] +---- ==== +The `plan` attribute contains similar properties to the `executionTimings` object included with the query results when profiling is active. + [#sys_my-user-info] == Monitor Your User Info From 8c97eb8a3a442d72257cd131b3debc752aea2abf Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 18:43:02 +0100 Subject: [PATCH 20/25] Minor changes --- .../pages/n1ql-manage/monitoring-n1ql-query.adoc | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index f02544269..7535e651c 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -1,4 +1,5 @@ = Manage and Monitor Queries +:example-caption!: :description: Monitoring and profiling {sqlpp} queries, query service nodes, and corresponding system resources is very important for smoother operational performance and efficiency of the system. :page-aliases: monitoring:monitoring-n1ql-query, manage:monitor/monitoring-n1ql-query @@ -20,11 +21,15 @@ For example, this can help identify: These system keyspaces are like virtual keyspaces that are transient in nature, and are not persisted to disk or permanent storage. Hence, the information in the keyspaces pertains to the current instantiation of the query service. + +//// +TODO: Reinstate this for monitoring and managing when other content is moved to the System Information page You can access the keyspaces using any of the following: * {sqlpp} language (from the cbq shell or Query Workbench) * REST API * Monitoring SDK +//// NOTE: All the power of the {sqlpp} query language can be applied on the keyspaces to obtain various insights. @@ -742,8 +747,7 @@ For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_reque You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API settings endpoint. -In Couchbase Server 6.5 and later, you can specify the conditions for completed request logging using the `completed` field. - +You can specify the conditions for completed request logging using the `completed` field. This field takes a JSON object containing the names and values of logging qualifiers. Completed requests that meet the defined qualifiers are logged. @@ -1033,12 +1037,12 @@ You can access the profiling information in the following ways: When a query executes a user-defined function, profiling information is available for the {sqlpp} queries within the user-defined function as well. [[profile]] -=== Profiling Details in Query Response +=== Profiling Details in Query Responses When profiling is enabled: * If you are using the cbq shell or the Query REST API, query profiling information is returned with the query results. -* However, if you are using the Query workbench, query profiling information is not returned with the query results. +* If you are using the Query workbench, query profiling information is not returned with the query results. .Phases Profile ==== @@ -1262,7 +1266,7 @@ The `profile` object contains the following attributes: include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] -The `kernTime`, `servTime`, and `execTime` statistics can be very helpful in troubleshooting query performance issues +The `kernTime`, `servTime`, and `execTime` statistics can be very helpful in troubleshooting query performance issues. For example: * A high `servTime` for a low number of items processed is an indication that the indexer or KV store is stressed. From fccb55264203d855355427a62b389d3d00903a53 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 20:57:05 +0100 Subject: [PATCH 21/25] =?UTF-8?q?Add=20links=20to=20query=20plan=20field?= =?UTF-8?q?=20names=20and=20meanings;=20also,=20refer=20to=20=E2=86=92=20s?= =?UTF-8?q?ee?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../n1ql-manage/monitoring-n1ql-query.adoc | 30 +++++++++---------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 7535e651c..ebcd59305 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -169,7 +169,7 @@ Getting system vitals, as described in <>, returns results simil ---- ==== -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. +For field names and meanings, see xref:n1ql:n1ql-rest-api/admin.adoc#_vitals[Vitals]. [#sys-active-req] == Monitor and Manage Active Requests @@ -306,13 +306,9 @@ Getting active requests, as described in <>, returns results sim ---- ==== -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. +For field names and meanings, see xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. -[NOTE] -==== -For active requests, `phaseTimes` and `phaseCounts` are dynamic, depending on the documents processed by various phases up to this moment in time. -A new query on `system:active_requests` may return different values. -==== +For query plan field names and meanings, see <>. [#sys-prepared] == Monitor and Manage Prepared Statements @@ -533,7 +529,9 @@ In this example, the names of the prepared statements are identical, but they ar <.> The name of the prepared statement showing the associated query context ==== -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_statements[Statements]. +For field names and meanings, see xref:n1ql:n1ql-rest-api/admin.adoc#_statements[Statements]. + +For query plan field names and meanings, see <>. [#sys-completed-req] == Monitor and Manage Completed Requests @@ -740,7 +738,9 @@ Getting completed requests, as described in <>, returns resul ---- ==== -For field names and meanings, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. +For field names and meanings, see xref:n1ql:n1ql-rest-api/admin.adoc#_requests[Requests]. + +For query plan field names and meanings, see <>. [[sys-completed-config]] == Configure the Completed Requests @@ -771,7 +771,7 @@ A completed request is logged if _any_ of the qualifiers are met (logical OR). `user`:: Log requests with this user name. `context`:: Log requests with this client context ID. -For full details, refer to xref:n1ql:n1ql-rest-api/admin.adoc#_logging_parameters[Logging parameters]. +For full details, see xref:n1ql:n1ql-rest-api/admin.adoc#_logging_parameters[Logging parameters]. The basic syntax adds a qualifier to the logging parameters, i.e. any existing qualifiers are not removed. You can change the value of a logging qualifier by specifying the same qualifier again with a new value. @@ -1419,7 +1419,7 @@ Getting the plan for a statement that was run when profile was set to `timings` ---- ==== -The `plan` attribute contains similar properties to the `executionTimings` object included with the query results when profiling is active. +For field names and meanings, see xref:n1ql:n1ql-rest-api/index.adoc#_execution_timings[Execution Timings]. [#sys_my-user-info] == Monitor Your User Info @@ -1785,7 +1785,7 @@ __required__ |Integer |=== -For further details, refer to xref:n1ql:n1ql-language-reference/updatestatistics.adoc[UPDATE STATISTICS]. +For further details, see xref:n1ql:n1ql-language-reference/updatestatistics.adoc[]. [#sys-dictionary-cache] == Monitor Cached Statistics @@ -1847,7 +1847,7 @@ This will result in a list similar to: This catalog contains an array of dictionary caches, one for each keyspace for which optimizer statistics are available. Each dictionary cache gives the same information as the <> catalog. -For further details, refer to xref:n1ql:n1ql-language-reference/updatestatistics.adoc[UPDATE STATISTICS]. +For further details, see xref:n1ql:n1ql-language-reference/updatestatistics.adoc[]. [#sys-functions] == Monitor Functions @@ -2543,7 +2543,7 @@ __optional__ |Integer |=== -For further details, refer to xref:n1ql:n1ql-language-reference/createsequence.adoc[]. +For further details, see xref:n1ql:n1ql-language-reference/createsequence.adoc[]. [#sys-all-sequences] == Monitor All Sequences @@ -2605,7 +2605,7 @@ This will result in a list similar to: This catalog gives the same information as the <> catalog. -For further details, refer to xref:n1ql:n1ql-language-reference/createsequence.adoc[]. +For further details, see xref:n1ql:n1ql-language-reference/createsequence.adoc[]. == Related Links From 47dc282ca7b4b0cc79e8600d23ea5d764189f4e7 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 20:58:06 +0100 Subject: [PATCH 22/25] Replace profile field inclusion with link --- .../n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc | 10 +--------- 1 file changed, 1 insertion(+), 9 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index ebcd59305..3b153a17f 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -1262,15 +1262,7 @@ If you are using the cbq shell or the Query REST API, the following statistics a ---- ==== -The `profile` object contains the following attributes: - -include::n1ql:partial$n1ql-rest-api/query/definitions.adoc[tags=profile] - -The `kernTime`, `servTime`, and `execTime` statistics can be very helpful in troubleshooting query performance issues. -For example: - -* A high `servTime` for a low number of items processed is an indication that the indexer or KV store is stressed. -* A high `kernTime` means there is a downstream issue in the query plan or the query server having many requests to process, so the scheduled waiting time will be more for CPU time. +For field names and meanings, see xref:n1ql:n1ql-rest-api/index.adoc#_profile[Profile]. [[plan]] === Profiling Details in System Catalogs From dc0b2c5ce8a7b3b5a0959221a946cb1f0a78efe0 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 20:58:30 +0100 Subject: [PATCH 23/25] Minor wording changes --- modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index 3b153a17f..d75d9a2e9 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -745,7 +745,7 @@ For query plan field names and meanings, see <>. [[sys-completed-config]] == Configure the Completed Requests -You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API settings endpoint. +You can configure the `system:completed_requests` keyspace by specifying parameters through the Admin API `/admin/settings` endpoint. You can specify the conditions for completed request logging using the `completed` field. This field takes a JSON object containing the names and values of logging qualifiers. @@ -1284,16 +1284,15 @@ Within these system catalogs, not all statements have a `meta().plan` attribute. ==== When request profiling is set to `timings`, profiling information is likely to use 100KB+ per entry in the `system:completed_requests` keyspace. -* Due to the added overhead of running both profiling and logging, we recommend turning on both of them only when needed. +* Due to the added overhead of running both profiling and logging, turn on both of them only when needed. Running only one of them continuously has no noticeable affect on performance. * Profiling does not carry any extra cost beyond memory for completed requests, so it's fine to run it continuously. ==== - [[example-2]] .Plan Details ==== -Getting the plan for a statement that was run when profile was set to `timings` returns results similar to the following. +Getting the plan for a statement that you ran when the profile was set to `timings` returns results similar to the following. [source,json] ---- From adbddc608e5558ec4df775843a173d4cb3afe502 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 21:13:29 +0100 Subject: [PATCH 24/25] Link to logging --- modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index d75d9a2e9..eb2556075 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -1284,7 +1284,7 @@ Within these system catalogs, not all statements have a `meta().plan` attribute. ==== When request profiling is set to `timings`, profiling information is likely to use 100KB+ per entry in the `system:completed_requests` keyspace. -* Due to the added overhead of running both profiling and logging, turn on both of them only when needed. +* Due to the added overhead of running both profiling and xref:manage:manage-logging/manage-logging.adoc[logging], turn on both of them only when needed. Running only one of them continuously has no noticeable affect on performance. * Profiling does not carry any extra cost beyond memory for completed requests, so it's fine to run it continuously. ==== From 5e8af55b8ef5ae166a1dfaccc5e4b9c629940db7 Mon Sep 17 00:00:00 2001 From: Simon Dew Date: Wed, 22 May 2024 21:23:20 +0100 Subject: [PATCH 25/25] Tighten up wording for conditional output --- .../n1ql-manage/monitoring-n1ql-query.adoc | 24 +++++++++---------- 1 file changed, 12 insertions(+), 12 deletions(-) diff --git a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc index eb2556075..92df234cd 100644 --- a/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc +++ b/modules/n1ql/pages/n1ql-manage/monitoring-n1ql-query.adoc @@ -105,14 +105,14 @@ This information can be very useful to assess the current workload and performan [#sys-vitals-get] === Get System Vitals -To view system vitals, you can use the Admin REST API or a {sqlpp} query. +To view system vitals, use the Admin REST API or a {sqlpp} query. [tabs] ==== REST API:: + -- -To view system vitals with Admin REST API: +To view system vitals with the Admin REST API: [source,sh] ---- @@ -179,14 +179,14 @@ The `system:active_requests` catalog lists all currently executing active reques [[sys-active-get]] === Get Active Requests -To view active requests, you can use the Admin REST API or a {sqlpp} query. +To view active requests, use the Admin REST API or a {sqlpp} query. [tabs] ==== REST API:: + -- -To view active requests with Admin REST API: +To view active requests with the Admin REST API: [source,sh] ---- @@ -325,7 +325,7 @@ When there are multiple prepared statements with the same name in different quer [[sys-prepared-get]] === Get Prepared Statements -To get a list of all known prepared statements, you can use the Admin REST API or a {sqlpp} query. +To get a list of all known prepared statements, use the Admin REST API or a {sqlpp} query. [tabs] ==== @@ -352,7 +352,7 @@ SELECT * FROM system:prepareds; -- ==== -To get information about a specific prepared statement, you can use the Admin REST API or a {sqlpp} query. +To get information about a specific prepared statement, use the Admin REST API or a {sqlpp} query. [tabs] ==== @@ -399,7 +399,7 @@ SELECT *, meta().plan FROM system:prepareds; [[sys-prepared-delete]] === Delete Prepared Statements -To delete a specific prepared statement, you can use the Admin REST API or a {sqlpp} query. +To delete a specific prepared statement, use the Admin REST API or a {sqlpp} query. [tabs] ==== @@ -426,7 +426,7 @@ DELETE FROM system:prepareds WHERE name = "p1"; -- ==== -To delete all the known prepared statements, you must use a {sqlpp} query. +To delete all the known prepared statements, use a {sqlpp} query. [tabs] ==== @@ -545,7 +545,7 @@ This information provides a general insight into the health and performance of t [[sys-completed-get]] === Get Completed Requests -To get a list of all logged completed requests, you can use the Admin REST API or a {sqlpp} query. +To get a list of all logged completed requests, use the Admin REST API or a {sqlpp} query. [tabs] ==== @@ -612,7 +612,7 @@ SELECT *, meta().plan FROM system:completed_requests; [[sys-completed-delete]] === Purge the Completed Requests -To purge a specific completed request, you can use the Admin REST API or a {sqlpp} query. +To purge a specific completed request, use the Admin REST API or a {sqlpp} query. [tabs] ==== @@ -639,7 +639,7 @@ DELETE FROM system:completed_requests WHERE requestId = "uuid"; -- ==== -To delete purge completed requests for a given time period, you must use a {sqlpp} query. +To purge completed requests for a given time period, use a {sqlpp} query. [tabs] ==== @@ -967,7 +967,7 @@ curl $BASE_URL/admin/settings -u $USER:$PASSWORD \ [#enable-settings-per-session-or-per-query] === Enable Query Profiling for a Request -To activate profiling at the request level, do one of the following: +To activate profiling at the request level, you can: * Specify the `profile` setting using the xref:n1ql:n1ql-rest-api/index.adoc[Query REST API] (`/query/service` endpoint). * Specify the `profile` setting using the xref:n1ql:n1ql-intro/cbq.adoc[cbq] command line tool.