mysql/stonedb的子查询处理解析耗时分析
  TEZNKK3IfmPf 2023年11月14日 61 0

记录stonedb的子查询处理，并进行耗时分析

核心函数:

ParameterizedFilter::ApplyDescriptor

void ParameterizedFilter::ApplyDescriptor(int desc_number, int64_t limit)
// desc_number = -1 => switch off the rough part
{
  Descriptor &desc = descriptors[desc_number];
  if (desc.op == common::Operator::O_TRUE) {
    desc.done = true;
    return;
  }
  if (desc.op == common::Operator::O_FALSE) {
    mind->Empty();
    desc.done = true;
    return;
  }

  DimensionVector dims(mind->NoDimensions());
  desc.DimensionUsed(dims);
  mind->MarkInvolvedDimGroups(dims);  // create iterators on whole groups (important for
                                      // multidimensional updatable iterators)
  int no_dims = dims.NoDimsUsed();
  if (no_dims == 0 && !desc.IsDeterministic()) dims.SetAll();
  // Check the easy case (one-dim, parallelizable)
  int one_dim = -1;
  common::RSValue *rf = NULL;
  if (no_dims == 1) {
    for (int i = 0; i < mind->NoDimensions(); i++) {
      if (dims[i]) {
        if (mind->GetFilter(i)) one_dim = i;  // exactly one filter (non-join or join with forgotten dims)
        break;
      }
    }
  }
  if (one_dim != -1)
    rf = rough_mind->GetLocalDescFilter(one_dim, desc_number,
                                        true);  // "true" here means that we demand an existing local rough
                                                // filter

  int packs_no = (int)((mind->OrigSize(one_dim) + ((1 << mind->NoPower()) - 1)) >> mind->NoPower());
  int pack_all = rough_mind->NoPacks(one_dim);
  int pack_some = 0;
  for (int b = 0; b < pack_all; b++) {
    if (rough_mind->GetPackStatus(one_dim, b) != common::RSValue::RS_NONE) pack_some++;
  }
  MIUpdatingIterator mit(mind, dims);
  desc.CopyDesCond(mit);
  if (desc.EvaluateOnIndex(mit, limit) == common::ErrorCode::SUCCESS) {
    rccontrol.lock(mind->m_conn->GetThreadID())
        << "EvaluateOnIndex done, desc number " << desc_number << system::unlock;
  } else {
    int poolsize = rceng->query_thread_pool.size();
    if ((stonedb_sysvar_threadpoolsize > 0) && (packs_no / poolsize > 0) && !desc.IsType_Subquery() &&
        !desc.ExsitTmpTable()) {
      int step = 0;
      int task_num = 0;
      /*Partition task slice*/
      if (pack_some <= poolsize) {
        task_num = poolsize;
      } else {
        step = pack_some / poolsize;
        task_num = packs_no / step;
      }
      int mod = packs_no % task_num;
      int num = packs_no / task_num;

      desc.InitParallel(task_num, mit);

      std::vector<MultiIndex> mis;
      mis.reserve(task_num);

      std::vector<MIUpdatingIterator> taskIterator;
      taskIterator.reserve(task_num);

      for (int i = 0; i < task_num; ++i) {
        auto &mi = mis.emplace_back(*mind, true);
        int pstart = ((i == 0) ? 0 : mod + i * num);
        int pend = mod + (i + 1) * num - 1;

        auto &mii = taskIterator.emplace_back(&mi, dims);
        mii.SetTaskNum(task_num);
        mii.SetTaskId(i);
        mii.SetNoPacksToGo(pend);
        mii.RewindToPack(pstart);
      }

      utils::result_set<void> res;
      for (int i = 0; i < task_num; ++i) {
        res.insert(rceng->query_thread_pool.add_task(&ParameterizedFilter::TaskProcessPacks, this, &taskIterator[i],
                                                     current_tx, rf, &dims, desc_number, limit, one_dim));
      }
      res.get_all_with_except();

      if (mind->m_conn->Killed()) throw common::KilledException("catch thread pool Exception: TaskProcessPacks");
      mind->UpdateNoTuples();

    } else {
      common::RSValue cur_roughval;
      uint64_t passed = 0;
      int pack = -1;
      while (mit.IsValid()) {
        if (limit != -1 && rf) {  // rf - not null if there is one dim only
                                  // (otherwise packs make no sense)
          if (passed >= (uint64_t)limit) {
            mit.ResetCurrentPack();
            mit.NextPackrow();
            continue;
          }
          if (mit.PackrowStarted()) {
            if (pack != -1) passed += mit.NoOnesUncommited(pack);
            pack = mit.GetCurPackrow(one_dim);
          }
        }

        if (rf && mit.GetCurPackrow(one_dim) >= 0)
          cur_roughval = rf[mit.GetCurPackrow(one_dim)];
        else
          cur_roughval = common::RSValue::RS_SOME;

        if (cur_roughval == common::RSValue::RS_NONE) {
          mit.ResetCurrentPack();
          mit.NextPackrow();
        } else if (cur_roughval == common::RSValue::RS_ALL) {
          mit.NextPackrow();
        } else {
          // common::RSValue::RS_SOME or common::RSValue::RS_UNKNOWN
          desc.EvaluatePack(mit);
        }
        if (mind->m_conn->Killed()) throw common::KilledException();
      }
      mit.Commit();
    }
  }
  desc.done = true;
  if (one_dim != -1 && mind->GetFilter(one_dim)) {  // update global rough part
    Filter *f = mind->GetFilter(one_dim);
    for (int p = 0; p < rough_mind->NoPacks(one_dim); p++)
      if (f->IsEmpty(p)) {
        rough_mind->SetPackStatus(one_dim, p, common::RSValue::RS_NONE);
      }
  }
  desc.UpdateVCStatistics();
  return;
}

