Protobuf: buffer underflow #729

activenodes · 2023-05-26T20:08:57Z

Chains with:

github.com/tendermint/tendermint@v0.37.0-dev
blocks every ~350ms

Every ~40 sigratures (softsign due to low time blocks) connection go down with this error:

protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow

Let me know if you need any more details.

Thanks @tony-iqlusion

The text was updated successfully, but these errors were encountered:

tony-iqlusion · 2023-05-26T20:53:40Z

What is on the other side of the privval connection? You're the first to report an error like this in many years of TMKMS existing, so it seems like the other side is the likely culprit.

activenodes · 2023-05-26T20:58:37Z

It's a testnet (Sei Network).
Other 3/4 guys can confirm the same issue (like @mkaczanowski)

imperator-co · 2023-05-26T23:43:25Z

Hi, I can confirm that we have the same problem, afaik "buffer underflow" indicates an attempt to read a message that is larger than the amount of data available in the buffer (on tmkms side)

tony-iqlusion · 2023-05-27T04:38:31Z

It indicates the data is misframed. It seems very unlikely this is a TMKMS bug, and something wrong with the specific app you are trying to run.

activenodes · 2023-05-27T08:13:38Z

It indicates the data is misframed. It seems very unlikely this is a TMKMS bug, and something wrong with the specific app you are trying to run.

I'm not a Horcrux user, but it works fine in this chain too.
What can we provide you to analyze the cause?

tony-iqlusion · 2023-05-27T13:14:40Z

I need a much better description of the problem than this, and instructions on how to reproduce it. Ideally it would be nice to have a dump of the incoming Protobuf which TMKMS can't parse.

What chain are you running?

How did you install it?

How are you running it?

Which message is causing the problem? Can you link to the Protobuf Schema for it?

qezz · 2023-05-30T17:39:40Z

Expanding a bit on this issue, we, too, faced this issue on Sei testnet (atlantic-2).

From what I understand, Sei has its own fork of tendermint - https://github.com/sei-protocol/sei-tendermint. So I believe the schema is https://github.com/sei-protocol/sei-tendermint/tree/main/proto, but I'm not 100% sure.

