Bug#847288: libdbd-firebird-perl: FTBFS randomly (failing tests)

Mon Dec 26 16:32:20 UTC 2016

[explicitly cc'ing Damyan as the firebird3.0 maintainer; see the
 backtraces below. Any ideas?]

On Mon, Dec 26, 2016 at 11:07:53AM +0100, Santiago Vila wrote:
> On Mon, Dec 26, 2016 at 02:03:25AM +0100, gregor herrmann wrote:
> > On Sun, 25 Dec 2016 20:06:46 +0100, Santiago Vila wrote:
> > 
> > > The "slowness" is the inverse of the speed. My unit of measure
> > > (i.e. slowness 1) is the speed of my i3-3217U @ 1.80GHz at home,
> > > which was my first autobuilder.
> > 
> > Don't know where my laptop qualifies with
> >     model name	: Intel(R) Core(TM) i7-2620M CPU @ 2.70GHz
> > :)
> 
> Most probably, yes.

FWIW I've tried quite a bit locally with different VM setups but I don't
see any failures, with the underlying HW a quad-core of

 model name  : Intel(R) Core(TM) i5-3427U CPU @ 1.80GHz

However, I had temporary access to a host where the original failure
happened: t/embed-90-dbinfo.t and others get a SIGSEGV at cleanup phase,
after passing all the tests.

Observations:

- it needs PERL_DL_NONLAZY=1 to happen
- the gcc optimization level of DBD::Firebird XS parts doesn't affect it
- strace makes it go away, and IIRC so does valgrind
- there are always three threads active when it crashes; the crashing
  thread backtrace is totally unhelpful but the main thread seems to be
  the Firebird server unloading plugin modules or something like that

(gdb) run -Iblib/lib -Iblib/arch t/embed-90-dbinfo.t
Starting program: /usr/bin/perl -Iblib/lib -Iblib/arch t/embed-90-dbinfo.t
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff54ea700 (LWP 2375)]
[New Thread 0x7ffff4ce9700 (LWP 2376)]
[New Thread 0x7fffed752700 (LWP 2377)]
[New Thread 0x7fffece51700 (LWP 2378)]
1..13
ok 1 - Connected to the database
ok 2
ok 3
ok 4 - tx count should be 0, no tx started yet
ok 5
ok 6 - tx count should be 1
ok 7
ok 8 - tx count should be 0 after commit
ok 9
[Thread 0x7fffece51700 (LWP 2378) exited]
[Thread 0x7fffed752700 (LWP 2377) exited]
ok 10
[New Thread 0x7fffed752700 (LWP 2379)]
[New Thread 0x7fffece51700 (LWP 2380)]
ok 11
ok 12 - tx count should be 1, with dbkey_scope = 1
[Thread 0x7fffed752700 (LWP 2379) exited]
ok 13
[Thread 0x7ffff4ce9700 (LWP 2376) exited]

Thread 7 "perl" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffece51700 (LWP 2380)]
0x00007fffef88e2c4 in ?? ()
(gdb)
(gdb) bt
#0  0x00007fffef88e2c4 in ?? ()
#1  0x0000000000000000 in ?? ()

(gdb) info threads
  Id   Target Id         Frame
  1    Thread 0x7ffff7ff02c0 (LWP 2371) "perl" __GI__dl_debug_state () at dl-debug.c:74
  2    Thread 0x7ffff54ea700 (LWP 2375) "perl" 0x00007ffff76c4577 in futex_abstimed_wait_cancelable (private=0,
    abstime=0x0, expected=0, futex_word=0x7ffff7fe0088) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
* 7    Thread 0x7fffece51700 (LWP 2380) "perl" 0x00007fffef88e2c4 in ?? ()

(gdb) thread 1
[Switching to thread 1 (Thread 0x7ffff7ff02c0 (LWP 2371))]
#0  __GI__dl_debug_state () at dl-debug.c:74
74  dl-debug.c: No such file or directory.
(gdb) bt
#0  __GI__dl_debug_state () at dl-debug.c:74
#1  0x00007ffff7dee9a7 in _dl_close_worker (map=<optimized out>, force=<optimized out>) at dl-close.c:490
#2  0x00007ffff7def39e in _dl_close (_map=0x555556078c90) at dl-close.c:822
#3  0x00007ffff7de9484 in _dl_catch_error (objname=0x555555b6dec0, errstring=0x555555b6dec8,
    mallocedp=0x555555b6deb8, operate=0x7ffff7bd6fb0 <dlclose_doit>, args=0x555556078c90) at dl-error.c:187
