Firestore [Violation] 'setTimeout' handler took [n]ms index.esm2017.js:15504

[RaheutRahwana]

Operating System

Debian GNU/Linux 12 (bookworm)

Browser Version

Chromium 119.0.6045.159 (Official Build) snap (64-bit)

Firebase SDK Version

9.8.2

Firebase SDK Product:

Firestore

Describe your project's tooling

Browser modules.

Describe the problem

Firestore returns [Violation] 'setTimeout' handler took [n]ms index.esm2017.js:15504 when data does not exist.

The program works as expected. I just wonder what's with that Violation. It has never occurred before. AFAIK

log:

    "_query": {
        "path": {
            "segments": [
                "serem"
            ],
            "offset": 0,
            "len": 1
        },
        "collectionGroup": null,
        "explicitOrderBy": [],
        "filters": [
            {
                "field": {
                    "segments": [
                        "reminder_service_date"
                    ],
                    "offset": 0,
                    "len": 1
                },
                "op": ">=",
                "value": {
                    "stringValue": "11/27/2023"
                }
            },
            {
                "field": {
                    "segments": [
                        "reminder_service_date"
                    ],
                    "offset": 0,
                    "len": 1
                },
                "op": "<",
                "value": {
                    "stringValue": "11/28/2023"
                }
            }
        ],
        "limit": 111,
        "limitType": "F",
        "startAt": null,
        "endAt": null,
        "D": [
            {
                "field": {
                    "segments": [
                        "reminder_service_date"
                    ],
                    "offset": 0,
                    "len": 1
                },
                "dir": "asc"
            },
            {
                "field": {
                    "segments": [
                        "__name__"
                    ],
                    "offset": 0,
                    "len": 1
                },
                "dir": "asc"
            }
        ],
        "C": {
            "path": {
                "segments": [
                    "serem"
                ],
                "offset": 0,
                "len": 1
            },
            "collectionGroup": null,
            "orderBy": [
                {
                    "field": {
                        "segments": [
                            "reminder_service_date"
                        ],
                        "offset": 0,
                        "len": 1
                    },
                    "dir": "asc"
                },
                {
                    "field": {
                        "segments": [
                            "__name__"
                        ],
                        "offset": 0,
                        "len": 1
                    },
                    "dir": "asc"
                }
            ],
            "filters": [
                {
                    "field": {
                        "segments": [
                            "reminder_service_date"
                        ],
                        "offset": 0,
                        "len": 1
                    },
                    "op": ">=",
                    "value": {
                        "stringValue": "11/27/2023"
                    }
                },
                {
                    "field": {
                        "segments": [
                            "reminder_service_date"
                        ],
                        "offset": 0,
                        "len": 1
                    },
                    "op": "<",
                    "value": {
                        "stringValue": "11/28/2023"
                    }
                }
            ],
            "limit": 111,
            "startAt": null,
            "endAt": null,
            "P": "serem|f:reminder_service_date>=11/27/2023,reminder_service_date<11/28/2023|ob:reminder_service_dateasc,__name__asc|l:111"
        }
    }

Steps and code to reproduce issue

code:

onSnapshot(
    query(
        collection(firestore, location.pathname),
        where("reminder_service_date", ">=", reminder_service_date_start),
        where("reminder_service_date", "<", reminder_service_date_end),
        limit(111)
    ),
    ({docs}) => {
        if (docs.length) {
            console.log(docs);
        } else {
            console.log("204 No Content");
        }
    },
    (error) => console.error(error)
);

[milaGGL]

Hi @RaheutRahwana, thank you for reporting this issue. I didn't see the [Violation] 'setTimeout' handler took [n]ms in the log you provided, and I am unable to reproduce the error with the code above.