子查询处理：

common::RSValue cur_roughval;
      uint64_t passed = 0;
      int pack = -1;
      while (mit.IsValid()) {
        if (limit != -1 && rf) {  // rf - not null if there is one dim only
                                  // (otherwise packs make no sense)
          if (passed >= (uint64_t)limit) {
            mit.ResetCurrentPack();
            mit.NextPackrow();
            continue;
          }
          if (mit.PackrowStarted()) {
            if (pack != -1) passed += mit.NoOnesUncommited(pack);
            pack = mit.GetCurPackrow(one_dim);
          }
        }

        if (rf && mit.GetCurPackrow(one_dim) >= 0)
          cur_roughval = rf[mit.GetCurPackrow(one_dim)];
        else
          cur_roughval = common::RSValue::RS_SOME;

        if (cur_roughval == common::RSValue::RS_NONE) {
          mit.ResetCurrentPack();
          mit.NextPackrow();
        } else if (cur_roughval == common::RSValue::RS_ALL) {
          mit.NextPackrow();
        } else {
          // common::RSValue::RS_SOME or common::RSValue::RS_UNKNOWN
          desc.EvaluatePack(mit);
        }
        if (mind->m_conn->Killed()) throw common::KilledException();
      }
      mit.Commit();

调用堆栈:

(gdb) bt
#0  stonedb::core::ParameterizedFilter::ApplyDescriptor (this=0x7fa8d404e7a0, desc_number=0, limit=-1)
    at /root/work/stonedb/storage/stonedb/core/parameterized_filter.cpp:1306
#1  0x0000000001d4ef85 in stonedb::core::ParameterizedFilter::UpdateMultiIndex (this=0x7fa8d404e7a0, count_only=false, limit=-1)
    at /root/work/stonedb/storage/stonedb/core/parameterized_filter.cpp:1053
#2  0x00000000019e95e0 in stonedb::core::Query::Preexecute (this=0x7fa8d4027780, qu=..., sender=0x0, display_now=false)
    at /root/work/stonedb/storage/stonedb/core/query.cpp:776
#3  0x0000000001d9172e in stonedb::dbhandler::StonedbHandler::set_cond_iter (this=0x7fa8d4034910)
    at /root/work/stonedb/storage/stonedb/handler/stonedb_handler.cpp:1315
#4  0x0000000001d92482 in stonedb::dbhandler::StonedbHandler::cond_push (this=0x7fa8d4034910, a_cond=0x7fa8d4044f20)
    at /root/work/stonedb/storage/stonedb/handler/stonedb_handler.cpp:1399
#5  0x000000000154590e in make_join_select (join=0x7fa8d4043930, cond=0x7fa8d404b710) at /root/work/stonedb/sql/sql_optimizer.cc:7806
#6  0x0000000001533ae4 in JOIN::optimize (this=0x7fa8d4043930, part=0 '\000') at /root/work/stonedb/sql/sql_optimizer.cc:513
#7  0x00000000014c720c in subselect_single_select_engine::exec (this=0x7fa8d40093a0) at /root/work/stonedb/sql/item_subselect.cc:2747
#8  0x00000000014c07c5 in Item_subselect::exec (this=0x7fa8d404b800) at /root/work/stonedb/sql/item_subselect.cc:642
#9  0x00000000014c26d6 in Item_exists_subselect::val_int (this=0x7fa8d404b800) at /root/work/stonedb/sql/item_subselect.cc:1269
#10 0x000000000125338c in eval_const_cond (cond=0x7fa8d404b800) at /root/work/stonedb/sql/item_func.cc:76
#11 0x0000000001548155 in internal_remove_eq_conds (thd=0x41658a0, cond=0x7fa8d404b800, cond_value=0x7fa90140b6dc, part=1 '\001')
    at /root/work/stonedb/sql/sql_optimizer.cc:8681
#12 0x0000000001547c68 in internal_remove_eq_conds (thd=0x41658a0, cond=0x7fa8d40089e0, cond_value=0x4167e38, part=1 '\001')
    at /root/work/stonedb/sql/sql_optimizer.cc:8552
#13 0x0000000001548516 in remove_eq_conds (thd=0x41658a0, cond=0x7fa8d40089e0, cond_value=0x4167e38, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:8774
#14 0x00000000015479da in optimize_cond (thd=0x41658a0, conds=0x7fa8d40089e0, cond_equal=0x7fa8d404c008, join_list=0x4167ee8, build_equalities=true, 
    cond_value=0x4167e38, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:8507
