Repaired support for multiple timeouts in FrameManager #945

twolfson · 2017-01-07T11:24:07Z

I'm a new user of Nightmare but found an issue when recording multiple screenshots on a static page (i.e. one with no frame updates). I was recording multiple screenshots in series at different viewport sizes.

Nightmare was hanging indefinitely when hidden
Nightmare was hanging when visible until I moved my mouse over the content (thus generating a new frame for the debugger)

After some sleuthing, it looks like FrameManager has some sneaky edge cases that needed deeper testing. In this PR:

Fixed up double subscription issue due to still using subscribed boolean despite no longer being used
Added requestedFrame resetting on attach error and timeout so future attach errors/timeouts can get the same null frame
Added tests

Notes:

With respect to tests, I feel like I did a quick and dirty job. The require chunks aren't pulled out and I added async despite it not being used in the rest of the repo. I mostly wanted to get feedback on the PR and how y'all would like to handle the code setup instead of stressing myself out. I will gladly make any requested changes

Closes #555 (comment)

Mr0grog

D’oh, thanks for catching this mistake around not resetting the flag. And for writing a lot of the tests I probably should have.

I’m not a committer, so take all my comments here with a grain of salt. I just thought I’d give a quick review since I wrote the original code.

Mr0grog · 2017-01-09T04:26:24Z

lib/frame-manager.js

+    clearTimeout(frameRequestTimeout);
+    self.emit('data', null);
+  }
+


Since this implementation is pretty much exactly the same as receiveFrame, I think it might make sense to either remove this method entirely (i.e. replace call to it with receiveFrame(null) or to rewrite it as:

function cancelFrame() { receiveFrame(null); }

Ah, good insight. I didn't even see that o_o

If we are going for conciseness, we could probably do 1 better and remove cancelFrame() altogether (i.e. call receiveFrame(null); at those locations).

If we are going for clarity (my preference), I sometimes will sacrifice DRYness for making the intent clear (i.e. we mean to cancel the frame request and emit null data). In the concise scenario and another contributor reading the code, they might be uncertain if we actually wanted to emit null or not =/

Yeah, that’s why I gave two solutions :P I think I agree with you that clarity is better, so I’d keep cancelFrame() around but rewrite it to just delegate to receiveFrame(null).

Oh, I totally missed that first part. That's what I get for reading it half-awake x_x

Mr0grog · 2017-01-09T04:39:01Z

test/index.js

+    it('should subscribe to frames when requested necessary', function(done) {
+      var didSubscribe = false;
+      var didUnsubscribe = false;
+      var FrameManager = require('../lib/frame-manager.js');


As you noted, this should probably be pulled out of the test scenario (as I also should have done in the original test above).

Same, obviously for the rest of these (and the other require calls) in the other 3 tests you added.

Mr0grog · 2017-01-09T04:42:38Z

test/index.js

+          endFrameSubscription: function() { didUnsubscribe = true; },
+          executeJavaScript: function() {}
+        }
+      });


Since we now have 5 tests that require a dummy Window instance for the FrameManager, it would probably be much clearer and cleaner to simply make a MockFrameManagerWindow class that encapsulates all this logic, that way you can just:

