Ungraceful error None could not be converted to unicode

[k0ral]

Environment details

• OS: Ubuntu 18.04.5 LTS, running docker image based on Ubuntu 20.04
• Python version: 3.7.1
• pip version: 19.0.3
• google-auth version: 1.35.0
• google-cloud-bigtable version: 1.7.0
• google-cloud-storage version: 1.42.3
• google-cloud-pubsub version: 2.8.0

Error

Traceback (most recent call last):
  File "/opt/venv/lib/python3.7/site-packages/grpc/_plugin_wrapping.py", line 90, in __call__
    context, _AuthMetadataPluginCallback(callback_state, callback))
  File "/opt/venv/lib/python3.7/site-packages/google/auth/transport/grpc.py", line 101, in __call__
    callback(self._get_authorization_headers(context), None)
  File "/opt/venv/lib/python3.7/site-packages/google/auth/transport/grpc.py", line 88, in _get_authorization_headers
    self._request, context.method_name, context.service_url, headers
  File "/opt/venv/lib/python3.7/site-packages/google/auth/credentials.py", line 134, in before_request
    self.apply(headers)
  File "/opt/venv/lib/python3.7/site-packages/google/auth/credentials.py", line 110, in apply
    _helpers.from_bytes(token or self.token)
  File "/opt/venv/lib/python3.7/site-packages/google/auth/_helpers.py", line 130, in from_bytes
    raise ValueError("{0!r} could not be converted to unicode".format(value))
ValueError: None could not be converted to unicode

This is essentially the same error as described in this StackOverflow question.

Steps to reproduce

I'm afraid we haven't iterated enough to isolate the minimal reproducing piece of code, so at the moment we can't provide a detailed steps to reproduce with a minimal, complete, verifiable example, but we know that:

• the error happens at the start of a microservice that interacts with multiple GCP components (namely: PubSub, Storage and Bigtable)
• the error seems to have no consequence whatsoever: the microservice correctly starts and runs after that error

It would be nice if google-auth library could report a more graceful/meaningful error, then we can figure out by ourselves what we did wrong.

[syrkuit]

Reproduction script:

import logging
import time
import google.cloud.pubsub_v1 as pubsub

logging.basicConfig(level=logging.DEBUG)
ps = pubsub.SubscriberClient.from_service_account_json('secret.json')
ps.subscribe(ps.subscription_path('project-id', 'subscription-name-1'), lambda x: None)
ps.subscribe(ps.subscription_path('project-id', 'subscription-name-2'), lambda x: None)
time.sleep(2)

This is with Python 3.9.9 and the following modules installed:

google-api-core          2.4.0
google-auth              2.3.3
google-cloud-pubsub      2.9.0
googleapis-common-protos 1.54.0
grpc-google-iam-v1       0.12.3