#15 0x00000000015329cf in JOIN::optimize (this=0x7fa8d404bca0, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:246
#16 0x00000000019b7c3e in stonedb::core::optimize_select (thd=0x41658a0, tables=0x7fa8d4007ac0, wild_num=0, fields=..., conds=0x7fa8d40089e0, og_num=2, 
    order=0x7fa8d404bb80, group=0x7fa8d404ba20, having=0x0, select_options=2147748608, result=0x7fa8d404bc68, unit=0x4167720, select_lex=0x4167d68, 
    optimize_after_sdb=@0x7fa90140c094: 1, free_join=@0x7fa90140c098: 1) at /root/work/stonedb/storage/stonedb/core/engine_execute.cpp:339
#17 0x00000000019b7588 in stonedb::core::Engine::HandleSelect (this=0x41b1150, thd=0x41658a0, lex=0x4167660, result=@0x7fa90140c0a0: 0x7fa8d404bc68, 
    setup_tables_done_option=0, res=@0x7fa90140c09c: 0, optimize_after_sdb=@0x7fa90140c094: 1, sdb_free_join=@0x7fa90140c098: 1, with_insert=0)
    at /root/work/stonedb/storage/stonedb/core/engine_execute.cpp:223
#18 0x0000000001aacee3 in stonedb::dbhandler::SDB_HandleSelect (thd=0x41658a0, lex=0x4167660, result=@0x7fa90140c0a0: 0x7fa8d404bc68, setup_tables_done_option=0, 
    res=@0x7fa90140c09c: 0, optimize_after_sdb=@0x7fa90140c094: 1, sdb_free_join=@0x7fa90140c098: 1, with_insert=0)
    at /root/work/stonedb/storage/stonedb/handler/ha_rcengine.cpp:82
#19 0x000000000137b090 in execute_sqlcom_select (thd=0x41658a0, all_tables=0x7fa8d4007ac0)
#20 0x0000000001373ea1 in mysql_execute_command (thd=0x41658a0)
#21 0x000000000137daec in mysql_parse (thd=0x41658a0, 
    rawbuf=0x7fa8d40073f0 "select\n    o_carrier_id,\n    count(*) as order_count\nfrom\n    orders\nwhere\n    o_entry_d >= date '1993-07-01'\n    and o_entry_d < date '2022-07-06' + interval '3' month\n    and exists (\n        select"..., length=374, parser_state=0x7fa90140d170)
#22 0x000000000137109d in dispatch_command (command=COM_QUERY, thd=0x41658a0, 
    packet=0x4168bf1 "select\n    o_carrier_id,\n    count(*) as order_count\nfrom\n    orders\nwhere\n    o_entry_d >= date '1993-07-01'\n    and o_entry_d < date '2022-07-06' + interval '3' month\n    and exists (\n        select"..., packet_length=374)
#23 0x00000000013701d7 in do_command (thd=0x41658a0)
#24 0x000000000133be43 in do_handle_one_connection (thd_arg=0x41658a0) at /root/work/stonedb/sql/sql_connect.cc:982
#25 0x000000000133b9a6 in handle_one_connection (arg=0x41658a0) at /root/work/stonedb/sql/sql_connect.cc:898
#26 0x00000000019530a2 in pfs_spawn_thread (arg=0x4842510) at /root/work/stonedb/storage/perfschema/pfs.cc:1860
#27 0x00007faa73470ea5 in start_thread () from /lib64/libpthread.so.0
#28 0x00007faa71f7cb0d in clone () from /lib64/libc.so.6

Descriptor::EvaluatePackImpl