var mockWindow = MockFrameManagerWindow(); var manager = FrameManager(mockWindow); manager.requestFrame(function (data) { mockWindow.didSubscribe.should.be.true; // etc. });

I'm on the fence about this. I like the idea but...

We define custom hooks in each of the tests so it won't save us too many lines of code. It might even lead to more confusion due to jumping from code to definition and back. That is:

var manager = FrameManager({ webContents: { debugger: { isAttached: function() { return true; }, sendCommand: function(command) { if (command === 'DOM.highlightRect') { fn('mock-data'); }} }, beginFrameSubscription: function(_fn) { didSubscribe = true; fn = _fn; }, endFrameSubscription: function() { didUnsubscribe = true; }, executeJavaScript: function() {} } });

will become:

var mockWindow = MockWindow({ // Unsure about how we define `fn` access at the moment sendCommand: function(command) { if (command === 'DOM.highlightRect') { this.fn('mock-data'); }} beginFrameSubscription: function() { didSubscribe = true; }, endFrameSubscription: function() { didUnsubscribe = true; } })

This file is quite lengthy and isn't broken down, where would the class definition live? My gut says top of the file or in a separate file but both feel a little premature/less clear when reading code

Oh, that’s not what I was trying to suggest at all. I was thinking you might have something roughly like…

function MockFrameManagerWindow (options) { options = Object.assign({ debuggerAlreadyAttached: false, debuggerTriggersFrames: true }, options); var self = this; var _debuggerAttached = !!options.debuggerAlreadyAttached; var _frameCallback = function() {}; self.results = { subscribedCount: 0, unsubscribedCount: 0, currentSubscriptionCount: 0 }; self.beginFrameSubscription = function (callback) { _frameCallback = callback; self.results.subscribedCount++; self.results.currentSubscriptionCount++; }; self.endFrameSubscription = function () { _frameCallback = function() {}; self.results.unsubscribedCount++; self.results.currentSubscriptionCount--; }; self.debugger = { isAttached: function () { return _debuggerAttached; }, attach: function () { asset(!_debuggerAttached, 'Debugger is already attached'); _debuggerAttached = true; }, detach: function () { _debuggerAttached = false; }, sendCommand: function (command, callback) { if (options.debuggerTriggersFrames && command === 'DOM.highlightRect') { setTimeout(_frameCallback, 0, 'mock_data'); } if (callback) { setTimeout(callback, 0); } } }; }

If you wanted to do less work here, you could use Sinon to make all the functions; it automatically keeps tracked of whether they were called and how often.

Anyway, instead of using local closure variables, you’d just test mockInstance.results.whatever to find out whether things were called or not.

Ahh, so we could stub the mock's method for causing timeouts. I dig it 👍

I typically use live data instead of mocks but that's a neat technique =)

Fwiw, we don't need currentSubscriptionCount but if we did, it would always be subscribedCount - unsubscribedCount =/

This file is quite lengthy and isn't broken down, where would the class definition live?

Yeah, I am also reminded of how painfully long the test file is whenever I look at it—I think it’s a consequence of it having grown pretty organically and the Segment team not seeming to put much effort into this project anymore.

In the past, I’ve added support items to the bottom where there are a few such things (see this custom Chai assertion, for example), but I think a mock class like I’m suggesting would be too big for that. I’d either:

Just put it in a separate file in the same directory (e.g. how server.js is)

Create a test/support directory and put it in there

Maybe we could break out the frame manager tests into their own file altogether? It's only 1 test prior this this, it would eliminate worries, and it would more towards a cleaner repo (i.e. 1 test file per 1 repo file)

Maybe we could break out the frame manager tests into their own file altogether?

Sure. To be painfully honest, I don’t think I really have enough personal investment in Nightmare to push for reorganizing the repo. I made some noise to this effect way back near the start of 2016 and felt like I was mostly talking to a brick wall with the repo owners. You might have a different/better experience now, though.

Fair enough. I guess we'll wait until we get feedback from an owner =/

Mr0grog · 2017-01-09T04:46:17Z

test/index.js

@@ -1463,6 +1463,139 @@ describe('Nightmare', function () {
      didSubscribe.should.be.false;
    });

+    it('should subscribe to frames when requested necessary', function(done) {


I think this would read better as just “should subscribe to frames when requested”

Mr0grog · 2017-01-09T05:02:03Z

test/index.js

+      });
+    });
+
+    // DEV: We can have multiple timeouts if page is static


For what it’s worth, the entire point of #927 was to not have timeouts when the page is static ;)
(The timeout guard should really never fire at all, but is there just in case the debugger fails in ways it should probably not be able to or its API has a breaking change.)

Relatedly, I might re-title this test to something like “should time out with null data when debugger fails.”

Ah, interesting. I was getting consistent timeouts hence my PR in the first place o_o The script can be found here:

https://github.com/twolfson/multi-image-mergetool/blob/1.32.1/bin/_build-demo-screenshots.js#L75-L164

Well, that seems very bad. 😰

@twolfson do you have a more reduced test case than the script you linked to that demonstrates timeouts?

Can you file a separate issue, then? And include what version of Electron you are using, since that affects the debugger API?

Sure thing, I'm not in a place where I have the details but I'll do that later and cc you on it 👍

Thanks! No rush; I’m just about certain I won’t have time to look at it today anyway.

Fwiw, my guess is electron@1.4.13 as I was wrote that script 2/3 days ago and there hasn't been a new electron release in 20 days

https://github.com/electron/electron/releases

https://github.com/segmentio/nightmare/blob/2.9.1/package.json#L23

Finally got around to making a minimal version for you. Sorry about the delay, I accidentally archived the email and then forgot about it until today. Here's the issue:

#955

Mr0grog · 2017-01-09T05:02:09Z

test/index.js

+              }
+            }
+          },
+          beginFrameSubscription: function(_fn) { subscribeCount += 1; assert.strictEqual(fn, null); fn = _fn; },


