[switch] ensure all connections are closed on switch stop #436

alanshaw · 2018-10-22T10:34:54Z

I'm using why-is-node-running to inspect what's causing node to keep running after ipfs.stop() is called. I think the "latency-monitor" one is a red herring as these timeouts are unref'd:

There are 32 handle(s) keeping the process running

# Timeout
/Users/alan/Desktop/test/node_modules/latency-monitor/dist/LatencyMonitor.js:163 - this._emitIntervalID = setInterval(function () {
/Users/alan/Desktop/test/node_modules/latency-monitor/dist/LatencyMonitor.js:141 - that._startTimers();
/Users/alan/Desktop/test/node_modules/libp2p-connection-manager/src/index.js:53  - this._latencyMonitor = new LatencyMonitor({
/Users/alan/Desktop/test/node_modules/libp2p/src/index.js:157                    - this.connectionManager.start()

# TCPWRAP
/Users/alan/Desktop/test/node_modules/libp2p-tcp/src/index.js:30                 - const rawSocket = net.connect(cOpts)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:79 - const conn = transport.dial(addr, (err) => {
/Users/alan/Desktop/test/node_modules/async/timeout.js:86                        - fn.apply(null, args);
/Users/alan/Desktop/test/node_modules/async/internal/initialParams.js:11         - fn.call(this, args, callback);
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:86 - }, this.dialTimeout)(callback)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:41 - this._dialWithTimeout(transport, addr, (err, conn) => {

# TCPWRAP
/Users/alan/Desktop/test/node_modules/libp2p-tcp/src/index.js:30                 - const rawSocket = net.connect(cOpts)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:79 - const conn = transport.dial(addr, (err) => {
/Users/alan/Desktop/test/node_modules/async/timeout.js:86                        - fn.apply(null, args);
/Users/alan/Desktop/test/node_modules/async/internal/initialParams.js:11         - fn.call(this, args, callback);
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:86 - }, this.dialTimeout)(callback)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:41 - this._dialWithTimeout(transport, addr, (err, conn) => {

# TCPWRAP
/Users/alan/Desktop/test/node_modules/libp2p-tcp/src/index.js:30                 - const rawSocket = net.connect(cOpts)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:79 - const conn = transport.dial(addr, (err) => {
/Users/alan/Desktop/test/node_modules/async/timeout.js:86                        - fn.apply(null, args);
/Users/alan/Desktop/test/node_modules/async/internal/initialParams.js:11         - fn.call(this, args, callback);
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:86 - }, this.dialTimeout)(callback)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:41 - this._dialWithTimeout(transport, addr, (err, conn) => {

# TCPWRAP
/Users/alan/Desktop/test/node_modules/libp2p-tcp/src/index.js:30                 - const rawSocket = net.connect(cOpts)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:79 - const conn = transport.dial(addr, (err) => {
/Users/alan/Desktop/test/node_modules/async/timeout.js:86                        - fn.apply(null, args);
/Users/alan/Desktop/test/node_modules/async/internal/initialParams.js:11         - fn.call(this, args, callback);
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:86 - }, this.dialTimeout)(callback)
/Users/alan/Desktop/test/node_modules/libp2p-switch/src/limit-dialer/queue.js:41 - this._dialWithTimeout(transport, addr, (err, conn) => {

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# TLSWRAP
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# HTTPPARSER
(unknown stack trace)

# Timeout
/Users/alan/Desktop/test/ls-bug.js:33 - setTimeout(() => log(), 10000)

# Timeout
/Users/alan/Desktop/test/node_modules/latency-monitor/dist/LatencyMonitor.js:268 - this._checkLatencyID = setTimeout(function () {
/Users/alan/Desktop/test/node_modules/latency-monitor/dist/LatencyMonitor.js:257 - that._checkLatency(); // Start again ASAP
/Users/alan/Desktop/test/node_modules/latency-monitor/dist/LatencyMonitor.js:281 - cb();

The text was updated successfully, but these errors were encountered:

alanshaw · 2018-10-22T10:37:44Z

Example script:

const IPFS = require('ipfs')
const Path = require('path')
const Os = require('os')
const log = require('why-is-node-running')

const ipfs = new IPFS({ repo: Path.join(Os.tmpdir(), `${Date.now()}`) })

ipfs.on('ready', async () => {
  const files = Array.from([1, 2, 3], i => ({
    path: `test-file-${Date.now()}-${i}`,
    content: Buffer.from(`data ${Date.now()} ${i}`)
  }))

  const res = await ipfs.files.add(files, { wrapWithDirectory: true })

  console.log('Added files:')
  console.log(res)

  const { hash } = res[res.length - 1]

  const ipfsPath = `/ipfs/${hash}`
  console.log(`Copying from ${ipfsPath}`)

  const mfsPath = `/test-dir-${Date.now()}`
  console.log(`Copying to ${mfsPath}`)

  await ipfs.files.cp(ipfsPath, mfsPath)

  console.log(`Directory listing of ${mfsPath}:`)
  console.log(await ipfs.files.ls(mfsPath))

  await ipfs.stop()
  setTimeout(() => log(), 10000)
})

jacobheun · 2018-10-22T12:43:14Z

There are timeouts in latency-monitor, but all refs are removed on shutdown. There are private methods on the latency-monitor for turning off the timers, ideally we'd be able to shut those down, but it shouldn't be an issue for this.

The TCPWRAP logs are due to open dial attempts. I think we need to make sure Switch is cancelling dials as best it can when shutting down. I didn't see these locally since I didn't have active dials, but it should get addressed regardless. The new state machine updates may help us with that.

TLSWRAP and HTTPPARSER appear to be ipfs related, as best I can tell right now. I've got the libp2p internals for the example above replicated without ipfs, except for the data exchange, and I am not seeing either of those logs.

jacobheun · 2018-10-22T21:18:05Z

@alanshaw it looks like the TLSWRAP and HTTPPARSER logs go away when preloading is disabled on ipfs.

alanshaw · 2018-10-23T12:19:30Z

Preloading requests are tracked and canceled when the node is stopped https://github.com/ipfs/js-ipfs/blob/master/src/core/preload.js#L76-L81. Unless something has changed in a new Node.js version I don't think these are problematic as that code hasn't changed now for 3 months.

This is a very recent change. I noticed because all the examples here used to exit when done but now don't :(

jacobheun · 2018-10-23T16:14:38Z

Okay, I can replicate that now with the read+write iterator example. It looks like if the node is running long enough and attempts to stop there may be several queued dial calls, even if switch is stopped. I'm looking into making the queue abortable.

jacobheun · 2018-10-24T11:52:17Z

After look at this more there are a few things we're going to need to make sure are happening for graceful shutdowns, several of which aren't currently happening.

TODO List

1. Shutdown all listeners to prevent incoming dials.
Right now shutting down some listeners causes all existing connections to close ungracefully, which will throw errors. Related to https://github.com/libp2p/js-libp2p-switch/issues/251.
2. Clear dialing queues so no new dials will happen. [switch] Clear dialing queues when switch is shutting down #432
3. Close all open and dialing connection.
We can currently close open connections fairly easily, especially muxed connections. We need to add abort logic to the transports so that we can abort new connections.
4. Prevent dials when the switch is starting/stopping/stopped. https://github.com/libp2p/js-libp2p-switch/issues/293
Right now the dialer doesn't care what state the switch is in; it needs to. The latest state machine update should make this easy.

jacobheun · 2018-12-14T16:52:21Z

This has marginally improved with 0.41.3. Closing out in progress dials is the major issue left to resolve.

alanshaw · 2018-12-16T22:16:23Z

@jacobheun can you post the links to the PRs that are solving the issues you listed in https://github.com/libp2p/js-libp2p-switch/issues/281#issuecomment-432624680?

jacobheun · 2018-12-17T11:48:29Z

I added issues that were missing to complete this work and updated the todo list in the comment, https://github.com/libp2p/js-libp2p-switch/issues/281#issuecomment-447384312. There are several issues that need to be completed for in progress/queued dials, so it's still a significant amount of work left.

The marginal improvement was the result of a fixed bug where not all connections were being properly closed, libp2p/js-libp2p-switch#291. They are now being tracked better, and are also closing the underlying duplex stream, which they weren't previously doing.

## [8.0.4](libp2p/js-libp2p-kad-dht@v8.0.3...v8.0.4) (2023-03-30) ### Bug Fixes * correction package.json exports types path ([libp2p#436](libp2p/js-libp2p-kad-dht#436)) ([5024646](libp2p/js-libp2p-kad-dht@5024646))

maschad · 2023-09-28T21:44:46Z

Closing due to staleness

jacobheun changed the title ~~Holding node process open after libp2p stopped~~ ensure all connections are closed on switch stop Oct 24, 2018

daviddias changed the title ~~ensure all connections are closed on switch stop~~ [switch] ensure all connections are closed on switch stop Aug 22, 2019

daviddias transferred this issue from libp2p/js-libp2p-switch Aug 22, 2019

p-shahi added the kind/stale label May 30, 2023

maschad pushed a commit to maschad/js-libp2p that referenced this issue Jun 21, 2023

fix: correction package.json exports types path (libp2p#436)

5024646

nflaig mentioned this issue Jul 12, 2023

Beacon node active handles after close sequence is completed ChainSafe/lodestar#5642

Open

nflaig mentioned this issue Aug 5, 2023

Network worker not shutting down ChainSafe/lodestar#5775

Open

maschad closed this as completed Sep 28, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[switch] ensure all connections are closed on switch stop #436

[switch] ensure all connections are closed on switch stop #436

alanshaw commented Oct 22, 2018

alanshaw commented Oct 22, 2018

jacobheun commented Oct 22, 2018 •

edited

Loading

jacobheun commented Oct 22, 2018

alanshaw commented Oct 23, 2018

jacobheun commented Oct 23, 2018

jacobheun commented Oct 24, 2018 •

edited

Loading

jacobheun commented Dec 14, 2018

alanshaw commented Dec 16, 2018 •

edited

Loading

jacobheun commented Dec 17, 2018

maschad commented Sep 28, 2023

[switch] ensure all connections are closed on switch stop #436

[switch] ensure all connections are closed on switch stop #436

Comments

alanshaw commented Oct 22, 2018

alanshaw commented Oct 22, 2018

jacobheun commented Oct 22, 2018 • edited Loading

jacobheun commented Oct 22, 2018

alanshaw commented Oct 23, 2018

jacobheun commented Oct 23, 2018

jacobheun commented Oct 24, 2018 • edited Loading

TODO List

jacobheun commented Dec 14, 2018

alanshaw commented Dec 16, 2018 • edited Loading

jacobheun commented Dec 17, 2018

maschad commented Sep 28, 2023

jacobheun commented Oct 22, 2018 •

edited

Loading

jacobheun commented Oct 24, 2018 •

edited

Loading

alanshaw commented Dec 16, 2018 •

edited

Loading