LCB_ERR_TIMEOUT (201) occurring MANY times per day

Our server (7.0) is throwing VERY frequent instances of LCB_ERR_TIMEOUT (201). This occurs at seemingly completely random times throughout the day. We’re currently averaging min 10 of these errors per day.

Query performance appears to have nothing to do with triggering this error, though it always seems to be the Query Service that triggers the error. Just last week, I got this error IN THE CB CONSOLE itself immediately after logging in and going to the query tab, where a sub 100ms query was cached. I then re-executed the exact same query with no error in 80ms. The majority of the time, the error is triggered via the PHP SDK 3.2. And most of the time, re-executing the exact same query magically resolves the issue. And in EVERY case, the query being executed is confirmed performing perfectly well (i.e. sub 100ms).

We’re unable to figure out how to glean ANY additional information regarding this error.

We don’t have any explicit timeouts set ANYWHERE on the server or in code. My understanding is that if you don’t set an explicit timeout at any level, none is applied, which begs the question of how LCB_ERR_TIMEOUT can be thrown in the first place.

How can we diagnose the reason behind all these errors? Is there a logging setting (specifically for PHP) that would output any additional information? We scoured the docs and existing logs for hours looking for a hint, but could find nothing relevant.

This issue is negatively impacting our bottom line. Help!

1 Like

I would briefly note that the PHP SDK default timeout for queries is 75s, but override-able.

One thing you may want to do is shortly after you observe this, check the completed_requests from the query service and see if there are any long ones. I do recall having heard about a problem where some queries wouldn’t complete recently, so you may want to also check the release notes (or someone else might chime in if they remember the circumstances) with 7.0.

Hope that helps!

1 Like

@ingenthr Thanks for the input. The problem appears worse than I originally anticipated.

Using the completed_requests query, we can clearly see that queries that typically complete in under 1 second are OFTEN taking over 1 full minute to complete.

Via completed_requests, we observe that the phaseTimes of all queries are completely within expected ranges, EXCEPT the run phase (which I’m unfamiliar with), which regularly takes MINUTES, despite the query itself running in milliseconds.

Further, we get radically variable performance from consecutive executions of the SAME query.

For instance, we run a query, it bombs out completely (after 10 minutes). We run it again and it takes less than one second. We IMMEDIATELY re-execute the query and it takes 10 minutes and dies. We re-execute again and the query completes in under 1 second. Then again in under 1 second. Then again. Then bam, complete failure. This is all the same query, executed from the admin console, simply executed repeatedly without changing any conditions.

We estimate around 5% to 30% of ALL queries are now simply timing out. We’ve tried restarting the entire cluster to no avail. We host 11 buckets in our cluster, of which no relevant collections contain more than 20k documents. We expect timeouts to be a possibility once we reach many millions or perhaps billions of documents, but obviously NOT with just thousands.

Our cluster RAM quota is 17.7GB., Each of the buckets has a RAM quota of 3GB.

We’ve made every effort to improve indexing performance to no avail. Queries that take 10ms or less are just as likely to timeout as heavier queries.

This is now a global issue from which we appear to have no way to recover. It is severely impacting our business and with it, our faith in Couchbase. We have the equivalent of a four alarm fire and desperately need the help of anyone who can properly diagnose this issue and suggest a reasonable solution.

Help!

@Robert_Mirabelle ,

You might be hitting MB-51826. Try upgrade 7.0.4 and see if the problem resolves.

Will you able to pick one of the query run through Query Workbench multiple times when it timeout or take more time than expected post the Profile stats (Plan Text Tab)

On query node
curl -u Administrator:password http://localhost:8093/debug/pprof/goroutine?debug=2
If you post the output we can see same issue or not

In each thread stack reload2(), Object() should not depend on each other lock and waiting for long time.

1 Like

I’m glad we were able to get some more visibility on the problem, even if it looks like it might be worse than initially anticipated.

One comment/recommendation- if you need immediate assistance and have an Enterprise subscription please reach out to Couchbase support. We love helping on the forums, of course, but it is intended to help people get going and discuss between devs/users/community. It is not a support mechanism with defined service levels. Support can get you those service levels, some priority and some additional resources.

