Monitor Queries
Monitoring and profiling N1QL queries, query service engines, 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 query service. When running on a cluster with multiple query nodes, stats about all queries on all query nodes are collected in these system keyspaces.
For example, this can help identify:
-
The top 10 slow or fast queries running on a particular query engine 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 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. You can access the keyspaces using any of the following:
-
N1QL language (from the cbq shell or Query Workbench)
-
REST API
-
Monitoring SDK
All the power of the N1QL query language can be applied on the keyspaces to obtain various insights. |
The following diagnostics are provided:
System Catalogs |
|||
Monitoring Catalogs |
|||
Security Catalogs |
|||
Other |
|
Authentication and Client Privileges
Client applications must be authenticated with sufficient privileges to access system keyspaces.
-
An Administrator user can access all system keyspaces, and can grant or revoke privileges to and from other users.
-
Other non-Administrator users must have explicitly granted privilege called Query System Catalog to access the restricted system keyspaces. For querying details of system keyspaces, see Getting System Information.
-
The following system keyspaces are considered open, that is, all users can access them without any special privileges:
-
system:dual
-
system:datastores
-
system:namespaces
-
Query Monitoring Settings
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 Admin REST API (/admin/settings
endpoint) and the Query REST API (/query/service
endpoint).
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 Preferences option. For more information refer to the Query Workbench section.
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:
-
profile
-
controls
For more details and examples, refer to the Query Settings section.
Enabling Settings for a Query Engine
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.
-
Get the current query settings:
$ curl http://localhost:8093/admin/settings -u user:pword -o ./query_settings.json $ cat ./query_settings.json
{ "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 }
-
Set current query settings profile:
-
To set the query settings saved in a file ./query_settings.json, enter the following query:
$ curl http://localhost:8093/admin/settings -u user:pword \ -X POST \ -d@./query_settings.json
-
To explicitly specify the settings, enter the following query:
$ curl http://localhost:8093/admin/settings -u user:pword \ -H 'Content-Type: application/json' \ -d '{"profile": "phases"}'
-
-
Verify the settings are changed as specified:
$ curl http://localhost:8093/admin/settings -u user:pword
{ // ... "profile":"phases", "request-size-cap": 67108864, "scan-cap": 512, "servicers": 4, "timeout": 0, "txtimeout": "0s", "use-cbo": true }
Enabling Settings per Session or per Query
You can enable monitoring and profiling settings for each query statement.
To set query settings using the cbq shell, use the \SET
command:
cbq> \set -profile "timings";
cbq> \set;
Query Parameters :
Parameter name : profile
Value : ["timings"]
...
To set query settings using the REST API, specify the parameters in the request body:
$ curl http://localhost:8093/admin/settings -u user:pword \
-d 'profile=timings&statement=SELECT * FROM "world" AS hello;'
Monitoring and Profiling Details
Couchbase Server provides detailed query monitoring and profiling information. The profiling and finer query execution timing details can be obtained for any query.
Attribute Profile in Query Response
When profiling is enabled, a query response includes the profile attribute. The attribute details are as follows:
Attribute | Example | ||
---|---|---|---|
|
|
||
|
|
||
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 |
|
||
The following statistics are collected for each operator:
|
|
These statistics (kernTime
, servTime
, and execTime
) can be very helpful in troubleshooting query performance issues, such as:
-
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).
The cbq engine must be started with authorization, for example:
$ ./cbq -engine=http://localhost:8091/ -u Administrator -p pword
Show the statistics collected when the profile
is set to phases
:
cbq> \set -profile "phases";
cbq> SELECT * FROM `travel-sample`.inventory.airline LIMIT 1;
{
"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"
}
}
Show the statistics collected when profile
is set to timings
:
cbq> \set -profile "timings";
cbq> SELECT * FROM `travel-sample`.inventory.airline LIMIT 1;
{
"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"
]
}
}
}
Attribute Meta in System Keyspaces
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.
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.
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.
For the system:prepareds requests, the meta().plan is available at all times since the PREPARE statement is not dependant on the profile setting.
|
This attribute is enabled for the following system keyspaces:
For a detailed example, see Example 5.
N1QL Cluster Monitoring
Description
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 N1QL nodes from N1QL.
-
Ability to list nodes by type and with status from N1QL.
-
Ability to list system keyspaces from
system:keyspaces
. -
Extra fields in
system:active_requests
andsystem: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
andsystem: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
The 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.
For field names and meanings, refer to Vitals.
Get System Vitals
$ curl -u Administrator:pword http://localhost:8093/admin/vitals
{
"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
}
system:active_requests
This catalog lists all currently executing active requests or queries.
For field names and meanings, refer to Requests. The profile related attributes are described in the section Attribute profile in Query Response.
Get Active Requests
To view active requests with Admin REST API:
$ curl -u Administrator:pword http://localhost:8093/admin/active_requests
To view active requests with N1QL, 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.
To terminate an active request uuid
with the Admin REST API:
$ curl -u Administrator:pword -X DELETE http://localhost:8093/admin/active_requests/uuid
To terminate an active request uuid
with N1QL:
DELETE FROM system:active_requests WHERE requestId = "uuid";
Examples
SELECT *, meta().plan FROM system:active_requests;
[
{
"active_requests": {
"clientContextID": "81984707-a9cd-4b78-9110-d130eb580d7f",
"elapsedTime": "65.543946ms",
"executionTime": "65.507111ms",
"node": "127.0.0.1:8091",
"phaseCounts": {
"primaryScan": 1
},
"phaseOperators": {
"authorize": 1,
"fetch": 1,
"primaryScan": 1
},
"phaseTimes": {
"authorize": "2.361862ms",
"fetch": "7.222µs",
"instantiate": "13.233µs",
"parse": "660.048µs",
"plan": "52.877µs",
"primaryScan": "41.125271ms"
},
"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",
"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"
]
}
}
]
1 | The plan section contains a tree of operators that combine to execute the N1QL query. The root operator is a Sequence, which itself has a collection of child operators like Authorize, PrimaryScan, Fetch, and possibly even more Sequences. |
system:prepareds
This catalog provides data about the known prepared statements and their state in a query engine’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 Statements.
The system:prepareds
catalog returns all the properties that the N1QL Admin REST API would return for a specific prepared statement.
In addition, the system:prepareds
catalog also returns the following property.
Name | Description | Schema |
---|---|---|
node |
The node on which the prepared statement is stored. |
string |
Get Prepared Statements
To get a list of all known prepared statements, you can use the Admin REST API or a N1QL query:
$ curl -u Administrator:pword http://localhost:8093/admin/prepareds
SELECT * FROM system:prepareds;
To get information about a specific prepared statement example1
, you can use the Admin REST API or a N1QL query:
$ curl -u Administrator:pword http://localhost:8093/admin/prepareds/example1
SELECT * FROM system:prepareds WHERE name = "example1";
Delete Prepared Statements
To delete a specific prepared statement p1
, you can use the Admin REST API or a N1QL query:
$ curl -u Administrator:pword -X DELETE http://localhost:8093/admin/prepareds/p1
DELETE FROM system:prepareds WHERE name = "p1";
To delete all the known prepared statements, you must use a N1QL query:
DELETE FROM system:prepareds;
Examples
PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = "U2";
{
"requestID": "06819475-e1f6-48a6-8b78-41a6fbac7810",
"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": "60.560801ms",
"executionTime": "60.291394ms",
"resultCount": 1,
"resultSize": 3301,
"serviceLoad": 12
},
"profile": {
"phaseTimes": {
"authorize": "21.597µs",
"instantiate": "14.64µs",
"parse": "1.718303ms",
"plan": "1.658632ms",
"run": "56.817557ms"
},
"phaseOperators": {
"authorize": 1
},
"requestTime": "2021-04-30T21:46:33.972Z",
"servicingHost": "127.0.0.1:8091"
}
}
SELECT *, meta().plan FROM system:prepareds;
{
"requestID": "42adcc5e-3d7f-4228-8da1-035093a93406",
"signature": {
"*": "*",
"plan": "json"
},
"results": [
{
"plan": {
"#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"
}
]
}
},
"prepareds": {
"encoded_plan": "H4sIAAAAAAAA/6RT3W7UPBB9leh8N23lr6KAqGTExVJtBaKo0W6BC1olJpndmnptd+ysGlbh2ZGTtFW3CIR6l9gzZ86PZwOylaupLrxRFhIQWJCKDdORs5GdCZCHrwS0relm4vVn4qCdhXw5ns0rZT9QG7yqKEBuUNNCNSbKyGpN5v+gVt7QvrZrstFxu680G20JcqFMoE7AqhVBwh9g+O6hIG+BIOA8sYqOE/x/9z+YNPHSsf5BEPCs19rQciBxokOE/LrBmeIlxXu0v9ISyFmvIQ/Th/MB8ll30Qn8rC61qbcZzOm6IVultqGAyfZz/7koZ71S3CY7X0DgW1Nd9bwf8MVo+qCnuGNfjOwLP6Dc1hWe3XeqYp/YBuNtcUUtZOQmuX81ZgeJewt+H0OonE8nd2Mh0ARtl5BYBo1OPJR0TLG6/JOWJ83enpYrVsaQwZOyOtYmEkOgcrbWg3HY2SlHfuV+qVVU5W72JjvHp+fn2H1E5L3VUSuTD9ZDgCk0JhaReBX6gXTjU2Egs0jSouIxjovuokuvbYt4ZFIrpDuB64a4TbtJN3HYV6brs7Y3Zz49mR6dJUi9tP0SJw/2ILGHTmBsyWfTfDKbZv4gm8yzoSfby45npx+z8kFE5eP9yL68m86mWTLhzoLX/Tugo7eno4xfAQAA//83PgrgVgQAAA==",
"featuresControl": 76,
"indexApiVersion": 4,
"indexScanKeyspaces": {
"default:travel-sample.inventory.airline": false
},
"name": "p1",
"namespace": "default",
"node": "127.0.0.1:8091",
"statement": "PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = \"U2\";",
"uses": 0
}
}
],
"status": "success",
"metrics": {
"elapsedTime": "74.38189ms",
"executionTime": "74.238983ms",
"resultCount": 1,
"resultSize": 3936,
"serviceLoad": 12
},
"profile": {
"phaseTimes": {
"authorize": "18.115µs",
"fetch": "17.331889ms",
"instantiate": "18.856µs",
"parse": "673.255µs",
"plan": "99.23µs",
"primaryScan": "55.468539ms",
"run": "73.429071ms"
},
"phaseCounts": {
"fetch": 1,
"primaryScan": 1
},
"phaseOperators": {
"authorize": 1,
"fetch": 1,
"primaryScan": 1
},
"requestTime": "2021-04-30T21:47:56.814Z",
"servicingHost": "127.0.0.1:8091"
}
}
system:completed_requests
By default, this 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 Requests.
Note that most field names and meanings match exactly those of system:active_requests
.
Request profiling affects the
|
Get Completed Requests
To get a list of all logged completed requests using the Admin REST API:
$ curl -u Administrator:pword http://localhost:8093/admin/completed_requests
To get a list of all logged completed requests using N1QL, including the query plan:
SELECT *, meta().plan FROM system:completed_requests;
Purge the Completed Requests
To purge a completed request uuid
with the Admin REST API:
$ curl -u Administrator:pword -X DELETE http://localhost:8093/admin/completed_requests/uuid
To purge a completed request uuid
with N1QL:
DELETE FROM system:completed_requests WHERE requestId = "uuid";
To purge the completed requests for a given time period, use:
DELETE FROM system:completed_requests WHERE requestTime LIKE "2015-09-09%";
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.
$ 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).
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 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 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.
$ 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:
$ 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:
$ 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.
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 http://localhost:port/admin/settings -H 'Content-Type: application/json' -d '{"completed-threshold":0}' -u user:pword
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 http://localhost:port/admin/settings -H 'Content-Type: application/json' -d '{"completed-limit":1000}' -u user:pword
Examples
First, 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:
cbq> \set -profile "timings";
cbq> SELECT * FROM `travel-sample`.inventory.route ORDER BY sourceairport;
Now, we change the profile setting to "phases" and rerun another long query:
cbq> \set -profile "phases";
cbq> SELECT * FROM `travel-sample`.inventory.route ORDER BY destinationairport;
Run a query system:completed_requests
keyspace with meta().plan
.
cbq> SELECT meta().plan, * from system:completed_requests;
{
"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"
},
"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"
]
}
}
],
"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) |
system:my_user_info
This catalog maintains a list of all information of your profile.
To see your current information, use:
SELECT * FROM system:my_user_info;
This will result in a list similar to:
[
{
"my_user_info": {
"domain": "local",
"external_groups": [],
"groups": [],
"id": "jane",
"name": "Jane Doe",
"password_change_date": "2019-05-07T02:31:53.000Z",
"roles": [
{
"origins": [
{
"type": "user"
}
],
"role": "admin"
}
]
}
}
]
system:user_info
This catalog maintains a list of all current users in your bucket and their information.
To see the list of all current users, use:
SELECT * FROM system:user_info;
This will result in a list similar to:
[
{
"user_info": {
"domain": "local",
"external_groups": [],
"groups": [],
"id": "jane",
"name": "Jane Doe",
"password_change_date": "2019-05-07T02:31:53.000Z",
"roles": [
{
"origins": [
{
"type": "user"
}
],
"role": "admin"
}
]
}
},
{
"user_info": {
"domain": "ns_server",
"id": "Administrator",
"name": "Administrator",
"roles": [
{
"role": "admin"
}
]
}
}
]
system:nodes
This catalog shows the datastore topology information.
This is separate from the N1QL clustering view, in that N1QL clustering shows a map of the N1QL cluster, as provided by the cluster manager, while system:nodes
shows a view of the nodes and services that make up the actual datastore, which may or may not include N1QL nodes.
-
The dichotomy is important in that N1QL could be clustered by one entity (e.g. Zookeeper) and be connected to a clustered datastore (e.g. Couchbase) such that each does not have visibility of the other.
-
Should N1QL be extended to be able to concurrently connect to multiple datastores, each datastore will report its own topology, so that
system:nodes
offers a complete view of all the storage nodes, whatever those may be. -
The
system:nodes
keyspace provides a way to report services advertised by each node as well as services that are actually running. This is datastore dependent. -
N1QL clustering is still reported by the
/admin
endpoints.
To see the list of all current node information, use:
SELECT * FROM system:nodes;
This will result in a list similar to:
[
{
"nodes": {
"name": "127.0.0.1:8091",
"ports": {
"cbas": 8095,
"cbasAdmin": 9110,
"cbasCc": 9111,
"cbasSSL": 18095,
"eventingAdminPort": 8096,
"eventingSSL": 18096,
"fts": 8094,
"ftsSSL": 18094,
"indexAdmin": 9100,
"indexHttp": 9102,
"indexHttps": 19102,
"indexScan": 9101,
"indexStreamCatchup": 9104,
"indexStreamInit": 9103,
"indexStreamMaint": 9105,
"kv": 11210,
"kvSSL": 11207,
"n1ql": 8093,
"n1qlSSL": 18093
},
"services": [
"cbas",
"eventing",
"fts",
"index",
"kv",
"n1ql"
]
}
}
]
system:applicable_roles
This catalog maintains a list of all applicable roles and grantee of each bucket.
To see the list of all current applicable role information, use:
SELECT * FROM system:applicable_roles;
This will result in a list similar to:
[
{
"applicable_roles": {
"grantee": "anil",
"role": "replication_admin"
}
},
{
"applicable_roles": {
"bucket_name": "travel-sample",
"grantee": "anil",
"role": "select"
}
},
{
"applicable_roles": {
"bucket_name": "*",
"grantee": "anil",
"role": "select"
}
}
]
For more examples, take a look at the blog: Optimize N1QL performance using request profiling.
system:functions
This catalog maintains a list of all user-defined functions across all nodes. To see the list of all user-defined functions, use:
SELECT * FROM system:functions;
This will result in a list similar to:
[
{
"functions": {
"definition": {
"#language": "inline", (1)
"expression": "substr0(`vString`, (length(`vString`) - `vLen`), `vLen`)", (2)
"parameters": [ (3)
"vString",
"vLen"
]
},
"identity": {
"name": "rstr",
"namespace": "default",
"type": "global"
}
}
},
{
"functions": {
"definition": {
"#language": "javascript",
"library": "math77", (4)
"object": "add" (5)
},
"identity": {
"name": "javaScriptAdd", (6)
"namespace": "default", (7)
"type": "global" (8)
}
}
}
]
This query returns the following attributes:
1 | definition.#language : string (the language of the function, for example, inline) |
2 | definition.expression : string (for inline functions only: the expression defining the function) |
3 | definition.parameters : array of strings (the parameters required by the function) |
4 | definition.library : string (for JavaScript functions only: the library containing the function) |
5 | definition.object : string (for JavaScript functions only: the object defining the function) |
6 | identity.name : string (the name of the function) |
7 | identity.namespace : string (the namespace of the function, for example, default) |
8 | identity.type : string (the type of the function, for example, global) |
system:functions_cache
This catalog maintains a list of recently-used user-defined functions across all nodes. The catalog also lists user-defined functions that have been called recently, but do not exist. To see the list of recently-used user-defined functions, use:
SELECT * FROM system:functions_cache;
This will result in a list similar to:
[
{
"functions_cache": {
"#language": "inline", (1)
"avgServiceTime": "8.926µs",
"expression": "substr0(`vString`, (length(`vString`) - `vLen`), `vLen`)", (2)
"lastUse": "2019-08-06 06:08:35.37498882 -0700 PDT m=+2236.523899555",
"maxServiceTime": "8.926µs",
"minServiceTime": "0s",
"name": "rstr", (3)
"namespace": "default", (4)
"node": "127.0.0.1:8091",
"parameters": [ (5)
"vString",
"vLen"
],
"type": "global",
"uses": 1
}
},
{
"functions_cache": {
"#language": "javascript",
"avgServiceTime": "674.264µs",
"lastUse": "2019-08-06 06:10:50.681845642 -0700 PDT m=+2371.830756442",
"library": "math77", (6)
"maxServiceTime": "674.264µs",
"minServiceTime": "0s",
"name": "javaScriptAdd",
"namespace": "default",
"node": "127.0.0.1:8091",
"object": "add", (7)
"type": "global", (8)
"uses": 1
}
},
{
"functions_cache": {
"avgServiceTime": "22.79µs", (9)
"lastUse": "2019-08-06 16:59:51.630317391 +0100 BST m=+17.966707065", (10)
"maxServiceTime": "22.79µs", (11)
"minServiceTime": "0s", (12)
"name": "notFound",
"namespace": "default",
"node": "127.0.0.1:8091", (13)
"type": "global",
"undefined_function": true, (14)
"uses": 1 (15)
}
}
]
This query returns the following attributes:
1 | #language : string (the language of the function, for example, inline) |
2 | expression : string (for inline functions only: the expression defining the function) |
3 | name : string (the name of the function) |
4 | namespace : string (the namespace of the function, for example, default) |
5 | parameters : array of strings (the parameters required by the function) |
6 | library : string (for JavaScript functions only: the library containing the function) |
7 | object : string (for JavaScript functions only: the object defining the function) |
8 | type : string (the type of the function, for example, global) |
9 | avgServiceTime : string (the mean service time for the function) |
10 | lastUse : string (the date and time when the function was last used) |
11 | maxServiceTime : string (the maximum service time for the function) |
12 | minServiceTime : string (the minimum service time for the function) |
13 | node : string (the query node where the function is cached) |
14 | undefined_function : boolean (whether the function exists or is undefined) |
15 | uses : number (the number of uses of the function) |
Each query node keeps its own cache of recently-used user-defined functions, so you may see the same function listed for multiple nodes.
system:tasks_cache
This catalog maintains a list of recently-used scheduled tasks, such as index advisor sessions. To see the list of recently-used scheduled tasks, use:
SELECT * FROM system:tasks_cache;
This will result in a list similar to:
[
{
"tasks_cache": {
"class": "advisor", (1)
"delay": "1h0m0s", (2)
"id": "bcd9f8e4-b324-504c-a98b-ace90dba869f", (3)
"name": "aa7f688a-bf29-438f-888f-eeaead87ca40", (4)
"node": "10.143.192.101:8091", (5)
"state": "scheduled", (6)
"subClass": "analyze", (7)
"submitTime": "2019-09-17 05:18:12.903122381 -0700 PDT m=+8460.550715992" (8)
}
},
{
"tasks_cache": {
"class": "advisor",
"delay": "5m0s",
"id": "254abec5-5782-543e-9ee0-d07da146b94e",
"name": "ca2cfe56-01fa-4563-8eb0-a753af76d865",
"node": "10.143.192.101:8091",
"results": [ (9)
// ...
],
"startTime": "2019-09-17 05:03:31.821597725 -0700 PDT m=+7579.469191487", (10)
"state": "completed",
"stopTime": "2019-09-17 05:03:31.963133954 -0700 PDT m=+7579.610727539", (11)
"subClass": "analyze",
"submitTime": "2019-09-17 04:58:31.821230131 -0700 PDT m=+7279.468823737"
}
}
]
This query returns the following attributes:
1 | class : string (the class of the task; for example, advisor ) |
2 | delay : string (the scheduled duration of the task) |
3 | id : string (the internal ID of the task) |
4 | name : string (the name of the task) |
5 | node : string (the node where the task was started) |
6 | state : string (the class of the task — scheduled , cancelled , completed ) |
7 | subClass : string (the subclass of the task; for example, analyze ) |
8 | submitTime : string (the date and time when the task was submitted) |
9 | results : array (not scheduled tasks: the results of the task) |
10 | startTime : string (not scheduled tasks: the date and time when the task started) |
11 | stopTime : string (not scheduled tasks: the date and time when the task stopped) |
Refer to ADVISOR Function for more information on index advisor sessions.
system:transactions
This catalog maintains a list of active Couchbase transactions. To see the list of active transactions, use:
SELECT * FROM system:transactions;
This will result in a list similar to:
[
{
"transactions": {
"durabilityLevel": "majority", (1)
"durabilityTimeout": "2.5s", (2)
"expiryTime": "2021-04-21T12:53:48.598+01:00",
"id": "85aea637-2288-434b-b7c5-413ad8e7c175", (3)
"isolationLevel": "READ COMMITED", (4)
"lastUse": "2021-04-21T12:51:48.598+01:00",
"node": "127.0.0.1:8091", (5)
"numAtrs": 1024, (6)
"scanConsistency": "unbounded", (7)
"status": 0,
"timeout": "2m0s", (8)
"usedMemory": 960,
"uses": 1
}
// ...
}
]
This query returns the following attributes:
1 | durabilityLevel : string (durability level for all mutations within a transaction) |
2 | durabilityTimeout : duration (durability timeout per mutation within the transaction) |
3 | id : string (the transaction ID) |
4 | isolationLevel : string (the isolation level of the transaction) |
5 | node : string (the node where the transaction was started) |
6 | numAtrs : integer (the total number of active transaction records) |
7 | scanConsistency : string (the transactional scan consistency) |
8 | timeout : duration (the transaction timeout duration) |
Refer to N1QL Support for Couchbase Transactions for more information.
Related Links
-
Refer to Getting System Information for more information on the system namespace.