void Descriptor::EvaluatePackImpl(MIUpdatingIterator &mit) {
  MEASURE_FET("Descriptor::EvaluatePackImpl(...)");

  std::chrono::high_resolution_clock::time_point start = std::chrono::high_resolution_clock::now();

  // Check if we can delegate evaluation of descriptor to physical column
  if (encoded)
    attr.vc->EvaluatePack(mit, *this);
  else if (IsType_OrTree() && (GetParallelSize() == 0)) {
    // single thread Prepare rough values to be stored inside the tree
    tree->root->ClearRoughValues();
    tree->root->EvaluateRoughlyPack(mit);

    std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

    tree->root->EvaluatePack(mit);

    auto __diff =
        std::chrono::duration_cast<std::chrono::duration<float>>(std::chrono::high_resolution_clock::now() - __start);
    STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(), 
        " __SUBQUERY EvaluatePackImpl tree->root->EvaluatePack (IsType_OrTree() && (GetParallelSize() == 0))");

  } else if (IsType_OrTree() && GetParallelSize()) {
    // muti thread for IsType_OrTree; single reserved
    tree->root->MClearRoughValues(mit.GetTaskId());
    tree->root->MEvaluateRoughlyPack(mit, mit.GetTaskId());

    std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

    tree->root->MEvaluatePack(mit, mit.GetTaskId());
  
    auto __diff =
        std::chrono::duration_cast<std::chrono::duration<float>>(std::chrono::high_resolution_clock::now() - __start);
    STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(),
                " __SUBQUERY EvaluatePackImpl tree->root->MEvaluatePack (IsType_OrTree() && (GetParallelSize()))");
  
  } else if (types::RequiresUTFConversions(collation)) {

    std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

    std::scoped_lock guard(mtx);
    while (mit.IsValid()) {
      if (CheckCondition_UTF(mit) == false) mit.ResetCurrent();
      ++mit;
      if (mit.PackrowStarted()) break;
    }

    auto __diff =
        std::chrono::duration_cast<std::chrono::duration<float>>(std::chrono::high_resolution_clock::now() - __start);
    STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(),
                " __SUBQUERY EvaluatePackImpl types::RequiresUTFConversions(collation)");

  } else {
    if (IsType_Subquery() && op != common::Operator::O_OR_TREE) {
      // pack based optimization of corr. subq. by using RoughQuery
      common::Tribool res = RoughCheckSubselectCondition(mit, SubSelectOptimizationType::PACK_BASED);
      if (res == false)
        mit.ResetCurrentPack();
      else if (res == common::TRIBOOL_UNKNOWN) {
        // int true_c = 0, false_c = 0, unkn_c = 0;

        std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

        while (mit.IsValid()) {
          // row based optimization of corr. subq. by using RoughQuery
          res = RoughCheckSubselectCondition(mit, SubSelectOptimizationType::ROW_BASED);
          // if(res == false)
          //  false_c++;
          // else if(res == true)
          //  true_c++;
          // else
          //  unkn_c++;
          if (res == false)
            mit.ResetCurrent();
          else if (res == common::TRIBOOL_UNKNOWN && CheckCondition(mit) == false)
            mit.ResetCurrent();
          ++mit;
          if (mit.PackrowStarted()) break;
        }
        // cout << "# of skipped subqueries: " << true_c << "/" << false_c <<
        // "/" << unkn_c
        // << " -> " << (true_c + false_c) << " / " << (true_c + false_c +
        // unkn_c) << endl;

        auto __diff = std::chrono::duration_cast<std::chrono::duration<float>>(
            std::chrono::high_resolution_clock::now() - __start);
        STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(), 
            " __SUBQUERY EvaluatePackImpl res == common::TRIBOOL_UNKNOWN");

      }
    } else {

      std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

      std::scoped_lock guard(mtx);

      int index = 0;
      auto check_cast = std::chrono::duration<float> (0);
      auto reset_cast = std::chrono::duration<float>(0);
      while (mit.IsValid()) {

        index++;
     
        std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();
        
        bool cond = CheckCondition(mit);

        {
          auto __diff = std::chrono::duration_cast<std::chrono::duration<float>>(
              std::chrono::high_resolution_clock::now() - __start);
          // STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(), " __SUBQUERY EvaluatePackImpl CheckCondition");

          check_cast += __diff;
        }

        if (cond == false) {

          std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

          mit.ResetCurrent();

          auto __diff = std::chrono::duration_cast<std::chrono::duration<float>>(
              std::chrono::high_resolution_clock::now() - __start);
          // STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(), " __SUBQUERY EvaluatePackImpl mit.ResetCurrent");

          reset_cast += __diff;

        };

        ++mit;
        if (mit.PackrowStarted()) break;
      }

      auto __diff =
          std::chrono::duration_cast<std::chrono::duration<float>>(std::chrono::high_resolution_clock::now() - __start);
      STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s, index: %d, check_cast: %f, reset_cast: %f", __diff.count(),
                  " __SUBQUERY EvaluatePackImpl else else", index, check_cast.count(), reset_cast.count());

    }
  }

  auto diff =
      std::chrono::duration_cast<std::chrono::duration<float>>(std::chrono::high_resolution_clock::now() - start);
  STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", diff.count(), " __SUBQUERY EvaluatePackImpl");
}

调用堆栈:

(gdb) b descriptor.cpp:905
Breakpoint 1 at 0x1ce865a: file /root/work/stonedb/storage/stonedb/core/descriptor.cpp, line 905.
(gdb) c
Continuing.
[Switching to Thread 0x7f87d81c2700 (LWP 105980)]

Breakpoint 1, stonedb::core::Descriptor::EvaluatePackImpl (this=0x7f866405baa0, mit=...) at /root/work/stonedb/storage/stonedb/core/descriptor.cpp:905
warning: Source file is more recent than executable.
905            bool cond = CheckCondition(mit);
(gdb) bt
#0  stonedb::core::Descriptor::EvaluatePackImpl (this=0x7f866405baa0, mit=...) at /root/work/stonedb/storage/stonedb/core/descriptor.cpp:905
#1  0x0000000001cf2891 in stonedb::core::DescTreeNode::EvaluatePack (this=0x7f866405ba80, mit=...) at /root/work/stonedb/storage/stonedb/core/descriptor.cpp:2379
#2  0x0000000001cf261d in stonedb::core::DescTreeNode::EvaluatePack (this=0x7f86640596a0, mit=...) at /root/work/stonedb/storage/stonedb/core/descriptor.cpp:2330
#3  0x0000000001ce80b9 in stonedb::core::Descriptor::EvaluatePackImpl (this=0x7f8664059b20, mit=...) at /root/work/stonedb/storage/stonedb/core/descriptor.cpp:815
#4  0x0000000001ce8954 in stonedb::core::Descriptor::EvaluatePack (this=0x7f8664059b20, mit=...) at /root/work/stonedb/storage/stonedb/core/descriptor.cpp:952
#5  0x0000000001d516ff in stonedb::core::ParameterizedFilter::ApplyDescriptor (this=0x7f86640556e0, desc_number=0, limit=-1)
    at /root/work/stonedb/storage/stonedb/core/parameterized_filter.cpp:1338
