Bug in transport.rs

[conorbros]

I think I've found a bug in transport.rs. Had some trouble finding a fix, perhaps @krojew will fare better since you wrote the code. Here's a repo with everything needed: https://github.com/conorbros/cdrs-bug-report

In the logs you can see that the "receiving on an empty channel" error occurs frequently and then the driver sends some garbage bytes that aren't a valid frame: [0, 0, 2, 6a, 36, c4, d3, 7e, 77, 44]. I think Cassandra itself is ignoring this but I noticed it because it was causing problems in Shotover.

2022-07-12T04:43:03.166569Z DEBUG cdrs_tokio::cluster::control_connection: Establishing new control connection...
2022-07-12T04:43:03.166615Z DEBUG cdrs_tokio::cluster::topology::node: Establishing new connection to node...
2022-07-12T04:43:03.166828Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.166856Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.166861Z DEBUG cdrs_tokio::transport: writing frame: [0, 0, 2, 6a, 36, c4, d3, 7e, 77, 44]
2022-07-12T04:43:03.166886Z DEBUG cdrs_tokio::transport: writing frame: [0, 0, 2, 6a, 36, c4, d3, 7e, 77, 44]
2022-07-12T04:43:03.167801Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.167797Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.167828Z DEBUG cdrs_tokio::transport: writing frame: [21, 0, 2, 21, 62, 8d, 5, 0, 0, 2, f, 0, 0, 0, 18, 0, 0, 0, 14, 0, 63, 61, 73, 73, 61, 6e, 64, 72, 61, 0, 63, 61, 73, 73, 61, 6e, 64, 72, 61, c5, 9c, 7a, 7e]
2022-07-12T04:43:03.167823Z DEBUG cdrs_tokio::transport: writing frame: [21, 0, 2, 21, 62, 8d, 5, 0, 0, 2, f, 0, 0, 0, 18, 0, 0, 0, 14, 0, 63, 61, 73, 73, 61, 6e, 64, 72, 61, 0, 63, 61, 73, 73, 61, 6e, 64, 72, 61, c5, 9c, 7a, 7e]
2022-07-12T04:43:03.234758Z DEBUG cdrs_tokio::cluster::control_connection: Established new control connection.
2022-07-12T04:43:03.234789Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.234814Z DEBUG cdrs_tokio::transport: writing frame: [30, 0, 2, 95, 3f, 3e, 5, 0, 0, 3, 7, 0, 0, 0, 27, 0, 0, 0, 1d, 53, 45, 4c, 45, 43, 54, 20, 2a, 20, 46, 52, 4f, 4d, 20, 73, 79, 73, 74, 65, 6d, 2e, 70, 65, 65, 72, 73, 5f, 76, 32, 0, 1, 0, 0, 0, 0, d1, af, 84, 6b]
2022-07-12T04:43:03.234880Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.234904Z DEBUG cdrs_tokio::transport: writing frame: [95, 0, 2, f9, 75, c5, 5, 0, 0, 3, 7, 0, 0, 0, 24, 0, 0, 0, 1a, 53, 45, 4c, 45, 43, 54, 20, 2a, 20, 46, 52, 4f, 4d, 20, 73, 79, 73, 74, 65, 6d, 2e, 6c, 6f, 63, 61, 6c, 0, 1, 0, 0, 0, 0, 5, 0, 0, 4, 7, 0, 0, 0, 5f, 0, 0, 0, 55, 53, 45, 4c, 45, 43, 54, 20, 6b, 65, 79, 73, 70, 61, 63, 65, 5f, 6e, 61, 6d, 65, 2c, 20, 74, 6f, 4a, 73, 6f, 6e, 28, 72, 65, 70, 6c, 69, 63, 61, 74, 69, 6f, 6e, 29, 20, 41, 53, 20, 72, 65, 70, 6c, 69, 63, 61, 74, 69, 6f, 6e, 20, 46, 52, 4f, 4d, 20, 73, 79, 73, 74, 65, 6d, 5f, 73, 63, 68, 65, 6d, 61, 2e, 6b, 65, 79, 73, 70, 61, 63, 65, 73, 0, 1, 0, 0, 0, 0, b3, 6d, 53, 19]
2022-07-12T04:43:03.236852Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.236886Z DEBUG cdrs_tokio::transport: writing frame: [30, 0, 2, 95, 3f, 3e, 5, 0, 0, 5, 7, 0, 0, 0, 27, 0, 0, 0, 1d, 53, 45, 4c, 45, 43, 54, 20, 2a, 20, 46, 52, 4f, 4d, 20, 73, 79, 73, 74, 65, 6d, 2e, 70, 65, 65, 72, 73, 5f, 76, 32, 0, 1, 0, 0, 0, 0, fb, 52, 12, 14]
2022-07-12T04:43:03.237775Z DEBUG cdrs_tokio::cluster::metadata_builder: Copying contact point. node_info=NodeInfo { host_id: 491c454d-f62e-433e-95f0-e864c89bf2c3, broadcast_rpc_address: 127.0.0.1:9043, broadcast_address: Some(192.168.160.2:7000), datacenter: "datacenter1", rack: "rack1" }
2022-07-12T04:43:03.237985Z  WARN cdrs_tokio::transport: receiving on an empty channel
2022-07-12T04:43:03.238005Z DEBUG cdrs_tokio::transport: writing frame: [3a, 0, 2, 73, 61, 83, 5, 0, 0, 6, b, 0, 0, 0, 31, 0, 3, 0, d, 53, 43, 48, 45, 4d, 41, 5f, 43, 48, 41, 4e, 47, 45, 0, d, 53, 54, 41, 54, 55, 53, 5f, 43, 48, 41, 4e, 47, 45, 0, f, 54, 4f, 50, 4f, 4c, 4f, 47, 59, 5f, 43, 48, 41, 4e, 47, 45, d2, a7, 16, 43]
result : Envelope { version: V5, direction: Response, flags: (empty), opcode: Result, stream_id: 3, tracing_id: None, warnings: [] }

[krojew]

The receiving on an empty channel error is normal - it means we have no queued envelopes, which we can immediately aggregate in a frame. The strange bytes seem to be uncompressed header + trailer without actual payload. Will investigate.

[krojew]

Note: empty frames, while don't make sense, are still valid (you can see payload length 0), so you should still support them.