firebase-tools icon indicating copy to clipboard operation
firebase-tools copied to clipboard

Firestore emulator calls functions twice on startup

Open ryanadrig opened this issue 5 months ago • 3 comments

[REQUIRED] Environment info

firebase-tools: 14.6.0

Platform: Ubuntu 24.10

[REQUIRED] Test case

Create a python functions instance with initialize_app() and db = firestore.client(). Create a function that inserts 100 documents in a while loop (also works with batched write) inserting with db.collection("collection_name").document().set(<doc>) start emulator with firebase emulators:start

[REQUIRED] Steps to reproduce

Run endpoint with curl or API testing tool (I'm using insomnia).

[REQUIRED] Expected behavior

Expect inserts to be called once

[REQUIRED] Actual behavior

Function is run twice, inserting documents twice. When the function runs twice, I see Jun 18, 2025 9:03:27 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead INFO: Detected HTTP/2 connection. in firestore-debug.log. I see this when running other functions for the first time, including read all with fdb.collection("collection_name").stream() and always get the channelRead log when runs twice, but after running it again it runs once as expected with no log.

I've seen these articles https://firebase.google.com/docs/functions/tips https://cloud.google.com/blog/products/serverless/cloud-functions-pro-tips-building-idempotent-functions suggesting idempotency but they imply this is only an issue for triggered background functions which have an eventID, these calls do not have an eventID. This video ( mostly the one before it https://www.youtube.com/watch?v=MzTS6mFDGjU&list=PLl-K7zZEsYLm9A9rcHb1IkyQUu6QwbjdM&t=3m22s just briefly says "background functions") also switches from cloud Functions to triggers/background functions when mentioning there could be duplicate runs https://www.youtube.com/watch?v=Pwsy8XR7HNE&t=12s And anything else I could find blamed CORS which would happen every request not once and stop, and the only http status I see is 200 not 204 like they say for CORS.

So I don't think this should be the behavior

ryanadrig avatar Jun 19 '25 05:06 ryanadrig

Hey @ryanadrig, thanks for reporting this and for sharing your observations. Let me know in case I misunderstood, but just to verify, are you invoking an https functions that creates 100 docs in Firestore emulator? Something like:

from firebase_functions import https_fn
from firebase_admin import initialize_app, firestore

initialize_app()


@https_fn.on_request()
def create_docs(req: https_fn.Request) -> https_fn.Response:
    # code that writes 100 docs
    return https_fn.Response("Hello world!")

And based on your observations, this function runs twice on its initial invocation(so it creates 200 docs instead of 100), but only once on subsequent runs.

Also, which version of python and firebase_functions are you using?

aalej avatar Jun 19 '25 15:06 aalej

@aalej Hi thanks for looking at this! Yes that is exactly it, was maybe expecting to get RTMd as expected behavior but couldn't find it in docs, so at minimum maybe a docs update, most basic setup I can get, with the addition of fdb = firestore.client() I call the loop

                i = 0
                i_lim = 100
                while i < i_lim:
                    i += 1
                    tsi = {"test":"test" ... }                    
                    fdb.collection("collection_name").document().set(tsi)

and it completes in under 1 second with status 200 response, twice in the mentioned fashion...

versions ~~

Python 3.12.7

pip show firebase-admin Name: firebase-admin Version: 6.9.0

pip freeze selected output ... firebase-admin==6.9.0 firebase-functions==0.1.2 google-api-core==2.25.0 google-api-python-client==2.171.0 google-auth==2.40.3 google-auth-httplib2==0.2.0 google-cloud-core==2.4.3 google-cloud-firestore==2.21.0 google-cloud-storage==3.1.0 google-crc32c==1.7.1 google-events==0.14.0 google-resumable-media==2.7.2 googleapis-common-protos==1.70.0 ... grpcio==1.72.1 grpcio-status==1.72.1 gunicorn==23.0.0 h11==0.16.0 h2==4.2.0 hpack==4.1.0 httpcore==1.0.9 httplib2==0.22.0 httpx==0.28.1 ...

ryanadrig avatar Jun 19 '25 15:06 ryanadrig

Thanks for verifying @ryanadrig! I'm able to reproduce the reported behavior, it looks like this is an issue with the Functions Emulator. As you mentioned, when invoking the function for the first time, it always runs twice. Even a simple https trigger function like below seems to run twice

@https_fn.on_request()
def py_test(req: https_fn.Request) -> https_fn.Response:
    print("PRINT_STATEMENT - SHOULD ONLY APPEAR ONCE!!!")
    return https_fn.Response("Hello world!")

When running curl http://127.0.0.1:5001/demo-project/us-central1/py_test for the first time, PRINT_STATEMENT - SHOULD ONLY APPEAR ONCE!!! is printed twice

>   * Serving Flask app 'py_test'
>   * Debug mode: on
>  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:8427
>  Press CTRL+C to quit
>   * Restarting with watchdog (fsevents)
>   * Debugger is active!
>   * Debugger PIN: 126-030-938
>  PRINT_STATEMENT - SHOULD ONLY APPEAR ONCE!!!
>  127.0.0.1 - - [19/Jun/2025 16:49:58] "GET /__/health HTTP/1.1" 200 -
i  functions: Beginning execution of "us-central1-py_test"
>  PRINT_STATEMENT - SHOULD ONLY APPEAR ONCE!!!
>  127.0.0.1 - - [19/Jun/2025 16:49:58] "GET / HTTP/1.1" 200 -
i  functions: Finished "us-central1-py_test" in 1.856375ms

I'm also not able to reproduce the issue when emulating a JavaScript function, so this seems like a bug specific to emulating Python Functions.

I'll raise this to our engineering team so they can take a look. Sharing the mcve here

aalej avatar Jun 19 '25 17:06 aalej

I have the same problem, any solution for this?

Emanuel-Bissacotti avatar Aug 26 '25 19:08 Emanuel-Bissacotti

@Emanuel-Bissacotti In the mean time I used this, has been working for me to avoid duplication

insert_lock = threading.Lock()
already_inserting = False
def mainEndpoint(request):
    global already_inserting

    if insert_lock.locked() or already_inserting:
        return jsonify({"success": False, "reason": "Inserting already in progress"}), 429

    def do_inserts():
        global already_inserting
        with insert_lock:
           # main function logic ...

        threading.Thread(target=do_inserts).start() 

    return jsonify({"success": True,
                    "reason": "mainEndpoint success"}, )

ryanadrig avatar Aug 27 '25 00:08 ryanadrig