Emulator - Functions CloudEvent timestamp format mismatch

[Balazs23]

[REQUIRED] Environment info

firebase-tools: 12.2.0

Platform: Mac M1, running linux devcontainer

[REQUIRED] Test case

I tested the sample firestore function code from firebase-functions-python library with the emulator (v1.17.4) and the event trigger with the library was failed, because of the wrong timestamp format in CloudEvent object.

Current version of 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. From the logs the emulator CloudEvent trigger timestamp is 2023-05-24T18:33:00.900823421Z and the fractional seconds component 900823421 exceeds the six-digit limit specified by the RFC.

This is my previous test result, first opened an issue on python library side: firebase/firebase-functions-python#95 (comment)

[REQUIRED] Steps to reproduce

Use firebase-functions-python basic firestore sample, run the emulator and create a hello document.

[REQUIRED] Expected behavior

Matching timestamp format

[REQUIRED] Actual behavior

[debug] [2023-05-24T18:33:00.921Z] [work-queue] {"queuedWork":["/functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0-2023-05-24T18:33:00.920Z"],"queueLength":1,"runningWork":[],"workRunningCount":0}
[debug] [2023-05-24T18:33:00.921Z] [work-queue] {"queuedWork":[],"queueLength":0,"runningWork":["/functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0-2023-05-24T18:33:00.920Z"],"workRunningCount":1}
[debug] [2023-05-24T18:33:00.922Z] Accepted request POST /functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0 --> europe-west1-onfirestoredocumentwritten-0
[debug] [2023-05-24T18:33:00.923Z] [functions] Runtime ready! Sending request! {"metadata":{"emulator":{"name":"functions"},"message":"[functions] Runtime ready! Sending request!"}}
[debug] [2023-05-24T18:33:00.926Z] [functions] Got req.url=/functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0, mapping to path=/functions/projects/ {"metadata":{"emulator":{"name":"functions"},"message":"[functions] Got req.url=/functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0, mapping to path=/functions/projects/"}}
[debug] [2023-05-24T18:33:00.933Z] Running command with virtualenv: command=., args=["\"/workspaces/firebase-sample/cloud-functions/venv/bin/activate\"","&&","functions-framework"]
[debug] [2023-05-24T18:33:00.953Z] [worker-pool] addWorker(europe-west1-onfirestoredocumentwritten) {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] addWorker(europe-west1-onfirestoredocumentwritten)"}}
[debug] [2023-05-24T18:33:00.955Z] [worker-pool] Adding worker with key europe-west1-onfirestoredocumentwritten, total=1 {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] Adding worker with key europe-west1-onfirestoredocumentwritten, total=1"}}
[debug] [2023-05-24T18:33:01.070Z] May 24, 2023 6:33:01 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected non-HTTP/2 connection.
 {"metadata":{"emulator":{"name":"firestore"},"message":"May 24, 2023 6:33:01 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead\nINFO: Detected non-HTTP/2 connection.\n"}}
