Closed alx696 closed 1 year ago
marten-seemann
commented
1 year ago Have you changed anything in the code? This is the standard code path, which should be covered quite well by our tests.
When does the crash occur? Is it directly after you start the node, or does it take some time?
alx696
commented
1 year ago @marten-seemann Code not changed. Error occurs after the node starts up for a while.
https://github.com/alx696/go-open-p2p/commit/e87dff469caddb7ca3498d74a13fd3258fdb305c
This modification upgrades Go and libp2p, op/op.go adjusted according to the new api, other files just formated.
marten-seemann
commented
1 year ago @alx696 Can you please turn on autorelay debug logging? GOLOG_LOG_LEVEL="autorelay=debug" go run ... and post the output here?
alx696
commented
1 year ago @marten-seemann I am using go-open-p2p as embedded. I do not know how to set environment variable that time.
The error occurs when calling the method .
[2022-11-06 12:02:29.333] [debug] 可用端口: 29839
[2022-11-06 12:02:29.338] [info] 资源路径: /home/m/learn/network-express/desktop-ne
[2022-11-06 12:02:29.338] [info] 文件夹路径: /home/m/lilu-ne
[2022-11-06 12:02:29.338] [info] http端口: 29839
[2022-11-06 12:02:29.343] [debug] 后台服务进程 34692
[2022-11-06 12:08:36.117] [info] 退出应用
[2022-11-06 12:08:36.117] [info] 结束进程
[2022-11-06 12:15:10.982] [debug] 可用端口: 31125
[2022-11-06 12:15:10.987] [info] 资源路径: /home/m/learn/network-express/desktop-ne
[2022-11-06 12:15:10.987] [info] 文件夹路径: /home/m/lilu-ne
[2022-11-06 12:15:10.988] [info] http端口: 31125
[2022-11-06 12:15:10.993] [debug] 后台服务进程 39194
[2022-11-06 12:19:40.551] [info] 退出应用
[2022-11-06 12:19:40.552] [info] 结束进程
[2022-11-06 12:19:45.977] [debug] 可用端口: 5213
[2022-11-06 12:19:45.981] [info] 资源路径: /home/m/learn/network-express/desktop-ne
[2022-11-06 12:19:45.982] [info] 文件夹路径: /home/m/lilu-ne
[2022-11-06 12:19:45.982] [info] http端口: 5213
[2022-11-06 12:19:45.988] [debug] 后台服务进程 39704
[2022-11-06 12:21:16.729] [error] Error: Command failed: /home/m/learn/network-express/desktop-ne/op-linux --private=/home/m/lilu-ne/private --public=/home/m/lilu-ne/public --http=5213
2022/11/06 12:19:45 启动开放点对点
2022/11/06 12:19:45 私有文件夹 /home/m/lilu-ne/private
2022/11/06 12:19:45 公共文件夹 /home/m/lilu-ne/public
2022/11/06 12:19:45 开始启动HTTP服务: 5213
2022/11/06 12:19:46 通过dnsaddr得到引导地址 [/dnsaddr/am6.bootstrap.libp2p.io/p2p/QmbLHAnMoJPWSCR5Zhtx6BHJX9KiKNN6tpvbUcqanj75Nb /dnsaddr/ams-rust.bootstrap.libp2p.io/p2p/12D3KooWEZXjE41uU4EL2gpkAQeDXYok6wghN7wwNVPF5bwkaNfS /dnsaddr/ny5.bootstrap.libp2p.io/p2p/QmQCU2EcMqAqQPR2i9bChDtGNJchTbq5TbXJJ16u19uLTa /dnsaddr/sg1.bootstrap.libp2p.io/p2p/QmcZf59bWwK5XFi76CZX8cbJ4BhTzzA3gU1ZjYZcYW3dwt /dnsaddr/sv15.bootstrap.libp2p.io/p2p/QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN /dnsaddr/sv16.bootstrap.libp2p.io/p2p/QmZa1sAxajnQjVM8WjWXoMbmPd7NsWhfKsPkErzpm9wGkp]
2022/11/06 12:19:46 通过lilu.red得到引导地址 [/ip4/104.131.131.82/tcp/4001/p2p/QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ]
2022/11/06 12:19:46 初始化交换
2022/11/06 12:19:46 开放点对点已经启动 12D3KooWPkyhax3pTe2uBn3TXCiQ3JriAGQGoSWEiZved18rv4Ge [/ip4/192.168.1.3/tcp/20245 /ip4/127.0.0.1/tcp/20245 /ip4/192.168.1.3/udp/53659/quic /ip4/127.0.0.1/udp/53659/quic /ip6/2408:824e:1530:e2b0:5c44:6b4e:4ba2:26e0/udp/14207/quic /ip6/::1/udp/14207/quic]
2022/11/06 12:19:46 回调启动 12D3KooWPkyhax3pTe2uBn3TXCiQ3JriAGQGoSWEiZved18rv4Ge ["/ip4/192.168.1.3/tcp/20245","/ip4/127.0.0.1/tcp/20245","/ip4/192.168.1.3/udp/53659/quic","/ip4/127.0.0.1/udp/53659/quic","/ip6/2408:824e:1530:e2b0:5c44:6b4e:4ba2:26e0/udp/14207/quic","/ip6/::1/udp/14207/quic"]
2022/11/06 12:19:46 启动MDNS
2022/11/06 12:19:46 启动状态
2022/11/06 12:19:46 启动连接状态
2022/11/06 12:19:46 MDNS发现节点 12D3KooWMhFqJytxaCBQMr936uvcu8ZVxf8yspPGWnECRqov5SjA
2022/11/06 12:19:46 回调MDNS发现节点 12D3KooWMhFqJytxaCBQMr936uvcu8ZVxf8yspPGWnECRqov5SjA
2022-11-06T12:19:46.307+0800 DEBUG autorelay autorelay/relay_finder.go:666 stopping relay finder
2022/11/06 12:19:46 连接引导成功 /dnsaddr/sv15.bootstrap.libp2p.io/p2p/QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN
2022/11/06 12:19:46 连接引导成功 /dnsaddr/am6.bootstrap.libp2p.io/p2p/QmbLHAnMoJPWSCR5Zhtx6BHJX9KiKNN6tpvbUcqanj75Nb
2022/11/06 12:19:46 连接引导成功 /dnsaddr/ny5.bootstrap.libp2p.io/p2p/QmQCU2EcMqAqQPR2i9bChDtGNJchTbq5TbXJJ16u19uLTa
2022/11/06 12:19:46 连接引导成功 /dnsaddr/sv16.bootstrap.libp2p.io/p2p/QmZa1sAxajnQjVM8WjWXoMbmPd7NsWhfKsPkErzpm9wGkp
2022/11/06 12:19:46 连接引导成功 /dnsaddr/sg1.bootstrap.libp2p.io/p2p/QmcZf59bWwK5XFi76CZX8cbJ4BhTzzA3gU1ZjYZcYW3dwt
2022/11/06 12:19:47 订阅请求: 网页
2022/11/06 12:19:47 设置状态检查标识数组 []
2022/11/06 12:19:48 连接引导成功 /dnsaddr/ams-rust.bootstrap.libp2p.io/p2p/12D3KooWEZXjE41uU4EL2gpkAQeDXYok6wghN7wwNVPF5bwkaNfS
2022/11/06 12:19:51 连接引导失败 /ip4/104.131.131.82/tcp/4001/p2p/QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ failed to dial QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ:
* [/p2p-circuit/p2p/QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ] can't dial a p2p-circuit without specifying a relay: /p2p-circuit/p2p/QmaCpDMGvV2BGHeYERUEnRQAwe3N8SzbUtfsmvsqQLuvuJ
* [/ip4/104.131.131.82/tcp/4001] dial tcp4 0.0.0.0:20245->104.131.131.82:4001: i/o timeout
2022-11-06T12:21:16.717+0800 DEBUG autorelay autorelay/relay_finder.go:652 starting relay finder
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xc778f1]
goroutine 24701 [running]:
github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).findNodes(0xc000118d00, {0x146eed8?, 0xc00316e900})
/home/m/go/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:209 +0x51
github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).background.func2()
/home/m/go/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:112 +0x66
created by github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).background
/home/m/go/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:110 +0x192
at ChildProcess.exithandler (node:child_process:407:12)
at ChildProcess.emit (node:events:527:28)
at maybeClose (node:internal/child_process:1092:16)
at Socket.<anonymous> (node:internal/child_process:451:11)
at Socket.emit (node:events:527:28)
at Pipe.<anonymous> (node:net:709:12)
[2022-11-06 12:22:03.571] [info] 退出应用
[2022-11-06 12:22:03.572] [info] 结束进程@marten-seemann I am using go-open-p2p as embedded. I do not know how to set environment variable that time.
Unfortunately, we won't be able to debug this any further without the autorelay log.
You can just set the environment variable on your system:
export GOLOG_LOG_LEVEL="autorelay=debug"Alternatively, in your code:
import logging "github.com/ipfs/go-log/v2"
func init() {
logging.SetLogLevel("autorelay", "debug")
}@marten-seemann Thanks for you reply. I have try run GOLOG_LOG_LEVEL="autorelay=debug" npm test with desktop version base electron. I also add
import logging "github.com/ipfs/go-log/v2"
func init() {
logging.SetLogLevel("autorelay", "debug")
}to op/op.go.
It looks like there are only 2 more logs:
electron:
2022-11-06T12:19:46.307+0800 DEBUG autorelay autorelay/relay_finder.go:666 stopping relay finder
2022-11-06T12:21:16.717+0800 DEBUG autorelay autorelay/relay_finder.go:652 starting relay finderAndroid:
2022-11-06 19:47:06.365 13277-13376 GoLog red.lilu.app.ne E 2022-11-06T11:47:06.358Z DEBUG autorelay autorelay/relay_finder.go:666 stopping relay finder
2022-11-06 19:47:21.113 13277-13381 red.lilu.app.n red.lilu.app.ne W 0xebadde09 skipped times: 0
2022-11-06 19:47:21.118 13277-0 Go red.lilu.app.ne E panic: runtime error: invalid memory address or nil pointer dereference
2022-11-06 19:47:21.118 13277-0 Go red.lilu.app.ne E [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x7546fe59c8]
2022-11-06 19:47:21.119 13277-0 Go red.lilu.app.ne E
2022-11-06 19:47:21.119 13277-0 Go red.lilu.app.ne E goroutine 4593 [running]:
2022-11-06 19:47:21.119 13277-0 Go red.lilu.app.ne E github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).findNodes(0x40002be9c0, {0x7547701658?, 0x4002b0e3c0})
2022-11-06 19:47:21.119 13277-0 Go red.lilu.app.ne E /tmp/gomobile-work-3313461825/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:209 +0x38Sorry for not providing useful information. Thanks very much.
Raffy27
commented
1 year ago Hi there, I am currently facing the same issue. It appears that running with the log level set to debug yields an additional line, but nothing of interest.
2022-11-06T14:19:57.407+0200 DEBUG autorelay autorelay/relay_finder.go:657 starting relay finder
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xc8ca16]
goroutine 2346 [running]:
github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).findNodes(0xc0001284e0, {0x13c2158?, 0xc0032b8b00})
/home/raffy/go/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:214 +0xf6
github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).background.func2()
/home/raffy/go/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:112 +0x66
created by github.com/libp2p/go-libp2p/p2p/host/autorelay.(*relayFinder).background
/home/raffy/go/pkg/mod/github.com/libp2p/go-libp2p@v0.23.2/p2p/host/autorelay/relay_finder.go:110 +0x192
exit status 2```go func setupHost(ctx context.Context, cfg *P2PNetworkConfig) (host.Host, *dht.IpfsDHT, error) { cm, err := connmgr.NewConnManager(100, 400) if err != nil { return nil, nil, err } privKey, err := DeriveIdentity(cfg.PrivateKey) if err != nil { return nil, nil, err } zap.S().Debug("identity derived") // Setup libp2p host with custom options // We will initialize a Kademlia DHT instance in the meantime var kadDHT *dht.IpfsDHT h, err := libp2p.New( libp2p.Identity(privKey), libp2p.ListenAddrStrings(cfg.ListenAddr), // Security // Transport // Muxer libp2p.ConnectionManager(cm), libp2p.NATPortMap(), libp2p.Routing(func(h host.Host) (routing.PeerRouting, error) { kadDHT, err = dht.New( ctx, h, dht.Mode(dht.ModeServer), dht.BootstrapPeers( dht.GetDefaultBootstrapPeerAddrInfos()..., ), ) return kadDHT, err }), // AutoRelay libp2p.EnableAutoRelay(), ) return h, kadDHT, err } ```
The same logic used to work with previous versions of the libp2p infrastructure (see peerchat for an example).
It seems that, for some reason the peerSource function is holding nil when findPeers is called.
There was a recent discussion on the libp2p forums featuring the same error, I'll leave this here in case it is related: https://discuss.libp2p.io/t/minimal-example-for-autonat-autorelay-with-pnet/1589. Even though there has been a huge improvement in the quality of the available documentation, I could not find a minimal example with AutoRelay, which would probably help a lot in this case.
Stebalien
commented
1 year ago Yeah, it looks like peerSource just isn't set. It looks like we either need to pass WIthStaticRelays, WithDefaultStaticRelays, or WithPeerSource.
MarcoPolo
commented
1 year ago I’m touching this code today, I can fix this.
MarcoPolo
commented
1 year ago @marten-seemann this is actually this issue I brought up in Code review: https://github.com/libp2p/go-libp2p/pull/1587#discussion_r911442136.
We should at the very least panic in the constructor with a useful error. I don't think it's nice to nil pointer panic on users for not having deep knowledge with how autorelay works (it has auto in the name!). The docs around EnableAutoRelay could clarify that you must call this with at least autorelay.WithStaticRelays(...) or autorelay.WithPeerSource (I'll update).
For the time being folks can see how this is used in Kubo You'll need to pass a static list of relays or a way to get relay peers.
marten-seemann
commented
1 year ago @marten-seemann this is actually this issue I brought up in Code review: https://github.com/libp2p/go-libp2p/pull/1587#discussion_r911442136.
You're right. My bad.
The best way to solve this would be to have an error returned by libp2p.EnableAutoRelay. It's a bit difficult to implement, considering that we're using the options pattern here.
We could split the function into two options, one that requires a list of static relays and one that requires a peer source. Having options, some of which are required, is not a nice API pattern (and this is totally my fault, I wrote it like this).
MarcoPolo
commented
1 year ago We could split the function into two options, one that requires a list of static relays and one that requires a peer source.
I think we should do this
hsanjuan
commented
1 year ago I'll make more explicit that EnableAutoRelay did not need any options originally.
The right approach would have been to rename the method so that I get a big error when I build with a new libp2p version (not a panic on initialization!!), and then I can proceed to read the documentation and release notes about why a method is gone etc.
hsanjuan
commented
1 year ago For the time being folks can see how this is used in Kubo You'll need to pass a static list of relays or a way to get relay peers.
This is very unhelpful... are we supposed to now have an autorelayFeeder and copy-paste all that code from Kubo?
hsanjuan
commented
1 year ago As a user, I want to have a private network with a variable number of peers where all of them have relay capabilities that are used automatically as needed.
I'm thinking that perhaps not just the options changed, but the semantics. How did EnableAutoRelay() work before it required any options? Did it have logic to discover peers by itself?
marten-seemann
commented
1 year ago @hsanjuan You’re right, we should’ve broken the API when we refactored this. Better late then never, here’s the issue to split the EnableAutoRelay option: #1866.
I'm thinking that perhaps not just the options changed, but the semantics. How did EnableAutoRelay() work before it required any options? Did it have logic to discover peers by itself?
Previously, peers announced themselves as relays to the DHT, and we’d discover them from there. This was fine with a small number of relays, but obviously doesn’t scale to a network where (almost) all public nodes are relays (as they are with relay v2).
hsanjuan
commented
1 year ago Previously, peers announced themselves as relays to the DHT, and we’d discover them from there. This was fine with a small number of relays, but obviously doesn’t scale to a network where (almost) all public nodes are relays (as they are with relay v2).
Makes sense. I'm trying to think if EnableAutoRelay makes sense at all on a small network where all peers are relays though (EnableRelay() is set). Does not using EnableAutoRelay mean that peers will not attempt to use other peers as relays at all? Note that they should be connected to peers that are relays already, so they potentially know that they expose the relay protocol.
After update to v0.23.2, an error will occur:
If comment out
libp2p.EnableAutoRelay(), no errors.Version Information