Panic with signed peer records in go-lib2p v0.9.0

[vyzo]

We upgraded to the latest go-libp2p in the pubsub testplans in libp2p/test-plans (see libp2p/test-plans#7) and now identify no longer works.

The smoking gun is this panic:

2020-05-19T16:32:23.759Z	ERROR	net/identify	identify/id.go:432	latest peer record does not exist. identify message incomplete!
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x6dfb97]

goroutine 234 [running]:
github.com/libp2p/go-libp2p-core/record.(*Envelope).Marshal(0x0, 0xc0005b68e0, 0x8, 0x8, 0x203000, 0x2)
	/go/pkg/mod/github.com/libp2p/go-libp2p-core@v0.5.6/record/envelope.go:196 +0x37
github.com/libp2p/go-libp2p/p2p/protocol/identify.(*IDService).populateMessage(0xc0001f1040, 0xc0007780b0, 0xf83440, 0xc00048a720, 0xc000354380)
	/go/pkg/mod/github.com/libp2p/go-libp2p@v0.9.0/p2p/protocol/identify/id.go:469 +0x4ca
github.com/libp2p/go-libp2p/p2p/protocol/identify.(*IDService).sendIdentifyResp(0xc0001f1040, 0xf83f40, 0xc0003129c0)
	/go/pkg/mod/github.com/libp2p/go-libp2p@v0.9.0/p2p/protocol/identify/id.go:402 +0x39a
github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).SetStreamHandler.func1(0xc0001fe280, 0xe, 0x7f0c590e5198, 0xc0003129c0, 0x1, 0x0)
	/go/pkg/mod/github.com/libp2p/go-libp2p@v0.9.0/p2p/host/basic/basic_host.go:476 +0x9d
created by github.com/libp2p/go-libp2p/p2p/host/basic.(*BasicHost).newStreamHandler
	/go/pkg/mod/github.com/libp2p/go-libp2p@v0.9.0/p2p/host/basic/basic_host.go:327 +0x63c

[yusefnapora]

maybe relevant: we're staring our test Hosts with no listen addresses, and call .Listen later. Although I think that by the time we get the panic, we should have listen addresses configured.

[yusefnapora]

also, it's worth noting that not all the instances failed - it was about 80 / 1000. so there may be a race condition that only happens rarely.

I'm going to try making a minimal testground test case to reproduce the issue & will link it here

[Stebalien]

Hm. Somehow we're not creating the signed peer record, or somehow deleting it. We should return an error when we fail to create/store this record, so something weird is happening.

[yusefnapora]

It looks like this only happens if you create the host with no listen addrs, e.g. by calling libp2p.New with the NoListenAddrs option. The BasicHost's NewHost constructor will generate a signed record and add it to the peerstore successfully (as in, no errors are returned), but the peerstore will immediately GC it because the Addrs field is empty.

Then if you call myHost.Network().Listen(anAddr) later, there's a ~5 second window before the ticker for detecting address changes fires and a new signed record is generated. If we manage to actually connect to someone before then and identify gets triggered, that's when we hit the panic trying to fetch our own peer record.

The good news is, this is probably won't affect many real-world users. We're hitting it in our test plans because we're using the NoListenAddrs option, and we're pushing the host's addrs to the sync service right away after calling Listen, so some % of hosts are getting connected before the addr change detector ticks. That seems unlikely in real life, but of course it's not impossible & we should still fix it :)