Merge pull request #2306 from coreos-inc/QUAY-2842-audit-log-strict-config-option

feat(config.py): add setting for audit log strictness

config.py

@@ -273,6 +273,9 @@ class DefaultConfig(object):
   SYSTEM_LOGS_FILE = "/var/log/syslog"
   SYSTEM_SERVICES_PATH = "conf/init/service/"
 
+  # Allow registry pulls when unable to write to the audit log
+  ALLOW_PULLS_WITHOUT_STRICT_LOGGING = False
+
   # Services that should not be shown in the logs view.
   SYSTEM_SERVICE_BLACKLIST = []
 

data/model/log.py

@@ -1,13 +1,18 @@
 import json
+import logging
 
 from calendar import timegm
-from peewee import JOIN_LEFT_OUTER, fn
+from peewee import JOIN_LEFT_OUTER, fn, PeeweeException
 from datetime import datetime, timedelta
 from cachetools import lru_cache
 
 from data.database import LogEntry, LogEntryKind, User, RepositoryActionCount, db
 from data.model import config, user, DataModelException
 
+logger = logging.getLogger(__name__)
+
+ACTIONS_ALLOWED_WITHOUT_AUDIT_LOGGING = ['pull_repo']
+
 def _logs_query(selections, start_time, end_time, performer=None, repository=None, namespace=None,
                 ignore=None):
   joined = (LogEntry
@@ -109,9 +114,25 @@ def log_action(kind_name, user_or_organization_name, performer=None, repository=
 
   kind = _get_log_entry_kind(kind_name)
   metadata_json = json.dumps(metadata, default=_json_serialize)
-  LogEntry.create(kind=kind, account=account, performer=performer,
+  log_data = {
-                  repository=repository, ip=ip, metadata_json=metadata_json,
+    'kind': kind,
-                  datetime=timestamp)
+    'account': account,
+    'performer': performer,
+    'repository': repository,
+    'ip': ip,
+    'metadata_json': metadata_json,
+    'datetime': timestamp
+  }
+
+  try:
+    LogEntry.create(**log_data)
+  except PeeweeException as ex:
+    strict_logging_disabled = config.app_config.get('ALLOW_PULLS_WITHOUT_STRICT_LOGGING')
+    if strict_logging_disabled and kind_name in ACTIONS_ALLOWED_WITHOUT_AUDIT_LOGGING:
+      logger.exception('log_action failed', extra=({'exception': ex}).update(log_data))
+    else:
+      raise
+
 
 
 def get_stale_logs_start_id():

data/model/test/test_log.py

@@ -0,0 +1,80 @@
+import pytest
+
+from data.database import LogEntry, User
+from data.model import config as _config
+from data.model.log import log_action
+
+from mock import patch, Mock, DEFAULT, sentinel
+from peewee import PeeweeException
+
+
+@pytest.fixture(scope='function')
+def app_config():
+  with patch.dict(_config.app_config, {}, clear=True):
+    yield _config.app_config
+
+@pytest.fixture()
+def logentry_kind():
+  kinds = {'pull_repo': 'pull_repo_kind',  'push_repo': 'push_repo_kind'}
+  with patch('data.model.log.get_log_entry_kinds', return_value=kinds, spec=True):
+    yield kinds
+
+@pytest.fixture()
+def logentry(logentry_kind):
+  with patch('data.database.LogEntry.create', spec=True):
+    yield LogEntry
+
+@pytest.fixture()
+def user():
+  with patch.multiple('data.database.User', username=DEFAULT, get=DEFAULT, select=DEFAULT) as user:
+    user['get'].return_value = Mock(id='mock_user_id')
+    user['select'].return_value.tuples.return_value.get.return_value = ['default_user_id']
+    yield User
+
+@pytest.mark.parametrize('action_kind', [('pull'), ('oops')])
+def test_log_action_unknown_action(action_kind):
+  ''' test unknown action types throw an exception when logged '''
+  with pytest.raises(Exception):
+    log_action(action_kind, None)
+
+
+@pytest.mark.parametrize('user_or_org_name,account_id,account', [
+  ('my_test_org', 'N/A',             'mock_user_id'   ),
+  (None,          'test_account_id', 'test_account_id'),
+  (None,           None,             'default_user_id')
+])
+@pytest.mark.parametrize('unlogged_pulls_ok,action_kind,db_exception,throws', [
+  (False, 'pull_repo', None,            False),
+  (False, 'push_repo', None,            False),
+  (False, 'pull_repo', PeeweeException, True ),
+  (False, 'push_repo', PeeweeException, True ),
+
+  (True,  'pull_repo', PeeweeException, False),
+  (True,  'push_repo', PeeweeException, True ),
+  (True,  'pull_repo', Exception,       True ),
+  (True,  'push_repo', Exception,       True )
+])
+def test_log_action(user_or_org_name, account_id, account, unlogged_pulls_ok, action_kind,
+                      db_exception, throws, app_config, logentry, user):
+  log_args = {
+    'performer'  : Mock(id='TEST_PERFORMER_ID'),
+    'repository' : Mock(id='TEST_REPO'),
+    'ip'         : 'TEST_IP',
+    'metadata'   : { 'test_key' : 'test_value' },
+    'timestamp'  : 'TEST_TIMESTAMP'
+  }
+  app_config['SERVICE_LOG_ACCOUNT_ID'] = account_id
+  app_config['ALLOW_PULLS_WITHOUT_STRICT_LOGGING'] = unlogged_pulls_ok
+
+  logentry.create.side_effect = db_exception
+
+  if throws:
+    with pytest.raises(db_exception):
+      log_action(action_kind, user_or_org_name, **log_args)
+  else:
+    log_action(action_kind, user_or_org_name, **log_args)
+
+  logentry.create.assert_called_once_with(kind=action_kind+'_kind', account=account,
+                                          performer='TEST_PERFORMER_ID', repository='TEST_REPO',
+                                          ip='TEST_IP', metadata_json='{"test_key": "test_value"}',
+                                          datetime='TEST_TIMESTAMP')