当前位置:网站首页>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是否要重置的处理
边栏推荐
- What is the difference between animators and animators- What is the difference between an Animator and an Animation?
- 小满网络模型&http1-http2 &浏览器缓存
- Force deduction question 500, keyboard line, JS implementation
- Research and investment strategy report of China's VOCs catalyst industry (2022 Edition)
- Chapter 3: detailed explanation of class loading process (class life cycle)
- Some problems about the use of char[] array assignment through scanf..
- 2021 geometry deep learning master Michael Bronstein long article analysis
- OpenCV300 CMake生成project在项目过程中的问题
- 中国1,4-环己烷二甲醇(CHDM)行业调研与投资决策报告(2022版)
- [线性代数] 1.3 n阶行列式
猜你喜欢
LeetCode刷题(十一)——顺序刷题51至55
3DMAX assign face map
[Digital IC hand tearing code] Verilog burr free clock switching circuit | topic | principle | design | simulation
GPS从入门到放弃(十四)、电离层延时
Notes de développement du matériel (10): flux de base du développement du matériel, fabrication d'un module USB à RS232 (9): création de la Bibliothèque d'emballage ch340g / max232 SOP - 16 et Associa
Management background --1 Create classification
C#實現水晶報錶綁定數據並實現打印4-條形碼
GPS从入门到放弃(十九)、精密星历(sp3格式)
数据处理技巧(7):MATLAB 读取数字字符串混杂的文本文件txt中的数据
HDR image reconstruction from a single exposure using deep CNNs阅读札记
随机推荐
2500个常用中文字符 + 130常用中英文字符
硬件开发笔记(十): 硬件开发基本流程,制作一个USB转RS232的模块(九):创建CH340G/MAX232封装库sop-16并关联原理图元器件
图像的spatial domain 和 frequency domain 图像压缩
数据处理技巧(7):MATLAB 读取数字字符串混杂的文本文件txt中的数据
VIP case introduction and in-depth analysis of brokerage XX system node exceptions
Research and investment strategy report of China's VOCs catalyst industry (2022 Edition)
China 1,4-cyclohexanedimethanol (CHDM) industry research and investment decision-making report (2022 Edition)
[MySQL] online DDL details
Learn the principle of database kernel from Oracle log parsing
【sciter Bug篇】多行隐藏
Unity3d Learning Notes 6 - GPU instantiation (1)
中国1,4-环己烷二甲醇(CHDM)行业调研与投资决策报告(2022版)
经纪xx系统节点VIP案例介绍和深入分析异常
AI 企业多云存储架构实践 | 深势科技分享
Management background --5, sub classification
Codeforces Round #274 (Div. 2) –A Expression
GPS from getting started to giving up (16), satellite clock error and satellite ephemeris error
十二、启动流程
Oracle control file and log file management
Adjustable DC power supply based on LM317