diff --git a/autopush/endpoint.py b/autopush/endpoint.py index 8a446a58..144b398a 100644 --- a/autopush/endpoint.py +++ b/autopush/endpoint.py @@ -191,13 +191,14 @@ def _init_info(self): ############################################################# # Error Callbacks ############################################################# - def _write_response(self, status_code, errno, message=None, headers=None): + def _write_response(self, status_code, errno, message=None, headers=None, + reason=None): """Writes out a full JSON error and sets the appropriate status""" - self.set_status(status_code) + self.set_status(status_code, reason) error_data = dict( code=status_code, errno=errno, - error=status_codes.get(status_code, "") + error=status_codes.get(status_code, reason or "") ) if message: error_data["message"] = message diff --git a/autopush/log_check.py b/autopush/log_check.py new file mode 100644 index 00000000..4a12716e --- /dev/null +++ b/autopush/log_check.py @@ -0,0 +1,44 @@ +import uuid + +import cyclone.web + +from autopush.endpoint import AutoendpointHandler + + +class LogCheckError(Exception): + pass + + +class LogCheckHandler(AutoendpointHandler): + + def initialize(self, ap_settings): + self.ap_settings = ap_settings + self.request_id = str(uuid.uuid4()) + self._client_info = self._init_info() + + @cyclone.web.asynchronous + def get(self, errType=None): + """HTTP GET + + Generate a dummy error message for logging + + """ + if not errType: + errType = "error" + else: + errType = errType.lower() + if 'error' in errType: + self.log.error(format="Test Error Message", + status_code=418, errno=0, + **self._client_info) + self._write_response(418, 999, message="ERROR:Success", + reason="Test Error") + if 'crit' in errType: + try: + raise LogCheckError("LogCheck") + except: + self.log.failure(format="Test Critical Message", + status_code=418, errno=0, + **self._client_info) + self._write_response(418, 999, message="FAILURE:Success", + reason="Test Failure") diff --git a/autopush/main.py b/autopush/main.py index 9b26f47d..1f45d23a 100644 --- a/autopush/main.py +++ b/autopush/main.py @@ -16,6 +16,7 @@ MessageHandler, RegistrationHandler, ) +from autopush.log_check import LogCheckHandler from autopush.health import (HealthHandler, StatusHandler) from autopush.logging import PushLogger from autopush.settings import AutopushSettings @@ -509,6 +510,8 @@ def endpoint_main(sysargs=None, use_files=True): "?(?:/subscription)?(?:/([^\/]+))?", RegistrationHandler, dict(ap_settings=settings)), + (r"/v1/err(?:/([^\/]+))?", LogCheckHandler, + dict(ap_settings=settings)), ], default_host=settings.hostname, debug=args.debug, log_function=skip_request_logging diff --git a/autopush/tests/test_endpoint.py b/autopush/tests/test_endpoint.py index 96fa5669..9faed5cd 100644 --- a/autopush/tests/test_endpoint.py +++ b/autopush/tests/test_endpoint.py @@ -95,7 +95,7 @@ def test_delete_token_invalid(self): "decrypt.side_effect": InvalidToken}) def handle_finish(result): - self.status_mock.assert_called_with(400) + self.status_mock.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.message.delete('') @@ -105,7 +105,7 @@ def test_delete_token_wrong_components(self): self.fernet_mock.decrypt.return_value = "123:456" def handle_finish(result): - self.status_mock.assert_called_with(400) + self.status_mock.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.message.delete('') @@ -115,7 +115,7 @@ def test_delete_token_wrong_kind(self): self.fernet_mock.decrypt.return_value = "r:123:456" def handle_finish(result): - self.status_mock.assert_called_with(400) + self.status_mock.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.message.delete('') @@ -143,7 +143,7 @@ def test_delete_db_error(self): def handle_finish(result): self.assertTrue(result) - self.status_mock.assert_called_with(503) + self.status_mock.assert_called_with(503, None) self.finish_deferred.addCallback(handle_finish) self.message.delete('') @@ -248,7 +248,7 @@ def test_uaid_lookup_results_bad_ttl(self): self.endpoint._uaid_lookup_results(fresult) def handle_finish(value): - self.endpoint.set_status.assert_called_with(400) + self.endpoint.set_status.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) return self.finish_deferred @@ -314,7 +314,7 @@ def raise_error(*args): def handle_finish(result): self.flushLoggedErrors() - self.endpoint.set_status.assert_called_with(400) + self.endpoint.set_status.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.post(None, dummy_uaid) @@ -341,7 +341,7 @@ def test_webpush_bad_routertype(self): self.request_mock.body = b"stuff" self.endpoint._uaid_lookup_results(fresult) - self.endpoint.set_status.assert_called_with(400) + self.endpoint.set_status.assert_called_with(400, None) data = self.write_mock.call_args[0][0] d = json.loads(data) eq_(d.get("errno"), 108) @@ -356,7 +356,7 @@ def test_webpush_uaid_lookup_no_crypto_headers_with_data(self): self.endpoint._uaid_lookup_results(fresult) def handle_finish(value): - self.endpoint.set_status.assert_called_with(400) + self.endpoint.set_status.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) return self.finish_deferred @@ -502,7 +502,7 @@ def test_put_data_too_large(self): self.endpoint.request.body = b'version=1&data=1234' def handle_finish(result): - self.endpoint.set_status.assert_called_with(413) + self.endpoint.set_status.assert_called_with(413, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, '') @@ -527,7 +527,7 @@ def test_put_v1_token_as_v0_token(self): '\xcb\n<\x0c\xe6\xf3C4:\xa8\xaeO\xf5\xab\xfbb|' def handle_finish(result): - self.status_mock.assert_called_with(400) + self.status_mock.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, '') @@ -539,7 +539,7 @@ def test_put_token_invalid(self): self.endpoint.request.body = b'version=123&data=bad-token' def handle_finish(result): - self.status_mock.assert_called_with(400) + self.status_mock.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, '') @@ -550,7 +550,7 @@ def test_put_token_wrong(self): self.endpoint.request.body = b'version=123' def handle_finish(result): - self.status_mock.assert_called_with(400) + self.status_mock.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, '') @@ -568,7 +568,7 @@ def test_process_token_client_unknown(self): def handle_finish(result): self.router_mock.get_uaid.assert_called_with('123') - self.status_mock.assert_called_with(410) + self.status_mock.assert_called_with(410, None) self._check_error(410, 103, "") self.finish_deferred.addCallback(handle_finish) @@ -626,7 +626,7 @@ def test_put_router_needs_change(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(500) + self.endpoint.set_status.assert_called_with(500, None) assert(self.router_mock.register_user.called) self.finish_deferred.addCallback(handle_finish) @@ -646,7 +646,7 @@ def test_put_router_needs_update(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(503) + self.endpoint.set_status.assert_called_with(503, None) assert(self.router_mock.register_user.called) self.finish_deferred.addCallback(handle_finish) @@ -671,7 +671,7 @@ def test_put_bogus_headers(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(400) + self.endpoint.set_status.assert_called_with(400, None) self.finish_deferred.addBoth(handle_finish) self.endpoint.put(None, dummy_uaid) @@ -695,7 +695,7 @@ def test_put_invalid_vapid_crypto_header(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(400) + self.endpoint.set_status.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, dummy_uaid) @@ -719,7 +719,7 @@ def test_put_invalid_vapid_crypto_key(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(401) + self.endpoint.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, dummy_uaid) @@ -743,7 +743,7 @@ def test_put_invalid_vapid_auth_header(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(401) + self.endpoint.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, dummy_uaid) @@ -900,7 +900,7 @@ def test_post_webpush_with_bad_vapid_auth(self): ) def handle_finish(result): - self.endpoint.set_status.assert_called_with(401) + self.endpoint.set_status.assert_called_with(401, None) eq_(self.endpoint._client_info.get('jwt'), None) self.assertTrue(result) @@ -936,7 +936,7 @@ def test_post_webpush_no_sig(self): def handle_finish(result): eq_(self.endpoint._client_info.get('jwt'), None) self.assertTrue(result) - self.endpoint.set_status.assert_called_with(401) + self.endpoint.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) @@ -983,7 +983,7 @@ def test_post_webpush_bad_sig(self): def handle_finish(result): eq_(self.endpoint._client_info.get('jwt'), None) self.assertTrue(result) - self.endpoint.set_status.assert_called_with(401) + self.endpoint.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.post(None, dummy_uaid) @@ -1015,7 +1015,7 @@ def test_post_webpush_bad_exp(self): def handle_finish(result): eq_(self.endpoint._client_info.get('jwt'), None) self.assertTrue(result) - self.endpoint.set_status.assert_called_with(401) + self.endpoint.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.post(None, dummy_uaid) @@ -1125,7 +1125,7 @@ def raise_error(*args): def handle_finish(result): self.flushLoggedErrors() - self.endpoint.set_status.assert_called_with(503) + self.endpoint.set_status.assert_called_with(503, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.post(None, dummy_uaid) @@ -1137,7 +1137,7 @@ def test_put_db_error(self): def handle_finish(result): self.assertTrue(result) - self.endpoint.set_status.assert_called_with(503) + self.endpoint.set_status.assert_called_with(503, None) self.finish_deferred.addCallback(handle_finish) self.endpoint.put(None, dummy_uaid) @@ -1221,7 +1221,7 @@ def test_write_error_no_exc(self): self.assertTrue(self.endpoint.log.called) def _assert_error_response(self, result): - self.status_mock.assert_called_with(500) + self.status_mock.assert_called_with(500, None) def test_padding(self): # Some values can't be padded and still decode. @@ -1833,7 +1833,7 @@ def test_delete_bad_uaid(self): self.reg.request.headers["Authorization"] = self.auth def handle_finish(value): - self.reg.set_status.assert_called_with(401) + self.reg.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) self.reg.delete("test", "test", "invalid") @@ -1843,7 +1843,7 @@ def test_delete_orphans(self): self.reg.request.headers["Authorization"] = self.auth def handle_finish(value): - self.reg.set_status.assert_called_with(410) + self.reg.set_status.assert_called_with(410, None) self.router_mock.drop_user = Mock() self.router_mock.drop_user.return_value = False @@ -1855,7 +1855,7 @@ def test_delete_bad_auth(self, *args): self.reg.request.headers["Authorization"] = "Invalid" def handle_finish(value): - self.reg.set_status.assert_called_with(401) + self.reg.set_status.assert_called_with(401, None) self.finish_deferred.addCallback(handle_finish) self.reg.delete("test", "test", dummy_uaid) @@ -1865,7 +1865,7 @@ def test_delete_bad_router(self): self.reg.request.headers['Authorization'] = self.auth def handle_finish(value): - self.reg.set_status.assert_called_with(400) + self.reg.set_status.assert_called_with(400, None) self.finish_deferred.addCallback(handle_finish) self.reg.delete("invalid", "test", dummy_uaid) diff --git a/autopush/tests/test_log_check.py b/autopush/tests/test_log_check.py new file mode 100644 index 00000000..88459161 --- /dev/null +++ b/autopush/tests/test_log_check.py @@ -0,0 +1,78 @@ +import json + +import twisted +from cyclone.web import Application +from twisted.trial import unittest +from mock import Mock +from moto import mock_dynamodb2 +from nose.tools import eq_ + +from autopush.db import ( + create_rotating_message_table, +) +from autopush.log_check import LogCheckHandler +from autopush.settings import AutopushSettings +from twisted.internet.defer import Deferred + + +mock_dynamodb2 = mock_dynamodb2() + + +def setUp(): + mock_dynamodb2.start() + create_rotating_message_table() + + +def tearDown(): + mock_dynamodb2.stop() + + +class LogCheckTestCase(unittest.TestCase): + + def setUp(self): + twisted.internet.base.DelayedCall.debug = True + from twisted.logger import Logger + + settings = AutopushSettings( + hostname="localhost", + statsd_host=None, + ) + self.request_mock = Mock(body=b'', arguments={}, + headers={"ttl": "0"}, + host='example.com:8080') + self.lch = LogCheckHandler(Application(), + self.request_mock, + ap_settings=settings) + + self.finish_deferred = Deferred() + self.lch.finish = lambda: self.finish_deferred.callback(True) + self.lch.set_status = Mock() + self.lch.write = Mock() + self.lch.log = Mock(spec=Logger) + + def test_get_err(self): + + def handle_finish(value): + call_args = self.lch.log.error.call_args[1] + eq_(call_args.get('format'), 'Test Error Message') + eq_(call_args.get('status_code'), 418) + write_arg = json.loads(self.lch.write.call_args[0][0]) + eq_(write_arg.get('code'), 418) + eq_(write_arg.get('message'), "ERROR:Success") + + self.finish_deferred.addCallback(handle_finish) + self.lch.get(None) + return self.finish_deferred + + def test_get_crit(self): + + def handle_finish(value): + call_args = self.lch.log.failure.call_args[1] + eq_(call_args.get('status_code'), 418) + write_args = json.loads(self.lch.write.call_args[0][0]) + eq_(write_args.get('code'), 418) + eq_(write_args.get('error'), 'Test Failure') + + self.finish_deferred.addCallback(handle_finish) + self.lch.get('CRIT') + return self.finish_deferred