GOOPS method cache locking bug?

[Andreas Rottmann]

Hi!

I've found a bug (at least I think so) in the goops cache locking
code. I have written a C++ <-> Scripting language facility written
which works already with Python, and I'd like to support guile fully,
too. 

The code that produces the following backtrace loads a module (yehia)
that is built from C (or rather C++ ;-)) using the Goops API.

The loading goes well, but if the last line is added, I get the
deadlock illustrated by the following backtrace (all done with guile
1.7, quite recent CVS checkout).  

Probably I should point out that the (load-plugin pm "gql") method
call results in loading a C++ plugin that builds up another guile also
containing classes and methods built with the Goops C API. It seems
the GOOPS method cache should use a recursive mutex, but doesn't. I'll
try to patch it too use a recursive mutex and then see if that fixes
it.


simple.scm:
------------
(use-modules ((yehia) :select (<PluginManager> instance load-plugin)))
 
(define pm (instance <PluginManager>))
(load-plugin pm "gql")
-----------------


Backtrace:
----------
#0  0x4025eae2 in sigsuspend () from /lib/libc.so.6
#1  0x400f0f35 in __pthread_wait_for_restart_signal ()
   from /lib/libpthread.so.0
#2  0x400f24c2 in __pthread_lock () from /lib/libpthread.so.0
#3  0x400ef928 in pthread_mutex_lock () from /lib/libpthread.so.0
#4  0x400792fa in scm_mutex_lock (m=0x8093308) at threads.c:1070
#5  0x40078b70 in scm_lock_mutex (mx=0x4037c930) at threads.c:737
#6  0x400508bf in lock_cache_mutex (m=0x4037c930) at goops.c:2047
#7  0x40036f0b in scm_internal_dynamic_wind (
    before=0x400508a4 <lock_cache_mutex>, 
    inner=0x400508e4 <call_memoize_method>, 
    after=0x400508c4 <unlock_cache_mutex>, inner_data=0x40387758, 
    guard_data=0x4037c930) at dynwind.c:164
#8  0x400509ab in scm_memoize_method (x=0x4037da88, args=0x40387780)
    at goops.c:2077
#9  0x4003e00c in scm_ceval (x=0x4037da88, env=0x40387790) at eval.c:2542
#10 0x4003e841 in scm_ceval (x=0x40551ed0, env=0x40387790) at eval.c:2265
#11 0x4003e841 in scm_ceval (x=0x40551db0, env=0x40387860) at eval.c:2265
#12 0x4004041d in scm_apply (proc=0x40544ad8, arg1=0x2974, args=0x403878f0)
    at eval.c:3686
#13 0x4003fd66 in scm_call_3 (proc=0x40544b30, arg1=0x4050b440, 
    arg2=0x40387a20, arg3=0x40532578) at eval.c:3351
#14 0x40050959 in call_memoize_method (a=0x40387a10) at goops.c:2070
#15 0x40036f9a in scm_internal_dynamic_wind (
    before=0x400508a4 <lock_cache_mutex>, 
    inner=0x400508e4 <call_memoize_method>, 
    after=0x400508c4 <unlock_cache_mutex>, inner_data=0x40387a10, 
    guard_data=0x405323c0) at dynwind.c:168
#16 0x400509ab in scm_memoize_method (x=0x40532578, args=0x40387a20)
    at goops.c:2077
#17 0x4003e00c in scm_ceval (x=0x40532578, env=0x40387a30) at eval.c:2542
#18 0x4003e841 in scm_ceval (x=0x40551d20, env=0x40387a30) at eval.c:2265
#19 0x4004041d in scm_apply (proc=0x40544ad8, arg1=0x2974, args=0x40387a30)
    at eval.c:3686
#20 0x4003fd66 in scm_call_3 (proc=0x40544b30, arg1=0x4050fed0, 
    arg2=0x40387ab0, arg3=0x4037da88) at eval.c:3351
