Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: Support more than 100 long-lived streams #623

Merged
merged 10 commits into from
May 16, 2019

Conversation

schmidt-sebastian
Copy link
Contributor

Fixes firebase/firebase-admin-node#499

This is a different approach to #614 and solves the same problem. It re-uses more of the original code to achieve the same result. Instead of releasing the client back to the pool when a stream is marked as established, we instead keep it around until the stream is closed.

@googlebot googlebot added the cla: yes This human has signed the Contributor License Agreement. label May 15, 2019
Copy link
Contributor

@wilhuff wilhuff left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like the high level way this works better than the way I did it.

dev/src/index.ts Outdated
@@ -1176,7 +1174,7 @@ export class Firestore {
let endCalled = false;

return new Promise((resolve, reject) => {
const streamReady = () => {
const releaseStream = () => {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't like this name. "released" can be confused with releasing back into the pool. I certainly was confused that way when reading this.

This promise represents that the stream is ready for use or initialized or something like that.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I changed the PR to keep the renames of your original commit.

dev/src/index.ts Show resolved Hide resolved
dev/src/index.ts Outdated
});
return this._initializeStream(resultStream, requestTag, request);
})
.then(stream => {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

async/await?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I cleaned this up. I also removed the return value from _initializeStream as part of this since we always return the unmodified resultStream.

@codecov
Copy link

codecov bot commented May 15, 2019

Codecov Report

Merging #623 into master will increase coverage by 0.02%.
The diff coverage is 100%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master     #623      +/-   ##
==========================================
+ Coverage   61.45%   61.47%   +0.02%     
==========================================
  Files          21       21              
  Lines        3409     3411       +2     
  Branches      460      459       -1     
==========================================
+ Hits         2095     2097       +2     
  Misses       1252     1252              
  Partials       62       62
Impacted Files Coverage Δ
dev/src/pool.ts 97.14% <ø> (-0.36%) ⬇️
dev/src/index.ts 95.14% <100%> (+0.11%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 83c5dd9...0ffaee6. Read the comment docs.

@codecov
Copy link

codecov bot commented May 15, 2019

Codecov Report

Merging #623 into master will increase coverage by 0.16%.
The diff coverage is 100%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master     #623      +/-   ##
==========================================
+ Coverage   61.52%   61.68%   +0.16%     
==========================================
  Files          21       21              
  Lines        3407     3422      +15     
  Branches      460      459       -1     
==========================================
+ Hits         2096     2111      +15     
  Misses       1250     1250              
  Partials       61       61
Impacted Files Coverage Δ
dev/src/index.ts 95.19% <100%> (+0.17%) ⬆️
dev/src/util.ts 100% <100%> (ø) ⬆️
dev/src/pool.ts 97.36% <100%> (-0.14%) ⬇️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 43ac9c6...29caec6. Read the comment docs.

});

const resultStream = bun([stream, logStream]);
resultStream.on('close', lifetime.resolve);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Are streams guaranteed to emit the close event? What happens in the case of an error?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

According to https://nodejs.org/api/stream.html, yes:

"A Writable stream will always emit the 'close' event if it is created with the emitClose option."
"A Readable stream will always emit the 'close' event if it is created with the emitClose option."

emitClose defaults to true.

I originally trusted this, but I spent more time and added test asserts. It turns out that the close event is not always emitted. To make the unit and system tests pass, I also have to wait for error/end and finish on writeable streams.

await Promise.all(emptyResults.map(d => d.promise));
ref.set({i: 1337});
await Promise.all(documentResults.map(d => d.promise));
unsubscribeCallbacks.forEach(c => c());
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This test verifies that all 150 listeners succeed but doesn't verify that everything has been properly released to the pool.

Is it possible to check that pool.size is 150 once the listeners are started and then get back to zero after?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I worry that this test can succeed even if you remove the line that resolves the lifetime promise.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I added a "shutdown" block to each tests that verifies that the operation count goes back to zero. I had to change some of the unit tests to make this work.

@wilhuff wilhuff assigned schmidt-sebastian and unassigned wilhuff May 15, 2019
@JustinBeckwith JustinBeckwith changed the title Fix: Support more than 100 long-lived streams fix: Support more than 100 long-lived streams May 15, 2019
@wilhuff
Copy link
Contributor

wilhuff commented May 15, 2019

This is now failing tests under node 8:

  1) Query watch
       re-opens on unexpected stream end:
      Expected message of type 'end' but got 'open' with '{}'.
      + expected - actual
      -open
      +end
      at DeferredListener.await (build/test/watch.js:143:41)
      at StreamHelper.await (build/test/watch.js:186:43)
      at watchHelper.await.then (build/test/watch.js:604:41)
      at <anonymous>
  2) Query watch
       "after each" hook for "re-opens on unexpected stream end":
      AssertionError: expected 1 to equal 0
      + expected - actual
      -1
      +0
      at Object.verifyInstance (build/test/util/helpers.js:87:56)
      at Context.afterEach (build/test/watch.js:544:19)

LGTM otherwise.

@wilhuff wilhuff removed their assignment May 15, 2019
Copy link
Contributor

@wilhuff wilhuff left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. Awesome!

@schmidt-sebastian
Copy link
Contributor Author

The test failure for Node 8 was due to a flake, which I fixed.

@schmidt-sebastian schmidt-sebastian merged commit 9474e3f into master May 16, 2019
@schmidt-sebastian schmidt-sebastian deleted the mrschmidt-streamclose branch May 17, 2019 22:56
@jakeleventhal
Copy link

@wilhuff @schmidt-sebastian I just upgraded to @google-cloud/[email protected] and since upgrading, I've been getting all of these warnings that say:
(node:2870) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connectivityStateChanged listeners added. Use emitter.setMaxListeners() to increase limit

I read through the release notes and found that this thread is probably the reason that I am seeing these warnings. I tried downgrading back to v1.3.0 and no longer saw the messages in my logs. I believe that it makes sense to take care of the warning that I'm seeing within the @google-cloud/firestore package itself, as the user doesn't really have a good way to know when the listeners will be added.

What are your guys' thoughts?

@schmidt-sebastian
Copy link
Contributor Author

schmidt-sebastian commented May 28, 2019

@jakeleventhal Thanks for letting us know! I think I have seen this warning once before as well, so it may indeed be related to this change (which adds a lot of listeners). I filed #661 to track this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
cla: yes This human has signed the Contributor License Agreement.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Firestore: Deadline Exceeded, retrying doesn't help
4 participants