yugabyte / yugabyte-db

YugabyteDB - the cloud native distributed SQL database for mission-critical applications.
https://www.yugabyte.com
Other
8.93k stars 1.06k forks source link

Panic on executing CQL Query execution #11769

Closed dukedyer closed 2 years ago

dukedyer commented 2 years ago

Jira Link: DB-712

Description

Some older CQL clients could not connect to newer YB backends. In all FAIL instances, the YB cluster seems to have trouble with prepared statements, causing it to abruptly disconnect the client during processing

YB version launch method result
2.4.8 docker *works
2.8.3 docker FAIL
2.8.3 yb-ctl (local) DNF
2.11.1 yb-cloud FAIL
2.11.1 docker FAIL
2.11.2 docker FAIL
2.11.2 local works
2.12.1 docker FAIL
2.12.1 local works
2.13.0 docker *works

Reference internal ZD 2921

ghaskins commented 2 years ago

Thanks Duke,

To be clear: I no longer believe the issue is the older client. It seems to be a problem with certain prepared statements, with certain versions of yugabyte, launched a certain way. The use case attached to ZD 2921 provides more details and concrete examples.

OlegLoginov commented 2 years ago

Small reproducer: (can be run via ycqlsh)

CREATE KEYSPACE ks;

CREATE TABLE ks.tbl (
    provider INT, vault INT, attr INT, hashed INT, ref INT,
    PRIMARY KEY ((provider, vault), attr, hashed)
) WITH transactions = {'enabled': 'true'};

CREATE INDEX ind ON ks.tbl ((provider, hashed), vault, attr);

# wait 3 sec to get the index ready

SELECT vault, attr, ref FROM ks.tbl WHERE provider = :provider AND vault = :vault AND hashed = :hashed;
OlegLoginov commented 2 years ago

Debug call stack:

#0  0x00007f0c6f50f832 in yb::ql::PTBindVar::HashColCmp::operator() (this=0x5606c70ef3e0, v1=0x5606c6e32da8, v2=0x5606c70ee2c8)
    at ../../src/yb/yql/cql/ql/ptree/pt_expr.h:1427
#1  0x00007f0c6f514fee in std::_Rb_tree<yb::ql::PTBindVar*, yb::ql::PTBindVar*, std::_Identity<yb::ql::PTBindVar*>, yb::ql::PTBindVar::HashColCmp, yb::internal::ArenaAllocatorBase<yb::ql::PTBindVar*, yb::internal::ArenaTraits> >::_M_get_insert_unique_pos (this=0x5606c70ef3d8, 
    __k=@0x7f0c33404070: 0x5606c6e32da8) at /usr/include/c++/7/bits/stl_tree.h:2038
#2  0x00007f0c6f51320a in std::_Rb_tree<yb::ql::PTBindVar*, yb::ql::PTBindVar*, std::_Identity<yb::ql::PTBindVar*>, yb::ql::PTBindVar::HashColCmp, yb::internal::ArenaAllocatorBase<yb::ql::PTBindVar*, yb::internal::ArenaTraits> >::_M_insert_unique<yb::ql::PTBindVar* const&> (
    this=0x5606c70ef3d8, __v=@0x7f0c33404070: 0x5606c6e32da8) at /usr/include/c++/7/bits/stl_tree.h:2090
#3  0x00007f0c6f5111a2 in std::set<yb::ql::PTBindVar*, yb::ql::PTBindVar::HashColCmp, yb::internal::ArenaAllocatorBase<yb::ql::PTBindVar*, yb::internal::ArenaTraits> >::insert (this=0x5606c70ef3d8, __x=@0x7f0c33404070: 0x5606c6e32da8) at /usr/include/c++/7/bits/stl_set.h:501
#4  0x00007f0c6f5100ec in yb::ql::PTDmlStmt::AddHashColumnBindVar (this=0x5606c70ef248, bindvar=0x5606c6e32da8)
    at ../../src/yb/yql/cql/ql/ptree/pt_dml.h:377
