Messaging: Errors with multicast send #507

aplusm · 2020-12-01T07:20:01Z

App Engine environment
firebase-admin: 4.4.0
Firebase Product: Messaging

Describe the problem

From time to time, while sending multicast notification from our app engine application, the following issues are reported, all at the same time:

KeyError: '8'
at execute (/layers/google.python.pip/pip/googleapiclient/http.py:1548)
at positional_wrapper (/layers/google.python.pip/pip/googleapiclient/_helpers.py:134)
at send_all (/layers/google.python.pip/pip/firebase_admin/messaging.py:390)
at send_multicast (/layers/google.python.pip/pip/firebase_admin/messaging.py:167)
at send (/srv/main.py:109)
at notification_send (/srv/main.py:55)
at dispatch_request (/layers/google.python.pip/pip/flask/app.py:1936)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1950)
at reraise (/layers/google.python.pip/pip/flask/_compat.py:39)
at handle_user_exception (/layers/google.python.pip/pip/flask/app.py:1821)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1952)
at wsgi_app (/layers/google.python.pip/pip/flask/app.py:2447)

OSError: [Errno 0] Error
at read (/opt/python3.8/lib/python3.8/ssl.py:1099)
at recv_into (/opt/python3.8/lib/python3.8/ssl.py:1241)
at readinto (/opt/python3.8/lib/python3.8/socket.py:669)
at _read_status (/opt/python3.8/lib/python3.8/http/client.py:268)
at begin (/opt/python3.8/lib/python3.8/http/client.py:307)
at getresponse (/opt/python3.8/lib/python3.8/http/client.py:1347)
at _conn_request (/layers/google.python.pip/pip/httplib2/__init__.py:1589)
at _request (/layers/google.python.pip/pip/httplib2/__init__.py:1650)
at request (/layers/google.python.pip/pip/httplib2/__init__.py:1985)
at request (/layers/google.python.pip/pip/google_auth_httplib2.py:200)
at _execute (/layers/google.python.pip/pip/googleapiclient/http.py:1469)
at execute (/layers/google.python.pip/pip/googleapiclient/http.py:1540)
at positional_wrapper (/layers/google.python.pip/pip/googleapiclient/_helpers.py:134)
at send_all (/layers/google.python.pip/pip/firebase_admin/messaging.py:390)
at send_multicast (/layers/google.python.pip/pip/firebase_admin/messaging.py:167)
at send (/srv/main.py:109)
at notification_send (/srv/main.py:55)
at dispatch_request (/layers/google.python.pip/pip/flask/app.py:1936)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1950)
at reraise (/layers/google.python.pip/pip/flask/_compat.py:39)
at handle_user_exception (/layers/google.python.pip/pip/flask/app.py:1821)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1952)
at wsgi_app (/layers/google.python.pip/pip/flask/app.py:2447)

ssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:2622)
at read (/opt/python3.8/lib/python3.8/ssl.py:1099)
at recv_into (/opt/python3.8/lib/python3.8/ssl.py:1241)
at readinto (/opt/python3.8/lib/python3.8/socket.py:669)
at _safe_read (/opt/python3.8/lib/python3.8/http/client.py:612)
at _readall_chunked (/opt/python3.8/lib/python3.8/http/client.py:575)
at read (/opt/python3.8/lib/python3.8/http/client.py:465)
at _conn_request (/layers/google.python.pip/pip/httplib2/__init__.py:1618)
at _request (/layers/google.python.pip/pip/httplib2/__init__.py:1650)
at request (/layers/google.python.pip/pip/httplib2/__init__.py:1985)
at request (/layers/google.python.pip/pip/google_auth_httplib2.py:200)
at _execute (/layers/google.python.pip/pip/googleapiclient/http.py:1469)
at execute (/layers/google.python.pip/pip/googleapiclient/http.py:1540)
at positional_wrapper (/layers/google.python.pip/pip/googleapiclient/_helpers.py:134)
at send_all (/layers/google.python.pip/pip/firebase_admin/messaging.py:390)
at send_multicast (/layers/google.python.pip/pip/firebase_admin/messaging.py:167)
at send (/srv/main.py:109)
at notification_send (/srv/main.py:55)
at dispatch_request (/layers/google.python.pip/pip/flask/app.py:1936)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1950)
at reraise (/layers/google.python.pip/pip/flask/_compat.py:39)
at handle_user_exception (/layers/google.python.pip/pip/flask/app.py:1821)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1952)
at wsgi_app (/layers/google.python.pip/pip/flask/app.py:2447)

