Issues Updating to 4.2.10

[kript]

Hi folks,

Following on from The MR to make the docker image run standalone, I tried to bring up the entire docker-compose set, having just removed the update-mtime-collection package after it was rolled into 4.2.9 as per https://github.com/irods/irods/issues/5752 ;

$ git diff HEAD irods/Dockerfile
diff --git a/irods/Dockerfile b/irods/Dockerfile
index a672a01..76d40d5 100644
--- a/irods/Dockerfile
+++ b/irods/Dockerfile
@@ -18,7 +18,7 @@ RUN wget -qO - https://packages.irods.org/irods-signing-key.asc | apt-key add -;
     echo "deb [arch=amd64] https://packages.irods.org/apt/ $(lsb_release -sc) main" | tee /etc/apt/sources.list.d/renci-irods.list; \
     apt-get update
 RUN DEBIAN_FRONTEND=noninteractive \
-    apt-get install -y irods-runtime irods-icommands irods-server irods-database-plugin-postgres irods-rule-engine-plugin-audit-amqp irods-rule-engine-plugin-update-collection-mtime irods-rule-engine-plugin-unified-storage-tiering
+    apt-get install -y irods-runtime irods-icommands irods-server irods-database-plugin-postgres irods-rule-engine-plugin-audit-amqp irods-rule-engine-plugin-unified-storage-tiering
 COPY configure_audit_plugin.py /var/lib/irods/scripts/
 COPY configure_update_collection_mtime_plugin.py /var/lib/irods/scripts/
 COPY configure_unified_storage_tiering_plugin.py /var/lib/irods/scripts/

