seawasp failing, maybe in glibc allocator
Hi,
Since seawasp's bleeding-edge clang moved to "20210226", it failed
every run except 4, and a couple of days ago it moved to "20210508"
and it's still broken. It's always like this:
2021-05-09 03:31:37.602 CEST [1678796:171] pg_regress/_int LOG:
statement: RESET enable_seqscan;
corrupted double-linked list
... which doesn't appear in our code, but matches this:
https://github.com/bminor/glibc/blob/cedbf6d5f3f70ca911176de87d6e453eeab4b7a1/malloc/malloc.c#L1645
No reason to think it's our fault, but it'd be nice to see a
backtrace. Is gdb installed, and are core files being dumped by that
SIGABRT, and are they using the default name
(/proc/sys/kernel/core_pattern = core), which the BF can find with the
value it's using, namely 'core_file_glob' => 'core*'?
Hello Thomas,
Since seawasp's bleeding-edge clang moved to "20210226", it failed
every run except 4, and a couple of days ago it moved to "20210508"
and it's still broken.
Indeed I have noticed that there is indeed an issue, but the investigation
is not very high on my current too deep pg-unrelated todo list.
It's always like this:
2021-05-09 03:31:37.602 CEST [1678796:171] pg_regress/_int LOG:
statement: RESET enable_seqscan;
corrupted double-linked list... which doesn't appear in our code, but matches this:
https://github.com/bminor/glibc/blob/cedbf6d5f3f70ca911176de87d6e453eeab4b7a1/malloc/malloc.c#L1645
No reason to think it's our fault, but it'd be nice to see a
backtrace.
ISTM it looks like some kind of memory corruption. If I'd have to guess
between glibc, clang and pg, not sure which one I'd chose between the two
laters potential bug sources.
Is gdb installed, and are core files being dumped by that SIGABRT, and
are they using the default name (/proc/sys/kernel/core_pattern = core),
which the BF can find with the value it's using, namely 'core_file_glob'
=> 'core*'?
Nope:
sh> cat /proc/sys/kernel/core_pattern
|/usr/share/apport/apport %p %s %c %d %P %E
--
Fabien.
On Mon, May 10, 2021 at 6:59 PM Fabien COELHO <coelho@cri.ensmp.fr> wrote:
Is gdb installed, and are core files being dumped by that SIGABRT, and
are they using the default name (/proc/sys/kernel/core_pattern = core),
which the BF can find with the value it's using, namely 'core_file_glob'
=> 'core*'?Nope:
sh> cat /proc/sys/kernel/core_pattern
|/usr/share/apport/apport %p %s %c %d %P %E
If you don't care about Ubuntu "apport" on this system (something for
sending crash/bug reports to developers with a GUI), you could
uninstall it (otherwise it overwrites the core_pattern every time it
restarts, no matter what you write in your sysctl.conf, apparently),
and then sudo sysctl -w kernel.core_pattern=core to undo the setting
immediately (or reboot). Then hopefully the build farm would succeed
in dumping a backtrace into the log.
If you don't care about Ubuntu "apport" on this system (something for
sending crash/bug reports to developers with a GUI), you could
uninstall it (otherwise it overwrites the core_pattern every time it
restarts, no matter what you write in your sysctl.conf, apparently),
and then sudo sysctl -w kernel.core_pattern=core to undo the setting
immediately (or reboot). Then hopefully the build farm would succeed
in dumping a backtrace into the log.
I forced-removed apport (which meant removing xserver-xorg). Let's see
whether the reports are better or whether I break something.
--
Fabien.
On Mon, May 10, 2021 at 9:30 PM Fabien COELHO <coelho@cri.ensmp.fr> wrote:
I forced-removed apport (which meant removing xserver-xorg). Let's see
whether the reports are better or whether I break something.
And of course this time it succeeded :-)
Just by the way, I noticed it takes ~40 minutes to compile. Is there
a reason you don't install ccache and set eg CC="ccache
/path/to/clang", CXX="ccache /path/to/clang++", CLANG="ccache
/path/to/clang"? That doesn't seem to conflict with your goal of
testing LLVM/Clang's main branch, because ccache checks the compiler's
mtime as part of its cache invalidation strategy.
And of course this time it succeeded :-)
Hmmm. ISTM that failures are on and off every few attempts.
Just by the way, I noticed it takes ~40 minutes to compile. Is there
a reason you don't install ccache and set eg CC="ccache
/path/to/clang", CXX="ccache /path/to/clang++", CLANG="ccache
/path/to/clang"? That doesn't seem to conflict with your goal of
testing LLVM/Clang's main branch, because ccache checks the compiler's
mtime as part of its cache invalidation strategy.
Yep.
I remember that I disactivated it for some reason once, but I cannot
remember why. I just reactivated it, will see what happens.
--
Fabien.
On Mon, May 10, 2021 at 11:21 PM Fabien COELHO <coelho@cri.ensmp.fr> wrote:
And of course this time it succeeded :-)
Hmmm. ISTM that failures are on and off every few attempts.
OK we got the SIGABRT this time, but still no backtrace. If the
kernel's core_pattern is "core", gdb is installed, then considering
that the buildfarm core_file_glob is "core*" and the script version is
recent (REL_12), then I'm out of ideas. ulimit -c XXX shouldn't be
needed because the perl script does that with rlimit.
On 2021-05-11 12:16:44 +1200, Thomas Munro wrote:
OK we got the SIGABRT this time, but still no backtrace. If the
kernel's core_pattern is "core", gdb is installed, then considering
that the buildfarm core_file_glob is "core*" and the script version is
recent (REL_12), then I'm out of ideas. ulimit -c XXX shouldn't be
needed because the perl script does that with rlimit.
Unless perhaps the hard rlimit for -C is set? ulimit -c -H should show
that.
On 2021-05-11 12:16:44 +1200, Thomas Munro wrote:
OK we got the SIGABRT this time, but still no backtrace. If the
kernel's core_pattern is "core", gdb is installed, then considering
that the buildfarm core_file_glob is "core*" and the script version is
recent (REL_12), then I'm out of ideas. ulimit -c XXX shouldn't be
needed because the perl script does that with rlimit.Unless perhaps the hard rlimit for -C is set? ulimit -c -H should show
that.
Possibly I have just added "ulimit -c unlimited" in the script, we should
see the effect on next round.
--
Fabien.
On 2021-05-11 10:22:02 +0200, Fabien COELHO wrote:
On 2021-05-11 12:16:44 +1200, Thomas Munro wrote:
OK we got the SIGABRT this time, but still no backtrace. If the
kernel's core_pattern is "core", gdb is installed, then considering
that the buildfarm core_file_glob is "core*" and the script version is
recent (REL_12), then I'm out of ideas. ulimit -c XXX shouldn't be
needed because the perl script does that with rlimit.Unless perhaps the hard rlimit for -C is set? ulimit -c -H should show
that.Possibly I have just added "ulimit -c unlimited" in the script, we should
see the effect on next round.
If it's the hard limit that won't help, because the hard limit can only
be increased by a privileged process.
Hello Andres,p
Unless perhaps the hard rlimit for -C is set? ulimit -c -H should show
that.Possibly I have just added "ulimit -c unlimited" in the script, we should
see the effect on next round.If it's the hard limit that won't help, because the hard limit can only
be increased by a privileged process.
It seems to be the soft one, so ISTM that it may work.
Before:
sh> ulimit -c -S
0
sh> ulimit -c -H
unlimited
Then after:
sh> ulimit -c unlimited
I have:
sh> ulimit -c -S
unlimited
sh> ulimit -c -H
unlimited
--
Fabien.
Possibly I have just added "ulimit -c unlimited" in the script, we should see
the effect on next round.
for def5b065 it ended on on the contrib ltree test:
2021-05-12 20:12:52.528 CEST [3042602:410] pg_regress/ltree LOG: disconnection: session time: 0:00:13.426 user=buildfarm database=contrib_regression_ltree host=[local]
/home/fabien/pg/build-farm-12/buildroot/HEAD/pgsql.build/contrib/ltree/results/ltree.out
2021-05-12 20:12:52.523330311 +0200
@@ -7931,11 +7931,8 @@
(1 row)
SELECT count(*) FROM _ltreetest WHERE t ~ '1.1.1.*' ;
- count
--------
- 19
-(1 row)
-
+ERROR: stack depth limit exceeded
+HINT: Increase the configuration parameter "max_stack_depth" (currently 2048kB), after ensuring the platform's stack depth limit is adequate.
SELECT count(*) FROM _ltreetest WHERE t ~ '*.1' ;
count
-------Not a core dump, though.
--
Fabien.
Hello Andres,
It finally failed with a core on 8f72bba, in llvm_shutdown, AFAIKS in a
free while doing malloc-related housekeeping.
My guess is that there is an actual memory corruption somewhere. It is
unobvious whether it is in bleeding-edge llvm or bleeding-edge postgres
though.
The issue is non-deterministically triggered in contrib checks, either in
int or ltree, but not elsewhere. This suggests issues specific to these
modules, or triggered by these modules. Hmmm…
I've just launched a run with valgrind enabled.
--
Fabien.
On Sat, May 15, 2021 at 6:41 PM Fabien COELHO <coelho@cri.ensmp.fr> wrote:
The issue is non-deterministically triggered in contrib checks, either in
int or ltree, but not elsewhere. This suggests issues specific to these
modules, or triggered by these modules. Hmmm…
Hmm, yeah. A couple of different ways that ltreetest fails without crashing:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=seawasp&dt=2021-05-13%2001%3A17%3A15
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=seawasp&dt=2021-05-12%2017%3A17%3A15
Otherwise it's mostly free() blowing up, and one case of an assertion
failure in llvm::StringMapImpl::RemoveKey, I guess before free() is
reached:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=seawasp&dt=2021-05-14%2009%3A17%3A15
The issue is non-deterministically triggered in contrib checks, either in
int or ltree, but not elsewhere. This suggests issues specific to these
modules, or triggered by these modules. Hmmm…Hmm, yeah. A couple of different ways that ltreetest fails without crashing:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=seawasp&dt=2021-05-13%2001%3A17%3A15
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=seawasp&dt=2021-05-12%2017%3A17%3A15Otherwise it's mostly free() blowing up, and one case of an assertion
failure in llvm::StringMapImpl::RemoveKey, I guess before free() is
reached:https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=seawasp&dt=2021-05-14%2009%3A17%3A15
It seems that the upload of the valgrind run (many hours…) failed on "413
request entity too large", and everything seems to have been cleaned
despite the "--keepall" I think I put when I started the run.
Not sure about the best way to proceed.
--
Fabien.
On Wed, May 19, 2021 at 5:02 AM Fabien COELHO <coelho@cri.ensmp.fr> wrote:
It seems that the upload of the valgrind run (many hours…) failed on "413
request entity too large", and everything seems to have been cleaned
despite the "--keepall" I think I put when I started the run.
I installed Clang/LLVM version
"1:13~++20210520071732+02f2d739e074-1~exp1~20210520052519.57" from
https://apt.llvm.org/ on a Debian buster box, and I saw that
contrib/ltree's test fail about half the time with a range of weird
and wonderful outputs (wrong answers) similar to seawasp, but it never
crashed. I ran it under valgrind and I managed to get:
==529250== Invalid read of size 8
==529250== at 0x1475B6CA: void
std::vector<llvm::orc::SymbolStringPtr,
std::allocator<llvm::orc::SymbolStringPtr>
::_M_realloc_insert<llvm::orc::SymbolStringPtr
const&>(__gnu_cxx::__normal_iterator<llvm::orc::SymbolStringPtr*,
std::vector<llvm::orc::SymbolStringPtr,
std::allocator<llvm::orc::SymbolStringPtr> > >,
llvm::orc::SymbolStringPtr const&) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x1474F246:
llvm::orc::JITDylib::removeTracker(llvm::orc::ResourceTracker&) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x14741E0A:
llvm::orc::ExecutionSession::removeResourceTracker(llvm::orc::ResourceTracker&)
(in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x14747421: llvm::orc::JITDylib::clear() (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x14751F5B: llvm::orc::ExecutionSession::endSession()
(in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x14785207: llvm::orc::LLJIT::~LLJIT() (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x147A4C7D: LLVMOrcDisposeLLJIT (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x124D0094: llvm_shutdown (llvmjit.c:892)
==529250== by 0x57BC08: proc_exit_prepare (ipc.c:209)
==529250== by 0x57BC77: proc_exit (ipc.c:107)
==529250== by 0x5A545B: PostgresMain (postgres.c:4700)
==529250== by 0x517569: BackendRun (postmaster.c:4491)
==529250== by 0x517569: BackendStartup (postmaster.c:4213)
==529250== by 0x517569: ServerLoop (postmaster.c:1745)
==529250== Address 0x1a969088 is 1,416 bytes inside a block of size
3,072 free'd
==529250== at 0x4839EAB: operator delete(void*) (vg_replace_malloc.c:584)
==529250== by 0x141DFD8E: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x141DD9C0: llvm::LazyValueInfo::releaseMemory() (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13294832:
llvm::PMDataManager::freePass(llvm::Pass*, llvm::StringRef,
llvm::PassDebuggingString) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13294774:
llvm::PMDataManager::removeDeadPasses(llvm::Pass*, llvm::StringRef,
llvm::PassDebuggingString) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13290A69:
llvm::FPPassManager::runOnFunction(llvm::Function&) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x14137632: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13290FDE:
llvm::legacy::PassManagerImpl::run(llvm::Module&) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x131F8625: LLVMRunPassManager (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x124D0772: llvm_optimize_module (llvmjit.c:620)
==529250== by 0x124D0772: llvm_compile_module (llvmjit.c:671)
==529250== by 0x124D0772: llvm_get_function (llvmjit.c:291)
==529250== by 0x124DA3BC: ExecRunCompiledExpr (llvmjit_expr.c:2402)
==529250== by 0x41D15C: ExecEvalExprSwitchContext (executor.h:339)
==529250== by 0x41D15C: ExecQual (executor.h:408)
==529250== by 0x41D15C: ExecScan (execScan.c:227)
==529250== Block was alloc'd at
==529250== at 0x4838DEF: operator new(unsigned long)
(vg_replace_malloc.c:342)
==529250== by 0x141E47D6: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x141E43B7: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x141E3202: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x141E0501: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x141DDD74: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x141DDC4C:
llvm::LazyValueInfo::getConstant(llvm::Value*, llvm::Instruction*) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13D0EE4B: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13D11D42: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x1329098C:
llvm::FPPassManager::runOnFunction(llvm::Function&) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x14137632: ??? (in /usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250== by 0x13290FDE:
llvm::legacy::PassManagerImpl::run(llvm::Module&) (in
/usr/lib/x86_64-linux-gnu/libLLVM-13.so.1)
==529250==
Maybe they should rewrite LLVM in Rust.
Hi,
On 2021-05-21 21:37:22 +1200, Thomas Munro wrote:
I installed Clang/LLVM version
"1:13~++20210520071732+02f2d739e074-1~exp1~20210520052519.57" from
https://apt.llvm.org/ on a Debian buster box, and I saw that
contrib/ltree's test fail about half the time with a range of weird
and wonderful outputs (wrong answers) similar to seawasp, but it never
crashed. I ran it under valgrind and I managed to get:
Interesting. I tried this with a slightly older LLVM checkout
(6f4f0afaa8ae), from 2021-04-20, contrib/ltree tests run without an
issue, even if I force everything to be jitted+inlined+optimized. The
git hash in the package version indicates the commit is from
2021-05-20. Upgrading my local checkout to see whether I can repro the
problem. If I can we at least have a not too large bisection window...
Greetings,
Andres Freund
Andres Freund <andres@anarazel.de> writes:
Interesting. I tried this with a slightly older LLVM checkout
(6f4f0afaa8ae), from 2021-04-20, contrib/ltree tests run without an
issue, even if I force everything to be jitted+inlined+optimized. The
git hash in the package version indicates the commit is from
2021-05-20. Upgrading my local checkout to see whether I can repro the
problem. If I can we at least have a not too large bisection window...
We know that seawasp was okay as of
configure: using compiler=clang version 13.0.0 (https://github.com/llvm/llvm-project.git f22d3813850f9e87c5204df6844a93b8c5db7730)
and not okay as of
configure: using compiler=clang version 13.0.0 (https://github.com/llvm/llvm-project.git 0e8f5e4a6864839d2292ec1ddfe48b6178c01f85)
so that should correspond to a window of about a week, if I gather
Fabien's update strategy correctly.
regards, tom lane
Hi,
On 2021-05-21 14:58:38 -0700, Andres Freund wrote:
Interesting. I tried this with a slightly older LLVM checkout
(6f4f0afaa8ae), from 2021-04-20, contrib/ltree tests run without an
issue, even if I force everything to be jitted+inlined+optimized. The
git hash in the package version indicates the commit is from
2021-05-20. Upgrading my local checkout to see whether I can repro the
problem. If I can we at least have a not too large bisection window...
After resolving some PEBKAC issues I was able to reproduce the issue
after a git pull for fresh llvm sources and rebuilding. Hope I can
narrow it down without needing to bisect, there's faster building
projects than LLVM...
Greetings,
Andres Freund
Hi,
On 2021-05-21 18:18:54 -0400, Tom Lane wrote:
Andres Freund <andres@anarazel.de> writes:
Interesting. I tried this with a slightly older LLVM checkout
(6f4f0afaa8ae), from 2021-04-20, contrib/ltree tests run without an
issue, even if I force everything to be jitted+inlined+optimized. The
git hash in the package version indicates the commit is from
2021-05-20. Upgrading my local checkout to see whether I can repro the
problem. If I can we at least have a not too large bisection window...We know that seawasp was okay as of
configure: using compiler=clang version 13.0.0 (https://github.com/llvm/llvm-project.git f22d3813850f9e87c5204df6844a93b8c5db7730)
and not okay as of
configure: using compiler=clang version 13.0.0 (https://github.com/llvm/llvm-project.git 0e8f5e4a6864839d2292ec1ddfe48b6178c01f85)
so that should correspond to a window of about a week, if I gather
Fabien's update strategy correctly.
I found the LLVM commit to blame (c8fc5e3ba942057d6c4cdcd1faeae69a28e7b671).
Contacting the author and reading the change to see if I can spit the
issue myself.
Greetings,
Andres Freund