[debug] [2023-05-24T18:33:02.072Z] [worker-europe-west1-onfirestoredocumentwritten-256fb3eb-b43e-4da6-b004-2c509a272950]: IDLE {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"[worker-europe-west1-onfirestoredocumentwritten-256fb3eb-b43e-4da6-b004-2c509a272950]: IDLE"}}
[debug] [2023-05-24T18:33:02.073Z] [worker-pool] submitRequest(triggerId=europe-west1-onfirestoredocumentwritten) {"metadata":{"emulator":{"name":"functions"},"message":"[worker-pool] submitRequest(triggerId=europe-west1-onfirestoredocumentwritten)"}}
[info] i  functions: Beginning execution of "europe-west1-onfirestoredocumentwritten" {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"Beginning execution of \"europe-west1-onfirestoredocumentwritten\""}}
[debug] [2023-05-24T18:33:02.074Z] [worker-europe-west1-onfirestoredocumentwritten-256fb3eb-b43e-4da6-b004-2c509a272950]: BUSY {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"[worker-europe-west1-onfirestoredocumentwritten-256fb3eb-b43e-4da6-b004-2c509a272950]: BUSY"}}
[info] >  [2023-05-24 18:33:02,082] ERROR in app: Exception on /functions/projects/ [POST] {"user":"[2023-05-24 18:33:02,082] ERROR in app: Exception on /functions/projects/ [POST]","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m [2023-05-24 18:33:02,082] ERROR in app: Exception on /functions/projects/ [POST]"}}
[info] >  Traceback (most recent call last): {"user":"Traceback (most recent call last):","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m Traceback (most recent call last):"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py", line 2190, in wsgi_app {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 2190, in wsgi_app","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 2190, in wsgi_app"}}
[info] >      response = self.full_dispatch_request() {"user":"    response = self.full_dispatch_request()","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     response = self.full_dispatch_request()"}}
[info] >                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ {"user":"               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py", line 1486, in full_dispatch_request {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 1486, in full_dispatch_request","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 1486, in full_dispatch_request"}}
[info] >      rv = self.handle_user_exception(e) {"user":"    rv = self.handle_user_exception(e)","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     rv = self.handle_user_exception(e)"}}
[info] >           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ {"user":"         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py", line 1484, in full_dispatch_request {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 1484, in full_dispatch_request","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 1484, in full_dispatch_request"}}
[info] >      rv = self.dispatch_request() {"user":"    rv = self.dispatch_request()","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     rv = self.dispatch_request()"}}
[info] >           ^^^^^^^^^^^^^^^^^^^^^^^ {"user":"         ^^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m          ^^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py", line 1469, in dispatch_request {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 1469, in dispatch_request","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/flask/app.py\", line 1469, in dispatch_request"}}
[info] >      return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args) {"user":"    return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)"}}
[info] >             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ {"user":"           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/functions_framework/__init__.py", line 174, in view_func {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/functions_framework/__init__.py\", line 174, in view_func","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/functions_framework/__init__.py\", line 174, in view_func"}}
[info] >      function(event) {"user":"    function(event)","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     function(event)"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py", line 208, in on_document_written_wrapped {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py\", line 208, in on_document_written_wrapped","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py\", line 208, in on_document_written_wrapped"}}
[info] >      return _firestore_endpoint_handler( {"user":"    return _firestore_endpoint_handler(","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     return _firestore_endpoint_handler("}}
[info] >             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ {"user":"           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py", line 114, in _firestore_endpoint_handler {"user":"  File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py\", line 114, in _firestore_endpoint_handler","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/workspaces/firebase-sample/cloud-functions/venv/lib/python3.11/site-packages/firebase_functions/firestore_fn.py\", line 114, in _firestore_endpoint_handler"}}
[info] >      event_time = _dt.datetime.strptime( {"user":"    event_time = _dt.datetime.strptime(","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     event_time = _dt.datetime.strptime("}}
[info] >                   ^^^^^^^^^^^^^^^^^^^^^^ {"user":"                 ^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m                  ^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/usr/local/lib/python3.11/_strptime.py", line 568, in _strptime_datetime {"user":"  File \"/usr/local/lib/python3.11/_strptime.py\", line 568, in _strptime_datetime","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/usr/local/lib/python3.11/_strptime.py\", line 568, in _strptime_datetime"}}
[info] >      tt, fraction, gmtoff_fraction = _strptime(data_string, format) {"user":"    tt, fraction, gmtoff_fraction = _strptime(data_string, format)","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     tt, fraction, gmtoff_fraction = _strptime(data_string, format)"}}
[info] >                                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ {"user":"                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m                                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^"}}
[info] >    File "/usr/local/lib/python3.11/_strptime.py", line 349, in _strptime {"user":"  File \"/usr/local/lib/python3.11/_strptime.py\", line 349, in _strptime","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m   File \"/usr/local/lib/python3.11/_strptime.py\", line 349, in _strptime"}}
[info] >      raise ValueError("time data %r does not match format %r" % {"user":"    raise ValueError(\"time data %r does not match format %r\" %","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m     raise ValueError(\"time data %r does not match format %r\" %"}}
[info] >  ValueError: time data '2023-05-24T18:33:00.900823421Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z' {"user":"ValueError: time data '2023-05-24T18:33:00.900823421Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'","metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"\u001b[90m> \u001b[39m ValueError: time data '2023-05-24T18:33:00.900823421Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'"}}
[debug] [2023-05-24T18:33:02.092Z] Finishing up request with event=pause {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"Finishing up request with event=pause"}}
[info] i  functions: Finished "europe-west1-onfirestoredocumentwritten" in 18.678208ms {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"Finished \"europe-west1-onfirestoredocumentwritten\" in 18.678208ms"}}
[debug] [2023-05-24T18:33:02.093Z] [worker-europe-west1-onfirestoredocumentwritten-256fb3eb-b43e-4da6-b004-2c509a272950]: IDLE {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"[worker-europe-west1-onfirestoredocumentwritten-256fb3eb-b43e-4da6-b004-2c509a272950]: IDLE"}}
[debug] [2023-05-24T18:33:02.093Z] Finishing up request with event=finish {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"Finishing up request with event=finish"}}
[debug] [2023-05-24T18:33:02.093Z] Finishing up request with event=close {"metadata":{"emulator":{"name":"functions"},"function":{"name":"europe-west1-onfirestoredocumentwritten"},"extension":{},"message":"Finishing up request with event=close"}}
[debug] [2023-05-24T18:33:02.093Z] [work-queue] {"queuedWork":[],"queueLength":0,"runningWork":[],"workRunningCount":0}
[debug] [2023-05-24T18:33:02.098Z] May 24, 2023 6:33:02 PM com.google.cloud.datastore.emulator.impl.events.FunctionsEmulatorEventPublisher sendHttpRequestV2
WARNING: Unsuccessful HTTP response when publishing v2 event for projects/trmc-test/eventarcTriggers/europe-west1-onfirestoredocumentwritten-0: 500 Internal Server Error
POST http://127.0.0.1:5001/functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0
500 Internal Server Error: The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application.
 {"metadata":{"emulator":{"name":"firestore"},"message":"May 24, 2023 6:33:02 PM com.google.cloud.datastore.emulator.impl.events.FunctionsEmulatorEventPublisher sendHttpRequestV2\nWARNING: Unsuccessful HTTP response when publishing v2 event for projects/trmc-test/eventarcTriggers/europe-west1-onfirestoredocumentwritten-0: 500 Internal Server Error\nPOST http://127.0.0.1:5001/functions/projects/trmc-test/triggers/europe-west1-onfirestoredocumentwritten-0\n500 Internal Server Error: The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application.\n"}}
