Firebase-js-sdk: FR: meaningful debug information for firestore "permission_denied" errors

[jaufgang]

Describe your environment

• Firebase SDK version: 4.13.1
• Firebase Product: Firestore

Describe the problem

When a web app tries to access Firestore data in a way which is not authorized by the rules file, a permission_denied error is thrown.

core.js:1449 ERROR Error: permission_denied at /user/V7VRmPMAh2M2OLrKoab097pqfrq2/markerScans: Client doesn't have permission to access the desired data.
    at errorForServerCode (index.cjs.js:647)
    at onComplete (index.cjs.js:9114)
    at Object.onComplete (index.cjs.js:12681)
    at PersistentConnection.onListenRevoked_ (index.cjs.js:12300)
    at PersistentConnection.onDataPush_ (index.cjs.js:12072)
    at PersistentConnection.onDataMessage_ (index.cjs.js:12060)
    at Connection.onDataMessage_ (index.cjs.js:11337)
    at Connection.onPrimaryMessageReceived_ (index.cjs.js:11331)
    at WebSocketConnection.onMessage (index.cjs.js:11232)
    at WebSocketConnection.appendFrame_ (index.cjs.js:10837)
    at WebSocketConnection.handleIncomingFrame (index.cjs.js:10887)
    at WebSocket.mySock.onmessage [as __zone_symbol__ON_PROPERTYmessage] (index.cjs.js:10784)
    at WebSocket.H (polyfills.js:3)
    at WebSocket.wrapped (raven.js:375)
    at t.invokeTask (polyfills.js:3)
    at Object.onInvokeTask (core.js:4751)
    at t.invokeTask (polyfills.js:3)
    at r.runTask (polyfills.js:3)
    at e.invokeTask [as invoke] (polyfills.js:3)
    at p (polyfills.js:2)
    at WebSocket.v (polyfills.js:2)

The error message and stack trace does not include any information about what read or write operation on what document or collection caused this permission error. This makes it exceedingly difficult to track down what caused the error.

A question about this was asked about 7 months ago on the google-cloud-firestore-discuss group, to which @samtstern replied:

The lack of information in "permission denied" is intentional for now, although I completely understand your frustration. If we exposed the reason for the authentication failure in these messages it could help an attacker find the weak spots in your security.

That said, we have a lot of work to do to help non-attackers like you debug their rules! In the long term we want to have tools like the Realtime Database rules simulator which will help you avoid the trial-and-error pain you're currently experiencing. Look out for future updates in this space.

This explanation of why the diagnostic information was omitted makes sense, but it would still be really helpful if there was a way to enable/disable more detailed information.

It is possible to get some useful information about what Firestore was reading/writing immediately before the permission_denied error is thrown by setting

firebase.firestore.setLogLevel("debug");

and looking for log entries with the [Connection]: WebChannel sending: header immediately before the error was thrown. But even still, it can be a challenge to connect the error to the particular operation when a number of read or write operations happen in rapid succession, since the firestore communication is asynchronous.

In my case, the initial screen of my app is a dashboard that loads a variety of documents and lists from an assortment of collections, resulting in a flurry of read requests. When one of those reads generates a permission_denied error, it can be a mind-bending experience trying to figure out what went wrong, even with the debug logging turned on.

As I said, it would be very helpful if you could provide a way for developers have information about the path and type of the read/write operation that triggered the error. Since firebase.firestore.setLogLevel() already provides a way to turn debug logging on and off, perhaps this would be a good way to make this detailed information available to developers. You could write an additional debug log message to the console detailing the source of the error immediately before the error was thrown by the SDK. This way, developers could get useful diagnostic information when they need it. Since these messages could be easily turned off when deploying the code to a production environment, this would also satisfy the security concern expressed by @samtstern about exposing security information to end-users/attackers.

[samtstern]

@jaufgang thanks for filing such a detailed request! This is something we're actively working on. We probably will not take the route of allowing the production backend to return more information with a "debug mode" flag as that's something that could be pretty easily exploited (imagine opening up the Chrome Dev Tools on a Firestore-powered website and setting that flag).

Some things we are looking at include:

• Making the in-console simulator more powerful
• Exposing better testing APIs for rules
• A way to locally emulate rules requests for integration tests
• etc.

Stay tuned for news on this!

[jaufgang]

Thank you for your response, @samtstern. I appreciate you listing the ideas currently being worked on, but all of them seem to pertain to ways of testing rules outside of the core app logic of an app under development.

My request is to provide a fast and convenient way to discover what rule was violated when an error occurs in your app and it is unclear what caused it. Enhanced rule testing can still leave a developer needing to resort to a tedious trial-and-error process to track down the problem. Other possibilities could include logging rule violations on the server and allowing those logs to be viewed on the dashboard, or perhaps the ability to toggle detailed client-side error messages on or off from the dashboard.

I think something like this would be a very helpful addition to the enhancements you already have under consideration.

[samtstern]

@jaufgang thanks for all the ideas! I think we're on the same page. Our ideal solution looks a lot like yours, and we're working to get there.

[mikelehen]

Please take a look at the Firestore simulator and emulator features that were released recently. I think they should help a lot! https://firebase.google.com/docs/firestore/security/test-rules-emulator

[adamduren]

@mikelehen I do not think that this address should be closed as it does not address the problem described. As a developer when I am building my app I would like to see a more descriptive error in whatever environment I am working in, most likely the browser, that tells me the path, operation (read, write, update), and particular rule that was violated.

