Re: Pg11 server w/parallel backends unresponsive to cancel/terminate... (here are some backtraces)

Included a few backtraces...

Jerry Sievers <gsievers19@comcast.net> writes:

> Greetings!  One of my $power users launched big-nasty job on our ~50TB
> warehouse.
>
> Long-running jobs on that box aren't unusual, however this one we want
> stopped and it's unresponsive to cancel or terminate signalling for
> several hours.
>
> Below are 10 lines captured by running strace over each of the PIDs.
>
> What else to look for before we stop-immediate the system?
>
> Thx!
>
> PS: Will repost w/gdb output as soon as I can remember how to run it for
> a case like this :-)

cat debug.log
#0  0x00007f82bca695a0 in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#1  0x00007f82bca6b586 in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#2  0x00007f82bca739ca in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#3  0x00007f82bd0fd1a6 in llvm::SplitCriticalEdge(llvm::TerminatorInst*, unsigned int,
llvm::CriticalEdgeSplittingOptionsconst&) () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
 
#4  0x00007f82bd38e46f in llvm::GVN::splitCriticalEdges(llvm::BasicBlock*, llvm::BasicBlock*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#5  0x00007f82bd39a8af in llvm::GVN::processFoldableCondBr(llvm::BranchInst*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#6  0x00007f82bd39af97 in llvm::GVN::processInstruction(llvm::Instruction*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#7  0x00007f82bd39b188 in llvm::GVN::processBlock(llvm::BasicBlock*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#8  0x00007f82bd39c390 in llvm::GVN::iterateOnFunction(llvm::Function&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#9  0x00007f82bd39c4bb in llvm::GVN::runImpl(llvm::Function&, llvm::AssumptionCache&, llvm::DominatorTree&,
llvm::TargetLibraryInfoconst&, llvm::AAResults&, llvm::MemoryDependenceResults*, llvm::LoopInfo*,
llvm::OptimizationRemarkEmitter*)() from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
 
#10 0x00007f82bd39cc98 in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#11 0x00007f82bcaa9a22 in llvm::FPPassManager::runOnFunction(llvm::Function&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#12 0x00007f82bd6e870e in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#13 0x00007f82bcaa966f in llvm::legacy::PassManagerImpl::run(llvm::Module&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#14 0x00007f82bca365c9 in LLVMRunPassManager () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#15 0x00007f82cbd177c9 in llvm_get_function () from /usr/lib/postgresql/11/lib/llvmjit.so
#16 0x00007f82cbd205d0 in ?? () from /usr/lib/postgresql/11/lib/llvmjit.so
#17 0x00005640aabfb965 in ExecScan ()
#18 0x00005640aac09aaa in ?? ()
#19 0x00005640aac1b826 in ?? ()
#20 0x00005640aabf2d1b in standard_ExecutorRun ()
#21 0x00007fa3a05d95a5 in ?? () from /usr/lib/postgresql/11/lib/auto_explain.so
#22 0x00007fa3a03d0dfd in ?? () from /usr/lib/postgresql/11/lib/pg_stat_statements.so
#23 0x00005640aab7ec0c in ExecCreateTableAs ()
#24 0x00005640aad4b860 in ?? ()
#25 0x00005640aad4aa60 in standard_ProcessUtility ()
#26 0x00007fa3a03d316f in ?? () from /usr/lib/postgresql/11/lib/pg_stat_statements.so
#27 0x00007fa3a01b6613 in ?? () from /usr/lib/postgresql/11/lib/pglogical.so
#28 0x00005640aad47959 in ?? ()
#29 0x00005640aad48488 in ?? ()
#30 0x00005640aad491f5 in PortalRun ()
#31 0x00005640aad44cb1 in ?? ()
#32 0x00005640aad461ed in PostgresMain ()
#33 0x00005640aaa53d37 in ?? ()
#34 0x00005640aacd0882 in PostmasterMain ()
#35 0x00005640aaa550e5 in main ()
Continuing.

Program received signal SIGINT, Interrupt.
0x00007f82bca60a63 in llvm::DominatorTreeBase<llvm::BasicBlock, false>::updateDFSNumbers() const () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#0  0x00007f82bca60a63 in llvm::DominatorTreeBase<llvm::BasicBlock, false>::updateDFSNumbers() const () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#1  0x00007f82bca60b77 in llvm::DominatorTreeBase<llvm::BasicBlock,
false>::dominates(llvm::DomTreeNodeBase<llvm::BasicBlock>const*, llvm::DomTreeNodeBase<llvm::BasicBlock> const*) const
()from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
 