#4  0x00007ffff7bd7521 in _dlerror_run (operate=operate at entry=0x7ffff7bd6fb0 <dlclose_doit>,
    args=0x555556078c90) at dlerror.c:163
#5  0x00007ffff7bd6fdf in __dlclose (handle=<optimized out>) at dlclose.c:46
#6  0x00007ffff61f12d8 in DlfcnModule::~DlfcnModule (this=0x7ffff7fe2e08, __in_chrg=<optimized out>)
    at ./src/common/os/posix/mod_loader.cpp:113
#7  0x00007ffff61f1301 in DlfcnModule::~DlfcnModule (this=0x7ffff7fe2e08, __in_chrg=<optimized out>)
    at ./src/common/os/posix/mod_loader.cpp:114
#8  0x00007ffff6167546 in Firebird::SimpleDelete<ModuleLoader::Module>::clear (ptr=<optimized out>)
    at ./src/include/../common/classes/auto.h:45
#9  Firebird::AutoPtr<ModuleLoader::Module, Firebird::SimpleDelete<ModuleLoader::Module> >::~AutoPtr (
    this=0x7ffff7fe2b30, __in_chrg=<optimized out>) at ./src/include/../common/classes/auto.h:99
#10 (anonymous namespace)::PluginModule::~PluginModule (this=0x7ffff7fe2ae0, __in_chrg=<optimized out>)
    at ./src/yvalve/PluginManager.cpp:384
#11 0x00007ffff6167621 in (anonymous namespace)::PluginModule::~PluginModule (this=0x7ffff7fe2ae0,
    __in_chrg=<optimized out>) at ./src/yvalve/PluginManager.cpp:398
#12 0x00007ffff61465b9 in Firebird::RefCounted::release (this=<optimized out>)
    at ./src/include/../common/classes/RefCounted.h:46
#13 0x00007ffff61699de in Firebird::RefPtr<(anonymous namespace)::PluginModule>::~RefPtr (this=0x7ffff7fe32b8,
    __in_chrg=<optimized out>) at ./src/include/../common/classes/RefCounted.h:122
#14 (anonymous namespace)::ConfiguredPlugin::~ConfiguredPlugin (this=0x7ffff7fe3298, __in_chrg=<optimized out>)
    at ./src/yvalve/PluginManager.cpp:673
#15 0x00007ffff6169c68 in (anonymous namespace)::ConfiguredPlugin::~ConfiguredPlugin (this=0x7ffff7fe3298,
    __in_chrg=<optimized out>) at ./src/yvalve/PluginManager.cpp:692
#16 (anonymous namespace)::ConfiguredPlugin::release (this=0x7ffff7fe3298) at ./src/yvalve/PluginManager.cpp:721
---Type <return> to continue, or q <return> to quit---
#17 0x00007ffff6169ce9 in Firebird::ITimerBaseImpl<(anonymous namespace)::ConfiguredPlugin, Firebird::CheckStatus
Wrapper, Firebird::IReferenceCountedImpl<(anonymous namespace)::ConfiguredPlugin, Firebird::CheckStatusWrapper, F
irebird::Inherit<Firebird::IVersionedImpl<(anonymous namespace)::ConfiguredPlugin, Firebird::CheckStatusWrapper,
Firebird::Inherit<Firebird::ITimer> > > > >::cloopreleaseDispatcher (self=<optimized out>)
    at ./src/include/firebird/IdlFbInterfaces.h:12137
#18 0x00007ffff6113a1a in Firebird::IReferenceCounted::release (this=0x7ffff7fe32a0)
    at ./src/include/firebird/IdlFbInterfaces.h:169
#19 Why::(anonymous namespace)::TimerEntry::cleanup () at ./src/yvalve/MasterImplementation.cpp:217
#20 Firebird::InitMutex<Why::(anonymous namespace)::TimerEntry>::cleanup (
    this=0x7ffff6470290 <Why::(anonymous namespace)::timerHolder>) at ./src/include/../common/classes/init.h:191
#21 Why::shutdownTimers () at ./src/yvalve/MasterImplementation.cpp:404
#22 0x00007ffff613acdc in Why::Dispatcher::shutdown (this=this at entry=0x7ffff7fe2bb0,
    userStatus=userStatus at entry=0x7fffffffe8c0, timeout=timeout at entry=5000, reason=reason at entry=-7)
    at ./src/yvalve/why.cpp:5894
#23 0x00007ffff613bd05 in fb_shutdown (timeout=timeout at entry=5000, reason=reason at entry=-7)
    at ./src/yvalve/why.cpp:3725
#24 0x00007ffff6167268 in Firebird::PluginManager::unregisterModule (this=<optimized out>,
    cleanup=0x7ffff7f58578) at ./src/yvalve/PluginManager.cpp:1060