Sure test coverage will help but there will still be cases where this could save a lot of time and headache.

[mikelehen]

@adamduren Thanks for the feedback. I can see how this would be helpful. The difficulty we run into is we don't want to provide that detail (in particular the rule that failed) automatically since that would leak information about your security rules to (potentially malicious) users which could help them find holes in your app. So we'd need a way for owners of the project to opt-into this extra debugging information rather than do it automatically. We actually built something like this for Firebase Realtime Database, but it required a fair amount of internal plumbing to implement and ended up being too cumbersome to really catch on with users.

All that said, I don't think we're opposed to the idea, but we're much more eager to invest in the simulator and emulator to help users debug their rules. In particular, as the emulator becomes more flexible it should be straightforward to run your app against the emulator instead of against the production backend and the emulator can log any security rule failures with full details of what failed and why.

So I'm inclined to leave this closed since we don't currently have plans for the feature you described, but thank you for the feedback and other folks are welcome to chime in with ideas as well. We can certainly revisit if we come up with something that seems feasible.

cc/ @ryanpbrewster

[ryanpbrewster]

The Firestore emulator tries to provide a lot of the quality-of-life features that we haven't introduced in production due to security concerns.

One of these features is exactly the security rules feedback that you're looking for. For instance, with security rules like

service cloud.firestore {
  match /databases/{database}/documents {
    match /users/{userId} {
      allow create: if request.auth.uid == userId && request.resource.data.createdAt == request.time;
    }
  }
}

if you try to issue a request like this without logging in (i.e., where request.auth is null):

const profile = db.collection("users").doc("alice");
await profile.set({ birthday: "January 1" });

you'll get an error like this:

FirebaseError: 7 PERMISSION_DENIED: 
Null value error. for 'create' @ L4

indicating which rule failed and why.

Rule coverage reports will give you much more detailed information about how your rules failed, but even without setting those up you'll get a bit more insight into your permission errors.

[adamduren]

@mikelehen @ryanpbrewster I appreciate the information and am currently using the emulator. It is a life-saver compared to the pre-emulator era. Still it would be nice to have in development and possibly production.

If the firebase package could be ran against the emulator it would solve the development case and would be greatly welcomed.

The case for production is for bugs that appear in the wild. I understand the security concerns and why implementing this would be hard to do in a way that does not potentially expose the security rules making a hidden vulnerability more apparent.

I did have a thought come to mind and I realize they are not small asks / easy to implement but thought I would share it in case it may be useful to internal discussions.

Add a section to the Firebase console where security errors could be surfaced with information about the data and the rule that was violated. A unique random error id could be associated with errors which would be available to both the app where the error was thrown as well as the console. The developer could then do whatever they want with this error such as pass it along to their error reporting system.

The error reporting system Sentry could be used for instance to catch DB write errors, gather context about the application state (such as user ID, User Action Breadcrumbs, etc) the error ID, and other helpful information and record it to Sentry.

The Developer can then cross-reference the sentry error to the Firebase Console error logs which would go a long way towards helping debug errors in the wild.

[ryanpbrewster]

Cool concept, we've kicked around ideas like this over the past few months (in our current plans it's limited to ~10 detailed error traces per minute to limit load).

We're actively working on ways to make it easier to monitor your production traffic, this sounds like it'd fit right in. Would you mind if I brought up this issue to support the case for such a feature?

[adamduren]

@ryanpbrewster of course! I would be happy to discuss it further if at any point you think it would be beneficial to you and the team.

[ryanpbrewster]

For posterity: internal tracking # 132656968

The more I think about it the more I like the idea.

[crufter]

This is currently ruining my day big time, I'm digging around in the codebase to see which call may cause it... Absolutely maddening.

Edit: sorry if this is not too productive I just had to vent! Thanks.

[rockwotj]

To add a plug here, for "backend" or requests like this that are not specific to our SDKs feel free to file an issue here: https://issuetracker.google.com/savedsearches/5337669
https://issuetracker.google.com/issues/new?component=530136&template=0

Starting issues here also let's us prioritize appropriately.

[kevin-ashton]

The simulator seems nice but for any complex rules you are going to need to use a variety of functions. As the above example shows it doesn't appear show you the actual line that is the offender. Is there a way to enable that? Basically right now it's just telling me there is something wrong with create line which I already knew.

Above you mention how you don't want to expose security debug on production apps. When firebase came out they solved that problem by allowing you to add a debug property to your token. Problem solved most users didn't have access to production security debug logs. However, you still had the option to generate a special token and figure out what was going on.

[samtstern]

@kevin-ashton the create operation that was denied is at L10. So that seems correct.

If you want to know what parts of your request failed, you can use the debug() statement:

allow create: if debug(request.auth.uid == userId) && debug(request.resource.data.createdAt == request.time) && debug(fooBar()); 

You will see true true false in the logs, allowing you to know which part of the compound statement failed.

[samtstern]

@ryanpbrewster or @yuchenshi would it be possible to enable rules failure messages to include a stack trace of some kind to determine which part of the execution denied the request?

[ryanpbrewster]

Possible, but there's a bit of technical work involved in it.

One option that is possible already is to use the rule coverage report. This will give you the full information about how every expression (and subexpression) was evaluated. I've used it to debug a number of tricky security rules issues.