#6  0x0000000001d4fd37 in stonedb::core::ParameterizedFilter::UpdateMultiIndex (this=0x7f86640556e0, count_only=false, limit=-1)
    at /root/work/stonedb/storage/stonedb/core/parameterized_filter.cpp:1053
#7  0x00000000019e9630 in stonedb::core::Query::Preexecute (this=0x7f866405eb20, qu=..., sender=0x0, display_now=false) at /root/work/stonedb/storage/stonedb/core/query.cpp:776
#8  0x0000000001d92600 in stonedb::dbhandler::StonedbHandler::set_cond_iter (this=0x7f866402b910) at /root/work/stonedb/storage/stonedb/handler/stonedb_handler.cpp:1315
#9  0x0000000001d93354 in stonedb::dbhandler::StonedbHandler::cond_push (this=0x7f866402b910, a_cond=0x7f8664058010) at /root/work/stonedb/storage/stonedb/handler/stonedb_handler.cpp:1399
#10 0x000000000154595e in make_join_select (join=0x7f8664056a20, cond=0x7f8664051ab0) at /root/work/stonedb/sql/sql_optimizer.cc:7806
#11 0x0000000001533b34 in JOIN::optimize (this=0x7f8664056a20, part=0 '\000') at /root/work/stonedb/sql/sql_optimizer.cc:513
#12 0x00000000014c725c in subselect_single_select_engine::exec (this=0x7f8664008b90) at /root/work/stonedb/sql/item_subselect.cc:2747
#13 0x00000000014c0815 in Item_subselect::exec (this=0x7f8664051ba0) at /root/work/stonedb/sql/item_subselect.cc:642
#14 0x00000000014c2726 in Item_exists_subselect::val_int (this=0x7f8664051ba0) at /root/work/stonedb/sql/item_subselect.cc:1269
#15 0x00000000012533dc in eval_const_cond (cond=0x7f8664051ba0) at /root/work/stonedb/sql/item_func.cc:76
#16 0x00000000015481a5 in internal_remove_eq_conds (thd=0x4fa60e0, cond=0x7f8664051ba0, cond_value=0x7f87d81bf6dc, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:8681
#17 0x0000000001547cb8 in internal_remove_eq_conds (thd=0x4fa60e0, cond=0x7f86640081d0, cond_value=0x4fa8678, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:8552
#18 0x0000000001548566 in remove_eq_conds (thd=0x4fa60e0, cond=0x7f86640081d0, cond_value=0x4fa8678, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:8774
#19 0x0000000001547a2a in optimize_cond (thd=0x4fa60e0, conds=0x7f86640081d0, cond_equal=0x7f86640523a8, join_list=0x4fa8728, build_equalities=true, cond_value=0x4fa8678, part=1 '\001')
    at /root/work/stonedb/sql/sql_optimizer.cc:8507
#20 0x0000000001532a1f in JOIN::optimize (this=0x7f8664052040, part=1 '\001') at /root/work/stonedb/sql/sql_optimizer.cc:246
#21 0x00000000019b7c8e in stonedb::core::optimize_select (thd=0x4fa60e0, tables=0x7f86640072b0, wild_num=0, fields=..., conds=0x7f86640081d0, og_num=2, order=0x7f8664051f20, group=0x7f8664051dc0, 
    having=0x0, select_options=2147748608, result=0x7f8664052008, unit=0x4fa7f60, select_lex=0x4fa85a8, optimize_after_sdb=@0x7f87d81c0094: 1, free_join=@0x7f87d81c0098: 1)
    at /root/work/stonedb/storage/stonedb/core/engine_execute.cpp:339
#22 0x00000000019b75d8 in stonedb::core::Engine::HandleSelect (this=0x4fed590, thd=0x4fa60e0, lex=0x4fa7ea0, result=@0x7f87d81c00a0: 0x7f8664052008, setup_tables_done_option=0, 
    res=@0x7f87d81c009c: 0, optimize_after_sdb=@0x7f87d81c0094: 1, sdb_free_join=@0x7f87d81c0098: 1, with_insert=0) at /root/work/stonedb/storage/stonedb/core/engine_execute.cpp:223
#23 0x0000000001aacf33 in stonedb::dbhandler::SDB_HandleSelect (thd=0x4fa60e0, lex=0x4fa7ea0, result=@0x7f87d81c00a0: 0x7f8664052008, setup_tables_done_option=0, res=@0x7f87d81c009c: 0, 
    optimize_after_sdb=@0x7f87d81c0094: 1, sdb_free_join=@0x7f87d81c0098: 1, with_insert=0) at /root/work/stonedb/storage/stonedb/handler/ha_rcengine.cpp:82
