Re: BUG #17871: JIT during postgresql_fdw remote_estimates EXPLAIN have very negatively effect on planning time

>
>
> BTW, I'm still wondering how Maxim got to 100-plus-msec overheads;
> it's around 10ms at most for me, with what seems like a similar case.
>
> regards, tom lane
>
>
Hi Tom,

100+ms on FDW result of two factors
1)FDW call explain 3 times in my case and two of them surely fire JIT
2)locally single EXPLAIN work 35ms on 100 partitions on almost idle server
(after multiple runs)
negotiation_chat_archive=# explain select * from
interview_review_info_archive;
...
JIT:
Functions: 200
Options: Inlining false, Optimization false, Expressions true, Deforming
true
(106 rows)
Time: 34.076 ms
negotiation_chat_archive=# explain select * from
interview_review_info_archive;
Time: 34.437 ms
negotiation_chat_archive=# explain select * from
interview_review_info_archive;
Time: 34.015 ms
pretty stable... not even close to the 7ms that you show in your test.
Table consists of 2 bigint + 3 timestamptz field + single dropped boolean.

I run
explain select * from interview_review_info_archive
\watch 1
for few minutes with corresponding perf record -p recording
and there is perf report result:
4.04% postgres libLLVM-10.so.1 [.]
llvm::FoldingSetNodeID::AddString
2.94% postgres libc-2.31.so [.] malloc
2.58% postgres libLLVM-10.so.1 [.] llvm::AttributeImpl::operator<
2.44% postgres libLLVM-10.so.1 [.] llvm::AttributeSetNode::get
2.18% postgres libLLVM-10.so.1 [.]
llvm::BasicBlock::dropAllReferences
1.87% postgres libLLVM-10.so.1 [.] llvm::Value::setValueName
1.80% postgres libLLVM-10.so.1 [.]
llvm::StringMapImpl::LookupBucketFor
1.67% postgres libLLVM-10.so.1 [.]
llvm::FoldingSetBase::FindNodeOrInsertPos
1.50% postgres libLLVM-10.so.1 [.]
llvm::FoldingSetNodeID::AddPointer
1.49% postgres libLLVM-10.so.1 [.] llvm::StringMapImpl::RemoveKey
1.48% postgres libLLVM-10.so.1 [.] llvm::BasicBlock::~BasicBlock
1.46% postgres libLLVM-10.so.1 [.] llvm::AttrBuilder::addAttribute
1.30% postgres libLLVM-10.so.1 [.]
std::_Rb_tree<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::pair<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > c
1.23% postgres libLLVM-10.so.1 [.] llvm::Value::setNameImpl
1.17% postgres libstdc++.so.6.0.28 [.]
std::_Rb_tree_insert_and_rebalance
1.13% postgres libc-2.31.so [.] cfree
1.07% postgres libLLVM-10.so.1 [.] llvm::Value::destroyValueName
1.06% postgres libLLVM-10.so.1 [.] llvm::User::operator new
1.04% postgres postgres [.] hash_search_with_hash_value
0.97% postgres libLLVM-10.so.1 [.]
std::_Rb_tree<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::pair<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > c
0.95% postgres libLLVM-10.so.1 [.]
llvm::hashing::detail::hash_combine_range_impl<unsigned int const>
0.91% postgres libLLVM-10.so.1 [.] llvm::ConstantInt::get
0.84% postgres libLLVM-10.so.1 [.]
std::_Rb_tree<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::pair<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > c
0.80% postgres libLLVM-10.so.1 [.] std::__sort<llvm::Attribute*,
__gnu_cxx::__ops::_Iter_less_iter>
0.73% postgres libLLVM-10.so.1 [.] llvm::Value::getValueName
0.73% postgres libc-2.31.so [.] memcpy
0.69% postgres postgres [.] dopr.constprop.0
0.63% postgres libLLVM-10.so.1 [.]
llvm::AttributeList::addAttributes
0.63% postgres libLLVM-10.so.1 [.] llvm::AttrBuilder::addAttribute
0.62% postgres libLLVM-10.so.1 [.]
llvm::SymbolTableListTraits<llvm::Instruction>::setSymTabObject<llvm::Function*>
0.60% postgres libstdc++.so.6.0.28 [.] std::_Rb_tree_increment

Maybe it provides some clues.

PS: I run all tests on the postgresql 13 version, maybe there are
differences between JIT implementation/performance between 13 version and
15/head.

Regards,
Maxim

--
Maxim Boguk
Senior Postgresql DBA
https://dataegret.com/

Phone UA: +380 99 143 0000
Phone AU: +61 45 218 5678