While the image built (the entire docker compose did not complete due to #22 the irods_demo_irods-catalog-provider image did build.

Attempting to run it standalone with docker run --shm-size=512m <imageid>, I got several errors;

 * Starting PostgreSQL 10 database server
   ...done.
Postgres took approximately 0 seconds to fully start ...
Warning: Hostname `d8c1c66b2fbf` should be a fully qualified domain name.
iRODS user [irods]: 
iRODS group [irods]: 
iRODS server's role:
1. provider
2. consumer
Please select a number or choose 0 to enter a new value [1]: 
ODBC driver for postgres:
1. PostgreSQL ANSI
2. PostgreSQL Unicode
Please select a number or choose 0 to enter a new value [1]: 
Database server's hostname or IP address [localhost]: 
Database server's port [5432]: 
Database name [ICAT]: 
Database username [irods]: 

-------------------------------------------
Database Type: postgres
ODBC Driver:   PostgreSQL ANSI
Database Host: localhost
Database Port: 5432
Database Name: ICAT
Database User: irods
-------------------------------------------

Please confirm [yes]: Warning: Cannot control echo output on the terminal (stdin is not a tty). Input may be echoed.
Warning: Cannot control echo output on the terminal (stdin is not a tty). Input may be echoed.

iRODS server's zone name [tempZone]: 
iRODS server's port [1247]: 
iRODS port range (begin) [20000]: 
iRODS port range (end) [20199]: 
Control Plane port [1248]: 
Schema Validation Base URI (or off) [file:///var/lib/irods/configuration_schemas]: 
iRODS server's administrator username [rods]: 

-------------------------------------------
Zone name:                  tempZone
iRODS server port:          1247
iRODS port range (begin):   20000
iRODS port range (end):     20199
Control plane port:         1248
Schema validation base URI: file:///var/lib/irods/configuration_schemas
iRODS server administrator: rods
-------------------------------------------

Please confirm [yes]: Warning: Cannot control echo output on the terminal (stdin is not a tty). Input may be echoed.
Warning: Cannot control echo output on the terminal (stdin is not a tty). Input may be echoed.
Warning: Cannot control echo output on the terminal (stdin is not a tty). Input may be echoed.
Warning: Cannot control echo output on the terminal (stdin is not a tty). Input may be echoed.

iRODS Vault directory [/var/lib/irods/Vault]: 
 --- IrodsSession: icommand executed by [rods] [iinit rods] --- 
Assert Command: iinit rods
Expecting EMPTY: ['']
  stdout:
    | 
  stderr:
    |  ERROR: _rcConnect: connectToRhost error, server on d8c1c66b2fbf:1247 is probably down status = -305111 USER_SOCK_CONNECT_ERR, Connection refused
    |  ERROR: Saved password, but failed to connect to server d8c1c66b2fbf
Unexpected output on stderr

FAILED TESTING ASSERTION

Traceback (most recent call last):
  File "configure_unified_storage_tiering_plugin.py", line 21, in <module>
    rods = session.make_session_for_existing_admin()
  File "/var/lib/irods/scripts/irods/test/session.py", line 37, in make_session_for_existing_admin
    return IrodsSession(env_dict, test.settings.PREEXISTING_ADMIN_PASSWORD, False)
  File "/var/lib/irods/scripts/irods/test/session.py", line 103, in __init__
    self.assert_icommand(['iinit', self._password])
  File "/var/lib/irods/scripts/irods/test/session.py", line 159, in assert_icommand
    return assert_command(*args, **kwargs)
  File "/var/lib/irods/scripts/irods/test/command.py", line 77, in assert_command
    return _assert_helper(*args, should_fail=False, **kwargs)
  File "/var/lib/irods/scripts/irods/test/command.py", line 105, in _assert_helper
    assert result
AssertionError
 --- IrodsSession: icommand executed by [rods] [iinit rods] --- 
Assert Command: iinit rods
Expecting EMPTY: ['']
  stdout:
    | 
  stderr:
    |  ERROR: _rcConnect: connectToRhost error, server on d8c1c66b2fbf:1247 is probably down status = -305111 USER_SOCK_CONNECT_ERR, Connection refused
    |  ERROR: Saved password, but failed to connect to server d8c1c66b2fbf
Unexpected output on stderr

FAILED TESTING ASSERTION

Traceback (most recent call last):
  File "configure_users.py", line 10, in <module>
    rods = session.make_session_for_existing_admin()
  File "/var/lib/irods/scripts/irods/test/session.py", line 37, in make_session_for_existing_admin
    return IrodsSession(env_dict, test.settings.PREEXISTING_ADMIN_PASSWORD, False)
  File "/var/lib/irods/scripts/irods/test/session.py", line 103, in __init__
    self.assert_icommand(['iinit', self._password])
  File "/var/lib/irods/scripts/irods/test/session.py", line 159, in assert_icommand
    return assert_command(*args, **kwargs)
  File "/var/lib/irods/scripts/irods/test/command.py", line 77, in assert_command
    return _assert_helper(*args, should_fail=False, **kwargs)
  File "/var/lib/irods/scripts/irods/test/command.py", line 105, in _assert_helper
    assert result
AssertionError
Aug 15 17:28:33 pid:142 NOTICE: Initializing server ...
Aug 15 17:28:33 pid:142 NOTICE: Forking agent factory ...
Aug 15 17:28:33 pid:142 NOTICE: Agent factory PID = [143]
Aug 15 17:28:33 pid:143 NOTICE: Initializing agent factory ...
Aug 15 17:28:33 pid:142  ERROR: [-] /irods/server/re/include/irods_re_plugin.hpp:362:irods::error irods::rule_engine_plugin_manager<std::__1::tuple<> >::resolve(std::string &, const std::string &, pluggable_rule_engine<T> *&) [T = std::__1::tuple<>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
    [-] /irods/lib/core/include/irods_load_plugin.hpp:157:irods::error irods::load_plugin(PluginType *&, const std::string &, const std::string &, const std::string &, const Ts &...) [PluginType = irods::pluggable_rule_engine<std::__1::tuple<> >, Ts = <std::__1::basic_string<char>>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]

Aug 15 17:28:33 pid:142  ERROR: [-] /irods/server/re/include/irods_re_plugin.hpp:387:auto irods::rule_engine_manager<std::__1::tuple<>, RuleExecInfo *>::rule_engine_manager(rule_engine_plugin_manager<std::__1::tuple<> > &, std::vector<re_pack_inp<tuple<> > > &, microservice_manager<RuleExecInfo *> &)::(anonymous class)::operator()(re_pack_inp<T> &) const [T = std::__1::tuple<>, C = RuleExecInfo *] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
    [-] /irods/server/re/include/irods_re_plugin.hpp:401:irods::error irods::rule_engine_manager<std::__1::tuple<>, RuleExecInfo *>::init_rule_engine(re_pack_inp<T> &) [T = std::__1::tuple<>, C = RuleExecInfo *] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
        [-] /irods/lib/core/include/irods_load_plugin.hpp:157:irods::error irods::load_plugin(PluginType *&, const std::string &, const std::string &, const std::string &, const Ts &...) [PluginType = irods::pluggable_rule_engine<std::__1::tuple<> >, Ts = <std::__1::basic_string<char>>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]

    LocalHostName:  localhost, d8c1c66b2fbf, Port Num: 1247.

Zone Info:
    ZoneName: tempZone   Type: LOCAL_ICAT    HostAddr: localhost   PortNum: 1247

reHost:   localhost

Aug 15 17:28:33 pid:142 NOTICE: rodsServer Release version rods4.2.10 - API Version d is up
Aug 15 17:28:33 pid:142 NOTICE: Forking Rule Execution Server (irodsReServer) ...
Aug 15 17:28:33 pid:142 NOTICE: >>> control plane :: listening on port 1248

I found that while the server appears to have started, in fact, the server is very slow, even in responding to basic commands like ils etc, even if a connection is made from within the container;

sudo docker exec -ti d8c1c66b2fbf /bin/bash
irods@d8c1c66b2fbf:~$ time ils
/tempZone/home/rods:

real    0m21.245s
user    0m0.018s
sys 0m0.015s

running strace shows lots of errors like;

stat("/opt/irods-externals/clang-runtime6.0-0/lib/tls/haswell/x86_64", 0x7ffd79e2e030) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/opt/irods-externals/clang-runtime6.0-0/lib/tls/haswell/libirods_client.so.4.2.10", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)

rodsLog has similar;

irods@d8c1c66b2fbf:~/log$ cat rodsLog.2021.08.11 
 --- IrodsSession: icommand executed by [rods] [iinit rods] --- 
 --- IrodsSession: icommand executed by [rods] [iinit rods] --- 
Aug 15 17:28:33 pid:160 remote addresses: 172.17.0.2 ERROR: [-] /irods/server/re/include/irods_re_plugin.hpp:362:irods::error irods::rule_engine_plugin_manager<std::__1::tuple<> >::resolve(std::string &, const std::string &, pluggable_rule_engine<T> *&) [T = std::__1::tuple<>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
    [-] /irods/lib/core/include/irods_load_plugin.hpp:157:irods::error irods::load_plugin(PluginType *&, const std::string &, const std::string &, const std::string &, const Ts &...) [PluginType = irods::pluggable_rule_engine<std::__1::tuple<> >, Ts = <std::__1::basic_string<char>>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]

Aug 15 17:28:33 pid:160 remote addresses: 172.17.0.2 ERROR: [-] /irods/server/re/include/irods_re_plugin.hpp:387:auto irods::rule_engine_manager<std::__1::tuple<>, RuleExecInfo *>::rule_engine_manager(rule_engine_plugin_manager<std::__1::tuple<> > &, std::vector<re_pack_inp<tuple<> > > &, microservice_manager<RuleExecInfo *> &)::(anonymous class)::operator()(re_pack_inp<T> &) const [T = std::__1::tuple<>, C = RuleExecInfo *] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
    [-] /irods/server/re/include/irods_re_plugin.hpp:401:irods::error irods::rule_engine_manager<std::__1::tuple<>, RuleExecInfo *>::init_rule_engine(re_pack_inp<T> &) [T = std::__1::tuple<>, C = RuleExecInfo *] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
        [-] /irods/lib/core/include/irods_load_plugin.hpp:157:irods::error irods::load_plugin(PluginType *&, const std::string &, const std::string &, const std::string &, const Ts &...) [PluginType = irods::pluggable_rule_engine<std::__1::tuple<> >, Ts = <std::__1::basic_string<char>>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]

Aug 15 17:29:14 pid:163 remote addresses: 172.17.0.2 ERROR: [-] /irods/server/re/include/irods_re_plugin.hpp:362:irods::error irods::rule_engine_plugin_manager<std::__1::tuple<> >::resolve(std::string &, const std::string &, pluggable_rule_engine<T> *&) [T = std::__1::tuple<>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
    [-] /irods/lib/core/include/irods_load_plugin.hpp:157:irods::error irods::load_plugin(PluginType *&, const std::string &, const std::string &, const std::string &, const Ts &...) [PluginType = irods::pluggable_rule_engine<std::__1::tuple<> >, Ts = <std::__1::basic_string<char>>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]

Aug 15 17:29:14 pid:163 remote addresses: 172.17.0.2 ERROR: [-] /irods/server/re/include/irods_re_plugin.hpp:387:auto irods::rule_engine_manager<std::__1::tuple<>, RuleExecInfo *>::rule_engine_manager(rule_engine_plugin_manager<std::__1::tuple<> > &, std::vector<re_pack_inp<tuple<> > > &, microservice_manager<RuleExecInfo *> &)::(anonymous class)::operator()(re_pack_inp<T> &) const [T = std::__1::tuple<>, C = RuleExecInfo *] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
    [-] /irods/server/re/include/irods_re_plugin.hpp:401:irods::error irods::rule_engine_manager<std::__1::tuple<>, RuleExecInfo *>::init_rule_engine(re_pack_inp<T> &) [T = std::__1::tuple<>, C = RuleExecInfo *] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]
        [-] /irods/lib/core/include/irods_load_plugin.hpp:157:irods::error irods::load_plugin(PluginType *&, const std::string &, const std::string &, const std::string &, const Ts &...) [PluginType = irods::pluggable_rule_engine<std::__1::tuple<> >, Ts = <std::__1::basic_string<char>>] :  status [PLUGIN_ERROR_MISSING_SHARED_OBJECT]  errno [] -- message [shared library does not exist [/usr/lib/irods/plugins/rule_engines/libirods_rule_engine_plugin-update_collection_mtime.so]]

This worked in 4.2.8 with no change of the Dockerfile, I had not tested between 4.2.8 and 4.2.10, but get similar behaviour in other Dockerfiles written using the same basic template (but with less plugins) - are you able to reproduce this?

[kript]

Quick followup - this appears to be a 4.2.10 change, as restricting the packages to 4.2.9 results in a normally responsive container...

[trel]

irods_demo is now at the latest versions of things, as per #29