#24 0x000000000137b0e0 in execute_sqlcom_select (thd=0x4fa60e0, all_tables=0x7f86640072b0)
#25 0x0000000001373ef1 in mysql_execute_command (thd=0x4fa60e0)
#26 0x000000000137db3c in mysql_parse (thd=0x4fa60e0, 
    rawbuf=0x7f8664006be0 "select\n    o_carrier_id,\n    count(*) as order_count\nfrom\n    orders\nwhere\n    o_entry_d >= date '1993-07-01'\n    and o_entry_d < date '2022-07-06' + interval '3' month\n    and exists (\n        select"..., length=374, parser_state=0x7f87d81c1170)
#27 0x00000000013710ed in dispatch_command (command=COM_QUERY, thd=0x4fa60e0, 
    packet=0x4fa9431 "select\n    o_carrier_id,\n    count(*) as order_count\nfrom\n    orders\nwhere\n    o_entry_d >= date '1993-07-01'\n    and o_entry_d < date '2022-07-06' + interval '3' month\n    and exists (\n        select"..., packet_length=374)
#28 0x0000000001370227 in do_command (thd=0x4fa60e0)
#29 0x000000000133be93 in do_handle_one_connection (thd_arg=0x4fa60e0) at /root/work/stonedb/sql/sql_connect.cc:982
#30 0x000000000133b9f6 in handle_one_connection (arg=0x4fa60e0) at /root/work/stonedb/sql/sql_connect.cc:898
#31 0x00000000019530f2 in pfs_spawn_thread (arg=0x5855540) at /root/work/stonedb/storage/perfschema/pfs.cc:1860
#32 0x00007f87f8e74ea5 in start_thread () from /lib64/libpthread.so.0
#33 0x00007f87f7980b0d in clone () from /lib64/libc.so.6

执行耗时记录:

执行耗时统计方式:

  1. 采用函数调用分步骤埋点方式

记录：

