ConsumeBidirectionalStream error logged at DEBUG level

[elliottc]

It was difficult and time consuming to find the log messages that I needed to see to figure out my problem because the relevant messages were logged at debug and info level. It seems more appropriate for messages like these to be more prominent due to the severity of the issue.

I had incorrect permissions to pull messages from pubsub, and this caused the pubsub client background thread to exit immediately. The hint that this was happening was the log message:
google.api_core.bidi - INFO - 136365517502208 - Thread-ConsumeBidirectionalStream exiting

This wasn't enough info to know what the problem was, so I had to change my logging settings to get this message to appear:

google.api_core.bidi - DEBUG - 137863282816768 - Thread-ConsumeBidirectionalStream caught error 403 User not authorized to perform this action. and will exit. Generally this is due to the RPC itself being cancelled and the error will be surfaced to the calling code.
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/google/api_core/grpc_helpers.py", line 116, in __next__
    return next(self._wrapped)
  File "/usr/local/lib/python3.9/site-packages/grpc/_channel.py", line 543, in __next__
    return self._next()
  File "/usr/local/lib/python3.9/site-packages/grpc/_channel.py", line 969, in _next
    raise self
grpc._channel._MultiThreadedRendezvous: <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.PERMISSION_DENIED
	details = "User not authorized to perform this action."
	debug_error_string = "UNKNOWN:Error received from peer ipv4:142.250.72.170:443 {created_time:"2024-05-21T04:00:12.815505637+00:00", grpc_status:7, grpc_message:"User not authorized to perform this action."}"
>

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/google/api_core/bidi.py", line 663, in _thread_main
    response = self._bidi_rpc.recv()
  File "/usr/local/lib/python3.9/site-packages/google/api_core/bidi.py", line 569, in recv
    return self._recoverable(self._recv)
  File "/usr/local/lib/python3.9/site-packages/google/api_core/bidi.py", line 528, in _recoverable
    raise exc
  File "/usr/local/lib/python3.9/site-packages/google/api_core/bidi.py", line 512, in _recoverable
    return method(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/google/api_core/bidi.py", line 566, in _recv
    return next(call)
  File "/usr/local/lib/python3.9/site-packages/google/api_core/grpc_helpers.py", line 119, in __next__
    raise exceptions.from_grpc_error(exc) from exc
google.api_core.exceptions.PermissionDenied: 403 User not authorized to perform this action.

Environment details

• OS type and version: debian buster
• Python version: 3.9.16
• pip version: 24.0
• google-cloud-pubsub version: 2.21.1

Steps to reproduce

1. have insufficient permissions to access pubsub
2. pubsub_v1.SubscriberClient().subscribe(subscription_path, handler)

Code example

import logging
from google.cloud import pubsub_v1
from google.cloud.pubsub_v1.subscriber.message import Message

logging.basicConfig(level=logging.INFO)

SUBSCRIPTION = "<my subscription>"

def handler(message: Message):
    pass

client = pubsub_v1.SubscriberClient()
fut = client.subscribe(SUBSCRIPTION, handler)
fut.result() # wait until message processing is done