Disconnected context in the identify protocol

[MichaelMure]

Unless I'm missing something, the identify protocol should inherit from the host's context, which would then ensure that its main loop end when the host is terminated.

At the moment this main loop is left running after the host's context get cancelled.

See https://github.com/libp2p/go-libp2p/blob/master/p2p/protocol/identify/id.go#L130

[MichaelMure]

Alternatively and similar to #1031, Close() is not called properly when the host is terminated. What I found is that this goroutine is left hanging after the host's context get cancelled.

[aarshkshah1992]

@MichaelMure We shut down the Identify service when the Host is shut down over here:

go-libp2p/p2p/host/basic/basic_host.go

Line 1003 in 3155ff3

h.ids.Close()

The call to Identify.Close() will cancel the context that Identify's loop waits for:

go-libp2p/p2p/protocol/identify/id.go

Line 276 in 3155ff3

ids.ctxCancel()

Let me know if you have concerns otherwise otherwise I can close this.

Note: We moved to this pattern as we've run into problems propagating and using contexts for closing services. You can read our discussions here:

libp2p/go-libp2p-kbucket#50 (comment)
libp2p/go-libp2p-kbucket#50 (comment)

[MichaelMure]

Here is what I see:

func TestFoo(t *testing.T) {
	defer goleak.VerifyNone(t)

	ctx, cancel := context.WithCancel(context.Background())

	_, err := libp2p.New(ctx,
		libp2p.ListenAddrStrings("/ip4/0.0.0.0/tcp/1234"),
	)
	require.NoError(t, err)

	time.Sleep(10 * time.Second)

	cancel()

	time.Sleep(10 * time.Second)
}

=== RUN   TestFoo
    leaks.go:78: found unexpected goroutines:
        [Goroutine 21 in state select, with github.com/ipfs/go-log/writer.(*MirrorWriter).logRoutine on top of the stack:
        goroutine 21 [select]:
        github.com/ipfs/go-log/writer.(*MirrorWriter).logRoutine(0xc0000b5e30)
        	/home/michael/go/pkg/mod/github.com/ipfs/[email protected]/writer/writer.go:71 +0x128
        created by github.com/ipfs/go-log/writer.NewMirrorWriter
        	/home/michael/go/pkg/mod/github.com/ipfs/[email protected]/writer/writer.go:36 +0xb9
        
         Goroutine 22 in state select, with go.opencensus.io/stats/view.(*worker).start on top of the stack:
        goroutine 22 [select]:
        go.opencensus.io/stats/view.(*worker).start(0xc000146080)
        	/home/michael/go/pkg/mod/[email protected]/stats/view/worker.go:276 +0x100
        created by go.opencensus.io/stats/view.init.0
        	/home/michael/go/pkg/mod/[email protected]/stats/view/worker.go:34 +0x68
        
         Goroutine 5 in state select, with github.com/libp2p/go-libp2p-peerstore/pstoremem.(*memoryAddrBook).background on top of the stack:
        goroutine 5 [select]:
        github.com/libp2p/go-libp2p-peerstore/pstoremem.(*memoryAddrBook).background(0xc00012a000)
        	/home/michael/go/pkg/mod/github.com/libp2p/[email protected]/pstoremem/addr_book.go:93 +0x126
        created by github.com/libp2p/go-libp2p-peerstore/pstoremem.NewAddrBook
        	/home/michael/go/pkg/mod/github.com/libp2p/[email protected]/pstoremem/addr_book.go:83 +0x18e
        
         Goroutine 10 in state select, with github.com/libp2p/go-libp2p/p2p/protocol/identify.(*IDService).loop on top of the stack:
        goroutine 10 [select]:
        github.com/libp2p/go-libp2p/p2p/protocol/identify.(*IDService).loop(0xc0000b6b60)
        	/home/michael/go/pkg/mod/github.com/libp2p/[email protected]/p2p/protocol/identify/id.go:204 +0x4f7
        created by github.com/libp2p/go-libp2p/p2p/protocol/identify.NewIDService
        	/home/michael/go/pkg/mod/github.com/libp2p/[email protected]/p2p/protocol/identify/id.go:151 +0x2c3
        ]
--- FAIL: TestFoo (20.58s)
FAIL

Leaving aside opencensus and go-log, you can see that Identify and Peerstore are left around. Now admittedly, Close() could/should be used, but then why accepting a context?

Also, when actually using Close(), the Peerstore is still left around:

         Goroutine 11 in state select, with github.com/libp2p/go-libp2p-peerstore/pstoremem.(*memoryAddrBook).background on top of the stack:
        goroutine 11 [select]:
        github.com/libp2p/go-libp2p-peerstore/pstoremem.(*memoryAddrBook).background(0xc000170000)
        	/home/michael/go/pkg/mod/github.com/libp2p/[email protected]/pstoremem/addr_book.go:93 +0x126
        created by github.com/libp2p/go-libp2p-peerstore/pstoremem.NewAddrBook
        	/home/michael/go/pkg/mod/github.com/libp2p/[email protected]/pstoremem/addr_book.go:83 +0x18e

Just saw your edit. I understand now using the rational of using Close() instead of context cancelling, but then why accept a context in the first place as it expose to this incorrect termination? Is that something that will be removed? Maybe mention in the doc that the context is not to be used for closing?

[jacobheun]

@aarshkshah1992 can you take a look at this again?

[aarshkshah1992]

@jacobheun Taking a look

[aarshkshah1992]

@MichaelMure

Unfortunately, we haven't finished migrating completely from using the context to the Close method. I've added documentation regarding using the Close method at #1037.

That PR also introduces a change to close the PeerStore.

[BigLep]

@aarshkshah1992 : at the minimum as part of your maintenance week can you either handle this or make it clear what the next steps are please?

[marten-seemann]

We moved away from using contexts for service shutdown, so I believe this issue has become stale.