Update cleanup

5 files changed, 53 insertions, 42 deletions

diff --git a/omaha_server/omaha/limitation.py b/omaha_server/omaha/limitation.py
index 1ab62f3..21ff549 100644
--- a/omaha_server/omaha/limitation.py
+++ b/omaha_server/omaha/limitation.py
@@ -1,12 +1,14 @@
 from itertools import chain
 import operator
 import time
+import logging
 
 from django.db.models.loading import get_model
 from django.utils import timezone
 from django.conf import settings
 from django.db.models import Count
 from django.core.cache import cache
+from django.template import defaultfilters as filters
 
 import boto
 from raven import Client
@@ -113,6 +115,7 @@ def s3_bulk_delete(qs, file_fields, s3_fields):
     s3_keys = [x for x in chain(*[bucket.list(prefix="%s/" % field) for field in s3_fields])]
     error_keys = filter(lambda key: key in s3_keys, file_keys)
     if error_keys:
+        logging.error("Files were not deleted from s3: %r" % error_keys)
         exclude_fields = [qs.exclude(**{"%s__in" % key: error_keys}) for key in file_fields]
         qs = reduce(operator.and_, exclude_fields)
 
@@ -136,14 +139,16 @@ def delete_older_than(app, model_name, limit=None):
 
 
 def delete_duplicate_crashes(limit=None):
+    logger = logging.getLogger('limitation')
     full_result = dict(count=0, size=0, elements=[])
     if not limit:
         preference_key = '__'.join(['Crash', 'duplicate_number'])
         limit = gpm[preference_key]
     duplicated = Crash.objects.values('signature').annotate(count=Count('signature'))
     duplicated = filter(lambda x: x['count'] > limit, duplicated)
+    logger.info('Duplicated signatures: %r' % duplicated)
     for group in duplicated:
-        qs = Crash.objects.filter(signature=group['signature'])
+        qs = Crash.objects.filter(signature=group['signature']).order_by('created')
         dup_elements = []
         dup_count = qs.count()
         while dup_count > limit:
@@ -197,30 +202,35 @@ def delete_size_is_exceeded(app, model_name, limit=None):
 def monitoring_size():
     size = OmahaVersion.objects.get_size()
     if size > gpm['Version__limit_size'] * 1024 * 1024 * 1024:
