@firebase/testing with jsdom@16 crashes with INTERNAL ASSERTION FAILED: Unexpected state

[tv42]

[REQUIRED] Describe your environment

• Operating System version: node:14.8-alpine3.12 docker image
• Browser version: n/a
• Firebase SDK version: @firebase/testing 0.20.11
• Firebase Product: firestore

[REQUIRED] Describe the problem

@firebase/firestore: Firestore (7.18.0): FIRESTORE (7.18.0) INTERNAL ASSERTION FAILED: Unexpected state

Steps to reproduce:

Start the firestore emulator in a different terminal, leave it running:
firebase emulators:start --only firestore

git clone https://github.com/zkohi/firebase-testing-samples
cd firebase-testing-samples
# upgrade @firebase/testing to show this is a current bug (also helps to reproduce
# simpler and quicker because newer version doesn't have the c++ dependency
# the older version did)
npm install @firebase/[email protected]
# demonstrate it works before upgrading jsdom
$ npm run test
[...] Test Suites: 1 passed, 1 total [...]
# that was with jsdom 15.2.1
$ npm list jsdom
[email protected] /src
`-- [email protected]
  `-- @jest/[email protected]
    `-- [email protected]
      `-- [email protected]
        `-- [email protected] 

# now let's upgrade jsdom (and to make that actually happen,
# jest-environment-jsdom and to make *that* happen, jest.
# maybe there's a better way but my npm skills end here.)
$ npm install jest@26
# this repo happens to use ts-jest, it's not relevant to the bug
# but stop it from complaining about mismatching versions
$ npm install ts-jest@26
$ npm list jsdom
[email protected] /src
`-- [email protected]
  `-- @jest/[email protected]
    `-- [email protected]
      `-- [email protected]
        `-- [email protected] 

# now we're ready for the explosion
$ npm run test
> [email protected] test /src
> FIREBASE_FIRESTORE_EMULATOR_ADDRESS='127.0.0.1:8080' jest

ts-jest[versions] (WARN) Version 3.7.5 of typescript installed has not been tested with ts-jest. If you're experiencing issues, consider using a supported version (>=3.8.0 <4.0.0-0). Please do not report issues in ts-jest if you are using unsupported versions.
  console.error
    [2020-08-18T16:54:08.870Z]  @firebase/firestore: Firestore (7.18.0): FIRESTORE (7.18.0) INTERNAL ASSERTION FAILED: Unexpected state

      at Logger.defaultLogHandler [as _logHandler] (node_modules/@firebase/logger/src/logger.ts:115:57)
      at Logger.error (node_modules/@firebase/logger/src/logger.ts:210:21)
      at logError (node_modules/@firebase/firestore/src/util/log.ts:45:20)
      at fail (node_modules/@firebase/firestore/src/util/assert.ts:34:3)
      at hardAssert (node_modules/@firebase/firestore/src/util/assert.ts:53:5)
      at fromBytes (node_modules/@firebase/firestore/src/remote/serializer.ts:272:5)
      at fromWatchChange (node_modules/@firebase/firestore/src/remote/serializer.ts:488:25)

(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 1)
(Use `node --trace-warnings ...` to show where the warning was created)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 3)
  console.error
    [2020-08-18T16:54:09.423Z]  @firebase/firestore: Firestore (7.18.0): FIRESTORE (7.18.0) INTERNAL ASSERTION FAILED: Unexpected state

      at Logger.defaultLogHandler [as _logHandler] (node_modules/@firebase/logger/src/logger.ts:115:57)
      at Logger.error (node_modules/@firebase/logger/src/logger.ts:210:21)
      at logError (node_modules/@firebase/firestore/src/util/log.ts:45:20)
      at fail (node_modules/@firebase/firestore/src/util/assert.ts:34:3)
      at hardAssert (node_modules/@firebase/firestore/src/util/assert.ts:53:5)
      at fromBytes (node_modules/@firebase/firestore/src/remote/serializer.ts:272:5)
      at fromWatchChange (node_modules/@firebase/firestore/src/remote/serializer.ts:488:25)

