Halt when accessing CID served on a nodejs helia node from a browser helia node

bellbind commented 11 months ago

There are 3 helia nodes that are:

nodejs: served pinned content of the CID
- using plain createHelia()
browser: accessing with the CID
- run on chromium page of playwright
- using helia package and its dependencies is built with esbuild from local node_modules
- with custom config for connecting to local helia nodes
middle: connected from both nodejs and browser helia nodes
- with custom config for connected from browser helia nodes
- nodejs connects middle with nodejs.libp2p.dialProtocol(middle.libp2p.getMultiaddrs()[0], nodejs.libp2p.getProtocols())
- browser connects with bootstrap() config that list is only middle.libp2p.getMultiaddrs()

I tried to resolve content data of a cid served on nodejs helia nodes from browser helia nodes. But browser helia nodes halt when unixfs(browser).stat(cid) or unixfs(browser).cat(cid). (libp2p.contentRouting.findProviders(cid) can resolve peerId and multiaddrs of the nodejs helia node)

It is success that accessing CID from nodejs to browser.

And after accessed from a nodejs node to a browser node, it can access CID from same browser node to same nodejs node.

The complete codes are in https://gist.github.com/bellbind/5565c22255ae87a3c8e9948b467ee894 :

case-halt.mjs: halting case that resolve cid from browser to nodejs
case-success.mjs: successed case that resolved other cid from nodejs to browser before resolving from browser to nodejs

other files:

nodejs.js and browser.js: code of creating and connecting helia nodes
- for creating new browser helia node, served info of middle with http server
npm-libs.js: source of npm-browser.js for esbuild (complete command line options in package.json)
index.html: importmap only empty html file for loading playwright pages
- with http-server package to serve this index.html and the built npm-browser.js by http: URLs
package.json: minimal dependencies and esbuild command line

My environment is node-v20.5.1-darwin-arm64.tar.gz on M1 macbook air.

whizzzkid commented 11 months ago

Thanks for submitting this detailed issue @bellbind!

@achingbrain I think this another example of a locking, initially described here: https://github.com/ipfs/helia/pull/99, I never got around reproducing the test case as it would lock the test runner too. I believe the underlying cause is the same.

And after accessed from a nodejs node to a browser node, it can access CID from same browser node to same nodejs node.

I think at that point it's in the store, so it's serviceable right away.

bellbind commented 11 months ago

On my manual tracing, the halt point of case-halt.mjs is fetchFromNetwork in want() of bitswap.ts in js-ipfs-bitswap package.

https://github.com/ipfs/js-ipfs-bitswap/blob/master/src/bitswap.ts#L226

Digging into await calls, difference between case-success.mjs and case-halt.mjs is inbitswap's WantManager._addEntries():

case-success.mjs: calls wantlist.remove() then p.addEntries()
case-halt..mjs: calls wantlist.add()
https://github.com/ipfs/js-ipfs-bitswap/blob/master/src/want-manager/index.ts#L41C29-L60

I added console.log() lines into npm-browser.js bundle.

modified npm-browser.js: https://gist.github.com/bellbind/3890edd52277693241866aa367ebe73f

Trace of case-halt.mjs:

....
{ url: '', lineNumber: 7, columnNumber: 12 } [peer.protocolss.length] 0
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 36604,
  columnNumber: 12
} [get] lock
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 36606,
  columnNumber: 12
} [get] locked
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 36760,
  columnNumber: 14
} want
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31586,
  columnNumber: 14
} [want] race
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31563,
  columnNumber: 16
} [want] loadOrFetchFromNetwork get
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31573,
  columnNumber: 18
} [want] loadOrFetchFromNetwork findAndConnect
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31579,
  columnNumber: 16
} [want] fetchFromNetwork
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31365,
  columnNumber: 12
} [bitswap WantManager] wantBlocks
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31311,
  columnNumber: 12
} [bitswap WantManager] _addEntries
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 31326,
  columnNumber: 16
} [bitswap WantManager] _addEntries wantlist.add
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 30872,
  columnNumber: 12
} [bitswap network] connectTo 12D3KooWE8N1wFNGGqj3fVXvya574TDfNWTknLGD56Z7q9ukVV1M
{
  url: 'http://localhost:60103/npm-browser.js',
  lineNumber: 30874,
  columnNumber: 12
} [bitswap network] done connectTo
^C

Trace of case-success.mjs:

