Spurious "stream state error" causes connection failure

[huitema]

Spurious connection closure visible if we examine this log:

5d551e5889570abe_client_server_qlog.zip

and client log says: [20276388, 0, "info", "message", { "message": "Protocol error 0x5, frame 0, reason: ?"}],
0x5 stands for #define PICOQUIC_TRANSPORT_STREAM_STATE_ERROR (0x5) this means my application trys to send data on a closed stream or unique direction stream ? How can I known which stream caused this error from the qlog?

(Originally reported by @alex-cheung92 in issue #1993)

[huitema]

This error happens in the function picoquic_create_missing_streams() which is called when the endpoints create stream out of order, or receive stream frames for streams created out of order. It seems that the application that produces the qlog does indeed create a lot of server side unidir streams out of order. This is a table showing the list of all streams that appear in the trace:

Stream-ID	C/S	Type	Expected ID
0	Client	Bidir	0
2	Client	Unidir	2
6	Client	Unidir	6
10	Client	Unidir	10
14	Client	Unidir	14
18	Client	Unidir	18
22	Client	Unidir	22
26	Client	Unidir	26
30	Client	Unidir	30
34	Client	Unidir	34
38	Client	Unidir	38
42	Client	Unidir	42
46	Client	Unidir	46
47	Server	Unidir	3
51	Server	Unidir	7
59	Server	Unidir	11
71	Server	Unidir	15
75	Server	Unidir	19
79	Server	Unidir	23
95	Server	Unidir	27
103	Server	Unidir	31
107	Server	Unidir	35
115	Server	Unidir	39
127	Server	Unidir	43
131	Server	Unidir	47
143	Server	Unidir	51

Starting streams with out of order numbers is unefficient. For example, in this log, the server starts stream-ID 3 (server, unidir), then 51 (server, unidir). It should have opened stream ID 7, not 51. By "jumping ahead", it forces the opening of streams 7, 11, 15, up to 47. See RFC 9000, section 2.1, "A stream ID that is used out of order results in all streams of that type with lower-numbered stream IDs also being opened." As long as these extra streams are not closed by sending FIN, or Reset, they count as open when computing the total number of open streams. Eventually, this will match the total number of streams allowed by the peer, and transmission will stop.

Are you using the recommended way to find the next stream number, i.e.:

/* Obtain the next available stream ID in the local category */
uint64_t picoquic_get_next_local_stream_id(picoquic_cnx_t* cnx, int is_unidir)

If not, you really should. If yes, that could be a bug in the implementation of picoquic_get_next_local_stream_id, and we would need to fix that.

I think that there is probably also something wrong in the implementation of the function picoquic_create_missing_streams(), and that should be fixed. But streams should really be opened in the expected order. The missing stream process is only there to handle out of order delivery of data packets because of retransmission, or maybe multipath. For example, create stream 3 and 7, and due to a network issue packets for stream 7 arrive before packets for stream 3.

[alex-cheung92]

Thanks for your replay.
In my application ,stream 0 is a control stream , open first ,bidir. even number is client created unidir stream send data to server, odd number created by server send data to stream.

I guess it's NOT a bug from picoquic

My application is driven by libevet, the clientside listen and accept connection from user, once a connection comes in, I call picoquic_get_next_local_stream_id to get a c2s stream id ,and send this id to server, when the server acked control info and write back in stream 0, at this time , the clientside callpicoquic_mark_active_stream to casue the stream to be created ( as you say by picoquic_create_missing_streams internal method). the server may returned acked info in a delay and out of order. If acked info delayed ,and client accept more than ONE connection , picoquic_get_next_local_stream_id returned SAME ID , that makes different user connection associated with SAME ID, as long as one connection closed, the PICOQUIC_TRANSPORT_STREAM_STATE_ERROR may occurs.

I changed my code, once invoke picoquic_get_next_local_stream_id , I call picoquic_set_app_stream_ctx(cnx, returned_stream_id, NULL); follows to let the picoquic stack forces created stream then next call of picoquic_get_next_local_stream_id return a different stream id.

It should be the reason and my test goes on , this kind of errors seem disappear.

[huitema]

Good to see that your application is working now!

[huitema]

I think that you saw is a race condition:

• server opens stream N,
• server sends data on stream N
• server sends message about stream N on stream 0
• client starts listening on stream N

The server unidir stream is created when the client receives data or reference for that stream on the server. If the client tries to interact with the stream before it is created, we will get an error. That will happen if the client "starts listening" before the data arrives.

In theory, we could allow some operations on the stream before it is open by the server, placing the stream in some kind of temporary state. But most operations will still be forbidden -- cannot send flow control frames, or stop sending frames, before the server has started sending. But that would be a new feature request, new development.

[alex-cheung92]

It's hard for servers to create stream in order. But it seems not a problem to me. In my application , each peer keeps their unidir streams(except stream 0),stream 0 is always first stream in a quic connection, the 'stream id number space' is 'orthogonal'
My application should promise there not exist one stream associate with more than one connection.