#21 0x40050959 in call_memoize_method (a=0x40387aa0) at goops.c:2070
#22 0x40036f9a in scm_internal_dynamic_wind (
    before=0x400508a4 <lock_cache_mutex>, 
    inner=0x400508e4 <call_memoize_method>, 
    after=0x400508c4 <unlock_cache_mutex>, inner_data=0x40387aa0, 
    guard_data=0x4037c930) at dynwind.c:168
#23 0x400509ab in scm_memoize_method (x=0x4037da88, args=0x40387ab0)
    at goops.c:2077
#24 0x4003e00c in scm_ceval (x=0x4037da88, env=0x40387ab8) at eval.c:2542
#25 0x4003e841 in scm_ceval (x=0x40551ed0, env=0x40387ab8) at eval.c:2265
#26 0x4003e841 in scm_ceval (x=0x40551db0, env=0x40387b28) at eval.c:2265
#27 0x4004041d in scm_apply (proc=0x40544ad8, arg1=0x2974, args=0x40387c08)
    at eval.c:3686
#28 0x4003fd66 in scm_call_3 (proc=0x40544b30, arg1=0x4050d300, 
    arg2=0x40387c80, arg3=0x4039e780) at eval.c:3351
#29 0x40050959 in call_memoize_method (a=0x40387c70) at goops.c:2070
#30 0x40036f9a in scm_internal_dynamic_wind (
    before=0x400508a4 <lock_cache_mutex>, 
    inner=0x400508e4 <call_memoize_method>, 
    after=0x400508c4 <unlock_cache_mutex>, inner_data=0x40387c70, 
    guard_data=0x4039b078) at dynwind.c:168
#31 0x400509ab in scm_memoize_method (x=0x4039e780, args=0x40387c80)
    at goops.c:2077
#32 0x40063aba in scm_mcache_compute_cmethod (cache=0x4039e780, 
    args=0x40387c80) at objects.c:320
#33 0x40063ae3 in scm_apply_generic (gf=0xfffffffc, args=0x40387c80)
    at objects.c:327
#34 0x4004030d in scm_apply (proc=0x4050d300, arg1=0x4050fde0, args=0x40387c80)
    at eval.c:3725
#35 0x4003fcf3 in scm_call_1 (proc=0x4050d300, arg1=0x4050fde0) at eval.c:3339
#36 0x4004d2f0 in compute_cpl (class=0x1) at goops.c:214
#37 0x4004de2d in scm_basic_basic_make_class (class=0x4050fdf0, 
    name=0x40345000, dsupers=0x40385720, dslots=0x40387d00) at goops.c:628
#38 0x4004df67 in scm_basic_make_class (class=0x4050fdf0, name=0x40387cf8, 
    dsupers=0x40385720, dslots=0x40387d00) at goops.c:668
#39 0x404a7dde in 
Yehia::Script::guileObjectFactory::create_class(std::list<std::type_info 
const*, std::allocator<std::type_info const*> > const&) (
    this=0x8072ae4, address@hidden) at guile-script.cc:210
#40 0x403dc8df in ClassBuilder_ (this=0xbfffec40, address@hidden, 
    address@hidden, address@hidden, address@hidden)
    at classbuilder.cc:39
#41 0x4058a239 in ClassBuilder (this=0xbfffec40, address@hidden, 
    address@hidden, address@hidden, address@hidden)
    at /home/andy/include/yehia-0.5/yehia/script/class-builder.h:77
#42 0x40584eb3 in (anonymous 
namespace)::yehia_ns_gql_register(Yehia::Script::Language&) (address@hidden) at 
gql.cc:73
#43 0x404f877e in SigC::FuncSlot1_<void, 
Yehia::Script::Language&>::proxy(Yehia::Script::Language&, void*) 
(address@hidden, s=0x8084e30)
    at /usr/include/sigc++-1.2/sigc++/slot.h:93
#44 0x404f81cb in SigC::Slot1<void, 
Yehia::Script::Language&>::operator()(Yehia::Script::Language&) 
(this=0xbfffee30, address@hidden)
    at /usr/include/sigc++-1.2/sigc++/slot.h:239
