From af3e543e503febcc1d68c9b26cbc959c53139db3 Mon Sep 17 00:00:00 2001 From: Ben Bangert Date: Wed, 19 Jul 2017 09:49:43 -0700 Subject: [PATCH] fix: move metric increments to lowest callbacks The metric increments were being called for registration API calls due to an error callback. They weren't called for success cases as well. Moving them to the lower callbacks with a new flag should help ensure they're incremented correctly. Closes #958 --- autopush/web/base.py | 48 +++++++++++++++++++++++--------------- autopush/web/simplepush.py | 5 ++++ autopush/web/webpush.py | 14 ++++------- 3 files changed, 39 insertions(+), 28 deletions(-) diff --git a/autopush/web/base.py b/autopush/web/base.py index bd70d772..af82cc44 100644 --- a/autopush/web/base.py +++ b/autopush/web/base.py @@ -154,6 +154,7 @@ def initialize(self): self._base_tags = {} self._start_time = time.time() self._timings = {} + self._handling_message = False @property def routers(self): @@ -186,7 +187,9 @@ def head(self, *args, **kwargs): ############################################################# def _write_response(self, status_code, errno, message=None, error=None, headers=None, - url=DEFAULT_ERR_URL): + url=DEFAULT_ERR_URL, + router_type=None, + vapid=None): """Writes out a full JSON error and sets the appropriate status""" self.set_status(status_code, reason=error) error_data = dict( @@ -207,6 +210,13 @@ def _write_response(self, status_code, errno, message=None, error=None, if status_code == 410: self.set_header("Cache-Control", "max-age=86400") + if self._handling_message and status_code >= 300: + self.metrics.increment('notification.message.error', + tags=[ + "code:{}".format(status_code), + "router:{}".format(router_type), + "vapid:{}".format(vapid is not None) + ]) self._track_timing() self.finish() @@ -255,7 +265,7 @@ def _boto_err(self, fail): self._write_response(503, errno=202, message="Communication error, please retry") - def _router_response(self, response): + def _router_response(self, response, router_type=None, vapid=False): for name, val in response.headers.items(): if val is not None: self.set_header(name, val) @@ -263,19 +273,33 @@ def _router_response(self, response): if 200 <= response.status_code < 300: self.set_status(response.status_code, reason=None) self.write(response.response_body) + + dest = 'Direct' + if response.status_code == 202 or response.logged_status == 202: + dest = 'Stored' + + if self._handling_message: + self.metrics.increment('notification.message.success', + tags=[ + 'destination:{}'.format(dest), + 'router:{}'.format(router_type), + 'vapid:{}'.format(vapid is not None) + ]) self._track_timing(status_code=response.logged_status) self.finish() else: self._write_response( response.status_code, errno=response.errno or 999, - message=response.response_body) + message=response.response_body, + router_type=router_type, + vapid=vapid + ) def _router_fail_err(self, fail, router_type=None, vapid=False): """errBack for router failures""" fail.trap(RouterException) exc = fail.value - success = False if exc.log_exception: if exc.status_code >= 500: fmt = fail.value.message or 'Exception' @@ -288,27 +312,13 @@ def _router_fail_err(self, fail, router_type=None, vapid=False): self.log.debug(format="Success", status_code=exc.status_code, logged_status=exc.logged_status or 0, client_info=self._client_info) - success = True - self.metrics.increment('notification.message.success', - tags=[ - 'destination:Direct', - 'router:{}'.format(router_type), - 'vapid:{}'.format(vapid is not None) - ]) elif 400 <= exc.status_code < 500: self.log.debug(format="Client error", status_code=exc.status_code, logged_status=exc.logged_status or 0, errno=exc.errno or 0, client_info=self._client_info) - if not success: - self.metrics.increment('notification.message.error', - tags=[ - "code:{}".format(exc.status_code), - "router:{}".format(router_type), - "vapid:{}".format(vapid is not None) - ]) - self._router_response(exc) + self._router_response(exc, router_type, vapid) def _write_validation_err(self, errors): """Writes a set of validation errors out with details about what diff --git a/autopush/web/simplepush.py b/autopush/web/simplepush.py index fd31d216..1fc0fcb1 100644 --- a/autopush/web/simplepush.py +++ b/autopush/web/simplepush.py @@ -104,6 +104,11 @@ def extract_fields(self, d): class SimplePushHandler(BaseWebHandler): cors_methods = "PUT" + def initialize(self): + """Must run on initialization to set ahead of validation""" + super(SimplePushHandler, self).initialize() + self._handling_message = True + @threaded_validate(SimplePushRequestSchema) def put(self, subscription, version, data): # type: (Dict[str, Any], str, str) -> Deferred diff --git a/autopush/web/webpush.py b/autopush/web/webpush.py index b812fc79..1d8f5127 100644 --- a/autopush/web/webpush.py +++ b/autopush/web/webpush.py @@ -441,6 +441,11 @@ class WebPushHandler(BaseWebHandler): "authorization") cors_response_headers = ("location", "www-authenticate") + def initialize(self): + """Must run on initialization to set ahead of validation""" + super(WebPushHandler, self).initialize() + self._handling_message = True + @threaded_validate(WebPushRequestSchema) def post(self, subscription, # type: Dict[str, Any] @@ -520,7 +525,6 @@ def _router_completed(self, response, uaid_data, warning="", return d else: # No changes are requested by the bridge system, proceed as normal - dest = 'Direct' if response.status_code == 200 or response.logged_status == 200: self.log.debug(format="Successful delivery", client_info=self._client_info) @@ -528,16 +532,8 @@ def _router_completed(self, response, uaid_data, warning="", self.log.debug( format="Router miss, message stored.", client_info=self._client_info) - dest = 'Stored' self.metrics.timing("notification.request_time", duration=time_diff) - self.metrics.increment('notification.message.success', - tags=make_tags( - destination=dest, - router=router_type, - vapid=(vapid is not None)) - ) - response.response_body = ( response.response_body + " " + warning).strip() self._router_response(response)