[2022-07-05 03:10:07.095797] [105980] [INFO] [descriptor.cpp:850] MSG: Timer 0.018859 :  __SUBQUERY EvaluatePackImpl types::RequiresUTFConversions(collation)
[2022-07-05 03:10:07.095853] [105980] [INFO] [descriptor.cpp:943] MSG: Timer 0.018944 :  __SUBQUERY EvaluatePackImpl
[2022-07-05 03:10:07.095860] [105980] [INFO] [descriptor.cpp:2383] MSG: Timer 0.036352 :  __SUBQUERY DescTreeNode::EvaluatePack right
[2022-07-05 03:10:07.095864] [105980] [INFO] [descriptor.cpp:2389] MSG: Timer 0.036357 :  __SUBQUERY DescTreeNode::EvaluatePack over
[2022-07-05 03:10:07.095868] [105980] [INFO] [descriptor.cpp:2310] MSG: Timer 0.036366 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , left->EvaluatePack(mit)
[2022-07-05 03:10:07.095896] [105980] [INFO] [descriptor.cpp:2326] MSG: Timer 0.000001 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , mit.RewindToPack(pack_start)
[2022-07-05 03:10:07.206936] [105980] [INFO] [descriptor.cpp:936] MSG: Timer 0.106215 :  __SUBQUERY EvaluatePackImpl else else, index: 65536, check_cast: 0.099810, reset_cast: 0.000011
[2022-07-05 03:10:07.206991] [105980] [INFO] [descriptor.cpp:943] MSG: Timer 0.106300 :  __SUBQUERY EvaluatePackImpl
[2022-07-05 03:10:07.206998] [105980] [INFO] [descriptor.cpp:2383] MSG: Timer 0.111075 :  __SUBQUERY DescTreeNode::EvaluatePack right
[2022-07-05 03:10:07.207002] [105980] [INFO] [descriptor.cpp:2389] MSG: Timer 0.111080 :  __SUBQUERY DescTreeNode::EvaluatePack over
[2022-07-05 03:10:07.207006] [105980] [INFO] [descriptor.cpp:2337] MSG: Timer 0.111084 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , right->EvaluatePack(mit)
[2022-07-05 03:10:07.207019] [105980] [INFO] [descriptor.cpp:2348] MSG: Timer 0.000003 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , mit.OrPackFilter(pack_start, f.get());
[2022-07-05 03:10:07.207023] [105980] [INFO] [descriptor.cpp:2358] MSG: Timer 0.000008 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else 
[2022-07-05 03:10:07.207039] [105980] [INFO] [descriptor.cpp:2367] MSG: Timer 0.147537 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND
[2022-07-05 03:10:07.207044] [105980] [INFO] [descriptor.cpp:820] MSG: Timer 0.147542 :  __SUBQUERY EvaluatePackImpl tree->root->EvaluatePack (IsType_OrTree() && (GetParallelSize() == 0))
[2022-07-05 03:10:07.207048] [105980] [INFO] [descriptor.cpp:943] MSG: Timer 0.147546 :  __SUBQUERY EvaluatePackImpl
[2022-07-05 03:10:07.207053] [105980] [INFO] [parameterized_filter.cpp:1344] MSG: Timer 0.147552 :  __SUBQUERY  index: 0
[2022-07-05 03:10:07.219262] [105980] [INFO] [descriptor.cpp:850] MSG: Timer 0.009720 :  __SUBQUERY EvaluatePackImpl types::RequiresUTFConversions(collation)
[2022-07-05 03:10:07.219295] [105980] [INFO] [descriptor.cpp:943] MSG: Timer 0.009760 :  __SUBQUERY EvaluatePackImpl
[2022-07-05 03:10:07.219302] [105980] [INFO] [descriptor.cpp:2383] MSG: Timer 0.012232 :  __SUBQUERY DescTreeNode::EvaluatePack right
[2022-07-05 03:10:07.219306] [105980] [INFO] [descriptor.cpp:2389] MSG: Timer 0.012237 :  __SUBQUERY DescTreeNode::EvaluatePack over
[2022-07-05 03:10:07.219310] [105980] [INFO] [descriptor.cpp:2310] MSG: Timer 0.012246 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , left->EvaluatePack(mit)
[2022-07-05 03:10:07.219317] [105980] [INFO] [descriptor.cpp:2326] MSG: Timer 0.000001 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , mit.RewindToPack(pack_start)
[2022-07-05 03:10:07.274538] [105980] [INFO] [descriptor.cpp:936] MSG: Timer 0.055097 :  __SUBQUERY EvaluatePackImpl else else, index: 34464, check_cast: 0.052307, reset_cast: 0.000000
[2022-07-05 03:10:07.274572] [105980] [INFO] [descriptor.cpp:943] MSG: Timer 0.055140 :  __SUBQUERY EvaluatePackImpl
[2022-07-05 03:10:07.274579] [105980] [INFO] [descriptor.cpp:2383] MSG: Timer 0.055257 :  __SUBQUERY DescTreeNode::EvaluatePack right
[2022-07-05 03:10:07.274582] [105980] [INFO] [descriptor.cpp:2389] MSG: Timer 0.055261 :  __SUBQUERY DescTreeNode::EvaluatePack over
[2022-07-05 03:10:07.274586] [105980] [INFO] [descriptor.cpp:2337] MSG: Timer 0.055265 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , right->EvaluatePack(mit)
[2022-07-05 03:10:07.274591] [105980] [INFO] [descriptor.cpp:2348] MSG: Timer 0.000001 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else , mit.OrPackFilter(pack_start, f.get());
[2022-07-05 03:10:07.274595] [105980] [INFO] [descriptor.cpp:2358] MSG: Timer 0.000005 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND,  else 
[2022-07-05 03:10:07.274602] [105980] [INFO] [descriptor.cpp:2367] MSG: Timer 0.067539 :  __SUBQUERY DescTreeNode::EvaluatePack left desc.lop != common::LogicalOperator::O_AND
[2022-07-05 03:10:07.274606] [105980] [INFO] [descriptor.cpp:820] MSG: Timer 0.067543 :  __SUBQUERY EvaluatePackImpl tree->root->EvaluatePack (IsType_OrTree() && (GetParallelSize() == 0))
[2022-07-05 03:10:07.274610] [105980] [INFO] [descriptor.cpp:943] MSG: Timer 0.067551 :  __SUBQUERY EvaluatePackImpl
[2022-07-05 03:10:07.274614] [105980] [INFO] [parameterized_filter.cpp:1344] MSG: Timer 0.215113 :  __SUBQUERY  index: 1
[2022-07-05 03:10:07.274618] [105980] [INFO] [parameterized_filter.cpp:1352] MSG: Timer 0.215117 :  __SUBQUERY over

过于耗时的点:

过于耗时日志:

[2022-07-05 03:10:07.206936] [105980] [INFO] [descriptor.cpp:936] MSG: Timer 0.106215 :  __SUBQUERY EvaluatePackImpl else else, index: 65536, check_cast: 0.099810, reset_cast: 0.000011
[2022-07-05 03:10:07.274538] [105980] [INFO] [descriptor.cpp:936] MSG: Timer 0.055097 :  __SUBQUERY EvaluatePackImpl else else, index: 34464, check_cast: 0.052307, reset_cast: 0.000000

过于耗时的代码:

std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

      std::scoped_lock guard(mtx);

      int index = 0;
      auto check_cast = std::chrono::duration<float> (0);
      auto reset_cast = std::chrono::duration<float>(0);
      while (mit.IsValid()) {

        index++;
     
        std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();
        
        bool cond = CheckCondition(mit);

        {
          auto __diff = std::chrono::duration_cast<std::chrono::duration<float>>(
              std::chrono::high_resolution_clock::now() - __start);
          // STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(), " __SUBQUERY EvaluatePackImpl CheckCondition");

          check_cast += __diff;
        }

        if (cond == false) {

          std::chrono::high_resolution_clock::time_point __start = std::chrono::high_resolution_clock::now();

          mit.ResetCurrent();

          auto __diff = std::chrono::duration_cast<std::chrono::duration<float>>(
              std::chrono::high_resolution_clock::now() - __start);
          // STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s", __diff.count(), " __SUBQUERY EvaluatePackImpl mit.ResetCurrent");

          reset_cast += __diff;

        };

        ++mit;
        if (mit.PackrowStarted()) break;
      }

      auto __diff =
          std::chrono::duration_cast<std::chrono::duration<float>>(std::chrono::high_resolution_clock::now() - __start);
      STONEDB_LOG(LogCtl_Level::INFO, "Timer %f : %s, index: %d, check_cast: %f, reset_cast: %f", __diff.count(),
                  " __SUBQUERY EvaluatePackImpl else else", index, check_cast.count(), reset_cast.count());