I hope @vsr1 's suggestions nail it down though!

1 Like

MB-51826 Appears to be concerned with queries being stuck in timeout or submitted state. Our queries time out, but they don’t get “stuck” there. Immediately after timing out, you can re-execute the query it will typically work normally.

When I click Plan Text, the console displays an error in the results panel (where the plan text is expected):

Internal error generating query plan: TypeError: Cannot read properties of undefined (reading 'forEach')

The Chrome console outputs the following:

Got error: [@14,70:70=':',<26>,1:70],1,70,mismatched input ':' expecting ')',
myN1qlListener.js:222 mismatched input ':' expecting ')'
myN1qlListener.js:223 every `code` in correlated (select raw (`npky2`.`code`) from `default`^^^`npky` as `npky2` where (((`npky2`.`type`) = "export") and ((`npky2`.`pcrId`) = (`npky`.`id`)))) satisfies (not (`code` = "routine|Billing Export|KOT2L8M7")) end
qw.query.service.js:1705 Exception analyzing query plan: TypeError: Cannot read properties of undefined (reading 'forEach')

QUITE interestingly, this error only seems to occur when executing the following query:

SELECT npky.id AS `ePcr.01m`,
       npky.metaid AS `ePcr.02m`
FROM npky
WHERE npky.type = 'pcr'
    AND  STR_TO_UTC(ansDispatched) BETWEEN STR_TO_UTC('2022-06-07T13:12:16-04:00') AND STR_TO_UTC('2022-06-21T13:12:16-04:00')
        AND ANY a IN npky.answers SATISFIES a.q = 'eDisposition.01' END
        AND npky.ansCallSign IN ['M981', 'M982']
        AND npky.ansStatus = 'closed'
        AND EVERY code IN (
        SELECT RAW npky2.code
        FROM npky npky2
        WHERE `type`='export'
            AND pcrId = npky.id) SATISFIES code <> 'routine|Billing Export|KOT2L8M7' END
        AND npky.ansCallSign NOT LIKE 'Train'
        AND npky.ansSource <> 'import'
        AND EVERY obj IN tags SATISFIES obj.tag <> 'nemsis_invalid' END 
ORDER BY `ansDispatched` DESC
LIMIT 20
OFFSET 0

Other queries do not trigger the above error when I click Plan Text. The query above APPEARS to execute properly, always returning the expected results (when it’s not timing out). So it appears I may have uncovered a bug in the console. Whether it’s related to slow queries, I can only guess. But I’m reporting it here in case it is related.

I will try the debug and post soon.

I don’t know what you mean by: In each thread stack reload2(), Object() should not depend on each other lock and waiting for long time.

Thanks again for the help.

Hi Robert - could you just try

curl http://localhost:8093/query/service -u Administrator:password -d “statement=explain SELECT npky.id AS ePcr.01m, npky.metaid AS ePcr.02m FROM npky WHERE npky.type = ‘pcr’ AND STR_TO_UTC(ansDispatched) BETWEEN STR_TO_UTC(‘2022-06-07T13:12:16-04:00’) AND STR_TO_UTC(‘2022-06-21T13:12:16-04:00’) AND ANY a IN npky.answers SATISFIES a.q = ‘eDisposition.01’ END AND npky.ansCallSign IN [‘M981’, ‘M982’] AND npky.ansStatus = ‘closed’ AND EVERY code IN ( SELECT RAW npky2.code
FROM npky npky2 WHERE type=‘export’ AND pcrId = npky.id) SATISFIES code <> ‘routine|Billing Export|KOT2L8M7’ END AND npky.ansCallSign NOT LIKE ‘Train’ AND npky.ansSource <> ‘import’ AND EVERY obj IN tags SATISFIES obj.tag <> ‘nemsis_invalid’ END
ORDER BY ansDispatched DESC LIMIT 20 OFFSET 0”

You can also use cbq shell

${GOPATH}/bin/cbq -e=clusterhost:8091 -u=Administrator -p=password

Once with in the shell and keep executing query

\set -profile "timings";
SELECT ............;

Also this is correlated subquery, By any chance when it is timemout it using intersectscan (avoid that using index hint). Post the index definitions that used.