Is there a particular reason to use assert here instead of Chai? e.g. should.not.exist(fn);

There is! =D I prefer to use assert like a developer sanity check and should/expect for test assertions. It's kind of like undefined and null (i.e. one is for the system, one is for programmers)

I'm glad to change this based on the repo's coding styles but I didn't see any programmatic assert sanity checks when browsing =/

I'm glad to change this based on the repo's coding styles but I didn't see any programmatic assert sanity checks when browsing

There aren’t. I generally like to do that, too, but I my perception on this is that any assertion that only exists in the context of a test is a test assertion, not an “is the program in a good state” assertion. But I’m definitely not in charge of the coding style here at all.

Hmm, I would say it's on the fence. On one hand, it's faking out the beginFrameSubscription to prevent it's receiveFrame multiple times (i.e. programmatic). On the other hand, it's verifying that our async.times doesn't invoke the beginFrameSubscription multiple times (i.e. assertion)

On one hand, it's faking out the beginFrameSubscription to prevent it's receiveFrame multiple times (i.e. programmatic). On the other hand, it's verifying that our async.times doesn't invoke the beginFrameSubscription multiple times (i.e. assertion)

Wellllllllll, in the sense that it’s mocking Electron’s behavior, Electron allows beginFrameSubscription to be called multiple times—it just replaces the existing subscriber with no checks: https://github.com/electron/libchromiumcontent/blob/2249b37b0c3cb2e7ab4e333fbd3f87356beba55f/patches/guest_view.patch#L33-L36

I do think it’s totally reasonable for the test to be checking that we never call that method unless we’ve never subscribed or have already ended the subscription. In my book, that’s more of a test assertion.

But either way, I don’t think it’s a huge deal.

Mr0grog · 2017-01-09T05:07:20Z

lib/frame-manager.js

