@@ -59,7 +59,10 @@ xqc_h3_request_destroy(xqc_h3_request_t *h3_request)
5959 "|rcvd_bdy_sz:%uz|snd_bdy_sz:%uz|rcvd_hdr_sz:%uz|snd_hdr_sz:%uz"
6060 "|create:%ui|blkd:%ui|nblkd:%ui|hdr_b:%ui|hdr_e:%ui|bdy_b:%ui|fin:%ui|recv_end:%ui"
6161 "|hrd_send:%ui|bdy_send:%ui|fin_send:%ui|fin_ack:%ui|last_send:%ui|last_recv:%ui"
62- "|mp_state:%d|path_info:%s|comp_hdr_s:%uz|comp_hdr_r:%uz|" ,
62+ "|mp_state:%d|path_info:%s|comp_hdr_s:%uz|comp_hdr_r:%uz|fst_fin_snd:%ui|"
63+ "sched_blk:%ud|sched_blk_time:%ui|"
64+ "cwnd_blk:%ud|cwnd_blk_time:%ui|"
65+ "pacing_blk:%ud|pacing_blk_time:%ui|begin_state:%s|end_state:%s|" ,
6366 h3s -> stream_id , stats .stream_close_msg ? stats .stream_close_msg : "" ,
6467 stats .stream_err , stats .recv_body_size , stats .send_body_size ,
6568 stats .recv_header_size , stats .send_header_size ,
@@ -78,7 +81,16 @@ xqc_h3_request_destroy(xqc_h3_request_t *h3_request)
7881 xqc_calc_delay (h3_request -> h3_stream -> h3c -> conn -> conn_last_send_time , create_time ),
7982 xqc_calc_delay (h3_request -> h3_stream -> h3c -> conn -> conn_last_recv_time , create_time ),
8083 stats .mp_state , stats .stream_info , stats .send_hdr_compressed ,
81- stats .recv_hdr_compressed );
84+ stats .recv_hdr_compressed ,
85+ xqc_calc_delay (stats .stream_fst_fin_snd_time , create_time ),
86+ h3_request -> sched_cwnd_blk_cnt ,
87+ h3_request -> sched_cwnd_blk_duration / 1000 ,
88+ h3_request -> send_cwnd_blk_cnt ,
89+ h3_request -> send_cwnd_blk_duration / 1000 ,
90+ h3_request -> send_pacing_blk_cnt ,
91+ h3_request -> send_pacing_blk_duration / 1000 ,
92+ h3s -> begin_trans_state ,
93+ h3s -> end_trans_state );
8294
8395 if (h3_request -> request_if -> h3_request_close_notify ) {
8496 h3_request -> request_if -> h3_request_close_notify (h3_request , h3_request -> user_data );
@@ -168,6 +180,37 @@ xqc_h3_request_create_inner(xqc_h3_conn_t *h3_conn, xqc_h3_stream_t *h3_stream,
168180 return h3_request ;
169181}
170182
183+ void
184+ xqc_h3_request_encode_rtts (xqc_h3_request_t * h3r , char * buff , size_t buff_size )
185+ {
186+ xqc_h3_stream_t * h3_stream = h3r -> h3_stream ;
187+ size_t cursor = 0 ;
188+ int ret , i ;
189+
190+ for (int i = 0 ; i < XQC_MAX_PATHS_COUNT ; ++ i ) {
191+ if ((h3_stream -> paths_info [i ].path_send_bytes > 0 )
192+ || (h3_stream -> paths_info [i ].path_recv_bytes > 0 ))
193+ {
194+ ret = snprintf (buff + cursor , buff_size - cursor ,
195+ "%" PRIu64 "-" , h3_stream -> paths_info [i ].path_srtt / 1000 );
196+ cursor += ret ;
197+
198+ if (cursor >= buff_size ) {
199+ break ;
200+ }
201+ }
202+ }
203+
204+ cursor = xqc_min (cursor , buff_size );
205+ for (i = cursor - 1 ; i >= 0 ; i -- ) {
206+ if (buff [i ] == '-' ) {
207+ buff [i ] = '\0' ;
208+ break ;
209+ }
210+ }
211+ buff [buff_size - 1 ] = '\0' ;
212+ }
213+
171214void
172215xqc_stream_info_print (xqc_h3_stream_t * h3_stream , xqc_request_stats_t * stats )
173216{
@@ -189,9 +232,10 @@ xqc_stream_info_print(xqc_h3_stream_t *h3_stream, xqc_request_stats_t *stats)
189232
190233 xqc_conn_encode_mp_settings (h3c -> conn , mp_settings , XQC_MP_SETTINGS_STR_LEN );
191234
192- ret = snprintf (buff , buff_size , "(%d,%" PRIu64 ",%s,%" PRIu64 ",%" PRIu64 ")#" ,
235+ ret = snprintf (buff , buff_size , "(%d,%" PRIu64 ",%s,%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%u )#" ,
193236 flag , h3_stream -> recv_rate_limit , mp_settings ,
194- h3_stream -> send_offset , h3_stream -> recv_offset );
237+ h3_stream -> send_offset , h3_stream -> recv_offset ,
238+ stats -> cwnd_blocked_ms , stats -> retrans_cnt );
195239
196240 cursor += ret ;
197241
@@ -256,6 +300,9 @@ xqc_h3_request_get_stats(xqc_h3_request_t *h3_request)
256300 xqc_request_stats_t stats ;
257301 xqc_memzero (& stats , sizeof (stats ));
258302
303+ /* try to update stats */
304+ xqc_h3_stream_update_stats (h3_request -> h3_stream );
305+
259306 uint64_t conn_err = h3_request -> h3_stream -> h3c -> conn -> conn_err ;
260307 stats .recv_body_size = h3_request -> body_recvd ;
261308 stats .send_body_size = h3_request -> body_sent ;
@@ -273,18 +320,17 @@ xqc_h3_request_get_stats(xqc_h3_request_t *h3_request)
273320 stats .h3r_header_send_time = h3_request -> h3r_header_send_time ;
274321 stats .h3r_body_send_time = h3_request -> h3r_body_send_time ;
275322 stats .stream_fin_send_time = h3_request -> stream_fin_send_time ;
323+ stats .stream_fst_fin_snd_time = h3_request -> stream_fst_fin_snd_time ;
276324 stats .stream_fin_ack_time = h3_request -> stream_fin_ack_time ;
277325 stats .stream_close_msg = h3_request -> stream_close_msg ;
278326 stats .send_hdr_compressed = h3_request -> compressed_header_sent ;
279327 stats .recv_hdr_compressed = h3_request -> compressed_header_recvd ;
280328 stats .rate_limit = h3_request -> h3_stream -> recv_rate_limit ;
281-
282- /* try to update early data state */
283- if (h3_request -> h3_stream -> stream ) {
284- xqc_h3_stream_update_early_data_state (h3_request -> h3_stream );
285- }
286-
329+ stats .cwnd_blocked_ms = (h3_request -> sched_cwnd_blk_duration + h3_request -> send_cwnd_blk_duration ) / 1000 ;
287330 stats .early_data_state = h3_request -> h3_stream -> early_data_state ;
331+ stats .retrans_cnt = h3_request -> retrans_pkt_cnt ;
332+ stats .stream_fst_pkt_snd_time = h3_request -> stream_fst_pkt_snd_time ;
333+ stats .stream_fst_pkt_rcv_time = h3_request -> stream_fst_pkt_rcv_time ;
288334
289335 xqc_h3_stream_get_path_info (h3_request -> h3_stream );
290336 xqc_request_path_metrics_print (h3_request -> h3_stream -> h3c -> conn ,
@@ -299,8 +345,11 @@ xqc_h3_request_stats_print(xqc_h3_request_t *h3_request, char *str, size_t size)
299345{
300346 xqc_request_stats_t stats = xqc_h3_request_get_stats (h3_request );
301347 xqc_usec_t create_time = h3_request -> h3r_begin_time ;
348+ char rtt_str [32 ] = {0 };
349+ xqc_h3_request_encode_rtts (h3_request , rtt_str , 32 );
302350 return snprintf (str , size , "%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%" PRIu64
303- ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ,
351+ ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",%" PRIu64 ",cc:%" PRIu64
352+ ",rtx:%u,rtt:%s" ,
304353 h3_request -> h3_stream -> stream_id ,
305354 xqc_calc_delay (stats .h3r_header_begin_time , create_time ) / 1000 ,
306355 xqc_calc_delay (stats .h3r_header_end_time , create_time ) / 1000 ,
@@ -310,7 +359,8 @@ xqc_h3_request_stats_print(xqc_h3_request_t *h3_request, char *str, size_t size)
310359 xqc_calc_delay (stats .h3r_header_send_time , create_time ) / 1000 ,
311360 xqc_calc_delay (stats .h3r_body_send_time , create_time ) / 1000 ,
312361 xqc_calc_delay (stats .stream_fin_send_time , create_time ) / 1000 ,
313- xqc_calc_delay (stats .stream_fin_ack_time , create_time ) / 1000 );
362+ xqc_calc_delay (stats .stream_fin_ack_time , create_time ) / 1000 ,
363+ stats .cwnd_blocked_ms , stats .retrans_cnt , rtt_str );
314364}
315365
316366void
@@ -384,7 +434,6 @@ xqc_h3_request_copy_header(xqc_http_header_t *dst, xqc_http_header_t *src, xqc_v
384434 return XQC_OK ;
385435}
386436
387-
388437ssize_t
389438xqc_h3_request_send_headers (xqc_h3_request_t * h3_request , xqc_http_headers_t * headers , uint8_t fin )
390439{
@@ -634,7 +683,7 @@ xqc_h3_request_on_recv_header(xqc_h3_request_t *h3r)
634683 /* notify data before trailer headers*/
635684 ret = xqc_h3_request_on_recv_body (h3r );
636685 if (ret != XQC_OK ) {
637- xqc_log (h3r -> h3_stream -> log , XQC_LOG_ERROR , "|xqc_h3_request_on_recv_body error|%d|" , ret );
686+ xqc_log (h3r -> h3_stream -> log , XQC_LOG_ERROR , "|recv body error|%d|" , ret );
638687 return ret ;
639688 }
640689 }
0 commit comments