ssl.SSLError: [SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption failed or bad record mac (_ssl.c:2622)
at read (/opt/python3.8/lib/python3.8/ssl.py:1099)
at recv_into (/opt/python3.8/lib/python3.8/ssl.py:1241)
at readinto (/opt/python3.8/lib/python3.8/socket.py:669)
at _read_status (/opt/python3.8/lib/python3.8/http/client.py:268)
at begin (/opt/python3.8/lib/python3.8/http/client.py:307)
at getresponse (/opt/python3.8/lib/python3.8/http/client.py:1347)
at _conn_request (/layers/google.python.pip/pip/httplib2/__init__.py:1589)
at _request (/layers/google.python.pip/pip/httplib2/__init__.py:1650)
at request (/layers/google.python.pip/pip/httplib2/__init__.py:1985)
at request (/layers/google.python.pip/pip/google_auth_httplib2.py:200)
at _execute (/layers/google.python.pip/pip/googleapiclient/http.py:1469)
at execute (/layers/google.python.pip/pip/googleapiclient/http.py:1540)
at positional_wrapper (/layers/google.python.pip/pip/googleapiclient/_helpers.py:134)
at send_all (/layers/google.python.pip/pip/firebase_admin/messaging.py:390)
at send_multicast (/layers/google.python.pip/pip/firebase_admin/messaging.py:167)
at send (/srv/main.py:109)
at notification_send (/srv/main.py:55)
at dispatch_request (/layers/google.python.pip/pip/flask/app.py:1936)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1950)
at reraise (/layers/google.python.pip/pip/flask/_compat.py:39)
at handle_user_exception (/layers/google.python.pip/pip/flask/app.py:1821)
at full_dispatch_request (/layers/google.python.pip/pip/flask/app.py:1952)
at wsgi_app (/layers/google.python.pip/pip/flask/app.py:2447)

Steps to reproduce:

message = messaging.MulticastMessage(apns=apnsConfig, tokens=tokens)
response = messaging.send_multicast(message)

The text was updated successfully, but these errors were encountered:

hiranya911 · 2020-12-01T18:31:26Z

This seems to be a known thread-safety issue with httplib2:

googleapis/google-cloud-python#1214
googleapis/google-cloud-python#1346

Also documented at https://github.com/googleapis/google-api-python-client/blob/master/docs/thread_safety.md

Until we figure out a solution, can you try implementing some synchronization logic in your code and see if that helps?

hiranya911 · 2020-12-03T22:28:21Z

Related to googleapis/google-api-python-client#1118

GabrieleCalarota · 2021-03-02T15:41:04Z

Same issue
traceback

[SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:2622)\nTraceback (most recent call last):\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/FlaskAPI/../UserBot/Shared.py\", line 1340, in send_one_order_to_admin_chat_and_to_supplier_chat\n    firestoreClient.send_message_to_device_new_order(firestoreClient.get_tokens_for_supplierID(supplierID),\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/FlaskAPI/../ExternalServices/Firebase/firebase.py\", line 41, in send_message_to_device_new_order\n    return self.send_message_to_device_generic(registration_tokens, data=data,\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/FlaskAPI/../ExternalServices/Firebase/firebase.py\", line 59, in send_message_to_device_generic\n    response = messaging.send_multicast(message, app=self.firebase_app)\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/firebase_admin/messaging.py\", line 167, in send_multicast\n    return _get_messaging_service(app).send_all(messages, dry_run)\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/firebase_admin/messaging.py\", line 390, in send_all\n    batch.execute()\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/googleapiclient/_helpers.py\", line 130, in positional_wrapper\n    return wrapped(*args, **kwargs)\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/googleapiclient/http.py\", line 1454, in execute\n    self._execute(http, self._order, self._requests)\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/googleapiclient/http.py\", line 1385, in _execute\n    resp, content = http.request(self._batch_uri, method=\'\'POST\'\', body=body,\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/google_auth_httplib2.py\", line 197, in request\n    response, content = self.http.request(\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/newrelic/api/external_trace.py\", line 73, in dynamic_wrapper\n    return wrapped(*args, **kwargs)\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/httplib2/__init__.py\", line 1944, in request\n    (response, content) = self._request(\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/httplib2/__init__.py\", line 1617, in _request\n    (response, content) = self._conn_request(\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/httplib2/__init__.py\", line 1556, in _conn_request\n    response = conn.getresponse()\n  File \"/home/cto/SquisEatAppDEV/riCibiamo_bot/venv/lib/python3.8/site-packages/newrelic/hooks/external_httplib.py\", line 77, in httplib_getresponse_wrapper\n    return wrapped(*args, **kwargs)\n  File \"/usr/lib/python3.8/http/client.py\", line 1347, in getresponse\n    response.begin()\n  File \"/usr/lib/python3.8/http/client.py\", line 307, in begin\n    version, status, reason = self._read_status()\n  File \"/usr/lib/python3.8/http/client.py\", line 268, in _read_status\n    line = str(self.fp.readline(_MAXLINE + 1), \"iso-8859-1\")\n  File \"/usr/lib/python3.8/socket.py\", line 669, in readinto\n    return self._sock.recv_into(b)\n  File \"/usr/lib/python3.8/ssl.py\", line 1241, in recv_into\n    return self.read(nbytes, buffer)\n  File \"/usr/lib/python3.8/ssl.py\", line 1099, in read\n    return self._sslobj.read(len, buffer)\nssl.SSLError: [SSL: WRONG_VERSION_NUMBER] wrong version number (_ssl.c:2622)

mumu2001 · 2021-05-18T03:01:32Z

I encountered a same issue.
How should I deal with it?

firebase_admin.exceptions.UnknownError: Unknown error while making a remote service call: [SSL: DECRYPTION_FAILED_OR_BAD_RECORD_MAC] decryption failed or bad record mac (_ssl.c:2570)
at send_all (/layers/google.python.pip/pip/lib/python3.7/site-packages/firebase_admin/messaging.py:391)
at send_multicast (/layers/google.python.pip/pip/lib/python3.7/site-packages/firebase_admin/messaging.py:166)

hiranya911 · 2021-05-18T17:54:25Z

How should I deal with it?

For now you will have to synchronize the calls to send_multicast().

GabrieleCalarota · 2021-05-19T09:21:44Z

How should I deal with it?

For now you will have to synchronize the calls to send_multicast().

@hiranya911 Can you clarify with giving a little bit more details on your reply?

mumu2001 · 2021-05-19T09:31:31Z

send_multicast() calls send_all() to requests multi POST asynchronize.
I gave up this and decided to use topic.

GabrieleCalarota · 2021-05-19T09:33:30Z

send_multicast() calls send_all() to requests multi POST asynchronize.
I gave up this and decided to use topic.

Thanks, I use send_multicast() because it might happen that I want to notify same user with different token notification (because of different device) . How topic would solve this particular case scenario in your opinion? @mumu2001

mumu2001 · 2021-05-19T10:15:00Z

@GabrieleCalarota
In your scenario,
I think it's easy to simply call send() synchronous loop.
Topic subscribe is useful when you want to distribute more clients with one request.

mumu2001 · 2021-05-19T10:17:12Z

It would be best if the SDK created http client for each request :)

GabrieleCalarota · 2021-05-19T10:18:54Z

@GabrieleCalarota
In your scenario,
I think it's easy to simply call send() synchronous loop.
Topic subscribe is useful when you want to distribute more clients with one request.

But isn't a send() with a loop is the same (at least semantically) as the send_multicast? I have multiple tokens I want to send a notification to, and this is it. Even if I quite understand your point, I don't get how and why this solves my issue. Also I'm using the send_multicast as a generalized notification process, which is synchronous though. So If I would have to put that loop as a job task or as a futurable

hiranya911 · 2021-05-19T18:00:36Z

Can you clarify with giving a little bit more details on your reply?

I think for most developers, putting the send_multicast() call behind a lock should be sufficient to avoid the multithreading issues.

You can also try calling send() in a loop, but it would be a lot slower than send_multicast().

cvipul · 2021-05-31T07:44:01Z

I am using celery to send multicast messages and get this error in case of concurrent requests :

