当前位置:网站首页>2022-07-05 stonedb sub query processing parsing time analysis
2022-07-05 stonedb sub query processing parsing time analysis
2022-07-06 22:27:00 【Emperor Zunwu world】
Catalog
ParameterizedFilter::ApplyDescriptor
Execution time-consuming statistical method :
Time consuming cause analysis :
One . Traverse mit Check whether reset is needed one by one , The number of checks is too large
Optimizing subqueries takes time :
Abstract :
Record stonedb Subquery processing of , And time-consuming analysis
Core function :
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;
}
Sub query processing :
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();
call Stack :
(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");
}
call Stack :
(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
Record the execution time :
Execution time-consuming statistical method :
- Adopt the function call step by step embedding method
Record :
[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
Too time consuming points :
Too time consuming log :
[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
Time consuming code :
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());
Time consuming cause analysis :
One . Traverse mit Check whether reset is needed one by one , The number of checks is too large
Take subquery as an example :
- In total, it needs to be carried out 65536 Time
- Each calibration takes 0.000002 second
- A total of time consuming 65536 * 0.000002 = 0.131 second
Optimizing subqueries takes time :
Scheme 1 : Redesign the traversal verification in the sub query process mit Whether to reset the processing
边栏推荐
- China 1,4-cyclohexanedimethanol (CHDM) industry research and investment decision-making report (2022 Edition)
- Memorabilia of domestic database in June 2022 - ink Sky Wheel
- C#实现水晶报表绑定数据并实现打印4-条形码
- General implementation and encapsulation of go diversified timing tasks
- 基于 QEMUv8 搭建 OP-TEE 开发环境
- NPDP认证|产品经理如何跨职能/跨团队沟通?
- PVL EDI 项目案例
- Seata聚合 AT、TCC、SAGA 、 XA事务模式打造一站式的分布式事务解决方案
- Applet system update prompt, and force the applet to restart and use the new version
- Senior soft test (Information System Project Manager) high frequency test site: project quality management
猜你喜欢
2022-07-04 mysql的高性能数据库引擎stonedb在centos7.9编译及运行
在IPv6中 链路本地地址的优势
pytorch_ Yolox pruning [with code]
Aardio - 不声明直接传float数值的方法
[leetcode daily clock in] 1020 Number of enclaves
Attack and defense world ditf Misc
0 basic learning C language - digital tube
[sciter]: encapsulate the notification bar component based on sciter
2500个常用中文字符 + 130常用中英文字符
Chapter 3: detailed explanation of class loading process (class life cycle)
随机推荐
UDP编程
Installation and use of labelimg
A Mexican airliner bound for the United States was struck by lightning after taking off and then returned safely
NetXpert XG2帮您解决“布线安装与维护”难题
RESNET rs: Google takes the lead in tuning RESNET, and its performance comprehensively surpasses efficientnet series | 2021 arXiv
第4章:再谈类的加载器
Mysql database basic operations DML
Netxpert xg2 helps you solve the problem of "Cabling installation and maintenance"
Research and investment strategy report of China's VOCs catalyst industry (2022 Edition)
Embedded common computing artifact excel, welcome to recommend skills to keep the document constantly updated and provide convenience for others
Seata聚合 AT、TCC、SAGA 、 XA事务模式打造一站式的分布式事务解决方案
Aardio - 封装库时批量处理属性与回调函数的方法
What are the interface tests? What are the general test points?
做接口测试都测什么?有哪些通用测试点?
Build op-tee development environment based on qemuv8
Oracle-控制文件及日志文件的管理
C#实现水晶报表绑定数据并实现打印4-条形码
第3章:类的加载过程(类的生命周期)详解
CCNA Cisco network EIGRP protocol
Assembly and interface technology experiment 5-8259 interrupt experiment