caches: store computation time inside context manager as helper. Since the with block is full

calculation we can use it to calculate the function execution time.

rhodecode/apps/repository/views/repo_feed.py

@@ -17,7 +17,6 @@
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
-import time
 import pytz
 import logging
 
@@ -159,7 +158,6 @@ class RepoFeedView(RepoAppView):
 
             return feed.mime_type, feed.writeString('utf-8')
 
-        start = time.time()
         inv_context_manager = rc_cache.InvalidationContext(
             uid=cache_namespace_uid, invalidation_namespace=invalidation_namespace)
         with inv_context_manager as invalidation_context:
@@ -171,8 +169,9 @@ class RepoFeedView(RepoAppView):
 
             mime_type, feed = generate_atom_feed(
                 self.db_repo.repo_id, self.db_repo.repo_name, 'atom')
-            compute_time = time.time() - start
-            log.debug('Repo ATOM feed computed in %.3fs', compute_time)
+
+            log.debug('Repo ATOM feed computed in %.3fs',
+                      inv_context_manager.compute_time)
 
         response = Response(feed)
         response.content_type = mime_type
@@ -224,7 +223,6 @@ class RepoFeedView(RepoAppView):
 
             return feed.mime_type, feed.writeString('utf-8')
 
-        start = time.time()
         inv_context_manager = rc_cache.InvalidationContext(
             uid=cache_namespace_uid, invalidation_namespace=invalidation_namespace)
         with inv_context_manager as invalidation_context:
@@ -236,8 +234,8 @@ class RepoFeedView(RepoAppView):
 
             mime_type, feed = generate_rss_feed(
                 self.db_repo.repo_id, self.db_repo.repo_name, 'rss')
-            compute_time = time.time() - start
-            log.debug('Repo RSS feed computed in %.3fs', compute_time)
+            log.debug(
+                'Repo RSS feed computed in %.3fs', inv_context_manager.compute_time)
 
         response = Response(feed)
         response.content_type = mime_type

rhodecode/apps/repository/views/repo_summary.py

@@ -18,7 +18,6 @@
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
-import time
 import logging
 import string
 import rhodecode
@@ -86,7 +85,6 @@ class RepoSummaryView(RepoAppView):
                 readme_filename = readme_node.path
             return readme_data, readme_filename
 
-        start = time.time()
         inv_context_manager = rc_cache.InvalidationContext(
             uid=cache_namespace_uid, invalidation_namespace=invalidation_namespace)
         with inv_context_manager as invalidation_context:
@@ -98,8 +96,10 @@ class RepoSummaryView(RepoAppView):
 
             instance = generate_repo_readme(
                 db_repo.repo_id, db_repo.repo_name, renderer_type)
-            compute_time = time.time() - start
-            log.debug('Repo readme generated and computed in %.3fs', compute_time)
+
+            log.debug(
+                'Repo readme generated and computed in %.3fs',
+                inv_context_manager.compute_time)
             return instance
 
     def _get_landing_commit_or_none(self, db_repo):

rhodecode/lib/rc_cache/utils.py

@@ -18,6 +18,7 @@
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 import os
+import time
 import logging
 import functools
 import threading
@@ -210,23 +211,19 @@ class InvalidationContext(object):
     """
     usage::
 
-        import time
         from rhodecode.lib import rc_cache
-        my_id = 1
-        cache_namespace_uid = 'cache_demo.{}'.format(my_id)
-        invalidation_namespace = 'repo_cache:1'
+
+        cache_namespace_uid = CacheKey.SOME_NAMESPACE.format(1)
         region = rc_cache.get_or_create_region('cache_perms', cache_namespace_uid)
 
-        @region.conditional_cache_on_arguments(namespace=cache_namespace_uid,
-                                               expiration_time=30,
-                                               condition=True)
+        @region.conditional_cache_on_arguments(namespace=cache_namespace_uid, condition=True)
         def heavy_compute(cache_name, param1, param2):
             print('COMPUTE {}, {}, {}'.format(cache_name, param1, param2))
-            import time
-            time.sleep(30)
-            return True
 
-        start = time.time()
+        # invalidation namespace is shared namespace key for all process caches
+        # we use it to send a global signal
+        invalidation_namespace = 'repo_cache:1'
+
         inv_context_manager = rc_cache.InvalidationContext(
             uid=cache_namespace_uid, invalidation_namespace=invalidation_namespace)
         with inv_context_manager as invalidation_context:
@@ -236,7 +233,7 @@ class InvalidationContext(object):
                 heavy_compute.invalidate('some_name', 'param1', 'param2')
 
             result = heavy_compute('some_name', 'param1', 'param2')
-            compute_time = time.time() - start
+            compute_time = inv_context_manager.compute_time
             print(compute_time)
 
         # To send global invalidation signal, simply run
@@ -268,6 +265,7 @@ class InvalidationContext(object):
         self.cache_key = compute_key_from_params(uid)
         self.cache_key = 'proc:{}_thread:{}_{}'.format(
             self.proc_id, self.thread_id, self.cache_key)
+        self.compute_time = 0
 
     def get_or_create_cache_obj(self, uid, invalidation_namespace=''):
         log.debug('Checking if %s cache key is present and active', self.cache_key)
@@ -284,20 +282,23 @@ class InvalidationContext(object):
         """
         # register or get a new key based on uid
         self.cache_obj = self.get_or_create_cache_obj(uid=self.uid)
-
+        self._start_time = time.time()
         if self.cache_obj.cache_active:
             # means our cache obj is existing and marked as it's
             # cache is not outdated, we return ActiveRegionCache
             self.skip_cache_active_change = True
+
             return ActiveRegionCache(context=self)
 
-        # the key is either not existing or set to False, we return
+            # the key is either not existing or set to False, we return
         # the real invalidator which re-computes value. We additionally set
         # the flag to actually update the Database objects
         self.skip_cache_active_change = False
         return FreshRegionCache(context=self)
 
     def __exit__(self, exc_type, exc_val, exc_tb):
+        # save compute time
+        self.compute_time = time.time() - self._start_time
 
         if self.skip_cache_active_change:
             return

rhodecode/model/db.py

@@ -2339,7 +2339,6 @@ class Repository(Base, BaseModel):
         def get_instance_cached(repo_id):
             return self._get_instance()
 
-        start = time.time()
         inv_context_manager = rc_cache.InvalidationContext(
             uid=cache_namespace_uid, invalidation_namespace=invalidation_namespace)
         with inv_context_manager as invalidation_context:
@@ -2349,8 +2348,8 @@ class Repository(Base, BaseModel):
                 get_instance_cached.invalidate(self.repo_id)
 
             instance = get_instance_cached(self.repo_id)
-            compute_time = time.time() - start
-            log.debug('Repo instance fetched in %.3fs', compute_time)
+            log.debug(
+                'Repo instance fetched in %.3fs', inv_context_manager.compute_time)
             return instance
 
     def _get_instance(self, cache=True, config=None):