def test_audit_log_creation(faker, user, team, action, can_rollback):
assert AuditIndex.get_audit_ids(TYPE_SITE, 0) == []
last_audit_log = AuditLog.create(user.id, faker.ipv4(), action)
if can_rollback:
audit_log = AuditLog.create(
user.id, faker.ipv4(), action, last_audit_log.id)
else:
audit_log = AuditLog.create(user.id, faker.ipv4(), action)
assert audit_log.user_id == user.id
assert audit_log.user is user
assert audit_log.action_type == action_types.CREATE_TEAM
assert audit_log.action_name == 'CREATE_TEAM'
assert json.loads(audit_log.action_data) == {
'team_id': team.id,
'team_name': team.team_name,
'team_desc': team.team_desc,
}
if can_rollback:
assert audit_log.rollback_id == last_audit_log.id
assert audit_log.rollback_to is last_audit_log
with raises(ValueError) as error:
AuditLog.create(user.id, faker.ipv4(), action, -1)
assert error.match(r'^rollback_to is not a valid id$')
assert AuditIndex.get_audit_ids(TYPE_SITE, 0) == \
[audit_log.id, last_audit_log.id]
today = datetime.date.today()
assert AuditIndex.get_audit_ids_by_date(TYPE_SITE, 0, today) == \
[audit_log.id, last_audit_log.id]
def audit_log(action_type, **extra):
if not switch.is_switched_on(SWITCH_ENABLE_AUDIT_LOG):
yield
return
action = action_creator.make_action(action_type, **extra)
yield
try:
if g.auth.is_minimal_mode:
action_name = action_types[action_type]
fallback_audit_logger.info('%s %s %r', g.auth.username,
action_name, action.action_data)
else:
user_id = g.auth.id if g.auth else 0
AuditLog.create(user_id, request.remote_addr, action)
except AuditLogTooLongError:
logger.info('Audit log is too long. %s %s %s',
action_types[action_type], g.auth.username,
request.remote_addr)
return
except AuditLogLostError:
action_name = action_types[action_type]
fallback_audit_logger.info('%s %s %r', g.auth.username, action_name,
action.action_data)
sentry.captureException(level=logging.WARNING)
except Exception:
logger.exception('Unexpected error of audit log')
sentry.captureException()
def test_get_multi_by_index(faker, action):
assert AuditLog.get_multi_by_index(AuditLog.TYPE_SITE, 0)[:] == []
assert AuditLog.get_multi_by_index(AuditLog.TYPE_TEAM, 0)[:] == []
user = User.create_normal(faker.uuid4(), '-', faker.email())
log = AuditLog.create(user.id, faker.ipv4(), action)
assert AuditLog.get_multi_by_index(AuditLog.TYPE_SITE, 0)[:] == [log]
assert AuditLog.get_multi_by_index(AuditLog.TYPE_TEAM, 0)[:] == []
def huskar_audit_log(action_type, **extra):
if not switch.is_switched_on(SWITCH_ENABLE_AUDIT_LOG):
yield
return
action = action_creator.make_action(action_type, **extra)
yield
try:
if switch.is_switched_on(SWITCH_ENABLE_MINIMAL_MODE, False):
action_name = action_types[action_type]
fallback_audit_logger.info('arch.huskar_api %s %r', action_name,
action.action_data)
else:
user = User.get_by_name('arch.huskar_api')
user_id = user.id if user else 0
AuditLog.create(user_id, settings.LOCAL_REMOTE_ADDR, action)
except AuditLogTooLongError:
logger.info('Audit log is too long. %s arch.huskar_api',
action_types[action_type])
return
except AuditLogLostError:
action_name = action_types[action_type]
fallback_audit_logger.info('arch.huskar %s %r', action_name,
action.action_data)
except Exception:
logger.exception('Unexpected error of audit log')
def get(self, application_name, cluster_name, key):
"""Get the audit logs of specified instance key.
:param application_name: The name of application.
:param cluster_name: The name of clsuter.
:param key: The key of instance.
:query date: The date specified to search, default is today.
:query start: The offset of pagination. Default is ``0``.
:>header Authorization: Huskar Token (See :ref:`token`)
:status 403: You don't have required authority.
:status 501: The server is in minimal mode.
:status 200: The result is in the response.
(See :ref:`Audit Log Schema <audit_schema>`)
"""
check_application(application_name)
check_cluster_name(cluster_name, application_name)
start = request.args.get('start', type=int, default=0)
application = Application.get_by_name(application_name)
can_view_sensitive_data = AuditLog.can_view_sensitive_data(
g.auth.id, self.instance_type, application.id)
items = AuditLog.get_multi_by_instance_index(self.instance_type,
application.id,
cluster_name, key)
items = items[start:start + 20]
if not can_view_sensitive_data:
items = [item.desensitize() for item in items]
return api_response(audit_log_schema.dump(items, many=True).data)
def test_get_multi_by_instance_index(
db, redis_client, redis_flushall, faker, user, application):
cluster_name = 'bar'
key = 'test'
action_type = action_types.UPDATE_CONFIG
_, data_type = action_types[action_type].split('_', 1)
data_type = data_type.lower()
audit_num = 3
for _ in range(audit_num):
extra = {
'application_name': application.application_name,
'cluster_name': 'bar',
'key': 'test',
'old_data': 'old',
'new_data': 'new'
}
action = action_creator.make_action(
action_types.UPDATE_CONFIG, **extra)
AuditLog.create(user.id, faker.ipv4(), action)
audit_logs = AuditLog.get_multi_by_instance_index(
AuditLog.TYPE_CONFIG, application.id, cluster_name, key)
assert len(audit_logs[:]) == audit_num
with DBSession().close_on_exit(False):
DBSession.delete(user)
User._db_session.close()
redis_flushall(redis_client)
audit_logs = AuditLog.get_multi_by_instance_index(
AuditLog.TYPE_CONFIG, application.id, cluster_name, key)
assert not any(getattr(x, 'user') for x in audit_logs)
def test_get_multi_by_indices_with_date(faker, user, action):
log = AuditLog.create(user.id, faker.ipv4(), action)
today = datetime.date.today()
yesterday = today + datetime.timedelta(days=-1)
assert AuditLog.get_multi_by_index_with_date(
AuditLog.TYPE_SITE, 0, today)[:] == [log]
assert AuditLog.get_multi_by_index_with_date(
AuditLog.TYPE_SITE, 0, yesterday)[:] == []
def test_create_lost_audit(faker, mocker, user):
hook = mocker.patch('huskar_api.models.audit.audit._publish_new_action')
session = mocker.patch('huskar_api.models.audit.audit.DBSession')
session.side_effect = [InternalError(None, None, None, None)]
action = (action_types.UPDATE_CONFIG, 'data', [(TYPE_SITE, 0)])
with raises(AuditLogLostError):
AuditLog.create(user.id, faker.ipv4(), action)
hook.assert_called_once()
def test_create_too_large_audit(faker, mocker, user):
mocker.patch('huskar_api.models.audit.audit._publish_new_action')
action_data = 'x' * 65528
action = (action_types.UPDATE_CONFIG, action_data, [(TYPE_SITE, 0)])
with raises(AuditLogTooLongError):
AuditLog.create(user.id, faker.ipv4(), action)
action_data = 'x' * 65527
action = (action_types.UPDATE_CONFIG, action_data, [(TYPE_SITE, 0)])
assert AuditLog.create(user.id, faker.ipv4(), action)
def _get_audit_logs(self, target_id, start, date):
if target_id is None:
return []
if date:
audit_logs = AuditLog.get_multi_by_index_with_date(
self.target_type, target_id, date)
else:
audit_logs = AuditLog.get_multi_by_index(self.target_type,
target_id)
return audit_logs[start:start + 100]
def test_audit_event_publish_failed(
faker, mocker, user, action, connect_new_action_detected):
capture_exception = mocker.patch(
'huskar_api.models.audit.audit.capture_exception',
autospec=True
)
@connect_new_action_detected
def raise_error(*args, **kwargs):
raise ValueError
AuditLog.create(user.id, faker.ipv4(), action)
assert capture_exception.called
def test_rollback(user, unicode_action, action, config_action,
mocker, faker, zk):
audit_log = AuditLog.create(user.id, faker.ipv4(), action)
assert audit_log.can_rollback is False
audit_log = AuditLog.create(user.id, faker.ipv4(), unicode_action)
assert audit_log.can_rollback is True
audit_log = AuditLog.create(user.id, faker.ipv4(), config_action)
_, action_data, _ = config_action
zk.ensure_path('/huskar/config/%s/%s/%s' % (
action_data['application_name'], action_data['cluster_name'],
action_data['key']))
instance = audit_log.rollback(user.id, faker.ipv4())
assert instance.rollback_to == audit_log
def test_audit(request, mocker, test_team, test_user, test_application):
mocker.patch('huskar_api.extras.marshmallow.tzlocal', return_value=utc)
actions = []
if 'team' in request.param:
actions.extend([
(make_action(action_types.CREATE_TEAM, team=test_team), False),
(make_action(action_types.DELETE_TEAM, team=test_team), True),
])
if 'data' in request.param:
kwargs = {
'application_name': test_application.application_name,
'cluster_name': 'stable',
'key': '169.254.0.1_5000',
'old_data': '{"foo": "bar"}',
'new_data': '{"foo": "baz"}',
}
actions.extend([
(make_action(action_types.UPDATE_SERVICE, **kwargs), False),
(make_action(action_types.DELETE_SERVICE, **kwargs), True),
])
audit_log = None
for action, is_rollback in actions:
rid = audit_log.id if is_rollback else None
audit_log = AuditLog.create(test_user.id,
LOCALHOST,
action,
rollback_to=rid)
mocker.patch.object(audit_log, 'created_at',
datetime.datetime(2012, 12, 12))
return audit_log
def test_rollback_route_change(db, client, faker, test_application_name,
admin_token, action_type, cluster_name,
dest_application_name, destination_cluster_name,
zk):
action = action_creator.make_action(
action_type,
application_name=test_application_name,
cluster_name=cluster_name,
intent='direct',
dest_application_name=dest_application_name,
dest_cluster_name=destination_cluster_name)
audit_log = AuditLog.create(0, faker.ipv4(), action)
db.close()
rm = RouteManagement(huskar_client, test_application_name, cluster_name)
prev_destination_cluster = faker.uuid4()[:8]
for cluster in [destination_cluster_name, prev_destination_cluster]:
path = '/huskar/service/%s/%s/fo' % (dest_application_name, cluster)
zk.ensure_path(path)
rm.set_route(dest_application_name, prev_destination_cluster)
r = client.put('/api/audit-rollback/%s/%s' %
(test_application_name, audit_log.id),
headers={'Authorization': admin_token})
assert_response_ok(r)
if action_type == action_types.DELETE_ROUTE:
result = [(dest_application_name, 'direct', destination_cluster_name)]
else:
result = []
assert list(rm.list_route()) == result
def test_rollback_cluster_link_conflict(client, faker, db,
test_application_name, admin_token,
instance_management, action_type):
action = action_creator.make_action(
action_type,
application_name=test_application_name,
cluster_name='test',
physical_name='alpha_stable',
)
audit_log = AuditLog.create(0, faker.ipv4(), action)
db.close()
instance, _ = instance_management.get_instance('diff',
'key',
resolve=False)
instance.data = 'value'
instance.save()
cluster_info = instance_management.get_cluster_info('test')
cluster_info.set_link('diff')
cluster_info.save()
r = client.put('/api/audit-rollback/%s/%s' %
(test_application_name, audit_log.id),
headers={'Authorization': admin_token})
assert r.status_code == 409
def test_rollback_cluster_link_change(client, faker, admin_token, db,
action_type, test_application_name,
instance_management, cluster, link_to,
final_link_to):
action = action_creator.make_action(
action_type,
application_name=test_application_name,
cluster_name=cluster,
physical_name=link_to,
)
audit_log = AuditLog.create(0, faker.ipv4(), action)
db.close()
if action_type == action_types.ASSIGN_CLUSTER_LINK:
cluster_info = instance_management.get_cluster_info(cluster)
cluster_info.set_link(link_to)
cluster_info.save()
else:
instance, _ = instance_management.get_instance(link_to,
'key',
resolve=False)
instance.data = 'value'
instance.save()
r = client.put('/api/audit-rollback/%s/%s' %
(test_application_name, audit_log.id),
headers={'Authorization': admin_token})
assert_response_ok(r)
cluster_info = instance_management.get_cluster_info(cluster)
assert cluster_info.get_link() == final_link_to
def wrapped(instance_type,
application_name,
cluster_name,
key,
audit_num,
created_at=None):
action_type = getattr(action_types,
'UPDATE_%s' % instance_type.upper())
extra = {
'application_name': application_name,
'cluster_name': cluster_name,
'key': key,
}
new_data, old_data = faker.uuid4()[:8], None
ids = []
for i in range(audit_num):
extra.update(old_data=old_data, new_data=new_data)
action = make_action(action_type, **extra)
with db.close_on_exit(False):
audit_log = AuditLog.create(test_user.id, LOCALHOST, action)
if created_at:
mocker.patch.object(audit_log, 'created_at', created_at)
instance_indicies = db.query(AuditIndexInstance).filter_by(
audit_id=audit_log.id).all()
for index in instance_indicies:
mocker.patch.object(index, 'created_at', created_at)
ids.append(audit_log.id)
new_data, old_data = faker.uuid4()[:8], new_data
return ids
def wrapped(action_type, cluster, link=None):
action = action_creator.make_action(
action_type,
application_name=test_application_name,
cluster_name=cluster,
physical_name=link)
audit_log = AuditLog.create(0, faker.ipv4(), action)
db.close()
return audit_log
def test_normal_user_can_not_view_sensitive_data(
user, application, team, target_type):
if target_type == AuditLog.TYPE_SITE:
target_id = 0
elif target_type == AuditLog.TYPE_TEAM:
target_id = team.id
else:
target_id = application.id
assert not AuditLog.can_view_sensitive_data(
user.id, target_type, target_id)
def test_application_auth_can_view_application_sensitive_data(
user, application, team, target_type, can_view, authority):
application.ensure_auth(authority, user.id)
if target_type == AuditLog.TYPE_SITE:
target_id = 0
elif target_type == AuditLog.TYPE_TEAM:
target_id = team.id
else:
target_id = application.id
result = AuditLog.can_view_sensitive_data(user.id, target_type, target_id)
assert result == can_view
def test_application_admin_can_view_team_sensitive_data(
user, application, team, target_type, can_view):
team.grant_admin(user.id)
if target_type == AuditLog.TYPE_SITE:
target_id = 0
elif target_type == AuditLog.TYPE_TEAM:
target_id = team.id
else:
target_id = application.id
result = AuditLog.can_view_sensitive_data(user.id, target_type, target_id)
assert result == can_view
def test_application_use_user_token_change_user_type(
is_application, mocker, application, user,
connect_new_action_detected):
extra = {
'application_name': application.application_name,
'cluster_name': 'alta',
'key':
'b1b800dae3fca57fcb429615ff3e0a7054c59206640f1ef4dd30c12eccfdde43',
'new_data': {
'cluster': 'alta',
'ip': '192.168.1.2',
'meta': {'state': 'up'},
},
'old_data': None,
}
if is_application:
mocker.patch.object(
settings, 'APPLICATION_USE_USER_TOKEN_USER_LIST', [user.username])
events = []
@connect_new_action_detected
def test_event(sender, action_type, username, user_type,
action_data, is_subscriable, severity):
events.append([
action_type, username, user_type, action_data, is_subscriable,
severity])
action = action_creator.make_action(action_types.UPDATE_SERVICE, **extra)
AuditLog.create(user.id, '127.0.0.1', action)
assert len(events) == 1
action_type, _, user_type, _, is_subscriable, severity = events[0]
assert is_subscriable
assert severity == SEVERITY_DANGEROUS
if is_application:
assert user_type == APPLICATION_USER
else:
assert user_type == NORMAL_USER
assert action_type == action_types.UPDATE_SERVICE
def test_trace_all_application_events(
mocker, application, user, monitor_client):
extra = {
'application_name': application.application_name,
'cluster_name': 'alta',
'key':
'b1b800dae3fca57fcb429615ff3e0a7054c59206640f1ef4dd30c12eccfdde43',
'new_data': {
'cluster': 'alta',
'ip': '192.168.1.2',
'meta': {'state': 'up'},
},
'old_data': None,
}
action = action_creator.make_action(action_types.UPDATE_SERVICE, **extra)
AuditLog.create(user.id, '127.0.0.1', action)
monitor_client.increment.assert_called_once_with(
'audit.application_event', tags={
'action_name': 'UPDATE_SERVICE',
'application_name': application.application_name,
})
def test_prefetch_audit_log(faker, action):
users = [
User.create_normal(faker.uuid4()[:8], '-', faker.email())
for _ in xrange(10)]
audit_logs = [
AuditLog.create(user.id, faker.ipv4(), action) for user in users]
rollback_logs = [
AuditLog.create(
audit.user_id, faker.ipv4(), action, rollback_to=audit.id)
for audit in audit_logs]
ids = [audit.id for audit in audit_logs + rollback_logs]
fetched_logs = AuditLog.get_multi_and_prefetch(ids)
for index, audit in enumerate(fetched_logs[:len(audit_logs)]):
assert audit.__dict__['user'] is users[index]
assert 'rollback_to' not in audit.__dict__
assert audit.user is users[index]
assert audit.rollback_to is None
for index, audit in enumerate(fetched_logs[len(audit_logs):]):
assert audit.__dict__['user'] is users[index]
assert audit.__dict__['rollback_to'] is audit_logs[index]
assert audit.user is users[index]
assert audit.rollback_to is audit_logs[index]
def test_publish_new_action_with_low_severity(
mocker, user, connect_new_action_detected):
extra = {
'user': user,
}
events = []
@connect_new_action_detected
def test_event(sender, action_type, username, user_type,
action_data, is_subscriable, severity):
events.append([
action_type, username, user_type, action_data, is_subscriable,
severity])
action = action_creator.make_action(
action_types.OBTAIN_USER_TOKEN, **extra)
AuditLog.create(user.id, '127.0.0.1', action)
assert len(events) == 1
action_type, _, user_type, _, is_subscriable, severity = events[0]
assert not is_subscriable
assert user_type == NORMAL_USER
assert severity == SEVERITY_NORMAL
assert action_type == action_types.OBTAIN_USER_TOKEN
def test_fix_create_action_value_error(
mocker, application, user, connect_new_action_detected):
extra = {
'application_name': 'foo.bar',
'cluster_name': 'alta',
'key':
'b1b800dae3fca57fcb429615ff3e0a7054c59206640f1ef4dd30c12eccfdde43',
'new_data': {
'cluster': 'alta',
'ip': '192.168.1.2',
'meta': {'state': 'up'},
},
'old_data': None,
}
mocker.patch.object(
Application, 'get_by_name', side_effect=[None, application])
events = []
@connect_new_action_detected
def test_event(sender, action_type, username, user_type,
action_data, is_subscriable, severity):
events.append([
action_type, username, user_type, action_data, is_subscriable,
severity])
action = action_creator.make_action(action_types.UPDATE_SERVICE, **extra)
assert len(action.action_indices) == 1
assert len(action.action_indices[0]) == 4
AuditLog.create(user.id, '127.0.0.1', action)
assert len(events) == 1
action_type, _, user_type, _, is_subscriable, severity = events[0]
assert not is_subscriable
assert severity == SEVERITY_DANGEROUS
assert user_type == NORMAL_USER
assert action_type == action_types.UPDATE_SERVICE
def put(self, application_name, audit_id):
check_application_auth(application_name, Authority.WRITE)
audit = AuditLog.get(audit_id)
if audit is None:
abort(404, 'The audit log not existed.')
if not audit.can_rollback:
abort(400, 'The audit log can\'t be rollbacked.')
try:
audit.rollback(g.auth.id, request.remote_addr)
except DataConflictError:
abort(409, 'The audit log has conflict.')
return api_response()
def wrapped(action_type, key, new_data, old_data):
_, data_type = action_types[action_type].split('_', 1)
path = zk_path(data_type.lower(), key)
path_fragment = path.split('/')
application_name, cluster_name = path_fragment[3:5]
action = action_creator.make_action(action_type,
application_name=application_name,
cluster_name=cluster_name,
key=key,
old_data=old_data,
new_data=new_data)
audit_log = AuditLog.create(0, faker.ipv4(), action)
db.close()
return audit_log
def test_desensitize(user, action, data, value, nested):
audit_log = AuditLog.create(user.id, '127.0.0.1', action)
action_data = json.loads(audit_log.action_data)
if data:
action_data['data'] = {'old_data': '233', 'new_data': '666'}
if value:
action_data['value'] = {'url': 'sam+redis://redis.111/test'}
if nested:
action_data['nested'] = {
'client_self_check': {'overall': {'test': '0'}}}
audit_log.action_data = json.dumps(action_data)
action_data = audit_log.desensitize()['action_data']
action_data = json.loads(action_data)
for key in ('data', 'value', 'nested'):
assert key not in action_data
def test_rollback_failed(client, db, faker, test_application_name,
admin_token):
fake_audit_id = int(faker.numerify())
action = action_creator.make_action(action_types.CREATE_CONFIG_CLUSTER,
application_name=test_application_name,
cluster_name='bar')
audit_log = AuditLog.create(0, faker.ipv4(), action)
db.close()
r = client.put('/api/audit-rollback/%s/%s' %
(test_application_name, fake_audit_id),
headers={'Authorization': admin_token})
assert r.status_code == 404
assert r.json['status'] == 'NotFound'
assert r.json['message'] == 'The audit log not existed.'
r = client.put('/api/audit-rollback/%s/%s' %
(test_application_name, audit_log.id),
headers={'Authorization': admin_token})
assert r.status_code == 400
assert r.json['message'] == 'The audit log can\'t be rollbacked.'