[...message repeats 10 more times...]
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 23)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 25)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 24)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 2)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 4)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 6)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 8)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 9)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 11)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 13)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 16)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 19)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 21)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 26)
(node:18) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 27)
FAIL __tests__/firestore.rules.test.ts (11.339 s)
  firestore.rules
    /users/{user}
      create
        ✓ should not let logged out users create (199 ms)
        ✓ should not let logged in users create (115 ms)
        ✓ should not let admin create (71 ms)
      read
        ✕ should not let logged out users read (503 ms)
        ✕ should only let logged in users read own (43 ms)
        ✕ should not let admin read (142 ms)
      update
        ✕ should not let logged out users update (125 ms)
        ✕ should not let logged in users update own (56 ms)
        ✕ should not let admin update (68 ms)
      delete
        ✓ should not let logged out users delete (118 ms)
        ✓ should not let logged in users delete own (65 ms)
        ✓ should not let admin delete (70 ms)
    /admins/{admin}
      create
        ✓ should not let logged out users create (62 ms)
        ✓ should not let logged in users create (53 ms)
        ✓ should not let admin create (62 ms)
      read
        ✕ should not let logged out users read (72 ms)
        ✕ should not let logged in users read own (29 ms)
        ✕ should only let admin read (62 ms)
      update
        ✕ should not let logged out users update (64 ms)
        ✕ should not let logged in users update own (42 ms)
        ✓ should not let admin update (139 ms)
      delete
        ✓ should not let logged out users delete (63 ms)
        ✓ should not let logged in users delete own (78 ms)
        ✓ should not let admin delete (75 ms)
    /rooms/{room}
      create
        ✓ should not let logged out users create (58 ms)
        ✓ should let logged in users create room that owner is themselves (94 ms)
        ✓ should request.resource.data.keys().hasAll(['owner', 'name']) (205 ms)
        ✓ should request.resource.data.name is string (186 ms)
        ✓ should request.resource.data.name.size() > 0 (127 ms)
        ✓ should not let admin create (89 ms)
      read
        ✕ should not let logged out users read (422 ms)
        ✕ should let logged in users read own (109 ms)
        ✕ should only let admin read (138 ms)
      update
        ✕ should not let logged out users update (85 ms)
        ✕ should let logged in users update room that owner is themselves (66 ms)
        ✕ should request.resource.data.name is string (133 ms)
        ✕ should request.resource.data.name.size() > 0 (56 ms)
        ✕ should let admin update (91 ms)
        ✓ should request.resource.data.owner does not change (663 ms)
      delete
        ✓ should not let logged out users delete (108 ms)
        ✓ should not let logged in users delete own (60 ms)
        ✓ should not let admin delete (95 ms)
      /rooms/{room}/messages/{message}
        create
          ✓ should not let logged out users create (132 ms)
          ✓ should let logged in users create room message that owner is themselves (162 ms)
          ✓ should request.resource.data.keys().hasAll(['text']) (134 ms)
          ✓ should request.resource.data.text is string (122 ms)
          ✓ should request.resource.data.name.size() > 0 (120 ms)
        batched write
          ✓ should request.auth.uid == resource.data.owner on batch create (109 ms)
        read
          ✕ should not let logged out users read (130 ms)
          ✕ should let logged in users read room message that owner is themselves (98 ms)
          ✕ should let admin update (180 ms)
        update
          ✕ should not let logged out users update (78 ms)
          ✕ should let logged in users update room message that owner is themselves (252 ms)
          ✕ should request.resource.data.text is string (194 ms)
          ✕ should request.resource.data.name.size() > 0 (64 ms)
          ✕ should let admin update (164 ms)
        delete
          ✕ should not let logged out users delete (273 ms)
          ✓ should let logged in users delete (114 ms)
          ✓ should not let admin delete (131 ms)

  ● firestore.rules › /users/{user} › read › should not let logged out users read

    FIRESTORE (7.18.0) INTERNAL ASSERTION FAILED: Unexpected state

      at fail (node_modules/@firebase/firestore/src/util/assert.ts:39:9)
      at hardAssert (node_modules/@firebase/firestore/src/util/assert.ts:53:5)
      at fromBytes (node_modules/@firebase/firestore/src/remote/serializer.ts:272:5)
      at fromWatchChange (node_modules/@firebase/firestore/src/remote/serializer.ts:488:25)
      at PersistentListenStream.onMessage (node_modules/@firebase/firestore/src/remote/persistent_stream.ts:576:25)
      at node_modules/@firebase/firestore/src/remote/persistent_stream.ts:456:21
      at node_modules/@firebase/firestore/src/remote/persistent_stream.ts:509:18
      at node_modules/@firebase/firestore/src/util/async_queue.ts:382:14

