Sporadic datetime parse error #160

jacobg · 2023-11-13T13:08:56Z

The following error occurred once on my pubsub function. It's otherwise run fine hundreds of times without any issue.

Traceback (most recent call last):
  File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 2190, in wsgi_app
    response = self.full_dispatch_request()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 1486, in full_dispatch_request
    rv = self.handle_user_exception(e)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 1484, in full_dispatch_request
    rv = self.dispatch_request()
         ^^^^^^^^^^^^^^^^^^^^^^^
  File "/layers/google.python.pip/pip/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 "/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-11-13T12:30:23Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'

Why would that occur?

antont · 2023-11-13T14:56:09Z

are you using the latest release? #149

jacobg · 2023-11-13T14:58:43Z

firebase_functions~=0.1.1

Oh, does 0.1.2 fix this issue?
https://github.com/firebase/firebase-functions-python/pull/137/files

jacobg · 2023-11-13T15:00:41Z

Not sure it's fixed, but checking.... The issue you linked is for firestore, but my error is in pubsub function.

jacobg · 2023-11-13T15:06:04Z

From examining the firebase-functions-python code and commits, it doesn't seem fixed but maybe I'm missing something. Is your understanding that the issue is also fixed for pubsub functions?

antont · 2023-11-13T15:09:06Z

From examining the firebase-functions-python code and commits, it doesn't seem fixed but maybe I'm missing something. Is your understanding that the issue is also fixed for pubsub functions?

I don't know, but I'd assume though that datetime parsing is not in many places. I only saw the issue and fix passing by here on github earlier, I don't know anything else.

exaby73 · 2023-12-04T11:54:46Z

@jacobg Could you confirm on the status of this? If not fixed by 0.1.2, then please let me know and I can investigate further

jacobg · 2023-12-04T12:13:37Z

Hi @exaby73 I have not seen the error since bumping to 0.1.2, but I'm not sure that's a proof because it only happened once to me in the old version. I think it occurred when the event timestamp was exactly 0 milliseconds and so the formatted string left off the sub-second part.

exaby73 · 2023-12-18T11:59:46Z

Could you give me an example of a error timestamp you observed to be causing this error? Even if this is fixed, we can add tests for this

koenmtb1 · 2024-02-13T15:34:04Z

I'm still getting this issue. It seems to happen before it gets to any of the logic in the function itself. It persists between retries. I'm on the latest version firebase-functions = "^0.2.0"

