Aggregate TCP chunks with unmarshal protobuf retry

[zarkone]

Fixes #729

After successful internal testing on sei-testnet, we've decided to suggest this fix to tmkms upstream.

I've read all the previous discussions and understand the concern that this should belong to tendermint_p2p rather. I'm also agree that tendermint_p2p uses the wrong abstraction in a first place: a stream for a message-oriented protocol.

However, I don't see how it can be fixed inside of tendermint_p2p also: while tendermint / cometbft divides the data by chunks, it doesn't send the full length of data in advance, which means, it is not possible to glue these chunks together.

While his issue was seen only on Sei network, I think that it is rather an issue of tendermint TCP protocol design: it has implicit requirement for length over TCP which was not obvious even for authors of tendermint, it seems. Extending the message size shouldn't break the communication (see expanded below).

Here is the original message from a PR to our fork for the reference:

// tendermint/cometbft proposal:
type Proposal struct {
	Type      SignedMsgType
	Height    int64
	Round     int32
	PolRound  int32
	BlockID   BlockID
	Timestamp time.Time
	Signature []byte
}

// vs sei-tendermint proposal
type Proposal struct {
	Type            SignedMsgType
	Height          int64
	Round           int32
	PolRound        int32
	BlockID         BlockID
	Timestamp       time.Time
	Signature       []byte

        // this is a list, and can be very long...
	TxKeys          []*TxKey
	Evidence        *EvidenceList
	LastCommit      *Commit
	Header          Header
	ProposerAddress []byte
}

Since Proposal has TxKeys and other lists, Proposal has variable length It is easily goes > 1024 bytes if block has big mount of txs. And it is not a problem of canonical tendermint/cometbft implementations since due to its message structure, it has a fixed max length < 1024 (DATA_MAX_SIZE)

sei-tendermint, when it connects to remote signer over tcp, sends proposal divided by chunk of DATA_MAX_SIZE (1024) each, which kind of fits the expectation of tmkms. However, tmkms never tries to aggregate chunks. In fact, it is impossible for tmkms to implement aggregation properly without knowing the length beforehand: which is not provided by tendermint protocol.

There might be a confusioon also, because all implementations of tendermint send lenght-delimited protobufs, and tmkms also reads with a function "length delimited". However, it actually means that the protobuf msg is prepended by it's length: so that when tmkms reads 1024 bytes it knows which zeroes are payload and which a need to be cut. Another words, it has nothing to do with multi-chunk payload.

Which means that sei-tendermint just doesn't bother about tcp remote signer, and it is impossible to make it work with tmkms without rewriting both and adding this custom protocol of "aggregate chunks until you get full message length".

-- This code implements aggregation by trying to unmarshal aggregated message each time it gets a new chunk. I don't think it is a good idea in a long run, however, the alternative would be to adjust both Sei and tmkms, rolling out new length-aware protocol between them -- I'm not sure how sufficient it is and definitely needs a discussion. Current solution is compartable with both cometbft/tendermint and sei-tendermint, however, way less efficient then the original read implementation of tmkms.

P.S: Apart from custom length-aware protocol, there is another option: implement grpc in tmkms, which seem to be supported by sei-tendermint.

[tony-iqlusion]

I'm so frustrated with these error reports, especially when I can't reproduce any of them, that I'm tempted to merge this, but it seems like quite a hack.

Instead of just blindly aggregating data and trying to decode it over and over, it really seems like something should be decoding the length delimiter, then using the length delimiter to decode exactly as much data is needed to decode the proto.

The situation is certainly not helped by the tendermint-p2p crate which really should do that all for us, but instead provides a stream-oriented API on a message-oriented protocol where we still need to stitch chunks of data together ourselves.

A very, very, very frustrating situation. I am almost tempted to rewrite tendermint-p2p.

[tony-iqlusion]

Not sure why CI isn't running.

@zarkone you may need to push another commit or something. It's possible something was wrong with GitHub Actions at the time this was pushed.

[zarkone]

@tony-iqlusion I'm very agree, but I also don't see how tendermint-p2p is going to solve this issue? As I understood, tendremint-p2p is not aware of proto schema, therefore, can't do try-parse on each aggregation step.

