当前位置:网站首页>2022-07-05 stonedb的子查询处理解析耗时分析
2022-07-05 stonedb的子查询处理解析耗时分析
2022-07-06 14:28:00 【帝尊悟世】
目录
ParameterizedFilter::ApplyDescriptor
方案一: 重新设计子查询流程中的逐个遍历校验mit是否要重置的处理
摘要:
记录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,
[email protected]: 1, [email protected]: 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, [email protected]: 0x7fa8d404bc68,
setup_tables_done_option=0, [email protected]: 0, [email protected]: 1, [email protected]: 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, [email protected]: 0x7fa8d404bc68, setup_tables_done_option=0,
[email protected]: 0, [email protected]: 1, [email protected]: 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, [email protected]: 1, [email protected]: 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, [email protected]: 0x7f8664052008, setup_tables_done_option=0,
[email protected]: 0, [email protected]: 1, [email protected]: 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, [email protected]: 0x7f8664052008, setup_tables_done_option=0, [email protected]: 0,
[email protected]: 1, [email protected]: 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
执行耗时记录:
执行耗时统计方式:
- 采用函数调用分步骤埋点方式
记录:
[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逐个校验是否需要重置, 校验的次数过大
以子查询为例:
- 总共需要执行65536次
- 每次校验耗时 0.000002秒
- 一共耗时 65536 * 0.000002 = 0.131秒
优化子查询耗时:
方案一: 重新设计子查询流程中的逐个遍历校验mit是否要重置的处理
边栏推荐
- [sdx62] wcn685x will bdwlan Bin and bdwlan Txt mutual conversion operation method
- Leetcode learning records (starting from the novice village, you can't kill out of the novice Village) ---1
- MariaDB database management system learning (I) installation diagram
- C # réalise la liaison des données du rapport Crystal et l'impression du Code à barres 4
- GPS from getting started to giving up (19), precise ephemeris (SP3 format)
- [MySQL] online DDL details
- Oracle Performance Analysis 3: introduction to tkprof
- GPS从入门到放弃(十四)、电离层延时
- Wechat red envelope cover applet source code - background independent version - source code with evaluation points function
- GPS from getting started to giving up (XIII), receiver autonomous integrity monitoring (RAIM)
猜你喜欢
A Mexican airliner bound for the United States was struck by lightning after taking off and then returned safely
C#實現水晶報錶綁定數據並實現打印4-條形碼
[MySQL] online DDL details
Common sense: what is "preservation" in insurance?
CCNA-思科网络 EIGRP协议
Learn the principle of database kernel from Oracle log parsing
Embedded common computing artifact excel, welcome to recommend skills to keep the document constantly updated and provide convenience for others
Management background --5, sub classification
Barcodex (ActiveX print control) v5.3.0.80 free version
[线性代数] 1.3 n阶行列式
随机推荐
What is the difference between animators and animators- What is the difference between an Animator and an Animation?
功能强大的国产Api管理工具
硬件开发笔记(十): 硬件开发基本流程,制作一个USB转RS232的模块(九):创建CH340G/MAX232封装库sop-16并关联原理图元器件
GNN, please deepen your network layer~
经纪xx系统节点VIP案例介绍和深入分析异常
Management background --1 Create classification
Codeforces Round #274 (Div. 2) –A Expression
[10:00 public class]: basis and practice of video quality evaluation
Management background --5, sub classification
小满网络模型&http1-http2 &浏览器缓存
MongoDB(三)——CRUD
GPS从入门到放弃(十七) 、对流层延时
HDU 4912 paths on the tree (lca+)
GPS from getting started to giving up (XVIII), multipath effect
GPS from getting started to giving up (XX), antenna offset
QT | UDP broadcast communication, simple use case
GNN,请你的网络层数再深一点~
Memorabilia of domestic database in June 2022 - ink Sky Wheel
[sciter]: encapsulate the notification bar component based on sciter
Adjustable DC power supply based on LM317