#2  0x00007f82bd392950 in llvm::GVN::findLeader(llvm::BasicBlock const*, unsigned int) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#3  0x00007f82bd39b00d in llvm::GVN::processInstruction(llvm::Instruction*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#4  0x00007f82bd39b188 in llvm::GVN::processBlock(llvm::BasicBlock*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#5  0x00007f82bd39c390 in llvm::GVN::iterateOnFunction(llvm::Function&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#6  0x00007f82bd39c4bb in llvm::GVN::runImpl(llvm::Function&, llvm::AssumptionCache&, llvm::DominatorTree&,
llvm::TargetLibraryInfoconst&, llvm::AAResults&, llvm::MemoryDependenceResults*, llvm::LoopInfo*,
llvm::OptimizationRemarkEmitter*)() from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
 
#7  0x00007f82bd39cc98 in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#8  0x00007f82bcaa9a22 in llvm::FPPassManager::runOnFunction(llvm::Function&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#9  0x00007f82bd6e870e in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#10 0x00007f82bcaa966f in llvm::legacy::PassManagerImpl::run(llvm::Module&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#11 0x00007f82bca365c9 in LLVMRunPassManager () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#12 0x00007f82cbd177c9 in llvm_get_function () from /usr/lib/postgresql/11/lib/llvmjit.so
#13 0x00007f82cbd205d0 in ?? () from /usr/lib/postgresql/11/lib/llvmjit.so
#14 0x00005640aabfb965 in ExecScan ()
#15 0x00005640aac09aaa in ?? ()
#16 0x00005640aac1b826 in ?? ()
#17 0x00005640aabf2d1b in standard_ExecutorRun ()
#18 0x00007fa3a05d95a5 in ?? () from /usr/lib/postgresql/11/lib/auto_explain.so
#19 0x00007fa3a03d0dfd in ?? () from /usr/lib/postgresql/11/lib/pg_stat_statements.so
#20 0x00005640aab7ec0c in ExecCreateTableAs ()
#21 0x00005640aad4b860 in ?? ()
#22 0x00005640aad4aa60 in standard_ProcessUtility ()
#23 0x00007fa3a03d316f in ?? () from /usr/lib/postgresql/11/lib/pg_stat_statements.so
#24 0x00007fa3a01b6613 in ?? () from /usr/lib/postgresql/11/lib/pglogical.so
#25 0x00005640aad47959 in ?? ()
#26 0x00005640aad48488 in ?? ()
#27 0x00005640aad491f5 in PortalRun ()
#28 0x00005640aad44cb1 in ?? ()
#29 0x00005640aad461ed in PostgresMain ()
#30 0x00005640aaa53d37 in ?? ()
#31 0x00005640aacd0882 in PostmasterMain ()
#32 0x00005640aaa550e5 in main ()
Quit
Continuing.

Program received signal SIGINT, Interrupt.
0x00007fa3a7689747 in munmap () from /lib/x86_64-linux-gnu/libc.so.6
#0  0x00007fa3a7689747 in munmap () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007fa3a760c5d1 in free () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007f82bca6065f in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#3  0x00007f82bca6b5aa in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#4  0x00007f82bca739ca in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#5  0x00007f82bd0fd1a6 in llvm::SplitCriticalEdge(llvm::TerminatorInst*, unsigned int,
llvm::CriticalEdgeSplittingOptionsconst&) () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
 
#6  0x00007f82bd38e46f in llvm::GVN::splitCriticalEdges(llvm::BasicBlock*, llvm::BasicBlock*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#7  0x00007f82bd39a8af in llvm::GVN::processFoldableCondBr(llvm::BranchInst*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#8  0x00007f82bd39af97 in llvm::GVN::processInstruction(llvm::Instruction*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#9  0x00007f82bd39b188 in llvm::GVN::processBlock(llvm::BasicBlock*) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#10 0x00007f82bd39c390 in llvm::GVN::iterateOnFunction(llvm::Function&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#11 0x00007f82bd39c4bb in llvm::GVN::runImpl(llvm::Function&, llvm::AssumptionCache&, llvm::DominatorTree&,
llvm::TargetLibraryInfoconst&, llvm::AAResults&, llvm::MemoryDependenceResults*, llvm::LoopInfo*,
llvm::OptimizationRemarkEmitter*)() from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1 
#12 0x00007f82bd39cc98 in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#13 0x00007f82bcaa9a22 in llvm::FPPassManager::runOnFunction(llvm::Function&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#14 0x00007f82bd6e870e in ?? () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#15 0x00007f82bcaa966f in llvm::legacy::PassManagerImpl::run(llvm::Module&) () from
/usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#16 0x00007f82bca365c9 in LLVMRunPassManager () from /usr/lib/x86_64-linux-gnu/libLLVM-6.0.so.1
#17 0x00007f82cbd177c9 in llvm_get_function () from /usr/lib/postgresql/11/lib/llvmjit.so
#18 0x00007f82cbd205d0 in ?? () from /usr/lib/postgresql/11/lib/llvmjit.so
#19 0x00005640aabfb965 in ExecScan ()
#20 0x00005640aac09aaa in ?? ()
#21 0x00005640aac1b826 in ?? ()
#22 0x00005640aabf2d1b in standard_ExecutorRun ()
#23 0x00007fa3a05d95a5 in ?? () from /usr/lib/postgresql/11/lib/auto_explain.so
#24 0x00007fa3a03d0dfd in ?? () from /usr/lib/postgresql/11/lib/pg_stat_statements.so
#25 0x00005640aab7ec0c in ExecCreateTableAs ()
#26 0x00005640aad4b860 in ?? ()
#27 0x00005640aad4aa60 in standard_ProcessUtility ()
#28 0x00007fa3a03d316f in ?? () from /usr/lib/postgresql/11/lib/pg_stat_statements.so
#29 0x00007fa3a01b6613 in ?? () from /usr/lib/postgresql/11/lib/pglogical.so
#30 0x00005640aad47959 in ?? ()
#31 0x00005640aad48488 in ?? ()
#32 0x00005640aad491f5 in PortalRun ()
#33 0x00005640aad44cb1 in ?? ()
#34 0x00005640aad461ed in PostgresMain ()
#35 0x00005640aaa53d37 in ?? ()
#36 0x00005640aacd0882 in PostmasterMain ()
#37 0x00005640aaa550e5 in main ()
Detaching from program: /usr/lib/postgresql/11/bin/postgres, process 42079