[debug] [2023-05-24T18:33:10.159Z] Received signal SIGINT (Ctrl-C) 1

[aalej]

Hi @Balazs23, apologies for the delay. I’ve been trying to reproduce the behavior you mentioned, but so far I haven’t encountered any issues.

I used the code provided in https://github.com/firebase/firebase-functions-python/tree/main/samples/basic_firestore, and started the emulator. After creating a document in a collection called hello via the Firestore emulator UI, europe-west1-onfirestoredocumentwritten started executing and no errors were raised during execution.

I also tried following the steps provided in https://firebase.google.com/docs/functions/get-started?gen=2nd and no errors were raised as well.

I’m not sure if I may be missing something here, could you provide an MCVE where the issue is reproducible so that I can try it out on my end? This will help us narrow down the cause of the error. Thanks!

I’m using the following to reproduce the issue:

• Firebase Tools: v12.2.1
• Platform: macOS Intel
• Python: v3.11.3
• firebase_functions: v0.1.0

[arturoszulc]

I have the exact same problem, using very simple Cloud Function:

from firebase_functions.firestore_fn import (
  on_document_created,
  Event,
  DocumentSnapshot,
)

@on_document_created(document="test/{testId}")
def hello(event: Event[DocumentSnapshot]) -> None:
    print("hello")

