Venus: [bug]go-filecoin miner crash under stressed proposal bids

[steven004]

Describe the bug
I am running a go-filecoin test-devnet-0.2.2 version as a miner; and set up another miner as client to send proposals in parallel.

After a few hours, I got crash on miner side.

To Reproduce
Steps to reproduce the behavior:

1. Set up a miner and client using go-filecoin test-devnet-0.2.2
2. Start mining
3. set up a client to send proposal in parallel using 3 process
4. running for a few hours, see the following error and system crashed:

[0;37m18:29:59.359 WARNI /fil/hello: failed to send hello handshake to peer QmbNJ2Hzf7qJ32cPzAkRzqsjzBAR52RwhB6feWcT2xE1pX: stream reset hello.go:179
18:29:59.657 WARNI net/identi: error reading identify message:  stream reset id.go:146
panic: send on closed channel

goroutine 35945557 [running]:
github.com/filecoin-project/go-filecoin/proofs/sectorbuilder.(*RustSectorBuilder).AddPiece.func2(0xc0b5e52fc0, 0x22, 0xc03780e760, 0xc0098b3900, 0x1f, 0xc024b3df80, 0xc000be42a0)
    /root/go/src/github.com/filecoin-project/go-filecoin/proofs/sectorbuilder/rustsectorbuilder.go:230 +0x377
created by github.com/filecoin-project/go-filecoin/proofs/sectorbuilder.(*RustSectorBuilder).AddPiece
    /root/go/src/github.com/filecoin-project/go-filecoin/proofs/sectorbuilder/rustsectorbuilder.go:208 +0x27c

Expected behavior
no crash
Reject the proposal if too many to handle.
Or report an error, instead of crashing.

Version information
go-filecoin test-devnet-0.2.2

[steven004]

The log is uploaded here

[travisperson]

I also ran into this, though I was only working with a single deal at a time.

[laser]

Thanks for the logs, @steven004. I see the following, which is interesting:

context completed before CGO call could return (sinkPath=/tmp/916184228.fifo) rustsectorbuilder.go:237
failed to add piece: context completed before CGO call could return miner.go:429

What's happening is:

• RustSectorBuilder#AddPiece is called with a context
• it adds a timeout of MaxTimeToWriteBytesToSink to this context
• it spawns a goroutine which makes the CGO add_piece call
• it selects for values on errCh, sectorIDCh, and the ctx.Done() chan
• it receives a value on ctx.Done() and returns
• the deferred channel-closing function runs, which closes the sectorIDCh and errCh
• the CGO add_piece call returns (in the goroutine) and attemps to send a value to a now-closed sectorIDCh

The fix:

• the goroutine which contains the CGO call should close the sectorIDCh and errCh
• the goroutine which sends bytes to the pipe should use a different error channel than errCh and should close that channel when done

I do not know why the context which is passed to RustSectorBuilder#AddPiece is being marked as done.

[laser]

I was able to consistently repro this bug locally.

If the node receives deal proposals for pieces which completely fill up a staged sector while the node is sealing (and its CPUs are all pegged), RustSectorBuilder#AddPiece takes longer and longer (peaking on my machine at ~20s) until we bust the 30s timeout. Once we hit the timeout, we eject from RustSectorBuilder#AddPiece, which closes the channels that the goroutines try to send to. Thus the panic.

I propose a two-headed solution:

1. Fix the Go bug which closes the channels prematurely and causes the panic
2. Remove the timeout

[travisperson]

So this is induced by load, and spreading deal proposals out is a workaround for users who are self proposing deals?

[laser]

So this is induced by load, and spreading deal proposals out is a workaround for users who are self proposing deals?

Yes, that is correct.