paritytech/soketto

v0.4 sends back empty messages on `Receiver::receive_data`

niklasad1 opened this issue · 3 comments

Hi,

I have observed changed behavior in v0.4 where occasionally empty Websocket messages are propagated back to caller of receive_data which wasn't the case in v0.3 what I have seen when when performing multiple request after each other in a loop :

[2020-11-04T10:51:57Z TRACE soketto] read 153 bytes
[2020-11-04T10:51:57Z TRACE soketto] read 152 bytes
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e for header: Header { fin: true, rsv1: false, rsv2: false, rsv3: false, masked: false, opcode: Binary, mask: 0, payload_len: 0 }
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e: send: (Binary (fin 1) (rsv 000) (mask (1 abddc470)) (len 59))
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e: flushing connection
[2020-11-04T10:51:57Z TRACE soketto] read 2 bytes
[2020-11-04T10:51:57Z TRACE soketto] read 4 bytes
[2020-11-04T10:51:57Z TRACE soketto::connection] 22132ab0: recv: Header { fin: true, rsv1: false, rsv2: false, rsv3: false, masked: true, opcode: Binary, mask: 2883437680, payload_len: 59 }
[2020-11-04T10:51:57Z TRACE soketto::connection] header_fin true, header_op_code: Binary
[2020-11-04T10:51:57Z TRACE soketto::connection] 22132ab0 for header: Header { fin: true, rsv1: false, rsv2: false, rsv3: false, masked: false, opcode: Text, mask: 0, payload_len: 0 }
[2020-11-04T10:51:57Z TRACE soketto::connection] 22132ab0: send: (Text (fin 1) (rsv 000) (mask (0 0)) (len 38))
[2020-11-04T10:51:57Z TRACE soketto] read 2 bytes
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e: recv: Header { fin: true, rsv1: false, rsv2: false, rsv3: false, masked: false, opcode: Text, mask: 0, payload_len: 38 }
[2020-11-04T10:51:57Z TRACE soketto::connection] header_fin true, header_op_code: Text
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e for header: Header { fin: true, rsv1: false, rsv2: false, rsv3: false, masked: false, opcode: Binary, mask: 0, payload_len: 0 }
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e: send: (Binary (fin 1) (rsv 000) (mask (1 c798ccd0)) (len 59))
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e: flushing connection
[2020-11-04T10:51:57Z TRACE soketto::connection] f25e9a0e: recv: Header { fin: false, rsv1: false, rsv2: false, rsv3: false, masked: false, opcode: Continue, mask: 0, payload_len: 0 }
[2020-11-04T10:51:57Z TRACE soketto::connection] header_fin false, header_op_code: Continue
[2020-11-04T10:51:57Z DEBUG soketto::connection] f25e9a0e: continue frame while not processing message fragments

Is that expected?
If that's the case how would I as a user distinguish between an empty message or an actual unexpected op code?
Is it reasonable to have another error kind, such as EmtpyMessage

  • f25e9a0e - client connection
  • 22132ab0 - server connection

continue frame while not processing message fragments

This happened in the past because the futures returned by async methods of Receiver were not always driven to completion and soketto's async methods are not cancellation safe:

//! **Note**: None of the `async` methods are safe to cancel so their `Future`s
This led to paritytech/jsonrpsee#114 and a followup experiment in soketto to improve the API (#22) but it was ultimately abandoned because it seemed to be too invasive.

Without a test case I can not say for certain that the same happens here, but since you mentioned in your jsonrpsee issue that only the client is affected and paritytech/jsonrpsee#114 only changed the server, it may be worth investigating if a future may have been dropped before completion.

Ok, thanks.

Sounds likely that the future has been dropped indeed because it's done similarly in an event loop.

Confirmed, those messages go away after "not dropping" the futures.