#5  0x00007f0c6f50afcc in yb::ql::PTBindVar::Analyze (this=0x5606c6e32da8, sem_context=0x5606c67e2fd0)
    at ../../src/yb/yql/cql/ql/ptree/pt_expr.cc:1449
#6  0x00007f0c6fbd8a13 in yb::ql::PTExpr2<(yb::QLValuePB::ValueCase)8, (yb::DataType)6, yb::ql::PTRelationExpr>::Analyze (
    this=0x5606c6e32ef8, sem_context=0x5606c67e2fd0) at ../../src/yb/yql/cql/ql/ptree/pt_expr.h:622
#7  0x00007f0c6fbd9710 in yb::ql::PTExpr2<(yb::QLValuePB::ValueCase)8, (yb::DataType)6, yb::ql::PTLogicExpr>::Analyze (
    this=0x5606c70ee528, sem_context=0x5606c67e2fd0) at ../../src/yb/yql/cql/ql/ptree/pt_expr.h:619
#8  0x00007f0c6fbd9710 in yb::ql::PTExpr2<(yb::QLValuePB::ValueCase)8, (yb::DataType)6, yb::ql::PTLogicExpr>::Analyze (
    this=0x5606c70eeb30, sem_context=0x5606c67e2fd0) at ../../src/yb/yql/cql/ql/ptree/pt_expr.h:619
#9  0x00007f0c6fbd9710 in yb::ql::PTExpr2<(yb::QLValuePB::ValueCase)8, (yb::DataType)6, yb::ql::PTLogicExpr>::Analyze (
    this=0x5606c70ef138, sem_context=0x5606c67e2fd0) at ../../src/yb/yql/cql/ql/ptree/pt_expr.h:619
#10 0x00007f0c6f4b1933 in yb::ql::PTDmlStmt::AnalyzeWhereExpr (this=0x5606c70ef248, sem_context=0x5606c67e2fd0, expr=0x5606c70ef138)
    at ../../src/yb/yql/cql/ql/ptree/pt_dml.cc:274
#11 0x00007f0c6f4b1687 in yb::ql::PTDmlStmt::AnalyzeWhereClause (this=0x5606c70ef248, sem_context=0x5606c67e2fd0)
    at ../../src/yb/yql/cql/ql/ptree/pt_dml.cc:259
#12 0x00007f0c6f4cd025 in yb::ql::PTSelectStmt::Analyze (this=0x5606c70ef248, sem_context=0x5606c67e2fd0)
    at ../../src/yb/yql/cql/ql/ptree/pt_select.cc:459
#13 0x00007f0c6f431dff in yb::ql::ParseTree::Analyze (this=0x5606c70ed680, sem_context=0x5606c67e2fd0)
    at ../../src/yb/yql/cql/ql/ptree/parse_tree.cc:71
#14 0x00007f0c70686943 in yb::ql::Analyzer::Analyze (this=0x5606c55dc0e0, parse_tree=std::unique_ptr<yb::ql::ParseTree> = {...})
    at ../../src/yb/yql/cql/ql/sem/analyzer.cc:38
#15 0x00007f0c708ddaf9 in yb::ql::QLProcessor::Analyze (this=0x5606c55dc000, parse_tree=0x7f0c33404d08)
    at ../../src/yb/yql/cql/ql/ql_processor.cc:186
#16 0x00007f0c708ddda9 in yb::ql::QLProcessor::Prepare (this=0x5606c55dc000, 
    stmt="SELECT vault, attribute, ref FROM attributes WHERE provider = :provider AND vault = :vault AND hashed_value = :hashed_value AND entity = :entity;", parse_tree=0x7f0c33404d08, reparsed=false, mem_tracker=std::shared_ptr<yb::MemTracker> (empty) = {...}, internal=false)
    at ../../src/yb/yql/cql/ql/ql_processor.cc:202