returns the following error

> was unexpected at this time.

Apparently, even within quotes, the existence of > anywhere within the statement causes this error.

Tried removing the entire subquery, as this is what causes the error in the console, but I still get the error. Looks like > isn’t supported regardless of where it appears in the statement.

If I modify the query by removing the subquery

SELECT npky.id AS `ePcr.01m`,
       npky.metaid AS `ePcr.02m`
FROM npky
WHERE npky.type = 'pcr'
    AND  STR_TO_UTC(ansDispatched) BETWEEN STR_TO_UTC('2022-06-07T13:12:16-04:00') AND STR_TO_UTC('2022-06-21T13:12:16-04:00')
        AND ANY a IN npky.answers SATISFIES a.q = 'eDisposition.01' END
        AND npky.ansCallSign IN ['M981', 'M982']
        AND npky.ansStatus = 'closed'
        -- subquery removed
        AND npky.ansCallSign NOT LIKE 'Train'
        AND npky.ansSource <> 'import'
        AND EVERY obj IN tags SATISFIES obj.tag <> 'nemsis_invalid' END 
ORDER BY `ansDispatched` DESC
LIMIT 20
OFFSET 0

Then the statement executes in the console and Plan Text can be clicked without error.

The existence of the subquery:

AND EVERY code IN (
        SELECT RAW npky2.code
        FROM npky npky2
        WHERE `type`='export'
            AND pcrId = npky.id
) SATISFIES code <> 'routine|Billing Export|KOT2L8M7' END

seems to be what is causing the console to error. This is apparently a bug, as the statement executes fine with this subquery. Only Plan Text throws the error.

@vsr1 Here’s the debug output. Naturally, I have no idea how to decipher what it says, but maybe it will provide some clues. Thanks again for the help!

debug.zip (16.1 KB)

According to debug.zip this is not MB-51826

console error is bug it might have already fixed later versions.
I would suggest use cbq shell and provide the Timings (strip results).

  1. When query timeout (might have used intersectscans)
  2. when query return quickly (might have used single index)

Want to see what type of plan using (My guess is it might using intersectScans due to complexity of query) and index selection.

cbq timings.zip (4.8 KB)

I’ve attached the cbq output for the bad query. In this case, we executed the query twice. The first time, it ran perfectly. On the very next execution, the EXACT same query times out. The execution plan appears to be identical (as expected) for both executions.

Yes, the query does incur an OrderedIntersectScan, but this appears to have little impact on performance, as the query ok.txt document reveals phaseTimes.run of just 735.341017ms.

Then, the SAME query, run just 1 second later, times out after 2 minutes (we had to manually set the 2 minute timeout, or the process hangs forever). The query hang.txt file reveals phaseTimes.run of 2m0.000330008s (the timeout). All other phases of the query run quickly.

So perhaps the OrderedIntersectScan is the culprit. But if so, shouldn’t the query ALWAYS time out?

The problem here is IntersectScan , It looks like some synchronization lost.
It not ok case no items reached Fetch operator.

It might be bug and required repro identify root cause. You can track via MB-52662
If possible and not sensitive post index definition and sample document (not mandatroy)

idx_pcr_ansDispatched_DESC
idx_pcr_ansSource
idx_answer_q
idx_pcr_ansCallSign_DESC
idx_pcr_ansStatus_DESC

In mean time you can create the following index and specify USE INDEX () hint avoid the issue.

CREATE INDEX ix1 ON npky(ansDispatched DESC, ansStatus, ansCallSign, ansSource);

We have had a number of defects where (ordered) intersect scans will hang waiting for children, so that might be the possible routes.
I do no see any executing query in the stacks collected, so I cannot readily pinpoint an issue, but MB-47253 (et all) looks like a possible candidate.
If you could rerun and collect stats again, I can pinpoint the issue, if not, an upgrade looks like the route to go.

Our index definitions are all quite straightforward:

CREATE INDEX idx_pcr_ansDispatched_DESC ON npky(ansDispatched DESC) WHERE (type = 'pcr')
CREATE INDEX idx_pcr_ansSource ON npky(ansSource) WHERE (type = 'pcr')
CREATE INDEX idx_answer_q ON npky((DISTINCT (ARRAY (a.q) FOR a IN answers END))) WHERE (type = 'pcr')
CREATE INDEX idx_pcr_ansCallSign_DESC ON npky(ansCallSign DESC) WHERE (type = 'pcr')
CREATE INDEX idx_pcr_ansStatus_DESC ON npky(ansStatus DESC) WHERE (`type` = 'pcr')

We can create the new index you suggested, but we cannot fully predict the shape of the queries a user will choose to run (we support ad-hoc queries via a custom search engine we’ve developed). So even if it resolves the primary problem with the query above, other queries of similar shape are highly likely to NOT be covered, and thus we’ll have the same issue. So this is, at best, a stopgap measure.

Here’s an example of a pcr document:

{
  "agency": "agency|EPLJZ94Z",
  "ansCallSign": "TRAINING01",
  "ansDateCreated": "2022-06-22T13:17:53-04:00",
  "ansDispatched": "2022-06-22T13:19:48-04:00",
  "ansIncidentNum": "TESTCREW2",
  "ansSource": "mobile",
  "ansStatus": "deleted",
  "answers": [
    {
      "cids": [
        0
      ],
      "q": "eCrew.01",
      "v": "1054380"
    },
    {
      "aid": "choice|eCrew.03|JO27",
      "cids": [
        0
      ],
      "lbl": "Primary Patient Caregiver",
      "q": "eCrew.03",
      "v": "2403013"
    },
    {
      "cids": [
        0
      ],
      "q": "eCrew.04s",
      "v": "user|2SXOQ3SG"
    },
    {
      "cids": [
        0
      ],
      "q": "eCrew.07s",
      "v": "Michael"
    },
    {
      "cids": [
        0
      ],
      "q": "eCrew.09s",
      "v": "A"
    },
    {
      "q": "ePcr.01m",
      "v": "0JFPDND1G99T"
    },
    {
      "q": "ePcr.03m",
      "v": "abbbde3b074d11fd"
    },
    {
      "lbl": "Open",
      "q": "ePcr.04m",
      "v": "open"
    },
    {
      "lbl": "Mobile",
      "q": "ePcr.13m",
      "v": "mobile"
    },
    {
      "q": "eRecord.01",
      "v": "0JFPDND1G99T"
    },
    {
      "q": "eRecord.02",
      "v": "Saffire Software, Inc."
    },
    {
      "q": "eRecord.03",
      "v": "MetroPCR Mobile"
    },
    {
      "q": "eRecord.04",
      "v": "1.6.9"
    },
    {
      "q": "eResponse.03",
      "v": "TESTCREW2"
    },
    {
      "aid": "choice|eResponse.07|PLU6",
      "lbl": "Ground Transport (ALS Equipped)",
      "q": "eResponse.07",
      "v": "2207015"
    },
    {
      "lbl": "Training01",
      "q": "eResponse.14",
      "v": "TRAINING01"
    },
    {
      "aid": "choice|eResponse.14s|HD06",
      "lbl": "Platoon 1",
      "q": "eResponse.14s",
      "v": "P1"
    },
    {
      "q": "eTimes.03",
      "v": "2022-06-22T13:19:48-04:00"
    }
  ],
  "author": "tech@metropcr.com",
  "changes": [],
  "date_deleted": "2022-06-22T13:28:06-04:00",
  "deleted_reason": "admin",
  "dirty": true,
  "downloaded": false,
  "form": "form|pcr|237",
  "id": "0JFPDND1G99T",
  "metaid": "pcr|abbbde3b074d11fd|2022-06-22T13:17:53-04:00",
  "mobile_id": "abbbde3b074d11fd",
  "tags": [],
  "type": "pcr",
  "uuid": "2ffe5648-d16c-4bab-9006-3bafeb35061c"
}

and here’s an example of an export document:

{
  "type": "export",
  "pcrId": "F2FHL6YW8VOD",
  "date": "2022-06-20T14:28:45-04:00",
  "code": "routine|Billing Export|KOT2L8M7",
  "user": "user|C084TVUS3S"
}