This could be solved by tendermint p2p if tendermint/cometBFT would send a full length instead of lenght of a chunk -- however, it is not the case..

In theory, if we patch tendermint/cometBFT to send full length instead, it shouldn't break anything (right?)

[tony-iqlusion]

@zarkone each message begins with an LEB128-encoded length delimiter which can be parsed and then the given amount of data read and returned as a message, rather than this trial-and-error approach

[zarkone]

@tony-iqlusion right, but it is the lenght of a chunk rather then length of a whole message (multichunk), isn't it? see here: https://github.com/cometbft/cometbft/blob/main/p2p/conn/secret_connection.go#L201-L208

	for 0 < len(data) {
		if err := func() error {
			sealedFrame := pool.Get(aeadSizeOverhead + totalFrameSize)
			frame := pool.Get(totalFrameSize)
			defer func() {
				pool.Put(sealedFrame)
				pool.Put(frame)
			}()
			var chunk []byte
			if dataMaxSize < len(data) {
				chunk = data[:dataMaxSize]
				data = data[dataMaxSize:]
			} else {
				chunk = data
				data = nil
			}
			chunkLength := len(chunk)
			binary.LittleEndian.PutUint32(frame, uint32(chunkLength))
			copy(frame[dataLenSize:], chunk)

[zarkone]

same for tendermint, and sei-tendremint, implementation of this transport is the same in all of them

[tony-iqlusion]

Okay, well the problem remains CI hasn't run.

I guess I can just merge this since I'm really sick of hearing about it.

[tony-iqlusion]

A test of this behavior would also be nice

[zarkone]

@tony-iqlusion I understand your feelings, my apologies for rising this once again..

I'll also try to rise it in cometBFT, let's see :shrug: I'll add a test and bump the CI :+1:

Have a great weekend!

[IbrarMakaveli]

Thank you very much @zarkone. I had tried to work on the function, but given my limited skills in Rust, I didn't push it further. We absolutely need to merge this change, which fixes this buffer issue that has been around for over a year now. Many thanks to @tony-iqlusion for having the perseverance to stay with us through this tough challenge.

[zarkone]

hi @tony-iqlusion! I've added a test with a bigger proposal. I decided to use binary file with Sei Proposal payload because making extended proposal from protobuf would pull too much things -- there is no such protobuf description in tendermint-rs. I hope this is fine for an integration test!

I also don't see that my commit bumped build / test flows: not sure what could be the reson for this. It says "This workflow requires approval" -- maybe you need to explicitly launch it somewhere?

https://docs.github.com/en/actions/managing-workflow-runs/approving-workflow-runs-from-public-forks

[zarkone]

How to test this:

Test the failure on main

1. Restore original rpc.rs

git restore --source main -- src/rpc.rs

2. Run the test with:

 cargo test test_buffer_underflow_sign_proposal -- --exact

Output:

zarkone@fwlp ~/c/tmkms (aggregate-messages-from-sei-tendermint) [101]> cargo test test_buffer_underflow_sign_proposal -- --exact
    Finished test [unoptimized + debuginfo] target(s) in 0.07s
     Running unittests src/lib.rs (target/debug/deps/tmkms-f211f992cb5cea9a)

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 10 filtered out; finished in 0.00s

     Running unittests src/bin/tmkms/main.rs (target/debug/deps/tmkms-6a98ae819e3073b2)

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

     Running tests/integration.rs (target/debug/deps/integration-e1d781e6f87f08fb)

running 1 test
2024-07-18T09:23:26.198673Z  INFO tmkms::commands::start: tmkms 0.14.0 starting up...
2024-07-18T09:23:26.198966Z  INFO tmkms::keyring: [keyring:softsign] added consensus Ed25519 key: cosmosvalconspub1zcjduepqew5va3ef3znvmxnpjqhn367rswa5u0x2hdd83hmf2q8at4wxas0qy7ncuk
2024-07-18T09:23:26.199440Z  INFO tmkms::connection::tcp: KMS node ID: 48f6e1d553df65b05c57d2e5fb42b9c23b395d73
2024-07-18T09:23:26.201938Z  INFO tmkms::session: [test_chain_id@tcp://[email protected]:61430] connected to validator successfully
2024-07-18T09:23:26.208546Z  INFO tmkms::commands::start: tmkms 0.14.0 starting up...
2024-07-18T09:23:26.208773Z  INFO tmkms::keyring: [keyring:softsign] added consensus Ed25519 key: cosmosvalconspub1zcjduepqew5va3ef3znvmxnpjqhn367rswa5u0x2hdd83hmf2q8at4wxas0qy7ncuk
2024-07-18T09:23:26.208961Z  INFO tmkms::session: [test_chain_id@unix:///tmp/tmkms-u842978.sock] connected to validator successfully
2024-07-18T09:23:26.209726Z  INFO tmkms::session: [test_chain_id@unix:///tmp/tmkms-u842978.sock] signed Proposal:04E2BCCD7B at h/r/s 212/0/0 (0 ms)
2024-07-18T09:23:26.244005Z ERROR tmkms::client: [test_chain_id@tcp://[email protected]:61430] protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow
test test_buffer_underflow_sign_proposal ... FAILED

failures:

---- test_buffer_underflow_sign_proposal stdout ----
thread 'test_buffer_underflow_sign_proposal' panicked at tests/integration.rs:657:28:
called `Result::unwrap()` on an `Err` value: Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" }
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    test_buffer_underflow_sign_proposal

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 12 filtered out; finished in 0.05s

Make sure that buffer overflow happened:

protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow
test test_buffer_underflow_sign_proposal ... FAILED

Test the fix

3. Restore rpc.rs:

git checkout -- src/rpc.rs

4. Run the test again:

cargo test test_buffer_underflow_sign_proposal -- --exact
    Finished test [unoptimized + debuginfo] target(s) in 0.07s
     Running unittests src/lib.rs (target/debug/deps/tmkms-f211f992cb5cea9a)

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 10 filtered out; finished in 0.00s

     Running unittests src/bin/tmkms/main.rs (target/debug/deps/tmkms-6a98ae819e3073b2)

running 0 tests

test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

     Running tests/integration.rs (target/debug/deps/integration-e1d781e6f87f08fb)

running 1 test
2024-07-18T09:29:24.796135Z  INFO tmkms::commands::start: tmkms 0.14.0 starting up...
2024-07-18T09:29:24.796435Z  INFO tmkms::keyring: [keyring:softsign] added consensus Ed25519 key: cosmosvalconspub1zcjduepqew5va3ef3znvmxnpjqhn367rswa5u0x2hdd83hmf2q8at4wxas0qy7ncuk
2024-07-18T09:29:24.796907Z  INFO tmkms::connection::tcp: KMS node ID: 48f6e1d553df65b05c57d2e5fb42b9c23b395d73
2024-07-18T09:29:24.799480Z  INFO tmkms::session: [test_chain_id@tcp://[email protected]:60249] connected to validator successfully
2024-07-18T09:29:24.805873Z  INFO tmkms::commands::start: tmkms 0.14.0 starting up...
2024-07-18T09:29:24.806071Z  INFO tmkms::keyring: [keyring:softsign] added consensus Ed25519 key: cosmosvalconspub1zcjduepqew5va3ef3znvmxnpjqhn367rswa5u0x2hdd83hmf2q8at4wxas0qy7ncuk
2024-07-18T09:29:24.806273Z  INFO tmkms::session: [test_chain_id@unix:///tmp/tmkms-d384280.sock] connected to validator successfully
2024-07-18T09:29:24.807086Z  INFO tmkms::session: [test_chain_id@unix:///tmp/tmkms-d384280.sock] signed Proposal:04E2BCCD7B at h/r/s 212/0/0 (0 ms)
2024-07-18T09:29:24.842292Z  INFO tmkms::session: [test_chain_id@tcp://[email protected]:60249] signed Proposal:04E2BCCD7B at h/r/s 212/0/0 (0 ms)
test test_buffer_underflow_sign_proposal ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 12 filtered out; finished in 0.06s

Make sure to find test_buffer_underflow_sign_proposal ... ok