Prepared Statement with Request Plus is returning stale results


#1

The second usage of the prepared statement, with different parameters($varDate and $grpTags) results in stale data. The http POST body to couchbase looks something like…

{“prepared”:"[127.0.0.1:8091]41ec0000-bbbb-46f0-9l8f207",“encoded_plan”:“H4sIAA…AA”,“timeout”:“75000ms”,"$varDate":“2017-10-21T00:00:00”,"$grpTags":[“tag1”],“scan_consistency”:“request_plus”,“creds”:[{“user”:“local:testuser”,“pass”:“passw0rd1”}],“client_context_id”:“5::6”}

Is there any reason that it would not return the most recent results?


#2

I have a had a quick check - and we don’t do anything silly like storing the scan vector in the plan.

Just to clarify - we are saying that a not bound prepared statement returns the latest data at any execution, and a request_plus non prepared request does too, but the combination of prepared and request plus, on the second execution and later does not, correct?


#3

I did not try a “not bound” prepared statement, since I was attempting to get the most recent data. Regarding the second part of your statement/question “…the combination of prepared and request plus, on the second execution and later does not…”, yes, this is what I experienced.
But when I changed the value of the “prepared” property in a third or later request, the most recent data is returned.


#4

I would say that the likelihood is that on the third attempt you got the latest data just because the index was finally updated by the TCP stream.

Could I ask you to explicitly test all for combinations (not bound + adhoc, not bound + non adhoc, request_plus / adhoc, request_plus / non adhoc) 3 or more consecutive times and verify that it’s only request_plus / non adhoc that returns stale data?
Only asking because from what I reviewed in the code, the most likely explanation is just that the DCP stream had not yet managed to update the underlying index.


#5

After testing different combinations, anything adhoc is working as expected.

For Prepared statements…
when I do “not_bounded” I get stale results as expected.
when I do “request_plus” I get stale data like before.
Running a prepared statement “request_plus” repeatedly (6, 7, 8 times, wait 2 minutes run 9, 10, 11 times) returns the same stale result, which I would not expect.
Only after changing the value of “prepared” property do I get fresh results.
I can repeat this same process again and again with the same outcome. What is the purpose of the “prepared” property?


#6

I am not exactly sure about what you mean by changing the value of the “prepared” property, so I have asked around, to no avail.
Our SDKs only have an adhoc property, as far as I know - could you explain what you mean by changing the value of the prepared property, and I’ll look int it?


#7

If you look at the first post in this thread, you’ll find the example request that goes to couchbase. The first property is “prepared”. When I change it’s value (showing “[127.0.0.1:8091]41ec0000-bbbb-46f0-9l8f207” in the example) even by one character, and run the request again, the result is fresh data. This is after several repeated requests, using the same “prepared” value, return stale results.


#8

Gotcha - it’s the prepared REST API parameter that you are referring to not a SDK property.
That’s my territory.
Again I’m slightly perplexed about what you are doing here, as by changing the prepared name, even by 1 character, you are essentially asking for a prepared statement name that may not exist.

Anyway - quick prepared statement primer.
When adhoc is set to false, what the sdk does the first time you execute a statement is

  • pass a ‘{“statement”: “PREPARE “blah” FROM SELECT…”}’ to the N1QL service
  • pass a '{“prepared”: “blah”, “encoded_plan”, … } to the N1QL service

every subsequent time, you only do step two (with different parameters, of course)
On getting the first request, the N1QL service will work out a plan for the request and store it in the request cache.
On every other occasion, provided that SDK has already seen the statement, it will just pick up the plan, instantiate a set of execution operators, and execute it.
Essentially - this mechanism is done to save parsing and planning every time.

What you are doing by changing a character in the prepared is to create a new prepared statement.
The only moment in time in which executing the same plan gives you outdated data is if the plan contains (to simplify things) timing information about the data, which I have verified it doesn’t.
So there has to be something else at play here.

Let’s start with this - could you choose one statement that doesn’t work, and run

select *, meta().plan from system:prepareds where name = “…statement name…”

and post it?
That’ll give me a starting point.


#9

here are the results…