Thx
>
>
>
>  PostgreSQL 11.7 (Ubuntu 11.7-2.pgdg16.04+1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 5.4.0-6ubuntu1~16.04.12)
5.4.020160609, 64-bit
 
>
>
>
> # echo $#
> 9
>
> # for p; do strace -p $p 2>&1 | head -10; echo; done 
> strace: Process 42079 attached
> strace: [ Process PID=42079 runs in x32 mode. ]
> strace: [ Process PID=42079 runs in 64 bit mode. ]
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8219365000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8214364000
> munmap(0x7f8219365000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81ff856000
> munmap(0x7f8214364000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81eb855000
> munmap(0x7f81ff856000, 167776256)       = 0
>
> strace: Process 42372 attached
> strace: [ Process PID=42372 runs in x32 mode. ]
> strace: [ Process PID=42372 runs in 64 bit mode. ]
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
> munmap(0x7f81fdafb000, 167776256)       = 0
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8219a0b000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8214a0a000
> munmap(0x7f8219a0b000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
>
> strace: Process 42373 attached
> strace: [ Process PID=42373 runs in x32 mode. ]
> strace: [ Process PID=42373 runs in 64 bit mode. ]
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8217a0a000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8212a09000
> munmap(0x7f8217a0a000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8212a09000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
>
> strace: Process 42374 attached
> strace: [ Process PID=42374 runs in x32 mode. ]
> strace: [ Process PID=42374 runs in 64 bit mode. ]
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8219a0b000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8214a0a000
> munmap(0x7f8219a0b000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8214a0a000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
>
> strace: Process 42375 attached
> strace: [ Process PID=42375 runs in x32 mode. ]
> strace: [ Process PID=42375 runs in 64 bit mode. ]
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8219a0b000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8214a0a000
> munmap(0x7f8219a0b000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8214a0a000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
>
> strace: Process 42376 attached
> strace: [ Process PID=42376 runs in x32 mode. ]
> strace: [ Process PID=42376 runs in 64 bit mode. ]
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8217a0a000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8212a09000
> munmap(0x7f8217a0a000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8212a09000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
>
> strace: Process 42377 attached
> munmap(0x7f81fdafb000, 167776256)       = 0
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8217a0a000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8212a09000
> munmap(0x7f8217a0a000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8212a09000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
> munmap(0x7f81fdafb000, 167776256)       = 0
>
> strace: Process 42378 attached
> strace: [ Process PID=42378 runs in x32 mode. ]
> strace: [ Process PID=42378 runs in 64 bit mode. ]
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8214a0a000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000
> munmap(0x7f81fdafb000, 167776256)       = 0
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8219a0b000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8214a0a000
>
> strace: Process 42379 attached
> strace: [ Process PID=42379 runs in x32 mode. ]
> strace: [ Process PID=42379 runs in 64 bit mode. ]
> munmap(0x7f81e9afa000, 335548416)       = 0
> mmap(NULL, 41947136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8217a0a000
> mmap(NULL, 83890176, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8212a09000
> munmap(0x7f8217a0a000, 41947136)        = 0
> mmap(NULL, 167776256, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81fdafb000
> munmap(0x7f8212a09000, 83890176)        = 0
> mmap(NULL, 335548416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f81e9afa000

-- 
Jerry Sievers
Postgres DBA/Development Consulting
e: postgres.consulting@comcast.net