Test failure in `test_python_rule_engine_plugin.Test_Python_Rule_Engine_Plugin.test_python_continuation_to_native_58`

[SwooshyCueb]

#236 on irods/irods#8366 test failure in test_python_rule_engine_plugin.Test_Python_Rule_Engine_Plugin.test_python_continuation_to_native_58:

Traceback (most recent call last):
  File "/var/lib/irods/scripts/irods/test/test_python_rule_engine_plugin.py", line 70, in test_python_continuation_to_native_58
    with append_native_re_to_server_config():
  File "/usr/lib/python3.12/contextlib.py", line 137, in __enter__
    return next(self.gen)
           ^^^^^^^^^^^^^^
  File "/var/lib/irods/scripts/irods/test/test_python_rule_engine_plugin.py", line 48, in append_native_re_to_server_config
    IrodsController().reload_configuration()
  File "/var/lib/irods/scripts/irods/controller.py", line 166, in reload_configuration
    self.wait_for_server_to_start()
  File "/var/lib/irods/scripts/irods/controller.py", line 212, in wait_for_server_to_start
    if self.is_server_listening_for_client_requests():
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/irods/scripts/irods/controller.py", line 198, in is_server_listening_for_client_requests
    message = s.recv(256)
              ^^^^^^^^^^^
ConnectionResetError: [Errno 104] Connection reset by peer

Full test logs: https://gist.github.com/SwooshyCueb/753e21ff85d06bd6188450fa7ea5b50d

Test run on Ubuntu 24.04 with Postgres 16 using the testing environment.

[korydraughn]

I have not been able to reproduce this failure.

I've seen the test pass against ub22, ub24 + pg16 multiple times now.

Additional Info:

• Used debug build of server and icommands
• Used release build of PREP (build_hook does not contain debug option)
• irods SHA: dac3cf1782143456046797298fbba617f4724c2c
• icommands SHA: 590467f9648c9ed45103fc61a6ae496bc859b790
• PREP SHA: c8752dd

Did you see failures across multiple runs?
Is there anything you can think of that I may have missed?

[SwooshyCueb]

I was using a debug build of PREP. That's the only difference I can think of. The failures were consistent across multiple runs.

[korydraughn]

Okay. I will work on producing a debug build and see if that produces the failures.

[korydraughn]

The debug build was the key. Investigating.

[korydraughn]

gdb is reporting a segfault.

Thread 2.1 "irodsAgent" received signal SIGSEGV, Segmentation fault.
0x00007f40377ccc31 in (anonymous namespace)::python_thread_state_scope::python_thread_state_scope (this=0x7ffc26126a00) at /mnt/hdd_3tb/github/irods_rule_engine_plugin_python/src/main.cpp:254
254                                     python_state::ts_thread = PyThreadState_New(python_state::ts_main->interp);

(gdb) bt
#0  0x00007f40377ccc31 in (anonymous namespace)::python_thread_state_scope::python_thread_state_scope (this=0x7ffc26126a00) at /mnt/hdd_3tb/github/irods_rule_engine_plugin_python/src/main.cpp:254
#1  0x00007f40377bebdc in rule_exists(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&) (rule_name="pep_network_read_header_pre", _return=@0x7ffc2612707f: false) at /mnt/hdd_3tb/github/irods_rule_engine_plugin_python/src/main.cpp:518
#2  0x00007f4037869608 in std::__invoke_impl<irods::error, irods::error (*&)(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&), std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&>(std::__invoke_other, irods::error (*&)(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&), std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&) (__f=@0x7ffc26126e38: 0x7f40377beb90 <rule_exists(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)>, 
    __args=@0x7ffc2612707f: false, __args=@0x7ffc2612707f: false, __args=@0x7ffc2612707f: false) at /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61
#3  0x00007f4037869588 in std::__invoke_r<irods::error, irods::error (*&)(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&), std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&>(irods::error (*&)(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&), std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&) (__fn=@0x7ffc26126e38: 0x7f40377beb90 <rule_exists(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)>, __args=@0x7ffc2612707f: false, 
    __args=@0x7ffc2612707f: false, __args=@0x7ffc2612707f: false) at /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:114
#4  0x00007f4037869478 in std::_Function_handler<irods::error (std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&), irods::error (*)(std::tuple<> const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)>::_M_invoke(std::_Any_data const&, std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&) (__functor=..., __args=@0x7ffc2612707f: false, __args=@0x7ffc2612707f: false, __args=@0x7ffc2612707f: false) at /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_function.h:290
#5  0x00007f403c2c1bd0 in std::function<irods::error (std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)>::operator()(std::tuple<>&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&) const (this=0x7ffc26126e38, __args=@0x7ffc2612707f: false, __args=@0x7ffc2612707f: false, 
    __args=@0x7ffc2612707f: false) at /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_function.h:590
