Event Time parse issue in firestore_fn.py

[noonzyism]

I'm following the start guide at: https://firebase.google.com/docs/functions/get-started?gen=2nd

At step 7, when testing the functions using the emulator, the addmessage function works fine, and triggers the makeuppercase function appropriately, but the makeuppercase call fails with an error related to event datetime:

i  functions: Beginning execution of "us-central1-addmessage"
>  127.0.0.1 - - [21/May/2023 01:57:15] "GET /?text=newmessage HTTP/1.1" 200 -
i  functions: Finished "us-central1-addmessage" in 105.1165ms
>   * Serving Flask app 'makeuppercase'
>   * Debug mode: off
>  WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
>   * Running on http://127.0.0.1:8933
>  Press CTRL+C to quit
>  127.0.0.1 - - [21/May/2023 01:57:16] "GET /__/health HTTP/1.1" 405 -
i  functions: Beginning execution of "us-central1-makeuppercase"
>  [2023-05-21 01:57:16,487] ERROR in app: Exception on /functions/projects/ [POST]
>  Traceback (most recent call last):
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\flask\app.py", line 2190, in wsgi_app
>      response = self.full_dispatch_request()
>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\flask\app.py", line 1486, in full_dispatch_request
>      rv = self.handle_user_exception(e)
>           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\flask\app.py", line 1484, in full_dispatch_request
>      rv = self.dispatch_request()
>           ^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\flask\app.py", line 1469, in dispatch_request
>      return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\functions_framework\__init__.py", line 174, in view_func
>      function(event)
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\firebase_functions\firestore_fn.py", line 302, in on_document_created_wrapped
>      return _firestore_endpoint_handler(
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\user\proj\functions\venv\Lib\site-packages\firebase_functions\firestore_fn.py", line 114, in _firestore_endpoint_handler
>      event_time = _dt.datetime.strptime(
>                   ^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Python311\Lib\_strptime.py", line 568, in _strptime_datetime
>      tt, fraction, gmtoff_fraction = _strptime(data_string, format)
>                                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Python311\Lib\_strptime.py", line 349, in _strptime
>      raise ValueError("time data %r does not match format %r" %
>  ValueError: time data '2023-05-21T01:57:15.643674100Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'
i  functions: Finished "us-central1-makeuppercase" in 22.0598ms
>  127.0.0.1 - - [21/May/2023 01:57:16] "POST /functions/projects/ HTTP/1.1" 500 -

FWIW, I was able to hack around it locally by modifying firestore_fn.py to use dateutil.parser instead and changing line 114:

import dateutil.parser as dateutil

Line 114:

event_time = dateutil.parse(event_attributes["time"])

Not sure if this would be the most appropriate fix for the repo, or if there's some other underlying root cause that should be addressed.

[Balazs23]

Same issue for me, just I started with the sample

i  functions: Beginning execution of "europe-west1-onfirestoredocumentwritten"
>  [2023-05-24 14:06:55,688] ERROR in app: Exception on /functions/projects/ [POST]
>  Traceback (most recent call last):
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/flask/app.py", line 2190, in wsgi_app
>      response = self.full_dispatch_request()
>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/flask/app.py", line 1486, in full_dispatch_request
>      rv = self.handle_user_exception(e)
>           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/flask/app.py", line 1484, in full_dispatch_request
>      rv = self.dispatch_request()
>           ^^^^^^^^^^^^^^^^^^^^^^^
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/flask/app.py", line 1469, in dispatch_request
>      return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/functions_framework/__init__.py", line 174, in view_func
>      function(event)
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py", line 208, in on_document_written_wrapped
>      return _firestore_endpoint_handler(
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "/workspaces/firebase-sample/functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py", line 114, in _firestore_endpoint_handler
>      event_time = _dt.datetime.strptime(
>                   ^^^^^^^^^^^^^^^^^^^^^^
>    File "/usr/local/lib/python3.11/_strptime.py", line 568, in _strptime_datetime
>      tt, fraction, gmtoff_fraction = _strptime(data_string, format)
>                                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "/usr/local/lib/python3.11/_strptime.py", line 349, in _strptime
>      raise ValueError("time data %r does not match format %r" %
>  ValueError: time data '2023-05-24T14:06:54.424379216Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'
i  functions: Finished "europe-west1-onfirestoredocumentwritten" in 21.14ms

versions:
firebase-functions: 59d68cf
firebase cli version: 12.2.0
firebase emulator version: v1.17.4

I did a short research and the class implements the generic CloudEvent. Current version from the spec is v1.0.2 says the Timestamp format is RFC 3339 - it should match with %Y-%m-%dT%H:%M:%S.%f%z. Maybe the issue is with the emulator because 2023-05-24T14:06:54.424379216Z fractional seconds component 424379216 exceeds the six-digit limit specified by the RFC.

[kozzza]

Is there a workaround for this right now? I can't run test my firestore cloud functions at all without running into this error.

[arturoszulc]

Same problem here. Yesterday it worked, when I deployed my python function for the first time on functions emulator. After that I keep getting this error.

[kylemilden]

We are having the same issue in a live environment when the milliseconds happen to be 0. It looks like on line 65 of cloudevents.http.event.py it is trying to add the time attribute to the event using isoformat which is dropping off the milliseconds. Then in firebase_functions.pubsub_fn.py on line 108 it is trying to parse that time assuming that there are milliseconds and it is throwing the same error everyone else is seeing.

File "/layers/google.python.pip/pip/lib/python3.11/site-packages/functions_framework/__init__.py", line 174, in view_func
function(event)
File "/layers/google.python.pip/pip/lib/python3.11/site-packages/firebase_functions/pubsub_fn.py", line 184, in on_message_published_wrapped
return _message_handler(func, raw)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/layers/google.python.pip/pip/lib/python3.11/site-packages/firebase_functions/pubsub_fn.py", line 108, in _message_handler
time = _dt.datetime.strptime(
^^^^^^^^^^^^^^^^^^^^^^
File "/layers/google.python.runtime/python/lib/python3.11/_strptime.py", line 568, in _strptime_datetime
tt, fraction, gmtoff_fraction = _strptime(data_string, format)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/layers/google.python.runtime/python/lib/python3.11/_strptime.py", line 349, in _strptime
raise ValueError("time data %r does not match format %r" %
ValueError: time data '2023-06-13T15:17:49Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'

[xSavian]

Release exist with this fix? I'm still have this issue sometimes