@firebase/rules-unit-testing logs rule fails as warnings

[MergeCommits]

[REQUIRED] Describe your environment

• Operating System version: Windows 10
• Firebase SDK version: 9.6.2
• rules-unit-test package version: 2.0.1
• Firebase Product: firestore

[REQUIRED] Describe the problem

When using the rules-unit-testing package, a warning is logged whenever a rule fails even if assertFails() is present and suceeds.

Doesn't appear to cause any side-effects and can be disabled by calling setLogLevel("silent") during setup but I'm assuming this is a bug since all it appears to do is cause console noise during unit test runs.

Steps to reproduce:

• Setup a test environment.
• Create a basic test that calls assertFails() and suceeds.
• Run the test.
• A warning is logged to the console that firestore denied permission.

Relevant Code:

firestore.rules

rules_version = '2';

service cloud.firestore {
    match /databases/{database}/documents {
        match /users/{uid} {
            allow read, write: if false;
        }
    }
}

it("test", async () => {
    const testEnvironment = await initializeTestEnvironment({
        projectId: "foo",
        firestore: {
            rules: fs.readFileSync("firestore.rules", "utf8"),
        }
    });

    const randomUserDocument = testEnvironment.unauthenticatedContext().firestore().collection("users").doc("foo");

    await assertFails(randomUserDocument.set({ foo: "bar" }));
});

Running this test succeeds but writes the following warning to console:

@firebase/firestore: Firestore (9.6.2): Connection GRPC stream error. Code: 7 Message: 7 PERMISSION_DENIED: 
    false for 'create' @ L100

      at Logger.defaultLogHandler [as _logHandler] (node_modules/@firebase/logger/src/logger.ts:115:57)
      at Logger.Object.<anonymous>.Logger.warn (node_modules/@firebase/logger/src/logger.ts:206:21)
      at logWarn (node_modules/@firebase/firestore/src/util/log.ts:69:15)
      at ClientDuplexStreamImpl.<anonymous> (node_modules/@firebase/firestore/src/platform/node/grpc_connection.ts:252:9)
      at Object.onReceiveStatus (node_modules/@firebase/firestore/node_modules/@grpc/grpc-js/src/client.ts:673:18)
      at Object.onReceiveStatus (node_modules/@firebase/firestore/node_modules/@grpc/grpc-js/src/client-interceptors.ts:424:48)

[HayataSuenaga]

Connection GRPC stream error

I encountered the same problem. I created a sample project that reproduces the following problems.

https://github.com/HayataSuenaga/grpc-error

Problems

1. Connection GRPC stream error is logged for every run.

2. The test script does not exit after execution even though I cleanup RulesTestEnvironment and wait the cleanup to finish. I'm using Jest, and it shows the following messages:

   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.

Environment

• macOS Big Sur: v11.5.1
• node: v.14.17.0
• @firebase/rules-unit-testing: v2.0.1
• firebase v9.6.2
• jest: v27.4.7

[yuchenshi]

As noted, setLogLevel('error') or above is the only workaround for now.

Ideally, we'd want to silence these errors when assertFails is used, but it's quite challenging to implement. assertFails takes a promise as input, which doesn't allow any control over the operation behind that promise -- the operation has already started. This is further complicated by the fact that Firestore logging at gRPC / request level is a few layers deep from .set. Please let us know if you have ideas on how to solve it (or even better, Pull Requests).

[Acterion]

As noted, setLogLevel('error') or above is the only workaround for now.

Ideally, we'd want to silence these errors when assertFails is used, but it's quite challenging to implement. assertFails takes a promise as input, which doesn't allow any control over the operation behind that promise -- the operation has already started. This is further complicated by the fact that Firestore logging at gRPC / request level is a few layers deep from .set. Please let us know if you have ideas on how to solve it (or even better, Pull Requests).

Can you provide a code sample on how to do that? I can't find a context where this method is available.

[yuchenshi]

The linked source file on GitHub contains a full working example. https://github.com/firebase/quickstart-testing/blob/8c0b7db5616e09824a6f44415e4128d2d8dd4fa2/unit-test-security-rules-v9/test/firestore.spec.js#L28-L30

tl;dr:

1. Import / require setLogLevel from firebase/firestore: const { setLogLevel } = require('firebase/firestore')
2. You'd usually want to call setLogLevel('error') in a "before-all" hook using the test framework of your choice.
3. Your tests that run after that will not print verbose rules errors any more.

[BernsteinA]

@yuchenshi even with setLogLevel('silent') I'm still seeing FirebaseError: 7 PERMISSION_DENIED which causes my assertFails lines to throw errors, instead of passing.

Any suggestions?

[yuchenshi]

@BernsteinA I think you're experiencing a separate issue which concerns the Promise behaviors instead of logs, and I'd appreciate it if you can open a new issue in this repository with a minimal repro.

[NickVanzo]

The linked source file on GitHub contains a full working example. https://github.com/firebase/quickstart-testing/blob/8c0b7db5616e09824a6f44415e4128d2d8dd4fa2/unit-test-security-rules-v9/test/firestore.spec.js#L28-L30

tl;dr:

1. Import / require setLogLevel from firebase/firestore: const { setLogLevel } = require('firebase/firestore')
2. You'd usually want to call setLogLevel('error') in a "before-all" hook using the test framework of your choice.
3. Your tests that run after that will not print verbose rules errors any more.

This solved my issue, I can confirm