[email protected] Change Detection Irregularities

[byrondover]

I'm experiencing a reproducible change detection issue with [email protected], where the first emissions from snapshotChanges() and valueChanges() are not triggering Angular change detection appropriately.

https://stackblitz.com/edit/angular-nkqyhq

As demonstrated in the StackBlitz example above, the first values emitted by AngularFireDatabase valueChanges() Observables are being populated as expected, but UI is not redrawing automatically (unless triggered manually, or by something else). Subsequent valueChanges() emissions appear to trigger change detection as expected, reproducible in the above example by navigating away from and back to the example routed component.

This issue first appears with the merging of #1454 (commit e343f137).

I haven't had a chance to dig into it, but this behavior appears to be related to the new FirebaseZoneScheduler; the current implementation of the keepUnstableUntilFirst() method in particular has me a bit puzzled.

https://github.com/angular/angularfire2/blob/master/src/core/angularfire2.ts#L25-L33

Version info

Angular: 5.2.10

% ng --version

    _                      _                 ____ _     ___
   / \   _ __   __ _ _   _| | __ _ _ __     / ___| |   |_ _|
  / △ \ | '_ \ / _` | | | | |/ _` | '__|   | |   | |    | |
 / ___ \| | | | (_| | |_| | | (_| | |      | |___| |___ | |
/_/   \_\_| |_|\__, |\__,_|_|\__,_|_|       \____|_____|___|
               |___/

Angular CLI: 1.7.4
Node: 9.11.1
OS: darwin x64
Angular: 5.2.10
... animations, common, compiler, compiler-cli, core, forms
... http, language-service, platform-browser
... platform-browser-dynamic, router

@angular/cdk: 5.2.5
@angular/cli: 1.7.4
@angular/flex-layout: 5.0.0-beta.14
@angular/material: 5.2.5
@angular-devkit/build-optimizer: 0.3.2
@angular-devkit/core: 0.3.2
@angular-devkit/schematics: 0.3.2
@ngtools/json-schema: 1.2.0
@ngtools/webpack: 1.10.2
@schematics/angular: 0.3.2
@schematics/package-update: 0.3.2
typescript: 2.6.2
webpack-bundle-analyzer: 2.11.1
webpack: 3.11.0

Firebase: 4.12.1

AngularFire: 5.0.0-rc.7.0-next

Browser: Chrome OS v66.0.3359.139

Operating system: macOS Sierra v10.12.6

How to reproduce these conditions

Failing test unit, Plunkr, or JSFiddle demonstrating the problem

https://stackblitz.com/edit/angular-nkqyhq

Steps to set up and reproduce

1. Create a component which injects AngularFireDatabase
2. Subscribe to valueChanges() Observable
3. Interpolate value change in template (will not display first result from Observable)

Debug output

* Errors in the JavaScript console *

None.

* Output from firebase.database().enableLogging(true); *

Not sure how to enable this.

* Screenshots *

N/A

Expected behavior

First value emitted from AngularFireDatabase.valueChanges() Observable consistently triggers change detection.

Actual behavior

First value emitted from AngularFireDatabase.valueChanges() Observable does not consistently trigger change detection.

[larssn]

Commendable research job you've done looking into this issue.

[davideast]

Hey @byrondover! Thank you so much for the in depth work on this issue. I wish they all were like this!

I'm going to page @jamesdaniels who was the implementer of FirebaseZoneScheduler and keepUnstableUntilFirst(). We'll get to the bottom of this.

[patrickmichalina]

Does this means its not emitting events when it should be? I've had the opposite experience (emitting double events when nothing has changed). In order to solve, use a hash function on the object and distinctUntilChanged operator.

[jamesdaniels]

Just cut a new angularfire2@next which should address, it seems I slipped up on some Zone.js stuff esp. on the RTDB. I'm mostly using Firestore myself these days. Give it a spin and let me know if that's working better for you @byrondover; and I'll double check my Zone.js work in my Universal test bed.

https://stackblitz.com/edit/angular-fau5ia?file=app/example/example.component.ts

Really appreciate the time you spent diagnosing this, it allowed me to zero in on the bad spot in the code immediately.

[byrondover]

I can confirm angularfire2@next fixes the change detection irregularities.

Thank you, @jamesdaniels!

I hate to drop this on you without more concrete details, but upon further testing, I am also noticing a significant drop in application performance under production workloads _after_ upgrading angularfire2 from rc.6.0 to rc.7.1-next.

Here's a summary of the behavior I'm seeing.

Before
[email protected]

• CD, CD, Result, CD, CD
• Angular app remains interactive while results of Firebase database queries are pending.
• Prior to receiving results of database queries, change detection is triggered once every 30 secs (per listener).
• After database results are received, AngularFire continues to trigger change detection periodically.

https://stackblitz.com/edit/angular-bqw1xv

After
[email protected]

• CD, CD, CD, Result, CD
• Main JS thread is blocked pending results of Firebase database queries.
• Prior to receiving results of database queries, change detection is triggered 10+ times per second (per listener).
• After database results are received, AngularFire no longer triggers change detection.

https://stackblitz.com/edit/angular-gjyz3e

In the contrived StackBlitz examples above, this may not have much impact. But in a large Angular application with dozens of active, concurrent Firebase queries, this behavior change results in a significant drop in page performance prior to Angular stability (empty task queue).

I'm seeing one large production Angular app I contribute to freeze completely for several seconds when users route to the dashboard component, as FPS drops to 0 and the CPU pegs on Recalculate Style, setProperty, etc. Interactivity returns once the Firebase queries resolve, and change detection normalizes.

I know this is a nebulous issue to raise without source code to demonstrate the impact (unfortunately I'm not at liberty to share source code from the aforementioned app's private repo), but I'd be happy to share production Chrome Dev Tools performance profiles privately with you and @davideast, if they could be of any help.

If nothing else, I'd just like to put this on your radar, in case performance issues surface with any other AngularFire users. I have no doubt we can find ways to work around the performance impact in production; if I have time to dig into this and come up with any more pertinent details, I'll open a new issue.

Thank you again for the quick fix, James! Please feel free to close this issue, at your discretion.

[jamesdaniels]

We're aware of the blocking before .first() returns, as we're currently invoking a microtask to support Angular Universal and work with ngsw as expected. The timers will no longer trigger change detection every couple seconds, as that was a bug.

It should not however drop your frames, I'll look into that.

I'm going to be working with a Zone.js maintainer to make sure that we're doing this the "right" way in the future.

[byrondover]

Thank you for the clarification, James! If I can help or provide anything further, please let me know.

[jamesdaniels]

@byrondover I just cut a new angularfire2@next build, can you check if you're seeing better performance for your large application or is it still locking up? While we're investigating, I've made the microtask only happen on the server; which should allow both browser side performance and render blocking for Universal.

[byrondover]

@jamesdaniels Surprisingly, upgrading to 5.0.0-rc.7.2-next didn't make much of a difference.

It helped a bit on the initial delay before interactivity, but for whatever reason, passing Firebase object references through FirebaseZoneScheduler methods (even when no-op) seems to be slowing things down a lot.

I was able to dramatically improve performance in the browser by reverting snapshotChanges() and valueChanges() to their pre-runOutsideAngular() equivalents in database/object/create-reference.ts.

export function createObjectReference<T>(query: DatabaseQuery, afDatabase: AngularFireDatabase): AngularFireObject<T> {
  return {
     query,
+    snapshotChanges: createObjectSnapshotChanges(query),
-    snapshotChanges<T>() {
-      const snapshotChanges$ = createObjectSnapshotChanges(query)();
-      return afDatabase.scheduler.keepUnstableUntilFirst(
-        afDatabase.scheduler.runOutsideAngular(
-          snapshotChanges$
-        )
-      );
-    },
     update(data: Partial<T>) { return query.ref.update(data as any) as Promise<void>; },
     set(data: T) { return query.ref.set(data) as Promise<void>; },
     remove() { return query.ref.remove() as Promise<void>; },
     valueChanges<T>() { 
+      return createObjectSnapshotChanges(query)()
+        .map(action => action.payload.exists() ? action.payload.val() as T : null);
-      const snapshotChanges$ = createObjectSnapshotChanges(query)();
-      return afDatabase.scheduler.keepUnstableUntilFirst(
-        afDatabase.scheduler.runOutsideAngular(
-          snapshotChanges$
-        )
-      ).map(action => action.payload.exists() ? action.payload.val() as T : null)
     },
   }
 }

Obviously this defeats the purpose, and I've since abandoned these reversions, but for whatever it's worth this did clear up the performance issues entirely.

Further investigation revealed a discrepancy between the number of events emitted by firebase.database().ref() and the number of values emitted by the corresponding snapshotChanges() and valueChanges() Observables.

Adding debug logging to database/observable/fromRef.ts confirmed Firebase references emitting the expected number of ref['on']('value') events, while the corresponding snapshotChanges() and valueChanges() Observables emitted n² the number of values expected as users navigated around the app. Event counts are always consistent upon first page load, then quickly diverge as users route from component to component.

Strange. And unfortunately, as of right now, not reproducible in StackBlitz (I'll keep poking at it).

Good news is, we were able to work around the issue in production without much hassle by adding debounceTime(5) operators to our snapshotChanges() and valueChanges() Observables. :neckbeard:

[jamesdaniels]

That's just bizarre... sounds like maybe the scan isn't collapsing things as expected. I'll call this good for now and keep an eye on this :/ if you are able to repro let me know. I'll sync up with the zone folks too and review after Google I/O.

[jamesdaniels]

You know maybe it's because I dropped the observeOn queue... that's the only other thing I changed since it only seems to create bottlenecks and false assurances (at least in my test apps). Maybe dropping it is losing some magic at the larger scale that I'm not immediately thinking of.

[jamesdaniels]

@byrondover would you mind shooting me an email at [email protected] so we can setup a meeting RE your use of the lib + the performance issues. My calendar is pretty full for the next week and a half but after that we can see if I can find out what exactly is wrong.

Thank you very much for all your help in diagnosing these issues.

[byrondover]

@jamesdaniels Just sent you an email!

I think you may be onto something with the scan not collapsing idea. One thing I noticed is the distinctUntilChanged() operator on listChanges() only prevents duplicate boolean/number/string emissions, and does not block duplicate arrays and objects. A deep comparison might be too costly here, but perhaps there's a cleverer approach.

Side note—I submitted a PR (#1588) with the changes I alluded to earlier. It feels more like a workaround at this point than a proper fix, so feel free to close if you think it's not the right direction, but I figured I should at least show my work so you can see what's functioning for me in production right now. 🙂