#17 0x00007f0c708e100c in yb::ql::QLProcessor::RunAsync(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, yb::ql::StatementParameters const&, yb::Callback<void (yb::Status const&, std::shared_ptr<yb::ql::ExecutedResult> const&)>, bool) (
    this=0x5606c55dc000, 
    stmt="SELECT vault, attribute, ref FROM attributes WHERE provider = :provider AND vault = :vault AND hashed_value = :hashed_value AND entity = :entity;", params=warning: RTTI symbol not found for class 'yb::ql::CQLMessage::QueryParameters'
..., cb=..., reparsed=false) at ../../src/yb/yql/cql/ql/ql_processor.cc:433
#18 0x00007f0c728caff7 in yb::cqlserver::CQLProcessor::ProcessRequest (this=0x5606c55dc000, req=...)
    at ../../src/yb/yql/cql/cqlserver/cql_processor.cc:430
#19 0x00007f0c728c98b7 in yb::cqlserver::CQLProcessor::ProcessRequest (this=0x5606c55dc000, req=...)
    at ../../src/yb/yql/cql/cqlserver/cql_processor.cc:313
#20 0x00007f0c728c90f9 in yb::cqlserver::CQLProcessor::ProcessCall (this=0x5606c55dc000, call=
    std::shared_ptr<yb::rpc::InboundCall> (use count 3, weak count 2) = {...}) at ../../src/yb/yql/cql/cqlserver/cql_processor.cc:239
#21 0x00007f0c72926592 in yb::cqlserver::CQLServiceImpl::Handle (this=0x5606c52c42d0, 
    inbound_call=std::shared_ptr<yb::rpc::InboundCall> (empty) = {...}) at ../../src/yb/yql/cql/cqlserver/cql_service.cc:201
#22 0x00007f0c6164a486 in yb::rpc::ServicePoolImpl::Handle (this=0x5606c5b41680, 
    incoming=std::shared_ptr<yb::rpc::InboundCall> (empty) = {...}) at ../../src/yb/rpc/service_pool.cc:260
#23 0x00007f0c615795d1 in yb::rpc::InboundCall::InboundCallTask::Run (this=0x5606c6f42840) at ../../src/yb/rpc/inbound_call.cc:218
#24 0x00007f0c6165f8af in yb::rpc::(anonymous namespace)::Worker::Execute (this=0x5606c57529a0) at ../../src/yb/rpc/thread_pool.cc:105
#25 0x00007f0c6166447f in std::__invoke_impl<void, void (yb::rpc::(anonymous namespace)::Worker::*&)(), yb::rpc::(anonymous namespace)::Worker*&> (
    __f=@0x5606c5751560: (void (yb::rpc::(anonymous namespace)::Worker::*)(yb::rpc::(anonymous namespace)::Worker * const)) 0x7f0c6165f82a <yb::rpc::(anonymous namespace)::Worker::Execute()>, __t=@0x5606c5751570: 0x5606c57529a0) at /usr/include/c++/7/bits/invoke.h:73
#26 0x00007f0c6166402c in std::__invoke<void (yb::rpc::(anonymous namespace)::Worker::*&)(), yb::rpc::(anonymous namespace)::Worker*&> (
    __fn=@0x5606c5751560: (void (yb::rpc::(anonymous namespace)::Worker::*)(yb::rpc::(anonymous namespace)::Worker * const)) 0x7f0c6165f82a <yb::rpc::(anonymous namespace)::Worker::Execute()>) at /usr/include/c++/7/bits/invoke.h:95