@@ -32,7 +31,7 @@ function FrameManager(window) {
  this.on('removeListener', unsubscribe);

  function subscribe(eventName) {
-    if (!subscribed && eventName === 'data') {
+    if (!self.listenerCount('data') && eventName === 'data') {


Oh, geez, I really lost track of cleaning up that subscribed flag! This approach is way better 👍

twolfson · 2017-01-09T10:26:16Z

Thanks for the feedback @Mr0grog =) I left 👍 on comments I will definitely take care of and feedback on other ones for longer discussions. I'm going to wait until repo owners leave comments until I take care of the 👍'd comments though (saves me time with less context switching)

twolfson · 2017-01-10T01:28:16Z

@Mr0grog On a tangent, did we ever explore using requestAnimationFrame instead of trying to force a DOM redraw?

Mr0grog · 2017-01-10T01:30:40Z

@Mr0grog On a tangent, did we ever explore using requestAnimationFrame instead of trying to force a DOM redraw?

Yes. It turned out not to trigger anything—it only schedules things for the next time a frame is prepared (before drawing).

twolfson · 2017-01-10T01:32:07Z

Ah, alright. Worth asking about. Thanks =)

Mr0grog · 2017-01-10T01:33:10Z

Haha, no worries, I would have definitely asked the same question if I were in your position :)

Mr0grog · 2017-01-20T22:55:16Z

The fix for two other issues (#955, #964) depends on the changes here and is also in the same area of the codebase. There’s an outline for what needs to change in #955, but I don’t really want to do that work until this PR is mostly set to go because they will conflict.

cscanlin · 2017-03-23T09:54:33Z

I'm having this an issue with nightmare 2.10.0 that I believe is related to this PR.

Specifically for taking screenshots with varying viewport sizes:

Here's a debug log on a crashed run:

  nightmare:log did-frame-finish-load [{},true] +4ms
  nightmare:log did-finish-load [{}] +0ms
  nightmare:log page-favicon-updated [{},["http://cscanlin.github.io/periodic-table-timeline/beaker.ico"]] +0ms
  nightmare:log did-stop-loading [{}] +1ms
  nightmare:actions .viewport() +0ms
  nightmare:actions .screenshot() +57ms
  nightmare:log subscribing to browser window frames +1ms

And here's a debug log when it finished successfully:

 nightmare:log did-frame-finish-load [{},true] +28ms
 nightmare:log did-finish-load [{}] +1ms
 nightmare:log page-favicon-updated [{},["http://cscanlin.github.io/periodic-table-timeline/beaker.ico"]] +0ms
 nightmare:log did-stop-loading [{}] +0ms
 nightmare:actions .viewport() +1ms
 nightmare:actions .screenshot() +40ms
 nightmare:log subscribing to browser window frames +1ms
 nightmare:log Highlighting page to trigger rendering. +0ms
 nightmare:log unsubscribing from browser window frames +108ms
 nightmare:actions .screenshot() captured with length 104999 +296ms

Will this PR fix my issue? If so, and idea when it might be merged?

Thanks in advance, and let me know if I can provide more detail.

twolfson · 2017-03-23T10:01:07Z

@cscanlin It looks similar to my problem so I would bet it would fix it. Since this PR hasn't been touched in 2 months and as @Mr0grog has previously suggested, we're probably going to be waiting for a while.

I suggest working around it in the meantime by pointing to a fork. This can be done via git URLs in your package.json:

https://docs.npmjs.com/files/package.json#git-urls-as-dependencies

https://github.com/twolfson/multi-image-mergetool/blob/1.32.1/package.json#L90

cscanlin · 2017-03-23T10:17:41Z

@twolfson That did the trick, thanks! On that note, I was also able to merge your branch with the master branch with 0 conflicts. Are there any other major roadblocks in getting this deployed? @Mr0grog, you said that this branch will actually open up the path for even more fixes (in addition to fixing this issue), so it seems like an easy win. Thoughts?

Mr0grog · 2017-03-23T16:57:10Z

@cscanlin I don’t think anybody who has commented here has any commit rights, so I dunno. It doesn’t seem like there should be any roadblocks here and I would think this should be high priority since it’s really easy to trigger it and hang Nightmare.

Paging @rosshinkley…

https://github.com/segmentio/nightmare/pull/945/commits

ledniy · 2017-05-04T20:44:27Z

So why it's not merged? Without it screenshot doesn't work properly

cianbuckley · 2017-06-09T09:55:17Z

could this be merged? currently creating my own nightmare version to patch this...

keithkml · 2017-10-13T19:30:31Z

Are there any plans to cut a release of Nightmare to include this fix? Or should I start building my code against master?

nettofarah · 2017-10-13T21:01:35Z

cc @fouad

twolfson added 9 commits January 7, 2017 02:52

Added normal frame manager test

05b634d

Caught and fixed an edge case

ca2ee0d

Completed more tests

736dfc2

Added cleanup

397bbe9

Caught edge case

ead9129

Completed test/fixes

2e784a3

Removed dev .only

b7fb5ea

Consolidated code into a single definition

cf19f08

Removed dev .only

716336f

twolfson mentioned this pull request Jan 7, 2017

Screenshot action hangs application #555

Closed

Mr0grog reviewed Jan 9, 2017

View reviewed changes

twolfson mentioned this pull request Jan 12, 2017

Screenshots timing out #955

Closed

Mr0grog mentioned this pull request Jan 20, 2017

Random glitch when capturing screenshot #964

Open

FredrikNoren pushed a commit to FredrikNoren/nightmare that referenced this pull request Apr 12, 2017

PR segment-boneyard#945

24f8c28

https://github.com/segmentio/nightmare/pull/945/commits

casesandberg merged commit dbb1b64 into segment-boneyard:master Aug 31, 2017

Repaired support for multiple timeouts in FrameManager #945

Repaired support for multiple timeouts in FrameManager #945

Conversation

twolfson commented Jan 7, 2017 • edited by casesandberg

Mr0grog left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Mr0grog Jan 10, 2017 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Mr0grog Jan 10, 2017 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

twolfson commented Jan 9, 2017

twolfson commented Jan 10, 2017

Mr0grog commented Jan 10, 2017 • edited

twolfson commented Jan 10, 2017

Mr0grog commented Jan 10, 2017

Mr0grog commented Jan 20, 2017

cscanlin commented Mar 23, 2017

twolfson commented Mar 23, 2017 • edited

cscanlin commented Mar 23, 2017

Mr0grog commented Mar 23, 2017

ledniy commented May 4, 2017

cianbuckley commented Jun 9, 2017

keithkml commented Oct 13, 2017

nettofarah commented Oct 13, 2017

twolfson commented Jan 7, 2017 •

edited by casesandberg

Mr0grog Jan 10, 2017 •

edited

Mr0grog Jan 10, 2017 •

edited

Mr0grog commented Jan 10, 2017 •

edited

twolfson commented Mar 23, 2017 •

edited