Manage and Monitor Queries
Monitoring and profiling SQL++ queries, query service nodes, and corresponding system resources is very important for smoother operational performance and efficiency of the system. In fact, often it is vital for diagnosing and troubleshooting issues such as query performance, resource bottlenecks, and overloading of various services.
System keyspaces provide various monitoring details and statistics about individual queries and the Query service. When running on a cluster with multiple query nodes, stats about all queries on all query nodes are collected in the Query management and monitoring system keyspaces.
For example, this can help identify:
-
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.
These system keyspaces 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.
You can access the Query management and monitoring system keyspaces using any of the following:
-
SQL++ from the cbq shell or Query Workbench
-
The Query Admin REST API
-
A monitoring SDK
Using SQL++ enables you to obtain further insights from the keyspaces.
Authentication and Client Privileges
Users must have the Query System Catalog role to access restricted system keyspaces. For more details about user roles, see Authorization.
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.
Monitor System Vitals
The system:vitals
catalog provides data about the running state and health of the query nodes, 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.
Get System Vitals
To view system vitals, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To view system vitals with the Admin REST API:
curl -u $USER:$PASSWORD $BASE_URL/admin/vitals
To view system vitals with SQL++:
SELECT * FROM system:vitals;
System Vitals Details
Getting system vitals, as described in Get System Vitals, returns results similar to the following.
{
"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
}
For field names and meanings, see Vitals.
Monitor and Manage Active Requests
The system:active_requests
catalog lists all currently executing active requests or queries.
Get Active Requests
To view active requests, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To view active requests with the Admin REST API:
curl -u $USER:$PASSWORD $BASE_URL/admin/active_requests
To view active requests with SQL++:
SELECT * FROM system:active_requests;
To get the query plan for active requests, include meta().plan
in a SQL++ query.
See Query Profiling.
-
SQL++
To view active requests with SQL++, including the query plan:
SELECT *, meta().plan FROM system:active_requests;
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.
-
REST API
-
SQL++
To terminate an active request uuid
with the Admin REST API:
curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/active_requests/uuid
To terminate an active request uuid
with SQL++:
DELETE FROM system:active_requests WHERE requestId = "uuid";
Active Request Details
Getting active requests, as described in Get Active Requests, returns results similar to the following.
[
{
"active_requests": {
"clientContextID": "832adfa0-e9e6-464e-b5e6-b7ec7549d511",
"cpuTime": "111.877µs",
"elapsedTime": "77.631814ms",
"executionTime": "77.517185ms",
"n1qlFeatCtrl": 76,
"node": "127.0.0.1:8091",
"phaseOperators": {
"authorize": 1,
"fetch": 1,
"primaryScan": 1,
"project": 1,
"stream": 1
},
"phaseTimes": {
"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"
},
"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 * 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"
}
}
]
For field names and meanings, see Requests.
For query plan field names and meanings, see Query Profiling Details.
Monitor and Manage Prepared Statements
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.
A prepared statement is created and stored relative to the current 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.
When there are multiple prepared statements with the same name in different query contexts, the name of the prepared statement in the system:prepareds
catalog includes the associated query context in brackets.
Get Prepared Statements
To get a list of all known prepared statements, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To get a list of all known prepared statements with the Admin REST API:
curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds
To get a list of all known prepared statements with a SQL++ query:
SELECT * FROM system:prepareds;
To get information about a specific prepared statement, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To get information about a specific prepared statement example1
with the Admin REST API:
curl -u $USER:$PASSWORD $BASE_URL/admin/prepareds/example1
To get information about a specific prepared statement example1
with a SQL++ query:
SELECT * FROM system:prepareds WHERE name = "example1";
To get the query plan for prepared statements, include meta().plan
in a SQL++ query.
See Query Profiling.
-
SQL++
To view prepared statements with SQL++, including the query plan:
SELECT *, meta().plan FROM system:prepareds;
Delete Prepared Statements
To delete a specific prepared statement, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To delete a prepared statement p1
with the Admin REST API:
curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/prepareds/p1
To delete a prepared statement p1
with a SQL++ query:
DELETE FROM system:prepareds WHERE name = "p1";
To delete all the known prepared statements, use a SQL++ query.
-
SQL++
To delete all known prepared statements:
DELETE FROM system:prepareds;
Prepared Statement Details
To try the examples in this section, first create a couple of prepared statements.
For this example, unset the query context. For more information, see Query Context.
PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = "U2";
For this example, set the query context to the inventory
scope in the travel sample dataset.
For more information, see Query Context.
PREPARE p1 AS SELECT * FROM airline WHERE iata = "U2";
Getting prepared statements, as described in Get Prepared Statements, returns results similar to the following.
{
"requestID": "d976e59a-d74e-4350-b0df-fa137099d594",
"signature": {
"*": "*",
"plan": "json"
},
"results": [
{
"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
}
},
{
"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
}
}
In this example, the names of the prepared statements are identical, but they are associated with different query contexts.
1 | The name of the prepared statement for the default query context |
2 | The name of the prepared statement showing the associated query context |
For field names and meanings, see Statements.
For query plan field names and meanings, see Query Profiling Details.
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 node and the cluster.
Get Completed Requests
To get a list of all logged completed requests, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To get a list of all logged completed requests using the Admin REST API:
curl -u $USER:$PASSWORD $BASE_URL/admin/completed_requests
To get a list of all logged completed requests using SQL++:
SELECT * FROM system:completed_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
.
-
SQL++
To get a list of all logged completed requests, including only successful requests:
SELECT * FROM system:completed_requests
WHERE state = "completed" AND errorCount = 0;
To get the query plan for completed requests, include meta().plan
in a SQL++ query.
See Query Profiling.
-
SQL++
To view completed requests with SQL++, including the query plan:
SELECT *, meta().plan FROM system:completed_requests;
Purge the Completed Requests
To purge a specific completed request, use the Admin REST API or a SQL++ query.
-
REST API
-
SQL++
To purge a completed request uuid
with the Admin REST API:
curl -u $USER:$PASSWORD -X DELETE $BASE_URL/admin/completed_requests/uuid
To purge a completed request uuid
with SQL++:
DELETE FROM system:completed_requests WHERE requestId = "uuid";
To purge completed requests for a given time period, use a SQL++ query.
-
SQL++
To purge the completed requests for a given time period:
DELETE FROM system:completed_requests WHERE requestTime LIKE "2015-09-09%";
Completed Request Details
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.
For this example, set the query context to the inventory
scope in the travel sample dataset.
For more information, see Query Context.
SELECT * FROM route ORDER BY sourceairport LIMIT 5;
Getting completed requests, as described in Get Completed Requests, returns results similar to the following.
[
// ...
{
"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
},
"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"
}
}
]
For field names and meanings, see Requests.
For query plan field names and meanings, see Query Profiling Details.
Configure the Completed Requests
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.
Completed requests that meet the defined qualifiers are logged.
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).
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, see 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
.
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.
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:
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:
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.
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 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 0
to log all requests and -1
to not log any requests to the keyspace.
To specify a different value, use:
curl $BASE_URL/admin/settings -u $USER:$PASSWORD \
-H 'Content-Type: application/json' \
-d '{"completed-threshold":0}'
Completed Limit
The 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 0
to not track any requests and -1
to set no limit.
To specify a different value, use:
curl $BASE_URL/admin/settings -u $USER:$PASSWORD \
-H 'Content-Type: application/json' \
-d '{"completed-limit":1000}'
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 node level, so that it is enabled for all queries on that node.
-
At the request level, for individual queries.
For more information about Query settings and parameters, see Configure Queries.
Enable Query Profiling for a Query Node
To activate query profiling at the node level, specify the profile
setting using the Admin REST API (/admin/settings
endpoint).
The following request gets the current node-level query settings.
curl $BASE_URL/admin/settings -u $USER:$PASSWORD
{
"atrcollection": "",
"auto-prepare": false,
"cleanupclientattempts": true,
"cleanuplostattempts": true,
"cleanupwindow": "1m0s",
"completed": {
"aborted": null,
"threshold": 1000
},
"completed-limit": 4000,
"completed-threshold": 1000,
"controls": false,
"cpuprofile": "",
"debug": false,
"functions-limit": 16384,
"keep-alive-length": 16384,
"loglevel": "INFO",
"max-index-api": 4,
"max-parallelism": 1,
"memory-quota": 0,
"memprofile": "",
"mutexprofile": false,
"n1ql-feat-ctrl": 76,
"numatrs": 1024,
"pipeline-batch": 16,
"pipeline-cap": 512,
"plus-servicers": 16,
"prepared-limit": 16384,
"pretty": false,
"profile": "off",
"request-size-cap": 67108864,
"scan-cap": 512,
"servicers": 4,
"timeout": 0,
"txtimeout": "0s",
"use-cbo": true
}
The following request saves the current node-level query settings to the file query_settings.json
.
curl $BASE_URL/admin/settings -u $USER:$PASSWORD -o ./query_settings.json
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.
curl $BASE_URL/admin/settings -u $USER:$PASSWORD \
-X POST \
-d@./query_settings.json
The following request explicitly sets query profiling at the node level.
curl $BASE_URL/admin/settings -u $USER:$PASSWORD \
-H 'Content-Type: application/json' \
-d '{"profile": "phases"}'
{
// ...
"profile":"phases",
"request-size-cap": 67108864,
"scan-cap": 512,
"servicers": 4,
"timeout": 0,
"txtimeout": "0s",
"use-cbo": true
}
Enable Query Profiling for a Request
To activate profiling at the request level, you can:
-
Specify the
profile
setting using the Query REST API (/query/service
endpoint). -
Specify the
profile
setting using the cbq command line tool.
-
REST API
-
SQL++
To set query settings using the REST API, specify the parameters in the request body.
The following statement sets the profiling to phases:
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:
curl $BASE_URL/query/service -u $USER:$PASSWORD \
-d 'profile=timings&statement=SELECT * FROM `travel-sample`.inventory.airline LIMIT 1'
To set query settings using the cbq shell, use the \SET
command.
The following statement sets the profiling to phases:
\set -profile "phases";
SELECT * FROM `travel-sample`.inventory.airline LIMIT 1;
The following statement sets the profiling to timings:
\set -profile "timings";
SELECT * FROM `travel-sample`.inventory.airline LIMIT 1;
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 Query Preferences.
Query Profiling Details
You can access the profiling information in the following ways:
-
In the query responses.
-
In the system catalogs.
When a query executes a user-defined function, profiling information is available for the SQL++ queries within the user-defined function as well.
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.
-
If you are using the Query workbench, query profiling information is not returned with the query results.
If you are using the cbq shell or the Query REST API, the following statistics are returned when profile
is set to phases
:
{
"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"
}
}
If you are using the cbq shell or the Query REST API, the following statistics are returned when profile
is set to timings
:
{
"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"
]
}
}
}
For field names and meanings, see Profile.
Profiling Details in System Catalogs
The system:active_requests and system:completed_requests system catalogs always return profiling information regarding query phases: that is, phase times, phase counts, and phase operators.
The system:active_requests, system:completed_requests, and system:prepareds system catalogs also support the meta().plan
virtual attribute.
This captures the whole query plan, and includes profiling information regarding execution timings.
To get execution timing information from these system catalogs, you must explicitly specify meta().plan
in the projection list for the SELECT query.
Within these system catalogs, not all statements have a meta().plan
attribute.
-
With system:active_requests and system:completed_requests, the
meta().plan
attribute is only available for statements that you run when profile is set totimings
. -
With system:prepareds, the
meta().plan
attribute is available for all statements.
When request profiling is set to
|
Getting the plan for a statement that you ran when the profile was set to timings
returns results similar to the following.
[
{
// ...
"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"
]
}
}
]
For field names and meanings, see Execution Timings.
Query Profiling Summary
The following table summarizes Query profiling behavior.
Profile is … | Query returns … | Catalog includes … | ||||
---|---|---|---|---|---|---|
cbq |
REST API |
Query |
Active |
Completed |
Prepared |
|
|
phases |
phases |
timings |
|||
|
phases |
phases |
phases |
phases |
timings |
|
|
phases |
phases |
phases |
phases |
timings |
Related Links
-
Refer to Getting System Information for more information on the system namespace.