当前位置：网站首页>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
边栏推荐
- PVL EDI project case
- Senior soft test (Information System Project Manager) high frequency test site: project quality management
- Heavyweight news | softing fg-200 has obtained China 3C explosion-proof certification to provide safety assurance for customers' on-site testing
- What are the interface tests? What are the general test points?
- 十二、启动流程
- General implementation and encapsulation of go diversified timing tasks
- void关键字
- AI enterprise multi cloud storage architecture practice | Shenzhen potential technology sharing
- 软考高级（信息系统项目管理师）高频考点：项目质量管理
- 硬件開發筆記（十）: 硬件開發基本流程，制作一個USB轉RS232的模塊（九）：創建CH340G/MAX232封裝庫sop-16並關聯原理圖元器件
猜你喜欢
Spatial domain and frequency domain image compression of images
墨西哥一架飞往美国的客机起飞后遭雷击 随后安全返航
Management background --1 Create classification
Aardio - 封装库时批量处理属性与回调函数的方法
自制J-Flash烧录工具——Qt调用jlinkARM.dll方式
硬件开发笔记（十）: 硬件开发基本流程，制作一个USB转RS232的模块（九）：创建CH340G/MAX232封装库sop-16并关联原理图元器件
二叉（搜索）树的最近公共祖先 ●●
0 basic learning C language - digital tube
小常识：保险中的“保全”是什么？
Management background --3, modify classification
随机推荐
MySQL数据库基本操作-DML
Classification, function and usage of MySQL constraints
Chapter 3: detailed explanation of class loading process (class life cycle)
NPDP认证|产品经理如何跨职能/跨团队沟通?
A Mexican airliner bound for the United States was struck by lightning after taking off and then returned safely
pytorch_YOLOX剪枝【附代码】
2022-07-04 mysql的高性能数据库引擎stonedb在centos7.9编译及运行
Heavyweight news | softing fg-200 has obtained China 3C explosion-proof certification to provide safety assurance for customers' on-site testing
新手程序员该不该背代码？
Attack and defense world ditf Misc
Management background --4, delete classification
Classic sql50 questions
第3章：类的加载过程(类的生命周期)详解
Web APIs DOM 时间对象
3DMAX assign face map
2022-07-05 stonedb的子查询处理解析耗时分析
volatile关键字
[linear algebra] determinant of order 1.3 n
中国1,4-环己烷二甲醇（CHDM）行业调研与投资决策报告（2022版）
HDR image reconstruction from a single exposure using deep CNNs阅读札记