#45 0x404f768b in void SigCX::tunnel<void, 
Yehia::Script::Language&>(SigC::Slot1<void, Yehia::Script::Language&>, 
Yehia::Script::Language&, SigCX::Tunnel*, bool) (s=
          {<SlotBase> = {<Node> = {node_ = 0x8084e30}, <No data fields>}, <No 
data fields>}, address@hidden, tunnel=0x0, sync=false)
    at /home/andy/include/sigcx-0.6/sigcx/tunnel.h:283
#46 0x405a4cb1 in gqlPlugin (this=0x8090f30, address@hidden) at gql.cc:175
#47 0x40589a22 in yehia_gql_plugin_init (mgr=0x806fb48) at gql.cc:195
#48 0x403cf927 in Yehia::ShLibPluginLoader::load(Yehia::PluginManager&, 
std::string const&) (this=0x80714a0, address@hidden, address@hidden) at 
plugin.cc:318
#49 0x403ce46f in Yehia::PluginManager::load_plugin(std::string const&) (
    this=0x806fb48, address@hidden) at plugin.cc:115
#50 0x404e58ea in SigC::MethodSlot1_<Yehia::Plugin*, Yehia::PluginManager, 
std::string const&>::proxy(Yehia::PluginManager&, std::string const&, void*) (
    address@hidden, address@hidden, s=0x80896b0)
    at /usr/include/sigc++-1.2/sigc++/method_slot.h:103
#51 0x404f0710 in SigC::Slot2<Yehia::Plugin*, Yehia::PluginManager&, 
std::string const&>::operator()(Yehia::PluginManager&, std::string const&) (
    this=0x8084ec4, address@hidden, address@hidden)
    at /usr/include/sigc++-1.2/sigc++/slot.h:283
#52 0x404eb1a2 in Yehia::Script::MarshalWrapper2<Yehia::Plugin*, 
Yehia::PluginManager&, std::string 
const&>::unmarshal(SigC::Slot2<Yehia::Plugin*, Yehia::PluginManager&, 
std::string const&>&, std::list<Yehia::Script::Any, 
std::allocator<Yehia::Script::Any> > const&) (address@hidden, address@hidden)
    at ../../yehia/script/slot-convert.h:199
#53 0x404f084b in SigCX::AdaptorConvertSlot1_<Yehia::Script::Any, 
std::list<Yehia::Script::Any, std::allocator<Yehia::Script::Any> > const&, 
SigC::Slot2<Yehia::Plugin*, Yehia::PluginManager&, std::string const&> 
>::proxy(std::list<Yehia::Script::Any, std::allocator<Yehia::Script::Any> > 
const&, void*) (
    address@hidden, data=0x8084eb0)
    at /home/andy/include/sigcx-0.6/sigcx/convert.h:80
#54 0x403df25c in SigC::Slot1<Yehia::Script::Any, std::list<Yehia::Script::Any, 
std::allocator<Yehia::Script::Any> > 
const&>::operator()(std::list<Yehia::Script::Any, 
std::allocator<Yehia::Script::Any> > const&) (this=0x80897bc, 
    address@hidden) at /usr/include/sigc++-1.2/sigc++/slot.h:239
#55 0x403dec5e in 
Yehia::Script::LangConvertSlotNode::from_script_proxy(std::list<Yehia::Script::Object*,
 std::allocator<Yehia::Script::Object*> > const&, void*) (address@hidden, 
data=0x80897a8) at slotconv.cc:58
#56 0x403df525 in SigC::Slot1<Yehia::Script::Object*, 
std::list<Yehia::Script::Object*, std::allocator<Yehia::Script::Object*> > 
const&>::operator()(std::list<Yehia::Script::Object*, 
std::allocator<Yehia::Script::Object*> > const&) (
    this=0x80778f0, address@hidden)
    at /usr/include/sigc++-1.2/sigc++/slot.h:239
#57 0x404aadc2 in Yehia::Script::(anonymous 
namespace)::slotsmob_apply(scm_unused_struct*, scm_unused_struct*) 
(smob=0x40533b00, args=0x2974)
    at guile-script.cc:1014
#58 0x4006f292 in scm_smob_apply_2_001 (smob=0x40533b00, a1=0x4050edd0, 
    a2=0x40549f90) at smob.c:234