#27 0x00007f0c61663445 in std::_Bind<void (yb::rpc::(anonymous namespace)::Worker::*(yb::rpc::(anonymous namespace)::Worker*))()>::__call<void, 0>(std::tuple<> &&, std::_Index_tuple<0>) (this=0x5606c5751560, __args=...) at /usr/include/c++/7/functional:467
#28 0x00007f0c616624a3 in std::_Bind<void (yb::rpc::(anonymous namespace)::Worker::*(yb::rpc::(anonymous namespace)::Worker*))()>::operator()<>(void) (this=0x5606c5751560) at /usr/include/c++/7/functional:551
#29 0x00007f0c6166122b in std::_Function_handler<void(), std::_Bind<void (yb::rpc::(anonymous namespace)::Worker::*(yb::rpc::(anonymous namespace)::Worker*))()> >::_M_invoke(const std::_Any_data &) (__functor=...) at /usr/include/c++/7/bits/std_function.h:316
#30 0x00007f0c72436ae8 in std::function<void ()>::operator()() const (this=0x5606c677feb8) at /usr/include/c++/7/bits/std_function.h:706
#31 0x00007f0c60e53062 in yb::Thread::SuperviseThread (arg=0x5606c677fe60) at ../../src/yb/util/thread.cc:771
#32 0x00007f0c70b116db in start_thread (arg=0x7f0c3340d700) at pthread_create.c:463
#33 0x00007f0c5a98861f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
OlegLoginov commented 2 years ago

Crash point:

bool PTDmlStmt::HashColCmp::operator()(const PTBindVar* v1, const PTBindVar* v2) const {
  DCHECK(v1->hash_col() != nullptr) << "bindvar pos " << v1->pos() << " is not a hash column";
  DCHECK(v2->hash_col() != nullptr) << "bindvar pos " << v2->pos() << " is not a hash column";
  return v1->hash_col()->id() < v2->hash_col()->id();    <<<<<< NULL POINTER ACCESS:
                                                         <<<<<<   v2->hash_col() == NULL
}

Error (in DEBUG):

Check failed: v2->hash_col() != nullptr bindvar pos 1 is not a hash column
OlegLoginov commented 2 years ago

NOTE: this is reproduced via a simple CQL statement, but the case makes sense for PREPARED statements only, as the Bind Vars are used for the Prepared statements.

OlegLoginov commented 2 years ago

Root cause of the issue is not trivial.