...
{ url: '', lineNumber: 7, columnNumber: 12 } [peer.protocolss.length] 0
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36604,
  columnNumber: 12
} [get] lock
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36606,
  columnNumber: 12
} [get] locked
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36760,
  columnNumber: 14
} want
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31586,
  columnNumber: 14
} [want] race
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31563,
  columnNumber: 16
} [want] loadOrFetchFromNetwork get
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31573,
  columnNumber: 18
} [want] loadOrFetchFromNetwork findAndConnect
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31579,
  columnNumber: 16
} [want] fetchFromNetwork
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31365,
  columnNumber: 12
} [bitswap WantManager] wantBlocks
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31311,
  columnNumber: 12
} [bitswap WantManager] _addEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31326,
  columnNumber: 16
} [bitswap WantManager] _addEntries wantlist.add
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31331,
  columnNumber: 14
} [bitswap WantManager] _addEntries p.addEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31261,
  columnNumber: 12
} [bitswap MsgQueue] sendEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31250,
  columnNumber: 12
} [bitswap MsgQueue] addMessage
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31278,
  columnNumber: 14
} [bitswap MsgQueue send] connectTo
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30872,
  columnNumber: 12
} [bitswap network] connectTo 12D3KooWLCCAenwvP3SErYt9by5x8TYAGjHJ9V6eZ5gwB5ndsrag
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30874,
  columnNumber: 12
} [bitswap network] done connectTo
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31280,
  columnNumber: 14
} [bitswap MsgQueue send] done connectTo
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31286,
  columnNumber: 12
} [bitswap MsgQueue send] sendMessage
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30859,
  columnNumber: 12
} [bitswap sendMessage] _writeMessage
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30861,
  columnNumber: 12
} [bitswap sendMessage] _updateSentStats
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30795,
  columnNumber: 12
} [bitswap network] _onConnection
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30872,
  columnNumber: 12
} [bitswap network] connectTo 12D3KooWLCCAenwvP3SErYt9by5x8TYAGjHJ9V6eZ5gwB5ndsrag
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30874,
  columnNumber: 12
} [bitswap network] done connectTo
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31474,
  columnNumber: 14
} [bitswap] _receiveMessage
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31311,
  columnNumber: 12
} [bitswap WantManager] _addEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31321,
  columnNumber: 16
} [bitswap WantManager] _addEntries wantlist.remove
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31331,
  columnNumber: 14
} [bitswap WantManager] _addEntries p.addEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31648,
  columnNumber: 12
} [bitswap] notify
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30955,
  columnNumber: 16
} [onBlock]
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 30955,
  columnNumber: 16
} [onBlock]
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31597,
  columnNumber: 14
} [want] done race
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31311,
  columnNumber: 12
} [bitswap WantManager] _addEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31321,
  columnNumber: 16
} [bitswap WantManager] _addEntries wantlist.remove
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 31331,
  columnNumber: 14
} [bitswap WantManager] _addEntries p.addEntries
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36762,
  columnNumber: 14
} wanted
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36764,
  columnNumber: 14
} put
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36766,
  columnNumber: 14
} done put
{
  url: 'http://localhost:58846/npm-browser.js',
  lineNumber: 36611,
  columnNumber: 14
} [get] released
{ url: '', lineNumber: 13, columnNumber: 10 } [stat of cid from nodejs] {cid: _CID, mode: undefined, mtime: undefined, fileSize: 17n, dagSize: 17n}
...

bellbind commented 11 months ago

I found peer:connect events spawned, but /ipfs/bitswap/1.2.0 topology never spawned in case-halt.mjs.

(update for display peer:connect event and /ipfs/bitswap/1.2.0 onConnect) https://gist.github.com/bellbind/5565c22255ae87a3c8e9948b467ee894

case-halt.mjs:

$ node case-halt.mjs
[middle info URL] http://localhost:59635/
[peerId on nodejs] 12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
[page server url] http://localhost:59642/index.html
(node:70713) [DEP0066] DeprecationWarning: OutgoingMessage.prototype._headers is deprecated
(Use `node --trace-deprecation ...` to show where the warning was created)
{
  url: 'http://localhost:59642/browser.js',
  lineNumber: 54,
  columnNumber: 12
} [peer:connect] 12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ
{ url: '', lineNumber: 4, columnNumber: 10 } [peerId on browser] 12D3KooWNHdkwEtkuDqSfZeVjc8Lam217LCkfewMX3UFwAhR1WYk
{ url: '', lineNumber: 4, columnNumber: 12 } [peer.id] 12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 5, columnNumber: 12 } [peer.multiaddrs.length] 12
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59633/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59633/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit/p2p/12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59634/ws/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59634/ws/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit/p2p/12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59639
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59639/p2p/12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59633/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59633/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit/p2p/12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59634/ws/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59634/ws/p2p/12D3KooWSrsvuX3s8LmcGbaSXKpC6M5kQ7GeA8naBfx42QcALuBZ/p2p-circuit/p2p/12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59639
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59639/p2p/12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
{ url: '', lineNumber: 7, columnNumber: 12 } [peer.protocolss.length] 0
{
  url: 'http://localhost:59642/browser.js',
  lineNumber: 54,
  columnNumber: 12
} [peer:connect] 12D3KooWK2RXGcEacMu2mgR3cW4TFCKbEgxXBNeiBSryo6qWALJy
^C

