async def _dispatch_request(self, log, span, device, shaved_payload, prio):
"""
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 == self.TOKEN_ERROR_CODE
or response.description == self.TOKEN_ERROR_REASON):
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 dispatch_notification(self, n, device, context):
if device.pushkey == "raise_exception":
raise Exception("Bad things have occurred!")
elif device.pushkey == "remote_error":
raise NotificationDispatchException("Synthetic failure")
elif device.pushkey == "temporary_remote_error":
raise TemporaryNotificationDispatchException("Synthetic failure")
elif device.pushkey == "reject":
return [device.pushkey]
elif device.pushkey == "accept":
return []
raise Exception(f"Unexpected fall-through. {device.pushkey}")
async def dispatch_notification(
self, n: Notification, device: Device, context: "NotificationContext"
) -> List[str]:
if self._concurrent_now >= self._concurrent_limit:
self.dropped_requests_counter.inc()
raise NotificationDispatchException(
"Too many in-flight requests for this pushkin. "
"(Something is wrong and Sygnal is struggling to keep up!)"
)
self._concurrent_now += 1
try:
return await self._dispatch_notification_unlimited(n, device, context)
finally:
self._concurrent_now -= 1
async def _dispatch_notification_unlimited(
self, n: Notification, device: Device,
context: NotificationContext) -> List[str]:
log = NotificationLoggerAdapter(logger,
{"request_id": context.request_id})
# The pushkey is kind of secret because you can use it to send push
# to someone.
# span_tags = {"pushkey": device.pushkey}
span_tags: Dict[str, int] = {}
with self.sygnal.tracer.start_span(
"apns_dispatch", tags=span_tags,
child_of=context.opentracing_span) as span_parent:
# Before we build the payload, check that the default_payload is not
# malformed and reject the pushkey if it is
default_payload = {}
if device.data:
default_payload = device.data.get("default_payload", {})
if not isinstance(default_payload, dict):
log.error(
"default_payload is malformed, this value must be a dict."
)
return [device.pushkey]
if n.event_id and not n.type:
payload: Optional[Dict[str,
Any]] = self._get_payload_event_id_only(
n, default_payload)
else:
payload = self._get_payload_full(n, device, log)
if payload is None:
# Nothing to do
span_parent.log_kv({logs.EVENT: "apns_no_payload"})
return []
prio = 10
if n.prio == "low":
prio = 5
shaved_payload = apnstruncate.truncate(
payload, max_length=self.MAX_JSON_BODY_SIZE)
for retry_number in range(self.MAX_TRIES):
try:
span_tags = {"retry_num": retry_number}
with self.sygnal.tracer.start_span(
"apns_dispatch_try",
tags=span_tags,
child_of=span_parent) as span:
assert shaved_payload is not None
return await self._dispatch_request(
log, span, device, shaved_payload, prio)
except TemporaryNotificationDispatchException as exc:
retry_delay = self.RETRY_DELAY_BASE * (2**retry_number)
if exc.custom_retry_delay is not None:
retry_delay = exc.custom_retry_delay
log.warning(
"Temporary failure, will retry in %d seconds",
retry_delay,
exc_info=True,
)
span_parent.log_kv({
"event": "temporary_fail",
"retrying_in": retry_delay
})
if retry_number < self.MAX_TRIES - 1:
await twisted_sleep(
retry_delay, twisted_reactor=self.sygnal.reactor)
raise NotificationDispatchException("Retried too many times.")
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 _dispatch_notification_unlimited(self, n, device, context):
log = NotificationLoggerAdapter(logger,
{"request_id": context.request_id})
# The pushkey is kind of secret because you can use it to send push
# to someone.
# span_tags = {"pushkey": device.pushkey}
span_tags: Dict[str, int] = {}
with self.sygnal.tracer.start_span(
"apns_dispatch", tags=span_tags,
child_of=context.opentracing_span) as span_parent:
if n.event_id and not n.type:
payload = self._get_payload_event_id_only(n, device)
else:
payload = self._get_payload_full(n, device, log)
if payload is None:
# Nothing to do
span_parent.log_kv({logs.EVENT: "apns_no_payload"})
return
prio = 10
if n.prio == "low":
prio = 5
shaved_payload = apnstruncate.truncate(
payload, max_length=self.MAX_JSON_BODY_SIZE)
for retry_number in range(self.MAX_TRIES):
try:
log.debug("Trying")
span_tags = {"retry_num": retry_number}
with self.sygnal.tracer.start_span(
"apns_dispatch_try",
tags=span_tags,
child_of=span_parent) as span:
return await self._dispatch_request(
log, span, device, shaved_payload, prio)
except TemporaryNotificationDispatchException as exc:
retry_delay = self.RETRY_DELAY_BASE * (2**retry_number)
if exc.custom_retry_delay is not None:
retry_delay = exc.custom_retry_delay
log.warning(
"Temporary failure, will retry in %d seconds",
retry_delay,
exc_info=True,
)
span_parent.log_kv({
"event": "temporary_fail",
"retrying_in": retry_delay
})
if retry_number == self.MAX_TRIES - 1:
raise NotificationDispatchException(
"Retried too many times.") from exc
else:
await twisted_sleep(
retry_delay, twisted_reactor=self.sygnal.reactor)
