Provide a way for closing sessions manually

drakhart commented 2 years ago

While trying to use this library I found two quirks when handling sessions: 1) There's no way (at least none that I've found) to manually and forcibly close a session. 2) Opening a session leaves the app running forever.

Running this code finishes ok (node process exits with code 0):

import { DocumentStore } from 'ravendb'

const ds = new DocumentStore('http://localhost:8080', 'test').initialize()

Running this doesn't finish:

import { DocumentStore } from 'ravendb'

const ds = new DocumentStore('http://localhost:8080', 'test').initialize()
ds.openSession()

Running this doesn't finish either:

import { DocumentStore } from 'ravendb'

const ds = new DocumentStore('http://localhost:8080', 'test').initialize()
ds.openSession()
ds.dispose()

It would be nice to check why the app continues to run even when it should exit (idk, maybe a stray setInterval?), and to provide a way for closing the sessions at will (pretty much like the Go and the beta PHP clients do).

ayende commented 2 years ago

There shouldn't be anything in the session that would cause it to hang.

Can you use https://github.com/mafintosh/why-is-node-running and see what is going on?

drakhart commented 1 year ago

Sure, I enclose the Why is Node running output below.

Please note: I didn't notice before that using .dispose() actually allows the Node process to exit, but only after exactly and consistently 16 seconds. In my prior tests I just assumed that the process was stale after more or less 5 seconds and did Ctrl+C. Without .dispose() it never exits (I waited up to 1 minute just to make sure).

Without `.dispose()`

Code:

import log from 'why-is-node-running'
import { DocumentStore } from 'ravendb'

const ds = new DocumentStore('http://localhost:8080', 'test').initialize()
ds.openSession()

setTimeout(() => log(), 100)

Output:

