当前位置：网站首页>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
边栏推荐
- 自制J-Flash烧录工具——Qt调用jlinkARM.dll方式
- 将MySQL的表数据纯净方式导出
- MySQL----初识MySQL
- 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
- 第3章：类的加载过程(类的生命周期)详解
- GPS from getting started to giving up (XI), differential GPS
- Oracle control file and log file management
- Barcodex (ActiveX print control) v5.3.0.80 free version
- Aardio - 通过变量名将变量值整合到一串文本中
- NetXpert XG2帮您解决“布线安装与维护”难题
猜你喜欢
NPDP certification | how do product managers communicate across functions / teams?
GPS from getting started to giving up (12), Doppler constant speed
微信红包封面小程序源码-后台独立版-带测评积分功能源码
Unity3d minigame-unity-webgl-transform插件转换微信小游戏报错To use dlopen, you need to use Emscripten‘s...问题
CCNA Cisco network EIGRP protocol
网络基础入门理解
Embedded common computing artifact excel, welcome to recommend skills to keep the document constantly updated and provide convenience for others
RESNET rs: Google takes the lead in tuning RESNET, and its performance comprehensively surpasses efficientnet series | 2021 arXiv
Management background --5, sub classification
2021 geometry deep learning master Michael Bronstein long article analysis
随机推荐
[Digital IC hand tearing code] Verilog burr free clock switching circuit | topic | principle | design | simulation
枚举与＃define 宏的区别
The SQL response is slow. What are your troubleshooting ideas?
2500个常用中文字符 + 130常用中英文字符
Spatial domain and frequency domain image compression of images
Aardio - 封装库时批量处理属性与回调函数的方法
剑指offer刷题记录1
[leetcode daily clock in] 1020 Number of enclaves
Data storage (1)
Hardware development notes (10): basic process of hardware development, making a USB to RS232 module (9): create ch340g/max232 package library sop-16 and associate principle primitive devices
Common sense: what is "preservation" in insurance?
手写ABA遇到的坑
China 1,4-cyclohexanedimethanol (CHDM) industry research and investment decision-making report (2022 Edition)
BarcodeX(ActiveX打印控件) v5.3.0.80 免费版使用
插入排序与希尔排序
微信红包封面小程序源码-后台独立版-带测评积分功能源码
Force deduction question 500, keyboard line, JS implementation
UDP编程
Barcodex (ActiveX print control) v5.3.0.80 free version
Management background --1 Create classification