Debug log of pubsub subscribe getting stalled

[v-stickykeys]

• Version:

Http Client

"ipfs-http-client": "48.1.1",

Daemon

js-ipfs version: 0.3.1-6b207d77cd66bc5326f260221e53914192807861
interface-ipfs-core version: ^0.142.3
ipfs-http-client version: undefined
Repo version: 9
System version: x64/darwin
Node.js version: v12.18.4
Commit: 6b207d7

• Platform:

Darwin MBP 19.6.0 Darwin Kernel Version 19.6.0: Mon Aug 31 22:12:52 PDT 2020; root:xnu-6153.141.2~1/RELEASE_X86_64 x86_64

• Subsystem:

Pubsub / debug

Severity:

Medium - because it could be indicative of some larger issue

Description:

When running pubsub.subscribe from the http client, the API's debug logs are not showing requests to "/api/v0/pubsub/sub" until the client process is exited.

This seems to be just a logging issue but it is concerning that it could be a symptom of an underlying problem--hopefully not!

Steps to reproduce the error:

1. Start the daemon with debug logs enabled

DEBUG=ipfs* jsipfs daemon

2. Run an http client script connected to the daemon

const ipfsClient = require("ipfs-http-client")

const topic = process.env.TOPIC || '/ceramic/dev-unstable'
const ipfsApiUrl = process.env.IPFS_API_URL || 'http://localhost:5011'

const run = async () => {
  const ipfs = ipfsClient({ url: ipfsApiUrl })

  const receiveMsg = (msg) => { console.log('receiving', JSON.stringify(msg)) }

  await ipfs.pubsub.subscribe(topic, receiveMsg, { timeout: 500 })
    .then(async () => {
      console.log('subscribe success')
      console.log('subscriptions')
      console.log(await ipfs.pubsub.ls({ timeout: 500 }))
    })
    .catch((err) => {
      console.error('subscribe failure', err.message)
    })
}

run()

3. Notice the daemon logs calls to /pubsub/ls and the client shows the topic is listed in subscriptions
4. Stop the client script
5. Notice the daemon now logs the /pubsub/sub call that was made earlier and the response time exceeds the timeout set

[Gozala]

@valmack thanks for taking time to report this. I'll looking into this as well as I make changes for #3465. I think there are two things here if I'm reading it right:

1. Server not logging things until connection is closed
2. No respect for timeouts.

I'll definitely make sure to address no 2 as part of #3465, as of no 1 I wonder if that might be a clue to #3469 and/or #3464

[v-stickykeys]

@Gozala Yes 1 and 2 are exactly right thanks.

and yeah no 1 does seem indicative of a memory leak or some other issue--the fact that it doesn't break or surface on the client side makes it appear as though the response is being sent from the api, and some work in the api after that response gets sent is not resolving.

[SgtPooki]

js-ipfs is being deprecated in favor of Helia. You can #4336 and read the migration guide.

Please feel to reopen with any comments by 2023-06-02. We will do a final pass on reopened issues afterward (see #4336).

This issue won't be fixed in js-ipfs but you can check out kubo-rpc-client for your ipfs-http-client needs when talking to Kubo.