SSLWantReadError: The operation did not complete (read) (_ssl.c:2622)
  File "gevent/_ssl3.py", line 385, in read
    return self._sslobj.read(nbytes, buffer)
ConcurrentObjectUseError: This socket is already used by another greenlet: <bound method Waiter.switch of <gevent._gevent_c_waiter.Waiter object at 0x7f688733e090>>
  File "firebase_admin/messaging.py", line 389, in send_all
    batch.execute()
  File "googleapiclient/_helpers.py", line 134, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "googleapiclient/http.py", line 1560, in execute
    self._execute(http, self._order, self._requests)
  File "googleapiclient/http.py", line 1489, in _execute
    resp, content = http.request(
  File "google_auth_httplib2.py", line 218, in request
    response, content = self.http.request(
  File "__init__.py", line 1708, in request
    (response, content) = self._request(
  File "__init__.py", line 1424, in _request
    (response, content) = self._conn_request(conn, request_uri, method, body, headers)
  File "__init__.py", line 1376, in _conn_request
    response = conn.getresponse()
  File "http/client.py", line 1347, in getresponse
    response.begin()
  File "http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "http/client.py", line 268, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "socket.py", line 669, in readinto
    return self._sock.recv_into(b)
  File "gevent/_ssl3.py", line 567, in recv_into
    return self.read(nbytes, buffer)
  File "gevent/_ssl3.py", line 390, in read
    self._wait(self._read_event, timeout_exc=_SSLErrorReadTimeout)
  File "src/gevent/_hub_primitives.py", line 317, in gevent._gevent_c_hub_primitives.wait_on_socket
  File "src/gevent/_hub_primitives.py", line 322, in gevent._gevent_c_hub_primitives.wait_on_socket
  File "src/gevent/_hub_primitives.py", line 297, in gevent._gevent_c_hub_primitives._primitive_wait

How can I make the SDK use a connection pool to handle this as well as optimise the number of connections being made to the FCM server?

hiranya911 · 2021-08-27T22:15:42Z

I'm closing this assuming #558 has resolved the issue. Happy to take another look if the problem persists even after the fix.

GabrieleCalarota · 2021-10-21T09:53:50Z

I still have the issue, which version are you running?

google-oss-bot added the api: messaging label Dec 1, 2020

hiranya911 mentioned this issue Jun 24, 2021

fix(fcm): A workaround for the concurrency issues in googleapiclient #558

Merged

hiranya911 closed this as completed Aug 27, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Messaging: Errors with multicast send #507

Messaging: Errors with multicast send #507

aplusm commented Dec 1, 2020 •

edited

Loading

hiranya911 commented Dec 1, 2020

hiranya911 commented Dec 3, 2020

GabrieleCalarota commented Mar 2, 2021 •

edited

Loading

mumu2001 commented May 18, 2021

hiranya911 commented May 18, 2021

GabrieleCalarota commented May 19, 2021

mumu2001 commented May 19, 2021

GabrieleCalarota commented May 19, 2021

mumu2001 commented May 19, 2021

mumu2001 commented May 19, 2021

GabrieleCalarota commented May 19, 2021

hiranya911 commented May 19, 2021

cvipul commented May 31, 2021

hiranya911 commented Aug 27, 2021

GabrieleCalarota commented Oct 21, 2021

Messaging: Errors with multicast send #507

Messaging: Errors with multicast send #507

Comments

aplusm commented Dec 1, 2020 • edited Loading

Describe the problem

Steps to reproduce:

hiranya911 commented Dec 1, 2020

hiranya911 commented Dec 3, 2020

GabrieleCalarota commented Mar 2, 2021 • edited Loading

mumu2001 commented May 18, 2021

hiranya911 commented May 18, 2021

GabrieleCalarota commented May 19, 2021

mumu2001 commented May 19, 2021

GabrieleCalarota commented May 19, 2021

mumu2001 commented May 19, 2021

mumu2001 commented May 19, 2021

GabrieleCalarota commented May 19, 2021

hiranya911 commented May 19, 2021

cvipul commented May 31, 2021

hiranya911 commented Aug 27, 2021

GabrieleCalarota commented Oct 21, 2021

aplusm commented Dec 1, 2020 •

edited

Loading

GabrieleCalarota commented Mar 2, 2021 •

edited

Loading