There are 5 handle(s) keeping the process running

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/debuggability.js:956 - if (util.isNode && process.stderr.isTTY) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/promise.js:75        - var debug = require("./debuggability")(Promise, Context,
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/bluebird.js:9        - var bluebird = require("./promise")();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:4       - const BluebirdPromise = require("bluebird");

# Timeout
file:///Users/drakhart/Documents/poc/ravendb-client/index.js:7

# Timeout
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:667 - const cancelTask = setTimeout(() => abortController.abort(), timeout);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:4   - return new (P || (P = Promise))(function (resolve, reject) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:662 - return __awaiter(this, void 0, void 0, function* () {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:598 - const responseAndStream = yield this._sendRequestToServer(chosenNode, nodeIndex, command, shouldRetry, sessionInfo, req, url, controller);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());

# DNSCHANNEL
(unknown stack trace)

# Timeout
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:19      - this._firstTimeDelayId = setTimeout(() => {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:11      - this._schedule(dueTimeInMs);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:554 - new Timer_1.Timer(function timerActionUpdateTopology() {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:508 - this._initializeUpdateTopologyTimer();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:5   - function fulfilled(value) { try { step(generator.next(value)); } catch (e) { reject(e); } }

With `.dispose()`

Code:

import log from 'why-is-node-running'
import { DocumentStore } from 'ravendb'

const ds = new DocumentStore('http://localhost:8080', 'test').initialize()
ds.openSession()
ds.dispose()

setTimeout(() => log(), 100)

Output:

There are 4 handle(s) keeping the process running

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/debuggability.js:956 - if (util.isNode && process.stderr.isTTY) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/promise.js:75        - var debug = require("./debuggability")(Promise, Context,
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/bluebird.js:9        - var bluebird = require("./promise")();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:4       - const BluebirdPromise = require("bluebird");

# Timeout
file:///Users/drakhart/Documents/poc/ravendb-client/index.js:8

# Timeout
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:667 - const cancelTask = setTimeout(() => abortController.abort(), timeout);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:4   - return new (P || (P = Promise))(function (resolve, reject) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:662 - return __awaiter(this, void 0, void 0, function* () {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:598 - const responseAndStream = yield this._sendRequestToServer(chosenNode, nodeIndex, command, shouldRetry, sessionInfo, req, url, controller);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());

# DNSCHANNEL
(unknown stack trace)

ml054 commented 1 year ago

Hi @drakhart

Thanks for reporting this issue.

I was able to reproduce your issue and working on fix.

For temporary workaround you can set store.conventions.disableTopologyUpdates = true;

You can track progress here: https://issues.hibernatingrhinos.com/issue/RDBC-626/nodejs-process-doesnt-finish

ml054 commented 1 year ago

Looks like bug is here: https://github.com/ravendb/ravendb-nodejs-client/blob/183f3ee6fd4fba7218767a21a9b55d90232d51ad/src/Http/RequestExecutor.ts#L996

If we throw during first request we don't clear timeout and that's the reason test lasts for ~15 seconds.

Could you repeat your test with server that is running, ex. you can use http://live-test.ravendb.net.

If I run this and server is running then dispose on store properly closes and finish node.js app. If I point to server which can't be reached app runs for 15 seconds and then finish.

Side note:

you don't have to dispose session
you should dispose store when applications exist - it holds periodic tasks like connection hearbeats etc - so if you finish program w/o calling dispose on DocumentStore - it won't finish.

drakhart commented 1 year ago

Sorry, my bad: I didn't notice that my Docker daemon wasn't running after the weekend. I restarted it and ran some more tests.

Here are some updated test cases:

Connect to running Docker container, without ds.dispose() -> process doesn't ever exit (even after 15-16 seconds)

Click here to see output

There are 6 handle(s) keeping the process running

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/debuggability.js:956 - if (util.isNode && process.stderr.isTTY) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/promise.js:75        - var debug = require("./debuggability")(Promise, Context,
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/bluebird.js:9        - var bluebird = require("./promise")();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:4       - const BluebirdPromise = require("bluebird");

# Timeout
file:///Users/drakhart/Documents/poc/ravendb-client/index.js:7

# DNSCHANNEL
(unknown stack trace)

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1597 - let body = res.pipe(new PassThrough$1());

# ZLIB
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1638 - body = body.pipe(zlib.createGunzip(zlibOptions));

# Timeout
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:19      - this._firstTimeDelayId = setTimeout(() => {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:11      - this._schedule(dueTimeInMs);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:554 - new Timer_1.Timer(function timerActionUpdateTopology() {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:466 - this._initializeUpdateTopologyTimer();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:5   - function fulfilled(value) { try { step(generator.next(value)); } catch (e) { reject(e); } }

Connect to running Docker container, with ds.dispose() -> process exits

Click here to see output

There are 5 handle(s) keeping the process running

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/debuggability.js:956 - if (util.isNode && process.stderr.isTTY) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/promise.js:75        - var debug = require("./debuggability")(Promise, Context,
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/bluebird.js:9        - var bluebird = require("./promise")();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:4       - const BluebirdPromise = require("bluebird");

# Timeout
file:///Users/drakhart/Documents/poc/ravendb-client/index.js:8

# DNSCHANNEL
(unknown stack trace)

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1597 - let body = res.pipe(new PassThrough$1());

# ZLIB
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1638 - body = body.pipe(zlib.createGunzip(zlibOptions));

Connect to live test server, without ds.dispose() -> process exits

Click here to see output

There are 7 handle(s) keeping the process running

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/debuggability.js:956 - if (util.isNode && process.stderr.isTTY) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/promise.js:75        - var debug = require("./debuggability")(Promise, Context,
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/bluebird.js:9        - var bluebird = require("./promise")();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:4       - const BluebirdPromise = require("bluebird");

# Timeout
file:///Users/drakhart/Documents/poc/ravendb-client/index.js:7

# Timeout
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:667 - const cancelTask = setTimeout(() => abortController.abort(), timeout);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:4   - return new (P || (P = Promise))(function (resolve, reject) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:662 - return __awaiter(this, void 0, void 0, function* () {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:598 - const responseAndStream = yield this._sendRequestToServer(chosenNode, nodeIndex, command, shouldRetry, sessionInfo, req, url, controller);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());

# TCPWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1468          - const req = send(options);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1437          - return new fetch.Promise(function (resolve, reject) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RavenCommand.js:107 - const response = yield (0, node_fetch_1.default)(uri, optionsToUse);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RavenCommand.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RavenCommand.js:4   - return new (P || (P = Promise))(function (resolve, reject) {

# DNSCHANNEL
(unknown stack trace)

# HTTPCLIENTREQUEST
(unknown stack trace)

# TCPCONNECTWRAP
(unknown stack trace)

Connect to live test server, with ds.dispose() -> process exits

Click here to see output

There are 7 handle(s) keeping the process running

# TTYWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/debuggability.js:956 - if (util.isNode && process.stderr.isTTY) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/promise.js:75        - var debug = require("./debuggability")(Promise, Context,
/Users/drakhart/Documents/poc/ravendb-client/node_modules/bluebird/js/release/bluebird.js:9        - var bluebird = require("./promise")();
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Primitives/Timer.js:4       - const BluebirdPromise = require("bluebird");

# Timeout
file:///Users/drakhart/Documents/poc/ravendb-client/index.js:8

# Timeout
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:667 - const cancelTask = setTimeout(() => abortController.abort(), timeout);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:4   - return new (P || (P = Promise))(function (resolve, reject) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:662 - return __awaiter(this, void 0, void 0, function* () {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:598 - const responseAndStream = yield this._sendRequestToServer(chosenNode, nodeIndex, command, shouldRetry, sessionInfo, req, url, controller);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RequestExecutor.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());

# TCPWRAP
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1468          - const req = send(options);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/node-fetch/lib/index.js:1437          - return new fetch.Promise(function (resolve, reject) {
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RavenCommand.js:107 - const response = yield (0, node_fetch_1.default)(uri, optionsToUse);
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RavenCommand.js:8   - step((generator = generator.apply(thisArg, _arguments || [])).next());
/Users/drakhart/Documents/poc/ravendb-client/node_modules/ravendb/dist/Http/RavenCommand.js:4   - return new (P || (P = Promise))(function (resolve, reject) {

# DNSCHANNEL
(unknown stack trace)

# HTTPCLIENTREQUEST
(unknown stack trace)

# TCPCONNECTWRAP
(unknown stack trace)

I'll try to dispose the document store in my main app after opening a session, as you suggest, and see if that allows it to finish ok.

ml054 commented 1 year ago

Thanks for investigation.

Please remember DocumentStore should live during application live. There is no point to dispose that when app is running.

Will try to fix setTimeout issue shortly. :)

ml054 commented 1 year ago

Fixed https://github.com/ravendb/ravendb-nodejs-client/pull/333

ravendb / ravendb-nodejs-client