I wonder if this is a Firestore related problem. Could you please enable debug logs and share the output? To enable debug logs, call setLogLevel('debug') (https://firebase.google.com/docs/reference/js/firestore_#setloglevel).

[RaheutRahwana]

Hi @milaGGL, thank you for the quick response. Here is the debug logs output. The "Violation" warning happens only if the data does not exist.

logger.ts:115 [2023-11-28T03:29:19.954Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: Execute query
logger.ts:115 [2023-11-28T03:29:19.954Z]  @firebase/firestore: Firestore (9.8.2): QueryEngine Using full collection scan to execute query: Query(target=Target(serem, filters: [reminder_service_date >= 11/28/2023, reminder_service_date < 11/29/2023], limit: 111, orderBy: [reminder_service_date (asc), __name__ (asc)]); limitType=F)
logger.ts:115 [2023-11-28T03:29:20.245Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"targetChangeType":"REMOVE","targetIds":[2]}}
logger.ts:115 [2023-11-28T03:29:20.565Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"targetChangeType":"ADD","targetIds":[4]}}
logger.ts:115 [2023-11-28T03:29:20.869Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"targetChangeType":"CURRENT","targetIds":[4],"resumeToken":"CgkIzq64seDlggM=","readTime":"2023-11-28T03:29:20.349006Z"}}
logger.ts:115 [2023-11-28T03:29:20.870Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"resumeToken":"CgkIzq64seDlggM=","readTime":"2023-11-28T03:29:20.349006Z"}}
logger.ts:115 [2023-11-28T03:29:20.870Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"targetChangeType":"RESET","targetIds":[4],"resumeToken":"CgA="}}
logger.ts:115 [2023-11-28T03:29:20.871Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"targetChangeType":"CURRENT","targetIds":[4],"resumeToken":"CgkIutm9seDlggM=","readTime":"2023-11-28T03:29:20.436410Z"}}
logger.ts:115 [2023-11-28T03:29:20.871Z]  @firebase/firestore: Firestore (9.8.2): Connection WebChannel received: {"targetChange":{"resumeToken":"CgkIutm9seDlggM=","readTime":"2023-11-28T03:29:20.436410Z"}}
logger.ts:115 [2023-11-28T03:29:20.872Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: Get last remote snapshot version
logger.ts:115 [2023-11-28T03:29:20.873Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: Apply remote event
logger.ts:115 [2023-11-28T03:29:20.873Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: notifyLocalViewChanges
logger.ts:115 [2023-11-28T03:29:20.874Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: Get last remote snapshot version
logger.ts:115 [2023-11-28T03:29:20.875Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: Apply remote event
logger.ts:115 [2023-11-28T03:29:20.875Z]  @firebase/firestore: Firestore (9.8.2): MemoryPersistence Starting transaction: notifyLocalViewChanges
index.esm2017.js:15504 [Violation] 'setTimeout' handler took 1605ms

[RaheutRahwana]

I just found the problem a short while after replying to the last post. It is window.alert("204 No Content");

onSnapshot(
    query(
        collection(firestore, location.pathname),
        where("reminder_service_date", ">=", reminder_service_date_start),
        where("reminder_service_date", "<", reminder_service_date_end),
        limit(111)
    ),
    ({docs}) => {
        if (docs.length) {
            console.log(docs);
        } else {
            window.alert("204 No Content"); //This is the cause.
        }
    },
    (error) => console.error(error)
);

[DellaBitta]

Hi @RaheutRahwana,

window.alert waits until the alert dialog box has been dismissed. The violation might be due to the fact that there's a too long of a delay in the setTimeout handler (which is waiting for the user to dismiss the alert box) that goes beyond the timeout the runtime expects of the handler. Could you try logging to the console, or displaying some other error message that immediately returns, and see if the Violation log goes away?

Thanks!

[RaheutRahwana]

Hi @DellaBitta,
Sure. I have found that the window.alert function is the only cause of the Violation log so far.

[DellaBitta]

Hi @RaheutRahwana,

Ok, great. Please let us know if the error ends up being part of Firestore's behavior in your subsequent testing.