Thanks again for the input. We have a sales meeting this afternoon with the CB team, where we expect to address all of this.

Thanks for info. Will you able to provide info that @Marco_Greco requested

Connect to specific query service and run the query with higher timeout
When you feel it hit issue capture go routine dump on that host (before finished).

curl -u Administrator:password http://localhost:8093/debug/pprof/goroutine?debug=2

:wink: sorry, I meant stacks, not stats!

We now notice that for ANY query that includes a correlated subquery, not only does Plan Text throw errors in the console, but we get very poor performance, seemingly regardless of indexing.

Here’s another example of a very poorly performing query (there are about 20 signature_forms and about 6000 choices:

SELECT a.*, META().id AS metaid,
       (SELECT RAW b.label
         FROM demo b
         WHERE b.type='choice'
        AND b.code = a.code
        )[0] AS _signature_reason_label
FROM demo a
WHERE a.type = 'signature_form'
    AND (archived IS MISSING
        OR archived = NULL
        OR archived = FALSE)

Yields the following results (only available via cbq \set -profile "timings";, as the console throws an error):

 "status": "success",
    "metrics": {
        "elapsedTime": "8.375158915s",
        "executionTime": "8.375057474s",
        "resultCount": 32,
        "resultSize": 52105,
        "serviceLoad": 3
    },
    "profile": {
        "phaseTimes": {
            "authorize": "16.87µs",
            "fetch": "7.911489904s",
            "filter": "3.16878583s",
            "indexScan": "595.341227ms",
            "instantiate": "25.87µs",
            "parse": "2.294214ms",
            "plan": "2.957318ms",
            "run": "8.369754722s"
        },
        "phaseCounts": {
            "fetch": 388200,
            "filter": 86,
            "indexScan": 388214
        },
        "phaseOperators": {
            "authorize": 1,
            "fetch": 33,
            "filter": 33,
            "indexScan": 34
        },
        "requestTime": "2022-06-23T17:25:12.264Z",
        "servicingHost": "172.31.16.198:8091",
        "executionTimings": {
            "#operator": "Authorize",
            "#stats": {
                "#phaseSwitches": 4,
                "execTime": "1.64µs",
                "servTime": "15.23µs"
            },
            "privileges": {
                "List": [
                    {
                        "Target": "default:demo",
                        "Priv": 7,
                        "Props": 0
                    }
                ]
            },
            "~child": {
                "#operator": "Sequence",
                "#stats": {
                    "#phaseSwitches": 2,
                    "execTime": "1.09µs"
                },
                "~children": [
                    {
                        "#operator": "UnionScan",
                        "#stats": {
                            "#itemsIn": 54,
                            "#itemsOut": 40,
                            "#phaseSwitches": 195,
                            "execTime": "28.86µs",
                            "kernTime": "1.024047ms"
                        },
                        "scans": [
                            {
                                "#operator": "IndexScan3",
                                "#stats": {
                                    "#heartbeatYields": 4,
                                    "#itemsOut": 40,
                                    "#phaseSwitches": 165,
                                    "execTime": "53.18µs",
                                    "kernTime": "190.191µs",
                                    "servTime": "709.564µs"
                                },
                                "as": "a",
                                "index": "idx_type",
                                "index_id": "aec17a28a074149b",
                                "index_projection": {
                                    "primary_key": true
                                },
                                "keyspace": "demo",
                                "namespace": "default",
                                "spans": [
                                    {
                                        "exact": true,
                                        "range": [
                                            {
                                                "high": "\"signature_form\"",
                                                "inclusion": 3,
                                                "low": "\"signature_form\""
                                            }
                                        ]
                                    }
                                ],
                                "using": "gsi"
                            },
                            {
                                "#operator": "IndexScan3",
                                "#stats": {
                                    "#heartbeatYields": 1,
                                    "#itemsOut": 14,
                                    "#phaseSwitches": 61,
                                    "execTime": "47.102µs",
                                    "kernTime": "9.08µs",
                                    "servTime": "980.355µs"
                                },
                                "as": "a",
                                "index": "idx_signature_form_archived",
                                "index_id": "f6e08d771c0d0b9e",
                                "index_projection": {
                                    "primary_key": true
                                },
                                "keyspace": "demo",
                                "namespace": "default",
                                "spans": [
                                    {
                                        "exact": true,
                                        "range": [
                                            {
                                                "high": "false",
                                                "inclusion": 3,
                                                "low": "false"
                                            }
                                        ]
                                    }
                                ],
                                "using": "gsi"
                            }
                        ]
                    },
                    {
                        "#operator": "Fetch",
                        "#stats": {
                            "#heartbeatYields": 2,
                            "#itemsIn": 40,
                            "#itemsOut": 40,
                            "#phaseSwitches": 168,
                            "execTime": "83.811µs",
                            "kernTime": "1.017026ms",
                            "servTime": "1.369189ms"
                        },
                        "as": "a",
                        "keyspace": "demo",
                        "namespace": "default"
                    },
                    {
                        "#operator": "Sequence",
                        "#stats": {
                            "#phaseSwitches": 2,
                            "execTime": "340.302µs",
                            "kernTime": "110ns",
                            "state": "running"
                        },
                        "~children": [
                            {
                                "#operator": "Filter",
                                "#stats": {
                                    "#heartbeatYields": 1,
                                    "#itemsIn": 40,
                                    "#itemsOut": 32,
                                    "#phaseSwitches": 148,
                                    "execTime": "1.018596ms",
                                    "kernTime": "1.859422ms"
                                },
                                "condition": "(((`a`.`type`) = \"signature_form\") and ((((`a`.`archived`) is missing) or ((`a`.`archived`) = null)) or ((`a`.`archived`) = false)))"
                            },
                            {
                                "#operator": "InitialProject",
                                "#stats": {
                                    "#itemsIn": 32,
                                    "#itemsOut": 32,
                                    "#phaseSwitches": 102,
                                    "execTime": "8.366478145s",
                                    "kernTime": "1.66075ms"
                                },
                                "result_terms": [
                                    {
                                        "expr": "`a`",
                                        "star": true
                                    },
                                    {
                                        "as": "metaid",
                                        "expr": "(meta(`a`).`id`)"
                                    },
                                    {
                                        "as": "_signature_reason_label",
                                        "expr": "(correlated (select raw (`b`.`label`) from `default`:`demo` as `b` where (((`b`.`type`) = \"choice\") and ((`b`.`code`) = (`a`.`code`))))[0])"
                                    }
                                ]
                            }
                        ]
                    },
                    {
                        "#operator": "Stream",
                        "#stats": {
                            "#itemsIn": 32,
                            "#itemsOut": 32,
                            "#phaseSwitches": 34,
                            "execTime": "1.492897ms"
                        }
                    }
                ]
            },
            "~versions": [
                "7.0.2-N1QL",
                "7.0.2-6703-enterprise"
            ]
        }
    }
}

