From ed5d6e5938e1c8d56d6f03efdc1b7df5fd95d103 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Tue, 18 Jan 2022 20:46:14 -0500 Subject: [PATCH 01/43] Exactly-once changes --- google/cloud/pubsub_v1/proto/pubsub.proto | 1 + .../subscriber/_protocol/dispatcher.py | 79 ++- .../pubsub_v1/subscriber/_protocol/leaser.py | 2 +- .../subscriber/_protocol/requests.py | 6 + .../_protocol/streaming_pull_manager.py | 191 +++++- google/cloud/pubsub_v1/subscriber/futures.py | 45 ++ google/cloud/pubsub_v1/subscriber/message.py | 102 +++- google/cloud/pubsub_v1/types.py | 7 + .../pubsub_v1/subscriber/test_dispatcher.py | 91 ++- .../unit/pubsub_v1/subscriber/test_leaser.py | 8 +- .../unit/pubsub_v1/subscriber/test_message.py | 5 +- .../subscriber/test_streaming_pull_manager.py | 542 +++++++++++++++++- 12 files changed, 940 insertions(+), 139 deletions(-) diff --git a/google/cloud/pubsub_v1/proto/pubsub.proto b/google/cloud/pubsub_v1/proto/pubsub.proto index c5cb855d6..716c7ba05 100644 --- a/google/cloud/pubsub_v1/proto/pubsub.proto +++ b/google/cloud/pubsub_v1/proto/pubsub.proto @@ -1164,6 +1164,7 @@ message StreamingPullRequest { message StreamingPullResponse { // Subscription properties sent as part of the response. message SubscriptionProperties { + bool exactly_once_delivery_enabled = 1; // True iff message ordering is enabled for this subscription. bool message_ordering_enabled = 2; } diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 885210fc6..9e6f81632 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -22,6 +22,7 @@ import typing from typing import List, Optional, Sequence, Union import warnings +from google.api_core.retry import exponential_sleep_generator from google.cloud.pubsub_v1.subscriber._protocol import helper_threads from google.cloud.pubsub_v1.subscriber._protocol import requests @@ -66,6 +67,13 @@ IDs at a time. """ +_MIN_ACK_MODACK_RETRY_DURATION_SECS = 1 +"""The time to wait for the first retry of failed acks and modacks when exactly-once +is enabled.""" + +_MAX_ACK_MODACK_RETRY_DURATION_SECS = 20 * 60 +"""The maximum amount of time in seconds to retry failed acks and modacks when +exactly-once is enabled.""" class Dispatcher(object): def __init__(self, manager: "StreamingPullManager", queue: "queue.Queue"): @@ -168,17 +176,35 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: # We must potentially split the request into multiple smaller requests # to avoid the server-side max request size limit. - ack_ids = (item.ack_id for item in items) + items_gen = iter(items) + ack_ids_gen = (item.ack_id for item in items) total_chunks = int(math.ceil(len(items) / _ACK_IDS_BATCH_SIZE)) for _ in range(total_chunks): - request = gapic_types.StreamingPullRequest( - ack_ids=itertools.islice(ack_ids, _ACK_IDS_BATCH_SIZE) - ) - self._manager.send(request) - - # Remove the message from lease management. - self.drop(items) + future_reqs_dict = {req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) if req.future} + requests_completed, requests_to_retry = self._manager.send_unary_ack( + ack_ids=list(itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE)), + future_reqs_dict=future_reqs_dict) + + # Remove the completed messages from lease management. + self.drop(requests_completed) + + # retry acks + retry_delay_gen = exponential_sleep_generator(initial=_MIN_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_ACK_MODACK_RETRY_DURATION_SECS) + while requests_to_retry: + time_to_wait = retry_delay_gen() + _LOGGER.debug("Retrying {len(requests_to_retry)} ack(s) after delay of " + + str(time_to_wait) + " seconds") + time.sleep(time_to_wait) + + future_reqs_dict = {req.ack_id: req for req in requests_to_retry if req.future} + requests_completed, requests_to_retry = self._manager.send_unary_ack( + ack_ids=[req.ack_id for req in requests_to_retry], + future_reqs_dict=future_reqs_dict) + assert len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE, "Too many requests to be retried." + # Remove the completed messages from lease management. + self.drop(requests_completed) def drop( self, @@ -215,16 +241,35 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: """ # We must potentially split the request into multiple smaller requests # to avoid the server-side max request size limit. - ack_ids = (item.ack_id for item in items) - seconds = (item.seconds for item in items) + items_gen = iter(items) + ack_ids_gen = (item.ack_id for item in items) + deadline_seconds_gen = (item.seconds for item in items) total_chunks = int(math.ceil(len(items) / _ACK_IDS_BATCH_SIZE)) for _ in range(total_chunks): - request = gapic_types.StreamingPullRequest( - modify_deadline_ack_ids=itertools.islice(ack_ids, _ACK_IDS_BATCH_SIZE), - modify_deadline_seconds=itertools.islice(seconds, _ACK_IDS_BATCH_SIZE), - ) - self._manager.send(request) + future_reqs_dict = {req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) if req.future} + # no further work needs to be done for `requests_to_retry` + requests_completed, requests_to_retry = self._manager.send_unary_modack( + modify_deadline_ack_ids=list(itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE)), + modify_deadline_seconds=list(itertools.islice(deadline_seconds_gen, _ACK_IDS_BATCH_SIZE)), + future_reqs_dict=future_reqs_dict) + assert len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE, "Too many requests to be retried." + + # retry modacks + retry_delay_gen = exponential_sleep_generator(initial=_MIN_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_ACK_MODACK_RETRY_DURATION_SECS) + while requests_to_retry: + time_to_wait = retry_delay_gen() + _LOGGER.debug("Retrying {len(requests_to_retry)} modack(s) after delay of " + + str(time_to_wait) + " seconds") + time.sleep(time_to_wait) + + print(requests_to_retry) + future_reqs_dict = {req.ack_id: req for req in requests_to_retry if req.future} + requests_to_retry = self._manager.send_unary_modack( + modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], + modify_deadline_seconds=[req.seconds for req in requests_to_retry], + future_reqs_dict=future_reqs_dict) def nack(self, items: Sequence[requests.NackRequest]) -> None: """Explicitly deny receipt of messages. @@ -233,6 +278,6 @@ def nack(self, items: Sequence[requests.NackRequest]) -> None: items: The items to deny. """ self.modify_ack_deadline( - [requests.ModAckRequest(ack_id=item.ack_id, seconds=0) for item in items] + [requests.ModAckRequest(ack_id=item.ack_id, seconds=0, future=item.future) for item in items] ) - self.drop([requests.DropRequest(*item) for item in items]) + self.drop([requests.DropRequest(ack_id=item.ack_id, byte_size=item.byte_size, ordering_key=item.ordering_key) for item in items]) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py index bfa1b5a49..ad8b01595 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py @@ -195,7 +195,7 @@ def maintain_leases(self) -> None: # is inactive. assert self._manager.dispatcher is not None self._manager.dispatcher.modify_ack_deadline( - [requests.ModAckRequest(ack_id, deadline) for ack_id in ack_ids] + [requests.ModAckRequest(ack_id, deadline, None) for ack_id in ack_ids] ) # Now wait an appropriate period of time and do this again. diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/requests.py b/google/cloud/pubsub_v1/subscriber/_protocol/requests.py index 7481d95a9..c8dd90d90 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/requests.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/requests.py @@ -12,8 +12,11 @@ # See the License for the specific language governing permissions and # limitations under the License. +import typing from typing import NamedTuple, Optional +if typing.TYPE_CHECKING: # pragma: NO COVER + from google.cloud.pubsub_v1.subscriber import futures # Namedtuples for management requests. Used by the Message class to communicate # items of work back to the policy. @@ -22,6 +25,7 @@ class AckRequest(NamedTuple): byte_size: int time_to_ack: float ordering_key: Optional[str] + future: Optional["pubsub_v1.subscriber.futures.Future"] class DropRequest(NamedTuple): @@ -39,9 +43,11 @@ class LeaseRequest(NamedTuple): class ModAckRequest(NamedTuple): ack_id: str seconds: float + future: Optional["pubsub_v1.subscriber.futures.Future"] class NackRequest(NamedTuple): ack_id: str byte_size: int ordering_key: Optional[str] + future: Optional["pubsub_v1.subscriber.futures.Future"] diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index d207718fc..328ff544a 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -20,7 +20,7 @@ import logging import threading import typing -from typing import Any, Callable, Iterable, List, Optional, Union +from typing import Any, Callable, Iterable, List, Optional, Tuple, Union import uuid import grpc # type: ignore @@ -37,9 +37,13 @@ import google.cloud.pubsub_v1.subscriber.message from google.cloud.pubsub_v1.subscriber.scheduler import ThreadScheduler from google.pubsub_v1 import types as gapic_types +from grpc_status import rpc_status +from google.rpc.error_details_pb2 import ErrorInfo if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1 import subscriber + from google.cloud.pubsub_v1.subscriber.scheduler import Scheduler + from google.protobuf.internal import containers _LOGGER = logging.getLogger(__name__) @@ -60,6 +64,10 @@ _RESUME_THRESHOLD = 0.8 """The load threshold below which to resume the incoming message stream.""" +_MIN_ACK_DEADLINE_SECS_WHEN_EXACTLY_ONCE_ENABLED = 60 +"""The minimum ack_deadline, in seconds, for when exactly_once is enabled for +a subscription. We do this to reduce premature ack expiration. +""" def _wrap_as_exception(maybe_exception: Any) -> BaseException: """Wrap an object as a Python exception, if needed. @@ -104,6 +112,63 @@ def _wrap_callback_errors( on_callback_error(exc) +def _get_ack_errors(exc: exceptions.GoogleAPICallError) -> Optional["containers.ScalarMap"]: + if not exc.response: + _LOGGER.debug("No response obj in errored RPC call.") + return None + try: + status = rpc_status.from_call(exc.response) + if not status: + _LOGGER.debug("Unable to get status of errored RPC.") + return None + for detail in status.details: + if detail.Is(ErrorInfo.DESCRIPTOR): + info = ErrorInfo() + if not detail.Unpack(info): + _LOGGER.debug("Unable to unpack ErrorInfo.") + return None + return info.metadata + # Possible "If the gRPC call’s code or details are inconsistent + # with the status code and message inside of the + # google.rpc.status.Status" + except ValueError: + _LOGGER.debug( "ValueError when parsing ErrorInfo.", exc_info=True) + return None + +def _process_futures(future_reqs_dict: "containers.ScalarMap", + errors_dict: Optional["containers.ScalarMap"]): + """Process futures by referring to errors_dict. + + The errors returned by the server in `errors_dict` are used to complete + the request futures in `future_reqs_dict` (with a success or exception) or + to return requests for further retries. + """ + requests_completed = [] + requests_to_retry = [] + for ack_id in future_reqs_dict: + if errors_dict and ack_id in errors_dict: + exactly_once_error = errors_dict[ack_id] + if exactly_once_error.startswith("PERMANENT_"): + exc = RuntimeError("Permanent error: " + exactly_once_error) + future = future_reqs_dict[ack_id].future + future.set_exception(exc) + requests_completed.append(future_reqs_dict[ack_id]) + elif exactly_once_error.startswith("TRANSIENT_"): + requests_to_retry.append(future_reqs_dict[ack_id]) + else: + exc = RuntimeError("Unknown error: " + exactly_once_error) + future = future_reqs_dict[ack_id].future + future.set_exception(exc) + requests_completed.append(future_reqs_dict[ack_id]) + else: + future = future_reqs_dict[ack_id].future + # success + future.set_result(ack_id) + requests_completed.append(future_reqs_dict[ack_id]) + + return requests_completed, requests_to_retry + + class StreamingPullManager(object): """The streaming pull manager coordinates pulling messages from Pub/Sub, leasing them, and scheduling them to be processed. @@ -148,6 +213,7 @@ def __init__( ): self._client = client self._subscription = subscription + self._exactly_once_enabled = False self._flow_control = flow_control self._use_legacy_flow_control = use_legacy_flow_control self._await_callbacks_on_shutdown = await_callbacks_on_shutdown @@ -159,6 +225,8 @@ def __init__( self._closing = threading.Lock() self._closed = False self._close_callbacks: List[Callable[["StreamingPullManager", Any], Any]] = [] + # Guarded by self._exactly_once_enabled_lock + self._send_new_ack_deadline = False # A shutdown thread is created on intentional shutdown. self._regular_shutdown_thread: Optional[threading.Thread] = None @@ -189,6 +257,12 @@ def __init__( # currently on hold. self._pause_resume_lock = threading.Lock() + # A lock guarding the self._exactly_once_enabled variable. We may also + # acquire the self._ack_deadline_lock while this lock is held, but not + # the reverse. So, we maintain a simple ordering of these two locks to + # prevent deadlocks. + self._exactly_once_enabled_lock = threading.Lock() + # A lock protecting the current ACK deadline used in the lease management. This # value can be potentially updated both by the leaser thread and by the message # consumer thread when invoking the internal _on_response() callback. @@ -273,6 +347,20 @@ def _obtain_ack_deadline(self, maybe_update: bool) -> float: histogram.MIN_ACK_DEADLINE, ) self._ack_deadline = min(self._ack_deadline, flow_control_setting) + + # If the user explicitly sets a min ack_deadline, respect it. + if self.flow_control.min_duration_per_lease_extension > 0: + # The setting in flow control could be too high, adjust if needed. + flow_control_setting = min( + self.flow_control.min_duration_per_lease_extension, + histogram.MAX_ACK_DEADLINE, + ) + self._ack_deadline = max(self._ack_deadline, flow_control_setting) + elif self._exactly_once_enabled: + # Higher minimum ack_deadline for exactly_once subscriptions. + self._ack_deadline = max(self._ack_deadline, + _MIN_ACK_DEADLINE_SECS_WHEN_EXACTLY_ONCE_ENABLED) + return self._ack_deadline @property @@ -435,48 +523,73 @@ def _schedule_message_on_hold( assert self._callback is not None self._scheduler.schedule(self._callback, msg) - def _send_unary_request(self, request: gapic_types.StreamingPullRequest) -> None: + + def send_unary_ack(self, ack_ids, future_reqs_dict) -> Tuple[List[requests.AckRequest], List[requests.AckRequest]]: """Send a request using a separate unary request instead of over the stream. - Args: - request: The stream request to be mapped into unary requests. + If a RetryError occurs, the manager shutdown is triggered, and the + error is re-raised. """ - if request.ack_ids: - self._client.acknowledge( # type: ignore - subscription=self._subscription, ack_ids=list(request.ack_ids) + assert ack_ids + + success = True + ack_errors_dict = None + try: + self._client.acknowledge( + subscription=self._subscription, ack_ids=ack_ids ) + except exceptions.GoogleAPICallError as exc: + _LOGGER.debug( + "Exception while sending unary RPC. This is typically " + "non-fatal as stream requests are best-effort.", + exc_info=True, + ) + ack_errors_dict = _get_ack_errors(exc) + except exceptions.RetryError as exc: + _LOGGER.debug( + "RetryError while sending unary RPC. Waiting on a transient " + "error resolution for too long, will now trigger shutdown.", + exc_info=False, + ) + # The underlying channel has been suffering from a retryable error + # for too long, time to give up and shut the streaming pull down. + self._on_rpc_done(exc) + raise + + requests_completed, requests_to_retry = _process_futures(future_reqs_dict, ack_errors_dict) + return requests_completed, requests_to_retry + + + def send_unary_modack(self, modify_deadline_ack_ids, modify_deadline_seconds, future_reqs_dict) -> Tuple[List[requests.ModAckRequest], List[requests.ModAckRequest]]: + """Send a request using a separate unary request instead of over the stream. + + If a RetryError occurs, the manager shutdown is triggered, and the + error is re-raised. + """ + assert modify_deadline_ack_ids - if request.modify_deadline_ack_ids: + modack_errors_dict = None + try: # Send ack_ids with the same deadline seconds together. deadline_to_ack_ids = collections.defaultdict(list) - for n, ack_id in enumerate(request.modify_deadline_ack_ids): - deadline = request.modify_deadline_seconds[n] + for n, ack_id in enumerate(modify_deadline_ack_ids): + deadline = modify_deadline_seconds[n] deadline_to_ack_ids[deadline].append(ack_id) for deadline, ack_ids in deadline_to_ack_ids.items(): - self._client.modify_ack_deadline( # type: ignore + self._client.modify_ack_deadline( subscription=self._subscription, ack_ids=ack_ids, ack_deadline_seconds=deadline, ) - - _LOGGER.debug("Sent request(s) over unary RPC.") - - def send(self, request: gapic_types.StreamingPullRequest) -> None: - """Queue a request to be sent to the RPC. - - If a RetryError occurs, the manager shutdown is triggered, and the - error is re-raised. - """ - try: - self._send_unary_request(request) - except exceptions.GoogleAPICallError: + except exceptions.GoogleAPICallError as exc: _LOGGER.debug( "Exception while sending unary RPC. This is typically " "non-fatal as stream requests are best-effort.", exc_info=True, ) + modack_errors_dict = _get_ack_errors(exc) except exceptions.RetryError as exc: _LOGGER.debug( "RetryError while sending unary RPC. Waiting on a transient " @@ -488,14 +601,31 @@ def send(self, request: gapic_types.StreamingPullRequest) -> None: self._on_rpc_done(exc) raise + requests_completed, requests_to_retry = _process_futures(future_reqs_dict, modack_errors_dict) + return requests_completed, requests_to_retry + def heartbeat(self) -> bool: - """Sends an empty request over the streaming pull RPC. + """Sends a heartbeat request over the streaming pull RPC. + + The request is empty by default, but may contain the current ack_deadline + if the exactly_once flag has changed. Returns: If a heartbeat request has actually been sent. """ if self._rpc is not None and self._rpc.is_active: - self._rpc.send(gapic_types.StreamingPullRequest()) + send_new_ack_deadline = False + with self._exactly_once_enabled_lock: + send_new_ack_deadline = self._send_new_ack_deadline + self._send_new_ack_deadline = False + + if send_new_ack_deadline: + request = gapic_types.StreamingPullRequest( + stream_ack_deadline_seconds=self.ack_deadline) + else: + request = gapic_types.StreamingPullRequest() + + self._rpc.send(request) return True return False @@ -730,11 +860,20 @@ def _on_response(self, response: gapic_types.StreamingPullResponse) -> None: self._on_hold_bytes, ) + with self._exactly_once_enabled_lock: + if response.subscription_properties.exactly_once_delivery_enabled != \ + self._exactly_once_enabled: + self._exactly_once_enabled = response.subscription_properties.exactly_once_delivery_enabled + # Update ack_deadline, whose minimum depends on self._exactly_once_enabled + # This method acquires the self._ack_deadline_lock lock. + self._obtain_ack_deadline(maybe_update=True) + self._send_new_ack_deadline = True + # Immediately (i.e. without waiting for the auto lease management) # modack the messages we received, as this tells the server that we've # received them. items = [ - requests.ModAckRequest(message.ack_id, self.ack_deadline) + requests.ModAckRequest(message.ack_id, self.ack_deadline, None) for message in received_messages ] assert self._dispatcher is not None diff --git a/google/cloud/pubsub_v1/subscriber/futures.py b/google/cloud/pubsub_v1/subscriber/futures.py index a024ba698..71cef2d57 100644 --- a/google/cloud/pubsub_v1/subscriber/futures.py +++ b/google/cloud/pubsub_v1/subscriber/futures.py @@ -16,6 +16,7 @@ import typing from typing import Any +from typing import Union from google.cloud.pubsub_v1 import futures @@ -80,3 +81,47 @@ def cancelled(self) -> bool: ``True`` if the subscription has been cancelled. """ return self.__cancelled + + +class Future(futures.Future): + # TODO: update docs as necessary + """This future object for subscribe-side calls. + + Calling :meth:`result` will resolve the future by returning the message + ID, unless an error occurs. + """ + + def cancel(self) -> bool: + """Actions in Pub/Sub generally may not be canceled. + + This method always returns ``False``. + """ + return False + + def cancelled(self) -> bool: + """Actions in Pub/Sub generally may not be canceled. + + This method always returns ``False``. + """ + return False + + # TODO modify return type annotation + def result(self, timeout: Union[int, float] = None) -> str: + """Return the message ID or raise an exception. + + This blocks until the operation completes successfully and + returns the error code unless an exception is raised. + + Args: + timeout: The number of seconds before this call + times out and raises TimeoutError. + + Returns: + The message ID. + + Raises: + concurrent.futures.TimeoutError: If the request times out. + Exception: For undefined exceptions in the underlying + call execution. + """ + return super().result(timeout=timeout) diff --git a/google/cloud/pubsub_v1/subscriber/message.py b/google/cloud/pubsub_v1/subscriber/message.py index 2d72bba57..78ac62db3 100644 --- a/google/cloud/pubsub_v1/subscriber/message.py +++ b/google/cloud/pubsub_v1/subscriber/message.py @@ -22,6 +22,7 @@ from typing import Optional from google.cloud.pubsub_v1.subscriber._protocol import requests +from google.cloud.pubsub_v1.subscriber import futures if typing.TYPE_CHECKING: # pragma: NO COVER import datetime @@ -242,9 +243,44 @@ def ack(self) -> None: byte_size=self.size, time_to_ack=time_to_ack, ordering_key=self.ordering_key, + future=None ) ) + def ack_with_response(self) -> "pubsub_v1.subscriber.futures.Future": + """Acknowledge the given message. + + Acknowledging a message in Pub/Sub means that you are done + with it, and it will not be delivered to this subscription again. + You should avoid acknowledging messages until you have + *finished* processing them, so that in the event of a failure, + you receive the message again. + + .. warning:: + Acks in Pub/Sub are best effort. You should always + ensure that your processing code is idempotent, as you may + receive any given message more than once. + + Returns: + A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` + instance that conforms to Python Standard library's + :class:`~concurrent.futures.Future` interface (but not an + instance of that class). + """ + future = futures.Future() + time_to_ack = math.ceil(time.time() - self._received_timestamp) + self._request_queue.put( + requests.AckRequest( + ack_id=self._ack_id, + byte_size=self.size, + time_to_ack=time_to_ack, + ordering_key=self.ordering_key, + future=future + ) + ) + return future + + def drop(self) -> None: """Release the message from lease management. @@ -269,8 +305,8 @@ def modify_ack_deadline(self, seconds: int) -> None: New deadline will be the given value of seconds from now. - The default implementation handles this for you; you should not need - to manually deal with setting ack deadlines. The exception case is + The default implementation handles automatically modacking received messages for you; + you should not need to manually deal with setting ack deadlines. The exception case is if you are implementing your own custom subclass of :class:`~.pubsub_v1.subcriber._consumer.Consumer`. @@ -281,16 +317,70 @@ def modify_ack_deadline(self, seconds: int) -> None: against. """ self._request_queue.put( - requests.ModAckRequest(ack_id=self._ack_id, seconds=seconds) + requests.ModAckRequest(ack_id=self._ack_id, seconds=seconds, future=None) ) + def modify_ack_deadline_with_response(self, seconds: int) -> "pubsub_v1.subscriber.futures.Future": + """Resets the deadline for acknowledgement and returns the response + status via a future. + + New deadline will be the given value of seconds from now. + + The default implementation handles automatically modacking received messages for you; + you should not need to manually deal with setting ack deadlines. The exception case is + if you are implementing your own custom subclass of + :class:`~.pubsub_v1.subcriber._consumer.Consumer`. + + Args: + seconds: + The number of seconds to set the lease deadline to. This should be + between 0 and 600. Due to network latency, values below 10 are advised + against. + Returns: + A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` + instance that conforms to Python Standard library's + :class:`~concurrent.futures.Future` interface (but not an + instance of that class). + """ + future = futures.Future() + self._request_queue.put( + requests.ModAckRequest(ack_id=self._ack_id, seconds=seconds, future=future) + ) + return future + def nack(self) -> None: - """Decline to acknowldge the given message. + """Decline to acknowledge the given message. - This will cause the message to be re-delivered to the subscription. + This will cause the message to be re-delivered to subscribers. Re-deliveries + may take place immediately or after a delay, and may arrive at this subscriber + or another. """ self._request_queue.put( requests.NackRequest( - ack_id=self._ack_id, byte_size=self.size, ordering_key=self.ordering_key + ack_id=self._ack_id, byte_size=self.size, ordering_key=self.ordering_key, + future=None + ) + ) + + def nack_with_response(self) -> "pubsub_v1.subscriber.futures.Future": + """Decline to acknowledge the given message, returning the response status via + a future. + + This will cause the message to be re-delivered to subscribers. Re-deliveries + may take place immediately or after a delay, and may arrive at this subscriber + or another. + + Returns: + A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` + instance that conforms to Python Standard library's + :class:`~concurrent.futures.Future` interface (but not an + instance of that class). + """ + future = futures.Future() + self._request_queue.put( + requests.NackRequest( + ack_id=self._ack_id, byte_size=self.size, ordering_key=self.ordering_key, + future=future ) ) + return future diff --git a/google/cloud/pubsub_v1/types.py b/google/cloud/pubsub_v1/types.py index e843a6da9..5c017da27 100644 --- a/google/cloud/pubsub_v1/types.py +++ b/google/cloud/pubsub_v1/types.py @@ -162,6 +162,13 @@ class FlowControl(NamedTuple): "before dropping it from the lease management." ) + min_duration_per_lease_extension: float = 0 + ( + "The min amount of time in seconds for a single lease extension attempt. " + "Must be between 10 and 600 (inclusive). Ignored by default, but set to " + "60 seconds if the subscription has exactly-once enabled." + ) + max_duration_per_lease_extension: float = 0 # disabled by default ( "The max amount of time in seconds for a single lease extension attempt. " diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index 539ae40c7..6ce09ff17 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -15,7 +15,6 @@ import collections import queue import threading -import warnings from google.cloud.pubsub_v1.subscriber._protocol import dispatcher from google.cloud.pubsub_v1.subscriber._protocol import helper_threads @@ -30,11 +29,11 @@ @pytest.mark.parametrize( "item,method_name", [ - (requests.AckRequest("0", 0, 0, ""), "ack"), + (requests.AckRequest("0", 0, 0, "", None), "ack"), (requests.DropRequest("0", 0, ""), "drop"), (requests.LeaseRequest("0", 0, ""), "lease"), - (requests.ModAckRequest("0", 0), "modify_ack_deadline"), - (requests.NackRequest("0", 0, ""), "nack"), + (requests.ModAckRequest("0", 0, None), "modify_ack_deadline"), + (requests.NackRequest("0", 0, "", None), "nack"), ], ) def test_dispatch_callback_active_manager(item, method_name): @@ -54,11 +53,11 @@ def test_dispatch_callback_active_manager(item, method_name): @pytest.mark.parametrize( "item,method_name", [ - (requests.AckRequest("0", 0, 0, ""), "ack"), + (requests.AckRequest("0", 0, 0, "", None), "ack"), (requests.DropRequest("0", 0, ""), "drop"), (requests.LeaseRequest("0", 0, ""), "lease"), - (requests.ModAckRequest("0", 0), "modify_ack_deadline"), - (requests.NackRequest("0", 0, ""), "nack"), + (requests.ModAckRequest("0", 0, None), "modify_ack_deadline"), + (requests.NackRequest("0", 0, "", None), "nack"), ], ) def test_dispatch_callback_inactive_manager(item, method_name): @@ -76,26 +75,6 @@ def test_dispatch_callback_inactive_manager(item, method_name): method.assert_called_once_with([item]) -def test_dispatch_callback_inactive_manager_unknown_request(): - manager = mock.create_autospec( - streaming_pull_manager.StreamingPullManager, instance=True - ) - manager.is_active = False - dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) - - FooType = type("FooType", (), {}) - items = [FooType()] - - with warnings.catch_warnings(record=True) as warned: - dispatcher_.dispatch_callback(items) - - assert len(warned) == 1 - assert issubclass(warned[0].category, RuntimeWarning) - warning_msg = str(warned[0].message) - assert "unknown request item" in warning_msg - assert "FooType" in warning_msg - - def test_ack(): manager = mock.create_autospec( streaming_pull_manager.StreamingPullManager, instance=True @@ -104,14 +83,14 @@ def test_ack(): items = [ requests.AckRequest( - ack_id="ack_id_string", byte_size=0, time_to_ack=20, ordering_key="" + ack_id="ack_id_string", byte_size=0, time_to_ack=20, ordering_key="", + future=None ) ] + manager.send_unary_ack.return_value = (items, []) dispatcher_.ack(items) - manager.send.assert_called_once_with( - gapic_types.StreamingPullRequest(ack_ids=["ack_id_string"]) - ) + manager.send_unary_ack.assert_called_once_with(ack_ids=["ack_id_string"], future_reqs_dict={}) manager.leaser.remove.assert_called_once_with(items) manager.maybe_resume_consumer.assert_called_once() @@ -126,14 +105,14 @@ def test_ack_no_time(): items = [ requests.AckRequest( - ack_id="ack_id_string", byte_size=0, time_to_ack=None, ordering_key="" + ack_id="ack_id_string", byte_size=0, time_to_ack=None, ordering_key="", + future=None ) ] + manager.send_unary_ack.return_value = (items, []) dispatcher_.ack(items) - manager.send.assert_called_once_with( - gapic_types.StreamingPullRequest(ack_ids=["ack_id_string"]) - ) + manager.send_unary_ack.assert_called_once_with(ack_ids=["ack_id_string"], future_reqs_dict={}) manager.ack_histogram.add.assert_not_called() @@ -147,22 +126,24 @@ def test_ack_splitting_large_payload(): items = [ # use realistic lengths for ACK IDs (max 176 bytes) requests.AckRequest( - ack_id=str(i).zfill(176), byte_size=0, time_to_ack=20, ordering_key="" + ack_id=str(i).zfill(176), byte_size=0, time_to_ack=20, ordering_key="", + future=None ) for i in range(5001) ] + manager.send_unary_ack.return_value = (items, []) dispatcher_.ack(items) - calls = manager.send.call_args_list + calls = manager.send_unary_ack.call_args_list assert len(calls) == 3 all_ack_ids = {item.ack_id for item in items} sent_ack_ids = collections.Counter() for call in calls: - message = call.args[0] - assert message._pb.ByteSize() <= 524288 # server-side limit (2**19) - sent_ack_ids.update(message.ack_ids) + ack_ids = call[1]["ack_ids"] + assert len(ack_ids) <= dispatcher._ACK_IDS_BATCH_SIZE + sent_ack_ids.update(ack_ids) assert set(sent_ack_ids) == all_ack_ids # all messages should have been ACK-ed assert sent_ack_ids.most_common(1)[0][1] == 1 # each message ACK-ed exactly once @@ -224,14 +205,13 @@ def test_nack(): dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) items = [ - requests.NackRequest(ack_id="ack_id_string", byte_size=10, ordering_key="") + requests.NackRequest(ack_id="ack_id_string", byte_size=10, ordering_key="", future=None) ] + manager.send_unary_modack.return_value = (items, []) dispatcher_.nack(items) - manager.send.assert_called_once_with( - gapic_types.StreamingPullRequest( - modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0] - ) + manager.send_unary_modack.assert_called_once_with( + modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0], future_reqs_dict={} ) @@ -241,13 +221,12 @@ def test_modify_ack_deadline(): ) dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) - items = [requests.ModAckRequest(ack_id="ack_id_string", seconds=60)] + items = [requests.ModAckRequest(ack_id="ack_id_string", seconds=60, future=None)] + manager.send_unary_modack.return_value = (items, []) dispatcher_.modify_ack_deadline(items) - manager.send.assert_called_once_with( - gapic_types.StreamingPullRequest( - modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[60] - ) + manager.send_unary_modack.assert_called_once_with( + modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[60], future_reqs_dict={} ) @@ -259,21 +238,23 @@ def test_modify_ack_deadline_splitting_large_payload(): items = [ # use realistic lengths for ACK IDs (max 176 bytes) - requests.ModAckRequest(ack_id=str(i).zfill(176), seconds=60) + requests.ModAckRequest(ack_id=str(i).zfill(176), seconds=60, future=None) for i in range(5001) ] + manager.send_unary_modack.return_value = (items, []) dispatcher_.modify_ack_deadline(items) - calls = manager.send.call_args_list + calls = manager.send_unary_modack.call_args_list assert len(calls) == 3 all_ack_ids = {item.ack_id for item in items} sent_ack_ids = collections.Counter() for call in calls: - message = call.args[0] - assert message._pb.ByteSize() <= 524288 # server-side limit (2**19) - sent_ack_ids.update(message.modify_deadline_ack_ids) + modack_ackids = call[1]["modify_deadline_ack_ids"] + print(type(modack_ackids)) + assert len(modack_ackids) <= dispatcher._ACK_IDS_BATCH_SIZE + sent_ack_ids.update(modack_ackids) assert set(sent_ack_ids) == all_ack_ids # all messages should have been MODACK-ed assert sent_ack_ids.most_common(1)[0][1] == 1 # each message MODACK-ed exactly once diff --git a/tests/unit/pubsub_v1/subscriber/test_leaser.py b/tests/unit/pubsub_v1/subscriber/test_leaser.py index f389e5205..36c184c2d 100644 --- a/tests/unit/pubsub_v1/subscriber/test_leaser.py +++ b/tests/unit/pubsub_v1/subscriber/test_leaser.py @@ -139,7 +139,7 @@ def test_maintain_leases_ack_ids(): leaser_.maintain_leases() manager.dispatcher.modify_ack_deadline.assert_called_once_with( - [requests.ModAckRequest(ack_id="my ack id", seconds=10)] + [requests.ModAckRequest(ack_id="my ack id", seconds=10, future=None)] ) @@ -184,9 +184,9 @@ def test_maintain_leases_outdated_items(time): # ack2, ack3, and ack4 should be renewed. ack1 should've been dropped modacks = manager.dispatcher.modify_ack_deadline.call_args.args[0] expected = [ - requests.ModAckRequest(ack_id="ack2", seconds=10), - requests.ModAckRequest(ack_id="ack3", seconds=10), - requests.ModAckRequest(ack_id="ack4", seconds=10), + requests.ModAckRequest(ack_id="ack2", seconds=10, future=None), + requests.ModAckRequest(ack_id="ack3", seconds=10, future=None), + requests.ModAckRequest(ack_id="ack4", seconds=10, future=None), ] # Use sorting to allow for ordering variance. assert sorted(modacks) == sorted(expected) diff --git a/tests/unit/pubsub_v1/subscriber/test_message.py b/tests/unit/pubsub_v1/subscriber/test_message.py index e3c14c93c..22c812031 100644 --- a/tests/unit/pubsub_v1/subscriber/test_message.py +++ b/tests/unit/pubsub_v1/subscriber/test_message.py @@ -127,6 +127,7 @@ def test_ack(): byte_size=30, time_to_ack=mock.ANY, ordering_key="", + future=None ) ) check_call_types(put, requests.AckRequest) @@ -147,7 +148,7 @@ def test_modify_ack_deadline(): with mock.patch.object(msg._request_queue, "put") as put: msg.modify_ack_deadline(60) put.assert_called_once_with( - requests.ModAckRequest(ack_id="bogus_ack_id", seconds=60) + requests.ModAckRequest(ack_id="bogus_ack_id", seconds=60, future=None) ) check_call_types(put, requests.ModAckRequest) @@ -157,7 +158,7 @@ def test_nack(): with mock.patch.object(msg._request_queue, "put") as put: msg.nack() put.assert_called_once_with( - requests.NackRequest(ack_id="bogus_ack_id", byte_size=30, ordering_key="") + requests.NackRequest(ack_id="bogus_ack_id", byte_size=30, ordering_key="", future=None) ) check_call_types(put, requests.NackRequest) diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 42c14c47d..29873e3f3 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -33,8 +33,14 @@ from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.cloud.pubsub_v1.subscriber._protocol import requests from google.cloud.pubsub_v1.subscriber._protocol import streaming_pull_manager +from google.cloud.pubsub_v1.subscriber import futures from google.pubsub_v1 import types as gapic_types +import grpc_status import grpc +from google.rpc import status_pb2 +from google.rpc import code_pb2 +from google.rpc import error_details_pb2 +from google.protobuf.any_pb2 import Any @pytest.mark.parametrize( @@ -144,8 +150,10 @@ def test__obtain_ack_deadline_no_custom_flow_control_setting(): manager = make_manager() - # Make sure that max_duration_per_lease_extension is disabled. - manager._flow_control = types.FlowControl(max_duration_per_lease_extension=0) + # Make sure that min_duration_per_lease_extension and + # max_duration_per_lease_extension is disabled. + manager._flow_control = types.FlowControl(min_duration_per_lease_extension=0, + max_duration_per_lease_extension=0) deadline = manager._obtain_ack_deadline(maybe_update=True) assert deadline == histogram.MIN_ACK_DEADLINE @@ -175,6 +183,20 @@ def test__obtain_ack_deadline_with_max_duration_per_lease_extension(): assert deadline == histogram.MIN_ACK_DEADLINE + 1 +def test__obtain_ack_deadline_with_min_duration_per_lease_extension(): + from google.cloud.pubsub_v1.subscriber._protocol import histogram + + manager = make_manager() + manager._flow_control = types.FlowControl( + min_duration_per_lease_extension=histogram.MAX_ACK_DEADLINE + ) + manager.ack_histogram.add(histogram.MIN_ACK_DEADLINE) # make p99 value small + + # The deadline configured in flow control should prevail. + deadline = manager._obtain_ack_deadline(maybe_update=True) + assert deadline == histogram.MAX_ACK_DEADLINE + + def test__obtain_ack_deadline_with_max_duration_per_lease_extension_too_low(): from google.cloud.pubsub_v1.subscriber._protocol import histogram @@ -182,13 +204,58 @@ def test__obtain_ack_deadline_with_max_duration_per_lease_extension_too_low(): manager._flow_control = types.FlowControl( max_duration_per_lease_extension=histogram.MIN_ACK_DEADLINE - 1 ) - manager.ack_histogram.add(histogram.MIN_ACK_DEADLINE * 3) # make p99 value large # The deadline configured in flow control should be adjusted to the minimum allowed. deadline = manager._obtain_ack_deadline(maybe_update=True) assert deadline == histogram.MIN_ACK_DEADLINE +def test__obtain_ack_deadline_with_min_duration_per_lease_extension_too_high(): + from google.cloud.pubsub_v1.subscriber._protocol import histogram + + manager = make_manager() + manager._flow_control = types.FlowControl( + min_duration_per_lease_extension=histogram.MAX_ACK_DEADLINE + 1 + ) + + # The deadline configured in flow control should be adjusted to the maximum allowed. + deadline = manager._obtain_ack_deadline(maybe_update=True) + assert deadline == histogram.MAX_ACK_DEADLINE + + +def test__obtain_ack_deadline_with_exactly_once_enabled(): + from google.cloud.pubsub_v1.subscriber._protocol import histogram + + manager = make_manager() + manager._flow_control = types.FlowControl( + min_duration_per_lease_extension=0 # leave as default value + ) + manager._exactly_once_enabled = True + manager.ack_histogram.add(10) # reduce p99 value below 60s min for exactly_once subscriptions + + deadline = manager._obtain_ack_deadline(maybe_update=True) + # Since the 60-second min ack_deadline value for exactly_once subscriptions + # seconds is higher than the histogram value, the deadline should be 60 sec. + assert deadline == 60 + + +def test__obtain_ack_deadline_with_min_duration_per_lease_extension_with_exactly_once_enabled(): + from google.cloud.pubsub_v1.subscriber._protocol import histogram + + manager = make_manager() + manager._flow_control = types.FlowControl( + min_duration_per_lease_extension=histogram.MAX_ACK_DEADLINE + ) + manager._exactly_once_enabled = True + manager.ack_histogram.add(histogram.MIN_ACK_DEADLINE) # make p99 value small + + # The deadline configured in flow control should prevail. + deadline = manager._obtain_ack_deadline(maybe_update=True) + # User-defined custom min ack_deadline value takes precedence over + # exactly_once default of 60 seconds. + assert deadline == histogram.MAX_ACK_DEADLINE + + def test__obtain_ack_deadline_no_value_update(): manager = make_manager() @@ -426,21 +493,25 @@ def test__maybe_release_messages_negative_on_hold_bytes_warning(caplog): assert manager._on_hold_bytes == 0 # should be auto-corrected -def test_send_unary(): +def test_send_unary_ack(): manager = make_manager() - manager.send( - gapic_types.StreamingPullRequest( - ack_ids=["ack_id1", "ack_id2"], - modify_deadline_ack_ids=["ack_id3", "ack_id4", "ack_id5"], - modify_deadline_seconds=[10, 20, 20], - ) - ) + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], future_reqs_dict={}) manager._client.acknowledge.assert_called_once_with( subscription=manager._subscription, ack_ids=["ack_id1", "ack_id2"] ) + +def test_send_unary_modack(): + manager = make_manager() + + manager.send_unary_modack( + modify_deadline_ack_ids=["ack_id3", "ack_id4", "ack_id5"], + modify_deadline_seconds=[10, 20, 20], + future_reqs_dict={} + ) + manager._client.modify_ack_deadline.assert_has_calls( [ mock.call( @@ -458,29 +529,35 @@ def test_send_unary(): ) -def test_send_unary_empty(): +def test_send_unary_ack_api_call_error(caplog): + caplog.set_level(logging.DEBUG) + manager = make_manager() - manager.send(gapic_types.StreamingPullRequest()) + error = exceptions.GoogleAPICallError("The front fell off") + manager._client.acknowledge.side_effect = error + + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], future_reqs_dict={}) - manager._client.acknowledge.assert_not_called() - manager._client.modify_ack_deadline.assert_not_called() + assert "The front fell off" in caplog.text -def test_send_unary_api_call_error(caplog): +def test_send_unary_modack_api_call_error(caplog): caplog.set_level(logging.DEBUG) manager = make_manager() error = exceptions.GoogleAPICallError("The front fell off") - manager._client.acknowledge.side_effect = error + manager._client.modify_ack_deadline.side_effect = error - manager.send(gapic_types.StreamingPullRequest(ack_ids=["ack_id1", "ack_id2"])) + manager.send_unary_modack(modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[0], + future_reqs_dict={}) assert "The front fell off" in caplog.text -def test_send_unary_retry_error(caplog): +def test_send_unary_ack_retry_error(caplog): caplog.set_level(logging.DEBUG) manager, _, _, _, _, _ = make_running_manager() @@ -491,7 +568,26 @@ def test_send_unary_retry_error(caplog): manager._client.acknowledge.side_effect = error with pytest.raises(exceptions.RetryError): - manager.send(gapic_types.StreamingPullRequest(ack_ids=["ack_id1", "ack_id2"])) + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], future_reqs_dict={}) + + assert "RetryError while sending unary RPC" in caplog.text + assert "signaled streaming pull manager shutdown" in caplog.text + + +def test_send_unary_modack_retry_error(caplog): + caplog.set_level(logging.DEBUG) + + manager, _, _, _, _, _ = make_running_manager() + + error = exceptions.RetryError( + "Too long a transient error", cause=Exception("Out of time!") + ) + manager._client.modify_ack_deadline.side_effect = error + + with pytest.raises(exceptions.RetryError): + manager.send_unary_modack(modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[0], + future_reqs_dict={}) assert "RetryError while sending unary RPC" in caplog.text assert "signaled streaming pull manager shutdown" in caplog.text @@ -519,6 +615,23 @@ def test_heartbeat_inactive(): assert not result +def test_heartbeat_stream_ack_deadline_seconds(): + manager = make_manager() + manager._rpc = mock.create_autospec(bidi.BidiRpc, instance=True) + manager._rpc.is_active = True + # Send new ack deadline with next heartbeat. + manager._send_new_ack_deadline = True + + result = manager.heartbeat() + + manager._rpc.send.assert_called_once_with(gapic_types.StreamingPullRequest( + stream_ack_deadline_seconds=10 + )) + assert result + # Set to false after a send is initiated. + assert not manager._send_new_ack_deadline + + @mock.patch("google.api_core.bidi.ResumableBidiRpc", autospec=True) @mock.patch("google.api_core.bidi.BackgroundConsumer", autospec=True) @mock.patch("google.cloud.pubsub_v1.subscriber._protocol.leaser.Leaser", autospec=True) @@ -860,9 +973,118 @@ def test__on_response_modifies_ack_deadline(): manager._on_response(response) dispatcher.modify_ack_deadline.assert_called_once_with( - [requests.ModAckRequest("ack_1", 18), requests.ModAckRequest("ack_2", 18)] + [requests.ModAckRequest("ack_1", 18, None), requests.ModAckRequest("ack_2", 18, None)] + ) + + +def test__on_response_modifies_ack_deadline_with_exactly_once_min_lease(): + # exactly_once is disabled by default. + manager, _, dispatcher, leaser, _, scheduler = make_running_manager() + manager._callback = mock.sentinel.callback + + # make p99 value smaller than exactly_once min lease + manager.ack_histogram.add(10) + + # adjust message bookkeeping in leaser + fake_leaser_add(leaser, init_msg_count=0, assumed_msg_size=42) + + # Set up the response with the first set of messages and exactly_once not + # enabled. + response1 = gapic_types.StreamingPullResponse( + received_messages=[ + gapic_types.ReceivedMessage( + ack_id="ack_1", + message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), + ), + gapic_types.ReceivedMessage( + ack_id="ack_2", + message=gapic_types.PubsubMessage(data=b"bar", message_id="2"), + ), + ], + subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled = False + ) + + ) + + # Set up the response with the second set of messages and exactly_once enabled. + response2 = gapic_types.StreamingPullResponse( + received_messages=[ + gapic_types.ReceivedMessage( + ack_id="ack_3", + message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), + ), + gapic_types.ReceivedMessage( + ack_id="ack_4", + message=gapic_types.PubsubMessage(data=b"bar", message_id="2"), + ), + ], + subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled = True + ) + + ) + + # assertions for the _on_response calls below + dispatcher.assert_has_calls( + # assertion 1: mod-acks called with histogram-based lease value + dispatcher.modify_ack_deadline([requests.ModAckRequest("ack_1", 10, None), requests.ModAckRequest("ack_2", 10, None)]), + + # assertion 2: mod-acks called with 60 sec min lease value for exactly_once subscriptions + dispatcher.modify_ack_deadline([requests.ModAckRequest("ack_3", 60, None), requests.ModAckRequest("ack_4", 60, None)]) + ) + + # exactly_once is still disabled b/c subscription_properties says so + # should satisfy assertion 1 + manager._on_response(response1) + + # exactly_once should be enabled after this request b/c subscription_properties says so + # should satisfy assertion 2 + manager._on_response(response2) + + +def test__on_response_send_ack_deadline_after_enabling_exactly_once(): + # exactly_once is disabled by default. + manager, _, dispatcher, leaser, _, scheduler = make_running_manager() + manager._callback = mock.sentinel.callback + + # set up an active RPC + manager._rpc = mock.create_autospec(bidi.BidiRpc, instance=True) + manager._rpc.is_active = True + + # make p99 value smaller than exactly_once min lease + manager.ack_histogram.add(10) + + # adjust message bookkeeping in leaser + fake_leaser_add(leaser, init_msg_count=0, assumed_msg_size=42) + + # Set up the response with the a message and exactly_once enabled. + response2 = gapic_types.StreamingPullResponse( + received_messages=[ + gapic_types.ReceivedMessage( + ack_id="ack_1", + message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), + ), + ], + subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled = True + ) ) + # exactly_once should be enabled after this request b/c subscription_properties says so + # when exactly_once is enabled or disabled, we send a new ack_deadline via + # the heartbeat + # should satisfy assertion 1 + manager._on_response(response2) + + # simulate periodic heartbeat trigger + result = manager.heartbeat() + + # heartbeat request is sent with the 60 sec min lease value for exactly_once subscriptions + manager._rpc.send.assert_called_once_with(gapic_types.StreamingPullRequest( + stream_ack_deadline_seconds=60 + )) + def test__on_response_no_leaser_overload(): manager, _, dispatcher, leaser, _, scheduler = make_running_manager() @@ -890,7 +1112,7 @@ def test__on_response_no_leaser_overload(): manager._on_response(response) dispatcher.modify_ack_deadline.assert_called_once_with( - [requests.ModAckRequest("fack", 10), requests.ModAckRequest("back", 10)] + [requests.ModAckRequest("fack", 10, None), requests.ModAckRequest("back", 10, None)] ) schedule_calls = scheduler.schedule.mock_calls @@ -937,9 +1159,9 @@ def test__on_response_with_leaser_overload(): # deadline extended, even those not dispatched to callbacks dispatcher.modify_ack_deadline.assert_called_once_with( [ - requests.ModAckRequest("fack", 10), - requests.ModAckRequest("back", 10), - requests.ModAckRequest("zack", 10), + requests.ModAckRequest("fack", 10, None), + requests.ModAckRequest("back", 10, None), + requests.ModAckRequest("zack", 10, None), ] ) @@ -1017,9 +1239,9 @@ def test__on_response_with_ordering_keys(): # deadline extended, even those not dispatched to callbacks. dispatcher.modify_ack_deadline.assert_called_once_with( [ - requests.ModAckRequest("fack", 10), - requests.ModAckRequest("back", 10), - requests.ModAckRequest("zack", 10), + requests.ModAckRequest("fack", 10, None), + requests.ModAckRequest("back", 10, None), + requests.ModAckRequest("zack", 10, None), ] ) @@ -1058,6 +1280,74 @@ def test__on_response_with_ordering_keys(): assert manager._messages_on_hold.get() is None +def test__on_response_enable_exactly_once(): + from google.cloud.pubsub_v1.subscriber._protocol import histogram + + manager, _, dispatcher, leaser, _, scheduler = make_running_manager() + manager._callback = mock.sentinel.callback + + # Set up the messages. + response = gapic_types.StreamingPullResponse( + received_messages=[ + gapic_types.ReceivedMessage( + ack_id="fack", + message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), + ), + ], + subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled = True + ) + ) + + # adjust message bookkeeping in leaser + fake_leaser_add(leaser, init_msg_count=0, assumed_msg_size=42) + + # exactly_once should be enabled + manager._on_response(response) + + assert manager._exactly_once_enabled + # new deadline for exactly_once subscriptions should be used + assert manager.ack_deadline == 60 + + +def test__on_response_disable_exactly_once(): + from google.cloud.pubsub_v1.subscriber._protocol import histogram + + manager, _, dispatcher, leaser, _, scheduler = make_running_manager() + manager._callback = mock.sentinel.callback + + manager._flow_control = types.FlowControl( + min_duration_per_lease_extension=histogram.MIN_ACK_DEADLINE + ) + # enable exactly_once + manager._exactly_once_enabled = True + + # Set up the messages. + response = gapic_types.StreamingPullResponse( + received_messages=[ + gapic_types.ReceivedMessage( + ack_id="fack", + message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), + ), + ], + subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled = False + ) + ) + + # adjust message bookkeeping in leaser + fake_leaser_add(leaser, init_msg_count=0, assumed_msg_size=42) + + # exactly_once should be disabled + manager._on_response(response) + + assert not manager._exactly_once_enabled + # The deadline configured in flow control should be used, not the + # exactly_once minimum since exactly_once has been disabled. + deadline = manager._obtain_ack_deadline(maybe_update=True) + assert deadline == histogram.MIN_ACK_DEADLINE + + def test__should_recover_true(): manager = make_manager() @@ -1130,3 +1420,199 @@ def test_activate_ordering_keys_stopped_scheduler(): manager.activate_ordering_keys(["key1", "key2"]) manager._messages_on_hold.activate_ordering_keys.assert_not_called() + + +@mock.patch("grpc_status.rpc_status.from_call") +@mock.patch("google.protobuf.any_pb2.Any.Unpack") +def test_get_ack_errors_unable_to_unpack(from_call, unpack): + manager = make_manager() + + st = status_pb2.Status() + st.code = code_pb2.Code.INTERNAL + st.message = "qmsg" + error_info = error_details_pb2.ErrorInfo() + error_info.metadata["ack_1"] = "error1" + st.details.add().Pack(error_info) + mock_gprc_call = mock.Mock(spec=grpc.Call) + exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + from_call.return_value = st + # Unpack() failed + unpack.return_value = None + + assert not streaming_pull_manager._get_ack_errors(exception) + + +@mock.patch("grpc_status.rpc_status.from_call") +def test_get_ack_errors_no_response_obj(from_call): + manager = make_manager() + + exception = exceptions.InternalServerError("msg", errors=(), response=None) + # No response obj + assert not streaming_pull_manager._get_ack_errors(exception) + + +@mock.patch("grpc_status.rpc_status.from_call") +def test_get_ack_errors_from_call_returned_none(from_call): + manager = make_manager() + + mock_gprc_call = mock.Mock(spec=grpc.Call) + exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + from_call.return_value = None + # rpc_status.from_call() returned None + assert not streaming_pull_manager._get_ack_errors(exception) + + +@mock.patch("grpc_status.rpc_status.from_call") +def test_get_ack_errors_value_error_thrown(from_call): + manager = make_manager() + + mock_gprc_call = mock.Mock(spec=grpc.Call) + exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + from_call.side_effect = ValueError("val error msg") + # ValueError thrown, so return None + assert not streaming_pull_manager._get_ack_errors(exception) + + +@mock.patch("grpc_status.rpc_status.from_call") +def test_get_ack_errors_happy_case(from_call): + manager = make_manager() + + st = status_pb2.Status() + st.code = code_pb2.Code.INTERNAL + st.message = "qmsg" + error_info = error_details_pb2.ErrorInfo() + error_info.metadata["ack_1"] = "error1" + st.details.add().Pack(error_info) + mock_gprc_call = mock.Mock(spec=grpc.Call) + exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + from_call.side_effect = None + from_call.return_value = st + # happy case - errors returned in a map + ack_errors = streaming_pull_manager._get_ack_errors(exception) + assert ack_errors + assert ack_errors["ack_1"] == "error1" + + +def test_process_futures_no_requests(): + # no requests so no items in results lists + future_reqs_dict = {} + errors_dict = {} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + assert not requests_completed + assert not requests_to_retry + + +def test_process_futures_error_dict_is_none(): + # it's valid to pass in `None` for `errors_dict` + future_reqs_dict = {} + errors_dict = None + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + assert not requests_completed + assert not requests_to_retry + + +def test_process_futures_no_errors(): + # no errors so request should be completed + future = futures.Future() + future_reqs_dict = { + 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + } + errors_dict = {} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + assert requests_completed[0].ack_id == 'ackid1' + assert future.result() == 'ackid1' + assert not requests_to_retry + + +def test_process_futures_permanent_error_raises_exception(): + # a permanent error raises an exception + future = futures.Future() + future_reqs_dict = { + 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + } + errors_dict = {'ackid1': 'PERMANENT_FAILURE_INVALID_ACK_ID'} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + assert requests_completed[0].ack_id == 'ackid1' + with pytest.raises(RuntimeError) as exc_info: + future.result() + assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" + assert not requests_to_retry + + +def test_process_futures_transient_error_returns_request(): + # a transient error returns the request in `requests_to_retry` + future = futures.Future() + future_reqs_dict = { + 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + } + errors_dict = {'ackid1': 'TRANSIENT_FAILURE_INVALID_ACK_ID'} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + assert not requests_completed + assert requests_to_retry[0].ack_id == 'ackid1' + assert not future.done() + + +def test_process_futures_unknown_error_raises_exception(): + # an unknown error raises an exception + future = futures.Future() + future_reqs_dict = { + 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + } + errors_dict = {'ackid1': 'unknown_error'} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + assert requests_completed[0].ack_id == 'ackid1' + with pytest.raises(RuntimeError) as exc_info: + future.result() + assert str(exc_info.value) == "Unknown error: unknown_error" + assert not requests_to_retry + + +def test_process_futures_mixed_success_and_failure_acks(): + # mixed success and failure (acks) + future1 = futures.Future() + future2 = futures.Future() + future3 = futures.Future() + future_reqs_dict = { + 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future1), + 'ackid2': requests.AckRequest(ack_id='ackid2', byte_size=0, time_to_ack=20, ordering_key="", future=future2), + 'ackid3': requests.AckRequest(ack_id='ackid3', byte_size=0, time_to_ack=20, ordering_key="", future=future3) + } + errors_dict = {'ackid1': 'PERMANENT_FAILURE_INVALID_ACK_ID', 'ackid2': 'TRANSIENT_FAILURE_INVALID_ACK_ID'} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + # message with ack_id 'ackid1' fails with an exception + assert requests_completed[0].ack_id == 'ackid1' + with pytest.raises(RuntimeError) as exc_info: + future1.result() + assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" + # message with ack_id 'ackid2' is to be retried + assert requests_to_retry[0].ack_id == 'ackid2' + assert not requests_to_retry[0].future.done() + # message with ack_id 'ackid3' succeeds + assert requests_completed[1].ack_id == 'ackid3' + assert future3.result() == 'ackid3' + + +def test_process_futures_mixed_success_and_failure_modacks(): + # mixed success and failure (modacks) + future1 = futures.Future() + future2 = futures.Future() + future3 = futures.Future() + future_reqs_dict = { + 'ackid1': requests.ModAckRequest(ack_id='ackid1', seconds=60, future=future1), + 'ackid2': requests.ModAckRequest(ack_id='ackid2', seconds=60, future=future2), + 'ackid3': requests.ModAckRequest(ack_id='ackid3', seconds=60, future=future3) + } + errors_dict = {'ackid1': 'PERMANENT_FAILURE_INVALID_ACK_ID', 'ackid2': 'TRANSIENT_FAILURE_INVALID_ACK_ID'} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + # message with ack_id 'ackid1' fails with an exception + assert requests_completed[0].ack_id == 'ackid1' + with pytest.raises(RuntimeError) as exc_info: + future1.result() + assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" + # message with ack_id 'ackid2' is to be retried + assert requests_to_retry[0].ack_id == 'ackid2' + assert not requests_to_retry[0].future.done() + # message with ack_id 'ackid3' succeeds + assert requests_completed[1].ack_id == 'ackid3' + assert future3.result() == 'ackid3' + From e35de42b6b4bf67bb858a9dfa53803093da8258b Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 14:56:06 -0500 Subject: [PATCH 02/43] rename retry duration constants --- .../pubsub_v1/subscriber/_protocol/dispatcher.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 9e6f81632..a1f8fa337 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -67,11 +67,11 @@ IDs at a time. """ -_MIN_ACK_MODACK_RETRY_DURATION_SECS = 1 +_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS = 1 """The time to wait for the first retry of failed acks and modacks when exactly-once is enabled.""" -_MAX_ACK_MODACK_RETRY_DURATION_SECS = 20 * 60 +_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS = 10 * 60 """The maximum amount of time in seconds to retry failed acks and modacks when exactly-once is enabled.""" @@ -190,8 +190,8 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: self.drop(requests_completed) # retry acks - retry_delay_gen = exponential_sleep_generator(initial=_MIN_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_ACK_MODACK_RETRY_DURATION_SECS) + retry_delay_gen = exponential_sleep_generator(initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS) while requests_to_retry: time_to_wait = retry_delay_gen() _LOGGER.debug("Retrying {len(requests_to_retry)} ack(s) after delay of " + @@ -256,8 +256,8 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: assert len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE, "Too many requests to be retried." # retry modacks - retry_delay_gen = exponential_sleep_generator(initial=_MIN_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_ACK_MODACK_RETRY_DURATION_SECS) + retry_delay_gen = exponential_sleep_generator(initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS) while requests_to_retry: time_to_wait = retry_delay_gen() _LOGGER.debug("Retrying {len(requests_to_retry)} modack(s) after delay of " + From 23504c82849231647e04bb0804e7d09edc0157d1 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 15:26:11 -0500 Subject: [PATCH 03/43] add grpc-status dependency --- setup.py | 1 + 1 file changed, 1 insertion(+) diff --git a/setup.py b/setup.py index 666fa61aa..7d74bda0e 100644 --- a/setup.py +++ b/setup.py @@ -36,6 +36,7 @@ "google-api-core[grpc] >= 1.28.0, <3.0.0dev", "proto-plus >= 1.7.1", "grpc-google-iam-v1 >= 0.12.3, < 0.13dev", + "grpc-status >= 1.0.0", ] extras = {"libcst": "libcst >= 0.3.10"} From 0a33f37254e7849e6cc3a8804214286136994056 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 15:30:40 -0500 Subject: [PATCH 04/43] change dep from grpc-status to grpcio-status per error message during build --- setup.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/setup.py b/setup.py index 7d74bda0e..d3110f9e4 100644 --- a/setup.py +++ b/setup.py @@ -36,7 +36,7 @@ "google-api-core[grpc] >= 1.28.0, <3.0.0dev", "proto-plus >= 1.7.1", "grpc-google-iam-v1 >= 0.12.3, < 0.13dev", - "grpc-status >= 1.0.0", + "grpcio-status >= 1.43.0", ] extras = {"libcst": "libcst >= 0.3.10"} From 0b6db2e4fb204812316ab92540c7a206da703196 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 15:34:04 -0500 Subject: [PATCH 05/43] run lint formatter --- .../subscriber/_protocol/dispatcher.py | 95 +++++-- .../pubsub_v1/subscriber/_protocol/leaser.py | 5 +- .../_protocol/streaming_pull_manager.py | 64 +++-- google/cloud/pubsub_v1/subscriber/message.py | 21 +- .../pubsub_v1/subscriber/test_dispatcher.py | 41 ++- .../unit/pubsub_v1/subscriber/test_message.py | 6 +- .../subscriber/test_streaming_pull_manager.py | 241 ++++++++++++------ 7 files changed, 321 insertions(+), 152 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index a1f8fa337..8b036ba76 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -75,6 +75,7 @@ """The maximum amount of time in seconds to retry failed acks and modacks when exactly-once is enabled.""" + class Dispatcher(object): def __init__(self, manager: "StreamingPullManager", queue: "queue.Queue"): self._manager = manager @@ -181,28 +182,43 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: total_chunks = int(math.ceil(len(items) / _ACK_IDS_BATCH_SIZE)) for _ in range(total_chunks): - future_reqs_dict = {req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) if req.future} - requests_completed, requests_to_retry = self._manager.send_unary_ack( + future_reqs_dict = { + req.ack_id: req + for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) + if req.future + } + requests_completed, requests_to_retry = self._manager.send_unary_ack( ack_ids=list(itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE)), - future_reqs_dict=future_reqs_dict) + future_reqs_dict=future_reqs_dict, + ) # Remove the completed messages from lease management. self.drop(requests_completed) # retry acks - retry_delay_gen = exponential_sleep_generator(initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS) + retry_delay_gen = exponential_sleep_generator( + initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + ) while requests_to_retry: time_to_wait = retry_delay_gen() - _LOGGER.debug("Retrying {len(requests_to_retry)} ack(s) after delay of " + - str(time_to_wait) + " seconds") + _LOGGER.debug( + "Retrying {len(requests_to_retry)} ack(s) after delay of " + + str(time_to_wait) + + " seconds" + ) time.sleep(time_to_wait) - future_reqs_dict = {req.ack_id: req for req in requests_to_retry if req.future} + future_reqs_dict = { + req.ack_id: req for req in requests_to_retry if req.future + } requests_completed, requests_to_retry = self._manager.send_unary_ack( ack_ids=[req.ack_id for req in requests_to_retry], - future_reqs_dict=future_reqs_dict) - assert len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE, "Too many requests to be retried." + future_reqs_dict=future_reqs_dict, + ) + assert ( + len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE + ), "Too many requests to be retried." # Remove the completed messages from lease management. self.drop(requests_completed) @@ -247,29 +263,48 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: total_chunks = int(math.ceil(len(items) / _ACK_IDS_BATCH_SIZE)) for _ in range(total_chunks): - future_reqs_dict = {req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) if req.future} + future_reqs_dict = { + req.ack_id: req + for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) + if req.future + } # no further work needs to be done for `requests_to_retry` requests_completed, requests_to_retry = self._manager.send_unary_modack( - modify_deadline_ack_ids=list(itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE)), - modify_deadline_seconds=list(itertools.islice(deadline_seconds_gen, _ACK_IDS_BATCH_SIZE)), - future_reqs_dict=future_reqs_dict) - assert len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE, "Too many requests to be retried." + modify_deadline_ack_ids=list( + itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE) + ), + modify_deadline_seconds=list( + itertools.islice(deadline_seconds_gen, _ACK_IDS_BATCH_SIZE) + ), + future_reqs_dict=future_reqs_dict, + ) + assert ( + len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE + ), "Too many requests to be retried." # retry modacks - retry_delay_gen = exponential_sleep_generator(initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS) + retry_delay_gen = exponential_sleep_generator( + initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + ) while requests_to_retry: time_to_wait = retry_delay_gen() - _LOGGER.debug("Retrying {len(requests_to_retry)} modack(s) after delay of " + - str(time_to_wait) + " seconds") + _LOGGER.debug( + "Retrying {len(requests_to_retry)} modack(s) after delay of " + + str(time_to_wait) + + " seconds" + ) time.sleep(time_to_wait) print(requests_to_retry) - future_reqs_dict = {req.ack_id: req for req in requests_to_retry if req.future} + future_reqs_dict = { + req.ack_id: req for req in requests_to_retry if req.future + } requests_to_retry = self._manager.send_unary_modack( modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], modify_deadline_seconds=[req.seconds for req in requests_to_retry], - future_reqs_dict=future_reqs_dict) + future_reqs_dict=future_reqs_dict, + ) def nack(self, items: Sequence[requests.NackRequest]) -> None: """Explicitly deny receipt of messages. @@ -278,6 +313,20 @@ def nack(self, items: Sequence[requests.NackRequest]) -> None: items: The items to deny. """ self.modify_ack_deadline( - [requests.ModAckRequest(ack_id=item.ack_id, seconds=0, future=item.future) for item in items] + [ + requests.ModAckRequest( + ack_id=item.ack_id, seconds=0, future=item.future + ) + for item in items + ] + ) + self.drop( + [ + requests.DropRequest( + ack_id=item.ack_id, + byte_size=item.byte_size, + ordering_key=item.ordering_key, + ) + for item in items + ] ) - self.drop([requests.DropRequest(ack_id=item.ack_id, byte_size=item.byte_size, ordering_key=item.ordering_key) for item in items]) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py index ad8b01595..09cb74c40 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py @@ -195,7 +195,10 @@ def maintain_leases(self) -> None: # is inactive. assert self._manager.dispatcher is not None self._manager.dispatcher.modify_ack_deadline( - [requests.ModAckRequest(ack_id, deadline, None) for ack_id in ack_ids] + [ + requests.ModAckRequest(ack_id, deadline, None) + for ack_id in ack_ids + ] ) # Now wait an appropriate period of time and do this again. diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 328ff544a..24fe99a60 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -69,6 +69,7 @@ a subscription. We do this to reduce premature ack expiration. """ + def _wrap_as_exception(maybe_exception: Any) -> BaseException: """Wrap an object as a Python exception, if needed. @@ -112,7 +113,9 @@ def _wrap_callback_errors( on_callback_error(exc) -def _get_ack_errors(exc: exceptions.GoogleAPICallError) -> Optional["containers.ScalarMap"]: +def _get_ack_errors( + exc: exceptions.GoogleAPICallError +) -> Optional["containers.ScalarMap"]: if not exc.response: _LOGGER.debug("No response obj in errored RPC call.") return None @@ -132,11 +135,14 @@ def _get_ack_errors(exc: exceptions.GoogleAPICallError) -> Optional["containers. # with the status code and message inside of the # google.rpc.status.Status" except ValueError: - _LOGGER.debug( "ValueError when parsing ErrorInfo.", exc_info=True) + _LOGGER.debug("ValueError when parsing ErrorInfo.", exc_info=True) return None -def _process_futures(future_reqs_dict: "containers.ScalarMap", - errors_dict: Optional["containers.ScalarMap"]): + +def _process_futures( + future_reqs_dict: "containers.ScalarMap", + errors_dict: Optional["containers.ScalarMap"], +): """Process futures by referring to errors_dict. The errors returned by the server in `errors_dict` are used to complete @@ -358,8 +364,9 @@ def _obtain_ack_deadline(self, maybe_update: bool) -> float: self._ack_deadline = max(self._ack_deadline, flow_control_setting) elif self._exactly_once_enabled: # Higher minimum ack_deadline for exactly_once subscriptions. - self._ack_deadline = max(self._ack_deadline, - _MIN_ACK_DEADLINE_SECS_WHEN_EXACTLY_ONCE_ENABLED) + self._ack_deadline = max( + self._ack_deadline, _MIN_ACK_DEADLINE_SECS_WHEN_EXACTLY_ONCE_ENABLED + ) return self._ack_deadline @@ -399,7 +406,7 @@ def load(self) -> float: ) def add_close_callback( - self, callback: Callable[["StreamingPullManager", Any], Any], + self, callback: Callable[["StreamingPullManager", Any], Any] ) -> None: """Schedules a callable when the manager closes. @@ -523,8 +530,9 @@ def _schedule_message_on_hold( assert self._callback is not None self._scheduler.schedule(self._callback, msg) - - def send_unary_ack(self, ack_ids, future_reqs_dict) -> Tuple[List[requests.AckRequest], List[requests.AckRequest]]: + def send_unary_ack( + self, ack_ids, future_reqs_dict + ) -> Tuple[List[requests.AckRequest], List[requests.AckRequest]]: """Send a request using a separate unary request instead of over the stream. If a RetryError occurs, the manager shutdown is triggered, and the @@ -535,9 +543,7 @@ def send_unary_ack(self, ack_ids, future_reqs_dict) -> Tuple[List[requests.AckRe success = True ack_errors_dict = None try: - self._client.acknowledge( - subscription=self._subscription, ack_ids=ack_ids - ) + self._client.acknowledge(subscription=self._subscription, ack_ids=ack_ids) except exceptions.GoogleAPICallError as exc: _LOGGER.debug( "Exception while sending unary RPC. This is typically " @@ -556,11 +562,14 @@ def send_unary_ack(self, ack_ids, future_reqs_dict) -> Tuple[List[requests.AckRe self._on_rpc_done(exc) raise - requests_completed, requests_to_retry = _process_futures(future_reqs_dict, ack_errors_dict) + requests_completed, requests_to_retry = _process_futures( + future_reqs_dict, ack_errors_dict + ) return requests_completed, requests_to_retry - - def send_unary_modack(self, modify_deadline_ack_ids, modify_deadline_seconds, future_reqs_dict) -> Tuple[List[requests.ModAckRequest], List[requests.ModAckRequest]]: + def send_unary_modack( + self, modify_deadline_ack_ids, modify_deadline_seconds, future_reqs_dict + ) -> Tuple[List[requests.ModAckRequest], List[requests.ModAckRequest]]: """Send a request using a separate unary request instead of over the stream. If a RetryError occurs, the manager shutdown is triggered, and the @@ -601,7 +610,9 @@ def send_unary_modack(self, modify_deadline_ack_ids, modify_deadline_seconds, fu self._on_rpc_done(exc) raise - requests_completed, requests_to_retry = _process_futures(future_reqs_dict, modack_errors_dict) + requests_completed, requests_to_retry = _process_futures( + future_reqs_dict, modack_errors_dict + ) return requests_completed, requests_to_retry def heartbeat(self) -> bool: @@ -621,7 +632,8 @@ def heartbeat(self) -> bool: if send_new_ack_deadline: request = gapic_types.StreamingPullRequest( - stream_ack_deadline_seconds=self.ack_deadline) + stream_ack_deadline_seconds=self.ack_deadline + ) else: request = gapic_types.StreamingPullRequest() @@ -861,13 +873,17 @@ def _on_response(self, response: gapic_types.StreamingPullResponse) -> None: ) with self._exactly_once_enabled_lock: - if response.subscription_properties.exactly_once_delivery_enabled != \ - self._exactly_once_enabled: - self._exactly_once_enabled = response.subscription_properties.exactly_once_delivery_enabled - # Update ack_deadline, whose minimum depends on self._exactly_once_enabled - # This method acquires the self._ack_deadline_lock lock. - self._obtain_ack_deadline(maybe_update=True) - self._send_new_ack_deadline = True + if ( + response.subscription_properties.exactly_once_delivery_enabled + != self._exactly_once_enabled + ): + self._exactly_once_enabled = ( + response.subscription_properties.exactly_once_delivery_enabled + ) + # Update ack_deadline, whose minimum depends on self._exactly_once_enabled + # This method acquires the self._ack_deadline_lock lock. + self._obtain_ack_deadline(maybe_update=True) + self._send_new_ack_deadline = True # Immediately (i.e. without waiting for the auto lease management) # modack the messages we received, as this tells the server that we've diff --git a/google/cloud/pubsub_v1/subscriber/message.py b/google/cloud/pubsub_v1/subscriber/message.py index 78ac62db3..bfd826a94 100644 --- a/google/cloud/pubsub_v1/subscriber/message.py +++ b/google/cloud/pubsub_v1/subscriber/message.py @@ -243,7 +243,7 @@ def ack(self) -> None: byte_size=self.size, time_to_ack=time_to_ack, ordering_key=self.ordering_key, - future=None + future=None, ) ) @@ -275,12 +275,11 @@ def ack_with_response(self) -> "pubsub_v1.subscriber.futures.Future": byte_size=self.size, time_to_ack=time_to_ack, ordering_key=self.ordering_key, - future=future + future=future, ) ) return future - def drop(self) -> None: """Release the message from lease management. @@ -320,7 +319,9 @@ def modify_ack_deadline(self, seconds: int) -> None: requests.ModAckRequest(ack_id=self._ack_id, seconds=seconds, future=None) ) - def modify_ack_deadline_with_response(self, seconds: int) -> "pubsub_v1.subscriber.futures.Future": + def modify_ack_deadline_with_response( + self, seconds: int + ) -> "pubsub_v1.subscriber.futures.Future": """Resets the deadline for acknowledgement and returns the response status via a future. @@ -357,8 +358,10 @@ def nack(self) -> None: """ self._request_queue.put( requests.NackRequest( - ack_id=self._ack_id, byte_size=self.size, ordering_key=self.ordering_key, - future=None + ack_id=self._ack_id, + byte_size=self.size, + ordering_key=self.ordering_key, + future=None, ) ) @@ -379,8 +382,10 @@ def nack_with_response(self) -> "pubsub_v1.subscriber.futures.Future": future = futures.Future() self._request_queue.put( requests.NackRequest( - ack_id=self._ack_id, byte_size=self.size, ordering_key=self.ordering_key, - future=future + ack_id=self._ack_id, + byte_size=self.size, + ordering_key=self.ordering_key, + future=future, ) ) return future diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index 6ce09ff17..a309610e7 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -83,14 +83,19 @@ def test_ack(): items = [ requests.AckRequest( - ack_id="ack_id_string", byte_size=0, time_to_ack=20, ordering_key="", - future=None + ack_id="ack_id_string", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=None, ) ] manager.send_unary_ack.return_value = (items, []) dispatcher_.ack(items) - manager.send_unary_ack.assert_called_once_with(ack_ids=["ack_id_string"], future_reqs_dict={}) + manager.send_unary_ack.assert_called_once_with( + ack_ids=["ack_id_string"], future_reqs_dict={} + ) manager.leaser.remove.assert_called_once_with(items) manager.maybe_resume_consumer.assert_called_once() @@ -105,14 +110,19 @@ def test_ack_no_time(): items = [ requests.AckRequest( - ack_id="ack_id_string", byte_size=0, time_to_ack=None, ordering_key="", - future=None + ack_id="ack_id_string", + byte_size=0, + time_to_ack=None, + ordering_key="", + future=None, ) ] manager.send_unary_ack.return_value = (items, []) dispatcher_.ack(items) - manager.send_unary_ack.assert_called_once_with(ack_ids=["ack_id_string"], future_reqs_dict={}) + manager.send_unary_ack.assert_called_once_with( + ack_ids=["ack_id_string"], future_reqs_dict={} + ) manager.ack_histogram.add.assert_not_called() @@ -126,8 +136,11 @@ def test_ack_splitting_large_payload(): items = [ # use realistic lengths for ACK IDs (max 176 bytes) requests.AckRequest( - ack_id=str(i).zfill(176), byte_size=0, time_to_ack=20, ordering_key="", - future=None + ack_id=str(i).zfill(176), + byte_size=0, + time_to_ack=20, + ordering_key="", + future=None, ) for i in range(5001) ] @@ -205,13 +218,17 @@ def test_nack(): dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) items = [ - requests.NackRequest(ack_id="ack_id_string", byte_size=10, ordering_key="", future=None) + requests.NackRequest( + ack_id="ack_id_string", byte_size=10, ordering_key="", future=None + ) ] manager.send_unary_modack.return_value = (items, []) dispatcher_.nack(items) manager.send_unary_modack.assert_called_once_with( - modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0], future_reqs_dict={} + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[0], + future_reqs_dict={}, ) @@ -226,7 +243,9 @@ def test_modify_ack_deadline(): dispatcher_.modify_ack_deadline(items) manager.send_unary_modack.assert_called_once_with( - modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[60], future_reqs_dict={} + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[60], + future_reqs_dict={}, ) diff --git a/tests/unit/pubsub_v1/subscriber/test_message.py b/tests/unit/pubsub_v1/subscriber/test_message.py index 22c812031..3e79f2f20 100644 --- a/tests/unit/pubsub_v1/subscriber/test_message.py +++ b/tests/unit/pubsub_v1/subscriber/test_message.py @@ -127,7 +127,7 @@ def test_ack(): byte_size=30, time_to_ack=mock.ANY, ordering_key="", - future=None + future=None, ) ) check_call_types(put, requests.AckRequest) @@ -158,7 +158,9 @@ def test_nack(): with mock.patch.object(msg._request_queue, "put") as put: msg.nack() put.assert_called_once_with( - requests.NackRequest(ack_id="bogus_ack_id", byte_size=30, ordering_key="", future=None) + requests.NackRequest( + ack_id="bogus_ack_id", byte_size=30, ordering_key="", future=None + ) ) check_call_types(put, requests.NackRequest) diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 29873e3f3..5a7c36a7d 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -152,8 +152,9 @@ def test__obtain_ack_deadline_no_custom_flow_control_setting(): # Make sure that min_duration_per_lease_extension and # max_duration_per_lease_extension is disabled. - manager._flow_control = types.FlowControl(min_duration_per_lease_extension=0, - max_duration_per_lease_extension=0) + manager._flow_control = types.FlowControl( + min_duration_per_lease_extension=0, max_duration_per_lease_extension=0 + ) deadline = manager._obtain_ack_deadline(maybe_update=True) assert deadline == histogram.MIN_ACK_DEADLINE @@ -228,10 +229,12 @@ def test__obtain_ack_deadline_with_exactly_once_enabled(): manager = make_manager() manager._flow_control = types.FlowControl( - min_duration_per_lease_extension=0 # leave as default value + min_duration_per_lease_extension=0 # leave as default value ) manager._exactly_once_enabled = True - manager.ack_histogram.add(10) # reduce p99 value below 60s min for exactly_once subscriptions + manager.ack_histogram.add( + 10 + ) # reduce p99 value below 60s min for exactly_once subscriptions deadline = manager._obtain_ack_deadline(maybe_update=True) # Since the 60-second min ack_deadline value for exactly_once subscriptions @@ -509,7 +512,7 @@ def test_send_unary_modack(): manager.send_unary_modack( modify_deadline_ack_ids=["ack_id3", "ack_id4", "ack_id5"], modify_deadline_seconds=[10, 20, 20], - future_reqs_dict={} + future_reqs_dict={}, ) manager._client.modify_ack_deadline.assert_has_calls( @@ -550,9 +553,11 @@ def test_send_unary_modack_api_call_error(caplog): error = exceptions.GoogleAPICallError("The front fell off") manager._client.modify_ack_deadline.side_effect = error - manager.send_unary_modack(modify_deadline_ack_ids=["ack_id_string"], - modify_deadline_seconds=[0], - future_reqs_dict={}) + manager.send_unary_modack( + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[0], + future_reqs_dict={}, + ) assert "The front fell off" in caplog.text @@ -585,9 +590,11 @@ def test_send_unary_modack_retry_error(caplog): manager._client.modify_ack_deadline.side_effect = error with pytest.raises(exceptions.RetryError): - manager.send_unary_modack(modify_deadline_ack_ids=["ack_id_string"], - modify_deadline_seconds=[0], - future_reqs_dict={}) + manager.send_unary_modack( + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[0], + future_reqs_dict={}, + ) assert "RetryError while sending unary RPC" in caplog.text assert "signaled streaming pull manager shutdown" in caplog.text @@ -624,9 +631,9 @@ def test_heartbeat_stream_ack_deadline_seconds(): result = manager.heartbeat() - manager._rpc.send.assert_called_once_with(gapic_types.StreamingPullRequest( - stream_ack_deadline_seconds=10 - )) + manager._rpc.send.assert_called_once_with( + gapic_types.StreamingPullRequest(stream_ack_deadline_seconds=10) + ) assert result # Set to false after a send is initiated. assert not manager._send_new_ack_deadline @@ -973,7 +980,10 @@ def test__on_response_modifies_ack_deadline(): manager._on_response(response) dispatcher.modify_ack_deadline.assert_called_once_with( - [requests.ModAckRequest("ack_1", 18, None), requests.ModAckRequest("ack_2", 18, None)] + [ + requests.ModAckRequest("ack_1", 18, None), + requests.ModAckRequest("ack_2", 18, None), + ] ) @@ -1001,10 +1011,9 @@ def test__on_response_modifies_ack_deadline_with_exactly_once_min_lease(): message=gapic_types.PubsubMessage(data=b"bar", message_id="2"), ), ], - subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( - exactly_once_delivery_enabled = False - ) - + subscription_properties=gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled=False + ), ) # Set up the response with the second set of messages and exactly_once enabled. @@ -1019,19 +1028,27 @@ def test__on_response_modifies_ack_deadline_with_exactly_once_min_lease(): message=gapic_types.PubsubMessage(data=b"bar", message_id="2"), ), ], - subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( - exactly_once_delivery_enabled = True - ) - + subscription_properties=gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled=True + ), ) # assertions for the _on_response calls below dispatcher.assert_has_calls( # assertion 1: mod-acks called with histogram-based lease value - dispatcher.modify_ack_deadline([requests.ModAckRequest("ack_1", 10, None), requests.ModAckRequest("ack_2", 10, None)]), - + dispatcher.modify_ack_deadline( + [ + requests.ModAckRequest("ack_1", 10, None), + requests.ModAckRequest("ack_2", 10, None), + ] + ), # assertion 2: mod-acks called with 60 sec min lease value for exactly_once subscriptions - dispatcher.modify_ack_deadline([requests.ModAckRequest("ack_3", 60, None), requests.ModAckRequest("ack_4", 60, None)]) + dispatcher.modify_ack_deadline( + [ + requests.ModAckRequest("ack_3", 60, None), + requests.ModAckRequest("ack_4", 60, None), + ] + ), ) # exactly_once is still disabled b/c subscription_properties says so @@ -1064,11 +1081,11 @@ def test__on_response_send_ack_deadline_after_enabling_exactly_once(): gapic_types.ReceivedMessage( ack_id="ack_1", message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), - ), + ) ], - subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( - exactly_once_delivery_enabled = True - ) + subscription_properties=gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled=True + ), ) # exactly_once should be enabled after this request b/c subscription_properties says so @@ -1081,9 +1098,9 @@ def test__on_response_send_ack_deadline_after_enabling_exactly_once(): result = manager.heartbeat() # heartbeat request is sent with the 60 sec min lease value for exactly_once subscriptions - manager._rpc.send.assert_called_once_with(gapic_types.StreamingPullRequest( - stream_ack_deadline_seconds=60 - )) + manager._rpc.send.assert_called_once_with( + gapic_types.StreamingPullRequest(stream_ack_deadline_seconds=60) + ) def test__on_response_no_leaser_overload(): @@ -1112,7 +1129,10 @@ def test__on_response_no_leaser_overload(): manager._on_response(response) dispatcher.modify_ack_deadline.assert_called_once_with( - [requests.ModAckRequest("fack", 10, None), requests.ModAckRequest("back", 10, None)] + [ + requests.ModAckRequest("fack", 10, None), + requests.ModAckRequest("back", 10, None), + ] ) schedule_calls = scheduler.schedule.mock_calls @@ -1292,11 +1312,11 @@ def test__on_response_enable_exactly_once(): gapic_types.ReceivedMessage( ack_id="fack", message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), - ), + ) ], - subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( - exactly_once_delivery_enabled = True - ) + subscription_properties=gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled=True + ), ) # adjust message bookkeeping in leaser @@ -1328,11 +1348,11 @@ def test__on_response_disable_exactly_once(): gapic_types.ReceivedMessage( ack_id="fack", message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), - ), + ) ], - subscription_properties = gapic_types.StreamingPullResponse.SubscriptionProperties( - exactly_once_delivery_enabled = False - ) + subscription_properties=gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled=False + ), ) # adjust message bookkeeping in leaser @@ -1434,7 +1454,9 @@ def test_get_ack_errors_unable_to_unpack(from_call, unpack): error_info.metadata["ack_1"] = "error1" st.details.add().Pack(error_info) mock_gprc_call = mock.Mock(spec=grpc.Call) - exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + exception = exceptions.InternalServerError( + "msg", errors=(), response=mock_gprc_call + ) from_call.return_value = st # Unpack() failed unpack.return_value = None @@ -1456,7 +1478,9 @@ def test_get_ack_errors_from_call_returned_none(from_call): manager = make_manager() mock_gprc_call = mock.Mock(spec=grpc.Call) - exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + exception = exceptions.InternalServerError( + "msg", errors=(), response=mock_gprc_call + ) from_call.return_value = None # rpc_status.from_call() returned None assert not streaming_pull_manager._get_ack_errors(exception) @@ -1467,7 +1491,9 @@ def test_get_ack_errors_value_error_thrown(from_call): manager = make_manager() mock_gprc_call = mock.Mock(spec=grpc.Call) - exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + exception = exceptions.InternalServerError( + "msg", errors=(), response=mock_gprc_call + ) from_call.side_effect = ValueError("val error msg") # ValueError thrown, so return None assert not streaming_pull_manager._get_ack_errors(exception) @@ -1484,7 +1510,9 @@ def test_get_ack_errors_happy_case(from_call): error_info.metadata["ack_1"] = "error1" st.details.add().Pack(error_info) mock_gprc_call = mock.Mock(spec=grpc.Call) - exception = exceptions.InternalServerError("msg", errors=(), response=mock_gprc_call) + exception = exceptions.InternalServerError( + "msg", errors=(), response=mock_gprc_call + ) from_call.side_effect = None from_call.return_value = st # happy case - errors returned in a map @@ -1497,7 +1525,9 @@ def test_process_futures_no_requests(): # no requests so no items in results lists future_reqs_dict = {} errors_dict = {} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) assert not requests_completed assert not requests_to_retry @@ -1506,7 +1536,9 @@ def test_process_futures_error_dict_is_none(): # it's valid to pass in `None` for `errors_dict` future_reqs_dict = {} errors_dict = None - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) assert not requests_completed assert not requests_to_retry @@ -1515,12 +1547,16 @@ def test_process_futures_no_errors(): # no errors so request should be completed future = futures.Future() future_reqs_dict = { - 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) } errors_dict = {} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) - assert requests_completed[0].ack_id == 'ackid1' - assert future.result() == 'ackid1' + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) + assert requests_completed[0].ack_id == "ackid1" + assert future.result() == "ackid1" assert not requests_to_retry @@ -1528,11 +1564,15 @@ def test_process_futures_permanent_error_raises_exception(): # a permanent error raises an exception future = futures.Future() future_reqs_dict = { - 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) } - errors_dict = {'ackid1': 'PERMANENT_FAILURE_INVALID_ACK_ID'} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) - assert requests_completed[0].ack_id == 'ackid1' + errors_dict = {"ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID"} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) + assert requests_completed[0].ack_id == "ackid1" with pytest.raises(RuntimeError) as exc_info: future.result() assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" @@ -1543,12 +1583,16 @@ def test_process_futures_transient_error_returns_request(): # a transient error returns the request in `requests_to_retry` future = futures.Future() future_reqs_dict = { - 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) } - errors_dict = {'ackid1': 'TRANSIENT_FAILURE_INVALID_ACK_ID'} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + errors_dict = {"ackid1": "TRANSIENT_FAILURE_INVALID_ACK_ID"} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) assert not requests_completed - assert requests_to_retry[0].ack_id == 'ackid1' + assert requests_to_retry[0].ack_id == "ackid1" assert not future.done() @@ -1556,11 +1600,15 @@ def test_process_futures_unknown_error_raises_exception(): # an unknown error raises an exception future = futures.Future() future_reqs_dict = { - 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future) + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) } - errors_dict = {'ackid1': 'unknown_error'} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) - assert requests_completed[0].ack_id == 'ackid1' + errors_dict = {"ackid1": "unknown_error"} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) + assert requests_completed[0].ack_id == "ackid1" with pytest.raises(RuntimeError) as exc_info: future.result() assert str(exc_info.value) == "Unknown error: unknown_error" @@ -1573,23 +1621,46 @@ def test_process_futures_mixed_success_and_failure_acks(): future2 = futures.Future() future3 = futures.Future() future_reqs_dict = { - 'ackid1': requests.AckRequest(ack_id='ackid1', byte_size=0, time_to_ack=20, ordering_key="", future=future1), - 'ackid2': requests.AckRequest(ack_id='ackid2', byte_size=0, time_to_ack=20, ordering_key="", future=future2), - 'ackid3': requests.AckRequest(ack_id='ackid3', byte_size=0, time_to_ack=20, ordering_key="", future=future3) + "ackid1": requests.AckRequest( + ack_id="ackid1", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=future1, + ), + "ackid2": requests.AckRequest( + ack_id="ackid2", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=future2, + ), + "ackid3": requests.AckRequest( + ack_id="ackid3", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=future3, + ), + } + errors_dict = { + "ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID", + "ackid2": "TRANSIENT_FAILURE_INVALID_ACK_ID", } - errors_dict = {'ackid1': 'PERMANENT_FAILURE_INVALID_ACK_ID', 'ackid2': 'TRANSIENT_FAILURE_INVALID_ACK_ID'} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) # message with ack_id 'ackid1' fails with an exception - assert requests_completed[0].ack_id == 'ackid1' + assert requests_completed[0].ack_id == "ackid1" with pytest.raises(RuntimeError) as exc_info: future1.result() assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" # message with ack_id 'ackid2' is to be retried - assert requests_to_retry[0].ack_id == 'ackid2' + assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() # message with ack_id 'ackid3' succeeds - assert requests_completed[1].ack_id == 'ackid3' - assert future3.result() == 'ackid3' + assert requests_completed[1].ack_id == "ackid3" + assert future3.result() == "ackid3" def test_process_futures_mixed_success_and_failure_modacks(): @@ -1598,21 +1669,25 @@ def test_process_futures_mixed_success_and_failure_modacks(): future2 = futures.Future() future3 = futures.Future() future_reqs_dict = { - 'ackid1': requests.ModAckRequest(ack_id='ackid1', seconds=60, future=future1), - 'ackid2': requests.ModAckRequest(ack_id='ackid2', seconds=60, future=future2), - 'ackid3': requests.ModAckRequest(ack_id='ackid3', seconds=60, future=future3) + "ackid1": requests.ModAckRequest(ack_id="ackid1", seconds=60, future=future1), + "ackid2": requests.ModAckRequest(ack_id="ackid2", seconds=60, future=future2), + "ackid3": requests.ModAckRequest(ack_id="ackid3", seconds=60, future=future3), } - errors_dict = {'ackid1': 'PERMANENT_FAILURE_INVALID_ACK_ID', 'ackid2': 'TRANSIENT_FAILURE_INVALID_ACK_ID'} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures(future_reqs_dict, errors_dict) + errors_dict = { + "ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID", + "ackid2": "TRANSIENT_FAILURE_INVALID_ACK_ID", + } + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + future_reqs_dict, errors_dict + ) # message with ack_id 'ackid1' fails with an exception - assert requests_completed[0].ack_id == 'ackid1' + assert requests_completed[0].ack_id == "ackid1" with pytest.raises(RuntimeError) as exc_info: future1.result() assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" # message with ack_id 'ackid2' is to be retried - assert requests_to_retry[0].ack_id == 'ackid2' + assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() # message with ack_id 'ackid3' succeeds - assert requests_completed[1].ack_id == 'ackid3' - assert future3.result() == 'ackid3' - + assert requests_completed[1].ack_id == "ackid3" + assert future3.result() == "ackid3" From ccbd066470bc4394f6ecc1da0a3dadc6b3c227ad Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 15:43:19 -0500 Subject: [PATCH 06/43] loosen version requirement for grpcio-status dependency to fix build --- setup.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/setup.py b/setup.py index d3110f9e4..5423bbb0d 100644 --- a/setup.py +++ b/setup.py @@ -36,7 +36,7 @@ "google-api-core[grpc] >= 1.28.0, <3.0.0dev", "proto-plus >= 1.7.1", "grpc-google-iam-v1 >= 0.12.3, < 0.13dev", - "grpcio-status >= 1.43.0", + "grpcio-status >= 1.16.0", ] extras = {"libcst": "libcst >= 0.3.10"} From bd21fade4c471fa76d62c3a78560493ad90c35b5 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 15:44:59 -0500 Subject: [PATCH 07/43] rerun formatter with new version of black to fix lint error --- .../pubsub_v1/subscriber/_protocol/streaming_pull_manager.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 24fe99a60..1d359d6c8 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -114,7 +114,7 @@ def _wrap_callback_errors( def _get_ack_errors( - exc: exceptions.GoogleAPICallError + exc: exceptions.GoogleAPICallError, ) -> Optional["containers.ScalarMap"]: if not exc.response: _LOGGER.debug("No response obj in errored RPC call.") From a6ab8efa97d2bf2b004a46f34a0776d26a6bd2ec Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 16 Feb 2022 17:09:52 -0500 Subject: [PATCH 08/43] Add receive_messages_with_exactly_once_subscribe sample. --- samples/snippets/subscriber.py | 55 ++++++++++++++++++++++++++++++++++ 1 file changed, 55 insertions(+) diff --git a/samples/snippets/subscriber.py b/samples/snippets/subscriber.py index 7bc124ca8..c902fb2ad 100644 --- a/samples/snippets/subscriber.py +++ b/samples/snippets/subscriber.py @@ -580,6 +580,61 @@ def callback(message: pubsub_v1.subscriber.message.Message) -> None: # [END pubsub_subscriber_blocking_shutdown] +def receive_messages_with_exactly_once_subscribe( + project_id: str, subscription_id: str, timeout: Optional[float] = None +) -> None: + """Receives messages from a pull subscription with exactly-once enabled.""" + # [START pubsub_subscriber_async_pull] + # [START pubsub_quickstart_subscriber] + from concurrent.futures import TimeoutError + from google.cloud import pubsub_v1 + + # TODO(developer) + # project_id = "your-project-id" + # subscription_id = "your-subscription-id" + # Number of seconds the subscriber should listen for messages + # timeout = 5.0 + + subscriber = pubsub_v1.SubscriberClient() + # The `subscription_path` method creates a fully qualified identifier + # in the form `projects/{project_id}/subscriptions/{subscription_id}` + subscription_path = subscriber.subscription_path(project_id, subscription_id) + + def callback(message: pubsub_v1.subscriber.message.Message) -> None: + print(f"Received {message}.") + + ack_future = message.ack_with_response() + + try: + # Block on result of acknowledge call. + ack_id = ack_future.result() + print(f"Ack for id {ack_id} successful.") + except RuntimeError as e: + # A permanent error indicates the ack_id is no longer valid - retries + # will always fail. + if "Permanent error" in str(e): + print(f"Ack for id {message.ack_id} failed with permanent error: {e}") + except Exception as e: + # All other errors, including failures after retries, fall here. + print(f"An ack error occurred: {e}") + + + streaming_pull_future = subscriber.subscribe(subscription_path, callback=callback) + print(f"Listening for messages on {subscription_path}..\n") + + # Wrap subscriber in a 'with' block to automatically call close() when done. + with subscriber: + try: + # When `timeout` is not set, result() will block indefinitely, + # unless an exception is encountered first. + streaming_pull_future.result(timeout=timeout) + except TimeoutError: + streaming_pull_future.cancel() # Trigger the shutdown. + streaming_pull_future.result() # Block until the shutdown is complete. + # [END pubsub_subscriber_async_pull] + # [END pubsub_quickstart_subscriber] + + def synchronous_pull(project_id: str, subscription_id: str) -> None: """Pulling messages synchronously.""" # [START pubsub_subscriber_sync_pull] From fd7301515d698848a64e08c5cd1c445c3c86d3b2 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 13:07:21 -0500 Subject: [PATCH 09/43] Return new AcknowledgeError exception type for ack/modack failures. Translate permanent GRPC errors to an error enum contained in this exception type. --- .../_protocol/streaming_pull_manager.py | 81 +++++++++++++------ .../cloud/pubsub_v1/subscriber/exceptions.py | 46 +++++++++++ .../subscriber/test_streaming_pull_manager.py | 34 ++++---- 3 files changed, 121 insertions(+), 40 deletions(-) create mode 100644 google/cloud/pubsub_v1/subscriber/exceptions.py diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 1d359d6c8..11f510fa9 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -34,16 +34,19 @@ from google.cloud.pubsub_v1.subscriber._protocol import leaser from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.cloud.pubsub_v1.subscriber._protocol import requests +from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeError, AcknowledgeErrorCode import google.cloud.pubsub_v1.subscriber.message from google.cloud.pubsub_v1.subscriber.scheduler import ThreadScheduler from google.pubsub_v1 import types as gapic_types from grpc_status import rpc_status from google.rpc.error_details_pb2 import ErrorInfo +from google.rpc import code_pb2 if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1 import subscriber from google.cloud.pubsub_v1.subscriber.scheduler import Scheduler from google.protobuf.internal import containers + from google.rpc import status_pb2 _LOGGER = logging.getLogger(__name__) @@ -113,24 +116,12 @@ def _wrap_callback_errors( on_callback_error(exc) -def _get_ack_errors( - exc: exceptions.GoogleAPICallError, -) -> Optional["containers.ScalarMap"]: +def _get_status(exc: exceptions.GoogleAPICallError,) -> Optional["status_pb2.Status"]: if not exc.response: _LOGGER.debug("No response obj in errored RPC call.") return None try: - status = rpc_status.from_call(exc.response) - if not status: - _LOGGER.debug("Unable to get status of errored RPC.") - return None - for detail in status.details: - if detail.Is(ErrorInfo.DESCRIPTOR): - info = ErrorInfo() - if not detail.Unpack(info): - _LOGGER.debug("Unable to unpack ErrorInfo.") - return None - return info.metadata + return rpc_status.from_call(exc.response) # Possible "If the gRPC call’s code or details are inconsistent # with the status code and message inside of the # google.rpc.status.Status" @@ -139,7 +130,25 @@ def _get_ack_errors( return None +def _get_ack_errors( + exc: exceptions.GoogleAPICallError, +) -> Optional["containers.ScalarMap"]: + status = _get_status(exc) + if not status: + _LOGGER.debug("Unable to get status of errored RPC.") + return None + for detail in status.details: + if detail.Is(ErrorInfo.DESCRIPTOR): + info = ErrorInfo() + if not detail.Unpack(info): + _LOGGER.debug("Unable to unpack ErrorInfo.") + return None + return info.metadata + return None + + def _process_futures( + error_status: Optional["status_pb2.Status"], future_reqs_dict: "containers.ScalarMap", errors_dict: Optional["containers.ScalarMap"], ): @@ -154,18 +163,39 @@ def _process_futures( for ack_id in future_reqs_dict: if errors_dict and ack_id in errors_dict: exactly_once_error = errors_dict[ack_id] - if exactly_once_error.startswith("PERMANENT_"): - exc = RuntimeError("Permanent error: " + exactly_once_error) - future = future_reqs_dict[ack_id].future - future.set_exception(exc) - requests_completed.append(future_reqs_dict[ack_id]) - elif exactly_once_error.startswith("TRANSIENT_"): + if exactly_once_error.startswith("TRANSIENT_"): requests_to_retry.append(future_reqs_dict[ack_id]) else: - exc = RuntimeError("Unknown error: " + exactly_once_error) + if exactly_once_error == "PERMANENT_FAILURE_INVALID_ACK_ID": + exc = AcknowledgeError( + AcknowledgeErrorCode.INVALID_ACK_ID, info = None + ) + else: + exc = AcknowledgeError( + AcknowledgeErrorCode.OTHER, exactly_once_error + ) + future = future_reqs_dict[ack_id].future future.set_exception(exc) requests_completed.append(future_reqs_dict[ack_id]) + elif error_status: + # Only permanent errors are expected here b/c retriable errors are + # retried at the lower, GRPC level. + if error_status.code == code_pb2.PERMISSION_DENIED: + exc = AcknowledgeError( + AcknowledgeErrorCode.PERMISSION_DENIED, info = None + ) + elif error_status.code == code_pb2.FAILED_PRECONDITION: + exc = AcknowledgeError( + AcknowledgeErrorCode.FAILED_PRECONDITION, info = None + ) + else: + exc = AcknowledgeError( + AcknowledgeErrorCode.OTHER, str(error_status) + ) + future = future_reqs_dict[ack_id].future + future.set_exception(exc) + requests_completed.append(future_reqs_dict[ack_id]) else: future = future_reqs_dict[ack_id].future # success @@ -540,7 +570,7 @@ def send_unary_ack( """ assert ack_ids - success = True + error_status = None ack_errors_dict = None try: self._client.acknowledge(subscription=self._subscription, ack_ids=ack_ids) @@ -550,6 +580,7 @@ def send_unary_ack( "non-fatal as stream requests are best-effort.", exc_info=True, ) + error_status = _get_status(exc) ack_errors_dict = _get_ack_errors(exc) except exceptions.RetryError as exc: _LOGGER.debug( @@ -563,7 +594,7 @@ def send_unary_ack( raise requests_completed, requests_to_retry = _process_futures( - future_reqs_dict, ack_errors_dict + error_status, future_reqs_dict, ack_errors_dict ) return requests_completed, requests_to_retry @@ -577,6 +608,7 @@ def send_unary_modack( """ assert modify_deadline_ack_ids + error_status = None modack_errors_dict = None try: # Send ack_ids with the same deadline seconds together. @@ -598,6 +630,7 @@ def send_unary_modack( "non-fatal as stream requests are best-effort.", exc_info=True, ) + error_status = _get_status(exc) modack_errors_dict = _get_ack_errors(exc) except exceptions.RetryError as exc: _LOGGER.debug( @@ -611,7 +644,7 @@ def send_unary_modack( raise requests_completed, requests_to_retry = _process_futures( - future_reqs_dict, modack_errors_dict + error_status, future_reqs_dict, modack_errors_dict ) return requests_completed, requests_to_retry diff --git a/google/cloud/pubsub_v1/subscriber/exceptions.py b/google/cloud/pubsub_v1/subscriber/exceptions.py new file mode 100644 index 000000000..6415a4547 --- /dev/null +++ b/google/cloud/pubsub_v1/subscriber/exceptions.py @@ -0,0 +1,46 @@ +# Copyright 2017, Google LLC All rights reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +from __future__ import absolute_import + +from enum import Enum +from google.api_core.exceptions import GoogleAPICallError +from typing import Optional + + +class AcknowledgeErrorCode(Enum): + SUCCESS = 1 + PERMISSION_DENIED = 2 + FAILED_PRECONDITION = 3 + INVALID_ACK_ID = 4 + OTHER = 5 + + +class AcknowledgeError(GoogleAPICallError): + """Error during ack/modack/nack operation on exactly-once-enabled subscription.""" + + + def __init__(self, error_code: str, info: Optional[str]): + self.error_code = error_code + self.info = info + message = None + if info: + message = str(self.error_code) + " : " + self.info + else: + message = str(self.error_code) + super(AcknowledgeError, self).__init__(message) + +__all__ = ( + "AcknowledgeError", +) diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 5a7c36a7d..a09c9dcfc 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -33,6 +33,7 @@ from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.cloud.pubsub_v1.subscriber._protocol import requests from google.cloud.pubsub_v1.subscriber._protocol import streaming_pull_manager +from google.cloud.pubsub_v1.subscriber import exceptions as subscriber_exceptions from google.cloud.pubsub_v1.subscriber import futures from google.pubsub_v1 import types as gapic_types import grpc_status @@ -1526,7 +1527,7 @@ def test_process_futures_no_requests(): future_reqs_dict = {} errors_dict = {} requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) assert not requests_completed assert not requests_to_retry @@ -1537,7 +1538,7 @@ def test_process_futures_error_dict_is_none(): future_reqs_dict = {} errors_dict = None requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) assert not requests_completed assert not requests_to_retry @@ -1553,7 +1554,7 @@ def test_process_futures_no_errors(): } errors_dict = {} requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" assert future.result() == "ackid1" @@ -1570,12 +1571,12 @@ def test_process_futures_permanent_error_raises_exception(): } errors_dict = {"ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID"} requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" - with pytest.raises(RuntimeError) as exc_info: + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.INVALID_ACK_ID assert not requests_to_retry @@ -1589,7 +1590,7 @@ def test_process_futures_transient_error_returns_request(): } errors_dict = {"ackid1": "TRANSIENT_FAILURE_INVALID_ACK_ID"} requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) assert not requests_completed assert requests_to_retry[0].ack_id == "ackid1" @@ -1606,12 +1607,13 @@ def test_process_futures_unknown_error_raises_exception(): } errors_dict = {"ackid1": "unknown_error"} requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" - with pytest.raises(RuntimeError) as exc_info: + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert str(exc_info.value) == "Unknown error: unknown_error" + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.OTHER + assert exc_info.value.info == "unknown_error" assert not requests_to_retry @@ -1648,13 +1650,13 @@ def test_process_futures_mixed_success_and_failure_acks(): "ackid2": "TRANSIENT_FAILURE_INVALID_ACK_ID", } requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) # message with ack_id 'ackid1' fails with an exception assert requests_completed[0].ack_id == "ackid1" - with pytest.raises(RuntimeError) as exc_info: + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future1.result() - assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.INVALID_ACK_ID # message with ack_id 'ackid2' is to be retried assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() @@ -1678,13 +1680,13 @@ def test_process_futures_mixed_success_and_failure_modacks(): "ackid2": "TRANSIENT_FAILURE_INVALID_ACK_ID", } requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - future_reqs_dict, errors_dict + None, future_reqs_dict, errors_dict ) # message with ack_id 'ackid1' fails with an exception assert requests_completed[0].ack_id == "ackid1" - with pytest.raises(RuntimeError) as exc_info: + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future1.result() - assert str(exc_info.value) == "Permanent error: PERMANENT_FAILURE_INVALID_ACK_ID" + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.INVALID_ACK_ID # message with ack_id 'ackid2' is to be retried assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() From 349de4074416ed5abdf55c212a996c4a3f1015d8 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 13:37:14 -0500 Subject: [PATCH 10/43] Modify exactly-once subscribe sample to use new AcknowledgeError exception. --- samples/snippets/subscriber.py | 22 ++++++++++------------ 1 file changed, 10 insertions(+), 12 deletions(-) diff --git a/samples/snippets/subscriber.py b/samples/snippets/subscriber.py index c902fb2ad..bc358b3bb 100644 --- a/samples/snippets/subscriber.py +++ b/samples/snippets/subscriber.py @@ -606,18 +606,16 @@ def callback(message: pubsub_v1.subscriber.message.Message) -> None: ack_future = message.ack_with_response() try: - # Block on result of acknowledge call. - ack_id = ack_future.result() - print(f"Ack for id {ack_id} successful.") - except RuntimeError as e: - # A permanent error indicates the ack_id is no longer valid - retries - # will always fail. - if "Permanent error" in str(e): - print(f"Ack for id {message.ack_id} failed with permanent error: {e}") - except Exception as e: - # All other errors, including failures after retries, fall here. - print(f"An ack error occurred: {e}") - + # Block on result of acknowledge call. + ack_id = ack_future.result() + print(f"Ack for id {ack_id} successful.") + except pubsub_1.subscriber.exceptions.AcknowledgeError as e: + print(f"Ack for id {message.ack_id} failed with error: {e.error_code}") + if ( + e.error_code + == pubsub_1.subscriber.exceptions.AcknowledgeErrorCode.OTHER + ): + print(f"Additional error info: {e.info}.") streaming_pull_future = subscriber.subscribe(subscription_path, callback=callback) print(f"Listening for messages on {subscription_path}..\n") From 71cb780932650263fd1d490d19f36c9feba42015 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 13:38:52 -0500 Subject: [PATCH 11/43] Fix formatting for google/cloud/pubsub_v1/subscriber/exceptions.py --- google/cloud/pubsub_v1/subscriber/exceptions.py | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/exceptions.py b/google/cloud/pubsub_v1/subscriber/exceptions.py index 6415a4547..0a3531c57 100644 --- a/google/cloud/pubsub_v1/subscriber/exceptions.py +++ b/google/cloud/pubsub_v1/subscriber/exceptions.py @@ -30,17 +30,15 @@ class AcknowledgeErrorCode(Enum): class AcknowledgeError(GoogleAPICallError): """Error during ack/modack/nack operation on exactly-once-enabled subscription.""" - def __init__(self, error_code: str, info: Optional[str]): self.error_code = error_code self.info = info message = None if info: - message = str(self.error_code) + " : " + self.info + message = str(self.error_code) + " : " + self.info else: - message = str(self.error_code) + message = str(self.error_code) super(AcknowledgeError, self).__init__(message) -__all__ = ( - "AcknowledgeError", -) + +__all__ = ("AcknowledgeError",) From 77ce3ef64b6b35514d444b191c563c18625b997c Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 14:28:19 -0500 Subject: [PATCH 12/43] Address Mahesh's comments --- .../_protocol/streaming_pull_manager.py | 2 +- samples/snippets/subscriber.py | 15 ++++++--------- .../subscriber/test_streaming_pull_manager.py | 6 +++--- 3 files changed, 10 insertions(+), 13 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 11f510fa9..344a75cbb 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -199,7 +199,7 @@ def _process_futures( else: future = future_reqs_dict[ack_id].future # success - future.set_result(ack_id) + future.set_result(AcknowledgeErrorCode.SUCCESS) requests_completed.append(future_reqs_dict[ack_id]) return requests_completed, requests_to_retry diff --git a/samples/snippets/subscriber.py b/samples/snippets/subscriber.py index bc358b3bb..64a6bda9e 100644 --- a/samples/snippets/subscriber.py +++ b/samples/snippets/subscriber.py @@ -583,7 +583,7 @@ def callback(message: pubsub_v1.subscriber.message.Message) -> None: def receive_messages_with_exactly_once_subscribe( project_id: str, subscription_id: str, timeout: Optional[float] = None ) -> None: - """Receives messages from a pull subscription with exactly-once enabled.""" + """Receives messages from a pull subscription with exactly-once delivery enabled.""" # [START pubsub_subscriber_async_pull] # [START pubsub_quickstart_subscriber] from concurrent.futures import TimeoutError @@ -607,15 +607,12 @@ def callback(message: pubsub_v1.subscriber.message.Message) -> None: try: # Block on result of acknowledge call. - ack_id = ack_future.result() - print(f"Ack for id {ack_id} successful.") + ack_future.result() + print(f"Ack for message {message.message_id} successful.") except pubsub_1.subscriber.exceptions.AcknowledgeError as e: - print(f"Ack for id {message.ack_id} failed with error: {e.error_code}") - if ( - e.error_code - == pubsub_1.subscriber.exceptions.AcknowledgeErrorCode.OTHER - ): - print(f"Additional error info: {e.info}.") + print( + f"Ack for message {message.message_id} failed with error: {e.error_code}" + ) streaming_pull_future = subscriber.subscribe(subscription_path, callback=callback) print(f"Listening for messages on {subscription_path}..\n") diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index a09c9dcfc..a5fb31619 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1557,7 +1557,7 @@ def test_process_futures_no_errors(): None, future_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" - assert future.result() == "ackid1" + assert future.result() == subscriber_exceptions.AcknowledgeErrorCode.SUCCESS assert not requests_to_retry @@ -1662,7 +1662,7 @@ def test_process_futures_mixed_success_and_failure_acks(): assert not requests_to_retry[0].future.done() # message with ack_id 'ackid3' succeeds assert requests_completed[1].ack_id == "ackid3" - assert future3.result() == "ackid3" + assert future3.result() == subscriber_exceptions.AcknowledgeErrorCode.SUCCESS def test_process_futures_mixed_success_and_failure_modacks(): @@ -1692,4 +1692,4 @@ def test_process_futures_mixed_success_and_failure_modacks(): assert not requests_to_retry[0].future.done() # message with ack_id 'ackid3' succeeds assert requests_completed[1].ack_id == "ackid3" - assert future3.result() == "ackid3" + assert future3.result() == subscriber_exceptions.AcknowledgeErrorCode.SUCCESS From f6f5d8ef2e539611ed36a2b9ef2a9402bcefed02 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 15:11:46 -0500 Subject: [PATCH 13/43] Rename AcknowledgeErrorCode to AcknowledgeStatus bc it includes SUCCESS. --- .../subscriber/_protocol/streaming_pull_manager.py | 14 +++++++------- google/cloud/pubsub_v1/subscriber/exceptions.py | 2 +- .../subscriber/test_streaming_pull_manager.py | 14 +++++++------- 3 files changed, 15 insertions(+), 15 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 344a75cbb..0f57facde 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -34,7 +34,7 @@ from google.cloud.pubsub_v1.subscriber._protocol import leaser from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.cloud.pubsub_v1.subscriber._protocol import requests -from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeError, AcknowledgeErrorCode +from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeError, AcknowledgeStatus import google.cloud.pubsub_v1.subscriber.message from google.cloud.pubsub_v1.subscriber.scheduler import ThreadScheduler from google.pubsub_v1 import types as gapic_types @@ -168,11 +168,11 @@ def _process_futures( else: if exactly_once_error == "PERMANENT_FAILURE_INVALID_ACK_ID": exc = AcknowledgeError( - AcknowledgeErrorCode.INVALID_ACK_ID, info = None + AcknowledgeStatus.INVALID_ACK_ID, info = None ) else: exc = AcknowledgeError( - AcknowledgeErrorCode.OTHER, exactly_once_error + AcknowledgeStatus.OTHER, exactly_once_error ) future = future_reqs_dict[ack_id].future @@ -183,15 +183,15 @@ def _process_futures( # retried at the lower, GRPC level. if error_status.code == code_pb2.PERMISSION_DENIED: exc = AcknowledgeError( - AcknowledgeErrorCode.PERMISSION_DENIED, info = None + AcknowledgeStatus.PERMISSION_DENIED, info = None ) elif error_status.code == code_pb2.FAILED_PRECONDITION: exc = AcknowledgeError( - AcknowledgeErrorCode.FAILED_PRECONDITION, info = None + AcknowledgeStatus.FAILED_PRECONDITION, info = None ) else: exc = AcknowledgeError( - AcknowledgeErrorCode.OTHER, str(error_status) + AcknowledgeStatus.OTHER, str(error_status) ) future = future_reqs_dict[ack_id].future future.set_exception(exc) @@ -199,7 +199,7 @@ def _process_futures( else: future = future_reqs_dict[ack_id].future # success - future.set_result(AcknowledgeErrorCode.SUCCESS) + future.set_result(AcknowledgeStatus.SUCCESS) requests_completed.append(future_reqs_dict[ack_id]) return requests_completed, requests_to_retry diff --git a/google/cloud/pubsub_v1/subscriber/exceptions.py b/google/cloud/pubsub_v1/subscriber/exceptions.py index 0a3531c57..9c2f604d9 100644 --- a/google/cloud/pubsub_v1/subscriber/exceptions.py +++ b/google/cloud/pubsub_v1/subscriber/exceptions.py @@ -19,7 +19,7 @@ from typing import Optional -class AcknowledgeErrorCode(Enum): +class AcknowledgeStatus(Enum): SUCCESS = 1 PERMISSION_DENIED = 2 FAILED_PRECONDITION = 3 diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index a5fb31619..723f12923 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1557,7 +1557,7 @@ def test_process_futures_no_errors(): None, future_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" - assert future.result() == subscriber_exceptions.AcknowledgeErrorCode.SUCCESS + assert future.result() == subscriber_exceptions.AcknowledgeStatus.SUCCESS assert not requests_to_retry @@ -1576,7 +1576,7 @@ def test_process_futures_permanent_error_raises_exception(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.INVALID_ACK_ID + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID assert not requests_to_retry @@ -1612,7 +1612,7 @@ def test_process_futures_unknown_error_raises_exception(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.OTHER + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.OTHER assert exc_info.value.info == "unknown_error" assert not requests_to_retry @@ -1656,13 +1656,13 @@ def test_process_futures_mixed_success_and_failure_acks(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future1.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.INVALID_ACK_ID + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID # message with ack_id 'ackid2' is to be retried assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() # message with ack_id 'ackid3' succeeds assert requests_completed[1].ack_id == "ackid3" - assert future3.result() == subscriber_exceptions.AcknowledgeErrorCode.SUCCESS + assert future3.result() == subscriber_exceptions.AcknowledgeStatus.SUCCESS def test_process_futures_mixed_success_and_failure_modacks(): @@ -1686,10 +1686,10 @@ def test_process_futures_mixed_success_and_failure_modacks(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future1.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeErrorCode.INVALID_ACK_ID + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID # message with ack_id 'ackid2' is to be retried assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() # message with ack_id 'ackid3' succeeds assert requests_completed[1].ack_id == "ackid3" - assert future3.result() == subscriber_exceptions.AcknowledgeErrorCode.SUCCESS + assert future3.result() == subscriber_exceptions.AcknowledgeStatus.SUCCESS From f35573a98dd5b0680a0c519a7e94f94f6d39aecf Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 18:25:26 -0500 Subject: [PATCH 14/43] Retry leasing modack failures if exactly-once is enabled. Tests haven't been updated yet, so they're failing. --- .../pubsub_v1/subscriber/_protocol/leaser.py | 4 +- .../_protocol/streaming_pull_manager.py | 66 ++++++++++++------- .../subscriber/test_streaming_pull_manager.py | 15 ++++- 3 files changed, 58 insertions(+), 27 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py index 09cb74c40..04fb02ce1 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py @@ -181,7 +181,7 @@ def maintain_leases(self) -> None: for item in to_drop: leased_messages.pop(item.ack_id) - # Create a streaming pull request. + # Create a modack request. # We do not actually call `modify_ack_deadline` over and over # because it is more efficient to make a single request. ack_ids = leased_messages.keys() @@ -200,6 +200,8 @@ def maintain_leases(self) -> None: for ack_id in ack_ids ] ) + ack_id_gen = (ack_id for ack_id in ack_ids) + self._manager._send_lease_modacks(ack_id_gen, ack_deadline) # Now wait an appropriate period of time and do this again. # diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 0f57facde..5a7f0036b 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -20,7 +20,7 @@ import logging import threading import typing -from typing import Any, Callable, Iterable, List, Optional, Tuple, Union +from typing import Any, Callable, Iterable, List, Optional, Sequence, Tuple, Union import uuid import grpc # type: ignore @@ -34,8 +34,12 @@ from google.cloud.pubsub_v1.subscriber._protocol import leaser from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.cloud.pubsub_v1.subscriber._protocol import requests -from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeError, AcknowledgeStatus +from google.cloud.pubsub_v1.subscriber.exceptions import ( + AcknowledgeError, + AcknowledgeStatus, +) import google.cloud.pubsub_v1.subscriber.message +from google.cloud.pubsub_v1.subscriber import futures from google.cloud.pubsub_v1.subscriber.scheduler import ThreadScheduler from google.pubsub_v1 import types as gapic_types from grpc_status import rpc_status @@ -167,13 +171,9 @@ def _process_futures( requests_to_retry.append(future_reqs_dict[ack_id]) else: if exactly_once_error == "PERMANENT_FAILURE_INVALID_ACK_ID": - exc = AcknowledgeError( - AcknowledgeStatus.INVALID_ACK_ID, info = None - ) + exc = AcknowledgeError(AcknowledgeStatus.INVALID_ACK_ID, info=None) else: - exc = AcknowledgeError( - AcknowledgeStatus.OTHER, exactly_once_error - ) + exc = AcknowledgeError(AcknowledgeStatus.OTHER, exactly_once_error) future = future_reqs_dict[ack_id].future future.set_exception(exc) @@ -182,17 +182,11 @@ def _process_futures( # Only permanent errors are expected here b/c retriable errors are # retried at the lower, GRPC level. if error_status.code == code_pb2.PERMISSION_DENIED: - exc = AcknowledgeError( - AcknowledgeStatus.PERMISSION_DENIED, info = None - ) + exc = AcknowledgeError(AcknowledgeStatus.PERMISSION_DENIED, info=None) elif error_status.code == code_pb2.FAILED_PRECONDITION: - exc = AcknowledgeError( - AcknowledgeStatus.FAILED_PRECONDITION, info = None - ) + exc = AcknowledgeError(AcknowledgeStatus.FAILED_PRECONDITION, info=None) else: - exc = AcknowledgeError( - AcknowledgeStatus.OTHER, str(error_status) - ) + exc = AcknowledgeError(AcknowledgeStatus.OTHER, str(error_status)) future = future_reqs_dict[ack_id].future future.set_exception(exc) requests_completed.append(future_reqs_dict[ack_id]) @@ -875,6 +869,36 @@ def _get_initial_request( # Return the initial request. return request + def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): + exactly_once_enabled = None + with self._exactly_once_enabled_lock: + exactly_once_enabled = self._exactly_once_enabled + if exactly_once_enabled: + items = [] + for ack_id in ack_ids: + future = futures.Future() + request = requests.ModAckRequest(ack_id, ack_deadline, future) + items.append(request) + + assert self._dispatcher is not None + self._dispatcher.modify_ack_deadline(items) + + for req in items: + try: + req.future.result() + except pubsub_1.subscriber.exceptions.AcknowledgeError as e: + _LOGGER.debug( + f"AcknowledgeError when modacking a message immediately after receiving it.", + exc_info=False, + ) + else: + items = [ + requests.ModAckRequest(message.ack_id, self.ack_deadline, None) + for message in received_messages + ] + assert self._dispatcher is not None + self._dispatcher.modify_ack_deadline(items) + def _on_response(self, response: gapic_types.StreamingPullResponse) -> None: """Process all received Pub/Sub messages. @@ -921,12 +945,8 @@ def _on_response(self, response: gapic_types.StreamingPullResponse) -> None: # Immediately (i.e. without waiting for the auto lease management) # modack the messages we received, as this tells the server that we've # received them. - items = [ - requests.ModAckRequest(message.ack_id, self.ack_deadline, None) - for message in received_messages - ] - assert self._dispatcher is not None - self._dispatcher.modify_ack_deadline(items) + ack_id_gen = (message.ack_id for message in received_messages) + self._send_lease_modacks(ack_id_gen, self.ack_deadline) with self._pause_resume_lock: assert self._scheduler is not None diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 723f12923..79c28a313 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1576,7 +1576,10 @@ def test_process_futures_permanent_error_raises_exception(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID + assert ( + exc_info.value.error_code + == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID + ) assert not requests_to_retry @@ -1656,7 +1659,10 @@ def test_process_futures_mixed_success_and_failure_acks(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future1.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID + assert ( + exc_info.value.error_code + == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID + ) # message with ack_id 'ackid2' is to be retried assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() @@ -1686,7 +1692,10 @@ def test_process_futures_mixed_success_and_failure_modacks(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future1.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID + assert ( + exc_info.value.error_code + == subscriber_exceptions.AcknowledgeStatus.INVALID_ACK_ID + ) # message with ack_id 'ackid2' is to be retried assert requests_to_retry[0].ack_id == "ackid2" assert not requests_to_retry[0].future.done() From c8017f760e08c5bf0eba28979f7ee64b38befec1 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 18:46:32 -0500 Subject: [PATCH 15/43] Address Mahesh's comments --- google/cloud/pubsub_v1/subscriber/_protocol/leaser.py | 6 ------ .../subscriber/_protocol/streaming_pull_manager.py | 2 +- samples/snippets/subscriber.py | 3 ++- 3 files changed, 3 insertions(+), 8 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py index 04fb02ce1..b39e3a183 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py @@ -194,12 +194,6 @@ def maintain_leases(self) -> None: # way for ``send_request`` to fail when the consumer # is inactive. assert self._manager.dispatcher is not None - self._manager.dispatcher.modify_ack_deadline( - [ - requests.ModAckRequest(ack_id, deadline, None) - for ack_id in ack_ids - ] - ) ack_id_gen = (ack_id for ack_id in ack_ids) self._manager._send_lease_modacks(ack_id_gen, ack_deadline) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 5a7f0036b..aa487fa28 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -887,7 +887,7 @@ def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): try: req.future.result() except pubsub_1.subscriber.exceptions.AcknowledgeError as e: - _LOGGER.debug( + _LOGGER.warning( f"AcknowledgeError when modacking a message immediately after receiving it.", exc_info=False, ) diff --git a/samples/snippets/subscriber.py b/samples/snippets/subscriber.py index 64a6bda9e..b88ef8643 100644 --- a/samples/snippets/subscriber.py +++ b/samples/snippets/subscriber.py @@ -588,6 +588,7 @@ def receive_messages_with_exactly_once_subscribe( # [START pubsub_quickstart_subscriber] from concurrent.futures import TimeoutError from google.cloud import pubsub_v1 + from google.cloud.pubsub_v1.subscriber import sub_exceptions # TODO(developer) # project_id = "your-project-id" @@ -609,7 +610,7 @@ def callback(message: pubsub_v1.subscriber.message.Message) -> None: # Block on result of acknowledge call. ack_future.result() print(f"Ack for message {message.message_id} successful.") - except pubsub_1.subscriber.exceptions.AcknowledgeError as e: + except sub_exceptions.AcknowledgeError as e: print( f"Ack for message {message.message_id} failed with error: {e.error_code}" ) From b2e9c4b79ac34d3d792fe784388f118ea84c4361 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 18 Feb 2022 18:57:58 -0500 Subject: [PATCH 16/43] Shorten use of AcknowledgeError --- .../pubsub_v1/subscriber/_protocol/streaming_pull_manager.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index aa487fa28..0df3049e8 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -886,7 +886,7 @@ def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): for req in items: try: req.future.result() - except pubsub_1.subscriber.exceptions.AcknowledgeError as e: + except AcknowledgeError as e: _LOGGER.warning( f"AcknowledgeError when modacking a message immediately after receiving it.", exc_info=False, From 21c14317b6dd2bdea5d12fddd4d83464890cdd32 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Tue, 22 Feb 2022 18:09:13 -0500 Subject: [PATCH 17/43] Fix tests and code --- .../pubsub_v1/subscriber/_protocol/leaser.py | 2 +- .../_protocol/streaming_pull_manager.py | 6 +-- noxfile.py | 3 ++ .../unit/pubsub_v1/subscriber/test_leaser.py | 23 ++++----- .../subscriber/test_streaming_pull_manager.py | 51 +++++++++++-------- 5 files changed, 49 insertions(+), 36 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py index b39e3a183..de110e992 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/leaser.py @@ -195,7 +195,7 @@ def maintain_leases(self) -> None: # is inactive. assert self._manager.dispatcher is not None ack_id_gen = (ack_id for ack_id in ack_ids) - self._manager._send_lease_modacks(ack_id_gen, ack_deadline) + self._manager._send_lease_modacks(ack_id_gen, deadline) # Now wait an appropriate period of time and do this again. # diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 0df3049e8..b162f6400 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -870,7 +870,7 @@ def _get_initial_request( return request def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): - exactly_once_enabled = None + exactly_once_enabled = False with self._exactly_once_enabled_lock: exactly_once_enabled = self._exactly_once_enabled if exactly_once_enabled: @@ -893,8 +893,8 @@ def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): ) else: items = [ - requests.ModAckRequest(message.ack_id, self.ack_deadline, None) - for message in received_messages + requests.ModAckRequest(ack_id, self.ack_deadline, None) + for ack_id in ack_ids ] assert self._dispatcher is not None self._dispatcher.modify_ack_deadline(items) diff --git a/noxfile.py b/noxfile.py index e9fea8af8..9bef72e61 100644 --- a/noxfile.py +++ b/noxfile.py @@ -146,6 +146,9 @@ def default(session): session.install("-e", ".", "-c", constraints_path) # Run py.test against the unit tests. + # THe following flags are useful during development: + # "-s" -> show print() statement output + # "-k " -> filter test cases session.run( "py.test", "--quiet", diff --git a/tests/unit/pubsub_v1/subscriber/test_leaser.py b/tests/unit/pubsub_v1/subscriber/test_leaser.py index 36c184c2d..890c3c947 100644 --- a/tests/unit/pubsub_v1/subscriber/test_leaser.py +++ b/tests/unit/pubsub_v1/subscriber/test_leaser.py @@ -102,7 +102,7 @@ def test_maintain_leases_inactive_manager(caplog): leaser_.maintain_leases() # Leases should still be maintained even if the manager is inactive. - manager.dispatcher.modify_ack_deadline.assert_called() + manager._send_lease_modacks.assert_called() assert "exiting" in caplog.text @@ -138,9 +138,11 @@ def test_maintain_leases_ack_ids(): leaser_.maintain_leases() - manager.dispatcher.modify_ack_deadline.assert_called_once_with( - [requests.ModAckRequest(ack_id="my ack id", seconds=10, future=None)] - ) + assert len(manager._send_lease_modacks.mock_calls) == 1 + call = manager._send_lease_modacks.mock_calls[0] + ack_ids = list(call.args[0]) + assert ack_ids == ["my ack id"] + assert call.args[1] == 10 def test_maintain_leases_no_ack_ids(): @@ -182,14 +184,11 @@ def test_maintain_leases_outdated_items(time): leaser_.maintain_leases() # ack2, ack3, and ack4 should be renewed. ack1 should've been dropped - modacks = manager.dispatcher.modify_ack_deadline.call_args.args[0] - expected = [ - requests.ModAckRequest(ack_id="ack2", seconds=10, future=None), - requests.ModAckRequest(ack_id="ack3", seconds=10, future=None), - requests.ModAckRequest(ack_id="ack4", seconds=10, future=None), - ] - # Use sorting to allow for ordering variance. - assert sorted(modacks) == sorted(expected) + assert len(manager._send_lease_modacks.mock_calls) == 1 + call = manager._send_lease_modacks.mock_calls[0] + ack_ids = list(call.args[0]) + assert ack_ids == ["ack2", "ack3", "ack4"] + assert call.args[1] == 10 manager.dispatcher.drop.assert_called_once_with( [requests.DropRequest(ack_id="ack1", byte_size=50, ordering_key="")] diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 79c28a313..e636d97db 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -129,6 +129,16 @@ def make_manager(**kwargs): ) +def complete_modify_ack_deadline_calls(dispatcher): + def complete_futures(*args, **kwargs): + modack_requests = args[0] + for req in modack_requests: + if req.future: + req.future.set_result(subscriber_exceptions.AcknowledgeStatus.SUCCESS) + + dispatcher.modify_ack_deadline.side_effect = complete_futures + + def fake_leaser_add(leaser, init_msg_count=0, assumed_msg_size=10): """Add a simplified fake add() method to a leaser instance. @@ -992,6 +1002,7 @@ def test__on_response_modifies_ack_deadline_with_exactly_once_min_lease(): # exactly_once is disabled by default. manager, _, dispatcher, leaser, _, scheduler = make_running_manager() manager._callback = mock.sentinel.callback + complete_modify_ack_deadline_calls(dispatcher) # make p99 value smaller than exactly_once min lease manager.ack_histogram.add(10) @@ -1034,37 +1045,36 @@ def test__on_response_modifies_ack_deadline_with_exactly_once_min_lease(): ), ) - # assertions for the _on_response calls below - dispatcher.assert_has_calls( - # assertion 1: mod-acks called with histogram-based lease value - dispatcher.modify_ack_deadline( - [ - requests.ModAckRequest("ack_1", 10, None), - requests.ModAckRequest("ack_2", 10, None), - ] - ), - # assertion 2: mod-acks called with 60 sec min lease value for exactly_once subscriptions - dispatcher.modify_ack_deadline( - [ - requests.ModAckRequest("ack_3", 60, None), - requests.ModAckRequest("ack_4", 60, None), - ] - ), - ) - # exactly_once is still disabled b/c subscription_properties says so - # should satisfy assertion 1 manager._on_response(response1) + # expect mod-acks are called with histogram-based lease value + assert len(dispatcher.modify_ack_deadline.mock_calls) == 1 + call = dispatcher.modify_ack_deadline.mock_calls[0] + assert call.args[0] == [ + requests.ModAckRequest("ack_1", 10, None), + requests.ModAckRequest("ack_2", 10, None), + ] + # exactly_once should be enabled after this request b/c subscription_properties says so - # should satisfy assertion 2 manager._on_response(response2) + # expect mod-acks called with 60 sec min lease value for exactly_once subscriptions + # ignore the futures here + assert len(dispatcher.modify_ack_deadline.mock_calls) == 2 + call = dispatcher.modify_ack_deadline.mock_calls[1] + modack_reqs = call.args[0] + assert modack_reqs[0].ack_id == "ack_3" + assert modack_reqs[0].seconds == 60 + assert modack_reqs[1].ack_id == "ack_4" + assert modack_reqs[1].seconds == 60 + def test__on_response_send_ack_deadline_after_enabling_exactly_once(): # exactly_once is disabled by default. manager, _, dispatcher, leaser, _, scheduler = make_running_manager() manager._callback = mock.sentinel.callback + complete_modify_ack_deadline_calls(dispatcher) # set up an active RPC manager._rpc = mock.create_autospec(bidi.BidiRpc, instance=True) @@ -1306,6 +1316,7 @@ def test__on_response_enable_exactly_once(): manager, _, dispatcher, leaser, _, scheduler = make_running_manager() manager._callback = mock.sentinel.callback + complete_modify_ack_deadline_calls(dispatcher) # Set up the messages. response = gapic_types.StreamingPullResponse( From 08351c2fea30c7a51394dcd825f41ac06aa7e238 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 12:08:58 -0500 Subject: [PATCH 18/43] Fix lint errors --- .../subscriber/_protocol/dispatcher.py | 3 +-- .../subscriber/_protocol/requests.py | 7 ++++--- .../_protocol/streaming_pull_manager.py | 7 +++---- google/cloud/pubsub_v1/subscriber/message.py | 8 +++----- .../pubsub_v1/subscriber/test_dispatcher.py | 1 - .../subscriber/test_streaming_pull_manager.py | 19 ++----------------- 6 files changed, 13 insertions(+), 32 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 8b036ba76..ba7798712 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -18,6 +18,7 @@ import itertools import logging import math +import time import threading import typing from typing import List, Optional, Sequence, Union @@ -26,7 +27,6 @@ from google.cloud.pubsub_v1.subscriber._protocol import helper_threads from google.cloud.pubsub_v1.subscriber._protocol import requests -from google.pubsub_v1 import types as gapic_types if typing.TYPE_CHECKING: # pragma: NO COVER import queue @@ -296,7 +296,6 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: ) time.sleep(time_to_wait) - print(requests_to_retry) future_reqs_dict = { req.ack_id: req for req in requests_to_retry if req.future } diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/requests.py b/google/cloud/pubsub_v1/subscriber/_protocol/requests.py index c8dd90d90..9cd387545 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/requests.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/requests.py @@ -18,6 +18,7 @@ if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1.subscriber import futures + # Namedtuples for management requests. Used by the Message class to communicate # items of work back to the policy. class AckRequest(NamedTuple): @@ -25,7 +26,7 @@ class AckRequest(NamedTuple): byte_size: int time_to_ack: float ordering_key: Optional[str] - future: Optional["pubsub_v1.subscriber.futures.Future"] + future: Optional["futures.Future"] class DropRequest(NamedTuple): @@ -43,11 +44,11 @@ class LeaseRequest(NamedTuple): class ModAckRequest(NamedTuple): ack_id: str seconds: float - future: Optional["pubsub_v1.subscriber.futures.Future"] + future: Optional["futures.Future"] class NackRequest(NamedTuple): ack_id: str byte_size: int ordering_key: Optional[str] - future: Optional["pubsub_v1.subscriber.futures.Future"] + future: Optional["futures.Future"] diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index b162f6400..3c3859869 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -48,7 +48,6 @@ if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1 import subscriber - from google.cloud.pubsub_v1.subscriber.scheduler import Scheduler from google.protobuf.internal import containers from google.rpc import status_pb2 @@ -886,10 +885,10 @@ def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): for req in items: try: req.future.result() - except AcknowledgeError as e: + except AcknowledgeError: _LOGGER.warning( - f"AcknowledgeError when modacking a message immediately after receiving it.", - exc_info=False, + "AcknowledgeError when modacking a message immediately after receiving it.", + exc_info=True, ) else: items = [ diff --git a/google/cloud/pubsub_v1/subscriber/message.py b/google/cloud/pubsub_v1/subscriber/message.py index bfd826a94..adfcbb84c 100644 --- a/google/cloud/pubsub_v1/subscriber/message.py +++ b/google/cloud/pubsub_v1/subscriber/message.py @@ -247,7 +247,7 @@ def ack(self) -> None: ) ) - def ack_with_response(self) -> "pubsub_v1.subscriber.futures.Future": + def ack_with_response(self) -> "futures.Future": """Acknowledge the given message. Acknowledging a message in Pub/Sub means that you are done @@ -319,9 +319,7 @@ def modify_ack_deadline(self, seconds: int) -> None: requests.ModAckRequest(ack_id=self._ack_id, seconds=seconds, future=None) ) - def modify_ack_deadline_with_response( - self, seconds: int - ) -> "pubsub_v1.subscriber.futures.Future": + def modify_ack_deadline_with_response(self, seconds: int) -> "futures.Future": """Resets the deadline for acknowledgement and returns the response status via a future. @@ -365,7 +363,7 @@ def nack(self) -> None: ) ) - def nack_with_response(self) -> "pubsub_v1.subscriber.futures.Future": + def nack_with_response(self) -> "futures.Future": """Decline to acknowledge the given message, returning the response status via a future. diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index a309610e7..70303c4e2 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -20,7 +20,6 @@ from google.cloud.pubsub_v1.subscriber._protocol import helper_threads from google.cloud.pubsub_v1.subscriber._protocol import requests from google.cloud.pubsub_v1.subscriber._protocol import streaming_pull_manager -from google.pubsub_v1 import types as gapic_types import mock import pytest diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index e636d97db..a196fdb71 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -36,12 +36,10 @@ from google.cloud.pubsub_v1.subscriber import exceptions as subscriber_exceptions from google.cloud.pubsub_v1.subscriber import futures from google.pubsub_v1 import types as gapic_types -import grpc_status import grpc from google.rpc import status_pb2 from google.rpc import code_pb2 from google.rpc import error_details_pb2 -from google.protobuf.any_pb2 import Any @pytest.mark.parametrize( @@ -236,8 +234,6 @@ def test__obtain_ack_deadline_with_min_duration_per_lease_extension_too_high(): def test__obtain_ack_deadline_with_exactly_once_enabled(): - from google.cloud.pubsub_v1.subscriber._protocol import histogram - manager = make_manager() manager._flow_control = types.FlowControl( min_duration_per_lease_extension=0 # leave as default value @@ -1106,7 +1102,8 @@ def test__on_response_send_ack_deadline_after_enabling_exactly_once(): manager._on_response(response2) # simulate periodic heartbeat trigger - result = manager.heartbeat() + heartbeat_request_sent = manager.heartbeat() + assert heartbeat_request_sent # heartbeat request is sent with the 60 sec min lease value for exactly_once subscriptions manager._rpc.send.assert_called_once_with( @@ -1312,8 +1309,6 @@ def test__on_response_with_ordering_keys(): def test__on_response_enable_exactly_once(): - from google.cloud.pubsub_v1.subscriber._protocol import histogram - manager, _, dispatcher, leaser, _, scheduler = make_running_manager() manager._callback = mock.sentinel.callback complete_modify_ack_deadline_calls(dispatcher) @@ -1457,8 +1452,6 @@ def test_activate_ordering_keys_stopped_scheduler(): @mock.patch("grpc_status.rpc_status.from_call") @mock.patch("google.protobuf.any_pb2.Any.Unpack") def test_get_ack_errors_unable_to_unpack(from_call, unpack): - manager = make_manager() - st = status_pb2.Status() st.code = code_pb2.Code.INTERNAL st.message = "qmsg" @@ -1478,8 +1471,6 @@ def test_get_ack_errors_unable_to_unpack(from_call, unpack): @mock.patch("grpc_status.rpc_status.from_call") def test_get_ack_errors_no_response_obj(from_call): - manager = make_manager() - exception = exceptions.InternalServerError("msg", errors=(), response=None) # No response obj assert not streaming_pull_manager._get_ack_errors(exception) @@ -1487,8 +1478,6 @@ def test_get_ack_errors_no_response_obj(from_call): @mock.patch("grpc_status.rpc_status.from_call") def test_get_ack_errors_from_call_returned_none(from_call): - manager = make_manager() - mock_gprc_call = mock.Mock(spec=grpc.Call) exception = exceptions.InternalServerError( "msg", errors=(), response=mock_gprc_call @@ -1500,8 +1489,6 @@ def test_get_ack_errors_from_call_returned_none(from_call): @mock.patch("grpc_status.rpc_status.from_call") def test_get_ack_errors_value_error_thrown(from_call): - manager = make_manager() - mock_gprc_call = mock.Mock(spec=grpc.Call) exception = exceptions.InternalServerError( "msg", errors=(), response=mock_gprc_call @@ -1513,8 +1500,6 @@ def test_get_ack_errors_value_error_thrown(from_call): @mock.patch("grpc_status.rpc_status.from_call") def test_get_ack_errors_happy_case(from_call): - manager = make_manager() - st = status_pb2.Status() st.code = code_pb2.Code.INTERNAL st.message = "qmsg" From 7ba40e18bea928c59bb01532d4009ab6fa49cb0f Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 14:12:07 -0500 Subject: [PATCH 19/43] Improved test coverage. --- .../subscriber/_protocol/dispatcher.py | 6 +- noxfile.py | 1 + .../pubsub_v1/subscriber/test_dispatcher.py | 71 +++++++++++++++++++ 3 files changed, 75 insertions(+), 3 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index ba7798712..806a8a28a 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -201,7 +201,7 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, ) while requests_to_retry: - time_to_wait = retry_delay_gen() + time_to_wait = next(retry_delay_gen) _LOGGER.debug( "Retrying {len(requests_to_retry)} ack(s) after delay of " + str(time_to_wait) @@ -288,7 +288,7 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, ) while requests_to_retry: - time_to_wait = retry_delay_gen() + time_to_wait = next(retry_delay_gen) _LOGGER.debug( "Retrying {len(requests_to_retry)} modack(s) after delay of " + str(time_to_wait) @@ -299,7 +299,7 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: future_reqs_dict = { req.ack_id: req for req in requests_to_retry if req.future } - requests_to_retry = self._manager.send_unary_modack( + requests_completed, requests_to_retry = self._manager.send_unary_modack( modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], modify_deadline_seconds=[req.seconds for req in requests_to_retry], future_reqs_dict=future_reqs_dict, diff --git a/noxfile.py b/noxfile.py index 9bef72e61..d1772f18c 100644 --- a/noxfile.py +++ b/noxfile.py @@ -229,6 +229,7 @@ def cover(session): test runs (not system test runs), and then erases coverage data. """ session.install("coverage", "pytest-cov") + # Tip: The "-i" flag lets you ignore errors with specific files. session.run("coverage", "report", "--show-missing", "--fail-under=100") session.run("coverage", "erase") diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index 70303c4e2..e1fb3938b 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -20,6 +20,7 @@ from google.cloud.pubsub_v1.subscriber._protocol import helper_threads from google.cloud.pubsub_v1.subscriber._protocol import requests from google.cloud.pubsub_v1.subscriber._protocol import streaming_pull_manager +from google.cloud.pubsub_v1.subscriber import futures import mock import pytest @@ -161,6 +162,76 @@ def test_ack_splitting_large_payload(): assert sent_ack_ids.most_common(1)[0][1] == 1 # each message ACK-ed exactly once +def test_ack_retry_failed_exactly_once_acks(): + manager = mock.create_autospec( + streaming_pull_manager.StreamingPullManager, instance=True + ) + dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) + + f = futures.Future() + items = [ + requests.AckRequest( + ack_id="ack_id_string", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=f, + ) + ] + # first and second calls fail, third one succeeds + manager.send_unary_ack.side_effect = [([], items), ([], items), (items, [])] + with mock.patch("time.sleep", return_value=None): + dispatcher_.ack(items) + + manager.send_unary_ack.assert_has_calls( + [ + mock.call( + ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ), + mock.call( + ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ), + mock.call( + ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ), + ] + ) + + +def test_modack_retry_failed_exactly_once_acks(): + manager = mock.create_autospec( + streaming_pull_manager.StreamingPullManager, instance=True + ) + dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) + + f = futures.Future() + items = [requests.ModAckRequest(ack_id="ack_id_string", seconds=20, future=f,)] + # first and second calls fail, third one succeeds + manager.send_unary_modack.side_effect = [([], items), ([], items), (items, [])] + with mock.patch("time.sleep", return_value=None): + dispatcher_.modify_ack_deadline(items) + + manager.send_unary_modack.assert_has_calls( + [ + mock.call( + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[20], + future_reqs_dict={"ack_id_string": items[0]}, + ), + mock.call( + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[20], + future_reqs_dict={"ack_id_string": items[0]}, + ), + mock.call( + modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_seconds=[20], + future_reqs_dict={"ack_id_string": items[0]}, + ), + ] + ) + + def test_lease(): manager = mock.create_autospec( streaming_pull_manager.StreamingPullManager, instance=True From 94aa54c21cf9d446a9a3c126f33a504003e82699 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 14:47:48 -0500 Subject: [PATCH 20/43] Improve coverage. --- .../pubsub_v1/subscriber/test_dispatcher.py | 11 +++ .../subscriber/test_streaming_pull_manager.py | 77 +++++++++++++++++++ 2 files changed, 88 insertions(+) diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index e1fb3938b..edad3f4e1 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -75,6 +75,17 @@ def test_dispatch_callback_inactive_manager(item, method_name): method.assert_called_once_with([item]) +def test_unknown_request_type(): + manager = mock.create_autospec( + streaming_pull_manager.StreamingPullManager, instance=True + ) + dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) + + items = ["a random string, not a known request type"] + manager.send_unary_ack.return_value = (items, []) + dispatcher_.dispatch_callback(items) + + def test_ack(): manager = mock.create_autospec( streaming_pull_manager.StreamingPullManager, instance=True diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index a196fdb71..647540450 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1498,6 +1498,21 @@ def test_get_ack_errors_value_error_thrown(from_call): assert not streaming_pull_manager._get_ack_errors(exception) +@mock.patch("grpc_status.rpc_status.from_call") +def test_get_ack_errors_no_error_details(from_call): + st = status_pb2.Status() + st.code = code_pb2.Code.INTERNAL + st.message = "qmsg" + mock_gprc_call = mock.Mock(spec=grpc.Call) + exception = exceptions.InternalServerError( + "msg", errors=(), response=mock_gprc_call + ) + from_call.side_effect = None + from_call.return_value = st + # status has no details to extract exactly-once error info from + assert not streaming_pull_manager._get_ack_errors(exception) + + @mock.patch("grpc_status.rpc_status.from_call") def test_get_ack_errors_happy_case(from_call): st = status_pb2.Status() @@ -1616,6 +1631,68 @@ def test_process_futures_unknown_error_raises_exception(): assert not requests_to_retry +def test_process_futures_permission_denied_error_status_raises_exception(): + # a permission-denied error status raises an exception + future = futures.Future() + future_reqs_dict = { + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) + } + st = status_pb2.Status() + st.code = code_pb2.Code.PERMISSION_DENIED + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + st, future_reqs_dict, None + ) + assert requests_completed[0].ack_id == "ackid1" + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: + future.result() + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.PERMISSION_DENIED + assert exc_info.value.info == None + assert not requests_to_retry + + +def test_process_futures_failed_precondition_error_status_raises_exception(): + # a failed-precondition error status raises an exception + future = futures.Future() + future_reqs_dict = { + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) + } + st = status_pb2.Status() + st.code = code_pb2.Code.FAILED_PRECONDITION + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + st, future_reqs_dict, None + ) + assert requests_completed[0].ack_id == "ackid1" + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: + future.result() + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.FAILED_PRECONDITION + assert exc_info.value.info == None + assert not requests_to_retry + + +def test_process_futures_other_error_status_raises_exception(): + # an unrecognized error status raises an exception + future = futures.Future() + future_reqs_dict = { + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) + } + st = status_pb2.Status() + st.code = code_pb2.Code.OUT_OF_RANGE + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + st, future_reqs_dict, None + ) + assert requests_completed[0].ack_id == "ackid1" + with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: + future.result() + assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.OTHER + assert not requests_to_retry + + def test_process_futures_mixed_success_and_failure_acks(): # mixed success and failure (acks) future1 = futures.Future() From 97fc72c4ee5ec7956373ec99956971e7249895ba Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 15:03:19 -0500 Subject: [PATCH 21/43] improve coverage for streaming_pull_manager --- noxfile.py | 3 ++- .../subscriber/test_streaming_pull_manager.py | 17 +++++++++++++++++ 2 files changed, 19 insertions(+), 1 deletion(-) diff --git a/noxfile.py b/noxfile.py index d1772f18c..0e3814d59 100644 --- a/noxfile.py +++ b/noxfile.py @@ -159,6 +159,7 @@ def default(session): "--cov-config=.coveragerc", "--cov-report=", "--cov-fail-under=0", + "-s", os.path.join("tests", "unit"), *session.posargs, ) @@ -230,7 +231,7 @@ def cover(session): """ session.install("coverage", "pytest-cov") # Tip: The "-i" flag lets you ignore errors with specific files. - session.run("coverage", "report", "--show-missing", "--fail-under=100") + session.run("coverage", "report", "-i", "--show-missing", "--fail-under=100") session.run("coverage", "erase") diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 647540450..24985ae93 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1513,6 +1513,23 @@ def test_get_ack_errors_no_error_details(from_call): assert not streaming_pull_manager._get_ack_errors(exception) +@mock.patch("grpc_status.rpc_status.from_call") +def test_get_ack_errors_detail_not_error_info(from_call): + st = status_pb2.Status() + st.code = code_pb2.Code.INTERNAL + st.message = "qmsg" + # pack a dummy status instead of an ErrorInfo + dummy_status = status_pb2.Status() + st.details.add().Pack(dummy_status ) + mock_gprc_call = mock.Mock(spec=grpc.Call) + exception = exceptions.InternalServerError( + "msg", errors=(), response=mock_gprc_call + ) + from_call.side_effect = None + from_call.return_value = st + assert not streaming_pull_manager._get_ack_errors(exception) + + @mock.patch("grpc_status.rpc_status.from_call") def test_get_ack_errors_happy_case(from_call): st = status_pb2.Status() From 1220d0f8faf615b50dd2699e6dffab98e63cb8c9 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 15:26:46 -0500 Subject: [PATCH 22/43] Improve code coverage --- google/cloud/pubsub_v1/subscriber/futures.py | 18 +++++---- .../subscriber/test_futures_subscriber.py | 27 ++++++++++++++ .../unit/pubsub_v1/subscriber/test_message.py | 37 +++++++++++++++++++ 3 files changed, 74 insertions(+), 8 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/futures.py b/google/cloud/pubsub_v1/subscriber/futures.py index 71cef2d57..940b84b76 100644 --- a/google/cloud/pubsub_v1/subscriber/futures.py +++ b/google/cloud/pubsub_v1/subscriber/futures.py @@ -19,6 +19,10 @@ from typing import Union from google.cloud.pubsub_v1 import futures +from google.cloud.pubsub_v1.subscriber.exceptions import ( + AcknowledgeError, + AcknowledgeStatus, +) if typing.TYPE_CHECKING: # pragma: NO COVER @@ -84,8 +88,7 @@ def cancelled(self) -> bool: class Future(futures.Future): - # TODO: update docs as necessary - """This future object for subscribe-side calls. + """This future object is for subscribe-side calls. Calling :meth:`result` will resolve the future by returning the message ID, unless an error occurs. @@ -105,9 +108,8 @@ def cancelled(self) -> bool: """ return False - # TODO modify return type annotation - def result(self, timeout: Union[int, float] = None) -> str: - """Return the message ID or raise an exception. + def result(self, timeout: Union[int, float] = None) -> AcknowledgeStatus: + """Return a success code or raise an exception. This blocks until the operation completes successfully and returns the error code unless an exception is raised. @@ -117,11 +119,11 @@ def result(self, timeout: Union[int, float] = None) -> str: times out and raises TimeoutError. Returns: - The message ID. + AcknowledgeStatus.SUCCESS if the operation succeeded. Raises: concurrent.futures.TimeoutError: If the request times out. - Exception: For undefined exceptions in the underlying - call execution. + AcknowledgeError: If the operation did not succeed for another + reason. """ return super().result(timeout=timeout) diff --git a/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py b/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py index 5411674c0..9bfe817cd 100644 --- a/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py +++ b/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py @@ -19,6 +19,10 @@ from google.cloud.pubsub_v1.subscriber import futures from google.cloud.pubsub_v1.subscriber._protocol import streaming_pull_manager +from google.cloud.pubsub_v1.subscriber.exceptions import ( + AcknowledgeError, + AcknowledgeStatus, +) class TestStreamingPullFuture(object): @@ -76,3 +80,26 @@ def test_cancel(self): manager.close.assert_called_once() assert future.cancelled() + + +class TestFuture(object): + def test_cancel(self): + future = futures.Future() + assert future.cancel() is False + + def test_cancelled(self): + future = futures.Future() + assert future.cancelled() is False + + def test_result_on_success(self): + future = futures.Future() + future.set_result(AcknowledgeStatus.SUCCESS) + assert future.result() == AcknowledgeStatus.SUCCESS + + def test_result_on_failure(self): + future = futures.Future() + future.set_exception(AcknowledgeError(AcknowledgeStatus.PERMISSION_DENIED, "Something bad happened.")) + with pytest.raises(AcknowledgeError) as e: + future.result() + assert e.error_code == AcknowledgeStatus.PERMISSION_DENIED + assert e.info == "Something bad happened." diff --git a/tests/unit/pubsub_v1/subscriber/test_message.py b/tests/unit/pubsub_v1/subscriber/test_message.py index 3e79f2f20..744a5e9c2 100644 --- a/tests/unit/pubsub_v1/subscriber/test_message.py +++ b/tests/unit/pubsub_v1/subscriber/test_message.py @@ -133,6 +133,22 @@ def test_ack(): check_call_types(put, requests.AckRequest) +def test_ack_with_response(): + msg = create_message(b"foo", ack_id="bogus_ack_id") + with mock.patch.object(msg._request_queue, "put") as put: + future = msg.ack_with_response() + put.assert_called_once_with( + requests.AckRequest( + ack_id="bogus_ack_id", + byte_size=30, + time_to_ack=mock.ANY, + ordering_key="", + future=future, + ) + ) + check_call_types(put, requests.AckRequest) + + def test_drop(): msg = create_message(b"foo", ack_id="bogus_ack_id") with mock.patch.object(msg._request_queue, "put") as put: @@ -153,6 +169,16 @@ def test_modify_ack_deadline(): check_call_types(put, requests.ModAckRequest) +def test_modify_ack_deadline_with_response(): + msg = create_message(b"foo", ack_id="bogus_ack_id") + with mock.patch.object(msg._request_queue, "put") as put: + future = msg.modify_ack_deadline_with_response(60) + put.assert_called_once_with( + requests.ModAckRequest(ack_id="bogus_ack_id", seconds=60, future=future) + ) + check_call_types(put, requests.ModAckRequest) + + def test_nack(): msg = create_message(b"foo", ack_id="bogus_ack_id") with mock.patch.object(msg._request_queue, "put") as put: @@ -165,6 +191,17 @@ def test_nack(): check_call_types(put, requests.NackRequest) +def test_nack_with_response(): + msg = create_message(b"foo", ack_id="bogus_ack_id") + with mock.patch.object(msg._request_queue, "put") as put: + future = msg.nack_with_response() + put.assert_called_once_with( + requests.NackRequest( + ack_id="bogus_ack_id", byte_size=30, ordering_key="", future=future + ) + ) + check_call_types(put, requests.NackRequest) + def test_repr(): data = b"foo" ordering_key = "ord_key" From 57235b9e862156b2fc68b8fb71ede1db8b20583b Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 15:29:03 -0500 Subject: [PATCH 23/43] Reformat files --- .../pubsub_v1/subscriber/test_futures_subscriber.py | 6 +++++- tests/unit/pubsub_v1/subscriber/test_message.py | 1 + .../subscriber/test_streaming_pull_manager.py | 12 +++++++++--- 3 files changed, 15 insertions(+), 4 deletions(-) diff --git a/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py b/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py index 9bfe817cd..6ed8a9d7e 100644 --- a/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py +++ b/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py @@ -98,7 +98,11 @@ def test_result_on_success(self): def test_result_on_failure(self): future = futures.Future() - future.set_exception(AcknowledgeError(AcknowledgeStatus.PERMISSION_DENIED, "Something bad happened.")) + future.set_exception( + AcknowledgeError( + AcknowledgeStatus.PERMISSION_DENIED, "Something bad happened." + ) + ) with pytest.raises(AcknowledgeError) as e: future.result() assert e.error_code == AcknowledgeStatus.PERMISSION_DENIED diff --git a/tests/unit/pubsub_v1/subscriber/test_message.py b/tests/unit/pubsub_v1/subscriber/test_message.py index 744a5e9c2..e8e51e822 100644 --- a/tests/unit/pubsub_v1/subscriber/test_message.py +++ b/tests/unit/pubsub_v1/subscriber/test_message.py @@ -202,6 +202,7 @@ def test_nack_with_response(): ) check_call_types(put, requests.NackRequest) + def test_repr(): data = b"foo" ordering_key = "ord_key" diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 24985ae93..0ab14a035 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1520,7 +1520,7 @@ def test_get_ack_errors_detail_not_error_info(from_call): st.message = "qmsg" # pack a dummy status instead of an ErrorInfo dummy_status = status_pb2.Status() - st.details.add().Pack(dummy_status ) + st.details.add().Pack(dummy_status) mock_gprc_call = mock.Mock(spec=grpc.Call) exception = exceptions.InternalServerError( "msg", errors=(), response=mock_gprc_call @@ -1664,7 +1664,10 @@ def test_process_futures_permission_denied_error_status_raises_exception(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.PERMISSION_DENIED + assert ( + exc_info.value.error_code + == subscriber_exceptions.AcknowledgeStatus.PERMISSION_DENIED + ) assert exc_info.value.info == None assert not requests_to_retry @@ -1685,7 +1688,10 @@ def test_process_futures_failed_precondition_error_status_raises_exception(): assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: future.result() - assert exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.FAILED_PRECONDITION + assert ( + exc_info.value.error_code + == subscriber_exceptions.AcknowledgeStatus.FAILED_PRECONDITION + ) assert exc_info.value.info == None assert not requests_to_retry From 10f5a93903f0c15c46fe61ad7bcea149122e89be Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 15:37:17 -0500 Subject: [PATCH 24/43] More fixes --- google/cloud/pubsub_v1/subscriber/futures.py | 6 +----- .../pubsub_v1/subscriber/test_streaming_pull_manager.py | 4 ++-- 2 files changed, 3 insertions(+), 7 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/futures.py b/google/cloud/pubsub_v1/subscriber/futures.py index 940b84b76..f043b7eb5 100644 --- a/google/cloud/pubsub_v1/subscriber/futures.py +++ b/google/cloud/pubsub_v1/subscriber/futures.py @@ -19,11 +19,7 @@ from typing import Union from google.cloud.pubsub_v1 import futures -from google.cloud.pubsub_v1.subscriber.exceptions import ( - AcknowledgeError, - AcknowledgeStatus, -) - +from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeStatus if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager import ( diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 0ab14a035..423dfc90a 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1668,7 +1668,7 @@ def test_process_futures_permission_denied_error_status_raises_exception(): exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.PERMISSION_DENIED ) - assert exc_info.value.info == None + assert exc_info.value.info is None assert not requests_to_retry @@ -1692,7 +1692,7 @@ def test_process_futures_failed_precondition_error_status_raises_exception(): exc_info.value.error_code == subscriber_exceptions.AcknowledgeStatus.FAILED_PRECONDITION ) - assert exc_info.value.info == None + assert exc_info.value.info is None assert not requests_to_retry From cdb63400e94fc24c21c2385e1198aa262df81257 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 16:13:40 -0500 Subject: [PATCH 25/43] Improve coverage --- .../subscriber/_protocol/streaming_pull_manager.py | 11 +++++------ noxfile.py | 3 +-- .../pubsub_v1/subscriber/test_futures_subscriber.py | 4 ++-- 3 files changed, 8 insertions(+), 10 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 3c3859869..e778db6c2 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -141,12 +141,11 @@ def _get_ack_errors( _LOGGER.debug("Unable to get status of errored RPC.") return None for detail in status.details: - if detail.Is(ErrorInfo.DESCRIPTOR): - info = ErrorInfo() - if not detail.Unpack(info): - _LOGGER.debug("Unable to unpack ErrorInfo.") - return None - return info.metadata + info = ErrorInfo() + if not (detail.Is(ErrorInfo.DESCRIPTOR) and detail.Unpack(info)): + _LOGGER.debug("Unable to unpack ErrorInfo.") + return None + return info.metadata return None diff --git a/noxfile.py b/noxfile.py index 0e3814d59..d1772f18c 100644 --- a/noxfile.py +++ b/noxfile.py @@ -159,7 +159,6 @@ def default(session): "--cov-config=.coveragerc", "--cov-report=", "--cov-fail-under=0", - "-s", os.path.join("tests", "unit"), *session.posargs, ) @@ -231,7 +230,7 @@ def cover(session): """ session.install("coverage", "pytest-cov") # Tip: The "-i" flag lets you ignore errors with specific files. - session.run("coverage", "report", "-i", "--show-missing", "--fail-under=100") + session.run("coverage", "report", "--show-missing", "--fail-under=100") session.run("coverage", "erase") diff --git a/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py b/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py index 6ed8a9d7e..9f71109e7 100644 --- a/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py +++ b/tests/unit/pubsub_v1/subscriber/test_futures_subscriber.py @@ -105,5 +105,5 @@ def test_result_on_failure(self): ) with pytest.raises(AcknowledgeError) as e: future.result() - assert e.error_code == AcknowledgeStatus.PERMISSION_DENIED - assert e.info == "Something bad happened." + assert e.value.error_code == AcknowledgeStatus.PERMISSION_DENIED + assert e.value.info == "Something bad happened." From 03c8b546f9516a547ef7603bec278e3d2bd73a31 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 16:41:49 -0500 Subject: [PATCH 26/43] Improve coverage --- noxfile.py | 3 +- .../subscriber/test_streaming_pull_manager.py | 30 +++++++++++++++++++ 2 files changed, 32 insertions(+), 1 deletion(-) diff --git a/noxfile.py b/noxfile.py index d1772f18c..0e3814d59 100644 --- a/noxfile.py +++ b/noxfile.py @@ -159,6 +159,7 @@ def default(session): "--cov-config=.coveragerc", "--cov-report=", "--cov-fail-under=0", + "-s", os.path.join("tests", "unit"), *session.posargs, ) @@ -230,7 +231,7 @@ def cover(session): """ session.install("coverage", "pytest-cov") # Tip: The "-i" flag lets you ignore errors with specific files. - session.run("coverage", "report", "--show-missing", "--fail-under=100") + session.run("coverage", "report", "-i", "--show-missing", "--fail-under=100") session.run("coverage", "erase") diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 423dfc90a..74372e6ad 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1375,6 +1375,36 @@ def test__on_response_disable_exactly_once(): assert deadline == histogram.MIN_ACK_DEADLINE +def test__on_response_exactly_once_immediate_modacks_fail(): + manager, _, dispatcher, leaser, _, scheduler = make_running_manager() + manager._callback = mock.sentinel.callback + def complete_futures_with_error(*args, **kwargs): + modack_requests = args[0] + for req in modack_requests: + req.future.set_exception(subscriber_exceptions.AcknowledgeError(subscriber_exceptions.AcknowledgeStatus.SUCCESS, None)) + dispatcher.modify_ack_deadline.side_effect = complete_futures_with_error + + # Set up the messages. + response = gapic_types.StreamingPullResponse( + received_messages=[ + gapic_types.ReceivedMessage( + ack_id="fack", + message=gapic_types.PubsubMessage(data=b"foo", message_id="1"), + ) + ], + subscription_properties=gapic_types.StreamingPullResponse.SubscriptionProperties( + exactly_once_delivery_enabled=True + ), + ) + + # adjust message bookkeeping in leaser + fake_leaser_add(leaser, init_msg_count=0, assumed_msg_size=42) + + # exactly_once should be enabled + manager._on_response(response) + # exceptions are logged, but otherwise no effect + + def test__should_recover_true(): manager = make_manager() From 8099fdefc033f8afc5178615b65c033abd6762c2 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Wed, 23 Feb 2022 16:48:54 -0500 Subject: [PATCH 27/43] lint --- .../pubsub_v1/subscriber/test_streaming_pull_manager.py | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 74372e6ad..2776d357c 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1378,10 +1378,16 @@ def test__on_response_disable_exactly_once(): def test__on_response_exactly_once_immediate_modacks_fail(): manager, _, dispatcher, leaser, _, scheduler = make_running_manager() manager._callback = mock.sentinel.callback + def complete_futures_with_error(*args, **kwargs): modack_requests = args[0] for req in modack_requests: - req.future.set_exception(subscriber_exceptions.AcknowledgeError(subscriber_exceptions.AcknowledgeStatus.SUCCESS, None)) + req.future.set_exception( + subscriber_exceptions.AcknowledgeError( + subscriber_exceptions.AcknowledgeStatus.SUCCESS, None + ) + ) + dispatcher.modify_ack_deadline.side_effect = complete_futures_with_error # Set up the messages. From 7edee1dc02f9f4abbc974d9b8d3fc1376178fe1a Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Thu, 24 Feb 2022 14:55:59 -0500 Subject: [PATCH 28/43] Retry on a new thread to avoid blocking the one dispatcher thread. --- .../subscriber/_protocol/dispatcher.py | 120 +++++++++++------- .../pubsub_v1/subscriber/test_dispatcher.py | 60 ++++++++- 2 files changed, 129 insertions(+), 51 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 806a8a28a..1d3b637d3 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -15,6 +15,7 @@ from __future__ import absolute_import from __future__ import division +import functools import itertools import logging import math @@ -195,32 +196,51 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: # Remove the completed messages from lease management. self.drop(requests_completed) - # retry acks - retry_delay_gen = exponential_sleep_generator( - initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - ) - while requests_to_retry: - time_to_wait = next(retry_delay_gen) - _LOGGER.debug( - "Retrying {len(requests_to_retry)} ack(s) after delay of " - + str(time_to_wait) - + " seconds" - ) - time.sleep(time_to_wait) - - future_reqs_dict = { - req.ack_id: req for req in requests_to_retry if req.future - } - requests_completed, requests_to_retry = self._manager.send_unary_ack( - ack_ids=[req.ack_id for req in requests_to_retry], - future_reqs_dict=future_reqs_dict, + # Retry on a separate thread so the dispatcher thread isn't blocked + # by sleeps. + if requests_to_retry: + self._start_retry_thread( + "Thread-RetryAcks", + functools.partial(self._retry_acks, requests_to_retry), ) - assert ( - len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE - ), "Too many requests to be retried." - # Remove the completed messages from lease management. - self.drop(requests_completed) + + def _start_retry_thread(self, thread_name, thread_target): + # note: if the thread is *not* a daemon, a memory leak exists due to a cpython issue. + # https://github.com/googleapis/python-pubsub/issues/395#issuecomment-829910303 + # https://github.com/googleapis/python-pubsub/issues/395#issuecomment-830092418 + retry_thread = threading.Thread( + name=thread_name, target=thread_target, daemon=True, + ) + # The thread finishes when the requests succeed or eventually fail with + # a back-end timeout error or other permanent failure. + retry_thread.start() + + def _retry_acks(self, requests_to_retry): + retry_delay_gen = exponential_sleep_generator( + initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + ) + while requests_to_retry: + time_to_wait = next(retry_delay_gen) + _LOGGER.debug( + "Retrying {len(requests_to_retry)} ack(s) after delay of " + + str(time_to_wait) + + " seconds" + ) + time.sleep(time_to_wait) + + future_reqs_dict = { + req.ack_id: req for req in requests_to_retry if req.future + } + requests_completed, requests_to_retry = self._manager.send_unary_ack( + ack_ids=[req.ack_id for req in requests_to_retry], + future_reqs_dict=future_reqs_dict, + ) + assert ( + len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE + ), "Too many requests to be retried." + # Remove the completed messages from lease management. + self.drop(requests_completed) def drop( self, @@ -282,29 +302,37 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE ), "Too many requests to be retried." - # retry modacks - retry_delay_gen = exponential_sleep_generator( - initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - ) - while requests_to_retry: - time_to_wait = next(retry_delay_gen) - _LOGGER.debug( - "Retrying {len(requests_to_retry)} modack(s) after delay of " - + str(time_to_wait) - + " seconds" - ) - time.sleep(time_to_wait) - - future_reqs_dict = { - req.ack_id: req for req in requests_to_retry if req.future - } - requests_completed, requests_to_retry = self._manager.send_unary_modack( - modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], - modify_deadline_seconds=[req.seconds for req in requests_to_retry], - future_reqs_dict=future_reqs_dict, + # Retry on a separate thread so the dispatcher thread isn't blocked + # by sleeps. + if requests_to_retry: + self._start_retry_thread( + "Thread-RetryModAcks", + functools.partial(self._retry_modacks, requests_to_retry), ) + def _retry_modacks(self, requests_to_retry): + retry_delay_gen = exponential_sleep_generator( + initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + ) + while requests_to_retry: + time_to_wait = next(retry_delay_gen) + _LOGGER.debug( + "Retrying {len(requests_to_retry)} modack(s) after delay of " + + str(time_to_wait) + + " seconds" + ) + time.sleep(time_to_wait) + + future_reqs_dict = { + req.ack_id: req for req in requests_to_retry if req.future + } + requests_completed, requests_to_retry = self._manager.send_unary_modack( + modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], + modify_deadline_seconds=[req.seconds for req in requests_to_retry], + future_reqs_dict=future_reqs_dict, + ) + def nack(self, items: Sequence[requests.NackRequest]) -> None: """Explicitly deny receipt of messages. diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index edad3f4e1..438921a62 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -173,7 +173,7 @@ def test_ack_splitting_large_payload(): assert sent_ack_ids.most_common(1)[0][1] == 1 # each message ACK-ed exactly once -def test_ack_retry_failed_exactly_once_acks(): +def test_retry_acks_in_new_thread(): manager = mock.create_autospec( streaming_pull_manager.StreamingPullManager, instance=True ) @@ -189,10 +189,39 @@ def test_ack_retry_failed_exactly_once_acks(): future=f, ) ] - # first and second calls fail, third one succeeds + # failure triggers creation of new retry thread + manager.send_unary_ack.side_effect = [([], items)] + with mock.patch("time.sleep", return_value=None): + with mock.patch.object(threading, "Thread", autospec=True) as Thread: + dispatcher_.ack(items) + + assert len(Thread.mock_calls) == 2 + ctor_call = Thread.mock_calls[0] + assert ctor_call.kwargs["name"] == "Thread-RetryAcks" + assert ctor_call.kwargs["target"].args[0] == items + assert ctor_call.kwargs["daemon"] + + +def test_retry_acks(): + manager = mock.create_autospec( + streaming_pull_manager.StreamingPullManager, instance=True + ) + dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) + + f = futures.Future() + items = [ + requests.AckRequest( + ack_id="ack_id_string", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=f, + ) + ] + # first and second `send_unary_ack` calls fail, third one succeeds manager.send_unary_ack.side_effect = [([], items), ([], items), (items, [])] with mock.patch("time.sleep", return_value=None): - dispatcher_.ack(items) + dispatcher_._retry_acks(items) manager.send_unary_ack.assert_has_calls( [ @@ -209,7 +238,28 @@ def test_ack_retry_failed_exactly_once_acks(): ) -def test_modack_retry_failed_exactly_once_acks(): +def test_retry_modacks_in_new_thread(): + manager = mock.create_autospec( + streaming_pull_manager.StreamingPullManager, instance=True + ) + dispatcher_ = dispatcher.Dispatcher(manager, mock.sentinel.queue) + + f = futures.Future() + items = [requests.ModAckRequest(ack_id="ack_id_string", seconds=20, future=f,)] + # failure triggers creation of new retry thread + manager.send_unary_modack.side_effect = [([], items)] + with mock.patch("time.sleep", return_value=None): + with mock.patch.object(threading, "Thread", autospec=True) as Thread: + dispatcher_.modify_ack_deadline(items) + + assert len(Thread.mock_calls) == 2 + ctor_call = Thread.mock_calls[0] + assert ctor_call.kwargs["name"] == "Thread-RetryModAcks" + assert ctor_call.kwargs["target"].args[0] == items + assert ctor_call.kwargs["daemon"] + + +def test_retry_modacks(): manager = mock.create_autospec( streaming_pull_manager.StreamingPullManager, instance=True ) @@ -220,7 +270,7 @@ def test_modack_retry_failed_exactly_once_acks(): # first and second calls fail, third one succeeds manager.send_unary_modack.side_effect = [([], items), ([], items), (items, [])] with mock.patch("time.sleep", return_value=None): - dispatcher_.modify_ack_deadline(items) + dispatcher_._retry_modacks(items) manager.send_unary_modack.assert_has_calls( [ From 6fe7bf855a802e22d181929f76011f42e1dfc01d Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Thu, 24 Feb 2022 15:12:45 -0500 Subject: [PATCH 29/43] Remove sample - will be pulled into separate PR. --- samples/snippets/subscriber.py | 51 ---------------------------------- 1 file changed, 51 deletions(-) diff --git a/samples/snippets/subscriber.py b/samples/snippets/subscriber.py index b88ef8643..7bc124ca8 100644 --- a/samples/snippets/subscriber.py +++ b/samples/snippets/subscriber.py @@ -580,57 +580,6 @@ def callback(message: pubsub_v1.subscriber.message.Message) -> None: # [END pubsub_subscriber_blocking_shutdown] -def receive_messages_with_exactly_once_subscribe( - project_id: str, subscription_id: str, timeout: Optional[float] = None -) -> None: - """Receives messages from a pull subscription with exactly-once delivery enabled.""" - # [START pubsub_subscriber_async_pull] - # [START pubsub_quickstart_subscriber] - from concurrent.futures import TimeoutError - from google.cloud import pubsub_v1 - from google.cloud.pubsub_v1.subscriber import sub_exceptions - - # TODO(developer) - # project_id = "your-project-id" - # subscription_id = "your-subscription-id" - # Number of seconds the subscriber should listen for messages - # timeout = 5.0 - - subscriber = pubsub_v1.SubscriberClient() - # The `subscription_path` method creates a fully qualified identifier - # in the form `projects/{project_id}/subscriptions/{subscription_id}` - subscription_path = subscriber.subscription_path(project_id, subscription_id) - - def callback(message: pubsub_v1.subscriber.message.Message) -> None: - print(f"Received {message}.") - - ack_future = message.ack_with_response() - - try: - # Block on result of acknowledge call. - ack_future.result() - print(f"Ack for message {message.message_id} successful.") - except sub_exceptions.AcknowledgeError as e: - print( - f"Ack for message {message.message_id} failed with error: {e.error_code}" - ) - - streaming_pull_future = subscriber.subscribe(subscription_path, callback=callback) - print(f"Listening for messages on {subscription_path}..\n") - - # Wrap subscriber in a 'with' block to automatically call close() when done. - with subscriber: - try: - # When `timeout` is not set, result() will block indefinitely, - # unless an exception is encountered first. - streaming_pull_future.result(timeout=timeout) - except TimeoutError: - streaming_pull_future.cancel() # Trigger the shutdown. - streaming_pull_future.result() # Block until the shutdown is complete. - # [END pubsub_subscriber_async_pull] - # [END pubsub_quickstart_subscriber] - - def synchronous_pull(project_id: str, subscription_id: str) -> None: """Pulling messages synchronously.""" # [START pubsub_subscriber_sync_pull] From 1d209c9750723067234508ead518caa62b05c4cb Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Thu, 24 Feb 2022 16:11:07 -0500 Subject: [PATCH 30/43] Fix type checking errors. --- .../subscriber/_protocol/streaming_pull_manager.py | 11 ++++++----- google/cloud/pubsub_v1/subscriber/exceptions.py | 4 ++-- 2 files changed, 8 insertions(+), 7 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index e778db6c2..1b0e3201c 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -20,7 +20,7 @@ import logging import threading import typing -from typing import Any, Callable, Iterable, List, Optional, Sequence, Tuple, Union +from typing import Any, Callable, Iterable, List, Optional, Tuple, Union import uuid import grpc # type: ignore @@ -42,9 +42,9 @@ from google.cloud.pubsub_v1.subscriber import futures from google.cloud.pubsub_v1.subscriber.scheduler import ThreadScheduler from google.pubsub_v1 import types as gapic_types -from grpc_status import rpc_status -from google.rpc.error_details_pb2 import ErrorInfo -from google.rpc import code_pb2 +from grpc_status import rpc_status # type: ignore +from google.rpc.error_details_pb2 import ErrorInfo # type: ignore +from google.rpc import code_pb2 # type: ignore if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1 import subscriber @@ -867,7 +867,7 @@ def _get_initial_request( # Return the initial request. return request - def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): + def _send_lease_modacks(self, ack_ids: Iterable[str], ack_deadline: float): exactly_once_enabled = False with self._exactly_once_enabled_lock: exactly_once_enabled = self._exactly_once_enabled @@ -883,6 +883,7 @@ def _send_lease_modacks(self, ack_ids: Sequence[str], ack_deadline: int): for req in items: try: + assert req.future is not None req.future.result() except AcknowledgeError: _LOGGER.warning( diff --git a/google/cloud/pubsub_v1/subscriber/exceptions.py b/google/cloud/pubsub_v1/subscriber/exceptions.py index 9c2f604d9..a5dad31a9 100644 --- a/google/cloud/pubsub_v1/subscriber/exceptions.py +++ b/google/cloud/pubsub_v1/subscriber/exceptions.py @@ -30,12 +30,12 @@ class AcknowledgeStatus(Enum): class AcknowledgeError(GoogleAPICallError): """Error during ack/modack/nack operation on exactly-once-enabled subscription.""" - def __init__(self, error_code: str, info: Optional[str]): + def __init__(self, error_code: AcknowledgeStatus, info: Optional[str]): self.error_code = error_code self.info = info message = None if info: - message = str(self.error_code) + " : " + self.info + message = str(self.error_code) + " : " + str(self.info) else: message = str(self.error_code) super(AcknowledgeError, self).__init__(message) From 3facfa534d25be2f7eb4c3dee3c8364fcc8dfcc9 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 13:52:43 -0500 Subject: [PATCH 31/43] Address some of Mahesh's comments --- .../subscriber/_protocol/dispatcher.py | 12 ++-- .../_protocol/streaming_pull_manager.py | 2 +- google/cloud/pubsub_v1/subscriber/message.py | 60 ++++++++++++++++--- google/cloud/pubsub_v1/types.py | 2 +- 4 files changed, 60 insertions(+), 16 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 1d3b637d3..979ddffe4 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -68,11 +68,11 @@ IDs at a time. """ -_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS = 1 +_MIN_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS = 1 """The time to wait for the first retry of failed acks and modacks when exactly-once is enabled.""" -_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS = 10 * 60 +_MAX_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS = 10 * 60 """The maximum amount of time in seconds to retry failed acks and modacks when exactly-once is enabled.""" @@ -217,8 +217,8 @@ def _start_retry_thread(self, thread_name, thread_target): def _retry_acks(self, requests_to_retry): retry_delay_gen = exponential_sleep_generator( - initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + initial=_MIN_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS, ) while requests_to_retry: time_to_wait = next(retry_delay_gen) @@ -312,8 +312,8 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: def _retry_modacks(self, requests_to_retry): retry_delay_gen = exponential_sleep_generator( - initial=_MIN_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, - maximum=_MAX_EXACTLY_ONCE_ACK_MODACK_RETRY_DURATION_SECS, + initial=_MIN_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS, + maximum=_MAX_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS, ) while requests_to_retry: time_to_wait = next(retry_delay_gen) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 1b0e3201c..2c269ba19 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -887,7 +887,7 @@ def _send_lease_modacks(self, ack_ids: Iterable[str], ack_deadline: float): req.future.result() except AcknowledgeError: _LOGGER.warning( - "AcknowledgeError when modacking a message immediately after receiving it.", + "AcknowledgeError when lease-modacking a message.", exc_info=True, ) else: diff --git a/google/cloud/pubsub_v1/subscriber/message.py b/google/cloud/pubsub_v1/subscriber/message.py index adfcbb84c..3203edd9c 100644 --- a/google/cloud/pubsub_v1/subscriber/message.py +++ b/google/cloud/pubsub_v1/subscriber/message.py @@ -234,7 +234,10 @@ def ack(self) -> None: .. warning:: Acks in Pub/Sub are best effort. You should always ensure that your processing code is idempotent, as you may - receive any given message more than once. + receive any given message more than once. If you need strong + guarantees about acks and re-deliveres, enable exactly-once + delivery on your subscription and use the `ack_with_response` + method instead. """ time_to_ack = math.ceil(time.time() - self._received_timestamp) self._request_queue.put( @@ -256,16 +259,31 @@ def ack_with_response(self) -> "futures.Future": *finished* processing them, so that in the event of a failure, you receive the message again. - .. warning:: - Acks in Pub/Sub are best effort. You should always - ensure that your processing code is idempotent, as you may - receive any given message more than once. + If exactly-once delivery is enabled on the subscription, the + future returned by this method tracks the state of acknowledgement + operation. If the future completes successfully, the message is + guaranteed NOT to be re-delivered. Otherwise, the future will + contain an exception with more details about the failure and the + message may be re-delivered. + + If exactly-once delivery is NOT enabled on the subscription, the + future simply tracks the state of the acknowledgement operation. + Since acks in Cloud Pub/Sub are best effort when exactly-once + delivery is disabled, the message may be re-delivered. Because + re-deliveries are possible, you should ensure that your processing + code is idempotent, as you may receive any given message more than + once. Returns: A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` instance that conforms to Python Standard library's :class:`~concurrent.futures.Future` interface (but not an - instance of that class). + instance of that class). Call `result()` to get the result + of the operation; upon success, a + pubsub_v1.subscriber.exceptions.AcknowledgeStatus.SUCCESS + will be returned and upon an error, an + pubsub_v1.subscriber.exceptions.AcknowledgeError exception + will be thrown. """ future = futures.Future() time_to_ack = math.ceil(time.time() - self._received_timestamp) @@ -330,6 +348,20 @@ def modify_ack_deadline_with_response(self, seconds: int) -> "futures.Future": if you are implementing your own custom subclass of :class:`~.pubsub_v1.subcriber._consumer.Consumer`. + If exactly-once delivery is enabled on the subscription, the + future returned by this method tracks the state of the + modify-ack-deadline operation. If the future completes successfully, + the message is guaranteed NOT to be re-delivered within the new deadline. + Otherwise, the future will contain an exception with more details about + the failure and the message will be redelivered according to its + currently-set ack deadline. + + If exactly-once delivery is NOT enabled on the subscription, the + future simply tracks the state of the modify-ack-deadline operation. + Since modify-ack-deadline operations in Cloud Pub/Sub are best effort + when exactly-once delivery is disabled, the message may be re-delivered + within the set deadline, even if the operation was successful. + Args: seconds: The number of seconds to set the lease deadline to. This should be @@ -339,7 +371,13 @@ def modify_ack_deadline_with_response(self, seconds: int) -> "futures.Future": A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` instance that conforms to Python Standard library's :class:`~concurrent.futures.Future` interface (but not an - instance of that class). + instance of that class). Call `result()` to get the result + of the operation; upon success, a + pubsub_v1.subscriber.exceptions.AcknowledgeStatus.SUCCESS + will be returned and upon an error, an + pubsub_v1.subscriber.exceptions.AcknowledgeError exception + will be thrown. + """ future = futures.Future() self._request_queue.put( @@ -375,7 +413,13 @@ def nack_with_response(self) -> "futures.Future": A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` instance that conforms to Python Standard library's :class:`~concurrent.futures.Future` interface (but not an - instance of that class). + instance of that class). Call `result()` to get the result + of the operation; upon success, a + pubsub_v1.subscriber.exceptions.AcknowledgeStatus.SUCCESS + will be returned and upon an error, an + pubsub_v1.subscriber.exceptions.AcknowledgeError exception + will be thrown. + """ future = futures.Future() self._request_queue.put( diff --git a/google/cloud/pubsub_v1/types.py b/google/cloud/pubsub_v1/types.py index 5c017da27..109d4aadc 100644 --- a/google/cloud/pubsub_v1/types.py +++ b/google/cloud/pubsub_v1/types.py @@ -166,7 +166,7 @@ class FlowControl(NamedTuple): ( "The min amount of time in seconds for a single lease extension attempt. " "Must be between 10 and 600 (inclusive). Ignored by default, but set to " - "60 seconds if the subscription has exactly-once enabled." + "60 seconds if the subscription has exactly-once delivery enabled." ) max_duration_per_lease_extension: float = 0 # disabled by default From c186713c8d350cfebc974ebda76f0b2b113c5b42 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 15:01:30 -0500 Subject: [PATCH 32/43] Return AcknowledgeStatus.SUCCESS for _with_response methods if exactly-once delivery is not enabled. --- .../_protocol/streaming_pull_manager.py | 6 ++ google/cloud/pubsub_v1/subscriber/message.py | 51 +++++++++++++-- .../unit/pubsub_v1/subscriber/test_message.py | 64 +++++++++++++++++-- .../subscriber/test_messages_on_hold.py | 8 ++- .../subscriber/test_streaming_pull_manager.py | 2 +- 5 files changed, 118 insertions(+), 13 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 2c269ba19..d79773037 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -898,6 +898,11 @@ def _send_lease_modacks(self, ack_ids: Iterable[str], ack_deadline: float): assert self._dispatcher is not None self._dispatcher.modify_ack_deadline(items) + def _exactly_once_delivery_enabled(self) -> bool: + """Whether exactly-once delivery is enabled for the subscription.""" + with self._exactly_once_enabled_lock: + return self._exactly_once_enabled + def _on_response(self, response: gapic_types.StreamingPullResponse) -> None: """Process all received Pub/Sub messages. @@ -957,6 +962,7 @@ def _on_response(self, response: gapic_types.StreamingPullResponse) -> None: received_message.ack_id, received_message.delivery_attempt, self._scheduler.queue, + self._exactly_once_delivery_enabled, ) self._messages_on_hold.put(message) self._on_hold_bytes += message.size diff --git a/google/cloud/pubsub_v1/subscriber/message.py b/google/cloud/pubsub_v1/subscriber/message.py index 3203edd9c..3be7c9464 100644 --- a/google/cloud/pubsub_v1/subscriber/message.py +++ b/google/cloud/pubsub_v1/subscriber/message.py @@ -19,10 +19,12 @@ import math import time import typing -from typing import Optional +from typing import Optional, Callable from google.cloud.pubsub_v1.subscriber._protocol import requests from google.cloud.pubsub_v1.subscriber import futures +from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeStatus + if typing.TYPE_CHECKING: # pragma: NO COVER import datetime @@ -88,6 +90,7 @@ def __init__( ack_id: str, delivery_attempt: int, request_queue: "queue.Queue", + exactly_once_delivery_enabled_func: Callable[[], bool], ): """Construct the Message. @@ -111,11 +114,14 @@ def __init__( request_queue: A queue provided by the policy that can accept requests; the policy is responsible for handling those requests. + exactly_once_delivery_enabled_func: + A Callable that returns whether exactly-once delivery is currently-enabled. """ self._message = message self._ack_id = ack_id self._delivery_attempt = delivery_attempt if delivery_attempt > 0 else None self._request_queue = request_queue + self._exactly_once_delivery_enabled_func = exactly_once_delivery_enabled_func self.message_id = message.message_id # The instantiation time is the time that this message @@ -267,7 +273,7 @@ def ack_with_response(self) -> "futures.Future": message may be re-delivered. If exactly-once delivery is NOT enabled on the subscription, the - future simply tracks the state of the acknowledgement operation. + future returns immediately with an AcknowledgeStatus.SUCCESS. Since acks in Cloud Pub/Sub are best effort when exactly-once delivery is disabled, the message may be re-delivered. Because re-deliveries are possible, you should ensure that your processing @@ -286,6 +292,11 @@ def ack_with_response(self) -> "futures.Future": will be thrown. """ future = futures.Future() + req_future = None + if self._exactly_once_delivery_enabled_func(): + req_future = future + else: + future.set_result(AcknowledgeStatus.SUCCESS) time_to_ack = math.ceil(time.time() - self._received_timestamp) self._request_queue.put( requests.AckRequest( @@ -293,7 +304,7 @@ def ack_with_response(self) -> "futures.Future": byte_size=self.size, time_to_ack=time_to_ack, ordering_key=self.ordering_key, - future=future, + future=req_future, ) ) return future @@ -357,10 +368,10 @@ def modify_ack_deadline_with_response(self, seconds: int) -> "futures.Future": currently-set ack deadline. If exactly-once delivery is NOT enabled on the subscription, the - future simply tracks the state of the modify-ack-deadline operation. + future returns immediately with an AcknowledgeStatus.SUCCESS. Since modify-ack-deadline operations in Cloud Pub/Sub are best effort when exactly-once delivery is disabled, the message may be re-delivered - within the set deadline, even if the operation was successful. + within the set deadline. Args: seconds: @@ -380,9 +391,18 @@ def modify_ack_deadline_with_response(self, seconds: int) -> "futures.Future": """ future = futures.Future() + req_future = None + if self._exactly_once_delivery_enabled_func(): + req_future = future + else: + future.set_result(AcknowledgeStatus.SUCCESS) + self._request_queue.put( - requests.ModAckRequest(ack_id=self._ack_id, seconds=seconds, future=future) + requests.ModAckRequest( + ack_id=self._ack_id, seconds=seconds, future=req_future + ) ) + return future def nack(self) -> None: @@ -409,6 +429,16 @@ def nack_with_response(self) -> "futures.Future": may take place immediately or after a delay, and may arrive at this subscriber or another. + If exactly-once delivery is enabled on the subscription, the + future returned by this method tracks the state of the + nack operation. If the future completes successfully, + the future's result will be an AcknowledgeStatus.SUCCESS. + Otherwise, the future will contain an exception with more details about + the failure. + + If exactly-once delivery is NOT enabled on the subscription, the + future returns immediately with an AcknowledgeStatus.SUCCESS. + Returns: A :class:`~google.cloud.pubsub_v1.subscriber.futures.Future` instance that conforms to Python Standard library's @@ -422,12 +452,19 @@ def nack_with_response(self) -> "futures.Future": """ future = futures.Future() + req_future = None + if self._exactly_once_delivery_enabled_func(): + req_future = future + else: + future.set_result(AcknowledgeStatus.SUCCESS) + self._request_queue.put( requests.NackRequest( ack_id=self._ack_id, byte_size=self.size, ordering_key=self.ordering_key, - future=future, + future=req_future, ) ) + return future diff --git a/tests/unit/pubsub_v1/subscriber/test_message.py b/tests/unit/pubsub_v1/subscriber/test_message.py index e8e51e822..f5c7bf3c7 100644 --- a/tests/unit/pubsub_v1/subscriber/test_message.py +++ b/tests/unit/pubsub_v1/subscriber/test_message.py @@ -23,6 +23,7 @@ from google.cloud.pubsub_v1.subscriber._protocol import requests from google.protobuf import timestamp_pb2 from google.pubsub_v1 import types as gapic_types +from google.cloud.pubsub_v1.subscriber.exceptions import AcknowledgeStatus RECEIVED = datetime.datetime(2012, 4, 21, 15, 0, tzinfo=datetime.timezone.utc) @@ -32,7 +33,14 @@ PUBLISHED_SECONDS = datetime_helpers.to_milliseconds(PUBLISHED) // 1000 -def create_message(data, ack_id="ACKID", delivery_attempt=0, ordering_key="", **attrs): +def create_message( + data, + ack_id="ACKID", + delivery_attempt=0, + ordering_key="", + exactly_once_delivery_enabled=False, + **attrs +): with mock.patch.object(time, "time") as time_: time_.return_value = RECEIVED_SECONDS gapic_pubsub_message = gapic_types.PubsubMessage( @@ -51,6 +59,7 @@ def create_message(data, ack_id="ACKID", delivery_attempt=0, ordering_key="", ** ack_id=ack_id, delivery_attempt=delivery_attempt, request_queue=queue.Queue(), + exactly_once_delivery_enabled_func=lambda: exactly_once_delivery_enabled, ) return msg @@ -133,8 +142,27 @@ def test_ack(): check_call_types(put, requests.AckRequest) -def test_ack_with_response(): +def test_ack_with_response_exactly_once_delivery_disabled(): msg = create_message(b"foo", ack_id="bogus_ack_id") + with mock.patch.object(msg._request_queue, "put") as put: + future = msg.ack_with_response() + put.assert_called_once_with( + requests.AckRequest( + ack_id="bogus_ack_id", + byte_size=30, + time_to_ack=mock.ANY, + ordering_key="", + future=None, + ) + ) + assert future.result() == AcknowledgeStatus.SUCCESS + check_call_types(put, requests.AckRequest) + + +def test_ack_with_response_exactly_once_delivery_enabled(): + msg = create_message( + b"foo", ack_id="bogus_ack_id", exactly_once_delivery_enabled=True + ) with mock.patch.object(msg._request_queue, "put") as put: future = msg.ack_with_response() put.assert_called_once_with( @@ -169,8 +197,21 @@ def test_modify_ack_deadline(): check_call_types(put, requests.ModAckRequest) -def test_modify_ack_deadline_with_response(): +def test_modify_ack_deadline_with_response_exactly_once_delivery_disabled(): msg = create_message(b"foo", ack_id="bogus_ack_id") + with mock.patch.object(msg._request_queue, "put") as put: + future = msg.modify_ack_deadline_with_response(60) + put.assert_called_once_with( + requests.ModAckRequest(ack_id="bogus_ack_id", seconds=60, future=None) + ) + assert future.result() == AcknowledgeStatus.SUCCESS + check_call_types(put, requests.ModAckRequest) + + +def test_modify_ack_deadline_with_response_exactly_once_delivery_enabled(): + msg = create_message( + b"foo", ack_id="bogus_ack_id", exactly_once_delivery_enabled=True + ) with mock.patch.object(msg._request_queue, "put") as put: future = msg.modify_ack_deadline_with_response(60) put.assert_called_once_with( @@ -191,8 +232,23 @@ def test_nack(): check_call_types(put, requests.NackRequest) -def test_nack_with_response(): +def test_nack_with_response_exactly_once_delivery_disabled(): msg = create_message(b"foo", ack_id="bogus_ack_id") + with mock.patch.object(msg._request_queue, "put") as put: + future = msg.nack_with_response() + put.assert_called_once_with( + requests.NackRequest( + ack_id="bogus_ack_id", byte_size=30, ordering_key="", future=None + ) + ) + assert future.result() == AcknowledgeStatus.SUCCESS + check_call_types(put, requests.NackRequest) + + +def test_nack_with_response_exactly_once_delivery_enabled(): + msg = create_message( + b"foo", ack_id="bogus_ack_id", exactly_once_delivery_enabled=True + ) with mock.patch.object(msg._request_queue, "put") as put: future = msg.nack_with_response() put.assert_called_once_with( diff --git a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py index 797430e07..2f8105dcc 100644 --- a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py +++ b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py @@ -21,7 +21,13 @@ def make_message(ack_id, ordering_key): proto_msg = gapic_types.PubsubMessage(data=b"Q", ordering_key=ordering_key) - return message.Message(proto_msg._pb, ack_id, 0, queue.Queue()) + return message.Message( + proto_msg._pb, + ack_id, + 0, + queue.Queue(), + exactly_once_delivery_enabled_func=lambda: False, + ) def test_init(): diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 2776d357c..74ac3a3d4 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1332,7 +1332,7 @@ def test__on_response_enable_exactly_once(): # exactly_once should be enabled manager._on_response(response) - assert manager._exactly_once_enabled + assert manager._exactly_once_delivery_enabled() # new deadline for exactly_once subscriptions should be used assert manager.ack_deadline == 60 From 8fb9d5669645bfcf465d080475e072270bb9bff1 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 15:08:03 -0500 Subject: [PATCH 33/43] Get coverage to 100% --- tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py index 2f8105dcc..1f93006c3 100644 --- a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py +++ b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py @@ -18,6 +18,9 @@ from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.pubsub_v1 import types as gapic_types +# Using this function instead of a lambda to satisfy the coverage tool +def return_false(): + return False def make_message(ack_id, ordering_key): proto_msg = gapic_types.PubsubMessage(data=b"Q", ordering_key=ordering_key) @@ -26,7 +29,7 @@ def make_message(ack_id, ordering_key): ack_id, 0, queue.Queue(), - exactly_once_delivery_enabled_func=lambda: False, + exactly_once_delivery_enabled_func=return_false, ) From 898715bd44907a75e9f55dcdfbdda10dc4f4be0d Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 15:25:41 -0500 Subject: [PATCH 34/43] Add default value to new Message ctor parameter so PubSubLite code doesn't break. --- google/cloud/pubsub_v1/subscriber/message.py | 4 ++-- tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py | 3 ++- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/message.py b/google/cloud/pubsub_v1/subscriber/message.py index 3be7c9464..5744aa71c 100644 --- a/google/cloud/pubsub_v1/subscriber/message.py +++ b/google/cloud/pubsub_v1/subscriber/message.py @@ -90,7 +90,7 @@ def __init__( ack_id: str, delivery_attempt: int, request_queue: "queue.Queue", - exactly_once_delivery_enabled_func: Callable[[], bool], + exactly_once_delivery_enabled_func: Callable[[], bool] = lambda: False, ): """Construct the Message. @@ -115,7 +115,7 @@ def __init__( A queue provided by the policy that can accept requests; the policy is responsible for handling those requests. exactly_once_delivery_enabled_func: - A Callable that returns whether exactly-once delivery is currently-enabled. + A Callable that returns whether exactly-once delivery is currently-enabled. Defaults to a lambda that always returns False. """ self._message = message self._ack_id = ack_id diff --git a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py index 1f93006c3..bda1e51da 100644 --- a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py +++ b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py @@ -20,7 +20,8 @@ # Using this function instead of a lambda to satisfy the coverage tool def return_false(): - return False + return False + def make_message(ack_id, ordering_key): proto_msg = gapic_types.PubsubMessage(data=b"Q", ordering_key=ordering_key) From 245cdfded925ddf6cba89327617777237bca9c15 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 16:27:43 -0500 Subject: [PATCH 35/43] Complete futures when a permanent RetryError is thrown and the StreamingPull stream is being shutdown. --- .../_protocol/streaming_pull_manager.py | 10 ++++++- .../subscriber/test_streaming_pull_manager.py | 26 ++++++++++++++++--- 2 files changed, 32 insertions(+), 4 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index d79773037..b44b7f39f 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -45,11 +45,11 @@ from grpc_status import rpc_status # type: ignore from google.rpc.error_details_pb2 import ErrorInfo # type: ignore from google.rpc import code_pb2 # type: ignore +from google.rpc import status_pb2 if typing.TYPE_CHECKING: # pragma: NO COVER from google.cloud.pubsub_v1 import subscriber from google.protobuf.internal import containers - from google.rpc import status_pb2 _LOGGER = logging.getLogger(__name__) @@ -575,6 +575,10 @@ def send_unary_ack( error_status = _get_status(exc) ack_errors_dict = _get_ack_errors(exc) except exceptions.RetryError as exc: + status = status_pb2.Status() + status.code = code_pb2.DEADLINE_EXCEEDED + # Makes sure to complete futures so they don't block forever. + _process_futures(status, future_reqs_dict, None) _LOGGER.debug( "RetryError while sending unary RPC. Waiting on a transient " "error resolution for too long, will now trigger shutdown.", @@ -625,6 +629,10 @@ def send_unary_modack( error_status = _get_status(exc) modack_errors_dict = _get_ack_errors(exc) except exceptions.RetryError as exc: + status = status_pb2.Status() + status.code = code_pb2.DEADLINE_EXCEEDED + # Makes sure to complete futures so they don't block forever. + _process_futures(status, future_reqs_dict, None) _LOGGER.debug( "RetryError while sending unary RPC. Waiting on a transient " "error resolution for too long, will now trigger shutdown.", diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 74ac3a3d4..667da1fd1 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -579,11 +579,23 @@ def test_send_unary_ack_retry_error(caplog): ) manager._client.acknowledge.side_effect = error + future = futures.Future() + future_reqs_dict = { + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future + ) + } with pytest.raises(exceptions.RetryError): - manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], future_reqs_dict={}) + manager.send_unary_ack( + ack_ids=["ack_id1", "ack_id2"], future_reqs_dict=future_reqs_dict + ) assert "RetryError while sending unary RPC" in caplog.text assert "signaled streaming pull manager shutdown" in caplog.text + assert isinstance(future.exception(), subscriber_exceptions.AcknowledgeError) + assert ( + future.exception().error_code is subscriber_exceptions.AcknowledgeStatus.OTHER + ) def test_send_unary_modack_retry_error(caplog): @@ -596,15 +608,23 @@ def test_send_unary_modack_retry_error(caplog): ) manager._client.modify_ack_deadline.side_effect = error + future = futures.Future() + future_reqs_dict = { + "ackid1": requests.ModAckRequest(ack_id="ackid1", seconds=60, future=future) + } with pytest.raises(exceptions.RetryError): manager.send_unary_modack( - modify_deadline_ack_ids=["ack_id_string"], + modify_deadline_ack_ids=["ackid1"], modify_deadline_seconds=[0], - future_reqs_dict={}, + future_reqs_dict=future_reqs_dict, ) assert "RetryError while sending unary RPC" in caplog.text assert "signaled streaming pull manager shutdown" in caplog.text + assert isinstance(future.exception(), subscriber_exceptions.AcknowledgeError) + assert ( + future.exception().error_code is subscriber_exceptions.AcknowledgeStatus.OTHER + ) def test_heartbeat(): From b1e5d70100ef51391552093de63be184106d6626 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 16:30:33 -0500 Subject: [PATCH 36/43] Fix lint --- tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py index bda1e51da..9d2f6ea01 100644 --- a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py +++ b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py @@ -18,6 +18,7 @@ from google.cloud.pubsub_v1.subscriber._protocol import messages_on_hold from google.pubsub_v1 import types as gapic_types + # Using this function instead of a lambda to satisfy the coverage tool def return_false(): return False From 377222b1ddf53f7c1df90edce4f967fced07f4dc Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 16:37:13 -0500 Subject: [PATCH 37/43] Fix coverage false positive in test by ignoring it. --- tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py | 7 +------ 1 file changed, 1 insertion(+), 6 deletions(-) diff --git a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py index 9d2f6ea01..0d28ec447 100644 --- a/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py +++ b/tests/unit/pubsub_v1/subscriber/test_messages_on_hold.py @@ -19,11 +19,6 @@ from google.pubsub_v1 import types as gapic_types -# Using this function instead of a lambda to satisfy the coverage tool -def return_false(): - return False - - def make_message(ack_id, ordering_key): proto_msg = gapic_types.PubsubMessage(data=b"Q", ordering_key=ordering_key) return message.Message( @@ -31,7 +26,7 @@ def make_message(ack_id, ordering_key): ack_id, 0, queue.Queue(), - exactly_once_delivery_enabled_func=return_false, + exactly_once_delivery_enabled_func=lambda: False, # pragma: NO COVER ) From a20d48c0b742394afe1bd673fa0a2bf3062c2a69 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 17:12:33 -0500 Subject: [PATCH 38/43] Reword some comments with "exactly-once delivery" --- google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py | 4 ++-- .../pubsub_v1/subscriber/_protocol/streaming_pull_manager.py | 5 +++-- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 979ddffe4..4bbedb2de 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -70,11 +70,11 @@ _MIN_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS = 1 """The time to wait for the first retry of failed acks and modacks when exactly-once -is enabled.""" +delivery is enabled.""" _MAX_EXACTLY_ONCE_DELIVERY_ACK_MODACK_RETRY_DURATION_SECS = 10 * 60 """The maximum amount of time in seconds to retry failed acks and modacks when -exactly-once is enabled.""" +exactly-once delivery is enabled.""" class Dispatcher(object): diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index b44b7f39f..96ee1a0a1 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -385,7 +385,8 @@ def _obtain_ack_deadline(self, maybe_update: bool) -> float: ) self._ack_deadline = max(self._ack_deadline, flow_control_setting) elif self._exactly_once_enabled: - # Higher minimum ack_deadline for exactly_once subscriptions. + # Higher minimum ack_deadline for subscriptions with + # exactly-once delivery enabled. self._ack_deadline = max( self._ack_deadline, _MIN_ACK_DEADLINE_SECS_WHEN_EXACTLY_ONCE_ENABLED ) @@ -652,7 +653,7 @@ def heartbeat(self) -> bool: """Sends a heartbeat request over the streaming pull RPC. The request is empty by default, but may contain the current ack_deadline - if the exactly_once flag has changed. + if the self._exactly_once_enabled flag has changed. Returns: If a heartbeat request has actually been sent. From 3b390b780bbaa4cffdbbd8668105527b4070506d Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 17:22:43 -0500 Subject: [PATCH 39/43] Remove debug print --- tests/unit/pubsub_v1/subscriber/test_dispatcher.py | 1 - 1 file changed, 1 deletion(-) diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index 438921a62..c5faa408b 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -402,7 +402,6 @@ def test_modify_ack_deadline_splitting_large_payload(): for call in calls: modack_ackids = call[1]["modify_deadline_ack_ids"] - print(type(modack_ackids)) assert len(modack_ackids) <= dispatcher._ACK_IDS_BATCH_SIZE sent_ack_ids.update(modack_ackids) From 9fa28c55237c297f7c8a8e2c1ce3210bde1a8036 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Fri, 25 Feb 2022 17:24:35 -0500 Subject: [PATCH 40/43] Fix coverage false positive in test by ignoring it. --- tests/unit/pubsub_v1/subscriber/test_subscriber_client.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/unit/pubsub_v1/subscriber/test_subscriber_client.py b/tests/unit/pubsub_v1/subscriber/test_subscriber_client.py index 1f60b536d..793ceca3c 100644 --- a/tests/unit/pubsub_v1/subscriber/test_subscriber_client.py +++ b/tests/unit/pubsub_v1/subscriber/test_subscriber_client.py @@ -205,7 +205,7 @@ def test_context_manager_raises_if_closed(creds): expetect_msg = r"(?i).*closed.*cannot.*context manager.*" with pytest.raises(RuntimeError, match=expetect_msg): with client: - pass + pass # pragma: NO COVER def test_api_property_deprecated(creds): From c4ba9c7e7a53c7eaadc2bc7a2c0efa6e7a1294b9 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Mon, 28 Feb 2022 17:32:42 -0500 Subject: [PATCH 41/43] Complete all requests, not just ones with futures --- .../subscriber/_protocol/dispatcher.py | 10 ++-------- .../_protocol/streaming_pull_manager.py | 4 +++- noxfile.py | 3 +++ .../pubsub_v1/subscriber/test_dispatcher.py | 12 ++++++++---- .../subscriber/test_streaming_pull_manager.py | 17 ++++++++++++++++- 5 files changed, 32 insertions(+), 14 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 4bbedb2de..00154f8e6 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -186,7 +186,6 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: future_reqs_dict = { req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) - if req.future } requests_completed, requests_to_retry = self._manager.send_unary_ack( ack_ids=list(itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE)), @@ -229,9 +228,7 @@ def _retry_acks(self, requests_to_retry): ) time.sleep(time_to_wait) - future_reqs_dict = { - req.ack_id: req for req in requests_to_retry if req.future - } + future_reqs_dict = {req.ack_id: req for req in requests_to_retry} requests_completed, requests_to_retry = self._manager.send_unary_ack( ack_ids=[req.ack_id for req in requests_to_retry], future_reqs_dict=future_reqs_dict, @@ -286,7 +283,6 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: future_reqs_dict = { req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) - if req.future } # no further work needs to be done for `requests_to_retry` requests_completed, requests_to_retry = self._manager.send_unary_modack( @@ -324,9 +320,7 @@ def _retry_modacks(self, requests_to_retry): ) time.sleep(time_to_wait) - future_reqs_dict = { - req.ack_id: req for req in requests_to_retry if req.future - } + future_reqs_dict = {req.ack_id: req for req in requests_to_retry} requests_completed, requests_to_retry = self._manager.send_unary_modack( modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], modify_deadline_seconds=[req.seconds for req in requests_to_retry], diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 96ee1a0a1..b92696af8 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -188,11 +188,13 @@ def _process_futures( future = future_reqs_dict[ack_id].future future.set_exception(exc) requests_completed.append(future_reqs_dict[ack_id]) - else: + elif future_reqs_dict[ack_id].future: future = future_reqs_dict[ack_id].future # success future.set_result(AcknowledgeStatus.SUCCESS) requests_completed.append(future_reqs_dict[ack_id]) + else: + requests_completed.append(future_reqs_dict[ack_id]) return requests_completed, requests_to_retry diff --git a/noxfile.py b/noxfile.py index 0e3814d59..ba16d5a46 100644 --- a/noxfile.py +++ b/noxfile.py @@ -204,6 +204,9 @@ def system(session): session.install("-e", ".", "-c", constraints_path) # Run py.test against the system tests. + # THe following flags are useful during development: + # "-s" -> show print() statement output + # "-k " -> filter test cases if system_test_exists: session.run( "py.test", diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index c5faa408b..aaedcb6ff 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -105,7 +105,7 @@ def test_ack(): dispatcher_.ack(items) manager.send_unary_ack.assert_called_once_with( - ack_ids=["ack_id_string"], future_reqs_dict={} + ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} ) manager.leaser.remove.assert_called_once_with(items) @@ -132,7 +132,7 @@ def test_ack_no_time(): dispatcher_.ack(items) manager.send_unary_ack.assert_called_once_with( - ack_ids=["ack_id_string"], future_reqs_dict={} + ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} ) manager.ack_histogram.add.assert_not_called() @@ -359,7 +359,11 @@ def test_nack(): manager.send_unary_modack.assert_called_once_with( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0], - future_reqs_dict={}, + future_reqs_dict={ + "ack_id_string": requests.ModAckRequest( + ack_id="ack_id_string", seconds=0, future=None + ) + }, ) @@ -376,7 +380,7 @@ def test_modify_ack_deadline(): manager.send_unary_modack.assert_called_once_with( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[60], - future_reqs_dict={}, + future_reqs_dict={"ack_id_string": items[0]}, ) diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 667da1fd1..6451be035 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -1628,8 +1628,23 @@ def test_process_futures_error_dict_is_none(): assert not requests_to_retry +def test_process_futures_no_errors_has_no_future(): + # no errors so request should be completed, even with no future + future_reqs_dict = { + "ackid1": requests.AckRequest( + ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=None + ) + } + errors_dict = {} + requests_completed, requests_to_retry = streaming_pull_manager._process_futures( + None, future_reqs_dict, errors_dict + ) + assert requests_completed[0].ack_id == "ackid1" + assert not requests_to_retry + + def test_process_futures_no_errors(): - # no errors so request should be completed + # no errors so request and its future should be completed future = futures.Future() future_reqs_dict = { "ackid1": requests.AckRequest( From 36fcab9c2968067f196c258e294c2613b06524aa Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Mon, 28 Feb 2022 17:40:32 -0500 Subject: [PATCH 42/43] Better names to reflect them applying to all reqs not just ones with futures --- .../subscriber/_protocol/dispatcher.py | 16 +-- .../_protocol/streaming_pull_manager.py | 42 +++---- .../pubsub_v1/subscriber/test_dispatcher.py | 20 ++-- .../subscriber/test_streaming_pull_manager.py | 112 +++++++++--------- 4 files changed, 95 insertions(+), 95 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py index 00154f8e6..6ab5165d1 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/dispatcher.py @@ -183,13 +183,13 @@ def ack(self, items: Sequence[requests.AckRequest]) -> None: total_chunks = int(math.ceil(len(items) / _ACK_IDS_BATCH_SIZE)) for _ in range(total_chunks): - future_reqs_dict = { + ack_reqs_dict = { req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) } requests_completed, requests_to_retry = self._manager.send_unary_ack( ack_ids=list(itertools.islice(ack_ids_gen, _ACK_IDS_BATCH_SIZE)), - future_reqs_dict=future_reqs_dict, + ack_reqs_dict=ack_reqs_dict, ) # Remove the completed messages from lease management. @@ -228,10 +228,10 @@ def _retry_acks(self, requests_to_retry): ) time.sleep(time_to_wait) - future_reqs_dict = {req.ack_id: req for req in requests_to_retry} + ack_reqs_dict = {req.ack_id: req for req in requests_to_retry} requests_completed, requests_to_retry = self._manager.send_unary_ack( ack_ids=[req.ack_id for req in requests_to_retry], - future_reqs_dict=future_reqs_dict, + ack_reqs_dict=ack_reqs_dict, ) assert ( len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE @@ -280,7 +280,7 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: total_chunks = int(math.ceil(len(items) / _ACK_IDS_BATCH_SIZE)) for _ in range(total_chunks): - future_reqs_dict = { + ack_reqs_dict = { req.ack_id: req for req in itertools.islice(items_gen, _ACK_IDS_BATCH_SIZE) } @@ -292,7 +292,7 @@ def modify_ack_deadline(self, items: Sequence[requests.ModAckRequest]) -> None: modify_deadline_seconds=list( itertools.islice(deadline_seconds_gen, _ACK_IDS_BATCH_SIZE) ), - future_reqs_dict=future_reqs_dict, + ack_reqs_dict=ack_reqs_dict, ) assert ( len(requests_to_retry) <= _ACK_IDS_BATCH_SIZE @@ -320,11 +320,11 @@ def _retry_modacks(self, requests_to_retry): ) time.sleep(time_to_wait) - future_reqs_dict = {req.ack_id: req for req in requests_to_retry} + ack_reqs_dict = {req.ack_id: req for req in requests_to_retry} requests_completed, requests_to_retry = self._manager.send_unary_modack( modify_deadline_ack_ids=[req.ack_id for req in requests_to_retry], modify_deadline_seconds=[req.seconds for req in requests_to_retry], - future_reqs_dict=future_reqs_dict, + ack_reqs_dict=ack_reqs_dict, ) def nack(self, items: Sequence[requests.NackRequest]) -> None: diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index b92696af8..5971e7988 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -149,33 +149,33 @@ def _get_ack_errors( return None -def _process_futures( +def _process_requests( error_status: Optional["status_pb2.Status"], - future_reqs_dict: "containers.ScalarMap", + ack_reqs_dict: "containers.ScalarMap", errors_dict: Optional["containers.ScalarMap"], ): """Process futures by referring to errors_dict. The errors returned by the server in `errors_dict` are used to complete - the request futures in `future_reqs_dict` (with a success or exception) or + the request futures in `ack_reqs_dict` (with a success or exception) or to return requests for further retries. """ requests_completed = [] requests_to_retry = [] - for ack_id in future_reqs_dict: + for ack_id in ack_reqs_dict: if errors_dict and ack_id in errors_dict: exactly_once_error = errors_dict[ack_id] if exactly_once_error.startswith("TRANSIENT_"): - requests_to_retry.append(future_reqs_dict[ack_id]) + requests_to_retry.append(ack_reqs_dict[ack_id]) else: if exactly_once_error == "PERMANENT_FAILURE_INVALID_ACK_ID": exc = AcknowledgeError(AcknowledgeStatus.INVALID_ACK_ID, info=None) else: exc = AcknowledgeError(AcknowledgeStatus.OTHER, exactly_once_error) - future = future_reqs_dict[ack_id].future + future = ack_reqs_dict[ack_id].future future.set_exception(exc) - requests_completed.append(future_reqs_dict[ack_id]) + requests_completed.append(ack_reqs_dict[ack_id]) elif error_status: # Only permanent errors are expected here b/c retriable errors are # retried at the lower, GRPC level. @@ -185,16 +185,16 @@ def _process_futures( exc = AcknowledgeError(AcknowledgeStatus.FAILED_PRECONDITION, info=None) else: exc = AcknowledgeError(AcknowledgeStatus.OTHER, str(error_status)) - future = future_reqs_dict[ack_id].future + future = ack_reqs_dict[ack_id].future future.set_exception(exc) - requests_completed.append(future_reqs_dict[ack_id]) - elif future_reqs_dict[ack_id].future: - future = future_reqs_dict[ack_id].future + requests_completed.append(ack_reqs_dict[ack_id]) + elif ack_reqs_dict[ack_id].future: + future = ack_reqs_dict[ack_id].future # success future.set_result(AcknowledgeStatus.SUCCESS) - requests_completed.append(future_reqs_dict[ack_id]) + requests_completed.append(ack_reqs_dict[ack_id]) else: - requests_completed.append(future_reqs_dict[ack_id]) + requests_completed.append(ack_reqs_dict[ack_id]) return requests_completed, requests_to_retry @@ -556,7 +556,7 @@ def _schedule_message_on_hold( self._scheduler.schedule(self._callback, msg) def send_unary_ack( - self, ack_ids, future_reqs_dict + self, ack_ids, ack_reqs_dict ) -> Tuple[List[requests.AckRequest], List[requests.AckRequest]]: """Send a request using a separate unary request instead of over the stream. @@ -581,7 +581,7 @@ def send_unary_ack( status = status_pb2.Status() status.code = code_pb2.DEADLINE_EXCEEDED # Makes sure to complete futures so they don't block forever. - _process_futures(status, future_reqs_dict, None) + _process_requests(status, ack_reqs_dict, None) _LOGGER.debug( "RetryError while sending unary RPC. Waiting on a transient " "error resolution for too long, will now trigger shutdown.", @@ -592,13 +592,13 @@ def send_unary_ack( self._on_rpc_done(exc) raise - requests_completed, requests_to_retry = _process_futures( - error_status, future_reqs_dict, ack_errors_dict + requests_completed, requests_to_retry = _process_requests( + error_status, ack_reqs_dict, ack_errors_dict ) return requests_completed, requests_to_retry def send_unary_modack( - self, modify_deadline_ack_ids, modify_deadline_seconds, future_reqs_dict + self, modify_deadline_ack_ids, modify_deadline_seconds, ack_reqs_dict ) -> Tuple[List[requests.ModAckRequest], List[requests.ModAckRequest]]: """Send a request using a separate unary request instead of over the stream. @@ -635,7 +635,7 @@ def send_unary_modack( status = status_pb2.Status() status.code = code_pb2.DEADLINE_EXCEEDED # Makes sure to complete futures so they don't block forever. - _process_futures(status, future_reqs_dict, None) + _process_requests(status, ack_reqs_dict, None) _LOGGER.debug( "RetryError while sending unary RPC. Waiting on a transient " "error resolution for too long, will now trigger shutdown.", @@ -646,8 +646,8 @@ def send_unary_modack( self._on_rpc_done(exc) raise - requests_completed, requests_to_retry = _process_futures( - error_status, future_reqs_dict, modack_errors_dict + requests_completed, requests_to_retry = _process_requests( + error_status, ack_reqs_dict, modack_errors_dict ) return requests_completed, requests_to_retry diff --git a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py index aaedcb6ff..bbc6170e2 100644 --- a/tests/unit/pubsub_v1/subscriber/test_dispatcher.py +++ b/tests/unit/pubsub_v1/subscriber/test_dispatcher.py @@ -105,7 +105,7 @@ def test_ack(): dispatcher_.ack(items) manager.send_unary_ack.assert_called_once_with( - ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ack_ids=["ack_id_string"], ack_reqs_dict={"ack_id_string": items[0]} ) manager.leaser.remove.assert_called_once_with(items) @@ -132,7 +132,7 @@ def test_ack_no_time(): dispatcher_.ack(items) manager.send_unary_ack.assert_called_once_with( - ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ack_ids=["ack_id_string"], ack_reqs_dict={"ack_id_string": items[0]} ) manager.ack_histogram.add.assert_not_called() @@ -226,13 +226,13 @@ def test_retry_acks(): manager.send_unary_ack.assert_has_calls( [ mock.call( - ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ack_ids=["ack_id_string"], ack_reqs_dict={"ack_id_string": items[0]} ), mock.call( - ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ack_ids=["ack_id_string"], ack_reqs_dict={"ack_id_string": items[0]} ), mock.call( - ack_ids=["ack_id_string"], future_reqs_dict={"ack_id_string": items[0]} + ack_ids=["ack_id_string"], ack_reqs_dict={"ack_id_string": items[0]} ), ] ) @@ -277,17 +277,17 @@ def test_retry_modacks(): mock.call( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[20], - future_reqs_dict={"ack_id_string": items[0]}, + ack_reqs_dict={"ack_id_string": items[0]}, ), mock.call( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[20], - future_reqs_dict={"ack_id_string": items[0]}, + ack_reqs_dict={"ack_id_string": items[0]}, ), mock.call( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[20], - future_reqs_dict={"ack_id_string": items[0]}, + ack_reqs_dict={"ack_id_string": items[0]}, ), ] ) @@ -359,7 +359,7 @@ def test_nack(): manager.send_unary_modack.assert_called_once_with( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0], - future_reqs_dict={ + ack_reqs_dict={ "ack_id_string": requests.ModAckRequest( ack_id="ack_id_string", seconds=0, future=None ) @@ -380,7 +380,7 @@ def test_modify_ack_deadline(): manager.send_unary_modack.assert_called_once_with( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[60], - future_reqs_dict={"ack_id_string": items[0]}, + ack_reqs_dict={"ack_id_string": items[0]}, ) diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 6451be035..3d9904ca1 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -506,7 +506,7 @@ def test__maybe_release_messages_negative_on_hold_bytes_warning(caplog): def test_send_unary_ack(): manager = make_manager() - manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], future_reqs_dict={}) + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict={}) manager._client.acknowledge.assert_called_once_with( subscription=manager._subscription, ack_ids=["ack_id1", "ack_id2"] @@ -519,7 +519,7 @@ def test_send_unary_modack(): manager.send_unary_modack( modify_deadline_ack_ids=["ack_id3", "ack_id4", "ack_id5"], modify_deadline_seconds=[10, 20, 20], - future_reqs_dict={}, + ack_reqs_dict={}, ) manager._client.modify_ack_deadline.assert_has_calls( @@ -547,7 +547,7 @@ def test_send_unary_ack_api_call_error(caplog): error = exceptions.GoogleAPICallError("The front fell off") manager._client.acknowledge.side_effect = error - manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], future_reqs_dict={}) + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict={}) assert "The front fell off" in caplog.text @@ -563,7 +563,7 @@ def test_send_unary_modack_api_call_error(caplog): manager.send_unary_modack( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0], - future_reqs_dict={}, + ack_reqs_dict={}, ) assert "The front fell off" in caplog.text @@ -580,14 +580,14 @@ def test_send_unary_ack_retry_error(caplog): manager._client.acknowledge.side_effect = error future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } with pytest.raises(exceptions.RetryError): manager.send_unary_ack( - ack_ids=["ack_id1", "ack_id2"], future_reqs_dict=future_reqs_dict + ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict=ack_reqs_dict ) assert "RetryError while sending unary RPC" in caplog.text @@ -609,14 +609,14 @@ def test_send_unary_modack_retry_error(caplog): manager._client.modify_ack_deadline.side_effect = error future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.ModAckRequest(ack_id="ackid1", seconds=60, future=future) } with pytest.raises(exceptions.RetryError): manager.send_unary_modack( modify_deadline_ack_ids=["ackid1"], modify_deadline_seconds=[0], - future_reqs_dict=future_reqs_dict, + ack_reqs_dict=ack_reqs_dict, ) assert "RetryError while sending unary RPC" in caplog.text @@ -1606,71 +1606,71 @@ def test_get_ack_errors_happy_case(from_call): assert ack_errors["ack_1"] == "error1" -def test_process_futures_no_requests(): +def test_process_requests_no_requests(): # no requests so no items in results lists - future_reqs_dict = {} + ack_reqs_dict = {} errors_dict = {} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert not requests_completed assert not requests_to_retry -def test_process_futures_error_dict_is_none(): +def test_process_requests_error_dict_is_none(): # it's valid to pass in `None` for `errors_dict` - future_reqs_dict = {} + ack_reqs_dict = {} errors_dict = None - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert not requests_completed assert not requests_to_retry -def test_process_futures_no_errors_has_no_future(): +def test_process_requests_no_errors_has_no_future(): # no errors so request should be completed, even with no future - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=None ) } errors_dict = {} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" assert not requests_to_retry -def test_process_futures_no_errors(): +def test_process_requests_no_errors(): # no errors so request and its future should be completed future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } errors_dict = {} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" assert future.result() == subscriber_exceptions.AcknowledgeStatus.SUCCESS assert not requests_to_retry -def test_process_futures_permanent_error_raises_exception(): +def test_process_requests_permanent_error_raises_exception(): # a permanent error raises an exception future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } errors_dict = {"ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID"} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: @@ -1682,34 +1682,34 @@ def test_process_futures_permanent_error_raises_exception(): assert not requests_to_retry -def test_process_futures_transient_error_returns_request(): +def test_process_requests_transient_error_returns_request(): # a transient error returns the request in `requests_to_retry` future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } errors_dict = {"ackid1": "TRANSIENT_FAILURE_INVALID_ACK_ID"} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert not requests_completed assert requests_to_retry[0].ack_id == "ackid1" assert not future.done() -def test_process_futures_unknown_error_raises_exception(): +def test_process_requests_unknown_error_raises_exception(): # an unknown error raises an exception future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } errors_dict = {"ackid1": "unknown_error"} - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: @@ -1719,18 +1719,18 @@ def test_process_futures_unknown_error_raises_exception(): assert not requests_to_retry -def test_process_futures_permission_denied_error_status_raises_exception(): +def test_process_requests_permission_denied_error_status_raises_exception(): # a permission-denied error status raises an exception future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } st = status_pb2.Status() st.code = code_pb2.Code.PERMISSION_DENIED - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - st, future_reqs_dict, None + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + st, ack_reqs_dict, None ) assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: @@ -1743,18 +1743,18 @@ def test_process_futures_permission_denied_error_status_raises_exception(): assert not requests_to_retry -def test_process_futures_failed_precondition_error_status_raises_exception(): +def test_process_requests_failed_precondition_error_status_raises_exception(): # a failed-precondition error status raises an exception future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } st = status_pb2.Status() st.code = code_pb2.Code.FAILED_PRECONDITION - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - st, future_reqs_dict, None + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + st, ack_reqs_dict, None ) assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: @@ -1767,18 +1767,18 @@ def test_process_futures_failed_precondition_error_status_raises_exception(): assert not requests_to_retry -def test_process_futures_other_error_status_raises_exception(): +def test_process_requests_other_error_status_raises_exception(): # an unrecognized error status raises an exception future = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future ) } st = status_pb2.Status() st.code = code_pb2.Code.OUT_OF_RANGE - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - st, future_reqs_dict, None + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + st, ack_reqs_dict, None ) assert requests_completed[0].ack_id == "ackid1" with pytest.raises(subscriber_exceptions.AcknowledgeError) as exc_info: @@ -1787,12 +1787,12 @@ def test_process_futures_other_error_status_raises_exception(): assert not requests_to_retry -def test_process_futures_mixed_success_and_failure_acks(): +def test_process_requests_mixed_success_and_failure_acks(): # mixed success and failure (acks) future1 = futures.Future() future2 = futures.Future() future3 = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.AckRequest( ack_id="ackid1", byte_size=0, @@ -1819,8 +1819,8 @@ def test_process_futures_mixed_success_and_failure_acks(): "ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID", "ackid2": "TRANSIENT_FAILURE_INVALID_ACK_ID", } - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) # message with ack_id 'ackid1' fails with an exception assert requests_completed[0].ack_id == "ackid1" @@ -1838,12 +1838,12 @@ def test_process_futures_mixed_success_and_failure_acks(): assert future3.result() == subscriber_exceptions.AcknowledgeStatus.SUCCESS -def test_process_futures_mixed_success_and_failure_modacks(): +def test_process_requests_mixed_success_and_failure_modacks(): # mixed success and failure (modacks) future1 = futures.Future() future2 = futures.Future() future3 = futures.Future() - future_reqs_dict = { + ack_reqs_dict = { "ackid1": requests.ModAckRequest(ack_id="ackid1", seconds=60, future=future1), "ackid2": requests.ModAckRequest(ack_id="ackid2", seconds=60, future=future2), "ackid3": requests.ModAckRequest(ack_id="ackid3", seconds=60, future=future3), @@ -1852,8 +1852,8 @@ def test_process_futures_mixed_success_and_failure_modacks(): "ackid1": "PERMANENT_FAILURE_INVALID_ACK_ID", "ackid2": "TRANSIENT_FAILURE_INVALID_ACK_ID", } - requests_completed, requests_to_retry = streaming_pull_manager._process_futures( - None, future_reqs_dict, errors_dict + requests_completed, requests_to_retry = streaming_pull_manager._process_requests( + None, ack_reqs_dict, errors_dict ) # message with ack_id 'ackid1' fails with an exception assert requests_completed[0].ack_id == "ackid1" From 4158315411e2d79bc92efb657b239c1f6e6f4846 Mon Sep 17 00:00:00 2001 From: Prad Nelluru Date: Mon, 28 Feb 2022 17:54:46 -0500 Subject: [PATCH 43/43] Improve tests and comments --- .../_protocol/streaming_pull_manager.py | 9 ++- .../subscriber/test_streaming_pull_manager.py | 73 ++++++++++++++++--- 2 files changed, 68 insertions(+), 14 deletions(-) diff --git a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py index 5971e7988..5a9d08026 100644 --- a/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py +++ b/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py @@ -154,11 +154,11 @@ def _process_requests( ack_reqs_dict: "containers.ScalarMap", errors_dict: Optional["containers.ScalarMap"], ): - """Process futures by referring to errors_dict. + """Process requests by referring to error_status and errors_dict. - The errors returned by the server in `errors_dict` are used to complete - the request futures in `ack_reqs_dict` (with a success or exception) or - to return requests for further retries. + The errors returned by the server in as `error_status` or in `errors_dict` + are used to complete the request futures in `ack_reqs_dict` (with a success + or exception) or to return requests for further retries. """ requests_completed = [] requests_to_retry = [] @@ -564,6 +564,7 @@ def send_unary_ack( error is re-raised. """ assert ack_ids + assert len(ack_ids) == len(ack_reqs_dict) error_status = None ack_errors_dict = None diff --git a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py index 3d9904ca1..9e8d6c5ed 100644 --- a/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py +++ b/tests/unit/pubsub_v1/subscriber/test_streaming_pull_manager.py @@ -506,7 +506,15 @@ def test__maybe_release_messages_negative_on_hold_bytes_warning(caplog): def test_send_unary_ack(): manager = make_manager() - manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict={}) + ack_reqs_dict = { + "ack_id1": requests.AckRequest( + ack_id="ack_id1", byte_size=0, time_to_ack=20, ordering_key="", future=None + ), + "ack_id2": requests.AckRequest( + ack_id="ack_id2", byte_size=0, time_to_ack=20, ordering_key="", future=None + ), + } + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict=ack_reqs_dict) manager._client.acknowledge.assert_called_once_with( subscription=manager._subscription, ack_ids=["ack_id1", "ack_id2"] @@ -516,10 +524,15 @@ def test_send_unary_ack(): def test_send_unary_modack(): manager = make_manager() + ack_reqs_dict = { + "ack_id3": requests.ModAckRequest(ack_id="ack_id3", seconds=60, future=None), + "ack_id4": requests.ModAckRequest(ack_id="ack_id4", seconds=60, future=None), + "ack_id5": requests.ModAckRequest(ack_id="ack_id5", seconds=60, future=None), + } manager.send_unary_modack( modify_deadline_ack_ids=["ack_id3", "ack_id4", "ack_id5"], modify_deadline_seconds=[10, 20, 20], - ack_reqs_dict={}, + ack_reqs_dict=ack_reqs_dict, ) manager._client.modify_ack_deadline.assert_has_calls( @@ -547,7 +560,15 @@ def test_send_unary_ack_api_call_error(caplog): error = exceptions.GoogleAPICallError("The front fell off") manager._client.acknowledge.side_effect = error - manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict={}) + ack_reqs_dict = { + "ack_id1": requests.AckRequest( + ack_id="ack_id1", byte_size=0, time_to_ack=20, ordering_key="", future=None + ), + "ack_id2": requests.AckRequest( + ack_id="ack_id2", byte_size=0, time_to_ack=20, ordering_key="", future=None + ), + } + manager.send_unary_ack(ack_ids=["ack_id1", "ack_id2"], ack_reqs_dict=ack_reqs_dict) assert "The front fell off" in caplog.text @@ -560,10 +581,26 @@ def test_send_unary_modack_api_call_error(caplog): error = exceptions.GoogleAPICallError("The front fell off") manager._client.modify_ack_deadline.side_effect = error + ack_reqs_dict = { + "ack_id1": requests.AckRequest( + ack_id="ack_id1", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=futures.Future(), + ), + "ack_id2": requests.AckRequest( + ack_id="ack_id2", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=futures.Future(), + ), + } manager.send_unary_modack( modify_deadline_ack_ids=["ack_id_string"], modify_deadline_seconds=[0], - ack_reqs_dict={}, + ack_reqs_dict=ack_reqs_dict, ) assert "The front fell off" in caplog.text @@ -579,11 +616,23 @@ def test_send_unary_ack_retry_error(caplog): ) manager._client.acknowledge.side_effect = error - future = futures.Future() + future1 = futures.Future() + future2 = futures.Future() ack_reqs_dict = { - "ackid1": requests.AckRequest( - ack_id="ackid1", byte_size=0, time_to_ack=20, ordering_key="", future=future - ) + "ack_id1": requests.AckRequest( + ack_id="ack_id1", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=future1, + ), + "ack_id2": requests.AckRequest( + ack_id="ack_id2", + byte_size=0, + time_to_ack=20, + ordering_key="", + future=future2, + ), } with pytest.raises(exceptions.RetryError): manager.send_unary_ack( @@ -592,9 +641,13 @@ def test_send_unary_ack_retry_error(caplog): assert "RetryError while sending unary RPC" in caplog.text assert "signaled streaming pull manager shutdown" in caplog.text - assert isinstance(future.exception(), subscriber_exceptions.AcknowledgeError) + assert isinstance(future1.exception(), subscriber_exceptions.AcknowledgeError) assert ( - future.exception().error_code is subscriber_exceptions.AcknowledgeStatus.OTHER + future1.exception().error_code is subscriber_exceptions.AcknowledgeStatus.OTHER + ) + assert isinstance(future2.exception(), subscriber_exceptions.AcknowledgeError) + assert ( + future2.exception().error_code is subscriber_exceptions.AcknowledgeStatus.OTHER )