As for us, we were running tmkms as usual, as a separate process, and pointing seid (https://github.com/sei-protocol/sei-chain) to it via config parameter (which sets unix socket). The mode was softsign.

tony-iqlusion · 2023-05-30T17:54:38Z

I'm curious if they're expecting to use gRPC for the privval connection: https://github.com/sei-protocol/sei-tendermint/tree/main/privval

We don't support that yet: #73. We've been waiting for it to be added to upstream Tendermint, since it was removed in v0.35.

What version of Horcrux is it working with?

activenodes · 2023-05-30T18:00:10Z

My idea is to prepare you an environment with everything configured (chain/validator/tmkms) and give you access.
Can you be interested?

tony-iqlusion · 2023-05-30T18:24:00Z

That would be very helpful, thank you

activenodes · 2023-05-31T08:00:51Z

That would be very helpful, thank you

I'm getting that server ready for you.
Where I can send you logins (SSH)?
If you want to contact me on Discord (Simo | Active Nodes#3233) or give me an email.
Thanks!

tony-iqlusion · 2023-05-31T20:48:10Z

I will attempt to contact you via Discord

activenodes · 2023-05-31T20:54:55Z

I will attempt to contact you via Discord

Changed permissions... Could you try again with Discord (Simo | Active Nodes#3233)?
I'm not using Signal...
Thanks

tony-iqlusion · 2023-05-31T21:00:59Z

Request sent

IbrarMakaveli · 2023-08-14T23:04:22Z

Hey @tony-iqlusion , Any update on this issue ? Let me know how I can help to deal with, thanks

activenodes · 2023-08-16T10:28:13Z

Note. regarding previous tests and SSH access, now devnet is suspended. So we have to use testnet or mainnet chain

tony-iqlusion · 2023-08-16T11:53:59Z

I haven't had time to look, sorry. Note that there's a Hub upgrade today and a Stride upgrade tomorrow so I don't have much time this week either.

What would be very, very helpful is if someone could log the message that TMKMS can't parse for inspection.

activenodes · 2023-08-17T14:55:22Z

What would be very, very helpful is if someone could log the message that TMKMS can't parse for inspection.

Should we increase the debug level?
Or how to collect as many logs as possible?

Thanks

tony-iqlusion · 2023-08-17T15:07:57Z

You can try adding a dbg!(&msg) here: https://github.com/iqlusioninc/tmkms/blob/b6ce617/src/rpc.rs#L36

Out of curiosity, do you have protocol_version = "0.34" in the config?

activenodes · 2023-08-17T15:18:18Z

You can try adding a dbg!(&msg) here: https://github.com/iqlusioninc/tmkms/blob/b6ce617/src/rpc.rs#L36

Thanks, I will try later in testnet

Out of curiosity, do you have protocol_version = "0.34" in the config?

Yes protocol_version = "v0.34" (with the "v") ... I think I have all the chains like this. is it right?

activenodes · 2023-08-17T15:38:04Z

Here: https://pastebin.com/4wDMbwP3

ERROR tmkms::client: [atlantic-2@tcp://127.0.0.1:26658] protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow`

tony-iqlusion · 2023-08-17T17:26:06Z

Thanks, I believe this should be the message which is causing the issue encoded in hex:

ba2b2ab72b0aa82b08201091a6cc0d20ffffffffffffffffff012a480a20a33e4740e0b974cf1e010e6794ff620487e52ad63718d77e46ba3a62e1adc406122408011220cf19b022e389f5cd701b17b800caf505171bb98ae967349da72513b2138c1820320c08f1fbf8a60610a7bab0920242220a20bb985439aebaf357fad861849528d82e763031abd79fcc87c3a305bc1485388442220a2039825ada697b2d6959d75fa711636c7627c450c87ed8fe1aeaba4f20e28d435042220a20d9c22318e69463191372f92f66e5bdbf859c9b0e52020753785df5f53ea4bacb42220a20fc7ae857c36f4ea2f56285281e283ccdd600f4934183574bf5fd0ebb4c278cf942220a20ab49231edaa3fec0921d42b85cf90ba61d5251144980fa16f62a842a201755ad42220a20a7a17a651bfc02228490723a752a96e9f8ac3d64d261377726e2cdb0ccc646e342220a203178335d0ebe7e0ce2905df5b23aa05b9295e09caf80ba45472d2f61ccc9fb2f42220a20887cddac11b90e7a71888fefec183600dd79b94e9c8c43fb24d66038970eb91242220a202bfaf4b02410e8ba736e0443d63543e855cb4fb1eb99522a66d764802392700e42220a209a3e9332f29019d03097bcf290f377939b6bf8ee6a9d1952920cb9433515ca9542220a20dd148712e5a43ca35a0ed3560d6e753598da4e2ff71bd16d9dd553eddc4adcde42220a207e1df69adb7f32259154e375e20e98cf0a1c95b9f78ef1349df3ab539ab615be42220a2070a1e82287b3775ab287f7fe4e803c9bce2b03cbb4d0dba83b86104a114cb6e542220a207783770f1b6f8bdb347a8a8f113ecc67842783b4afbebb608aced8a51bb29bce42220a2008f7c95794aec249d2eba33161199c28574bc77f13accff28e5d70c23c3ebbd642220a20b53a7d779ebd7d0778aa9bb66e4565fe80903cfac23268ec016f2cf00818be9042220a20fa2f7fe3daa69c0cdd44058a44734bb6d44fce3e0c4db585e77a5190869137a142220a20f26cd81b78fa41bd46df409302c976f3451b3f0065a0e1e3e8dcb9947fd7d07c42220a20d002698eebbfd05a20492eaae6ed769068fac6cf0f3a55b6869ae8cacf5b92bf42220a20c1a848f44dfc893511262c49dd48072eb50472d49398c44b27044a028c76113b42220a2089c0affd2d4c2151cc654eebec6f0d29302ed611664965616e534e3b854eb43f42220a2084df4847e6d5998ac091ff0d6905400c3c7264855277e88cf06a184b81d2676b42220a2010e5cb10974a839fdd1584f1efc256d20fbf9d710c40ac4b968e23cb4927125b42220a20b12308f12fac8ecdc13b84feba49bf617ae0fb084b8d5fa8e8c975ee7f38c7954a0052ad200890a6cc0d1a480a203dee68aaa35b98433eba6c0416ec13403e50e3a2afb6ed1beaca515bbd7a98fc

I'll try to take a look and see if I can figure out what it's supposed to be

tony-iqlusion · 2023-08-17T17:32:47Z

If I plug that string into: https://protobuf-decoder.netlify.app/

...it doesn't appear to have a valid field number, which would need to match one of these field types (1 - 8):

https://docs.rs/tendermint-proto/latest/src/tendermint_proto/prost/v0_38/tendermint.privval.rs.html#79-96

...but the decoder says if that is a protobuf, its field number is 695, which would be a very unusual field number for a proto (they start at 1 and generally don't much higher than 30 typically)

So I have no idea what that message is supposed to be or how/why Horcrux would support it because it doesn't seem to be encoded correctly as a proto as far as I can tell.

It's possible Horcrux simply ignores messages it doesn't understand, whereas TMKMS considers it an error.

tony-iqlusion · 2023-08-17T20:02:10Z

Does anyone happen to know what that message might be, or know where to ask about it?

IbrarMakaveli · 2023-08-19T23:18:53Z

I don't really know too, if you could ignore this message, and deploy the code on a new branch, I could test and compile the tmkms on a machine and do the test on the testnet.
We could ask Sei dev, but I'm not sure they know what it means either.

mkaczanowski · 2023-09-17T01:39:16Z

I found the issue and our (Chorus One) testnet node runs with the patched / hacked tmkms version and everything seems to be fine.

TL;DR

The issue is that the serialized block proposal (SIGNED_MSG_TYPE_PROPOSAL) for weights from 4000 bytes to 6000 (eyeballed logs with additional log messages). The buffer defined below is 1024 bytes only:
https://github.com/iqlusioninc/tmkms/blob/main/src/rpc.rs#L197

resulting in message being always cut, thus malformed.

Proof of concept fix

I simply bumped the buffer size to:

let mut buf = vec![0; DATA_MAX_SIZE * 10];

Proper fix

Now I wonder whether this limit is actually correct in this context:
https://docs.rs/tendermint-p2p/latest/tendermint_p2p/secret_connection/constant.DATA_MAX_SIZE.html

because this is not strictly p2p message (between peers in tendermint network), but rather a node <-> signer relationship.

Now the question is how to fix it, shall I make the buffer len configurable or hardcode higher value, or does anyone has a better idea?

another option to fix it, could be simply using dynamic allocation via Vec::new():
https://doc.rust-lang.org/std/io/trait.Read.html#method.read_to_end

@tony-iqlusion could you share your thoughts here?

tony-iqlusion · 2023-09-18T15:37:29Z

@mkaczanowski sounds like a bug/issue in the tendermint-p2p crate. I would suggest opening an upstream issue on tendermint-rs

mkaczanowski · 2023-09-18T16:23:37Z

issue created: informalsystems/tendermint-rs#1356

mkaczanowski · 2023-09-18T16:34:03Z

funny enough this value comes from tmkms:
https://github.com/informalsystems/tendermint-rs/pull/696/files

(git blame)

tony-iqlusion · 2023-10-16T23:49:04Z

@IbrarMakaveli can you paste the complete error?

IbrarMakaveli · 2023-10-17T00:03:07Z

@tony-iqlusion Here below the error :
protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow

tony-iqlusion · 2023-10-18T13:48:44Z

@IbrarMakaveli can you confirm you see the following on startup?

tmkms 0.13.0-rc.0 starting up...

I'll try to add some better debug logging so we can appropriately gauge how large these messages can be.

IbrarMakaveli · 2023-10-18T21:27:20Z

Yes I have this message on my logs on startup :
Oct 16 23:33:12 tmkms bash[123858]: 2023-10-16T23:33:12.036546Z INFO tmkms::commands::start: tmkms 0.13.0-rc.0 starting up...

Thanks you, let me know if I can help

qezz · 2023-10-18T21:53:56Z

Our config looks very similar, except we don't set validator.secret_key, and the validator.addr is local socket

[[validator]]
addr = "unix:///path/to/sei-testnet.sock"
chain_id = "atlantic-2"
protocol_version = "v0.34"
reconnect = true

We're still getting reports that this size is too small to accommodate real-world use cases (see #729)

tony-iqlusion · 2023-10-18T22:18:51Z

Unfortunately the tendermint-p2p crate handles the message framing so it's not easy to add debug logging and adjust the buffer size automatically, however I tried bumping it to 256kB: #792

We're still getting reports that this size is too small to accommodate real-world use cases (see #729)

IbrarMakaveli · 2023-10-20T14:09:19Z

To give you some info, I have added print on buffer at read_msg function :

fn read_msg(conn: &mut impl Read) -> Result<Vec<u8>, Error> {
    let mut buf = vec![0; DATA_MAX_SIZE];
    let buf_read = conn.read(&mut buf)?;
    println!("Number bytes read: {}", buf_read); 
    buf.truncate(buf_read);
    Ok(buf)
}

The error (buffer underflow) happen when the number bytes read is more than 1024, I still thing the buffer is limit to 1024

tony-iqlusion · 2023-10-20T14:35:20Z

The constant is defined here: https://github.com/iqlusioninc/tmkms/blob/main/src/rpc.rs#L14

You can always try changing DATA_MAX_SIZE to a numeric literal of your choosing to eliminate it as a culprit:

let mut buf = vec![0; 1048576];

The error (buffer underflow) happen when the number bytes read is more than 1024, I still thing the buffer is limit to 1024

What numbers are you seeing here? That's what I really need to know.

tony-iqlusion · 2023-10-24T19:45:59Z

I've released TMKMS v0.13.0!

@IbrarMakaveli can you try it out and see if it resolves the issue?

IbrarMakaveli · 2023-11-07T16:25:36Z

@tony-iqlusion I've just tried again with this tag, I still have this error, has anyone been able to test with SoftSign ?
Is there a Linux dependency ? A parameter to change ?

qezz · 2024-01-16T19:49:21Z

Getting back to this issue. Today I discovered that

using unix socket works just fine
using (local) tcp connection produces buffer underflow

more specifically,

2024-01-16T18:18:31.875640Z DEBUG tmkms::session: [atlantic-2@tcp://...:26759] sending response: PublicKey(PubKeyResponse { pub_key: Some(PublicKey { sum: Some(Ed25519([ ... < cut >
2024-01-16T18:18:32.056127Z ERROR tmkms::client: [atlantic-2@tcp://...:26759] protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow
2024-01-16T18:18:33.056223Z DEBUG tmkms::session: [atlantic-2@tcp://...:26759] connecting to validator...
2024-01-16T18:18:33.056288Z  INFO tmkms::connection::tcp: KMS node ID: <nodeid>
2024-01-16T18:18:33.056706Z  INFO tmkms::session: [atlantic-2@tcp://...:26759] connected to validator successfully
2024-01-16T18:18:33.056712Z  WARN tmkms::session: [atlantic-2@tcp://...:26759]: unverified validator peer ID! (<id>)
2024-01-16T18:18:33.156651Z ERROR tmkms::client: [atlantic-2@tcp://...:26759] protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow
2024-01-16T18:18:34.156745Z DEBUG tmkms::session: [atlantic-2@tcp://...:26759] connecting to validator...
2024-01-16T18:18:34.156817Z  INFO tmkms::connection::tcp: KMS node ID: <nodeid>

then it manages to connect to validator for several blocks, and then fails again

IbrarMakaveli · 2024-01-17T00:43:41Z

Thanks for the feedback, I was thinking that I'm not the only one with this problem, how do you use unix socket on tmkms ?

qezz · 2024-01-17T00:58:02Z

how do you use unix socket on tmkms?

we use it for local connection only, so tmkms should be running on the same host (n.b. there are cons to this approach, as you may guess).

so for the cosmos chain

# config.toml
[priv-validator]
laddr = "unix://path/to/somewhere/kms.sock"

and in tmkms config you set the same address

[[validator]]
addr = "unix://path/to/somewhere/kms.sock"

(it's pretty late for me, so I hope I copypasted the correct thing)

anyway will look into it shortly (on Wed or Thu) and try to make it work

UPD: IIRC, the cosmos chain will create the socket, so tmkms will try connect to it. I would also recommend cleaning up (i.e. removing) the socket on every (re)start

tony-iqlusion · 2024-01-17T02:15:26Z

I can reopen this issue, however really issues should be filed against tendermint-p2p:, similar to this one: informalsystems/tendermint-rs#1356

IbrarMakaveli · 2024-02-11T20:25:24Z

Do you have any news on this, if I can help with anything, unfortunately we're using tmkms on a remote machine, we can't make a Unix Socket connection, in the short term isn't there a workaround ? Thanks

tony-iqlusion · 2024-02-12T19:15:46Z

@IbrarMakaveli I filed informalsystems/tendermint-rs#1392 to request upstream help debugging this problem.

What would be extremely helpful here is if someone could add reproduction instructions to that issue, especially if the issue is reproducible directly via the tendermint-p2p crate without involving TMKMS (or isolating TMKMS as the problem)

tony-iqlusion · 2024-03-05T18:09:54Z

Can someone attempt to reproduce this on a fresh install, which should use tendermint-p2p v0.34.1?

qezz · 2024-03-05T20:08:36Z

Rolled out 0.14.0-pre.1 to our Sei testnet validator, will let you know

Using tcp connection within the same host

qezz · 2024-03-05T20:20:38Z

Unfortunately the same error

Several signed blocks, then an underflow error

2024-03-05T20:18:43.118481Z DEBUG tmkms::session: [atlantic-2@tcp://...:51759] received request: ShowPublicKey
2024-03-05T20:18:43.118506Z DEBUG tmkms::session: [atlantic-2@tcp://...:51759] sending response: PublicKey(PubKeyResponse { pub_key: Some(PublicKey { sum: Some(Ed25519([162>
2024-03-05T20:18:43.314290Z ERROR tmkms::client: [atlantic-2@tcp://...:51759] protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow
2024-03-05T20:18:44.314384Z DEBUG tmkms::session: [atlantic-2@tcp://...:51759] connecting to validator...
2024-03-05T20:18:44.314456Z  INFO tmkms::connection::tcp: KMS node ID: ...
2024-03-05T20:18:44.314862Z  INFO tmkms::session: [atlantic-2@tcp://...:51759] connected to validator successfully
2024-03-05T20:18:44.314869Z  WARN tmkms::session: [atlantic-2@tcp://...:51759]: unverified validator peer ID! (a47c7867b3191c93eed4bf0f01a9d4bc95a193ac)
2024-03-05T20:18:44.414468Z ERROR tmkms::client: [atlantic-2@tcp://...:51759] protocol error: malformed message packet: failed to decode Protobuf message: buffer underflow

tony-iqlusion · 2024-03-05T20:22:34Z

@qezz can you confirm that tendermint-p2p v0.34.1 was used in the build? (I can pin it in the next prerelease)

qezz · 2024-03-05T20:23:12Z

let me check

qezz · 2024-03-05T20:32:08Z

In the build log it says

...
   Downloaded tendermint-p2p v0.34.1
...
   Compiling tendermint-proto v0.34.1
   Compiling yubihsm v0.42.1
   Compiling tendermint v0.34.1
   Compiling cosmos-sdk-proto v0.20.0
   Compiling tendermint-p2p v0.34.1
   Compiling tendermint-config v0.34.1

tony-iqlusion · 2024-03-05T20:34:59Z

Thanks, I reopened this issue: informalsystems/tendermint-rs#1392 (comment)

mkaczanowski mentioned this issue Sep 18, 2023

increase tendermint_p2p::secret_connection::DATA_MAX_SIZE informalsystems/tendermint-rs#1356

Closed

tony-iqlusion added a commit that referenced this issue Oct 18, 2023

Bump DATA_MAX_SIZE to 256kB

68e9de5

We're still getting reports that this size is too small to accommodate real-world use cases (see #729)

tarcieri mentioned this issue Oct 18, 2023

Bump DATA_MAX_SIZE to 256kB #792

Merged

tony-iqlusion pushed a commit that referenced this issue Oct 18, 2023

Bump DATA_MAX_SIZE to 256kB (#792)

5018a70

We're still getting reports that this size is too small to accommodate real-world use cases (see #729)

tony-iqlusion mentioned this issue Dec 6, 2023

Privval protocol incompatibility with namada node #817

Open

tony-iqlusion reopened this Jan 17, 2024

tony-iqlusion mentioned this issue Feb 12, 2024

p2p: failure to read complete message informalsystems/tendermint-rs#1392

Open

zarkone linked a pull request Apr 29, 2024 that will close this issue

Aggregate TCP chunks with unmarshal protobuf retry #903

Open

Protobuf: buffer underflow #729

Protobuf: buffer underflow #729

Comments

activenodes commented May 26, 2023 • edited

tony-iqlusion commented May 26, 2023

activenodes commented May 26, 2023 • edited

imperator-co commented May 26, 2023

tony-iqlusion commented May 27, 2023

activenodes commented May 27, 2023

tony-iqlusion commented May 27, 2023

qezz commented May 30, 2023

tony-iqlusion commented May 30, 2023

activenodes commented May 30, 2023

tony-iqlusion commented May 30, 2023

activenodes commented May 31, 2023

tony-iqlusion commented May 31, 2023

activenodes commented May 31, 2023

tony-iqlusion commented May 31, 2023

IbrarMakaveli commented Aug 14, 2023 • edited

activenodes commented Aug 16, 2023

tony-iqlusion commented Aug 16, 2023 • edited

activenodes commented Aug 17, 2023

tony-iqlusion commented Aug 17, 2023

activenodes commented Aug 17, 2023 • edited

activenodes commented Aug 17, 2023

tony-iqlusion commented Aug 17, 2023

tony-iqlusion commented Aug 17, 2023

tony-iqlusion commented Aug 17, 2023

IbrarMakaveli commented Aug 19, 2023

mkaczanowski commented Sep 17, 2023 • edited

TL;DR

Proof of concept fix

Proper fix

tony-iqlusion commented Sep 18, 2023

mkaczanowski commented Sep 18, 2023

mkaczanowski commented Sep 18, 2023

tony-iqlusion commented Oct 16, 2023

IbrarMakaveli commented Oct 17, 2023

tony-iqlusion commented Oct 18, 2023

IbrarMakaveli commented Oct 18, 2023

qezz commented Oct 18, 2023 • edited

tony-iqlusion commented Oct 18, 2023

IbrarMakaveli commented Oct 20, 2023 • edited

tony-iqlusion commented Oct 20, 2023 • edited

tony-iqlusion commented Oct 24, 2023

IbrarMakaveli commented Nov 7, 2023

qezz commented Jan 16, 2024

IbrarMakaveli commented Jan 17, 2024

qezz commented Jan 17, 2024 • edited

tony-iqlusion commented Jan 17, 2024

IbrarMakaveli commented Feb 11, 2024

tony-iqlusion commented Feb 12, 2024

tony-iqlusion commented Mar 5, 2024

qezz commented Mar 5, 2024 • edited

qezz commented Mar 5, 2024

tony-iqlusion commented Mar 5, 2024

qezz commented Mar 5, 2024

qezz commented Mar 5, 2024 • edited

tony-iqlusion commented Mar 5, 2024

activenodes commented May 26, 2023 •

edited

activenodes commented May 26, 2023 •

edited

IbrarMakaveli commented Aug 14, 2023 •

edited

tony-iqlusion commented Aug 16, 2023 •

edited

activenodes commented Aug 17, 2023 •

edited

mkaczanowski commented Sep 17, 2023 •

edited

qezz commented Oct 18, 2023 •

edited

IbrarMakaveli commented Oct 20, 2023 •

edited

tony-iqlusion commented Oct 20, 2023 •

edited

qezz commented Jan 17, 2024 •

edited

qezz commented Mar 5, 2024 •

edited

qezz commented Mar 5, 2024 •

edited