`test_audit_plugin.TestAuditPlugin.test_audit_plugin` test faliure

[SwooshyCueb]

• [x] main
• [x] 4-3-stable

iRODS version: 4.3.2 release candidate (irods/irods@5ba6de8627802ef994f9b6fa600ef1103bfc4ea7) Plugin version: 4.3.2 release candidate (151e1737432307b028dba0354fb07b88bac281c3) Externals: irods/externals@1b220bcd013678008c34a9268c15becfed35acb6 Running in the testing environment with the ubuntu-22.04-mysql-8 project

The test test_audit_plugin.TestAuditPlugin.test_audit_plugin fails consistently.

logs: https://gist.github.com/SwooshyCueb/a953843637583a77709ab5ae27c04d20

[alanking]

Just sharing my experience, which undoubtedly overlaps, saw these results:

======================================================================                                                                  
ERROR [2.310s]: test_audit_plugin (irods.test.test_audit_plugin.TestAuditPlugin)                                                        
----------------------------------------------------------------------                                                                  
Traceback (most recent call last):                                  
  File "/var/lib/irods/scripts/irods/test/test_audit_plugin.py", line 54, in test_audit_plugin                                          
    listener.run()                                                  
  File "/var/lib/irods/scripts/irods/test/queue_listener.py", line 42, in run                                                           
    container.run()                                                 
  File "/usr/local/lib64/python3.6/site-packages/proton/_reactor.py", line 194, in run                                                  
    while self.process():                                                                                                               
  File "/usr/local/lib64/python3.6/site-packages/proton/_reactor.py", line 259, in process                                              
    event.dispatch(self._global_handler)                            
  File "/usr/local/lib64/python3.6/site-packages/proton/_events.py", line 161, in dispatch                                              
    _dispatch(handler, type.method, self)                                                                                               
  File "/usr/local/lib64/python3.6/site-packages/proton/_events.py", line 130, in _dispatch                                             
    handler.on_unhandled(method, *args)                             
  File "/usr/local/lib64/python3.6/site-packages/proton/_reactor.py", line 903, in on_unhandled                                         
    event.dispatch(self.base)                                       
  File "/usr/local/lib64/python3.6/site-packages/proton/_events.py", line 161, in dispatch                                              
    _dispatch(handler, type.method, self)                           
  File "/usr/local/lib64/python3.6/site-packages/proton/_events.py", line 128, in _dispatch                                             
    m(*args)                                                        
  File "/usr/local/lib64/python3.6/site-packages/proton/_handlers.py", line 1159, in on_reactor_quiesced                                
    s.writable()                                                                                                                        
  File "/usr/local/lib64/python3.6/site-packages/proton/_handlers.py", line 1367, in writable                                           
    sock = IO.connect(self._addrs[0])                               
  File "/usr/local/lib64/python3.6/site-packages/proton/_io.py", line 66, in connect                                                    
    s.connect(addr[4])                                                                                                                  
OSError: [Errno 99] Cannot assign requested address                 

...and...

======================================================================
FAIL [0.256s]: test_delayed_rule_with_plugin_configured (irods.test.test_audit_plugin.TestAuditPlugin)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/irods/scripts/irods/test/test_audit_plugin.py", line 81, in test_delayed_rule_with_plugin_configured
    admin_session.assert_icommand(['irule', '-r', rep_name, '-F', rule_file], 'STDERR', 'SYS_NOT_SUPPORTED')
  File "/var/lib/irods/scripts/irods/test/session.py", line 164, 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

Stdout:
 --- IrodsSession: icommand executed by [rods#tempZone] [iinit] --- 
Assert Command: iinit
Expecting STDOUT_SINGLELINE: ['']
  stdout:
    | WARNING: Error 25 disabling echo mode. Password will be displayed in plaintext.
    | Enter your current iRODS password:
  stderr:
    | 
Output found

 --- IrodsSession: icommand executed by [rods#tempZone] [irule -r irods_rule_engine_plugin-audit_amqp-instance -F test_audit_plugin_delayed_rule.r] --- 
Assert Command: irule -r irods_rule_engine_plugin-audit_amqp-instance -F test_audit_plugin_delayed_rule.r
Expecting STDERR: ['SYS_NOT_SUPPORTED']
  stdout:
    | 
  stderr:
    | remote addresses: 172.22.0.3 ERROR: rcExecMyRule error.  status = -130000 SYS_INVALID_INPUT_PARAM
Output not found

FAILED TESTING ASSERTION

[alanking]

The SYS_INVALID_INPUT_PARAM failure appears to occur because the REP is not configured at the time the test is run, at least according to the server logs. It is expecting SYS_NOT_SUPPORTED because the REP does not support the rule that the test is attempting to run. However, irule fails to find the targeted REP instance and fails with SYS_INVALID_INPUT_PARAM. The REP does get configured at some point in the tests (by inspection of server_config.json), but it seems it was not at the time this test was run. I will try to run this one in isolation.

The other issue is the one that will be a bit harder to figure out, I think. The qpidproton listener fails to run() and doesn't really give any good errors other than the one shown above (that I've seen). Interestingly, the logs provided by @SwooshyCueb clearly show that messages are appearing somewhere, so this test fixture just needs to be stood up properly to get over that hump.

Not that it particularly matters, but I also tried using rabbitmq instead and found that the same issues exist.

[alanking]

Just confirmed that test_audit_plugin.TestAuditPlugin.test_delayed_rule_with_plugin_configured passes when run in isolation.

Also noting that I'm running these tests with AlmaLinux 8 / MySQL 8.

[trel]

So with a confident diagnosis of the tests themselves not yet being held correctly by the framework - and otherwise, no code changes... this doesn't feel like a blocker for release.

[alanking]

I'm not so sure about that. The test that is failing is the only test that actually exercises the plugin and confirms that it is working. The other tests are either dealing with configuration or literally just running the unixfilesystem suite with the REP configured to make sure it doesn't break anything by existing in normal usage.

[trel]

I see.

[alanking]

I installed OpenJDK 1.8 and was able to get the same error as shown in OP, so we're getting closer...