case-success.mjs:

$ node case-success.mjs
[middle info URL] http://localhost:59352/
[peerId on nodejs] 12D3KooWN3yQuxxh2dzroLGEveT87RC6HXF9f5Gfh3gvvPaHoq5M
[page server url] http://localhost:59358/index.html
(node:61832) [DEP0066] DeprecationWarning: OutgoingMessage.prototype._headers is deprecated
(Use `node --trace-deprecation ...` to show where the warning was created)
{
  url: 'http://localhost:59358/browser.js',
  lineNumber: 54,
  columnNumber: 12
} [peer:connect] 12D3KooWFhTo9QtMDziFLV655qoKxGsYDwoVDDMAhYwhimMJNt78
{
  url: 'http://localhost:59358/browser.js',
  lineNumber: 54,
  columnNumber: 12
} [peer:connect] 12D3KooWN3yQuxxh2dzroLGEveT87RC6HXF9f5Gfh3gvvPaHoq5M
{ url: '', lineNumber: 4, columnNumber: 10 } [peerId on browser] 12D3KooWH6rEdHDSDcbGyz11u4Mk5aLBHjAT8MWgYMW4W8mQqf7K
{
  url: 'http://localhost:59358/browser.js',
  lineNumber: 58,
  columnNumber: 42
} [/ipfs/bitswap/1.2.0] onConnect 12D3KooWN3yQuxxh2dzroLGEveT87RC6HXF9f5Gfh3gvvPaHoq5M
[stat of cid from browser] {
  cid: CID(bafkreif5viehisdkgsxmfrmu5crzazgqhtg7xaifnjzyrcypsddkfnecaa),
  mode: undefined,
  mtime: undefined,
  fileSize: 18n,
  dagSize: 18n,
  localFileSize: 18n,
  localDagSize: 18n,
  blocks: 1,
  type: 'raw',
  unixfs: undefined
}
[text of cid from browser] Hello from browser
{ url: '', lineNumber: 4, columnNumber: 12 } [peer.id] 12D3KooWN3yQuxxh2dzroLGEveT87RC6HXF9f5Gfh3gvvPaHoq5M
{ url: '', lineNumber: 5, columnNumber: 12 } [peer.multiaddrs.length] 6
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59350/p2p/12D3KooWFhTo9QtMDziFLV655qoKxGsYDwoVDDMAhYwhimMJNt78/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59351/ws/p2p/12D3KooWFhTo9QtMDziFLV655qoKxGsYDwoVDDMAhYwhimMJNt78/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/127.0.0.1/tcp/59355
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59350/p2p/12D3KooWFhTo9QtMDziFLV655qoKxGsYDwoVDDMAhYwhimMJNt78/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59351/ws/p2p/12D3KooWFhTo9QtMDziFLV655qoKxGsYDwoVDDMAhYwhimMJNt78/p2p-circuit
{ url: '', lineNumber: 6, columnNumber: 46 } [peer.multiaddrs] /ip4/192.168.10.6/tcp/59355
{ url: '', lineNumber: 7, columnNumber: 12 } [peer.protocolss.length] 0
{ url: '', lineNumber: 13, columnNumber: 10 } [stat of cid from nodejs] {cid: _CID, mode: undefined, mtime: undefined, fileSize: 17n, dagSize: 17n}
{ url: '', lineNumber: 19, columnNumber: 10 } [text of cid from nodejs] Hello from nodejs
[closing...]
{
  url: 'http://localhost:59358/browser.js',
  lineNumber: 59,
  columnNumber: 37
} [/ipfs/bitswap/1.2.0] onDisconnect 12D3KooWN3yQuxxh2dzroLGEveT87RC6HXF9f5Gfh3gvvPaHoq5M

bellbind commented 10 months ago

After updated helia-2.0.1, the helia node on nodejs cannot access with cid served by the helia node on browser (run on node-20.5.1 of m1mac).

https://gist.github.com/bellbind/5565c22255ae87a3c8e9948b467ee894

On case-success.mjs, peer:connect of middle and nodejs helia nodes are arrived on browser helia node, but /ipfs/bitswap/1.2.0 onConnect of the middle helia node is only arrived on the browser helia node.

/ipfs/bitswap/1.2.0 onConnect of the nodejs helia node is never arrived on the browser helia node. (is arrived former helia-1.3.12)

ipfs / helia

Halt when accessing CID served on a nodejs helia node from a browser helia node #229