#25 0x00007ffff616e749 in Firebird::IPluginManagerBaseImpl<Firebird::PluginManager, Firebird::CheckStatusWrapper,
 Firebird::IVersionedImpl<Firebird::PluginManager, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IPlu
ginManager> > >::cloopunregisterModuleDispatcher (self=<optimized out>, cleanup=<optimized out>)
    at ./src/include/firebird/IdlFbInterfaces.h:6450
#26 0x00007fffeecc096b in Firebird::IPluginManager::unregisterModule (cleanup=0x7ffff7f58578,
    this=<optimized out>) at ./src/include/firebird/IdlFbInterfaces.h:804
#27 Firebird::UnloadDetectorHelper::~UnloadDetectorHelper (this=0x7ffff7f58570, __in_chrg=<optimized out>)
    at ./src/include/../common/classes/ImplementHelper.h:295
#28 Firebird::UnloadDetectorHelper::~UnloadDetectorHelper (this=0x7ffff7f58570, __in_chrg=<optimized out>)
    at ./src/include/../common/classes/ImplementHelper.h:298
#29 Firebird::GlobalPtr<Firebird::UnloadDetectorHelper, (Firebird::InstanceControl::DtorPriority)1>::dtor (
---Type <return> to continue, or q <return> to quit---
    this=0x7fffeeef0ea0 <(anonymous namespace)::myModule>) at ./src/include/../common/classes/init.h:124
#30 Firebird::InstanceControl::InstanceLink<Firebird::GlobalPtr<Firebird::UnloadDetectorHelper, (Firebird::Instan
ceControl::DtorPriority)1>, (Firebird::InstanceControl::DtorPriority)1>::dtor (this=0x7ffff7f585a8)
    at ./src/include/../common/classes/init.h:98
#31 0x00007fffeecc0cec in Firebird::InstanceControl::InstanceList::destructors ()
    at ./src/common/classes/init.cpp:231
#32 0x00007fffeecc0d96 in Firebird::InstanceControl::destructors () at ./src/common/classes/init.cpp:212
#33 0x00007fffeecc0efc in (anonymous namespace)::allClean () at ./src/common/classes/init.cpp:87
#34 (anonymous namespace)::Cleanup::~Cleanup (this=<optimized out>, __in_chrg=<optimized out>)
    at ./src/common/classes/init.cpp:118
#35 0x00007ffff734c920 in __run_exit_handlers (status=0, listp=0x7ffff76af5d8 <__exit_funcs>,
    run_list_atexit=run_list_atexit at entry=true, run_dtors=run_dtors at entry=true) at exit.c:83
#36 0x00007ffff734c97a in __GI_exit (status=<optimized out>) at exit.c:105
#37 0x000055555557f83f in main (argc=<optimized out>, argv=<optimized out>, env=<optimized out>)
    at perlmain.c:160

(gdb) thread 2
[Switching to thread 2 (Thread 0x7ffff54ea700 (LWP 2375))]
#0  0x00007ffff76c4577 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0,
    futex_word=0x7ffff7fe0088) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
205 ../sysdeps/unix/sysv/linux/futex-internal.h: No such file or directory.
(gdb) bt
#0  0x00007ffff76c4577 in futex_abstimed_wait_cancelable (private=0, abstime=0x0, expected=0,
    futex_word=0x7ffff7fe0088) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  do_futex_wait (sem=sem at entry=0x7ffff7fe0088, abstime=0x0) at sem_waitcommon.c:111
#2  0x00007ffff76c4624 in __new_sem_wait_slow (sem=0x7ffff7fe0088, abstime=0x0) at sem_waitcommon.c:181
#3  0x00007ffff76c46b9 in __new_sem_wait (sem=sem at entry=0x7ffff7fe0088) at sem_wait.c:29
#4  0x00007ffff61f5342 in Firebird::SignalSafeSemaphore::enter (this=0x7ffff7fe0088)
    at ./src/common/classes/semaphore.cpp:163
#5  0x00007ffff613c01d in (anonymous namespace)::shutdownThread () at ./src/yvalve/why.cpp:810
#6  0x00007ffff61cc60e in (anonymous namespace)::ThreadArgs::run (this=<synthetic pointer>)
    at ./src/common/ThreadStart.cpp:78
#7  (anonymous namespace)::threadStart (arg=0x7ffff7fe00c0) at ./src/common/ThreadStart.cpp:93
#8  0x00007ffff76bc464 in start_thread (arg=0x7ffff54ea700) at pthread_create.c:333
#9  0x00007ffff73ff9df in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:105

-- 
Niko