def generate_headers_for_span_context_injection(span: Span, http_method: str,
http_url: str) -> dict:
span.set_tag(tags.HTTP_METHOD, http_method)
span.set_tag(tags.HTTP_URL, http_url)
span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_RPC_CLIENT)
headers = {}
tracer.inject(span, Format.HTTP_HEADERS, headers)
return headers
async def _dispatch_request(
self,
log: NotificationLoggerAdapter,
span: Span,
device: Device,
shaved_payload: Dict[str, Any],
prio: int,
) -> List[str]:
"""
Actually attempts to dispatch the notification once.
"""
# this is no good: APNs expects ID to be in their format
# so we can't just derive a
# notif_id = context.request_id + f"-{n.devices.index(device)}"
notif_id = str(uuid4())
log.info(f"Sending as APNs-ID {notif_id}")
span.set_tag("apns_id", notif_id)
device_token = base64.b64decode(device.pushkey).hex()
request = NotificationRequest(
device_token=device_token,
message=shaved_payload,
priority=prio,
notification_id=notif_id,
)
try:
with ACTIVE_REQUESTS_GAUGE.track_inprogress():
with SEND_TIME_HISTOGRAM.time():
response = await self._send_notification(request)
except aioapns.ConnectionError:
raise TemporaryNotificationDispatchException(
"aioapns Connection Failure")
code = int(response.status)
span.set_tag(tags.HTTP_STATUS_CODE, code)
RESPONSE_STATUS_CODES_COUNTER.labels(pushkin=self.name,
code=code).inc()
if response.is_successful:
return []
else:
# .description corresponds to the 'reason' response field
span.set_tag("apns_reason", response.description)
if (code, response.description) in self.TOKEN_ERRORS:
log.info(
"APNs token %s for pushkin %s was rejected: %d %s",
device_token,
self.name,
code,
response.description,
)
return [device.pushkey]
else:
if 500 <= code < 600:
raise TemporaryNotificationDispatchException(
f"{response.status} {response.description}")
else:
raise NotificationDispatchException(
f"{response.status} {response.description}")
async def _request_dispatch(
self,
n: Notification,
log: NotificationLoggerAdapter,
body: dict,
headers: Dict[AnyStr, List[AnyStr]],
pushkeys: List[str],
span: Span,
) -> Tuple[List[str], List[str]]:
poke_start_time = time.time()
failed = []
response, response_text = await self._perform_http_request(
body, headers)
RESPONSE_STATUS_CODES_COUNTER.labels(pushkin=self.name,
code=response.code).inc()
log.debug("GCM request took %f seconds", time.time() - poke_start_time)
span.set_tag(tags.HTTP_STATUS_CODE, response.code)
if 500 <= response.code < 600:
log.debug("%d from server, waiting to try again", response.code)
retry_after = None
for header_value in response.headers.getRawHeaders(b"retry-after",
default=[]):
retry_after = int(header_value)
span.log_kv({
"event": "gcm_retry_after",
"retry_after": retry_after
})
raise TemporaryNotificationDispatchException(
"GCM server error, hopefully temporary.",
custom_retry_delay=retry_after)
elif response.code == 400:
log.error(
"%d from server, we have sent something invalid! Error: %r",
response.code,
response_text,
)
# permanent failure: give up
raise NotificationDispatchException("Invalid request")
elif response.code == 401:
log.error("401 from server! Our API key is invalid? Error: %r",
response_text)
# permanent failure: give up
raise NotificationDispatchException("Not authorised to push")
elif response.code == 404:
# assume they're all failed
log.info("Reg IDs %r get 404 response; assuming unregistered",
pushkeys)
return pushkeys, []
elif 200 <= response.code < 300:
try:
resp_object = json_decoder.decode(response_text)
except ValueError:
raise NotificationDispatchException(
"Invalid JSON response from GCM.")
if "results" not in resp_object:
log.error(
"%d from server but response contained no 'results' key: %r",
response.code,
response_text,
)
if len(resp_object["results"]) < len(pushkeys):
log.error(
"Sent %d notifications but only got %d responses!",
len(n.devices),
len(resp_object["results"]),
)
span.log_kv({
logs.EVENT: "gcm_response_mismatch",
"num_devices": len(n.devices),
"num_results": len(resp_object["results"]),
})
# determine which pushkeys to retry or forget about
new_pushkeys = []
for i, result in enumerate(resp_object["results"]):
if "error" in result:
log.warning("Error for pushkey %s: %s", pushkeys[i],
result["error"])
span.set_tag("gcm_error", result["error"])
if result["error"] in BAD_PUSHKEY_FAILURE_CODES:
log.info(
"Reg ID %r has permanently failed with code %r: "
"rejecting upstream",
pushkeys[i],
result["error"],
)
failed.append(pushkeys[i])
elif result["error"] in BAD_MESSAGE_FAILURE_CODES:
log.info(
"Message for reg ID %r has permanently failed with code %r",
pushkeys[i],
result["error"],
)
else:
log.info(
"Reg ID %r has temporarily failed with code %r",
pushkeys[i],
result["error"],
)
new_pushkeys.append(pushkeys[i])
return failed, new_pushkeys
else:
raise NotificationDispatchException(
f"Unknown GCM response code {response.code}")
async def _handle_dispatch(
self,
root_span: Span,
request: Request,
log: NotificationLoggerAdapter,
notif: Notification,
context: NotificationContext,
) -> None:
"""
Actually handle the dispatch of notifications to devices, sequentially
for simplicity.
root_span: the OpenTracing span
request: the Twisted Web Request
log: the logger to use
notif: the notification to dispatch
context: the context of the notification
"""
try:
rejected = []
for d in notif.devices:
NOTIFS_RECEIVED_DEVICE_PUSH_COUNTER.inc()
appid = d.app_id
found_pushkins = self.find_pushkins(appid)
if len(found_pushkins) == 0:
log.warning("Got notification for unknown app ID %s",
appid)
rejected.append(d.pushkey)
continue
if len(found_pushkins) > 1:
log.warning("Got notification for an ambiguous app ID %s",
appid)
rejected.append(d.pushkey)
continue
pushkin = found_pushkins[0]
log.debug("Sending push to pushkin %s for app ID %s",
pushkin.name, appid)
NOTIFS_BY_PUSHKIN.labels(pushkin.name).inc()
result = await pushkin.dispatch_notification(notif, d, context)
if not isinstance(result, list):
raise TypeError("Pushkin should return list.")
rejected += result
request.write(json.dumps({"rejected": rejected}).encode())
if rejected:
log.info(
"Successfully delivered notifications with %d rejected pushkeys",
len(rejected),
)
except NotificationDispatchException:
request.setResponseCode(502)
log.warning("Failed to dispatch notification.", exc_info=True)
except Exception:
request.setResponseCode(500)
log.error("Exception whilst dispatching notification.",
exc_info=True)
finally:
if not request._disconnected:
request.finish()
PUSHGATEWAY_HTTP_RESPONSES_COUNTER.labels(code=request.code).inc()
root_span.set_tag(tags.HTTP_STATUS_CODE, request.code)
req_time = time.perf_counter() - context.start_time
if req_time > 0:
# can be negative as perf_counter() may not be monotonic
NOTIFY_HANDLE_HISTOGRAM.labels(
code=request.code).observe(req_time)
if not 200 <= request.code < 300:
root_span.set_tag(tags.ERROR, True)
root_span.finish()