ERROR 2024-02-13T15:30:18.399925Z Traceback (most recent call last): File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 1463, in wsgi_app response = self.full_dispatch_request()
DEFAULT 2024-02-13T15:30:18.399930Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.399936Z File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 872, in full_dispatch_request
DEFAULT 2024-02-13T15:30:18.399941Z rv = self.handle_user_exception(e)
DEFAULT 2024-02-13T15:30:18.399945Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.399950Z File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 870, in full_dispatch_request
DEFAULT 2024-02-13T15:30:18.399954Z rv = self.dispatch_request()
DEFAULT 2024-02-13T15:30:18.399959Z ^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.399964Z File "/layers/google.python.pip/pip/lib/python3.11/site-packages/flask/app.py", line 855, in dispatch_request
DEFAULT 2024-02-13T15:30:18.399969Z return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args) # type: ignore[no-any-return]
DEFAULT 2024-02-13T15:30:18.399973Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.399978Z File "/layers/google.python.pip/pip/lib/python3.11/site-packages/functions_framework/__init__.py", line 178, in view_func
DEFAULT 2024-02-13T15:30:18.399982Z function(event)
DEFAULT 2024-02-13T15:30:18.399987Z File "/layers/google.python.pip/pip/lib/python3.11/site-packages/firebase_functions/pubsub_fn.py", line 184, in on_message_published_wrapped
DEFAULT 2024-02-13T15:30:18.399991Z return _message_handler(func, raw)
DEFAULT 2024-02-13T15:30:18.399994Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.400003Z File "/layers/google.python.pip/pip/lib/python3.11/site-packages/firebase_functions/pubsub_fn.py", line 108, in _message_handler
DEFAULT 2024-02-13T15:30:18.400007Z time = _dt.datetime.strptime(
DEFAULT 2024-02-13T15:30:18.400010Z ^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.400015Z File "/layers/google.python.runtime/python/lib/python3.11/_strptime.py", line 568, in _strptime_datetime
DEFAULT 2024-02-13T15:30:18.400019Z tt, fraction, gmtoff_fraction = _strptime(data_string, format)
DEFAULT 2024-02-13T15:30:18.400024Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-02-13T15:30:18.400028Z File "/layers/google.python.runtime/python/lib/python3.11/_strptime.py", line 349, in _strptime
DEFAULT 2024-02-13T15:30:18.400032Z raise ValueError("time data %r does not match format %r" %
DEFAULT 2024-02-13T15:30:19.463180Z ValueError: time data '2024-02-13T15:07:18Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'

scottynoshotty · 2024-05-11T20:40:19Z

I saw this across 3 of my cloud functions this morning.

ValueError: time data '2024-05-11T05:54:28Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'

ValueError: time data '2024-05-11T05:54:28Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'

ValueError: time data '2024-05-11T05:54:28Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'

Each of them Python Firebase Cloud Functions triggered via pub sub with these dependencies

firebase_functions~=0.4.1
google-cloud-pubsub~=2.18.3

scottynoshotty · 2024-05-12T14:53:06Z

Saw this again this morning. Here is a more complete stack trace. Appears to error before the function ever starts

DEFAULT 2024-05-12T03:25:44.286622Z ValueError: time data '2024-05-12T03:25:42Z' does not match format '%Y-%m-%dT%H:%M:%S.%f%z'
DEFAULT 2024-05-12T03:25:43.191304Z raise ValueError("time data %r does not match format %r" %
DEFAULT 2024-05-12T03:25:43.191298Z File "/layers/google.python.runtime/python/lib/python3.12/_strptime.py", line 333, in _strptime
DEFAULT 2024-05-12T03:25:43.191295Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-05-12T03:25:43.191291Z tt, fraction, gmtoff_fraction = _strptime(data_string, format)
DEFAULT 2024-05-12T03:25:43.191288Z File "/layers/google.python.runtime/python/lib/python3.12/_strptime.py", line 554, in _strptime_datetime
DEFAULT 2024-05-12T03:25:43.191285Z ^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-05-12T03:25:43.191282Z time = _dt.datetime.strptime(
DEFAULT 2024-05-12T03:25:43.191279Z File "/layers/google.python.pip/pip/lib/python3.12/site-packages/firebase_functions/pubsub_fn.py", line 108, in _message_handler
DEFAULT 2024-05-12T03:25:43.191276Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-05-12T03:25:43.191273Z return _message_handler(func, raw)
DEFAULT 2024-05-12T03:25:43.191269Z File "/layers/google.python.pip/pip/lib/python3.12/site-packages/firebase_functions/pubsub_fn.py", line 184, in on_message_published_wrapped
DEFAULT 2024-05-12T03:25:43.191265Z function(event)
DEFAULT 2024-05-12T03:25:43.191261Z File "/layers/google.python.pip/pip/lib/python3.12/site-packages/functions_framework/__init__.py", line 178, in view_func
DEFAULT 2024-05-12T03:25:43.191258Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-05-12T03:25:43.191254Z return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
DEFAULT 2024-05-12T03:25:43.191251Z File "/layers/google.python.pip/pip/lib/python3.12/site-packages/flask/app.py", line 1469, in dispatch_request
DEFAULT 2024-05-12T03:25:43.191247Z ^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-05-12T03:25:43.191244Z rv = self.dispatch_request()
DEFAULT 2024-05-12T03:25:43.191241Z File "/layers/google.python.pip/pip/lib/python3.12/site-packages/flask/app.py", line 1484, in full_dispatch_request
DEFAULT 2024-05-12T03:25:43.191237Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEFAULT 2024-05-12T03:25:43.191233Z rv = self.handle_user_exception(e)
DEFAULT 2024-05-12T03:25:43.191229Z File "/layers/google.python.pip/pip/lib/python3.12/site-packages/flask/app.py", line 1486, in full_dispatch_request
DEFAULT 2024-05-12T03:25:43.191225Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
ERROR 2024-05-12T03:25:43.191215Z Traceback (most recent call last): File "/layers/google.python.pip/pip/lib/python3.12/site-packages/flask/app.py", line 2190, in wsgi_app response = self.full_dispatch_request()
DEFAULT 2024-05-12T03:25:43.191171Z [2024-05-12 03:25:43,178] ERROR in app: Exception on / [POST]
INFO 2024-05-12T03:25:43.150808Z https://publish-post-data-on-feed-reaction-ikiqidi4rq-uc.a.run.app/?__GCP_CloudEventsMode=CUSTOM_PUBSUB_projects%2Fclaptrap-project%2Ftopics%2Fnew-feed-reaction

mrares · 2024-06-06T20:18:48Z

This issue also affects Firebase Realtime DB functions such as db_fn.on_value_created (the issue is present in the db_fn _db_endpoint_handler method)

mrares · 2024-06-11T12:44:58Z

In order to protect from this insanity I've created the following function wrapper which I apply on all my cloud functions

import functools, logging

from config import LOG_LEVEL
log = logging.getLogger(__name__)
log.setLevel(LOG_LEVEL)

def timeMolester():

    def timeMolesterDecorator(func):

        @functools.wraps(func)
        def wrapper(raw):

            for timekey in ["time", "publish_time"]:
                time = raw[timekey] if timekey in raw else None

                if time is None:
                    continue

                if "." not in time:
                    after = time.replace("Z", ".000000Z")
                    log.error("Time was PATCHED because Google is stupid (before: %s  after: %s)" % (time, after))
                    raw[timekey] = after

            ret = func(raw)
            return ret
        return wrapper

    return timeMolesterDecorator

exaby73 added the waiting for customer response Issue is on hold awaiting more information from OP label Dec 4, 2023

koenmtb1 mentioned this issue Feb 14, 2024

fix: Check for no microseconds in timestamp for pubsub message handler #176

Closed

exaby73 mentioned this issue Apr 4, 2024

Time data format error #185

Closed

exaby73 mentioned this issue May 15, 2024

feat: fix datetime parse error #204

Merged

taeold closed this as completed in #204 Jun 17, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Sporadic datetime parse error #160

Sporadic datetime parse error #160

jacobg commented Nov 13, 2023

antont commented Nov 13, 2023

jacobg commented Nov 13, 2023

jacobg commented Nov 13, 2023

jacobg commented Nov 13, 2023

antont commented Nov 13, 2023

exaby73 commented Dec 4, 2023

jacobg commented Dec 4, 2023

exaby73 commented Dec 18, 2023

koenmtb1 commented Feb 13, 2024 •

edited

Loading

scottynoshotty commented May 11, 2024

scottynoshotty commented May 12, 2024

mrares commented Jun 6, 2024

mrares commented Jun 11, 2024 •

edited

Loading

Sporadic datetime parse error #160

Sporadic datetime parse error #160

Comments

jacobg commented Nov 13, 2023

antont commented Nov 13, 2023

jacobg commented Nov 13, 2023

jacobg commented Nov 13, 2023

jacobg commented Nov 13, 2023

antont commented Nov 13, 2023

exaby73 commented Dec 4, 2023

jacobg commented Dec 4, 2023

exaby73 commented Dec 18, 2023

koenmtb1 commented Feb 13, 2024 • edited Loading

scottynoshotty commented May 11, 2024

scottynoshotty commented May 12, 2024

mrares commented Jun 6, 2024

mrares commented Jun 11, 2024 • edited Loading

koenmtb1 commented Feb 13, 2024 •

edited

Loading

mrares commented Jun 11, 2024 •

edited

Loading