#6  0x00007f403c2c11cd in irods::pluggable_rule_engine<std::tuple<> >::rule_exists(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::tuple<>&, bool&) (this=0x55fa612deb50, _rn="pep_network_read_header_pre", _re_ctx=empty std::tuple, _out=@0x7ffc2612707f: false)
    at /mnt/hdd_3tb/github/irods/server/re/include/irods/irods_re_plugin.hpp:257
#7  0x00007f403c2c0c3d in irods::control<irods::rule_exists_manager<std::tuple<>, RuleExecInfo*>::rule_exists(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)::{lambda(irods::re_pack_inp<std::tuple<> >&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)#1}, irods::rule_exists_manager<std::tuple<>, RuleExecInfo*>::rule_exists(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)::{lambda(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)#1}, std::tuple<>>(std::__cxx11::list<irods::re_pack_inp<std::tuple<> >, std::allocator<irods::re_pack_inp<std::tuple<> > > >&, irods::rule_exists_manager<std::tuple<>, RuleExecInfo*>::rule_exists(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)::{lambda(irods::re_pack_inp<std::tuple<> >&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)#1}, irods::rule_exists_manager<std::tuple<>, RuleExecInfo*>::rule_exists(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&)::{lambda(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)#1}, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) (_re_packs=std::__cxx11::list = {...}, _er=..., _em=..., _rn="pep_network_read_header_pre")
    at /mnt/hdd_3tb/github/irods/server/re/include/irods/irods_re_plugin.hpp:541
#8  0x00007f403c2bffdc in irods::rule_exists_manager<std::tuple<>, RuleExecInfo*>::rule_exists(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool&) (this=0x7ffc261285d0, _rn="pep_network_read_header_pre", ret=@0x7ffc26127777: false) at /mnt/hdd_3tb/github/irods/server/re/include/irods/irods_re_plugin.hpp:587
#9  0x00007f403c2d961b in irods::plugin_base::invoke_policy_enforcement_point<void*, timeval*>(irods::rule_engine_context_manager<std::tuple<>, RuleExecInfo*, (irods::rule_execution_manager_pack)0>, irods::plugin_context&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, void*, timeval*) (this=0x55fa6180ee60, _re_ctx_mgr=..., _ctx=..., _out_param=0x7ffc2612bcc8, _operation_name="network_read_header", _class="pre", _t=0x7ffc26131ef0, _t=0x7ffc26131ef0) at /mnt/hdd_3tb/github/irods/lib/core/include/irods/irods_plugin_base.hpp:391
#10 0x00007f403c2b497d in irods::plugin_base::call<void*, timeval*> (this=0x55fa6180ee60, _comm=0x0, _operation_name="network_read_header", _fco=..., _t=0x7ffc26131ef0, _t=0x7ffc26131ef0) at /mnt/hdd_3tb/github/irods/lib/core/include/irods/irods_plugin_base.hpp:202
#11 0x00007f403c2a7390 in readMsgHeader (_ptr=..., _header=0x7ffc2612d198, _time_val=0x7ffc26131ef0) at /mnt/hdd_3tb/github/irods/lib/core/src/sockComm.cpp:209
#12 0x00007f403c9173a0 in readStartupPack (_ptr=..., startupPack=0x7ffc26131f10, tv=0x7ffc26131ef0) at /mnt/hdd_3tb/github/irods/server/core/src/miscServerFunct.cpp:2419
#13 0x000055fa4dc81014 in (anonymous namespace)::handle_client_request (_socket_fd=6, _created_at=1746808723) at /mnt/hdd_3tb/github/irods/server/main_server/src/agent_main.cpp:781
#14 0x000055fa4dc7e038 in main (_argc=6, _argv=0x7ffc26138128) at /mnt/hdd_3tb/github/irods/server/main_server/src/agent_main.cpp:400

[korydraughn]

I think what's happening here is rule_exists is being invoked before the PREP runs start. The start function is responsible for initializing the ts_main pointer.

The REPF is calling rule_exists for network PEPs before initializing the PREP via the start function.

[SwooshyCueb]

That's not great.

[korydraughn]

Agreed. Moving the invocation of the plugin start operations resolves this.

See irods/irods#8503 for the current fix.

[trel]

awesome