Before describing this error I would describe the general schema how the YCQL processor works with the Bind Variables.

  1. hash_col_ in PTBindVar. Any Bind Var is presented in the processor by a PTBindVar object. (They are stored as pointers in ParseContext::bind_variables_. But it's not important for the issue.)

Each such object has the fields:

class PTBindVar : public PTExpr {
...
  const ColumnDesc *hash_col() const { return hash_col_; }
...
  PTConstVarInt::SharedPtr user_pos_; // pos used for parsing.
  boost::optional<int64_t> pos_; // pos after parsing is done.
  MCSharedPtr<MCString> name_; // Variable name.
  const ColumnDesc *hash_col_ = nullptr; // Hash column descriptor.

The value hash_col_ is important here, because it's used below for comparison of two PTBindVar. It's set in:

Status PTBindVar::Analyze(SemContext *sem_context) {
...
  hash_col_ = sem_context->hash_col();
  if (hash_col_ != nullptr) {
    sem_context->current_dml_stmt()->AddHashColumnBindVar(this);
  }
  1. Collecting Bind Vars for Hash columns in DML statement object.

    class PTDmlStmt : public PTCollection {
    ...
    void AddHashColumnBindVar(PTBindVar* bindvar) { hash_col_bindvars_.insert(bindvar); }
    ...
    // Compare 2 bind variables for their hash column ids.
    struct HashColCmp {
    bool operator()(const PTBindVar* v1, const PTBindVar* v2) const {
      DCHECK(v1->hash_col() != nullptr) << "bindvar pos " << v1->pos() << " is not a hash column";
      DCHECK(v2->hash_col() != nullptr) << "bindvar pos " << v2->pos() << " is not a hash column";
      return v1->hash_col()->id() < v2->hash_col()->id();
    }
    };
    
    // List of bind variables associated with hash columns ordered by their column ids.
    MCSet<PTBindVar*, HashColCmp> hash_col_bindvars_;

    So, during the statement analyzing the top SELECT statement (PTSelectStmt is derived from PTDmlStmt) is collecting all PTBindVar objects related to the hash columns. Due to the comparator implementation it's important that each PTBindVar has a non-zero value of const ColumnDesc *hash_col_. Parser tree in the case looks like a tree of PT objects: e.g. PTDmlStmt::where_clause_->PTLogicExpr->...->PTLogicExpr->PTRelationExpr->PTBindVar

  2. PTSelectStmt::Analyze The SELECT statement analyze includes several phases. Two of them calls Analyze() for the where_clause_ sub-tree: PTSelectStmt::Analyze -> PTSelectStmt::AnalyzeReferences -> where_clause_->Analyze(...) PTSelectStmt::Analyze -> PTDmlStmt::AnalyzeWhereClause -> PTDmlStmt::AnalyzeWhereExpr(expr=where_clause_) -> expr->Analyze(...) So, for every PTBindVar the method PTBindVar::Analyze() will be called 2 times.

  3. PTSelectStmt::Analyze with a child SELECT SELECT statement procesing can include a child SELECT to a related index. This child statement object is stored in PTSelectStmt::SharedPtr child_select_. So, it's a complete PTSelectStmt instance - a copy of the parent PTSelectStmt object. The copy includes where_clause_ sub-tree as well. So, for the child (index related)we have one more Analyze() round via the chain: PTSelectStmt::Analyze -> PTSelectStmt::SetupScanPath -> child_select_->Analyze(...) Analyze() for the child object does the same as for the parent SELECT. The child object has own hash_col_bindvars_ set.

Finally we have 3 Analyze() rounds - 3 Analyze() calls for every PTBindVar.

  1. For main SELECT: PTSelectStmt::AnalyzeReferences -> where_clause_->Analyze
  2. For the child SELECT: PTSelectStmt::SetupScanPath -> child_select_->Analyze -> where_clause_->Analyze
  3. For main SELECT: PTDmlStmt::AnalyzeWhereClause -> where_clause_->Analyze

Note, that the context for round 1 and 3 - is the same, it's the main table context. But round 2 means child index-table context.

  1. The root cause of the crash. What's going on during the 3 Analyze() rounds in our case: [Round 1 - main table context]:
    Main-PTDmlStmt::hash_col_bindvars_:
    PTBindVar: name='provider' hash_col_=Ok 
    PTBindVar: name='vault' hash_col_=Ok 

    [Round 2 - child index context]:

    Main-PTDmlStmt::hash_col_bindvars_:
    PTBindVar: name='provider' hash_col_=Ok 
    PTBindVar: name='vault' hash_col_= NULL!
    Child-PTDmlStmt::hash_col_bindvars_:
    PTBindVar: name='provider' hash_col_=Ok 
    PTBindVar: name='hashed' hash_col_=Ok 

    In the Index context vault is NOT a hash-column. So setting PTBindVar::hash_col_ into NULL is correct in the child-select (index-related) context:

    Status PTBindVar::Analyze(SemContext *sem_context) {
    ...
    hash_col_ = sem_context->hash_col();   <<<

ROOT CAUSE: Two sets Main-PTDmlStmt::hash_col_bindvars_ and Child-PTDmlStmt::hash_col_bindvars_ have pointers to the same PTBindVar objects. And Analyze() for the child-select breaks internal correctness of Main-PTDmlStmt::hash_col_bindvars_ set.

CRASH point: [Round 3 - main table context]:

Main-PTDmlStmt::hash_col_bindvars_:
  PTBindVar: name='provider' hash_col_=Ok 
  PTBindVar: name='vault' hash_col_= NULL!
Child-PTDmlStmt::hash_col_bindvars_:
  PTBindVar: name='provider' hash_col_=Ok 
  PTBindVar: name='hashed' hash_col_=Ok 

ADD 'provider' into Main-PTDmlStmt::hash_col_bindvars_: 
  PTBindVar: name='provider' hash_col_=Ok 
  COMPARE it with: PTBindVar: name='vault' hash_col_= NULL!
  CRASH on hash_col_->id() as hash_col_ = NULL for 'vault'

Why it's not reproduced in some releases? Because we actually add PTBindVar pointer which is present already in the set. Some std::set implementations do not call the Comparator for: provider.id < vault.id. (they only call: existing-provider.id < new-provider.id + new-provider.id < existing-provider.id) Locally I see a crash with std::set from GCC, and it works for CLANG.

  1. Why do we need this set PTDmlStmt::hash_col_bindvars_? The only reason to collect PTBindVars to get hash_col_indices:
    std::vector<int64_t> PTDmlStmt::hash_col_indices() const {
    std::vector<int64_t> indices;
    indices.reserve(hash_col_bindvars_.size());
    for (const PTBindVar* bindvar : hash_col_bindvars_) {
    indices.emplace_back(bindvar->pos());
    }
    return indices;
    }

    So, we need actually hash_col_->id() for correct storing order + pos_. No more. This hash_col_indices()is used in PreparedResultResponse and PreparedResult to return correct response to the PREPARE CQL request.

OlegLoginov commented 2 years ago

As we see the problem happens because we have the facts:

  1. Main PTDmlStmt and Child PTDmlStmt reference to the same PTBindVar objects. That's why the Round-2 breaks data collected during the Round-1.
  2. Analize() Round-3 reuses broken data collected during the Round-1 (and broken by Round-2).

So, there are many different ways to fix the problem.

  1. We can phisically copy all PT objects for the Child PTDmlStmt. But it's quite big & complex fix.

  2. We can phisically copy only PTBindVar objects for the Child statement. But if we have Child SELECT - we don't actually need Main-PTDmlStmt::hash_col_bindvars_ because we use it from the Child:

    std::vector<int64_t> hash_col_indices() const override {
    return child_select_ ? child_select_->hash_col_indices() : PTDmlStmt::hash_col_indices();
    }
  3. We can just clean Main-PTDmlStmt::hash_col_bindvars_ if we have the Child statement. 1-line fix. Actually it's a workaround to prevent the crash.

Result: no crash, but Child-PTDmlStmt::hash_col_bindvars_ will still incorrect (NULL pointers) after the Round-3.

  1. Let's prevent calls for PTBindVars::Analyze() on Round-3 if we have Child statement. As the calls are not needed, because we called PTBindVars::Analyze() on Round-2 in the target child/Index context.

Result: no crash, Child-PTDmlStmt::hash_col_bindvars_ is correct, but Main-PTDmlStmt::hash_col_bindvars_ is incorrect, but it's not used.

  1. Let's replace the
    MCSet<PTBindVar*, HashColCmp> hash_col_bindvars_;

    by a set of pairs: <hash-col-id, pos>. As we need only these values.

Result: no crash, all hash_col_bindvars_ are correct, because they store values (not pointers).

  1. Prevent setting NULL into PTBindVar::hash_col_ if the value was not NULL. Was:
    Status PTBindVar::Analyze(SemContext *sem_context) {
    ...
    hash_col_ = sem_context->hash_col();
    if (hash_col_ != nullptr) {
    sem_context->current_dml_stmt()->AddHashColumnBindVar(this);
    }

    Fixed:

    Status PTBindVar::Analyze(SemContext *sem_context) {
    ...
    auto hash_col_in_context = sem_context->hash_col();
    if (hash_col_in_context != nullptr) {
    hash_col_ = hash_col_in_context;
    sem_context->current_dml_stmt()->AddHashColumnBindVar(this);
    }

Result: no crash, all hash_col_bindvars_ are correct, because no more NULL pointers in the sets.


Any option prevents the crash. Option 3 (workaround) is the simplest one. I like more option 5 or 6.

OlegLoginov commented 2 years ago

Implemented option 6.