#59 0x4003e119 in scm_ceval (x=0x2974, env=0x40549240) at eval.c:3048
#60 0x40041647 in scm_i_eval_x (exp=0xfffffffc, env=0x40549f80) at eval.c:4409
#61 0x400416ed in scm_primitive_eval_x (exp=0x40549fa0) at eval.c:4426
#62 0x40058dc0 in load (data=0x4037fda8) at load.c:98
#63 0x40036f9a in scm_internal_dynamic_wind (before=0x40058d48 <swap_port>, 
    inner=0x40058d90 <load>, after=0x40058d48 <swap_port>, 
    inner_data=0x4037fda8, guard_data=0xbffff468) at dynwind.c:168
#64 0x40058e6c in scm_primitive_load (filename=0x40380858) at load.c:127
#65 0x4003dd88 in scm_ceval (x=0x2974, env=0x4037fe60) at eval.c:2905
#66 0x4004169f in scm_i_eval (exp=0x40549f80, env=0x4037fe60) at eval.c:4416
#67 0x40036734 in scm_start_stack (id=0x40549f80, exp=0x4035a840, 
    env=0x4037fe60) at debug.c:505
#68 0x400367ac in scm_m_start_stack (exp=0x40345000, env=0x8) at debug.c:521
#69 0x40040074 in scm_apply (proc=0x403581f0, arg1=0x4037fe58, args=0x4037fe48)
    at eval.c:3566
#70 0x4003fa9d in scm_ceval (x=0x4037fe58, env=0x4037fe60) at eval.c:2729
#71 0x4004041d in scm_apply (proc=0x40380330, arg1=0x2974, args=0x4037ff20)
    at eval.c:3686
#72 0x4003fcc5 in scm_call_0 (proc=0x40380310) at eval.c:3333
#73 0x40036e53 in scm_dynamic_wind (in_guard=0x403800e8, thunk=0x40380310, 
    out_guard=0x403800b8) at dynwind.c:128
#74 0x4003dd88 in scm_ceval (x=0x40375f58, env=0x40380128) at eval.c:2905
#75 0x4003dad9 in scm_ceval (x=0x40380840, env=0x40380380) at eval.c:1994
#76 0x40041647 in scm_i_eval_x (exp=0x400401d9, env=0x40380380) at eval.c:4409
#77 0x400416ed in scm_primitive_eval_x (exp=0x403803a0) at eval.c:4426
#78 0x400417df in inner_eval_x (data=0x403803a0) at eval.c:4473
#79 0x40036f9a in scm_internal_dynamic_wind (
    before=0x4004175c <change_environment>, inner=0x400417c4 <inner_eval_x>, 
    after=0x40041790 <restore_environment>, inner_data=0x403803a0, 
    guard_data=0x40380398) at dynwind.c:168
#80 0x4004183b in scm_eval_x (exp=0x403803a0, module=0x40345000) at eval.c:4482
#81 0x4006eb2b in scm_shell (argc=3, argv=0xbffff994) at script.c:692
#82 0x0804859c in inner_main (closure=0x0, argc=3, argv=0xbffff994)
    at guile-interpreter.cc:22
#83 0x40056d8c in invoke_main_func (body_data=0x403803a0) at init.c:626
#84 0x40056d48 in scm_boot_guile_1 (base=0xbffff8fc, closure=0xbffff900)
    at init.c:606
#85 0x40056a43 in scm_boot_guile (argc=1077412768, argv=0x403803a0, 
    main_func=0x403803a0, closure=0x403803a0) at init.c:423
#86 0x080485c4 in main (argc=3, argv=0xbffff994) at guile-interpreter.cc:27

Regards, Andy
-- 
Andreas Rottmann         | address@hidden      | address@hidden | address@hidden
http://www.8ung.at/rotty | GnuPG Key: http://www.8ung.at/rotty/gpg.asc
Fingerprint              | DFB4 4EB4 78A4 5EEE 6219  F228 F92F CFC5 01FD 5B62

Make free software, not war!