[FEAT] TrackableRequests for when async leakage is detected

improve waiter erroring improve trace infra and add tests only run waiter tests in dev
emberjs · Aug 8, 2018 · 1f7512e · 1f7512e
1 parent ece0494
commit 1f7512e
Show file tree

Hide file tree

Showing 5 changed files with 555 additions and 19 deletions.
diff --git a/addon/-legacy-private/system/store.js b/addon/-legacy-private/system/store.js
@@ -220,9 +220,48 @@ Store = Service.extend({
     this._serializerCache = Object.create(null);
 
     if (DEBUG) {
-      this.__asyncRequestCount = 0;
+      if (this._shouldTrackAsyncRequests === undefined) {
+        this._shouldTrackAsyncRequests = true;
+      }
+      if (this._generateStackTracesForTrackedRequests === undefined) {
+        this._generateStackTracesForTrackedRequests = false;
+      }
+
+      this._trackedAsyncRequests = [];
+      this._trackAsyncRequestStart = label => {
+        let trace =
+          'set `store._generateStackTracesForTrackedRequests = true;` to get a detailed trace for where this request originated';
+
+        if (this._generateStackTracesForTrackedRequests) {
+          try {
+            throw new Error(`EmberData TrackedRequest: ${label}`);
+          } catch (e) {
+            trace = e;
+          }
+        }
+
+        let token = Object.freeze({
+          label,
+          trace,
+        });
+
+        this._trackedAsyncRequests.push(token);
+        return token;
+      };
+      this._trackAsyncRequestEnd = token => {
+        let index = this._trackedAsyncRequests.indexOf(token);
+
+        if (index !== -1) {
+          this._trackedAsyncRequests.splice(index, 1);
+        }
+      };
+
       this.__asyncWaiter = () => {
-        return this.__asyncRequestCount === 0;
+        let shouldTrack = this._shouldTrackAsyncRequests;
+        let tracked = this._trackedAsyncRequests;
+        let isSettled = tracked.length === 0;
+
+        return shouldTrack !== true || isSettled;
       };
 
       Ember.Test.registerWaiter(this.__asyncWaiter);
@@ -833,6 +872,24 @@ Store = Service.extend({
       options,
     };
 
+    if (DEBUG) {
+      if (this._generateStackTracesForTrackedRequests === true) {
+        let trace;
+
+        try {
+          throw new Error(`Trace Origin for scheduled fetch for ${modelName}:${id}.`);
+        } catch (e) {
+          trace = e;
+        }
+
+        // enable folks to discover the origin of this findRecord call when
+        // debugging. Ideally we would have a tracked queue for requests with
+        // labels or local IDs that could be used to merge this trace with
+        // the trace made available when we detect an async leak
+        pendingFetchItem.trace = trace;
+      }
+    }
+
     let promise = resolver.promise;
 
     internalModel.loadingData(promise);
@@ -2840,6 +2897,27 @@ Store = Service.extend({
 
     if (DEBUG) {
       Ember.Test.unregisterWaiter(this.__asyncWaiter);
+      let shouldTrack = this._shouldTrackAsyncRequests;
+      let tracked = this._trackedAsyncRequests;
+      let isSettled = tracked.length === 0;
+
+      if (!isSettled) {
+        if (shouldTrack) {
+          throw new Error(
+            'Async Request leaks detected. Add a breakpoint here and set `store._generateStackTracesForTrackedRequests = true;`to inspect traces for leak origins:\n\t - ' +
+              tracked.map(o => o.label).join('\n\t - ')
+          );
+        } else {
+          warn(
+            'Async Request leaks detected. Add a breakpoint here and set `store._generateStackTracesForTrackedRequests = true;`to inspect traces for leak origins:\n\t - ' +
+              tracked.map(o => o.label).join('\n\t - '),
+            false,
+            {
+              id: 'ds.async.leak.detected',
+            }
+          );
+        }
+      }
     }
   },
 

diff --git a/addon/-private/system/store/common.js b/addon/-private/system/store/common.js
@@ -34,14 +34,15 @@ export function _objectIsAlive(object) {
 }
 
 export function guardDestroyedStore(promise, store, label) {
+  let token;
   if (DEBUG) {
-    store.__asyncRequestCount++;
+    token = store._trackAsyncRequestStart(label);
   }
   let wrapperPromise = resolve(promise, label).then(v => promise);
 
   return _guard(wrapperPromise, () => {
     if (DEBUG) {
-      store.__asyncRequestCount--;
+      store._trackAsyncRequestEnd(token);
     }
     return _objectIsAlive(store);
   });

diff --git a/addon/-record-data-private/system/store.js b/addon/-record-data-private/system/store.js
@@ -226,9 +226,48 @@ Store = Service.extend({
     this.modelDataWrapper = new ModelDataWrapper(this);
 
     if (DEBUG) {
-      this.__asyncRequestCount = 0;
+      if (this._shouldTrackAsyncRequests === undefined) {
+        this._shouldTrackAsyncRequests = true;
+      }
+      if (this._generateStackTracesForTrackedRequests === undefined) {
+        this._generateStackTracesForTrackedRequests = false;
+      }
+
+      this._trackedAsyncRequests = [];
+      this._trackAsyncRequestStart = label => {
+        let trace =
+          'set `store._generateStackTracesForTrackedRequests = true;` to get a detailed trace for where this request originated';
+
+        if (this._generateStackTracesForTrackedRequests) {
+          try {
+            throw new Error(`EmberData TrackedRequest: ${label}`);
+          } catch (e) {
+            trace = e;
+          }
+        }
+
+        let token = Object.freeze({
+          label,
+          trace,
+        });
+
+        this._trackedAsyncRequests.push(token);
+        return token;
+      };
+      this._trackAsyncRequestEnd = token => {
+        let index = this._trackedAsyncRequests.indexOf(token);
+
+        if (index !== -1) {
+          this._trackedAsyncRequests.splice(index, 1);
+        }
+      };
+
       this.__asyncWaiter = () => {
-        return this.__asyncRequestCount === 0;
+        let shouldTrack = this._shouldTrackAsyncRequests;
+        let tracked = this._trackedAsyncRequests;
+        let isSettled = tracked.length === 0;
+
+        return shouldTrack !== true || isSettled;
       };
 
       Ember.Test.registerWaiter(this.__asyncWaiter);
@@ -842,6 +881,24 @@ Store = Service.extend({
       options,
     };
 
+    if (DEBUG) {
+      if (this._generateStackTracesForTrackedRequests === true) {
+        let trace;
+
+        try {
+          throw new Error(`Trace Origin for scheduled fetch for ${modelName}:${id}.`);
+        } catch (e) {
+          trace = e;
+        }
+
+        // enable folks to discover the origin of this findRecord call when
+        // debugging. Ideally we would have a tracked queue for requests with
+        // labels or local IDs that could be used to merge this trace with
+        // the trace made available when we detect an async leak
+        pendingFetchItem.trace = trace;
+      }
+    }
+
     let promise = resolver.promise;
 
     internalModel.loadingData(promise);
@@ -3060,6 +3117,27 @@ Store = Service.extend({
 
     if (DEBUG) {
       Ember.Test.unregisterWaiter(this.__asyncWaiter);
+      let shouldTrack = this._shouldTrackAsyncRequests;
+      let tracked = this._trackedAsyncRequests;
+      let isSettled = tracked.length === 0;
+
+      if (!isSettled) {
+        if (shouldTrack) {
+          throw new Error(
+            'Async Request leaks detected. Add a breakpoint here and set `store._generateStackTracesForTrackedRequests = true;`to inspect traces for leak origins:\n\t - ' +
+              tracked.map(o => o.label).join('\n\t - ')
+          );
+        } else {
+          warn(
+            'Async Request leaks detected. Add a breakpoint here and set `store._generateStackTracesForTrackedRequests = true;`to inspect traces for leak origins:\n\t - ' +
+              tracked.map(o => o.label).join('\n\t - '),
+            false,
+            {
+              id: 'ds.async.leak.detected',
+            }
+          );
+        }
+      }
     }
   },
 

diff --git a/tests/integration/store-test.js b/tests/integration/store-test.js
@@ -1,4 +1,4 @@
-import RSVP, { Promise as EmberPromise, resolve } from 'rsvp';
+import RSVP, { Promise, resolve } from 'rsvp';
 import { run, next } from '@ember/runloop';
 import setupStore from 'dummy/tests/helpers/store';
 
@@ -76,7 +76,7 @@ test("destroying record during find doesn't cause error", function(assert) {
 
   let TestAdapter = DS.Adapter.extend({
     findRecord(store, type, id, snapshot) {
-      return new EmberPromise((resolve, reject) => {
+      return new Promise((resolve, reject) => {
         next(() => {
           store.unloadAll(type.modelName);
           reject();
@@ -93,31 +93,51 @@ test("destroying record during find doesn't cause error", function(assert) {
   return run(() => store.findRecord(type, id).then(done, done));
 });
 
-test('find calls do not resolve when the store is destroyed', function(assert) {
-  assert.expect(0);
+test('find calls do not resolve when the store is destroyed', async function(assert) {
+  assert.expect(2);
   let done = assert.async();
-
+  let next;
+  let nextPromise = new Promise(resolve => {
+    next = resolve;
+  });
   let TestAdapter = DS.Adapter.extend({
-    findRecord(store, type, id, snapshot) {
-      store.destroy();
-      resolve(null);
+    findRecord() {
+      next();
+      nextPromise = new Promise(resolve => {
+        next = resolve;
+      }).then(() => {
+        return {
+          data: { type: 'car', id: '1' },
+        };
+      });
+      return nextPromise;
     },
   });
 
   initializeStore(TestAdapter);
 
-  let type = 'car';
-  let id = 1;
-
   store.push = function() {
     assert('The test should have destroyed the store by now', store.get('isDestroyed'));
 
     throw new Error("We shouldn't be pushing data into the store when it is destroyed");
   };
+  store.findRecord('car', '1');
+
+  await nextPromise;
+
+  assert.throws(() => {
+    run(() => store.destroy());
+  }, /Async Request leaks detected/);
 
-  run(() => store.findRecord(type, id));
+  next();
+  await nextPromise;
 
-  setTimeout(() => done(), 500);
+  // ensure we allow the internal store promises
+  // to flush, potentially pushing data into the store
+  setTimeout(() => {
+    assert.ok(true, 'We made it to the end');
+    done();
+  }, 0);
 });
 
 test('destroying the store correctly cleans everything up', function(assert) {