This is the error:

Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/grpc/_plugin_wrapping.py", line 89, in __call__
    self._metadata_plugin(
  File "/usr/local/lib/python3.9/site-packages/google/auth/transport/grpc.py", line 101, in __call__
    callback(self._get_authorization_headers(context), None)
  File "/usr/local/lib/python3.9/site-packages/google/auth/transport/grpc.py", line 87, in _get_authorization_headers
    self._credentials.before_request(
  File "/usr/local/lib/python3.9/site-packages/google/auth/credentials.py", line 134, in before_request
    self.apply(headers)
  File "/usr/local/lib/python3.9/site-packages/google/auth/credentials.py", line 110, in apply
    _helpers.from_bytes(token or self.token)
  File "/usr/local/lib/python3.9/site-packages/google/auth/_helpers.py", line 130, in from_bytes
    raise ValueError("{0!r} could not be converted to unicode".format(value))
ValueError: None could not be converted to unicode
INFO:google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager:Observed non-terminating stream error 503 Getting metadata from plugin failed with error: None could not be converted to unicode
INFO:google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager:Observed recoverable stream error 503 Getting metadata from plugin failed with error: None could not be converted to 

Notes:

• it does not happen if you use a single subscription, you need (at least?) 2
• the error is not fatal, it retries and things work. It's just annoying noise.
• it happens regularly (not just on startup), probably whenever it needs to reconnect

noise can be reduced with:

        def googleauth_filter(record):
            # https://github.com/googleapis/google-auth-library-python/issues/927
            if record.exc_info and isinstance(record.exc_info[1], ValueError) \
               and traceback.extract_tb(record.exc_info[2])[-1].name == 'from_bytes':
                record.levelno = logging.INFO
                record.levelname = logging.getLevelName(logging.INFO)
                record.msg += ': ' + str(record.exc_info[1])
                record.exc_info = None
            return True
        logging.getLogger('grpc._plugin_wrapping').addFilter(googleauth_filter)

[arugifa]

I confirm that I also have the same problem. Manually loading JSON tokens, as mentioned on Stackoverflow, didn't help.

Similar to what @syrkuit mentioned, it fails when having multiple subscriptions, but also topics.

In my case, I get the error when running contract tests as part of a test suite (i.e., I have fake clients simulating the behavior of official Publisher/Subscriber clients, and want to check that fake and official clients still behave the same).

Here is how look my tests:

    async def test_list_subscriptions(self, subscriber):
        subscriptions = await SubscriptionFactory.create_batch(2)

        subscription_list = await SubscriptionFactory.list_subscriptions()  # <== THIS FAILS
        # The previous line runs under the hood: await subscriber.list_subscriptions(project=project)

        sorted_subscription_list = sorted(subscription_list.subscriptions, key=attrgetter("name"))

        for actual, expected in zip(sorted_subscription_list, subscriptions):
            assert actual.name == expected.name

    async def test_list_topics(self, publisher):
        topics = await TopicFactory.create_batch(2)

        topic_list = await TopicFactory.list_topics()  # <== THIS FAILS
        # The previous line runs under the hood: await publisher.list_topics(project=project)

        sorted_topic_list = sorted(topic_list.topics, key=attrgetter("name"))

        for actual, expected in zip(sorted_topic_list, topics):
            assert actual.name == expected.name

I have the following Google dependencies installed:

google-api-core (2.5.0)
google-api-python-client (2.37.0)
google-auth (2.6.0)
google-auth-httplib2 (0.1.0)
google-cloud-appengine-logging (1.1.0)
google-cloud-audit-log (0.2.0)
google-cloud-core (2.2.2)
google-cloud-iot (2.3.0)
google-cloud-logging (3.0.0)
google-cloud-pubsub (2.9.0)
google-cloud-trace (1.5.1)
googleapis-common-protos (1.54.0)
grpc-google-iam-v1 (0.12.3)
grpcio (1.43.0)
grpcio-status (1.43.0)
protobuf (3.19.4)

My contract tests started to fail almost every time since August 2021. From time to time (they run once a day), they pass, but it's quite rare. Over the last month, they passed only once.

[vpfaulkner]

I too am running into this issue, specifically with the Google Vision async client: https://github.com/googleapis/python-vision/blob/main/google/cloud/vision_v1/services/image_annotator/async_client.py#L42

Seems to happen when we attempt to use the same client to fire several concurrent requests. Appears intermittent and non-fatal because of the library's built in retry.

[tokibito]

I have same problem. I use google.auth library by cloud-logging, dialogflow, and others.
Our application is running with gunicorn. It is using the gthread worker , so accept mutiple request per processes.

[nguaman]

I have the same problem!

googleapis/python-pubsub#737 (comment)

I think it's happens when you use a publisher and a subscriber in the same code.

Also related : #253

[ns-dzhang]

I have the same problem in my pubsublite application

grpc/grpc#30460

[nguaman]

any news about this?

[ferchuni]

News? The same here.

[clundin25]

This is due to a race condition overwriting the token value after a refresh but before the headers are applied.

[clundin25]

This should be resolved in v2.17.2