Bug 1397884 invalidate cache on new symbols (mozilla-services#389)

* bug 1397884 - invalidate cache on new symbols

* longer cache invalidation

* docs updates

Author: Peter Bengtsson

.coveragerc

@@ -8,6 +8,7 @@ omit =
     tests/*
     tecken/settings.py
     tecken/wsgi.py
+    tecken/benchmarking/*
     *migrations*
     *management*
     *management/commands*

docs/download.rst

@@ -165,3 +165,39 @@ route your request to the code that talks to S3. It can also come back
 as exactly ``Debug-Time: 0.0`` which means the symbol is in a blacklist of
 symbols that are immediately ``404 Not Found`` based on filename pattern
 matching.
+
+
+Download Without Caching
+========================
+
+Generally we can cache our work around S3 downloads quite aggressively since we
+tightly control the (only) input. Whenever a symbol archive file is uploaded,
+for every file within that we upload to S3 we also invalidate it from our
+cache. That means we can cache information about whether certain symbols
+exist in S3 or not quite long.
+
+However, if you are debugging something or if you manually remove a symbol
+from S3 that control is "lost". But there is a way to force the cache to
+be ignored. However, it only ignores looking in the cache. It will always
+update the cache.
+
+To do this append ``?_refresh`` to the URL. For example:
+
+.. code-block:: shell
+
+    $ curl https://symbols.mozilla.org/foo.pdb/HEX/foo.sym
+    ...302 Found...
+
+    # Now suppose you delete the file manually from S3 in the AWS Console.
+    # And without any delay do the curl again:
+    $ curl https://symbols.mozilla.org/foo.pdb/HEX/foo.sym
+    ...302 Found...
+    # Same old "broken", which is wrong.
+
+    # Avoid it by adding ?_refresh
+    $ curl https://symbols.mozilla.org/foo.pdb/HEX/foo.sym?_refresh
+    ...404 Symbol Not Found...
+
+    # Now our cache will be updated.
+    $ curl https://symbols.mozilla.org/foo.pdb/HEX/foo.sym
+    ...404 Symbol Not Found...

frontend/src/Common.js

@@ -63,7 +63,7 @@ export const formatFileSize = (bytes, decimals = 0) => {
 
 export const BooleanIcon = bool =>
   <span className="icon" style={{ color: bool ? 'green' : 'red' }}>
-    <i className={bool ? 'fa fa-thumbs-o-up' : 'fa fa-thumbs-o-down'} />
+    <i className={bool ? 'fa fa-check' : 'fa fa-close'} />
   </span>
 
 export const Pagination = ({

tecken/base/decorators.py

@@ -180,7 +180,6 @@ def send_email(email):
     Also, whatever you do where things get cached, you can undo that.
     For example::
 
-
         @cache_memoize(100)
         def callmeonce(arg1):
             print(arg1)
@@ -190,6 +189,18 @@ def callmeonce(arg1):
         callmeonce.invalidate('peter')
         callmeonce('peter')  # will print 'peter'
 
+    Suppose you know for good reason you want to bypass the cache and
+    really let the decorator let you through you can set one extra
+    keyword argument called `_refresh`. For example::
+
+        @cache_memoize(100)
+        def callmeonce(arg1):
+            print(arg1)
+
+        callmeonce('peter')                 # will print 'peter'
+        callmeonce('peter')                 # nothing printed
+        callmeonce('peter', _refresh=True)  # will print 'peter'
+
     """
 
     if args_rewrite is None:
@@ -212,11 +223,18 @@ def _make_cache_key(*args, **kwargs):
 
         @wraps(func)
         def inner(*args, **kwargs):
+            refresh = kwargs.pop('_refresh', False)
             cache_key = _make_cache_key(*args, **kwargs)
-            result = cache.get(cache_key)
+            if refresh:
+                result = None
+            else:
+                result = cache.get(cache_key)
             if result is None:
                 result = func(*args, **kwargs)
                 if not store_result:
+                    # Then the result isn't valuable/important to store but
+                    # we want to store something. Just to remember that
+                    # it has be done.
                     cache.set(cache_key, True, timeout)
                 elif result is not None:
                     cache.set(cache_key, result, timeout)

tecken/base/symboldownloader.py

@@ -2,7 +2,6 @@
 # License, v. 2.0. If a copy of the MPL was not distributed with this
 # file, you can obtain one at http://mozilla.org/MPL/2.0/.
 
-import hashlib
 import time
 from io import BytesIO
 from gzip import GzipFile
@@ -14,7 +13,6 @@
 from botocore.exceptions import ClientError
 
 from django.conf import settings
-from django.utils.encoding import force_bytes
 
 from tecken.base.decorators import cache_memoize
 from tecken.s3 import S3Bucket
@@ -78,10 +76,6 @@ def wrapper(self, *args, **kwargs):
     return wrapper
 
 
-def make_symbol_cache_key(bucket_name, key):
-    return hashlib.md5(force_bytes(f'symbol:{bucket_name}:{key}')).hexdigest()
-
-
 @metrics.timer_decorator('symboldownloader_exists')
 @cache_memoize(
     settings.SYMBOLDOWNLOAD_EXISTS_TTL_SECONDS,
@@ -232,7 +226,7 @@ def _make_key(prefix, symbol, debugid, filename):
             filename,
         )
 
-    def _get(self, symbol, debugid, filename):
+    def _get(self, symbol, debugid, filename, refresh_cache=False):
         """Return a dict if the symbol can be found. The dict will
         either be `{'url': ...}` or `{'buckey_name': ..., 'key': ...}`
         depending on if the symbol was found a public bucket or a
@@ -248,7 +242,9 @@ def _get(self, symbol, debugid, filename):
                 # If it's a private bucket we use boto3.
 
                 key = self._make_key(prefix, symbol, debugid, filename)
-                if not exists_in_source(source, key):
+                if not exists_in_source(
+                    source, key, _refresh=refresh_cache
+                ):
                     continue
 
                 logger.debug(
@@ -276,7 +272,7 @@ def _get(self, symbol, debugid, filename):
                 logger.debug(
                     f'Looking for symbol file by URL {file_url!r}'
                 )
-                if check_url_head(file_url):
+                if check_url_head(file_url, _refresh=refresh_cache):
                     return {'url': file_url, 'source': source}
 
     def _get_stream(self, symbol, debugid, filename):
@@ -404,16 +400,20 @@ def _get_stream(self, symbol, debugid, filename):
         raise SymbolNotFound(symbol, debugid, filename)
 
     @set_time_took
-    def has_symbol(self, symbol, debugid, filename):
+    def has_symbol(self, symbol, debugid, filename, refresh_cache=False):
         """return True if the symbol can be found, False if not
         found in any of the URLs provided."""
-        return bool(self._get(symbol, debugid, filename))
+        return bool(self._get(
+            symbol, debugid, filename, refresh_cache=refresh_cache,
+        ))
 
     @set_time_took
-    def get_symbol_url(self, symbol, debugid, filename):
+    def get_symbol_url(self, symbol, debugid, filename, refresh_cache=False):
         """return the redirect URL or None. If we return None
         it means we can't find the object in any of the URLs provided."""
-        found = self._get(symbol, debugid, filename)
+        found = self._get(
+            symbol, debugid, filename, refresh_cache=refresh_cache
+        )
         if found:
             if 'url' in found:
                 return found['url']

tecken/download/views.py

@@ -90,14 +90,26 @@ def download_symbol(request, symbol, debugid, filename):
             response['Debug-Time'] = 0
         return response
 
+    refresh_cache = '_refresh' in request.GET
+
     if request.method == 'HEAD':
-        if downloader.has_symbol(symbol, debugid, filename):
+        if downloader.has_symbol(
+            symbol,
+            debugid,
+            filename,
+            refresh_cache=refresh_cache,
+        ):
             response = http.HttpResponse()
             if request._request_debug:
                 response['Debug-Time'] = downloader.time_took
             return response
     else:
-        url = downloader.get_symbol_url(symbol, debugid, filename)
+        url = downloader.get_symbol_url(
+            symbol,
+            debugid,
+            filename,
+            refresh_cache=refresh_cache,
+        )
         if url:
             # If doing local development, with Docker, you're most likely
             # running minio as a fake S3 client. It runs on its own
@@ -110,7 +122,7 @@ def download_symbol(request, symbol, debugid, filename):
                 'http://minio:9000' in url and
                 request.get_host() == 'localhost:8000'
             ):  # pragma: no cover
-                url = url.replace('minio:9000', 'localhost:5000')
+                url = url.replace('minio:9000', 'localhost:9000')
             response = http.HttpResponseRedirect(url)
             if request._request_debug:
                 response['Debug-Time'] = downloader.time_took
@@ -148,8 +160,6 @@ def download_symbol(request, symbol, debugid, filename):
                 code_id=request.GET.get('code_id'),
             )
 
-            downloader.invalidate_cache(symbol, debugid, filename)
-
             # The querying of Microsoft's server is potentially slow.
             # That's why this call is down in a celery task.
             # But there is hope! And the client ought to be informed

tecken/settings.py

@@ -402,10 +402,9 @@ def LOGGING(self):
 
     # We can cache quite aggressively here because the SymbolDownloader
     # has chance to invalidate certain keys.
-    # But we don't want to make it too long since when a symbols.zip file
-    # is uploaded it doesn't have the opportunity to invalidate those
-    # that are uploaded.
-    SYMBOLDOWNLOAD_EXISTS_TTL_SECONDS = values.IntegerValue(60 * 60)
+    # Also, any time a symbol archive file is upload, for each file within
+    # that we end up uploading to S3 we also cache invalidate.
+    SYMBOLDOWNLOAD_EXISTS_TTL_SECONDS = values.IntegerValue(60 * 60 * 6)
 
     # Whether to start a background task to search for symbols
     # on Microsoft's server is protected by an in-memory cache.

tecken/upload/tasks.py

@@ -22,6 +22,7 @@
 from tecken.upload.models import Upload, FileUpload
 from tecken.upload.utils import get_archive_members
 from tecken.s3 import get_s3_client
+from tecken.base.symboldownloader import SymbolDownloader
 from tecken.boto_extra import (
     reraise_clienterrors,
     reraise_endpointconnectionerrors
@@ -30,6 +31,8 @@
 logger = logging.getLogger('tecken')
 metrics = markus.get_metrics('tecken')
 
+downloader = SymbolDownloader(settings.SYMBOL_URLS)
+
 
 @shared_task(autoretry_for=(
     EndpointConnectionError,
@@ -286,4 +289,24 @@ def upload_file_upload(s3_client, bucket_name, key_name, content, upload=None):
         **extras,
     )
     file_upload.completed_at = timezone.now()
+
+    # Take this opportunity to inform possible caches that the file,
+    # if before wasn't the case, is now stored in S3.
+    symbol, debugid, filename = _key_name_to_parts(key_name)
+    try:
+        downloader.invalidate_cache(
+            symbol, debugid, filename
+        )
+    except Exception as exception:  # pragma: no cover
+        if 1 or settings.DEBUG:
+            raise
+        logger.error(
+            f'Unable to invalidate symbol {symbol}/{debugid}/{filename}',
+            exc_info=True
+        )
+
     return file_upload
+
+
+def _key_name_to_parts(key_name):
+    return key_name.split(settings.SYMBOL_FILE_PREFIX + '/')[1].split('/')

tests/test_decorators.py

@@ -76,3 +76,20 @@ def returnnothing(a, b, k='bla'):
     returnnothing(1, 2)
     returnnothing(1, 2)
     assert len(calls_made) == 8
+
+
+def test_cache_memoize_refresh():
+
+    calls_made = []
+
+    @decorators.cache_memoize(10)
+    def runmeonce(a):
+        calls_made.append(a)
+        return a * 2
+
+    runmeonce(10)
+    assert len(calls_made) == 1
+    runmeonce(10)
+    assert len(calls_made) == 1
+    runmeonce(10, _refresh=True)
+    assert len(calls_made) == 2

tests/test_download.py

@@ -174,6 +174,39 @@ def mock_api_call(self, operation_name, api_params):
         assert len(mock_api_calls) == 1
 
 
+def test_client_with_cache_refreshed(client, botomock, metricsmock):
+    reload_downloader('https://s3.example.com/private/prefix/')
+
+    mock_api_calls = []
+
+    def mock_api_call(self, operation_name, api_params):
+        assert operation_name == 'ListObjectsV2'
+        mock_api_calls.append(api_params)
+        return {
+            'Contents': [{
+                'Key': api_params['Prefix'],
+            }]
+        }
+
+    url = reverse('download:download_symbol', args=(
+        'xul.pdb',
+        '44E4EC8C2F41492B9369D6B9A059577C2',
+        'xul.sym',
+    ))
+    with botomock(mock_api_call):
+        response = client.get(url)
+        assert response.status_code == 302
+        assert len(mock_api_calls) == 1
+
+        response = client.get(url)
+        assert response.status_code == 302
+        assert len(mock_api_calls) == 1  # still 1
+
+        response = client.get(url, {'_refresh': 1})
+        assert response.status_code == 302
+        assert len(mock_api_calls) == 2
+
+
 def test_client_404(client, botomock, clear_redis_store):
     reload_downloader('https://s3.example.com/private/prefix/')
 
@@ -387,11 +420,9 @@ def fake_task(symbol, debugid, **kwargs):
             assert response.status_code == 404
             assert response.content == b'Symbol Not Found Yet'
 
-            # Whenever a download_microsoft_symbol.delay() is is MAYBE
-            # called, the symboldownloader cache is invalidated on this
-            # key. So the second call to symboldownloader will actually
-            # reach out to S3 again.
-            assert len(mock_calls) == 2
+            # This basically checks that the SymbolDownloader cache is
+            # not invalidated between calls.
+            assert len(mock_calls) == 1
             # However, the act of triggering that
             # download_microsoft_symbol.delay() call is guarded by an
             # in-memory cache. So it shouldn't have called it more than