def test_input_request_to_homepage_should_be_logged_in_sql_backend(self, user):
with log_with_data(related_objects=[user]):
assert_http_ok(self.get('/home/?name=value'))
assert_equal(SQLInputRequestLog.objects.count(), 1)
sql_input_request_log = SQLInputRequestLog.objects.get()
assert_equal_model_fields(
sql_input_request_log,
request_headers={'Cookie': '[Filtered]'},
request_body='',
user_id=None,
method='GET',
host='testserver',
path='/home/',
queries={'name': 'value'},
is_secure=False,
ip='127.0.0.1',
view_slug='home',
slug=None,
time=(sql_input_request_log.stop - sql_input_request_log.start).total_seconds(),
extra_data={},
error_message=None,
response_code=200,
response_headers={'Content-Type': 'text/html; charset=utf-8', 'X-Frame-Options': 'DENY'},
response_body='home page response',
state=RequestLogState.INFO,
)
assert_equal([rel_obj.object for rel_obj in sql_input_request_log.related_objects.all()], [user])
def test_input_request_to_homepage_should_be_logged_in_elasticsearch_backend(self, user):
with log_with_data(related_objects=[user]):
with capture_security_logs() as logged_data:
assert_http_ok(self.get('/home/?name=value'))
elasticsearch_input_request_log = ElasticsearchInputRequestLog.get(
id=logged_data.input_request[0].id
)
assert_equal_model_fields(
elasticsearch_input_request_log,
request_headers='{"Cookie": "[Filtered]"}',
request_body='',
user_id=None,
method='GET',
host='testserver',
path='/home/',
queries='{"name": "value"}',
is_secure=False,
ip='127.0.0.1',
view_slug='home',
slug=None,
time=(elasticsearch_input_request_log.stop - elasticsearch_input_request_log.start).total_seconds(),
extra_data={},
error_message=None,
response_code=200,
response_headers='{"Content-Type": "text/html; charset=utf-8", "X-Frame-Options": "DENY"}',
response_body='home page response',
state=RequestLogState.INFO,
)
assert_equal(
[rel_obj for rel_obj in elasticsearch_input_request_log.related_objects],
['default|3|{}'.format(user.id)]
)
def test_input_request_to_homepage_should_be_logged(self):
expected_input_request_started_data = {
'request_headers': {'Cookie': '[Filtered]'},
'request_body': '',
'user_id': None,
'method': 'GET',
'host': 'testserver',
'path': '/home/',
'queries': {'name': 'value'},
'is_secure': False,
'ip': '127.0.0.1',
'start': all_eq_obj,
'view_slug': 'home',
}
expected_input_request_finished_data = {
**expected_input_request_started_data,
'stop': all_eq_obj,
'response_code': 200,
'response_headers': {'Content-Type': 'text/html; charset=utf-8', 'X-Frame-Options': 'DENY'},
'response_body': 'home page response',
}
with capture_security_logs() as logged_data:
assert_http_ok(self.get('/home/?name=value'))
assert_length_equal(logged_data.input_request_started, 1)
assert_length_equal(logged_data.input_request_finished, 1)
assert_length_equal(logged_data.input_request_error, 0)
assert_equal_log_data(logged_data.input_request_started[0], expected_input_request_started_data)
assert_equal_log_data(logged_data.input_request_finished[0], expected_input_request_finished_data)
def test_input_logged_request_should_have_set_data(self, user):
with capture_security_logs() as logged_data:
assert_http_redirect(self.post('/admin/login/', data={'username': '******', 'password': '******'}))
assert_http_ok(self.get('/home/'))
assert_equal(len(logged_data.input_request[1].related_objects), 1)
assert_equal(list(logged_data.input_request[1].related_objects)[0], get_object_triple(user))
assert_equal(logged_data.input_request_finished[1].slug, 'user-home')
def test_input_request_to_error_page_should_be_logged(self):
expected_input_request_started_data = {
'request_headers': {'Cookie': '[Filtered]'},
'request_body': '',
'user_id': None,
'method': 'GET',
'host': 'testserver',
'path': '/error/',
'queries': {},
'is_secure': False,
'ip': '127.0.0.1',
'start': all_eq_obj,
'view_slug': 'apps.test_security.views.error_view',
}
expected_input_request_error_data = {
**expected_input_request_started_data,
'error_message': all_eq_obj,
}
expected_input_request_finished_data = {
**expected_input_request_error_data,
'stop': all_eq_obj,
'response_code': 500,
'response_headers': all_eq_obj,
'response_body': all_eq_obj,
}
with capture_security_logs() as logged_data:
with assert_raises(RuntimeError):
assert_http_ok(self.get('/error/'))
assert_length_equal(logged_data.input_request_started, 1)
assert_length_equal(logged_data.input_request_finished, 1)
assert_length_equal(logged_data.input_request_error, 1)
assert_equal_log_data(logged_data.input_request_started[0], expected_input_request_started_data)
assert_equal_log_data(logged_data.input_request_finished[0], expected_input_request_finished_data)
assert_equal_log_data(logged_data.input_request_error[0], expected_input_request_error_data)
def test_input_logged_request_should_have_right_status(self, user):
assert_http_ok(self.post('/admin/login/', data={'username': '******', 'password': '******'}))
assert_equal(InputLoggedRequest.objects.first().status, InputLoggedRequest.INFO)
assert_http_redirect(self.post('/admin/login/', data={'username': '******', 'password': '******'}))
assert_equal(InputLoggedRequest.objects.first().status, InputLoggedRequest.INFO)
assert_raises(Exception, self.get, '/proxy/')
assert_equal(InputLoggedRequest.objects.first().status, InputLoggedRequest.ERROR)
assert_http_not_found(self.get('/404/'))
assert_equal(InputLoggedRequest.objects.first().status, InputLoggedRequest.WARNING)
def test_input_request_to_homepage_should_be_logged_in_elasticsearch_backend_through_logstash(self, user):
with log_with_data(related_objects=[user]):
with capture_security_logs() as logged_data:
with self.assertLogs('security.logstash', level='INFO') as cm:
assert_http_ok(self.get('/home/?name=value'))
input_request_log = logged_data.input_request[0]
assert_equal(len(cm.output), 2)
request_log, response_log = cm.output
request_log_expected_data = {
'slug': None,
'release': None,
'related_objects': ['|'.join(str(v) for v in get_object_triple(user))],
'extra_data': {},
'parent_log': None,
'request_headers': '{"Cookie": "[Filtered]"}',
'request_body': '',
'user_id': None,
'method': 'GET',
'host': 'testserver',
'path': '/home/',
'queries': '{"name": "value"}',
'is_secure': False,
'ip': '127.0.0.1',
'start': not_none_eq_obj,
'view_slug': 'home',
'state': 'INCOMPLETE'
}
response_log_expected_data = {
**request_log_expected_data,
'state': 'INFO',
'stop': not_none_eq_obj,
'time': not_none_eq_obj,
'response_body': 'home page response',
'response_code': 200,
'response_headers': '{"Content-Type": "text/html; charset=utf-8", ''"X-Frame-Options": "DENY"}',
}
assert_equal_logstash(
request_log,
'security-input-request-log',
0,
input_request_log.id,
request_log_expected_data
)
assert_equal_logstash(
response_log,
'security-input-request-log',
9999,
input_request_log.id,
response_log_expected_data
)
def test_elasticsearch_purge_logs_should_remove_logged_data(self):
responses.add(responses.GET, 'https://localhost/test', body='test')
with capture_security_logs() as logged_data:
test_call_command('test_command')
sum_task.apply(args=(5, 8))
assert_http_ok(self.get('/home/'))
requests.get('https://localhost/test')
elasticsearch_type_model_receivers = (
('input-request', ElasticsearchInputRequestLog,
'input_request'),
('output-request', ElasticsearchOutputRequestLog,
'output_request'),
('command', ElasticsearchCommandLog, 'command'),
('celery-task-invocation',
ElasticsearchCeleryTaskInvocationLog,
'celery_task_invocation'),
('celery-task-run', ElasticsearchCeleryTaskRunLog,
'celery_task_run'),
)
for log_type, log_model, log_data_name in elasticsearch_type_model_receivers:
log_directory = os.path.join(settings.BACKUP_STORAGE_PATH,
log_type)
os.makedirs(log_directory)
test_call_command('purge_logs',
type=log_type,
interactive=False,
expiration='1d',
backup=log_type)
log_model._index.refresh()
assert_equal(
log_model.search().filter(
'ids',
values=[logged_data[log_data_name][0].id]).count(), 1)
with freeze_time(now() + timedelta(days=1, minutes=1)):
test_call_command('purge_logs',
type=log_type,
interactive=False,
expiration='1d',
backup=log_type)
log_model._index.refresh()
assert_equal(
log_model.search().filter(
'ids',
values=[logged_data[log_data_name][0].id]).count(),
0)
assert_equal(len(os.listdir(log_directory)), 1)
shutil.rmtree(settings.BACKUP_STORAGE_PATH)
def test_input_request_to_homepage_should_be_logged_in_logging_backend(self):
with capture_security_logs() as logged_data:
with self.assertLogs('security.input_request', level='INFO') as cm:
assert_http_ok(self.get('/home/?name=value'))
assert_equal(
cm.output,
[
f'INFO:security.input_request:'
f'Input request "{logged_data.input_request[0].id}" '
f'to "testserver" with path "/home/" was started',
f'INFO:security.input_request:'
f'Input request "{logged_data.input_request[0].id}" '
f'to "testserver" with path "/home/" was finished'
]
)
def test_input_logged_request_should_have_right_status(self, user):
assert_http_ok(
self.post('/admin/login/',
data={
'username': '******',
'password': '******'
}))
assert_equal(InputLoggedRequest.objects.first().status,
LoggedRequestStatus.INFO)
assert_http_redirect(
self.post('/admin/login/',
data={
'username': '******',
'password': '******'
}))
assert_equal(InputLoggedRequest.objects.first().status,
LoggedRequestStatus.INFO)
assert_raises(Exception, self.get, '/proxy/')
assert_equal(InputLoggedRequest.objects.first().status,
LoggedRequestStatus.ERROR)
assert_http_not_found(self.get('/404/'))
assert_equal(InputLoggedRequest.objects.first().status,
LoggedRequestStatus.WARNING)
def test_sql_purge_logs_should_remove_logged_data(self):
responses.add(responses.GET, 'https://localhost/test', body='test')
test_call_command('test_command')
sum_task.apply(args=(5, 8))
assert_http_ok(self.get('/home/'))
requests.get('https://localhost/test')
sql_type_model = {
('input-request', SQLInputRequestLog),
('output-request', SQLOutputRequestLog),
('command', SQLCommandLog),
('celery-task-invocation', SQLCeleryTaskInvocationLog),
('celery-task-run', SQLCeleryTaskRunLog),
}
for log_type, log_model in sql_type_model:
log_directory = os.path.join(settings.BACKUP_STORAGE_PATH,
log_type)
os.makedirs(log_directory)
test_call_command('purge_logs',
type=log_type,
interactive=False,
expiration='1d',
backup=log_type)
assert_equal(log_model.objects.count(), 1)
with freeze_time(now() + timedelta(days=1, minutes=1)):
test_call_command('purge_logs',
type=log_type,
interactive=False,
expiration='1d',
backup=log_type)
assert_equal(log_model.objects.count(), 0)
assert_equal(len(os.listdir(log_directory)), 1)
shutil.rmtree(settings.BACKUP_STORAGE_PATH)
def test_decorated_view_with_throttling_should_raise_throttling_exception(
self):
assert_http_ok(self.get('/extra-throttling/'))
assert_http_too_many_requests(self.get('/extra-throttling/'))
def test_not_allowed_content_type_body_should_not_be_logged(self):
with capture_security_logs() as logged_data:
assert_http_ok(self.get('/home/'))
assert_is_none(logged_data.input_request[0].response_body)
def test_decorated_view_with_throttling_exempt_should_not_raise_throttling_exception(
self):
for _ in range(20):
assert_http_ok(self.get('/throttling-exempt/'))
assert_http_ok(self.get('/throttling-exempt/'))
def test_decorated_view_with_throttling_should_raise_throttling_exception(self):
assert_http_ok(self.get('/extra-throttling/'))
assert_http_too_many_requests(self.get('/extra-throttling/'))
def test_decorated_view_with_throttling_exempt_should_not_raise_throttling_exception(self):
for _ in range(20):
assert_http_ok(self.get('/throttling-exempt/'))
assert_http_ok(self.get('/throttling-exempt/'))
def test_slug_and_related_data_should_be_send_to_input_request_logger(self, user):
with log_with_data(related_objects=[user], slug='TEST'):
with capture_security_logs() as logged_data:
assert_http_ok(self.get('/home/'))
assert_equal(logged_data.input_request[0].related_objects, {get_object_triple(user)})
assert_equal(logged_data.input_request[0].slug, 'TEST')
def test_ignored_client_ip_should_not_be_logged(self):
with capture_security_logs() as logged_data:
assert_http_ok(self.get('/home/'))
assert_length_equal(logged_data.input_request, 0)
def test_sensitive_queries_should_be_hidden(self):
with capture_security_logs() as logged_data:
assert_http_ok(self.get('/home/?token=test'))
assert_equal(logged_data.input_request[0].queries['token'], '[Filtered]')