Notice the initialProject takes 8 seconds despite only 32 in and 32 out.

Index advisor says:

CREATE INDEX idx_type ON `demo`(`type`)
CREATE INDEX idx_signature_form_archived ON `demo`(`archived`) WHERE (`type` = 'signature_form')

and Existing indexes are sufficient

If I remove the subquery, performance returns and I can then click Plan Text in the console:

{
  "#operator": "Authorize",
  "#stats": {
    "#phaseSwitches": 4,
    "execTime": "1.4µs",
    "servTime": "1.117773ms"
  },
  "privileges": {
    "List": [
      {
        "Target": "default:demo",
        "Priv": 7,
        "Props": 0
      }
    ]
  },
  "~child": {
    "#operator": "Sequence",
    "#stats": {
      "#phaseSwitches": 2,
      "execTime": "1.67µs"
    },
    "~children": [
      {
        "#operator": "UnionScan",
        "#stats": {
          "#itemsIn": 54,
          "#itemsOut": 40,
          "#phaseSwitches": 195,
          "execTime": "26.541µs",
          "kernTime": "1.012751ms"
        },
        "scans": [
          {
            "#operator": "IndexScan3",
            "#stats": {
              "#heartbeatYields": 4,
              "#itemsOut": 40,
              "#phaseSwitches": 165,
              "execTime": "41.57µs",
              "kernTime": "69.651µs",
              "servTime": "879.39µs"
            },
            "as": "a",
            "index": "idx_type",
            "index_id": "aec17a28a074149b",
            "index_projection": {
              "primary_key": true
            },
            "keyspace": "demo",
            "namespace": "default",
            "spans": [
              {
                "exact": true,
                "range": [
                  {
                    "high": "\"signature_form\"",
                    "inclusion": 3,
                    "low": "\"signature_form\""
                  }
                ]
              }
            ],
            "using": "gsi",
            "#time_normal": "00:00.000",
            "#time_absolute": 0.00092096
          },
          {
            "#operator": "IndexScan3",
            "#stats": {
              "#heartbeatYields": 1,
              "#itemsOut": 14,
              "#phaseSwitches": 61,
              "execTime": "18.51µs",
              "kernTime": "22.82µs",
              "servTime": "875.83µs"
            },
            "as": "a",
            "index": "idx_signature_form_archived",
            "index_id": "f6e08d771c0d0b9e",
            "index_projection": {
              "primary_key": true
            },
            "keyspace": "demo",
            "namespace": "default",
            "spans": [
              {
                "exact": true,
                "range": [
                  {
                    "high": "false",
                    "inclusion": 3,
                    "low": "false"
                  }
                ]
              }
            ],
            "using": "gsi",
            "#time_normal": "00:00.000",
            "#time_absolute": 0.0008943400000000001
          }
        ],
        "#time_normal": "00:00.000",
        "#time_absolute": 0.000026541
      },
      {
        "#operator": "Fetch",
        "#stats": {
          "#heartbeatYields": 2,
          "#itemsIn": 40,
          "#itemsOut": 40,
          "#phaseSwitches": 168,
          "execTime": "102.641µs",
          "kernTime": "1.181293ms",
          "servTime": "1.590768ms"
        },
        "as": "a",
        "keyspace": "demo",
        "namespace": "default",
        "#time_normal": "00:00.001",
        "#time_absolute": 0.001693409
      },
      {
        "#operator": "Sequence",
        "#stats": {
          "#phaseSwitches": 2,
          "execTime": "276.213µs",
          "kernTime": "70ns",
          "state": "running"
        },
        "~children": [
          {
            "#operator": "Filter",
            "#stats": {
              "#itemsIn": 40,
              "#itemsOut": 32,
              "#phaseSwitches": 148,
              "execTime": "895.71µs",
              "kernTime": "2.296075ms"
            },
            "condition": "(((`a`.`type`) = \"signature_form\") and ((((`a`.`archived`) is missing) or ((`a`.`archived`) = null)) or ((`a`.`archived`) = false)))",
            "#time_normal": "00:00.000",
            "#time_absolute": 0.0008957100000000001
          },
          {
            "#operator": "InitialProject",
            "#stats": {
              "#itemsIn": 32,
              "#itemsOut": 32,
              "#phaseSwitches": 102,
              "execTime": "848.462µs",
              "kernTime": "1.929891ms"
            },
            "result_terms": [
              {
                "expr": "`a`",
                "star": true
              },
              {
                "as": "metaid",
                "expr": "(meta(`a`).`id`)"
              }
            ],
            "#time_normal": "00:00.000",
            "#time_absolute": 0.000848462
          }
        ],
        "#time_normal": "00:00.000",
        "#time_absolute": 0.00027621300000000003
      },
      {
        "#operator": "Stream",
        "#stats": {
          "#itemsIn": 32,
          "#itemsOut": 32,
          "#phaseSwitches": 34,
          "execTime": "729.766µs"
        },
        "#time_normal": "00:00.000",
        "#time_absolute": 0.000729766
      }
    ],
    "#time_normal": "00:00.000",
    "#time_absolute": 0.0000016699999999999999
  },
  "~versions": [
    "7.0.2-N1QL",
    "7.0.2-6703-enterprise"
  ],
  "#time_normal": "00:00.001",
  "#time_absolute": 0.0011191729999999998
}
1 Like

We re-ran the http://localhost:8093/debug/pprof/goroutine?debug=2 this morning, (assuming this is what you were asking for)

debug.zip (23.0 KB)