Tested on two different computers, both show the same problem.

My specs:

• Firebase Tools: v12.2.1
• Platform: Windows 11 notebook and Windows 10 PC
• Python: v3.11.3
• firebase_functions: v0.1.0

CF logs

>   * Serving Flask app 'hello'
>   * 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:8526
>  Press CTRL+C to quit
>  127.0.0.1 - - [30/May/2023 16:19:12] "GET /__/health HTTP/1.1" 405 -
i  functions: Beginning execution of "us-central1-hello"
>  [2023-05-30 16:19:12,246] ERROR in app: Exception on /functions/projects/ [POST]
>  Traceback (most recent call last):
>    File "C:\Users\artur\Desktop\sovo\functions\venv\Lib\site-packages\flask\app.py", line 2190, in wsgi_app
>      response = self.full_dispatch_request()
>                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\artur\Desktop\sovo\functions\venv\Lib\site-packages\flask\app.py", line 1486, in full_dispatch_request
>      rv = self.handle_user_exception(e)
>           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\artur\Desktop\sovo\functions\venv\Lib\site-packages\flask\app.py", line 1484, in full_dispatch_request
>      rv = self.dispatch_request()
>           ^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\artur\Desktop\sovo\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\artur\Desktop\sovo\functions\venv\Lib\site-packages\functions_framework\__init__.py", line 174, in view_func
>      function(event)
>    File "C:\Users\artur\Desktop\sovo\functions\venv\Lib\site-packages\firebase_functions\firestore_fn.py", line 302, in on_document_created_wrapped
>      return _firestore_endpoint_handler(
>             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Users\artur\Desktop\sovo\functions\venv\Lib\site-packages\firebase_functions\firestore_fn.py", line 114, in _firestore_endpoint_handler
>      event_time = _dt.datetime.strptime(
>                   ^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Python\Lib\_strptime.py", line 568, in _strptime_datetime
>      tt, fraction, gmtoff_fraction = _strptime(data_string, format)
>                                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>    File "C:\Python\Lib\_strptime.py", line 349, in _strptime
>      raise ValueError("time data %r does not match format %r" %
>  ValueError: time data '2023-05-30T16:19:11.403216500Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'
i  functions: Finished "us-central1-hello" in 30.6454ms
>  127.0.0.1 - - [30/May/2023 16:19:12] "POST /functions/projects/ HTTP/1.1" 500 -

[arturoszulc]

Additional investigation: some of the triggers pass. But it seems random and is very rare. Printed out event.time of such success occurences:

• 2023-05-30 16:38:44.125462+00:00
• 2023-05-30 16:50:57.973567+00:00
• 2023-05-30 16:57:56.296453+00:00
• 2023-05-30 16:59:16.467347+00:00

Unfortunately most of the triggers fail. Those have timestamps like this (taken from error log):

• 2023-05-30T16:38:23.382509200Z
• 2023-05-30T16:39:08.858897500Z
• 2023-05-30T16:46:02.993736200Z
• 2023-05-30T16:59:15.427840800Z

[inlined]

I'm additionally unable to reproduce this error. I've tried using timestamp fields or expecting built-in timestamps to fail. I've tried this in the emulator and I've tried this in prod.

Given that both Google employees are trying unsuccessfully to reproduce this on macOS and the reporters are in linux and windows, I'm going to assume this bug is OS specific. I won't have access to a non-macOS machine for a while, so I'll ask others to step in.

As an aside, where are you getting the restriction that the fractional time portion can only be six digits? I'm not seeing that in the grammar section of the RFC

[inlined]

Confirmed that unix/linux produce timestamps with up to 9 digits of precision, which is a valid timestamp but Python chokes. Apparently arrow had this problem. Will dig into how they solved it. Alternatively we can maybe just prevent the emulator from producing timestamps this granular.

[inlined]

After further investigation, I think it is relatively unlikely that Google will produce nanosecond precision timestamps in production. I'm going to call this an emulator bug for now and ask the Firestore team to reduce timestamp precision on linux/WSL