sile / jaegercat

A handy command line tool showing traces emitted by Jaeger clients
MIT License
4 stars 2 forks source link

Received malformed or unknown message: Failed (cause; assertion failed: `15 <= size`; size=-13) #3

Closed jayvdb closed 3 weeks ago

jayvdb commented 4 weeks ago

I see a lot of my trace messages appear, but also a lot of them appear to fail with:

Received malformed or unknown message: Failed (cause; assertion failed: `15 <= size`; size=-13)
    HISTORY:
      [0] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:387
      [1] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:315
      [2] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:429
      [3] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:393 -- i=0
      [4] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:315
      [5] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:324
      [6] at /home/jayvdb/.cargo/registry/src/index.crates.io-6f17d22bba15001f/thrift_codec-0.1.1/src/decode.rs:272
      [7] at src/thrift.rs:24
      [8] at src/main.rs:81
sile commented 4 weeks ago

Thank you for reporting this issue. Could you share a binary data to reproduce this error?

jayvdb commented 4 weeks ago

with

diff --git a/src/thrift.rs b/src/thrift.rs
index 8da6ca8..09470e7 100644
--- a/src/thrift.rs
+++ b/src/thrift.rs
@@ -21,7 +21,11 @@ impl EmitBatchNotification {
     pub fn decode(mut buf: &[u8], protocol: Protocol) -> Result<Self> {
         let message = match protocol {
             Protocol::Compact => {
-                track!(Message::compact_decode(&mut buf).map_err(|e| Failed.takes_over(e)))?
+                let rv = track!(Message::compact_decode(&mut buf).map_err(|e| Failed.takes_over(e)));
+                if rv.is_err() {
+                    eprintln!("{buf:?}");
+                }
+                rv?
             }
             Protocol::Binary => {
                 track!(Message::binary_decode(&mut buf).map_err(|e| Failed.takes_over(e)))?

I see

[24, 8, 116, 114, 97, 99, 101, 95, 105, 100, 21, 0, 24, 32, 48, 55, 99, 50, 57, 49, 54, 55, 55, 52, 52, 49, 52, 50, 48, 49, 97, 99, 101, 53, 101, 49, 51, 50, 98, 51, 50, 57, 57, 52, 54, 56, 0, 24, 7, 98, 117, 115, 121, 95, 110, 115, 21, 6, 70, 216, 139, 241, 145, 2, 0, 24, 14, 104, 116, 116, 112, 46, 99, 108, 105, 101, 110, 116, 95, 105, 112, 21, 0, 24, 9, 49, 50, 55, 46, 48, 46, 48, 46, 49, 0, 24, 7, 105, 100, 108, 101, 95, 110, 115, 21, 6, 70, 222, 195, 37, 0, 24, 11, 104, 116, 116, 112, 46, 109, 101, 116, 104, 111, 100, 21, 0, 24, 3, 71, 69, 84, 0, 24, 11, 104, 116, 116, 112, 46, 102, 108, 97, 118, 111, 114, 21, 0, 24, 3, 49, 46, 49, 0, 24, 14, 99, 111, 100, 101, 46, 110, 97, 109, 101, 115, 112, 97, 99, 101, 21, 0, 24, 24, 114, 111, 115, 95, 97, 99, 116, 105, 120, 95, 104, 101, 108, 112, 101, 114, 115, 58, 58, 116, 114, 97, 99, 101, 0, 24, 10, 104, 116, 116, 112, 46, 114, 111, 117, 116, 101, 21, 0, 24, 7, 47, 99, 97, 115, 101, 115, 47, 0, 24, 9, 104, 116, 116, 112, 46, 104, 111, 115, 116, 21, 0, 24, 14, 49, 50, 55, 46,48, 46, 48, 46, 49, 58, 56, 48, 48, 55, 0, 24, 9, 116, 104, 114, 101, 97, 100, 46, 105, 100, 21, 6, 70, 18, 0, 24, 11, 104, 116, 116, 112, 46, 116, 97, 114, 103, 101, 116, 21, 0, 24, 7, 47, 99, 97, 115, 101, 115, 47, 0, 24, 16, 104, 116, 116, 112, 46, 115, 116, 97, 116, 117, 115, 95, 99, 111, 100, 101, 21, 6, 70, 144, 3, 0, 24, 11, 104, 116, 116, 112, 46, 115, 99, 104, 101, 109, 101, 21, 0, 24, 4, 104, 116, 116, 112, 0, 24, 10, 114, 101, 113, 117, 101, 115, 116, 95, 105, 100, 21, 0, 24, 36, 53, 50, 100, 52, 102, 101, 53, 53, 45, 101, 48, 102, 98, 45, 52, 100, 100, 48, 45, 57, 50, 53, 55, 45, 48, 54, 49, 52, 100, 48, 101, 99, 55, 99, 53, 57, 0, 24, 11, 99, 111, 100, 101, 46, 108, 105, 110, 101, 110, 111, 21, 6, 70, 152, 1, 0, 24, 15, 104, 116, 116, 112, 46, 117, 115, 101, 114, 95, 97, 103, 101, 110, 116, 21, 0, 24, 9, 120, 104, 47, 48, 46, 50, 50, 46, 48, 0, 24, 13, 99, 111, 100, 101, 46, 102, 105, 108, 101, 112, 97, 116, 104, 21, 0, 24, 35, 108, 105, 98, 115, 47, 114, 111, 115, 45, 97, 99, 116, 105, 120, 45, 104, 101, 108, 112, 101, 114, 115, 47, 115, 114, 99, 47, 116, 114, 97, 99, 101, 46, 114, 115, 0, 24, 11, 116, 104, 114, 101, 97, 100, 46, 110, 97, 109, 101, 21, 0, 24, 27, 97, 99, 116, 105, 120, 45, 114, 116, 124, 115, 121, 115, 116, 101, 109, 58, 48, 124, 97, 114, 98, 105, 116, 101, 114, 58, 52, 0, 24, 17, 111, 116, 101, 108, 46, 108, 105, 98, 114, 97, 114, 121, 46, 110, 97, 109, 101, 21, 0, 24, 20, 111, 112, 101, 110, 116, 101, 108, 101, 109, 101, 116, 114, 121, 45, 106, 97, 101, 103, 101, 114, 0, 24, 20, 111, 116, 101, 108, 46, 108, 105, 98, 114, 97, 114, 121, 46, 118, 101, 114, 115, 105, 111, 110, 21, 0, 24, 6, 48, 46, 49, 55, 46, 48, 0, 24, 9, 115, 112, 97, 110, 46, 107, 105, 110, 100, 21, 0, 24, 6, 115, 101, 114, 118, 101, 114, 0, 24, 16, 111, 116, 101, 108, 46, 115, 116, 97, 116, 117, 115, 95, 99, 111, 100, 101, 21, 0, 24, 2, 79, 75, 0, 0, 0, 0]
[2024-06-10T08:19:19Z ERROR jaegercat] Received malformed or unknown message: Failed (cause; assertion failed: `15 <= size`; size=11)
sile commented 3 weeks ago

Thank you for sharing this information. However, since Message::compact_decode() consumes the header portion of &mut buf, you need to copy the buffer before calling compact_decode(), as shown below:

                let copied = buf.to_vec();
                let rv = track!(Message::compact_decode(&mut buf).map_err(|e| Failed.takes_over(e)));
                if rv.is_err() {
                    eprintln!("{copied:?}");
                }
                rv?
jayvdb commented 3 weeks ago

Here it is the output of copied

[130, 129, 9, 9, 101, 109, 105, 116, 66, 97, 116, 99, 104, 28, 28, 24, 7, 97, 105, 45, 109, 111, 99, 107, 25, 28, 24, 12, 115, 101, 114, 118, 105, 99, 101, 46, 110, 97, 109, 101, 21, 0, 24, 7, 97, 105, 45, 109, 111, 99, 107, 0, 0, 25, 28, 22, 226, 139, 190, 230, 173, 211, 146, 240, 151, 1, 22, 239, 182, 240, 155, 214, 178, 246, 203, 219, 1, 22, 212, 179, 245, 254, 170, 172, 129, 138, 12, 22, 154, 167, 159, 154, 245, 238, 171, 137, 126, 24, 57, 72, 84, 84, 80, 32, 80, 79, 83, 84, 32, 47, 112, 105, 112, 101, 108, 105, 110, 101, 115, 47, 112, 114, 111, 115, 116, 97, 116, 101, 45, 97, 105, 45, 115, 101, 114, 118, 105, 99, 101, 46, 101, 110, 115, 101, 109, 98, 108, 101, 47, 112, 114, 101, 100, 105, 99, 116, 37, 2, 22, 216, 160, 202, 241, 167, 164, 141, 6, 22, 182, 163, 232, 4, 25, 252, 22, 24, 10, 114, 101, 113, 117, 101, 115, 116, 95, 105, 100, 21, 0, 24, 36, 56, 53, 53, 53, 48, 97, 57, 49, 45, 56, 49, 99, 55, 45, 52, 102, 56, 50, 45, 57, 49, 102, 54, 45, 49, 53, 49, 50, 100, 48, 48, 101, 99, 52, 48, 55, 0, 24, 11, 116, 104, 114, 101, 97, 100, 46, 110, 97, 109, 101, 21, 0, 24, 27, 97, 99, 116, 105, 120, 45, 114, 116, 124, 115, 121, 115, 116, 101, 109, 58, 48, 124, 97, 114, 98, 105, 116, 101, 114, 58, 49, 0, 24, 9, 104, 116, 116, 112, 46, 104, 111, 115, 116, 21, 0, 24, 14, 49, 50, 55, 46, 48, 46, 48, 46, 49, 58, 56, 48, 48, 54, 0, 24, 14, 104, 116, 116, 112, 46, 99, 108, 105, 101, 110, 116, 95, 105, 112, 21, 0, 24, 9, 49, 50, 55, 46, 48, 46, 48, 46, 49, 0, 24, 16, 104, 116, 116, 112, 46, 115, 116, 97, 116, 117, 115, 95, 99, 111, 100, 101, 21, 6, 70, 144, 3, 0, 24, 11, 104, 116, 116, 112, 46, 115, 99, 104, 101, 109, 101, 21, 0, 24, 4, 104, 116, 116, 112, 0, 24, 11, 104, 116, 116, 112, 46, 102, 108, 97, 118, 111, 114, 21, 0, 24, 3, 49, 46, 49, 0, 24, 13, 99, 111, 100, 101, 46, 102, 105, 108, 101, 112, 97, 116, 104, 21, 0, 24, 35, 108, 105, 98, 115, 47, 114, 111, 115, 45, 97, 99, 116, 105, 120, 45, 104, 101, 108, 112, 101, 114, 115, 47, 115, 114, 99, 47, 116, 114, 97, 99, 101, 46, 114, 115, 0, 24, 11, 104, 116, 116, 112, 46, 109, 101, 116, 104, 111, 100, 21, 0, 24, 4, 80, 79, 83, 84, 0, 24, 9, 116, 104, 114, 101, 97, 100, 46, 105, 100, 21, 6, 70, 10, 0, 24, 10, 104, 116, 116, 112, 46, 114, 111, 117, 116, 101, 21, 0, 24, 47, 47, 112, 105, 112, 101, 108, 105, 110, 101, 115, 47, 112, 114, 111, 115, 116, 97, 116, 101, 45, 97, 105, 45, 115, 101, 114, 118, 105, 99, 101, 46, 101, 110, 115, 101, 109, 98, 108, 101, 47, 112, 114, 101, 100, 105, 99, 116, 0, 24, 15, 104, 116, 116, 112, 46, 117, 115, 101, 114, 95, 97, 103, 101, 110, 116, 21, 0, 24, 0, 0, 24, 8, 116, 114, 97, 99, 101, 95, 105, 100, 21, 0, 24, 32, 57, 50, 51, 52, 49, 51, 51, 53, 52, 101, 52, 49, 102, 50, 52, 56, 52, 98, 102, 48, 50, 53, 52, 100, 54, 101, 54, 55, 99, 50, 102, 49, 0, 24, 7, 105, 100, 108, 101, 95, 110, 115, 21, 6, 70, 162, 150, 173, 15, 0, 24, 11, 99, 111, 100, 101, 46, 108, 105, 110, 101, 110, 111, 21, 6, 70, 152, 1, 0, 24, 11, 104, 116, 116, 112, 46, 116, 97, 114, 103, 101, 116, 21, 0, 24, 47, 47, 112, 105, 112, 101, 108, 105, 110, 101, 115, 47, 112, 114, 111, 115, 116, 97, 116, 101, 45, 97, 105,45, 115, 101, 114, 118, 105, 99, 101, 46, 101, 110, 115, 101, 109, 98, 108, 101, 47, 112, 114, 101, 100, 105, 99, 116, 0, 24, 7, 98, 117, 115, 121, 95, 110, 115, 21, 6, 70, 254, 146, 170, 191, 37, 0, 24, 14, 99, 111, 100, 101, 46, 110, 97, 109, 101, 115, 112, 97, 99, 101, 21, 0, 24, 24, 114, 111, 115, 95, 97, 99, 116, 105, 120, 95, 104, 101, 108, 112, 101, 114, 115, 58, 58, 116, 114, 97, 99, 101, 0, 24, 17, 111, 116, 101, 108, 46, 108, 105, 98, 114, 97, 114, 121, 46, 110, 97, 109, 101, 21, 0, 24, 20, 111, 112, 101, 110, 116, 101, 108, 101, 109, 101, 116, 114, 121, 45, 106, 97, 101, 103, 101, 114, 0, 24, 20, 111, 116, 101, 108, 46, 108, 105, 98, 114, 97, 114, 121, 46, 118, 101, 114, 115, 105, 111, 110, 21, 0, 24, 6, 48, 46, 49, 55, 46, 48, 0, 24, 9, 115, 112, 97, 110, 46, 107, 105, 110, 100, 21, 0, 24, 6, 115, 101, 114, 118, 101, 114, 0, 24, 16, 111, 116, 101, 108, 46, 115, 116, 97, 116, 117, 115, 95, 99, 111, 100, 101, 21, 0, 24, 2, 79, 75, 0, 0, 0, 0]
[2024-06-10T23:09:56Z ERROR jaegercat] Received malformed or unknown message: Failed (cause; assertion failed: `15 <= size`; size=11)
jayvdb commented 3 weeks ago

In our logs when running with real jaeger, I see some "thrift agent failed with message too long" - so that is possibly the same thing. If so, perhaps the error message from jaegercat could be similar rather than a backtrace.

I'll dig into what is causing "thrift agent failed with message too long" with the real jaeger.

sile commented 3 weeks ago

Thank you for the additional information. I will investigate the data and consider how to address this issue tomorrow.

sile commented 3 weeks ago

It turned out that there was a bug in the thrift_codec crate. I have fixed the bug and released jaegercat-0.2.1.

jayvdb commented 3 weeks ago

Awesome; thank you. Confirming I dont see this any more.