Manage and Monitor Queries

  • Capella Operational
      +
      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 the Query tab

      • A monitoring SDK

      Using SQL++ enables you to obtain further insights from the keyspaces.

      Authentication and Client Privileges

      Users must have permission to access restricted system keyspaces. For more details about cluster credentials, see Configure Cluster Access Credentials.

      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 a SQL++ query.

      • SQL++

      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
      }

      This catalog contains the following attributes:

      Name Description Schema

      bucket.IO.stats
      optional

      The number of reads and retries for each bucket.

      object

      cores
      optional

      The maximum number of logical cores available to the query engine.

      integer

      cpu.sys.percent
      optional

      CPU usage. The percentage of time spent executing system code since the last time the statistics were checked.

      integer (int64)

      cpu.user.percent
      optional

      CPU usage. The percentage of time spent executing user code since the last time the statistics were checked.

      integer (int64)

      ffdc.total
      optional

      The total number of times FFDC has been invoked since the last restart.

      integer

      gc.num
      optional

      The target heap size of the next garbage collection cycle.

      integer (int64)

      gc.pause.percent
      optional

      The percentage of time spent pausing for garbage collection since the last time the statistics were checked.

      integer (int64)

      gc.pause.time
      optional

      The total time spent pausing for garbage collection since the query engine started (ns).

      string (duration)

      healthy
      optional

      False when either the unbounded or plus request queues are full; true otherwise.

      boolean

      host.memory.free
      optional

      Amount of free memory on the host.

      integer (int64)

      host.memory.quota
      optional

      The host memory quota. This reflects the node-quota setting.

      integer (int64)

      host.memory.total
      optional

      Total memory on the host.

      integer (int64)

      host.memory.value_quota
      optional

      This the total document memory quota on the node.

      integer (int64)

      load
      optional

      A calculation for how busy the server is.

      integer

      loadfactor
      optional

      The moving 15 minute average of the load calculation.

      integer

      local.time
      optional

      The local time of the query engine.

      string (date-time)

      memory.system
      optional

      The total amount of memory obtained from the operating system (bytes). This measures the virtual address space reserved by the query engine for heaps, stacks, and other internal data structures.

      integer (int64)

      memory.total
      optional

      The cumulative amount of memory allocated for heap objects (bytes). This increases as heap objects are allocated, but does not decrease when objects are freed.

      integer (int64)

      memory.usage
      optional

      The amount of memory allocated for heap objects (bytes). This increases as heap objects are allocated, and decreases as objects are freed.

      integer (int64)

      node
      optional

      The name or IP address and port of the node.

      string

      node.allocated.values
      optional

      The total number of values allocated to contain documents or computations around documents. (This is only of relevance internally.)

      integer

      node.memory.usage
      optional

      The currently allocated document memory on the node.

      integer

      process.memory.usage
      optional

      Current process memory use.

      integer

      process.percore.cpupercent
      optional

      Average CPU usage per core.

      number

      process.rss
      optional

      Process RSS (bytes)

      integer

      process.service.usage
      optional

      The number of active servicers for the dominant workload — unbound queue servicers or plus queue servicers.

      integer

      request.active.count
      optional

      Total number of active requests.

      integer

      request.completed.count
      optional

      Total number of completed requests.

      integer

      request.per.sec.15min
      optional

      Number of query requests processed per second. 15-minute exponentially weighted moving average.

      number

      request.per.sec.1min
      optional

      Number of query requests processed per second. 1-minute exponentially weighted moving average.

      number

      request.per.sec.5min
      optional

      Number of query requests processed per second. 5-minute exponentially weighted moving average.

      number

      request.prepared.percent
      optional

      Percentage of requests that are prepared statements.

      integer

      request.queued.count
      optional

      Number of queued requests.

      integer

      request.quota.used.hwm
      optional

      High water mark for request quota use.

      integer

      request_time.80percentile
      optional

      End-to-end time to process a query. The 80th percentile.

      string (duration)

      request_time.95percentile
      optional

      End-to-end time to process a query. The 95th percentile.

      string (duration)

      request_time.99percentile
      optional

      End-to-end time to process a query. The 99th percentile.

      string (duration)

      request_time.mean
      optional

      End-to-end time to process a query. The mean value.

      string (duration)

      request_time.median
      optional

      End-to-end time to process a query. The median value.

      string (duration)

      servicers.paused.count
      optional

      Number of servicers temporarily paused due to memory pressure. (Applies to serverless environments only.)

      integer

      servicers.paused.total
      optional

      Number of times servicers have been temporarily paused. (Applies to serverless environments only.)

      integer

      temp.hwm
      optional

      High water mark for temp space use directly by query. (Doesn’t include use by the GSI and FTS clients.)

      integer

      temp.usage
      optional

      Current Query temp space use. (Doesn’t include use by the GSI and FTS clients.)

      integer

      total.threads
      optional

      The number of active threads used by the query engine.

      integer

      uptime
      optional

      The uptime of the query engine.

      string (duration)

      version
      optional

      The version of the query engine.

      string

      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 a SQL++ query.

      • SQL++

      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.

      • SQL++

      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"
          }
        }
      ]

      This catalog contains the following attributes:

      Name Description Schema

      clientContextID
      optional

      The opaque ID or context provided by the client. Refer to the request-level client_context_id parameter for more information.

      string

      elapsedTime
      optional

      The time taken from when the request was acknowledged by the service to when the request was completed. It includes the time taken by the service to schedule the request.

      string (duration)

      errorCount
      optional

      Total number of errors encountered while executing the query.

      integer

      memoryQuota
      optional

      The memory quota for the request, in MB. This property is only returned if a memory quota is set for the query.

      integer

      node
      optional

      IP address and port number of the node where the query is executed.

      string

      phaseCounts
      optional

      Count of documents processed at selective phases involved in the query execution, such as authorize, index scan, fetch, parse, plan, run, etc.

      For active requests, this property is dynamic, depending on the documents processed by various phases up to this moment in time. Polling the active requests again may return different values.
      Example : { "fetch" : 16, "indexScan" : 187 }

      object

      phaseOperators
      optional

      Indicates the numbers of each kind of query operator involved in different phases of the query processing.

      For instance, a non-covering index path might involve one index scan and one fetch operator. A join would probably involve two or more fetches, one per keyspace. A union select would have twice as many operator counts, one per each branch of the union.
      Example : { "authorize" : 1, "fetch" : 1, "indexScan" : 2 }

      object

      phaseTimes
      optional

      Cumulative execution times for various phases involved in the query execution, such as authorize, index scan, fetch, parse, plan, run, etc.

      For active requests, this property is dynamic, depending on the documents processed by various phases up to this moment in time. Polling the active requests again may return different values.
      Example : { "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" }

      object

      remoteAddr
      optional

      IP address and port number of the client application, from where the query is received.

      string

      requestId
      optional

      Unique request ID internally generated for the query.

      string (uuid)

      requestTime
      optional

      Timestamp when the query is received.

      string (date-time)

      resultCount
      optional

      Total number of documents returned in the query result.

      integer

      resultSize
      optional

      Total number of bytes returned in the query result.

      integer

      scanConsistency
      optional

      The value of the query setting Scan Consistency used for the query.

      string

      serviceTime
      optional

      Total amount of calendar time taken to complete the query.

      string (duration)

      state
      optional

      The state of the query execution, such as completed, running, cancelled.

      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 were successful, use this field in conjunction with the errorCount field: search for requests whose state is completed and whose error count is 0.

      string

      statement
      optional

      The query statement being executed.

      string

      useCBO
      optional

      Whether the cost-based optimizer is enabled for the query.

      boolean

      usedMemory
      optional

      The amount of document memory used to execute the request. This property is only returned if a memory quota is set for the query.

      integer

      userAgent
      optional

      Name of the client application or program that issued the query.

      string

      users
      optional

      Username with whose privileges the query is run.

      string

      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 a SQL++ query.

      • SQL++

      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 a SQL++ query.

      • SQL++

      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 a SQL++ query.

      • SQL++

      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.

      Create a prepared statement with default query context

      For this example, unset the query context. For more information, see Query Context.

      Query
      PREPARE p1 AS SELECT * FROM `travel-sample`.inventory.airline WHERE iata = "U2";
      Create a prepared statement with specified query context

      For this example, set the query context to the inventory scope in the travel sample dataset. For more information, see Query Context.

      Query
      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

      This catalog contains the following attributes:

      Name Description Schema

      avgElapsedTime
      optional

      The mean time taken from when the request to execute the prepared statement was acknowledged by the service, to when the request was completed. It includes the time taken by the service to schedule the request.

      This property is only returned when the prepared statement has been executed. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      string (duration)

      avgServiceTime
      optional

      The mean amount of calendar time taken to complete the execution of the prepared statement.

      This property is only returned when the prepared statement has been executed. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      string (duration)

      encoded_plan
      required

      The full prepared statement in encoded format.

      string

      featureControls
      optional

      This property is provided for technical support only. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      integer

      indexApiVersion
      optional

      This property is provided for technical support only. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      integer

      lastUse
      optional

      Date and time of last use.

      This property is only returned when the prepared statement has been executed.

      string (date-time)

      maxElapsedTime
      optional

      The maximum time taken from when the request to execute the prepared statement was acknowledged by the service, to when the request was completed. It includes the time taken by the service to schedule the request.

      This property is only returned when the prepared statement has been executed. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      string (duration)

      maxServiceTime
      optional

      The maximum amount of calendar time taken to complete the execution of the prepared statement.

      This property is only returned when the prepared statement has been executed. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      string (duration)

      minElapsedTime
      optional

      The minimum time taken from when the request to execute the prepared statement was acknowledged by the service, to when the request was completed. It includes the time taken by the service to schedule the request.

      This property is only returned when the prepared statement has been executed. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      string (duration)

      minServiceTime
      optional

      The minimum amount of calendar time taken to complete the execution of the prepared statement.

      This property is only returned when the prepared statement has been executed. It is only returned when retrieving a specific prepared statement, not when retrieving all prepared statements.

      string (duration)

      name
      required

      The name of the prepared statement. This may be a UUID that was assigned automatically, or a name that was user-specified when the statement was created.

      string

      namespace
      optional

      The namespace in which the prepared statement is stored. Currently, only the default namespace is available.

      string

      node
      optional

      The node on which the prepared statement is stored.

      string

      statement
      required

      The text of the query.

      string

      uses
      required

      The count of times the prepared statement has been executed.

      integer

      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 a SQL++ query.

      • SQL++

      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 a SQL++ query.

      • SQL++

      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.

      Run a long query

      For this example, set the query context to the inventory scope in the travel sample dataset. For more information, see Query Context.

      Query
      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 Active Request Details.

      For query plan field names and meanings, see Query Profiling Details.

      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:

      For more information about Query settings and parameters, see Configure Queries.

      Enable Query Profiling for a Request

      To activate profiling at the request level, you can:

      • Specify the profile setting using the cbq command line tool.

      • SQL++

      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 tab automatically enables Query profiling, with detailed timing information. To disable or enable Query profiling with the Query tab, specify the Collect query timings option using the Query Settings.

      Query Profiling Details

      You can access the profiling information:

      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, query profiling information is returned with the query results.

      • If you are using the Query tab, query profiling information is not returned with the query results.

      Phases Profile

      If you are using the cbq shell, 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"
        }
      }
      Timings Profile

      If you are using the cbq shell, 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"
            ]
          }
        }
      }

      The profile object contains the following attributes:

      Name Description Schema

      requestTime
      required

      Timestamp when the query was received.

      string (date-time)

      servicingHost
      required

      IP address and port number of the node where the query was executed.

      string

      phaseCounts
      required

      Count of documents processed at selective phases involved in the query execution, such as authorize, index scan, fetch, parse, plan, run, etc.
      Example : { "fetch" : 16, "indexScan" : 187 }

      object

      phaseOperators
      required

      Indicates the numbers of each kind of query operator involved in different phases of the query processing.

      For instance, a non-covering index path might involve one index scan and one fetch operator. A join would probably involve two or more fetches, one per keyspace. A union select would have twice as many operator counts, one per each branch of the union.

      This is in essence the count of all the operators in the executionTimings object.
      Example : { "authorize" : 1, "fetch" : 1, "indexScan" : 2 }

      object

      phaseTimes
      required

      Cumulative execution times for various phases involved in the query execution, such as authorize, index scan, fetch, parse, plan, run, etc.
      Example : { "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" }

      object

      executionTimings
      optional

      Present only if profile was set to "timings" in the Request Parameters.

      The execution details for various phases involved in the query execution, such as kernel and service execution times, number of documents processed at each query operator in each phase, and number of phase switches.

      Execution Timings

      Name Description Schema

      #operator
      required

      Name of the operator.
      Example : "Fetch"

      string

      #stats
      required

      Statistics collected for the operator.

      ~child
      optional

      Further nested operators, each with their own execution timings.

      object

      Statistics

      Name Description Schema

      #itemsIn
      optional

      Number of input documents to the operator.
      Example : 187

      integer (int32)

      #itemsOut
      optional

      Number of output documents after the operator processing.
      Example : 16

      integer (int32)

      #phaseSwitches
      optional

      Number of switches between executing, waiting for services, or waiting for the goroutine scheduler.
      Example : 413

      integer (int32)

      execTime
      optional

      Time spent executing the operator code inside SQL++ query engine.
      Example : "128.434µs"

      string (duration)

      kernTime
      optional

      Time spent waiting to be scheduled for CPU time.
      Example : "15.027879ms"

      string (duration)

      servTime
      optional

      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.
      Example : "1.590934ms"

      string (duration)

      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.

      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.

      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. 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.

      Plan Details

      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 …​

      Query
      workbench

      cbq

      Active
      Requests

      Completed
      Requests

      Prepared
      Statements

      off

      phases

      phases

      timings

      phases

      phases

      phases

      phases

      timings

      timings

      phases
      timings

      phases
      timings

      phases
      timings

      timings