[
  {
    "plan": {
      "#operator": "Sequence",
      "~children": [
        {
          "#operator": "Authorize",
          "privileges": {
            "List": [
              {
                "Priv": 7,
                "Target": "default:test_automation"
              }
            ]
          },
          "~child": {
            "#operator": "Sequence",
            "~children": [
              {
                "#operator": "IndexScan3",
                "as": "rules",
                "index": "idx_doc_type_tenant",
                "index_id": "572184399402932d",
                "index_projection": {
                  "primary_key": true
                },
                "keyspace": "test_automation",
                "namespace": "default",
                "spans": [
                  {
                    "exact": true,
                    "range": [
                      {
                        "high": "\"rule\"",
                        "inclusion": 3,
                        "low": "\"rule\""
                      }
                    ]
                  }
                ],
                "using": "gsi"
              },
              {
                "#operator": "Fetch",
                "as": "rules",
                "keyspace": "test_automation",
                "namespace": "default"
              },
              {
                "#operator": "Parallel",
                "~child": {
                  "#operator": "Sequence",
                  "~children": [
                    {
                      "#operator": "Let",
                      "bindings": [
                        {
                          "expr": "(correlated (select max((`maxRule`.`version`)) as `ver`, `maxRule` as `theRule` from ((`rules`.`ruleVersions`).`__main__`) as `maxRule` let `minApp` = (correlated (select min((`minRule`.`maxDischargeDate`)) as `minDate` from ((`rules`.`ruleVersions`).`__main__`) as `minRule` where ((\"2017-05-21T00:00:00\" <= (`minRule`.`maxDischargeDate`)) and (not ((`minRule`.`state`) in [500, 100, 5000]))))[0]) where ((((`maxRule`.`maxDischargeDate`) = (`minApp`.`minDate`)) and (not ((`maxRule`.`state`) in [500, 100, 5000]))) and (0 < array_length(array_intersect($groupTags, (`maxRule`.`groupTags`)))))  group by `maxRule`)[0])",
                          "var": "maxAppVer"
                        }
                      ]
                    },
                    {
                      "#operator": "Filter",
                      "condition": "((((`rules`.`type`) = \"rule\") and ((`maxAppVer`.`ver`) is not null)) and any `r` in ((`rules`.`ruleVersions`).`__main__`) satisfies (any `gt` in (`r`.`groupTags`) satisfies (`gt` in $groupTags) end and (not ((`r`.`state`) in [500, 100, 5000]))) end)"
                    },
                    {
                      "#operator": "InitialProject",
                      "result_terms": [
                        {
                          "expr": "(`maxAppVer`.`theRule`)"
                        }
                      ]
                    },
                    {
                      "#operator": "FinalProject"
                    }
                  ]
                }
              }
            ]
          }
        },
        {
          "#operator": "Stream"
        }
      ]
    },
    "prepareds": {
      "avgElapsedTime": "5.98995ms",
      "avgServiceTime": "3.50355ms",
      "encoded_plan": "H4sIAAAAAAAA/6RVYW/bNhD9K8StHyRAMZQ4aWcB+WC07hagCALbKDDEhsRIF5mtRGkk5doLvN8+kCJlyenSdAOKBtTx7t57x3t+AuRplWEW1wXlEAEE8IhUNQLfV1yJqpAQhQEwnuFuWrPPKCSrOETjADgtESIIrybZ+cUDnk0e3k7OLseXD2eTFM/PrsYY4tvzd+klZhBAVaOgqhIQPcEvxwMs8M8GeYoQwN/phhWZQA7R/fDStFGbSrC/9K1asC0rMEepS31iUpnrSypyVBBBho+0KVSkUKqYNqoqqdKQA7gTbAvRu8P64Hr9JzA3WotFSvkYAqASIhBNgRKsShABy3ZxVqWx2tcYK+SUKxeNWQYRXL27OP/1cjyZXIYXk/FF1kVrUX3B1OCNnjTVkop9/BX3ECnR4CGAr7iXNU218s8Z6pG4qNUBApA15dLQwB1NVVsqAEF5jubzhuUbiGBliKzAoEmLppt0UX3rhw/rwzqARjKeQwS5ZHAIhhJ9RJVuTtX5aeSnVe+ooEWBBfyv8X1CrckD4xnjuZOl1hEvrYTAgirMiCexwFSRku48Lynpbt4UmIySbbsAie8TKok+JgHp4uab2mB7eBRVSTwvMQIkI/PXLpBM/FESxyVlPI6TtlZXpEBFkpLxaV0n5Jp8FxbjGhbjFlZJdx+YTDd6CT5QhQ5fybg5/jQWW5l826BA4nlvsn55smrCcJxekx9i4BnxeKXIAK1UJkwYJ/dXYRiQc/3fVRiGa9/3/ftw7XeNB+o/b0EsBq3VqKN72rkr8HLnNim07AgVgu7jAnmuNl57YFyhkJgq700uqqZe0lwGpN+h+5xoKj4h5gN52B8HbAhCAFuqX11Jd9O6/oxC79XpHrFCoYAA0opnrLUFMJq4OWqLMSq47bQkDKS2bvtqNWlJtCC8KQrLlfI9SUSi5Xjd25BUMfnIUBLP5OaqTU7EkHr/ort0VMwnaJofJyR+PBvkmf/MEm44U4wWd61tQgACZVOoWKEoh7s90MOtqP9dzfmx4GF90P9OriyUQFqaXJAs5+b3UpuRrQsRfJEVh0MACnf6R+luPrubzmfEri/pwIxsykqsuNnRE2skZig6ql2hS9MDFytOCBk4lX1hI+tSZpe3KAJiA/rca6jTTVPTZNSf+8gNXafYbJdikJiV68EYQGHcs9s+Ol1Zg8nu6SD5VUDaov201if+rVu7ynhNhv7VL6CfoUs3T9AsiXuEvTd4H65dnm1q1X7W9NrKM7I8XZppZZNeatW/P53Pp3/En2a3vy1/99rDze1yNl/M3i8HJuQKH7fMt+xJ6Ap2XuTegws4ci2xdgraWnrGosOWgH26WxR9T3EXtDEIzeqlYS6my5vFx5vZgjgMxlByI4c4kuhdbGNHysYRuklObz8Q8RpVkWdw+CcAAP//WMqSH/gKAAA=",
      "featuresControl": 0,
      "indexApiVersion": 3,
      "lastUse": "2018-11-26 20:01:56.5423003 +0000 GMT",
      "maxElapsedTime": "8.0014ms",
      "maxServiceTime": "4.0015ms",
      "minElapsedTime": "3.9785ms",
      "minServiceTime": "3.0056ms",
      "name": "059d12be-9b69-434b-9ce1-53e0e617c4ed",
      "node": "127.0.0.1:8091",
      "statement": "PREPARE select  maxAppVer.theRule\r\nfrom test_automation rules\r\nlet maxAppVer = \r\n    (select max(maxRule.version) as ver, maxRule as theRule\r\n    from rules.ruleVersions.__main__ as maxRule\r\n    let minApp = \r\n        (select min(minRule.maxDischargeDate) as minDate \r\n        from rules.ruleVersions.__main__ as minRule\r\n        where minRule.maxDischargeDate >= $dischargeDate\r\n        and minRule.state not in [500,100, 5000])[0]\r\n    where maxRule.maxDischargeDate = minApp.minDate\r\n    and maxRule.state not in [500,100, 5000]\r\n    and ARRAY_LENGTH(ARRAY_INTERSECT($groupTags, maxRule.groupTags)) > 0\r\n    group by maxRule \r\n    )[0]\r\nwhere rules.type = \"rule\"\r\nand maxAppVer.ver is not null\r\nand any r in rules.ruleVersions.__main__ SATISFIES  \r\n   (any gt in r.groupTags SATISFIES gt in $groupTags end)\r\n     AND r.state not in [500,100, 5000]\r\n   end",
      "uses": 2
    }
  }
]

#10

Opened MB-32140.


#11

@dsullivan just to let you know that we have internally had some good discussion about MB-32140, and progress is being made…