-        raven.captureMessage("[Limitation]Size limit of omaha versions is exceeded. Current size is %.4f GB[%d]" % (float(size) / 1024 / 1024 / 1024, time.time()),
+        raven.captureMessage("[Limitation]Size limit of omaha versions is exceeded. Current size is %s [%d]" %
+                             (filters.filesizeformat(size).replace(u'\xa0', u' '), time.time()),
                              data={'level': 30, 'logger': 'limitation'})
     cache.set('omaha_version_size', size)
 
     size = SparkleVersion.objects.get_size()
     if size > gpm['SparkleVersion__limit_size'] * 1024 * 1024 * 1024:
-        raven.captureMessage("[Limitation]Size limit of sparkle versions is exceeded. Current size is %.4f GB[%d]" % (float(size) / 1024 / 1024 / 1024, time.time()),
+        raven.captureMessage("[Limitation]Size limit of sparkle versions is exceeded. Current size is %s [%d]" %
+                             (filters.filesizeformat(size).replace(u'\xa0', u' '), time.time()),
                              data={'level': 30, 'logger': 'limitation'})
     cache.set('sparkle_version_size', size)
 
     size = Feedback.objects.get_size()
     if size > gpm['Feedback__limit_size'] * 1024 * 1024 * 1024:
-        raven.captureMessage("[Limitation]Size limit of feedbacks is exceeded. Current size is %.4f GB[%d]" % (float(size) / 1024 / 1024 / 1024, time.time()),
+        raven.captureMessage("[Limitation]Size limit of feedbacks is exceeded. Current size is %s [%d]" %
+                             (filters.filesizeformat(size).replace(u'\xa0', u' '), time.time()),
                              data={'level': 30, 'logger': 'limitation'})
     cache.set('feedbacks_size', size)
 
     size = Crash.objects.get_size()
     if size > gpm['Crash__limit_size'] * 1024 * 1024 * 1024:
-        raven.captureMessage("[Limitation]Size limit of crashes is exceeded. Current size is %.4f GB[%d]" % (float(size) / 1024 / 1024 / 1024, time.time()),
+        raven.captureMessage("[Limitation]Size limit of crashes is exceeded. Current size is %s [%d]" %
+                             (filters.filesizeformat(size).replace(u'\xa0', u' '), time.time()),
                              data={'level': 30, 'logger': 'limitation'})
     cache.set('crashes_size', size)
 
     size = Symbols.objects.get_size()
     if size > gpm['Symbols__limit_size'] * 1024 * 1024 * 1024:
-        raven.captureMessage("[Limitation]Size limit of symbols is exceeded. Current size is %.4f GB[%d]" % (float(size) / 1024 / 1024 / 1024, time.time()),
+        raven.captureMessage("[Limitation]Size limit of symbols is exceeded. Current size is %s [%d]" %
+                             (filters.filesizeformat(size).replace(u'\xa0', u' '), time.time()),
                              data={'level': 30, 'logger': 'limitation'})
     cache.set('symbols_size', size)
diff --git a/omaha_server/omaha/tasks.py b/omaha_server/omaha/tasks.py
index 95b0b8f..f3ee2d8 100644
--- a/omaha_server/omaha/tasks.py
+++ b/omaha_server/omaha/tasks.py
@@ -21,6 +21,8 @@ import time
 import logging
 import uuid
 
+from django.template import defaultfilters as filters
+
 from omaha_server.celery import app
 from omaha_server.utils import add_extra_to_log_message, get_splunk_url
 from omaha import statistics
@@ -29,6 +31,7 @@ from omaha.limitation import delete_older_than, delete_size_is_exceeded, delete_
 
 logger = logging.getLogger(__name__)
 
+
 @app.task(ignore_result=True)
 def collect_statistics(request, ip=None):
     statistics.collect_statistics(parse_request(request), ip=ip)
@@ -44,16 +47,15 @@ def auto_delete_older_than():
     for model in model_list:
         result = delete_older_than(*model)
         if result.get('count', 0):
-            result['size'] /= 1024.0 * 1024
             log_id = str(uuid.uuid4())
             params = dict(log_id=log_id)
             splunk_url = get_splunk_url(params)
             splunk_filter = 'log_id=%s' % log_id if splunk_url else None
             raven_extra = dict(id=log_id, splunk_url=splunk_url, splunk_filter=splunk_filter)
-            raven.captureMessage("[Limitation]Periodic task 'Older than' cleaned up %d %s, total size of cleaned space is %.2f Mb[%d]" %
-                                 (result['count'], model[1], result['size'], time.time()),
+            raven.captureMessage("[Limitation]Periodic task 'Older than' cleaned up %d %s, total size of cleaned space is %s [%d]" %
+                                 (result['count'], model[1], filters.filesizeformat(result['size']).replace(u'\xa0', u' '), time.time()),
                                  data=dict(level=20, logger='limitation'), extra=raven_extra)
-            extra = dict(log_id=log_id, meta=True, count=result['count'], size=result['size'], model=model[1], reason='old')
+            extra = dict(log_id=log_id, meta=True, count=result['count'], size=filters.filesizeformat(result['size']).replace(u'\xa0', u' '), model=model[1], reason='old')
             logger.info(add_extra_to_log_message('Automatic cleanup', extra=extra))
             for element in result['elements']:
                 element.update(dict(log_id=log_id))
@@ -69,16 +71,15 @@ def auto_delete_size_is_exceeded():
     for model in model_list:
         result = delete_size_is_exceeded(*model)
         if result.get('count', 0):
-            result['size'] /= 1024.0 * 1024
             log_id = str(uuid.uuid4())
             params = dict(log_id=log_id)
             splunk_url = get_splunk_url(params)
             splunk_filter = 'log_id=%s' % log_id if splunk_url else None
             raven_extra = dict(id=log_id, splunk_url=splunk_url, splunk_filter=splunk_filter)
-            raven.captureMessage("[Limitation]Periodic task 'Size is exceeded' cleaned up %d %s, total size of cleaned space is %.2f Mb[%d]" %
-                                 (result['count'], model[1], result['size'], time.time()),
+            raven.captureMessage("[Limitation]Periodic task 'Size is exceeded' cleaned up %d %s, total size of cleaned space is %s [%d]" %
+                                 (result['count'], model[1], filters.filesizeformat(result['size']).replace(u'\xa0', u' '), time.time()),
                                  data=dict(level=20, logger='limitation'), extra=raven_extra)
-            extra = dict(log_id=log_id, meta=True, count=result['count'], size=result['size'], model=model[1], reason='size_is_exceeded')
+            extra = dict(log_id=log_id, meta=True, count=result['count'], size=filters.filesizeformat(result['size']).replace(u'\xa0', u' '), model=model[1], reason='size_is_exceeded')
             logger.info(add_extra_to_log_message('Automatic cleanup', extra=extra))
             for element in result['elements']:
                 element.update(dict(log_id=log_id))
@@ -90,16 +91,15 @@ def auto_delete_duplicate_crashes():
     logger = logging.getLogger('limitation')
     result = delete_duplicate_crashes()
     if result.get('count', 0):
-        result['size'] /= 1024.0 * 1024
         log_id = str(uuid.uuid4())
         params = dict(log_id=log_id)
         splunk_url = get_splunk_url(params)
         splunk_filter = 'log_id=%s' % log_id if splunk_url else None
         raven_extra = dict(id=log_id, splunk_url=splunk_url, splunk_filter=splunk_filter)
-        raven.captureMessage("[Limitation]Periodic task 'Duplicated' cleaned up %d crashes, total size of cleaned space is %.2f Mb[%d]" %
-                             (result['count'], result['size'], time.time()),
+        raven.captureMessage("[Limitation]Periodic task 'Duplicated' cleaned up %d crashes, total size of cleaned space is %s [%d]" %
+                             (result['count'], filters.filesizeformat(result['size']).replace(u'\xa0', u' '), time.time()),
                              data=dict(level=20, logger='limitation'), extra=raven_extra)
-        extra = dict(log_id=log_id, meta=True, count=result['count'], size=result['size'], reason='duplicated', model='Crash')
+        extra = dict(log_id=log_id, meta=True, count=result['count'], size=filters.filesizeformat(result['size']).replace(u'\xa0', u' '), reason='duplicated', model='Crash')
         logger.info(add_extra_to_log_message('Automatic cleanup', extra=extra))
         for element in result['elements']:
             element.update(dict(log_id=log_id))
@@ -130,17 +130,16 @@ def deferred_manual_cleanup(model, limit_size=None, limit_days=None, limit_dupli
             full_result['size'] += result['size']
             full_result['elements'] += result['elements']
 
-    full_result['size'] /= 1024.0 * 1024
     log_id = str(uuid.uuid4())
     params = dict(log_id=log_id)
     splunk_url = get_splunk_url(params)
     splunk_filter = 'log_id=%s' % log_id if splunk_url else None
     raven_extra = dict(id=log_id, splunk_url=splunk_url, splunk_filter=splunk_filter)
-    raven.captureMessage("[Limitation]Manual cleanup freed %d %s, total size of cleaned space is %.2f Mb[%s]" %
-                         (full_result['count'], model[1], full_result['size'], log_id),
+    raven.captureMessage("[Limitation]Manual cleanup freed %d %s, total size of cleaned space is %s [%s]" %
+                         (full_result['count'], model[1], filters.filesizeformat(full_result['size']).replace(u'\xa0', u' '), log_id),
                          data=dict(level=20, logger='limitation'), extra=raven_extra)
 
-    extra = dict(log_id=log_id, meta=True, count=full_result['count'], size=full_result['size'], model=model[1],
+    extra = dict(log_id=log_id, meta=True, count=full_result['count'], size=filters.filesizeformat(full_result['size']).replace(u'\xa0', u' '), model=model[1],
                  limit_duplicated=limit_duplicated, limit_size=limit_size, limit_days=limit_days, reason='manual')
     logger.info(add_extra_to_log_message('Manual cleanup', extra=extra))
     for element in full_result['elements']:
diff --git a/omaha_server/omaha/tests/test_limitation.py b/omaha_server/omaha/tests/test_limitation.py
index 3405e76..fb0eb6e 100644
--- a/omaha_server/omaha/tests/test_limitation.py
+++ b/omaha_server/omaha/tests/test_limitation.py
@@ -105,6 +105,8 @@ class SizeExceedTest(TestCase):
 
 
 class DeleteDuplicateTest(TestCase):
+    maxDiff = None
+
     @is_private()
     def test_crashes(self):
         gpm['Crash__duplicate_number'] = 10
@@ -113,7 +115,7 @@ class DeleteDuplicateTest(TestCase):
         CrashFactory.create_batch(9, signature='test2')
         self.assertEqual(Crash.objects.filter(signature='test2').count(), 9)
 
-        deleted = list(Crash.objects.filter(signature='test1').values_list('id', 'created', 'signature', 'userid', 'appid'))[:15]
+        deleted = list(Crash.objects.filter(signature='test1').order_by('created').values_list('id', 'created', 'signature', 'userid', 'appid'))[:15]
         deleted = map(lambda x: dict(id=x[0], element_created=x[1].strftime("%d. %B %Y %I:%M%p"), signature=x[2],
                                      userid=x[3], appid=x[4]), deleted)
 
diff --git a/omaha_server/omaha/tests/test_tasks.py b/omaha_server/omaha/tests/test_tasks.py
index b86530a..5e1abc5 100644
--- a/omaha_server/omaha/tests/test_tasks.py
+++ b/omaha_server/omaha/tests/test_tasks.py
@@ -54,7 +54,7 @@ class DuplicatedCrashesTest(TestCase):
         self.assertEqual(Crash.objects.all().count(), 10)
 
         extra_meta = dict(count=8, reason='duplicated', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Crash', size=0.0)
+                          model='Crash', size='0 bytes')
         log_extra_msg = add_extra_to_log_message('Automatic cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_crash.id, element_created=deleted_crash.created.strftime("%d. %B %Y %I:%M%p"),
@@ -67,7 +67,7 @@ class DuplicatedCrashesTest(TestCase):
             mocked_uuid4.side_effect = (uuid.UUID('36446dc3-ae7c-42ad-ae4e-6a826dcf0a%02d' % x) for x in range(100))
             auto_delete_duplicate_crashes()
 
-        self.assertEqual(mocked_logger.info.call_count, 9)
+        self.assertEqual(mocked_logger.info.call_count, 10)
         mocked_logger.info.assert_any_call(log_extra_msg)
         mocked_logger.info.assert_any_call(log_msg)
 
@@ -83,7 +83,7 @@ class OldObjectsTest(TestCase):
         self.assertEqual(Crash.objects.all().count(), 10)
 
         extra_meta = dict(count=10, reason='old', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Crash', size=0.0)
+                          model='Crash', size='0 bytes')
         log_extra_msg = add_extra_to_log_message('Automatic cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_crash.id, element_created=deleted_crash.created.strftime("%d. %B %Y %I:%M%p"),
@@ -110,7 +110,7 @@ class OldObjectsTest(TestCase):
         self.assertEqual(Feedback.objects.all().count(), 10)
 
         extra_meta = dict(count=10, reason='old', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Feedback', size=0.0)
+                          model='Feedback', size='0 bytes')
         log_extra_msg = add_extra_to_log_message('Automatic cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_feedback.id, element_created=deleted_feedback.created.strftime("%d. %B %Y %I:%M%p"),
@@ -139,7 +139,7 @@ class SizeExceedTest(TestCase):
         self.assertEqual(Crash.objects.all().count(), 200)
 
         extra_meta = dict(count=98, reason='size_is_exceeded', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Crash', size=979.04296875)
+                          model='Crash', size='979.0 MB')
         log_extra_msg = add_extra_to_log_message('Automatic cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_crash.id, element_created=deleted_crash.created.strftime("%d. %B %Y %I:%M%p"),
@@ -168,7 +168,7 @@ class SizeExceedTest(TestCase):
         self.assertEqual(Feedback.objects.all().count(), 200)
 
         extra_meta = dict(count=98, reason='size_is_exceeded', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Feedback', size=979.04296875)
+                          model='Feedback', size='979.0 MB')
         log_extra_msg = add_extra_to_log_message('Automatic cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_feedback.id, element_created=deleted_feedback.created.strftime("%d. %B %Y %I:%M%p"),
@@ -195,7 +195,7 @@ class ManualCleanupTest(TestCase):
         self.assertEqual(Crash.objects.count(), 10)
 
         extra_meta = dict(count=8, reason='manual', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Crash', limit_duplicated=2, limit_size=None, limit_days=None, size=0.0)
+                          model='Crash', limit_duplicated=2, limit_size=None, limit_days=None, size='0 bytes')
         log_extra_msg = add_extra_to_log_message('Manual cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_crash.id, element_created=deleted_crash.created.strftime("%d. %B %Y %I:%M%p"),
@@ -208,7 +208,7 @@ class ManualCleanupTest(TestCase):
             mocked_uuid4.side_effect = (uuid.UUID('36446dc3-ae7c-42ad-ae4e-6a826dcf0a%02d' % x) for x in range(100))
             deferred_manual_cleanup(['crash', 'Crash'], limit_duplicated=2)
 
-        self.assertEqual(mocked_logger.info.call_count, 9)
+        self.assertEqual(mocked_logger.info.call_count, 10)
         mocked_logger.info.assert_any_call(log_extra_msg)
         mocked_logger.info.assert_any_call(log_msg)
 
@@ -224,7 +224,7 @@ class ManualCleanupTest(TestCase):
         self.assertEqual(Feedback.objects.count(), 20)
 
         extra_meta = dict(count=10, reason='manual', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Feedback', limit_duplicated=None, limit_size=1, limit_days=None, size=999.0234375)
+                          model='Feedback', limit_duplicated=None, limit_size=1, limit_days=None, size='999.0 MB')
         log_extra_msg = add_extra_to_log_message('Manual cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_feedback.id, element_created=deleted_feedback.created.strftime("%d. %B %Y %I:%M%p"),
@@ -250,7 +250,7 @@ class ManualCleanupTest(TestCase):
         self.assertEqual(Symbols.objects.count(), 20)
 
         extra_meta = dict(count=10, reason='manual', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Symbols', limit_duplicated=None, limit_size=1, limit_days=None, size=999.0234375)
+                          model='Symbols', limit_duplicated=None, limit_size=1, limit_days=None, size='999.0 MB')
         log_extra_msg = add_extra_to_log_message('Manual cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_symbols.id, element_created=deleted_symbols.created.strftime("%d. %B %Y %I:%M%p"),
@@ -276,7 +276,7 @@ class ManualCleanupTest(TestCase):
         self.assertEqual(Version.objects.count(), 2)
 
         extra_meta = dict(count=1, reason='manual', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='Version', limit_duplicated=None, limit_size=1, limit_days=None, size=999.0234375)
+                          model='Version', limit_duplicated=None, limit_size=1, limit_days=None, size='999.0 MB')
         log_extra_msg = add_extra_to_log_message('Manual cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_version.id, element_created=deleted_version.created.strftime("%d. %B %Y %I:%M%p"),
@@ -302,7 +302,7 @@ class ManualCleanupTest(TestCase):
         self.assertEqual(SparkleVersion.objects.count(), 2)
 
         extra_meta = dict(count=1, reason='manual', meta=True, log_id='36446dc3-ae7c-42ad-ae4e-6a826dcf0a00',
-                          model='SparkleVersion', limit_duplicated=None, limit_size=1, limit_days=None, size=999.0234375)
+                          model='SparkleVersion', limit_duplicated=None, limit_size=1, limit_days=None, size='999.0 MB')
         log_extra_msg = add_extra_to_log_message('Manual cleanup', extra=extra_meta)
 
         extra = dict(id=deleted_version.id, element_created=deleted_version.created.strftime("%d. %B %Y %I:%M%p"),
diff --git a/omaha_server/omaha_server/settings.py b/omaha_server/omaha_server/settings.py
index ba93359..6537156 100644
--- a/omaha_server/omaha_server/settings.py
+++ b/omaha_server/omaha_server/settings.py
@@ -245,19 +245,19 @@ if IS_PRIVATE:
     CELERYBEAT_SCHEDULE = {
         'auto_delete_older_then': {
             'task': 'tasks.auto_delete_older_then',
-            'schedule': timedelta(seconds=600),
+            'schedule': timedelta(hours=24),
             'options': {'queue': 'limitation'},
         },
         'auto_delete_size_is_exceed': {
             'task': 'tasks.auto_delete_size_is_exceeded',
-            'schedule': timedelta(seconds=600),
+            'schedule': timedelta(hours=1),
+            'options': {'queue': 'limitation'},
+        },
+        'auto_delete_duplicate_crashes': {
+            'task': 'tasks.auto_delete_duplicate_crashes',
+            'schedule': timedelta(hours=24),
             'options': {'queue': 'limitation'},
         },
-        # 'auto_delete_duplicate_crashes': {
-        #     'task': 'tasks.auto_delete_duplicate_crashes',
-        #     'schedule': timedelta(seconds=600),
-        #     'options': {'queue': 'limitation'},
-        # },
         'auto_monitoring_size': {
             'task': 'tasks.auto_monitoring_size',
             'schedule': timedelta(seconds=60),