[...message repeats 26 more times...]

  ● firestore.rules › /rooms/{room} › /rooms/{room}/messages/{message} › delete › should not let logged out users delete

    FirebaseError: 5 NOT_FOUND: no entity to update: app: "dev~firestore-emulator-example-1597769648269-53"
    path <
      Element {
        type: "rooms"
        name: "9be84553-480e-45e3-a8cc-6ddb8e3c23b4"
      }
      Element {
        type: "messages"
        name: "84b49098-e61c-4974-aff8-809714b4a79b"
      }
    >

      at new FirestoreError (node_modules/@firebase/firestore/src/util/error.ts:166:5)
      at ClientDuplexStreamImpl.<anonymous> (node_modules/@firebase/firestore/src/platform/node/grpc_connection.ts:241:15)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client.ts:666:18)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client-interceptors.ts:397:48)
      at Http2CallStream.outputStatus (node_modules/@grpc/grpc-js/src/call-stream.ts:230:22)
      at Http2CallStream.maybeOutputStatus (node_modules/@grpc/grpc-js/src/call-stream.ts:280:14)
      at Http2CallStream.endCall (node_modules/@grpc/grpc-js/src/call-stream.ts:263:12)
      at Http2CallStream.handleTrailers (node_modules/@grpc/grpc-js/src/call-stream.ts:412:10)

  ● firestore.rules › /rooms/{room} › /rooms/{room}/messages/{message} › delete › should not let logged out users delete

    Expected request to fail, but it succeeded.

      at node_modules/@firebase/testing/src/api/index.ts:265:22
          at runMicrotasks (<anonymous>)

  ● firestore.rules › /rooms/{room} › /rooms/{room}/messages/{message} › delete › should not let logged out users delete

    FirebaseError: 5 NOT_FOUND: no entity to update: app: "dev~firestore-emulator-example-1597769648269-56"
    path <
      Element {
        type: "rooms"
        name: "9be84553-480e-45e3-a8cc-6ddb8e3c23b4"
      }
      Element {
        type: "messages"
        name: "84b49098-e61c-4974-aff8-809714b4a79b"
      }
    >

      at new FirestoreError (node_modules/@firebase/firestore/src/util/error.ts:166:5)
      at ClientDuplexStreamImpl.<anonymous> (node_modules/@firebase/firestore/src/platform/node/grpc_connection.ts:241:15)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client.ts:666:18)
      at Object.onReceiveStatus (node_modules/@grpc/grpc-js/src/client-interceptors.ts:397:48)
      at Http2CallStream.outputStatus (node_modules/@grpc/grpc-js/src/call-stream.ts:230:22)
      at Http2CallStream.maybeOutputStatus (node_modules/@grpc/grpc-js/src/call-stream.ts:280:14)
      at Http2CallStream.endCall (node_modules/@grpc/grpc-js/src/call-stream.ts:263:12)
      at Http2CallStream.handleTrailers (node_modules/@grpc/grpc-js/src/call-stream.ts:412:10)

Test Suites: 1 failed, 1 total
Tests:       28 failed, 31 passed, 59 total
Snapshots:   0 total
Time:        12.362 s
Ran all test suites.
Jest did not exit one second after the test run has completed.

This usually means that there are asynchronous operations that weren't stopped in your tests. Consider running Jest with `--detectOpenHandles` to troubleshoot this issue.

I've tested against various versions in between and as far as I got things right the trigger is jsdom v16 the major upgrade, not one of the later minor/patch upgrades.

I don't understand the internals of Firebase enough to say whether this is a jsdom bug or not, but hey, it triggers an internal error in Firebase so this seems like the place to start.

For anyone looking for a quick workaround, you can often use the node test environment instead of jsdom. That is, of course, not ideal for testing something that's in general meant to run in the browser.

$ git diff __tests__/firestore.rules.test.ts
diff --git i/__tests__/firestore.rules.test.ts w/__tests__/firestore.rules.test.ts
index d93e97a..b804318 100644
--- i/__tests__/firestore.rules.test.ts
+++ w/__tests__/firestore.rules.test.ts
@@ -1,3 +1,7 @@
+/**
+ * @jest-environment node
+ */
+
 import * as firebase from "@firebase/testing";
 import * as fs from "fs";
 import { v4 } from "uuid";
$ npm run test
[...] Test Suites: 1 passed, 1 total [...]

[thebrianchen]

@tv42 Thanks for including a repro! I was able to reproduce this issue locally on my machine. I'll dig into this some more, and get back to you once I figure out what's going on.

[thebrianchen]

This seems to be a bug with jest.

The Firestore failure is an internal assertion that checks that a Buffer type is provided. While new Buffer(0) instanceof Uint8Array normally evaluates to true, the expression evaluates to false in your repro, which triggers the error you are seeing.

Digging into this some more, I found several threads that reference this behavior:
jestjs/jest#6248
nodejs/node#20978

Though the issue appeared to be marked as fixed at some point in time, the regression appeared again recently in jest-environment-jsdom@26 (jestjs/jest#7780 (comment)), which would explain why the different versions of jsdom have different behaviors.

[thebrianchen]

Just realized that is is a duplicate of #3096, which has a much more comprehensive answer courtesy of @dconeybe. Closing this thread.