[#175,#203] Fix read-only objects failing to update access_time (4-3-stable)

CMakeLists.txt

@@ -80,6 +80,8 @@ set(IRODS_PLUGIN_TARGET_NAME "${IRODS_TARGET_NAME_PREFIX}-${IRODS_POLICY_NAME}")
 string(REPLACE "_" "-" IRODS_POLICY_NAME_HYPHENS "${IRODS_POLICY_NAME}")
 set(IRODS_POLICY_PACKAGE_COMPONENT "${IRODS_POLICY_NAME_HYPHENS}")
 
+add_subdirectory(test/stream_test)
+
 add_library(
 	"${IRODS_PLUGIN_TARGET_NAME}"
 	MODULE

packaging/test_plugin_unified_storage_tiering.py

@@ -239,6 +239,25 @@ def get_tracked_replica(session, logical_path, group_attribute_name=None):
 
     return session.run_icommand(['iquest', '%s', tracked_replica_query])[0].strip()
 
+def get_access_time(session, data_object_path):
+    """Return value of AVU with attribute irods::access_time annotated on provided data_object_path.
+
+    If the provided data object path does not exist or does not have an irods::access_time AVU, the output will contain
+    CAT_NO_ROWS_FOUND.
+
+    Arguments:
+    session - iRODSSession which will run the query
+    data_object_path - Full iRODS logical path to a data object
+    """
+    coll_name = os.path.dirname(data_object_path)
+    data_name = os.path.basename(data_object_path)
+
+    query = "select META_DATA_ATTR_VALUE where " \
+            f"COLL_NAME = '{coll_name}' and DATA_NAME = '{data_name}' and " \
+            "META_DATA_ATTR_NAME = 'irods::access_time'"
+
+    return session.assert_icommand(['iquest', '%s', query], 'STDOUT')[1].strip()
+
 
 class TestStorageTieringPlugin(ResourceBase, unittest.TestCase):
     def setUp(self):
@@ -1948,3 +1967,99 @@ def test_one_rodsuser_and_one_rodsadmin_with_own_permission_succeeds__issue_273(
         self.tier_out_object_with_specified_permissions_test_impl(
             [(self.user1.username, "own"), (self.admin1.username, "own")]
         )
+
+
+class test_accessing_read_only_object_updates_access_time(unittest.TestCase):
+    @classmethod
+    def setUpClass(self):
+        self.user1 = session.mkuser_and_return_session("rodsuser", "tolstoy", "tpass", lib.get_hostname())
+
+        self.filename = "test_tiering_out_one_object_with_various_owners"
+        if not os.path.exists(self.filename):
+            lib.create_local_testfile(self.filename)
+
+        self.collection_path = "/".join(["/" + self.user1.zone_name, "public_collection"])
+        self.object_path = "/".join([self.collection_path, self.filename])
+
+        with session.make_session_for_existing_admin() as admin_session:
+            # Make a place for public group to put stuff.
+            admin_session.assert_icommand(["imkdir", "-p", self.collection_path])
+            admin_session.assert_icommand(["ichmod", "-r", "own", "public", self.collection_path])
+
+            with storage_tiering_configured():
+                IrodsController().restart(test_mode=True)
+                # TODO{#200): Replace with itouch or istream. Have to use put API due to missing PEP support.
+                # For this test, we don't actually care about tiering or restaging objects. We just want to test
+                # updating the access_time metadata. So, it doesn't matter into what resource the object's replica goes
+                # This is why no tier groups are being configured in this test.
+                admin_session.assert_icommand(["iput", self.filename, self.object_path])
+
+            # Give permissions exclusively to a rodsuser (removing permissions for original owner).
+            admin_session.assert_icommand(["ichmod", "own", self.user1.username, self.object_path])
+            admin_session.assert_icommand(["ichmod", "null", admin_session.username, self.object_path])
+
+        if os.path.exists(self.filename):
+            os.unlink(self.filename)
+
+    @classmethod
+    def tearDownClass(self):
+        self.user1.__exit__()
+
+        with session.make_session_for_existing_admin() as admin_session:
+            admin_session.assert_icommand(['iadmin', 'rmuser', self.user1.username])
+            admin_session.assert_icommand(['iadmin', 'rum'])
+
+    def tearDown(self):
+        # Make sure the test object is cleaned up after each test runs.
+        with session.make_session_for_existing_admin() as admin_session:
+            admin_session.assert_icommand(["ichmod", "-M", "own", admin_session.username, self.object_path])
+            admin_session.assert_icommand(["irm", "-f", self.object_path])
+
+    def read_object_updates_access_time_test_impl(self, read_command, *read_command_args):
+        """A basic test implementation to show that access_time metadata is updated for reads accessing data.
+
+        Arguments:
+        self - Instance of this class
+        read_command - A callable which will execute some sort of read operation on the object
+        read_command_args - *args to pass to the read_command callable
+        """
+        with storage_tiering_configured():
+            IrodsController().restart(test_mode=True)
+
+            # Capture the original access time so we have something against which to compare.
+            access_time = get_access_time(self.user1, self.object_path)
+            self.assertNotIn("CAT_NO_ROWS_FOUND", access_time)
+
+            # Sleeping guarantees the access time will be different following the access.
+            time.sleep(2)
+
+            # Access the data...
+            read_command(*read_command_args)
+
+            # Ensure the access_time was updated as a result of the access.
+            new_access_time = get_access_time(self.user1, self.object_path)
+            self.assertNotIn("CAT_NO_ROWS_FOUND", new_access_time)
+            self.assertGreater(new_access_time, access_time)
+
+    def test_dataobj_open_read_close_updates_access_time__issue_175_203(self):
+        # This basic test shows that access_time metadata is updated when dataObjOpen/Read/Close APIs access the data.
+        self.read_object_updates_access_time_test_impl(
+            self.user1.assert_icommand, ["irods_test_read_object", self.object_path], "STDOUT")
+
+    @unittest.skip("TODO(#200): Need to implement touch API PEP")
+    def test_touch_updates_access_time(self):
+        # This is a basic test to show that access_time metadata is updated when touch API accesses the data.
+        self.read_object_updates_access_time_test_impl(
+            self.user1.assert_icommand, ["itouch", self.object_path], "STDOUT")
+
+    @unittest.skip("TODO(#200): Need to implement replica_close PEP")
+    def test_replica_open_close_updates_access_time(self):
+        # This basic test shows that access_time metadata is updated when replica_open/close APIs access the data.
+        self.read_object_updates_access_time_test_impl(
+            self.user1.assert_icommand, ["istream", "read", self.object_path], "STDOUT")
+
+    @unittest.skip("TODO(#200): Need to implement get PEP")
+    def test_get_updates_access_time(self):
+        # This basic test shows that access_time metadata is updated when get API accesses the data.
+        self.read_object_updates_access_time_test_impl(
+            self.user1.assert_icommand, ["iget", self.object_path, "-"], "STDOUT")

src/main.cpp

@@ -7,10 +7,11 @@
 #include <irods/irods_resource_backport.hpp>
 #include "irods/private/storage_tiering/proxy_connection.hpp"
 
-#include <irods/rsModAVUMetadata.hpp>
-#include <irods/rsOpenCollection.hpp>
-#include <irods/rsReadCollection.hpp>
-#include <irods/rsCloseCollection.hpp>
+#include <irods/modAVUMetadata.h>
+#include <irods/openCollection.h>
+#include <irods/readCollection.h>
+#include <irods/closeCollection.h>
+#include <irods/irods_logger.hpp>
 #include <irods/irods_virtual_path.hpp>
 #include <irods/dataObjRepl.h>
 #include <irods/dataObjTrim.h>
@@ -53,6 +54,8 @@ int _delayExec(
     ruleExecInfo_t *rei );
 
 namespace {
+    using logger = irods::experimental::log::rule_engine;
+
     std::unique_ptr<irods::storage_tiering_configuration> config;
     std::map<int, std::tuple<std::string, std::string>> opened_objects;
     std::string plugin_instance_name{};
@@ -180,11 +183,10 @@ namespace {
 
     } // apply_data_retention_policy
 
-    void update_access_time_for_data_object(
-        rsComm_t*          _comm,
-        const std::string& _logical_path,
-        const std::string& _attribute) {
-
+    void update_access_time_for_data_object(rcComm_t* _comm,
+                                            const std::string& _logical_path,
+                                            const std::string& _attribute)
+    {
         auto ts = std::to_string(std::time(nullptr));
         modAVUMetadataInp_t avuOp{
             "set",
@@ -199,21 +201,18 @@ namespace {
             addKeyVal(&avuOp.condInput, ADMIN_KW, "");
         }
 
-        auto status = rsModAVUMetadata(_comm, &avuOp);
+        auto status = rcModAVUMetadata(_comm, &avuOp);
         if(status < 0) {
-            THROW(
-                status,
-                boost::format("failed to set access time for [%s]") %
-                _logical_path);
+            const auto msg = fmt::format("{}: failed to set access time for [{}]", __func__, _logical_path);
+            logger::error(msg);
+            THROW(status, msg);
         }
     } // update_access_time_for_data_object
 
-    void apply_access_time_to_collection(
-        rsComm_t*          _comm,
-        int                _handle,
-        const std::string& _attribute) {
+    void apply_access_time_to_collection(rcComm_t* _comm, int _handle, const std::string& _attribute)
+    {
         collEnt_t* coll_ent{nullptr};
-        int err = rsReadCollection(_comm, &_handle, &coll_ent);
+        int err = rcReadCollection(_comm, _handle, &coll_ent);
         while(err >= 0) {
             if(DATA_OBJ_T == coll_ent->objType) {
                 const auto& vps = irods::get_virtual_path_separator();
@@ -229,12 +228,12 @@ namespace {
                     coll_inp.collName,
                     coll_ent->collName,
                     MAX_NAME_LEN);
-                int handle = rsOpenCollection(_comm, &coll_inp);
+                int handle = rcOpenCollection(_comm, &coll_inp);
                 apply_access_time_to_collection(_comm, handle, _attribute);
-                rsCloseCollection(_comm, &handle);
+                rcCloseCollection(_comm, handle);
             }
 
-            err = rsReadCollection(_comm, &_handle, &coll_ent);
+            err = rcReadCollection(_comm, _handle, &coll_ent);
         } // while
     } // apply_access_time_to_collection
 
@@ -243,8 +242,10 @@ namespace {
         const std::string& _object_path,
         const std::string& _collection_type,
         const std::string& _attribute) {
+        auto proxy_conn = irods::proxy_connection();
+        rcComm_t* comm = proxy_conn.make_rodsadmin_connection();
         if(_collection_type.size() == 0) {
-            update_access_time_for_data_object(_comm, _object_path, _attribute);
+            update_access_time_for_data_object(comm, _object_path, _attribute);
         }
         else {
             // register a collection
@@ -254,17 +255,15 @@ namespace {
                 coll_inp.collName,
                 _object_path.c_str(),
                 MAX_NAME_LEN);
-            int handle = rsOpenCollection(
-                             _comm,
-                             &coll_inp);
+            int handle = rcOpenCollection(comm, &coll_inp);
             if(handle < 0) {
                 THROW(
                     handle,
                     boost::format("failed to open collection [%s]") %
                     _object_path);
             }
 
-            apply_access_time_to_collection(_comm, handle, _attribute);
+            apply_access_time_to_collection(comm, handle, _attribute);
         }
     } // set_access_time_metadata
 
@@ -295,11 +294,7 @@ namespace {
                     coll_type = "true";
                 }
 
-                set_access_time_metadata(
-                    _rei->rsComm,
-                    object_path,
-                    coll_type,
-                    config->access_time_attribute);
+                set_access_time_metadata(_rei->rsComm, object_path, coll_type, config->access_time_attribute);
             }
             else if("pep_api_data_obj_open_post" == _rn) {
                 auto it = _args.begin();
@@ -362,11 +357,7 @@ namespace {
                 if(opened_objects.find(l1_idx) != opened_objects.end()) {
                     auto [object_path, resource_name] = opened_objects[l1_idx];
 
-                    set_access_time_metadata(
-                        _rei->rsComm,
-                        object_path,
-                        "",
-                        config->access_time_attribute);
+                    set_access_time_metadata(_rei->rsComm, object_path, "", config->access_time_attribute);
                 }
             }
         } catch( const boost::bad_any_cast&) {

src/storage_tiering.cpp

@@ -19,10 +19,10 @@
 #include <irods/rsOpenCollection.hpp>
 #include <irods/rsReadCollection.hpp>
 #include <irods/rsCloseCollection.hpp>
+#include <irods/irods_logger.hpp>
 
 #include "irods/private/storage_tiering/data_verification_utilities.hpp"
 
-
 #include <boost/any.hpp>
 #include <boost/regex.hpp>
 #include <boost/exception/all.hpp>
@@ -49,6 +49,8 @@ int _delayExec(
 
 
 namespace irods {
+    using logger = irods::experimental::log::rule_engine;
+
     const std::string storage_tiering::policy::storage_tiering{"irods_policy_storage_tiering"};
     const std::string storage_tiering::policy::data_movement{"irods_policy_data_movement"};
     const std::string storage_tiering::policy::access_time{"irods_policy_apply_access_time"};
@@ -992,7 +994,9 @@ namespace irods {
         }
 
         if (const auto ec = rcModAVUMetadata(_comm, &set_op); ec < 0) {
-            THROW(ec, fmt::format("failed to set migration scheduled flag for [{}]", _object_path));
+            const auto msg = fmt::format("{}: failed to set migration scheduled flag for [{}]", __func__, _object_path);
+            logger::error(msg);
+            THROW(ec, msg);
         }
     } // set_migration_metadata_flag_for_object
 
@@ -1018,7 +1022,10 @@ namespace irods {
         }
 
         if (const auto ec = rcModAVUMetadata(_comm, &set_op); ec < 0) {
-            THROW(ec, fmt::format("failed to unset migration scheduled flag for [{}]", _object_path));
+            const auto msg =
+                fmt::format("{}: failed to unset migration scheduled flag for [{}]", __func__, _object_path);
+            logger::error(msg);
+            THROW(ec, msg);
         }
     } // unset_migration_metadata_flag_for_object
 
@@ -1076,12 +1083,11 @@ namespace irods {
             }
 
             auto status = rcModAVUMetadata(comm_, &set_op);
-            if(status < 0) {
-                THROW(
-                    status,
-                    boost::format("failed to set tier group [%s] metadata for [%s]")
-                    % _group_name
-                    % _object_path);
+            if (status < 0) {
+                const auto msg = fmt::format(
+                    "{}: failed to set tier group [{}] metadata for [{}]", __func__, _group_name, _object_path);
+                logger::error(msg);
+                THROW(status, msg);
             }
         }
         catch(const exception& _e) {

test/stream_test/CMakeLists.txt

@@ -0,0 +1,31 @@
+add_executable(
+	irods_test_read_object
+	"${CMAKE_CURRENT_SOURCE_DIR}/irods_test_read_object.cpp"
+)
+target_link_libraries(
+	irods_test_read_object
+	PRIVATE
+	irods_client
+	irods_common
+	irods_plugin_dependencies
+	"${IRODS_EXTERNALS_FULLPATH_BOOST}/lib/libboost_program_options.so"
+)
+target_include_directories(
+	irods_test_read_object
+	PRIVATE
+	"${IRODS_EXTERNALS_FULLPATH_BOOST}/include"
+)
+target_compile_definitions(
+    irods_test_read_object
+	PRIVATE
+	${IRODS_COMPILE_DEFINITIONS}
+	${IRODS_COMPILE_DEFINITIONS_PRIVATE}
+)
+install(
+	TARGETS
+	irods_test_read_object
+	RUNTIME
+	DESTINATION "${CMAKE_INSTALL_SBINDIR}"
+	COMPONENT "${IRODS_POLICY_PACKAGE_COMPONENT}"
+	PERMISSIONS OWNER_READ OWNER_WRITE OWNER_EXECUTE GROUP_READ GROUP_EXECUTE WORLD_READ WORLD_EXECUTE
+)