耗时原因分析:

一. 遍历mit逐个校验是否需要重置, 校验的次数过大

以子查询为例:

  1. 总共需要执行65536次
  2. 每次校验耗时 0.000002秒
  3. 一共耗时 65536 * 0.000002 = 0.131秒

优化子查询耗时:

方案一: 重新设计子查询流程中的逐个遍历校验mit是否要重置的处理

【版权声明】本文内容来自摩杜云社区用户原创、第三方投稿、转载，内容版权归原作者所有。本网站的目的在于传递更多信息，不拥有版权，亦不承担相应法律责任。如果您发现本社区中有涉嫌抄袭的内容，欢迎发送邮件进行举报，并提供相关证据，一经查实，本社区将立刻删除涉嫌侵权内容，举报邮箱： cloudbbs@moduyun.com
  1. 分享：
最后一次编辑于 2023年11月14日 0

暂无评论

推荐阅读
  TEZNKK3IfmPf   2024年05月31日   37   0   0 数据库mysql
  TEZNKK3IfmPf   2024年05月31日   35   0   0 数据库mysql索引
  TEZNKK3IfmPf   2024年05月17日   33   0   0 mysql
  TEZNKK3IfmPf   2024年04月26日   40   0   0 数据库sqlmysql
  TEZNKK3IfmPf   2024年05月31日   27   0   0 mysql
  TEZNKK3IfmPf   2024年05月31日   31   0   0 idmysql
  TEZNKK3IfmPf   2024年04月26日   40   0   0 数据库mysql慢查询
  TEZNKK3IfmPf   23天前   27   0   0 mysql
  TEZNKK3IfmPf   2024年05月17日   54   0   0 sqlmysql
  TEZNKK3IfmPf   2024年05月31日   31   0   0 数据库mysql
  TEZNKK3IfmPf   2024年05月17日   49   0   0 查询mysql索引
  TEZNKK3IfmPf   2024年05月17日   49   0   0 数据库sqlmysql
  TEZNKK3IfmPf   23天前   30   0   0 mysql
  TEZNKK3IfmPf   2024年05月17日   47   0   0 数据库mysql
  TEZNKK3IfmPf   23天前   38   0   0 linux数据库mysql
  TEZNKK3IfmPf   2024年05月17日   50   0   0 jsonmysql
  TEZNKK3IfmPf   2024年05月17日   50   0   0 mysqlphp
  TEZNKK3IfmPf   2024年05月17日   42   0   0 mysql
  TEZNKK3IfmPf   2024年05月31日   27   0   0 数据库mysql
  TEZNKK3IfmPf   2024年05月17日   66   0   0 数据库mysql
TEZNKK3IfmPf
TEZNKK3IfmPf
作者其他文章 更多
使用代码获得所有适用于创建的transaction type

2024-06-14

C/C++ realloc()函数解析

2024-06-14

生成一个文件 保存在指定的文件夹中 思路 python

2024-06-14

Windows 10封装中出现“无法验证你的Windows安装”错误解决方法

2024-06-14

109-修改返回体的内容RestControllerAdvice

2024-06-14

C/C++ 判断进程是否存在

2024-06-14

使用面向对象重构之-使用接口完成行为抽象

2024-06-14

使用面向对象重构之-把抽象控制在一处：提高内聚性

2024-06-14

重操旧业障碍多

2024-06-14

关于关闭自动装配

2024-06-14

最新推荐 更多
使用代码获得所有适用于创建的transaction type

2024-06-14

C/C++ realloc()函数解析

2024-06-14

生成一个文件 保存在指定的文件夹中 思路 python

2024-06-14

Windows 10封装中出现“无法验证你的Windows安装”错误解决方法

2024-06-14

109-修改返回体的内容RestControllerAdvice

2024-06-14

C/C++ 判断进程是否存在

2024-06-14

使用面向对象重构之-使用接口完成行为抽象

2024-06-14

使用面向对象重构之-把抽象控制在一处：提高内聚性

2024-06-14

重操旧业障碍多

2024-06-14

关于关闭自动装配

2024-06-14

使用面向对象重构之-从过程式设计到面向对象

2024-06-14

nodejs部署神器pm2的使用体验

2024-06-14

java虚拟机启动过程解析

2024-06-14

mysql-忘记密码时重置操作

2024-06-14

Callable和runnable的区别

2024-06-14

python的粘包和分包

2024-06-14

tftp文件服务（udp端口：69）

2024-06-14

C语言反汇编 - 流程控制与循环结构

2024-06-14

python-列表包字典-根据字典的某一个键的值来进行排序

2024-06-14

使用面向对象重构之-使用接口抽象完成不同维度的扩展

2024-06-14

常用标签
数据数据数据数据javalinuxlinuxpythonCentOSredisJavapython区块链技术区块链信息系统字符串MySQL资讯项目管理mysql教程MySQL